1132783 - Intermittent browser_animation_play_pause_button.js,browser_animation_playerWidgets_disables_on_finished.js,browser_animation_toggle_button_resets_on_navigate.js | Test timed out

Status: RESOLVED FIXED

(DevTools :: Inspector, defect)

Description

[Ryan VanderMeulen [:RyanVM]]

Calling this a regression from bug 1129454 given the timing.

15:41:07 INFO - 20 INFO TEST-START | browser/devtools/animationinspector/test/browser_animation_play_pause_button.js
15:41:21 INFO - 1423784481117 Browser.Experiments.Experiments TRACE Experiments #0::enabled=true, true
15:41:21 INFO - 1423784481124 Browser.Experiments.Experiments TRACE Experiments #0::Registering instance with Addon Manager.
15:41:21 INFO - 1423784481125 Browser.Experiments.Experiments TRACE Experiments #0::Registering previous experiment add-on provider.
15:41:21 INFO - 1423784481127 Browser.Experiments.Experiments TRACE PreviousExperimentProvider #0::startup()
15:41:21 INFO - 1423784481129 Browser.Experiments.Experiments TRACE Experiments #0::_loadFromCache
15:41:21 INFO - 1423784481149 Browser.Experiments.Experiments TRACE Experiments #0::_loadTask finished ok
15:41:21 INFO - 1423784481150 Browser.Experiments.Experiments TRACE Experiments #0::_run
15:41:21 INFO - 1423784481154 Browser.Experiments.Experiments TRACE Experiments #0::_main iteration
15:41:21 INFO - 1423784481155 Browser.Experiments.Experiments TRACE Experiments #0::_evaluateExperiments
15:41:21 INFO - 1423784481160 Browser.Experiments.Experiments TRACE Experiments #0::_main finished, scheduling next run
15:42:37 INFO - Xlib: extension "RANDR" missing on display ":0".
15:42:39 INFO - TEST-INFO | screentopng: exit 0
15:42:39 INFO - 21 INFO checking window state
15:42:39 INFO - 22 INFO Console message: [JavaScript Warning: "unsafe CPOW usage" {file: "resource://app/modules/sessionstore/TabState.jsm" line: 96}]
15:42:39 INFO - 23 INFO Console message: [JavaScript Warning: "unsafe CPOW usage" {file: "resource://app/modules/sessionstore/TabState.jsm" line: 96}]
15:42:39 INFO - 24 INFO Console message: [JavaScript Warning: "unsafe CPOW usage" {file: "resource://app/modules/sessionstore/TabState.jsm" line: 96}]
15:42:39 INFO - 25 INFO Console message: [JavaScript Warning: "unsafe CPOW usage" {file: "resource://app/modules/sessionstore/TabState.jsm" line: 96}]
15:42:39 INFO - 26 INFO Entering test
15:42:39 INFO - 27 INFO Adding a new tab with URL: 'http://example.com/browser/browser/devtools/animationinspector/test/doc_simple_animation.html'
15:42:39 INFO - 28 INFO Loading the helper frame script chrome://mochitests/content/browser/browser/devtools/animationinspector/test/doc_frame_script.js
15:42:39 INFO - 29 INFO Loading the helper frame script chrome://browser/content/devtools/frame-script-utils.js
15:42:39 INFO - 30 INFO URL 'http://example.com/browser/browser/devtools/animationinspector/test/doc_simple_animation.html' loading complete
15:42:39 INFO - 31 INFO Opening the toolbox with the inspector selected
15:42:39 INFO - 32 INFO Making sure that the toolbox's frame is focused
15:42:39 INFO - 33 INFO Switching to the animationinspector
15:42:39 INFO - 34 INFO Waiting for the inspector and sidebar to be ready
15:42:39 INFO - 35 INFO Console message: 1423784481117 Browser.Experiments.Experiments TRACE Experiments #0::enabled=true, true
15:42:39 INFO - 36 INFO Console message: 1423784481124 Browser.Experiments.Experiments TRACE Experiments #0::Registering instance with Addon Manager.
15:42:39 INFO - 37 INFO Console message: 1423784481125 Browser.Experiments.Experiments TRACE Experiments #0::Registering previous experiment add-on provider.
15:42:39 INFO - 38 INFO Console message: 1423784481127 Browser.Experiments.Experiments TRACE PreviousExperimentProvider #0::startup()
15:42:39 INFO - 39 INFO Console message: 1423784481129 Browser.Experiments.Experiments TRACE Experiments #0::_loadFromCache
15:42:39 INFO - 40 INFO Console message: 1423784481149 Browser.Experiments.Experiments TRACE Experiments #0::_loadTask finished ok
15:42:39 INFO - 41 INFO Console message: 1423784481150 Browser.Experiments.Experiments TRACE Experiments #0::_run
15:42:39 INFO - 42 INFO Console message: 1423784481154 Browser.Experiments.Experiments TRACE Experiments #0::_main iteration
15:42:39 INFO - 43 INFO Console message: 1423784481155 Browser.Experiments.Experiments TRACE Experiments #0::_evaluateExperiments
15:42:39 INFO - 44 INFO Console message: 1423784481160 Browser.Experiments.Experiments TRACE Experiments #0::_main finished, scheduling next run
15:42:39 INFO - 45 INFO Console message: 1423784512514 Services.HealthReport.HealthReporter WARN Saved state file does not exist.
15:42:39 INFO - 46 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_play_pause_button.js | Test timed out - expected PASS
15:42:39 INFO - 47 INFO MEMORY STAT vsize after test: 599289856
15:42:39 INFO - 48 INFO MEMORY STAT residentFast after test: 149651456
15:42:39 INFO - 49 INFO MEMORY STAT heapAllocated after test: 52621532
15:42:39 INFO - 50 INFO TEST-OK | browser/devtools/animationinspector/test/browser_animation_play_pause_button.js | took 91038ms

