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

Issue 784025 link

Starred by 2 users

Issue metadata

Status: Started
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 1
Type: Bug-Regression



Sign in to add a comment

telemetry_perf_unittests speedometer2-future flaky timeout on win7_chromium_rel_ng

Project Member Reported by ynovikov@chromium.org, Nov 11 2017

Issue description

https://build.chromium.org/p/tryserver.chromium.win/builders/win7_chromium_rel_ng/builds/41148
https://build.chromium.org/p/tryserver.chromium.win/builders/win7_chromium_rel_ng/builds/41166
https://build.chromium.org/p/tryserver.chromium.win/builders/win7_chromium_rel_ng/builds/41199

[25/25] benchmarks.benchmark_smoke_unittest.BenchmarkSmokeTest.speedometer2-future failed unexpectedly 630.1390s:
  [ RUN      ] Speedometer2
  Traceback (most recent call last):
    File "e:\b\swarm_slave\w\ir\third_party\catapult\telemetry\telemetry\internal\story_runner.py", line 105, in _RunStoryAndProcessErrorIfNeeded
      state.RunStory(results)
    File "e:\b\swarm_slave\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 52, in traced_function
      return func(*args, **kwargs)
    File "e:\b\swarm_slave\w\ir\third_party\catapult\telemetry\telemetry\page\shared_page_state.py", line 334, in RunStory
      self._current_page, self._current_tab, results)
    File "e:\b\swarm_slave\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 52, in traced_function
      return func(*args, **kwargs)
    File "e:\b\swarm_slave\w\ir\tools\perf\benchmarks\speedometer2.py", line 64, in ValidateAndMeasurePage
      tab.WaitForJavaScriptCondition('testDone', timeout=600)
    File "e:\b\swarm_slave\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 52, in traced_function
      return func(*args, **kwargs)
    File "e:\b\swarm_slave\w\ir\third_party\catapult\telemetry\telemetry\internal\browser\web_contents.py", line 239, in WaitForJavaScriptCondition
      return self._inspector_backend.WaitForJavaScriptCondition(*args, **kwargs)
    File "e:\b\swarm_slave\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 52, in traced_function
      return func(*args, **kwargs)
    File "e:\b\swarm_slave\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome_inspector\inspector_backend.py", line 302, in WaitForJavaScriptCondition
      e.message + '\n' + debug_message)
  TimeoutException: Timed out while waiting 600s for IsJavaScriptExpressionTrue.

Failed to delete e:\b\swarm_slave\w\ir (18 files remaining).
  Maybe the test has a subprocess outliving it.
  Sleeping 2 seconds.
Failed to delete e:\b\swarm_slave\w\ir (18 files remaining).
  Maybe the test has a subprocess outliving it.
  Sleeping 4 seconds.
Failed to delete e:\b\swarm_slave\w\ir. The following files remain:
- \\?\e:\b\swarm_slave\w\ir
- \\?\e:\b\swarm_slave\w\ir\out
- \\?\e:\b\swarm_slave\w\ir\out\Release
- \\?\e:\b\swarm_slave\w\ir\out\Release\chrome.dll
- \\?\e:\b\swarm_slave\w\ir\out\Release\chrome.exe
- \\?\e:\b\swarm_slave\w\ir\out\Release\chrome_100_percent.pak
- \\?\e:\b\swarm_slave\w\ir\out\Release\chrome_child.dll
- \\?\e:\b\swarm_slave\w\ir\out\Release\chrome_elf.dll
- \\?\e:\b\swarm_slave\w\ir\out\Release\d3dcompiler_47.dll
- \\?\e:\b\swarm_slave\w\ir\out\Release\icudtl.dat
- \\?\e:\b\swarm_slave\w\ir\out\Release\locales
- \\?\e:\b\swarm_slave\w\ir\out\Release\locales\en-US.pak
- \\?\e:\b\swarm_slave\w\ir\out\Release\natives_blob.bin
- \\?\e:\b\swarm_slave\w\ir\out\Release\resources.pak
- \\?\e:\b\swarm_slave\w\ir\out\Release\snapshot_blob.bin
- \\?\e:\b\swarm_slave\w\ir\out\Release\swiftshader
- \\?\e:\b\swarm_slave\w\ir\out\Release\swiftshader\libEGL.dll
- \\?\e:\b\swarm_slave\w\ir\out\Release\swiftshader\libGLESv2.dll

