autotest extension having problems (Unhandled KeyError: u'Cannot find a context with id=1AF9E7ADEF777071C7239F47D8C8AC77') |
|||||
Issue description[Filing for tracking, seems to be Chrome confused as Android starts fine?] 238746114 bob R71-11073.0.0 https://stainless.corp.google.com/browse/chromeos-autotest-results/238857462-chromeos-test/ 09/16 22:46:44.400 DEBUG| arc_util:0040| ARC is enabled in mode enabled 09/16 22:46:44.413 DEBUG| test:0381| Test failed due to u'Cannot find a context with id=1AF9E7ADEF777071C7239F47D8C8AC77'. Exception log follows the after_iteration_hooks. 09/16 22:46:44.414 DEBUG| test:0386| Starting after_iteration_hooks for cheets_StartAndroid.stress 09/16 22:46:44.416 DEBUG| base_sysinfo:0124| Loggable saves logs to /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1/interrupts.after 09/16 22:46:44.417 DEBUG| utils:0219| Running 'mkdir -p /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1/var/spool' 09/16 22:46:44.417 DEBUG| global_hooks:0056| 'mkdir -p /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1/var/spool' 09/16 22:46:44.439 DEBUG| utils:0219| Running 'rsync --no-perms --chmod=ugo+r -a --safe-links --exclude=/crash/**autoserv* --exclude=/crash/*.core /var/spool/crash /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1/var/spool' 09/16 22:46:44.439 DEBUG| global_hooks:0056| 'rsync --no-perms --chmod=ugo+r -a --safe-links --exclude=/crash/**autoserv* --exclude=/crash/*.core /var/spool/crash /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1/var/spool' 09/16 22:46:44.461 DEBUG| utils:0219| Running 'rm -rf /var/spool/crash/*' 09/16 22:46:44.462 DEBUG| global_hooks:0056| 'rm -rf /var/spool/crash/*' 09/16 22:46:44.480 DEBUG| base_sysinfo:0124| Loggable saves logs to /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1/meminfo.after 09/16 22:46:44.483 DEBUG| base_sysinfo:0124| Loggable saves logs to /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1/slabinfo.after 09/16 22:46:44.486 DEBUG| base_sysinfo:0124| Loggable saves logs to /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1/schedstat.after 09/16 22:46:44.487 DEBUG| utils:0219| Running 'logger "autotest finished iteration /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1"' 09/16 22:46:44.489 DEBUG| global_hooks:0056| 'logger "autotest finished iteration /usr/local/autotest/results/default/cheets_StartAndroid.stress/sysinfo/iteration.1"' 09/16 22:46:44.506 DEBUG| test:0391| after_iteration_hooks completed 09/16 22:46:44.512 WARNI| test:0606| The test failed with the following exception Traceback (most recent call last): File "/usr/local/autotest/common_lib/test.py", line 600, in _exec _call_test_function(self.execute, *p_args, **p_dargs) File "/usr/local/autotest/common_lib/test.py", line 806, in _call_test_function raise error.UnhandledTestFail(e) UnhandledTestFail: Unhandled KeyError: u'Cannot find a context with id=1AF9E7ADEF777071C7239F47D8C8AC77' Traceback (most recent call last): File "/usr/local/autotest/common_lib/test.py", line 800, in _call_test_function return func(*args, **dargs) File "/usr/local/autotest/common_lib/test.py", line 464, in execute postprocess_profiled_run, args, dargs) File "/usr/local/autotest/common_lib/test.py", line 371, in _call_run_once self.run_once(*args, **dargs) File "/usr/local/autotest/tests/cheets_StartAndroid/cheets_StartAndroid.py", line 53, in run_once dont_override_profile=dont_override_profile) File "/usr/local/autotest/common_lib/cros/chrome.py", line 185, in __init__ arc_util.enable_play_store(self.autotest_ext, True) File "/usr/local/autotest/common_lib/cros/chrome.py", line 223, in autotest_ext return self.get_extension(self._autotest_ext_path) File "/usr/local/autotest/common_lib/cros/chrome.py", line 216, in get_extension return self.browser.extensions[ext] File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/browser/extension_dict.py", line 19, in __getitem__ return self.GetByExtensionId(load_extension.extension_id)[0] File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/browser/extension_dict.py", line 34, in GetByExtensionId return self._extension_backend[extension_id] File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome/extension_backend.py", line 32, in __getitem__ if self.ContextIdToExtensionId(context_id) == extension_id: File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome/extension_backend.py", line 47, in ContextIdToExtensionId context = self._extension_backend_list.GetContextInfo(context_id) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend_list.py", line 39, in GetContextInfo return self._devtools_context_map_backend.GetContextInfo(context_id) File "/usr/local/telemetry/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/devtools_client_backend.py", line 581, in GetContextInfo raise KeyError('Cannot find a context with id=%s' % context_id) KeyError: u'Cannot find a context with id=1AF9E7ADEF777071C7239F47D8C8AC77'
,
Sep 18
Yes, it was a flake. This failure happen 10-20 times a day in the lab across all DUTs though. I guess any tests involving logging into Chrome affected? https://stainless.corp.google.com/search?status=FAIL&status=ERROR&status=ABORT&reason=Cannot+find+a+context+with+id&exclude_non_release=false&exclude_cts=false&view=list&first_date=2018-09-12&last_date=2018-09-18
,
Sep 19
All tests where autotest_ext is True (which loads the 'autotest' extension). https://cs.corp.google.com/search/?q=package:%5Echromeos_public$+autotest_ext%3DTrue&type=cs Some tests also load their own custom extensions (networking and cheets for example), and these also break. It's a subset of tests that login to chrome.
,
Sep 19
I think I'll need to enable logging for extensions - I looked at the chrome logs and we can't tell if the extension got loaded or not. This may be related to crbug.com/884454 . I can see --show-webui-login in these tests. For eg: https://storage.cloud.google.com/chromeos-autotest-results/239340666-chromeos-test/chromeos6-row3-rack13-host5/desktopui_ScreenLocker/debug/desktopui_ScreenLocker.DEBUG
,
Sep 19
Tast also loads a custom extension (I initially patterned its Chrome code off of Autotest/Telemetry), but I haven't seen failures like this there. If I had to guess, I'd say that Autotest might be trying to connect to and/or use the extension before it's ready. See e.g. issue 789313 , where I made Tast wait for chrome.autotestPrivate to be defined in the extension's execution context. This bug looks like it's about a connection error instead, but Tast also polls until it sees the extension's CDP target appear -- I'm not sure if Autotest/Telemetry does that as well.
,
Jan 7
|
|||||
►
Sign in to add a comment |
|||||
Comment 1 by achuith@chromium.org
, Sep 18