New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 735330 link

Starred by 1 user

Issue metadata

Status: Archived
Owner: ----
Closed: Jun 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux
Pri: 3
Type: Bug



Sign in to add a comment

unknown field name "match_tag" in vpython.Spec_Package

Project Member Reported by tansell@chromium.org, Jun 21 2017

Issue description

I was trying to run my third_party/WebKit/Tools/Scripts/merge-layout-test-results script and got the following error;
-----------------------------------------------------------
$ third_party/WebKit/Tools/Scripts/merge-layout-test-results --verbose --allow-existing-output-directory --remove-existing-output-directory --output-directory=/fast/testdir2 blah blah
[E2017-06-21T14:29:02.829101+10:00 153532 0 annotate.go:343] original error: line 23: unknown field name "match_tag" in vpython.Spec_Package
[E2017-06-21T14:29:02.829173+10:00 153532 0 annotate.go:343] 
[E2017-06-21T14:29:02.829203+10:00 153532 0 annotate.go:343] goroutine 1:
[E2017-06-21T14:29:02.829228+10:00 153532 0 annotate.go:343] #0 github.com/luci/luci-go/vpython/spec/load.go:64 - spec.Parse()
[E2017-06-21T14:29:02.829258+10:00 153532 0 annotate.go:343]   reason: "failed to unmarshal vpython.Spec"
[E2017-06-21T14:29:02.829291+10:00 153532 0 annotate.go:343] 
[E2017-06-21T14:29:02.829316+10:00 153532 0 annotate.go:343] #1 github.com/luci/luci-go/vpython/spec/load.go:53 - spec.Load()
[E2017-06-21T14:29:02.829340+10:00 153532 0 annotate.go:343] #2 github.com/luci/luci-go/vpython/spec/load.go:204 - spec.(*Loader).LoadForScript()
[E2017-06-21T14:29:02.829364+10:00 153532 0 annotate.go:343] #3 github.com/luci/luci-go/vpython/options.go:133 - vpython.(*Options).ResolveSpec()
[E2017-06-21T14:29:02.829387+10:00 153532 0 annotate.go:343]   reason: "failed to load spec for script: {third_party/WebKit/Tools/Scripts/merge-layout-test-results}"
[E2017-06-21T14:29:02.829411+10:00 153532 0 annotate.go:343]   "isModule" = false
[E2017-06-21T14:29:02.829438+10:00 153532 0 annotate.go:343]   "path" = python.ScriptTarget{Path:"third_party/WebKit/Tools/Scripts/merge-layout-test-results"}
[E2017-06-21T14:29:02.829470+10:00 153532 0 annotate.go:343] 
[E2017-06-21T14:29:02.829493+10:00 153532 0 annotate.go:343] #4 github.com/luci/luci-go/vpython/options.go:68 - vpython.(*Options).resolve()
[E2017-06-21T14:29:02.829517+10:00 153532 0 annotate.go:343]   reason: "failed to resolve Python script"
[E2017-06-21T14:29:02.829540+10:00 153532 0 annotate.go:343] 
[E2017-06-21T14:29:02.829567+10:00 153532 0 annotate.go:343] #5 github.com/luci/luci-go/vpython/run.go:52 - vpython.Run()
[E2017-06-21T14:29:02.829578+10:00 153532 0 annotate.go:343]   reason: "could not resolve options"
[E2017-06-21T14:29:02.829590+10:00 153532 0 annotate.go:343] 
[E2017-06-21T14:29:02.829600+10:00 153532 0 annotate.go:343] #6 github.com/luci/luci-go/vpython/application/application.go:208 - application.(*application).mainImpl()
[E2017-06-21T14:29:02.829612+10:00 153532 0 annotate.go:343] #7 github.com/luci/luci-go/vpython/application/application.go:278 - application.(*Config).Main.func1()
[E2017-06-21T14:29:02.829631+10:00 153532 0 annotate.go:343] #8 github.com/luci/luci-go/vpython/application/support.go:26 - application.run()
[E2017-06-21T14:29:02.829646+10:00 153532 0 annotate.go:343] #9 github.com/luci/luci-go/vpython/application/application.go:279 - application.(*Config).Main()
[E2017-06-21T14:29:02.829658+10:00 153532 0 annotate.go:343] #10 vpython/main.go:71 - main.mainImpl()
[E2017-06-21T14:29:02.829669+10:00 153532 0 annotate.go:343] #11 vpython/main.go:77 - main.main()
[E2017-06-21T14:29:02.829684+10:00 153532 0 annotate.go:343] #12 runtime/proc.go:185 - runtime.main()
[E2017-06-21T14:29:02.829696+10:00 153532 0 annotate.go:343] #13 runtime/asm_amd64.s:2197 - runtime.goexit()
-----------------------------------------------------------

