Closed Bug 1292233 Opened 8 years ago Closed 8 years ago

Intermittent devtools/client/animationinspector/test/browser_animation_spacebar_toggles_animations.js | This test exceeded the timeout threshold. It should be rewritten or split up.

Categories

(DevTools :: Inspector: Animations, defect, P1)

defect

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1313187

People

(Reporter: intermittent-bug-filer, Assigned: gbrown)

References

Details

(Keywords: intermittent-failure)

Low frequency intermittent -> P3.

Inspector bug triage, filter on CLIMBING SHOES.
Priority: -- → P3
Almost all of these timeout failures occur on Linux64-asan and in mochitest-dt-e10s. Successful runs on Linux64-opt/debug/pgo run in < 5 seconds; successful runs on Linux64-asan often complete in 40 to 45 seconds:

INFO TEST-OK | devtools/client/animationinspector/test/browser_animation_spacebar_toggles_animations.js | took 40249ms
as of the time of this comment, this bug is the #7 intermittent orange- it seemed to get works on Oct 12th for a couple days, then again on Oct 16th.  I suspect something landed on October 12th, was backed out, then landed again on the 16th (data could be off by up to 24 hours from actual landing times).  

:jlongster, can you determine if there is anyone else that could work on Inspector bugs and look into this either this week or next?  If not, possibly make sure that this gets on the radar with a higher priority?
Flags: needinfo?(jlong)
I can answer this for the inspector, so clearing James' needinfo.

This test is really simple and doesn't fail. It only happens to take a little bit too much time on linux asan builds (as comment 11 suggests).
I've seen this happen this past week on a few various intermittent test bugs, I wonder if this is something temporary that will go away?

In the case of this test, there's really no way for us to make the test run faster, it's already very simple and runs on other builds very quickly.
The only thing we can do at this stage is either disable it on linux-asan, or use requestLongerTimeout(2).

I'm a little bit uncomfortable with doing this though, because this is just moving the problem somewhere else. Is there a way to know why tests take so much longer on this platform than on others?
Flags: needinfo?(jlong)
Priority: P3 → P1
See Also: → 1297575
There is some info on asan at https://developer.mozilla.org/en-US/docs/Mozilla/Testing/Firefox_and_Address_Sanitizer, but that doesn't seem terribly helpful here.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=a0400e44e95f6c4eca1194bcf9ecaf24e31b5886 has this test running with requestCompleteLog(), to get a better sense of timing. This log seems typical:

https://public-artifacts.taskcluster.net/aj9J-TyvSvCoqA3ZxWqQNw/0/public/logs/live_backing.log