Comment 1

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=1986085
repository: fx-team
start_time: 2015-02-12T15:38:26
who: rvandermeulen[at]mozilla[dot]com
machine: tst-linux32-spot-762
buildname: Ubuntu VM 12.04 fx-team opt test mochitest-e10s-devtools-chrome
revision: 2c97566c3cb7

46 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_play_pause_button.js | Test timed out - expected PASS

Comment 2

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=1030817
repository: mozilla-central
start_time: 2015-02-12T18:01:04
who: rvandermeulen[at]mozilla[dot]com
machine: tst-linux32-spot-304
buildname: Ubuntu VM 12.04 mozilla-central pgo test mochitest-e10s-devtools-chrome
revision: 2f5c5ec1a24b

52 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_playerWidgets_disables_on_finished.js | Test timed out - expected PASS

Comment 3

[Patrick Brosset <:pbro>]

This is definitely a regression from bug 1129454 where I changed the way that tests wait for the animation panel to be initialized (function openAnimationInspector in browser/devtools/animationinspector/test/head.js).
I'll take a look at this now.

Comment 5

[Patrick Brosset <:pbro>]

Since this is a bug with the init sequence of the animationinspector tests, any of the tests in the folder can basically intermittently fail now ...

Comment 6

[Patrick Brosset <:pbro>]

Pushed a patch with a change to the test init sequence to try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=6fe9d330bf32

Comment 7

[Patrick Brosset <:pbro>]

Attachment: bug1132783-intermittent-animation-tests.patch

Brian, this change to head.js was made to avoid animation tests from failing intermittently with e10s.
The animation tab init sequence goes like this:
- the sidebar panel is created (and the inner iframe is added and loaded)
- the sidebar widget calls the global 'setPanel' function on the window object in the iframe, without waiting for it to end (it doesn't care about the return value being a promise)
- that starts the AnimationsController init
- and once done, the AnimationsPanel init is done too.

The function in head.js used to just wait for an event that is emitted at the end of the AnimationsPanel init function execution. But it turns out that, with e10s, the event has already been emitted by the time we listen to it in the test.

So the simple fix was: either use the 'AnimationsPanel.initialized' promise when it exists (meaning that the init has already started or even maybe finished) or subscribe to the event.

This should be enough to cover all cases, and the try push I linked to above seems to confirm this.

Comment 8

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=1031833
repository: mozilla-central
start_time: 2015-02-13T05:03:02
who: tomcat[at]mozilla[dot]com
machine: tst-linux64-spot-379
buildname: Ubuntu VM 12.04 x64 mozilla-central pgo test mochitest-e10s-devtools-chrome
revision: 2f5c5ec1a24b

60 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_toggle_button_resets_on_navigate.js | Test timed out - expected PASS

Comment 9

[Brian Grinstead [:bgrins]]

Comment on attachment 8564111 [details] [diff] [review]
bug1132783-intermittent-animation-tests.patch

Review of attachment 8564111 [details] [diff] [review]:
-----------------------------------------------------------------

Sounds good

Comment 10

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=1992438
repository: fx-team
start_time: 2015-02-13T08:08:17
who: rvandermeulen[at]mozilla[dot]com
machine: tst-linux64-spot-256
buildname: Ubuntu VM 12.04 x64 fx-team opt test mochitest-e10s-devtools-chrome
revision: d0b991fa0471

45 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_participate_in_inspector_update.js | Test timed out - expected PASS

Comment 11

[Ryan VanderMeulen [:RyanVM]]

Patrick, you're AFK on IRC, so I went ahead and landed this for you given the frequency and widespread nature of the failures. Hopefully you don't mind :)
https://hg.mozilla.org/integration/fx-team/rev/248aac04b9d8