I've yet to debug what is causing this, but it seems something to do with vpython.
 
After doing a gclient sync, I got the following output;
-----------------------------------------------------------
$ third_party/WebKit/Tools/Scripts/merge-layout-test-results --verbose --allow-existing-output-directory --remove-existing-output-directory --output-directory=/fast/testdir2 blah blah
[P160141 14:36:50.496 client.go:879 I] cipd: updating client to infra/tools/cipd/linux-amd64:e081417e34a0150bbf6f8aca4cc38e004964d6f8 (git_revision:05f9a685b72ee556899506ffd965dca91bd60efa)
[P160141 14:36:51.286 storage.go:248 I] cipd: initiating the fetch
[P160141 14:36:52.826 storage.go:215 I] cipd: about to fetch 10.5 Mb
[P160141 14:36:52.826 storage.go:206 I] cipd: fetching - 0%
[P160141 14:36:53.543 storage.go:206 I] cipd: fetching - 100%
[P160141 14:36:53.543 storage.go:206 I] cipd: fetching - 100%
[P160130 14:36:54.669 client.go:267 I] In root:
[P160130 14:36:54.669 client.go:279 I]   to update:
[P160130 14:36:54.669 client.go:282 I]     infra/tools/luci/vpython/linux-amd64 (63ed4e9609b3a0400815a961431b4b2ee0caa59d -> b529e138084a94bd5a5be3b0e7c1c43ea8e64c2c)
[P160130 14:36:54.669 client.go:282 I]     infra/tools/luci/led/linux-amd64 (53c64ad0f6589878b5a8a40f25b70a4890cd0875 -> 42d2e9f9c3eeb289a1d90bce3069a56ed3a9c915)
[P160130 14:36:54.669 client.go:1242 I] cipd: resolving fetch URL for infra/tools/luci/vpython/linux-amd64:b529e138084a94bd5a5be3b0e7c1c43ea8e64c2c
[P160130 14:36:56.511 storage.go:248 I] cipd: initiating the fetch
[P160130 14:36:58.769 storage.go:215 I] cipd: about to fetch 3.3 Mb
[P160130 14:36:58.769 storage.go:206 I] cipd: fetching - 0%
[P160130 14:36:58.817 storage.go:206 I] cipd: fetching - 100%
[P160130 14:36:58.817 storage.go:206 I] cipd: fetching - 100%
[P160130 14:36:58.817 client.go:1238 I] cipd: successfully fetched infra/tools/luci/vpython/linux-amd64:b529e138084a94bd5a5be3b0e7c1c43ea8e64c2c
[P160130 14:36:58.818 deployer.go:156 I] Deploying infra/tools/luci/vpython/linux-amd64:b529e138084a94bd5a5be3b0e7c1c43ea8e64c2c into /fast/chrome/depot_tools/.cipd_bin(/)
[P160130 14:36:58.818 reader.go:289 I] cipd: about to extract 9.8 Mb (3 files)
[P160130 14:36:58.953 reader.go:326 I] cipd: extracting - 99%
[P160130 14:36:58.954 reader.go:326 I] cipd: extracting - 100%
[P160130 14:36:58.955 deployer.go:260 I] Successfully deployed infra/tools/luci/vpython/linux-amd64:b529e138084a94bd5a5be3b0e7c1c43ea8e64c2c
[P160130 14:36:58.959 client.go:1242 I] cipd: resolving fetch URL for infra/tools/luci/led/linux-amd64:42d2e9f9c3eeb289a1d90bce3069a56ed3a9c915
[P160130 14:36:59.295 storage.go:248 I] cipd: initiating the fetch
[P160130 14:37:01.429 storage.go:215 I] cipd: about to fetch 3.6 Mb
[P160130 14:37:01.429 storage.go:206 I] cipd: fetching - 0%
[P160130 14:37:01.464 storage.go:206 I] cipd: fetching - 100%
[P160130 14:37:01.464 storage.go:206 I] cipd: fetching - 100%
[P160130 14:37:01.464 client.go:1238 I] cipd: successfully fetched infra/tools/luci/led/linux-amd64:42d2e9f9c3eeb289a1d90bce3069a56ed3a9c915
[P160130 14:37:01.464 deployer.go:156 I] Deploying infra/tools/luci/led/linux-amd64:42d2e9f9c3eeb289a1d90bce3069a56ed3a9c915 into /fast/chrome/depot_tools/.cipd_bin(/)
[P160130 14:37:01.465 reader.go:289 I] cipd: about to extract 11.2 Mb (3 files)
[P160130 14:37:01.615 reader.go:326 I] cipd: extracting - 99%
[P160130 14:37:01.615 reader.go:326 I] cipd: extracting - 100%
[P160130 14:37:01.616 deployer.go:260 I] Successfully deployed infra/tools/luci/led/linux-amd64:42d2e9f9c3eeb289a1d90bce3069a56ed3a9c915
[P160130 14:37:01.618 client.go:1382 I] All changes applied.
[E2017-06-21T14:37:03.455496+10:00 160127 0 client.go:1219] cipd: infra/python/virtualenv:d7fe4ca0377e894777e4f0a4d10defc600baf537 is unexpectedly missing from cache (open /usr/local/google/home/tansell/.vpython_cipd_cache/instances/d7fe4ca0377e894777e4f0a4d10defc600baf537: no such file or directory)
webkitpy.common.system.log_utils: [DEBUG] Debug logging enabled.
root: [DEBUG] results_json_value_overrides: {}
root: [WARNING] Output directory exists '/fast/testdir2'
webkitpy.common.system.filesystem: [INFO] Removing contents of /fast/testdir2
webkitpy.layout_tests.merge_results: [DEBUG] Merging following paths:
webkitpy.layout_tests.merge_results: [DEBUG] ['/fast/chrome/src/blah', '/fast/chrome/src/blah']
-----------------------------------------------------------