[task 2016-10-25T22:34:36.897065Z] 22:34:36     INFO -  35 INFO TEST-OK | devtools/client/animationinspector/test/browser_animation_shows_player_on_valid_node.js | took 41562ms
[task 2016-10-25T22:34:37.178913Z] 22:34:37     INFO -  36 INFO TEST-START | devtools/client/animationinspector/test/browser_animation_spacebar_toggles_animations.js
[task 2016-10-25T22:34:37.351905Z] 22:34:37     INFO -  37 INFO Entering test bound
[task 2016-10-25T22:34:37.433370Z] 22:34:37     INFO -  38 INFO Adding a new tab with URL: http://example.com/browser/devtools/client/animationinspector/test/doc_simple_animation.html
[task 2016-10-25T22:34:38.116641Z] 22:34:38     INFO -  39 INFO Tab added and finished loading
[task 2016-10-25T22:34:38.118644Z] 22:34:38     INFO -  40 INFO Loading the helper frame script chrome://mochitests/content/browser/devtools/client/animationinspector/test/doc_frame_script.js
[task 2016-10-25T22:34:38.135291Z] 22:34:38     INFO -  41 INFO Loading the helper frame script chrome://devtools/content/shared/frame-script-utils.js
[task 2016-10-25T22:34:38.151463Z] 22:34:38     INFO -  42 INFO Opening the inspector
[task 2016-10-25T22:34:38.172430Z] 22:34:38     INFO -  43 INFO Opening the toolbox
[task 2016-10-25T22:35:04.792486Z] 22:35:04     INFO -  44 INFO Toolbox opened and focused
[task 2016-10-25T22:35:04.813342Z] 22:35:04     INFO -  45 INFO Waiting for actor features to be detected
[task 2016-10-25T22:35:07.920619Z] 22:35:07     INFO -  46 INFO Selecting the animationinspector sidebar
[task 2016-10-25T22:35:08.525833Z] 22:35:08     INFO -  47 INFO Waiting for the inspector and sidebar to be ready
[task 2016-10-25T22:35:14.362712Z] 22:35:14     INFO -  48 INFO Waiting for the animation controller and panel to be ready
[task 2016-10-25T22:35:14.427287Z] 22:35:14     INFO -  49 INFO Selecting the node for '.still'
[task 2016-10-25T22:35:17.321322Z] 22:35:17     INFO -  50 INFO Simulate spacebar stroke and check toggleAll button is in paused state
[task 2016-10-25T22:35:17.329093Z] 22:35:17     INFO -  51 INFO Waiting for event: 'all-animations-toggled' on [object Object].
[task 2016-10-25T22:35:18.002905Z] 22:35:18     INFO -  52 INFO Console message: [JavaScript Warning: "Key event not available on some keyboard layouts: key=“r†modifiers=“accel,alt†id=“toggleReaderModeâ€" {file: "chrome://mochikit/content/tests/SimpleTest/EventUtils.js" line: 776}]
[task 2016-10-25T22:35:18.005224Z] 22:35:18     INFO -  53 INFO Console message: [JavaScript Warning: "Key event not available on some keyboard layouts: key=“i†modifiers=“accel,alt,shift†id=“key_browserToolboxâ€" {file: "chrome://mochikit/content/tests/SimpleTest/EventUtils.js" line: 776}]
[task 2016-10-25T22:35:18.195290Z] 22:35:18     INFO -  54 INFO Got event: 'all-animations-toggled' on [object Object].
[task 2016-10-25T22:35:18.214745Z] 22:35:18     INFO -  55 INFO TEST-PASS | devtools/client/animationinspector/test/browser_animation_spacebar_toggles_animations.js | The toggle all button is in its paused state -
[task 2016-10-25T22:35:18.215088Z] 22:35:18     INFO -  56 INFO Simulate spacebar stroke and check toggleAll button is in playing state
[task 2016-10-25T22:35:18.215381Z] 22:35:18     INFO -  57 INFO Waiting for event: 'all-animations-toggled' on [object Object].
[task 2016-10-25T22:35:18.418845Z] 22:35:18     INFO -  58 INFO Got event: 'all-animations-toggled' on [object Object].
[task 2016-10-25T22:35:18.436633Z] 22:35:18     INFO -  59 INFO TEST-PASS | devtools/client/animationinspector/test/browser_animation_spacebar_toggles_animations.js | The toggle all button is in its playing state again -
[task 2016-10-25T22:35:18.452669Z] 22:35:18     INFO -  60 INFO Leaving test bound
[task 2016-10-25T22:35:21.957296Z] 22:35:21     INFO -  61 INFO Removing tab.
[task 2016-10-25T22:35:21.976424Z] 22:35:21     INFO -  62 INFO Waiting for event: 'TabClose' on [object XULElement].
[task 2016-10-25T22:35:22.195363Z] 22:35:22     INFO -  63 INFO Got event: 'TabClose' on [object XULElement].
[task 2016-10-25T22:35:22.622134Z] 22:35:22     INFO -  64 INFO Tab removed and finished closing
[task 2016-10-25T22:35:22.959585Z] 22:35:22     INFO -  MEMORY STAT | vsize 20972879MB | residentFast 770MB
[task 2016-10-25T22:35:22.960030Z] 22:35:22     INFO -  65 INFO TEST-OK | devtools/client/animationinspector/test/browser_animation_spacebar_toggles_animations.js | took 45786ms

Several things are "slow", but by far the most time seems to go to "opening the toolbox":

[task 2016-10-25T22:34:38.172430Z] 22:34:38     INFO -  43 INFO Opening the toolbox
[task 2016-10-25T22:35:04.792486Z] 22:35:04     INFO -  44 INFO Toolbox opened and focused

I don't know if that's helpful.


Bug 1297575 is another intermittent test timeout on asan only; I'm trying to find a better solution than requestLongerTimeout() there, but that is the most obvious way forward for these right now.
Depends on: 1313187
Assignee: nobody → gbrown
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → DUPLICATE
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.