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

Issue 870673 link

Starred by 1 user

Issue metadata

Status: Assigned
Owner:
Last visit > 30 days ago
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 2
Type: Bug



Sign in to add a comment

telemetry_unittests timing out on chromium.win/Win10 Tests x64 (dbg)

Project Member Reported by sheriff-...@appspot.gserviceaccount.com, Aug 3

Issue description

Filed by sheriff-o-matic@appspot.gserviceaccount.com on behalf of engedy@chromium.org

Some individual test cases in `telemetry_unittests` take more than 2 minutes to run (before timing out), causing the entire shard to time out, e.g.:

[95/294] telemetry.internal.browser.tab_unittest.TabTest.testNavigateAndWaitForCompleteState failed unexpectedly 123.5670s:
  Chrome build location for win_AMD64 not found. Browser will be run without Flash.
  Running sub processes (10 processes): chrome.exe (2164) - ['../../out\\Debug_x64\\chrome.exe', '--enable-net-benchmarking', '--metrics-recording-only', '--no-default-browser-check', '--no-first-run', '--enable-gpu-benchmarking', '--deny-permission-prompts', '--autoplay-policy=no-user-gesture-required', '--disable-background-networking', '--disable-component-extensions-with-background-pages', '--disable-default-apps', '--disable-search-geolocation-disclosure', '--proxy-server=socks://localhost:51023', '--ignore-certificate-errors-spki-list=PhrPvGIaAMmd29hj8BCZOq096yj7uMpRNHpn5PDxI6I=', '--remote-debugging-port=0', '--enable-crash-reporter-for-testing', '--disable-component-update', '--window-size=1280,1024', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmprqzvxo', 'about:blank']
  chrome.exe (6312) - ['../../out\\Debug_x64\\chrome.exe', '--enable-net-benchmarking', '--metrics-recording-only', '--no-default-browser-check', '--no-first-run', '--enable-gpu-benchmarking', '--deny-permission-prompts', '--autoplay-policy=no-user-gesture-required', '--disable-background-networking', '--disable-component-extensions-with-background-pages', '--disable-default-apps', '--disable-search-geolocation-disclosure', '--proxy-server=socks://localhost:50447', '--ignore-certificate-errors-spki-list=PhrPvGIaAMmd29hj8BCZOq096yj7uMpRNHpn5PDxI6I=', '--remote-debugging-port=0', '--enable-crash-reporter-for-testing', '--disable-component-update', '--window-size=1280,1024', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmpftwji6', 'about:blank']
  python.exe (3644) - ['C:\\b\\s\\w\\ir\\.swarming_module_cache\\vpython\\383165\\Scripts\\python.exe', 'C:\\b\\s\\w\\ir\\third_party\\catapult\\telemetry\\third_party\\tsproxy\\tsproxy.py', '--port=0', '--desthost=127.0.0.1']
  chrome.exe (5912) - ['C:\\b\\s\\w\\ir\\out\\Debug_x64\\chrome.exe', '--type=crashpad-handler', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmprqzvxo', '/prefetch:7', '--monitor-self', '--monitor-self-argument=--type=crashpad-handler', '--monitor-self-argument=--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmprqzvxo', '--monitor-self-argument=/prefetch:7', '--monitor-self-annotation=ptype=crashpad-handler', '--database=c:\\b\\s\\w\\ito_26gx\\tmpe9zhga', '--metrics-dir=c:\\b\\s\\w\\ito_26gx\\tmprqzvxo', '--annotation=plat=Win64', '--annotation=prod=Chromium', '--annotation=ver=70.0.3512.0-devel', '--initial-client-data=0x21c,0x220,0x224,0x218,0x228,0x7ffc5587b948,0x7ffc5587b954,0x7ffc5587b918']
  chrome.exe (6492) - ['C:\\b\\s\\w\\ir\\out\\Debug_x64\\chrome.exe', '--type=gpu-process', '--field-trial-handle=1716,8187182763927733711,5375165161402129955,131072', '--noerrdialogs', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmprqzvxo', '--start-stack-profiler', '--gpu-preferences=KAAAAAAAAACAAwBgAQAAAAAAAAAAAGAAAAAAAAAAAAAIAAAAAAAAACgAAAAEAAAAIAAAAAAAAAAoAAAAAAAAADAAAAAAAAAAOAAAAAAAAAAQAAAAAAAAAAAAAAAKAAAAEAAAAAAAAAAAAAAACwAAABAAAAAAAAAAAQAAAAoAAAAQAAAAAAAAAAEAAAALAAAA', '--noerrdialogs', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmprqzvxo', '--start-stack-profiler', '--service-request-channel-token=8784810521673194843', '--mojo-platform-channel-handle=1740', '--ignored= --type=renderer ', '/prefetch:2']
  chrome.exe (5864) - ['C:\\b\\s\\w\\ir\\out\\Debug_x64\\chrome.exe', '--type=gpu-process', '--field-trial-handle=1704,17196352589802212563,9219418618727199773,131072', '--noerrdialogs', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmpftwji6', '--start-stack-profiler', '--gpu-preferences=KAAAAAAAAACAAwBgAQAAAAAAAAAAAGAAAAAAAAAAAAAIAAAAAAAAACgAAAAEAAAAIAAAAAAAAAAoAAAAAAAAADAAAAAAAAAAOAAAAAAAAAAQAAAAAAAAAAAAAAAKAAAAEAAAAAAAAAAAAAAACwAAABAAAAAAAAAAAQAAAAoAAAAQAAAAAAAAAAEAAAALAAAA', '--noerrdialogs', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmpftwji6', '--start-stack-profiler', '--service-request-channel-token=17994297544122954107', '--mojo-platform-channel-handle=1732', '--ignored= --type=renderer ', '/prefetch:2']
  chrome.exe (6504) - ['C:\\b\\s\\w\\ir\\out\\Debug_x64\\chrome.exe', '--type=utility', '--field-trial-handle=1704,17196352589802212563,9219418618727199773,131072', '--lang=en-US', '--service-sandbox-type=audio', '--ignore-certificate-errors-spki-list=PhrPvGIaAMmd29hj8BCZOq096yj7uMpRNHpn5PDxI6I=', '--proxy-server=socks://localhost:50447', '--noerrdialogs', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmpftwji6', '--service-request-channel-token=15654418124543499361', '--mojo-platform-channel-handle=3824', '/prefetch:8']
  chrome.exe (6728) - ['C:\\b\\s\\w\\ir\\out\\Debug_x64\\chrome.exe', '--type=crashpad-handler', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmpftwji6', '/prefetch:7', '--monitor-self', '--monitor-self-argument=--type=crashpad-handler', '--monitor-self-argument=--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmpftwji6', '--monitor-self-argument=/prefetch:7', '--monitor-self-annotation=ptype=crashpad-handler', '--database=c:\\b\\s\\w\\ito_26gx\\tmppt2nhp', '--metrics-dir=c:\\b\\s\\w\\ito_26gx\\tmpftwji6', '--annotation=plat=Win64', '--annotation=prod=Chromium', '--annotation=ver=70.0.3512.0-devel', '--initial-client-data=0x21c,0x220,0x224,0x218,0x228,0x7ffc5587b948,0x7ffc5587b954,0x7ffc5587b918']
  chrome.exe (2676) - ['C:\\b\\s\\w\\ir\\out\\Debug_x64\\chrome.exe', '--type=crashpad-handler', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmprqzvxo', '/prefetch:7', '--no-periodic-tasks', '--monitor-self-annotation=ptype=crashpad-handler', '--database=c:\\b\\s\\w\\ito_26gx\\tmpe9zhga', '--annotation=plat=Win64', '--annotation=prod=Chromium', '--annotation=ver=70.0.3512.0-devel', '--initial-client-data=0x238,0x23c,0x240,0x234,0x230,0x7ff6011844d8,0x7ff6011844e4,0x7ff6011844a8']
  chrome.exe (3500) - ['C:\\b\\s\\w\\ir\\out\\Debug_x64\\chrome.exe', '--type=crashpad-handler', '--user-data-dir=c:\\b\\s\\w\\ito_26gx\\tmpftwji6', '/prefetch:7', '--no-periodic-tasks', '--monitor-self-annotation=ptype=crashpad-handler', '--database=c:\\b\\s\\w\\ito_26gx\\tmppt2nhp', '--annotation=plat=Win64', '--annotation=prod=Chromium', '--annotation=ver=70.0.3512.0-devel', '--initial-client-data=0x238,0x23c,0x240,0x234,0x244,0x7ff6011844d8,0x7ff6011844e4,0x7ff6011844a8']
  Chrome build location for win_AMD64 not found. Browser will be run without Flash.
  Traceback (most recent call last):
    File "C:\b\s\w\ir\third_party\catapult\telemetry\telemetry\testing\tab_test_case.py", line 25, in setUp
      self._RestartBrowser()
    File "C:\b\s\w\ir\third_party\catapult\telemetry\telemetry\testing\tab_test_case.py", line 45, in _RestartBrowser
      self._tab = self._browser.tabs[0]
    File "C:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\browser\tab_list.py", line 18, in __getitem__
      return self._tab_list_backend.__getitem__(index)
    File "C:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome_inspector\inspector_backend_list.py", line 62, in __getitem__
      index, repr(self._filtered_context_ids)))
  DevtoolsTargetCrashException: Web content with index 0 may have crashed. filtered_context_ids = []
  Found Minidump: False
  Stack Trace:
  ********************************************************************************
  	No crash dump found.
  ********************************************************************************
  Standard output:
  ********************************************************************************
  ********************************************************************************
  System log:
  (Not implemented)
[95/294] telemetry.internal.browser.tab_unittest.TabTest.testTabIsAlive queued


See:
https://chromium-swarm.appspot.com/task?id=3f180b928b6bab10&refresh=10&show_raw=1
 
Cc: perezju@chromium.org
Components: Speed>Telemetry
Labels: OS-Windows
Owner: nednguyen@chromium.org
Status: Assigned (was: Available)
See failing build at: 
https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Win10%20Tests%20x64%20%28dbg%29/2268

Setting at Pri 1, as this is happening roughly 50% of the time on continuous build.
Cc: kbr@chromium.org
This is an example failing log: https://chromium-swarm.appspot.com/task?id=3f1a4fe51a2ee110&refresh=10&show_raw=1


Almost all the error have the following stack trace:

  Traceback (most recent call last):
    File "C:\b\s\w\ir\third_party\catapult\telemetry\telemetry\testing\tab_test_case.py", line 20, in setUp
      self._browser.tabs.New()
    File "C:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\browser\tab_list.py", line 9, in New
      return self._tab_list_backend.New(timeout)
    File "C:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome\tab_list_backend.py", line 43, in New
      return self.GetBackendFromContextId(context_id)
    File "C:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome_inspector\inspector_backend_list.py", line 75, in GetBackendFromContextId
      context_id)
    File "C:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome_inspector\devtools_client_backend.py", line 599, in GetInspectorBackend
      raise KeyError('Cannot find a context with id=%s' % context_id)
  KeyError: u'Cannot find a context with id=95062EA58DD55095E41D8FF661AD4CB3'

Ken: this failure is very basic, thus will affect any Telemetry tests involve the browser. Do you also see this happening with gpu tests?
Sheriff here -- pinging this bug to keep it around the top of your inbox, this is still making roughly 50% of builds on Win10 Tests x64 (dbg) red:

https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Win10%20Tests%20x64%20%28dbg%29?limit=200
Cc: jbudorick@chromium.org
Will move this to experimental for now.
Project Member

Comment 7 by bugdroid1@chromium.org, Aug 6

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/bb6d7909ffa3840ce76fd03157c35dae2c035a5d

commit bb6d7909ffa3840ce76fd03157c35dae2c035a5d
Author: nednguyen <nednguyen@google.com>
Date: Mon Aug 06 15:00:28 2018

Set telemetry_unittests to be 100% experimental on 'Win10 Tests x64 (dbg)'

Bug: 870673
Change-Id: I024d5bcad65d4d714c38066c71fcca352d21fda9
Reviewed-on: https://chromium-review.googlesource.com/1163623
Commit-Queue: Ned Nguyen <nednguyen@google.com>
Reviewed-by: Nico Weber <thakis@chromium.org>
Cr-Commit-Position: refs/heads/master@{#580869}
[modify] https://crrev.com/bb6d7909ffa3840ce76fd03157c35dae2c035a5d/testing/buildbot/chromium.win.json
[modify] https://crrev.com/bb6d7909ffa3840ce76fd03157c35dae2c035a5d/testing/buildbot/test_suite_exceptions.pyl

Labels: -Pri-1 Pri-2
Reduce priority now that this suite is experimental
Labels: -Sheriff-Chromium
Thanks, removing from sheriff queue as we are no longer expecting to see this popping up in sheriffomatic.
Have not seen this behavior on the GPU bots:

https://ci.chromium.org/p/chromium/g/chromium.gpu/console
https://ci.chromium.org/p/chromium/g/chromium.gpu.fyi/console

Is there a potential regression range for this issue? Sounds like it could be a bug in the product, such as a DCHECK failing somewhere. The other redness on this bot makes it hard to understand where such a regression might have crept in.

Cc: st...@chromium.org
Shutao: can we kick off bisect to figure out when the flakiness crept in?
Cc: chanli@chromium.org
Unfortunately, I don't think telemetry-based tests are supported by Findit. We need some change on the test runner (and maybe Findit as well) according to our last meeting.
I don't like setting tests to experimental just because things have started to fail, it's too easy to forget about them, and it means that we're not actually figuring out why things have regressed.

Any thoughts on how we can not do that? :)
Do we have the a CQ builder that maps to "Win10 Tests x64 (dbg)"? If so, I might be able to run a BigQuery sql to check for recent flakes of telemetry_unittests step.
#13: I think this practice is similar to setting a test "FAIL", rather than "SKIP". This is a flake at suite level, hence setting it to experimental is our only option for now.
Re #14: dpranke@ confirmed that "Win10 Tests x64 (dbg)" has no CQ builder.
Cc: nednguyen@chromium.org
 Issue 873538  has been merged into this issue.
Also seeing this on Win7 Tests (dbg)(1)

https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Win7%20Tests%20%28dbg%29%281%29

But they are marked as experimental there as well, so not blocking.
Cc: crouleau@chromium.org
Labels: Type-Bug
+caleb in case this is in the domain of stuff he's looking at these days. Looks like things just run too slowly on x64 dbg.

Comment 20 by benhenry@google.com, Jan 16 (6 days ago)

Components: Test>Telemetry

Comment 21 by benhenry@google.com, Jan 16 (6 days ago)

Components: -Speed>Telemetry

Sign in to add a comment