Terminating 4 processes:
- 840 killed
- 3220 killed
- 5864 killed
- 5980 killed
*** Swarming tried multiple times to delete the run directory and failed ***
*** Hard failing the task ***

 
Cc: -nednguyen@chromium.org nedngu...@google.com
Owner: hablich@chromium.org
Assign to Hablich@ for triaging. Otherwise we will need to disable Speedometer2 on win
Cc: hablich@chromium.org
Components: Infra>Client>V8
Owner: ----
That looks like some hanging process? Whats up with all the files that can't be deleted?
hablich: the actual crash stack is this:

Traceback (most recent call last):
    File "e:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\story_runner.py", line 105, in _RunStoryAndProcessErrorIfNeeded
      state.RunStory(results)
    File "e:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 52, in traced_function
      return func(*args, **kwargs)
    File "e:\b\s\w\ir\third_party\catapult\telemetry\telemetry\page\shared_page_state.py", line 334, in RunStory
      self._current_page, self._current_tab, results)
    File "e:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 52, in traced_function
      return func(*args, **kwargs)
    File "e:\b\s\w\ir\tools\perf\benchmarks\speedometer2.py", line 64, in ValidateAndMeasurePage
      tab.WaitForJavaScriptCondition('testDone', timeout=600)
    File "e:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 52, in traced_function
      return func(*args, **kwargs)
    File "e:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\browser\web_contents.py", line 239, in WaitForJavaScriptCondition
      return self._inspector_backend.WaitForJavaScriptCondition(*args, **kwargs)
    File "e:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 52, in traced_function
      return func(*args, **kwargs)
    File "e:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome_inspector\inspector_backend.py", line 302, in WaitForJavaScriptCondition
      e.message + '\n' + debug_message)
  TimeoutException: Timed out while waiting 600s for IsJavaScriptExpressionTrue.
  Console output:
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: Ember  : 2.6.2
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: jQuery : 2.2.4
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: -------------------------------
  (debug) http://127.0.0.1:58824/resources/todomvc/architecture-examples/emberjs-debug/assets/vendor.js:16649: DEBUG: For more advanced debugging, install the Ember Inspector from https://chrome.google.com/webstore/detail/ember-inspector/bmdblncegkenkacieihfhpjfppoconhi
  
  
  [  FAILED  ] Speedometer2 (618703 ms)
  [  PASSED  ] 0 tests.
  [  FAILED  ] 1 test, listed below:
  [  FAILED  ]  Speedometer2
  
  1 FAILED TEST
  

Cc: bmeu...@chromium.org
Components: -Infra>Client>V8 Blink>JavaScript
Not V8 side infrastructure. Either this is V8 engine or Chrome's infra.

+ V8 perf sheriff for further triage.
I don't have a Windows dev machine so I can't reproduce. I dug a little bit deeper in the data we already have though:

1.) This error seems to be widespread and unresolved: https://bugs.chromium.org/p/chromium/issues/list?can=1&q=Timed+out+while+waiting+600s+for+IsJavaScriptExpressionTrue&colspec=ID+Pri+M+Stars+ReleaseBlock+Component+Status+Owner+Summary+OS+Modified&x=m&y=releaseblock&cells=ids

2.) It is timing based which either means the hardware degraded and suddenly 600 seconds are not enough anymore (I doubt that) or some relevant timing changes on the Blink side happened. Ned, where do I find a graph to see when this flakyness started? Is this also happening on the non-try server perf bots?
Owner: nedngu...@google.com
Status: Assigned (was: Untriaged)
Owner: hablich@chromium.org
Time out while waiting 600s for IsJavascriptExpressionTrue just means the test timed out, so this is one the test timed out while waiting for  test to finish (see the stack       "tab.WaitForJavaScriptCondition('testDone', timeout=600)"). No surprise that this is the most popular failure stack in Telemetry tests.

2) Flakiness graph: https://test-results.appspot.com/dashboards/flakiness_dashboard.html#testType=telemetry_perf_unittests&showAllRuns=true&tests=benchmarks%2Fbenchmark_smoke_unittest%2FBenchmarkSmokeTest%2Fspeedometer2-future
Note that when the test passes, it takes much less than 600s.
Here for example:
https://ci.chromium.org/buildbot/tryserver.chromium.win/win7_chromium_rel_ng/49414
[26/26] benchmarks.benchmark_smoke_unittest.BenchmarkSmokeTest.speedometer2-future passed 356.2680s:
  [ RUN      ] Speedometer2
  [       OK ] Speedometer2 (355004 ms)
  [  PASSED  ] 1 test.