Comment 12

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=1992625
repository: fx-team
start_time: 2015-02-13T09:51:20
who: rvandermeulen[at]mozilla[dot]com
machine: tst-linux64-spot-192
buildname: Ubuntu VM 12.04 x64 fx-team opt test mochitest-e10s-devtools-chrome
revision: b40d31806495

52 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_playerWidgets_destroy.js | Test timed out - expected PASS

Comment 13

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=6607784
repository: mozilla-inbound
start_time: 2015-02-13T13:37:17
who: wkocher[at]mozilla[dot]com
machine: tst-linux64-spot-295
buildname: Ubuntu VM 12.04 x64 mozilla-inbound opt test mochitest-e10s-devtools-chrome
revision: 6f06821072ef

Traceback (most recent call last):
45 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_play_pause_button.js | Test timed out - expected PASS

Comment 14

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=6610135
repository: mozilla-inbound
start_time: 2015-02-13T15:46:39
who: rvandermeulen[at]mozilla[dot]com
machine: tst-linux64-spot-949
buildname: Ubuntu VM 12.04 x64 mozilla-inbound opt test mochitest-e10s-devtools-chrome
revision: 16df4e462d80

67 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_toolbar_exists.js | Test timed out - expected PASS

Comment 15

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=6610316
repository: mozilla-inbound
start_time: 2015-02-13T15:57:41
who: rvandermeulen[at]mozilla[dot]com
machine: tst-linux64-spot-282
buildname: Ubuntu VM 12.04 x64 mozilla-inbound opt test mochitest-e10s-devtools-chrome
revision: 16df4e462d80

43 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_participate_in_inspector_update.js | Test timed out - expected PASS

Comment 16

[Patrick Brosset <:pbro>]

(In reply to Ryan VanderMeulen [:RyanVM UTC-5] from comment #11)
> Patrick, you're AFK on IRC, so I went ahead and landed this for you given
> the frequency and widespread nature of the failures. Hopefully you don't
> mind :)
> https://hg.mozilla.org/integration/fx-team/rev/248aac04b9d8
Thanks!

Comment 17

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=6622918
repository: mozilla-inbound
start_time: 2015-02-14T00:32:49
who: nigelbabu[at]gmail[dot]com
machine: tst-linux32-spot-430
buildname: Ubuntu VM 12.04 mozilla-inbound pgo test mochitest-e10s-devtools-chrome
revision: 9507662057de

52 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_playerWidgets_disables_on_finished.js | Test timed out - expected PASS

Comment 18

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=6617531
repository: mozilla-inbound
start_time: 2015-02-13T19:03:22
who: nigelbabu[at]gmail[dot]com
machine: tst-linux64-spot-276
buildname: Ubuntu VM 12.04 x64 mozilla-inbound opt test mochitest-e10s-devtools-chrome
revision: 332dbc5e0d1a

52 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_playerWidgets_disables_on_finished.js | Test timed out - expected PASS

Comment 19

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=6611158
repository: mozilla-inbound
start_time: 2015-02-13T16:58:41
who: tomcat[at]mozilla[dot]com
machine: tst-linux64-spot-729
buildname: Ubuntu VM 12.04 x64 mozilla-inbound opt test mochitest-e10s-devtools-chrome
revision: 95f5dfa2292e

45 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_play_pause_button.js | Test timed out - expected PASS

Comment 20

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=6610770
repository: mozilla-inbound
start_time: 2015-02-13T16:48:23
who: tomcat[at]mozilla[dot]com
machine: tst-linux64-spot-725
buildname: Ubuntu VM 12.04 x64 mozilla-inbound opt test mochitest-e10s-devtools-chrome
revision: 1dd9353d0e97

52 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_playerWidgets_disables_on_finished.js | Test timed out - expected PASS

Comment 21

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/248aac04b9d8

Comment 22

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=2171218
repository: fx-team
start_time: 2015-03-05T21:40:11
who: tomcat[at]mozilla[dot]com
machine: tst-linux64-spot-825
buildname: Ubuntu VM 12.04 x64 fx-team pgo test mochitest-e10s-devtools-chrome
revision: 5fcb418e9aa9

44 INFO TEST-UNEXPECTED-FAIL | browser/devtools/animationinspector/test/browser_animation_playerWidgets_disables_on_finished.js | Uncaught exception - expected PASS