There seems to be a bunch of things which are concerning here about vpython;

 * It seems to be writing things into my home directory at .vpython_cipd_cache
 * It seems to be writing things into the depot_tools directory at /fast/chrome/depot_tools/.cipd_bin(/)
 * This download is being not being run as part of gclient sync
 * What would have happened if I was offline?
 * The logging messages don't indicate they are coming from vpython and not my program.
 * These logging messages could potentially interfere with the output of my program. IE Things would have been very confusing if I was running 'myprogram 2>&1 | head -n2' or similar.

Comment 3 by d...@chromium.org, Jun 21 2017

Cc: qyears...@chromium.org
Those are all good points. Let me see if I can address them one-by-one:

 * It seems to be writing things into my home directory at .vpython_cipd_cache

Gotta write them somewhere :) Other Chromium tools use home directory files for caching and staging, so this isn't really a deviation, and it is wholly encapsulated. If this is concerning, we should probably have a larger discussion about where user files that tools generate should reside.

 * It seems to be writing things into the depot_tools directory at /fast/chrome/depot_tools/.cipd_bin(/)

This is actually just the "depot_tools" CIPD binary distribution wrapper: https://chromium.googlesource.com/chromium/tools/depot_tools/+/master/cipd_bin_setup.sh

vpython uses this because it's a binary. It runs once and caches, effectively creating the semblance of binaries being included in "depot_tools" while not actually checking them in. Which brings us to the next part...

 * This download is being not being run as part of gclient sync
 * What would have happened if I was offline?

Great points. The right solution here is to add a "vpython -dev install" subcommand to runhooks so that the VirtualEnvs get initialized during checkout. This will seed by the CIPD binary wrapper and the VirtualEnv itself.

 * The logging messages don't indicate they are coming from vpython and not my program.
 * These logging messages could potentially interfere with the output of my program. IE Things would have been very confusing if I was running 'myprogram 2>&1 | head -n2' or similar.

The logging is definitely gratuitous. The script that's calling "vpython" must be supplying "-log-level info". This behavior should only be employed if the user requests verbose output. OTOH it looks like you did ("--verbose"), so maybe this is exactly what the logic is doing. +qyearsley@ for feedback here.

Components: -Infra Infra>Platform>CIPD
Project Member

Comment 5 by sheriffbot@chromium.org, Jun 22 2018

Status: Archived (was: Unconfirmed)
Issue has not been modified or commented on in the last 365 days, please re-open or file a new bug if this is still an issue.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

Sign in to add a comment