So this is not an issue of slowness or hardware. Look to me like it randomly hangs for some reason, because of the failure to kill processes and cleanup.
Re #9: Thanks, interesting link. It shows speedometer2-future though and it seems I can't force it to show speedometer2 instead.

Re #10: Yes, my current hunch is that something regarding event timing/startup changed on the blink side. This happened in the past too. That is the reason why I am looking for a way to isolate the problem better.
Still timing out:
https://ci.chromium.org/buildbot/tryserver.chromium.win/win7_chromium_rel_ng/70469

How come a test flake on a CQ trybot was not addressed in 40 days?
Cc: hpayer@chromium.org
Summary: telemetry_perf_unittests speedometer2-future flaky timeout on win7_chromium_rel_ng (was: telemetry_perf_unittests Speedometer2 flaky timeout on win7_chromium_rel_ng)
I am disabling it
Project Member

Comment 15 by bugdroid1@chromium.org, Dec 22 2017

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

commit 8d8c1d9539951918a1e991364af95ca8d9b2c7c7
Author: Ned Nguyen <nednguyen@google.com>
Date: Fri Dec 22 12:35:48 2017

Disable speedometer2-future on win

NOTRY=true
TBR=hablich@chromium.org

Bug: 784025
Change-Id: Ia5e151c334493d5286fa0c3982e2c93d72c65da0
Reviewed-on: https://chromium-review.googlesource.com/842303
Reviewed-by: Ned Nguyen <nednguyen@google.com>
Commit-Queue: Ned Nguyen <nednguyen@google.com>
Cr-Commit-Position: refs/heads/master@{#525979}
[modify] https://crrev.com/8d8c1d9539951918a1e991364af95ca8d9b2c7c7/tools/perf/expectations.config

Project Member

Comment 16 by bugdroid1@chromium.org, Feb 27 2018

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

commit 3b9005303e48fe88951a0c567d61199f37de8af0
Author: Michael Hablich <hablich@chromium.org>
Date: Tue Feb 27 09:25:33 2018

Enable Speedometer2-future on Linux and Windows

R=nednguyen@google.com

Bug: 792495, 784025
Change-Id: I05345c81f31b30418eb0bf76da1e2c52f0dc0f54
Reviewed-on: https://chromium-review.googlesource.com/937519
Reviewed-by: Ned Nguyen <nednguyen@google.com>
Commit-Queue: Michael Hablich <hablich@chromium.org>
Cr-Commit-Position: refs/heads/master@{#539414}
[modify] https://crrev.com/3b9005303e48fe88951a0c567d61199f37de8af0/tools/perf/expectations.config

Status: Fixed (was: Assigned)
Status: Started (was: Fixed)
This is still timed out ( issue 816913 )
Cc: nednguyen@chromium.org
 Issue 816913  has been merged into this issue.
Project Member

Comment 20 by bugdroid1@chromium.org, Feb 28 2018

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

commit e4d7f86853d4638c20c138a9b83fd6cfb7b56679
Author: Ned Nguyen <nednguyen@google.com>
Date: Wed Feb 28 01:59:20 2018

Revert "Enable Speedometer2-future on Linux and Windows"

This reverts commit 3b9005303e48fe88951a0c567d61199f37de8af0.

Reason for revert: still timeout ( crbug.com/816913 )

Original change's description:
> Enable Speedometer2-future on Linux and Windows
> 
> R=​nednguyen@google.com
> 
> Bug: 792495, 784025
> Change-Id: I05345c81f31b30418eb0bf76da1e2c52f0dc0f54
> Reviewed-on: https://chromium-review.googlesource.com/937519
> Reviewed-by: Ned Nguyen <nednguyen@google.com>
> Commit-Queue: Michael Hablich <hablich@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#539414}

TBR=hablich@chromium.org,nednguyen@google.com

Change-Id: Iebde8e94b22c1df80871ffcb00f46b444a0a7e86
No-Presubmit: true
No-Tree-Checks: true
No-Try: true
Bug: 792495, 784025
Reviewed-on: https://chromium-review.googlesource.com/940362
Reviewed-by: Ned Nguyen <nednguyen@google.com>
Commit-Queue: Ned Nguyen <nednguyen@google.com>
Cr-Commit-Position: refs/heads/master@{#539648}
[modify] https://crrev.com/e4d7f86853d4638c20c138a9b83fd6cfb7b56679/tools/perf/expectations.config

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

Components: Test>Telemetry

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

Components: -Tests>Telemetry

Sign in to add a comment