1475441 - Intermittent devtools/client/inspector/animation/test/browser_animation_rewind-button.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort.

Reporter

Description

•

6 years ago

treeherder

Filed by: toros [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=187939237&repo=mozilla-central

https://queue.taskcluster.net/v1/task/FtIX8B6HQVOMLX72YHM0Rg/runs/0/artifacts/public/logs/live_backing.log

23:49:19     INFO -  17 INFO TEST-PASS | devtools/client/inspector/animation/test/browser_animation_rewind-button.js | Rewind button should exist -
23:49:19     INFO -  18 INFO Checking rewind button makes animations to rewind to zero
23:49:19     INFO -  19 INFO Click on rewind button
23:49:19     INFO -  Buffered messages logged at 23:48:45
23:49:19     INFO -  20 INFO TEST-PASS | devtools/client/inspector/animation/test/browser_animation_rewind-button.js | Current time of animations should be 0 -
23:49:19     INFO -  21 INFO TEST-PASS | devtools/client/inspector/animation/test/browser_animation_rewind-button.js | All animations should be paused -
23:49:19     INFO -  22 INFO Checking rewind button makes animations after clicking scrubber
23:49:19     INFO -  23 INFO Click 61.5 on scrubber controller
23:49:19     INFO -  Buffered messages logged at 23:48:58
23:49:19     INFO -  24 INFO Click on rewind button
23:49:19     INFO -  Buffered messages logged at 23:49:09
23:49:19     INFO -  25 INFO TEST-PASS | devtools/client/inspector/animation/test/browser_animation_rewind-button.js | Current time of animations should be 0 -
23:49:19     INFO -  26 INFO TEST-PASS | devtools/client/inspector/animation/test/browser_animation_rewind-button.js | All animations should be paused -
23:49:19     INFO -  27 INFO Leaving test bound
23:49:19     INFO -  Buffered messages logged at 23:49:19
23:49:19     INFO -  28 INFO Removing tab.
23:49:19     INFO -  29 INFO Waiting for event: 'TabClose' on [object XULElement].
23:49:19     INFO -  30 INFO Got event: 'TabClose' on [object XULElement].
23:49:19     INFO -  31 INFO Tab removed and finished closing
23:49:19     INFO -  Buffered messages finished
23:49:19    ERROR -  32 INFO TEST-UNEXPECTED-FAIL | devtools/client/inspector/animation/test/browser_animation_rewind-button.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -
23:49:19     INFO -  GECKO(4304) | MEMORY STAT | vsize 2341MB | vsizeMaxContiguous 131549489MB | residentFast 392MB | heapAllocated 115MB
23:49:19     INFO -  33 INFO TEST-OK | devtools/client/inspector/animation/test/browser_animation_rewind-button.js | took 135466ms
23:49:19     INFO -  GECKO(4304) | ++DOCSHELL 0000023AEDF67800 == 1 [pid = 536] [id = {7a1b7fcb-5188-4ec0-b511-fad186a1f6f6}]
23:49:19     INFO -  GECKO(4304) | ++DOMWINDOW == 1 (0000023AEDF29200) [pid = 536] [serial = 1] [outer = 0000000000000000]
23:49:20     INFO -  34 INFO checking window state
23:49:20     INFO -  GECKO(4304) | ++DOMWINDOW == 22 (00000282465DB400) [pid = 4304] [serial = 30] [outer = 000002824CC04800]
23:49:20     INFO -  GECKO(4304) | ++DOMWINDOW == 2 (0000023AF20E1000) [pid = 536] [serial = 2] [outer = 0000023AEDF29200]
23:49:20     INFO -  GECKO(4304) | ++DOMWINDOW == 23 (0000028247677400) [pid = 4304] [serial = 31] [outer = 000002824CC04800]
23:49:21     INFO -  GECKO(4304) | --DOCSHELL 000001F3A825E000 == 0 [pid = 4548] [id = {567e1836-d7da-4c1d-891b-5d9320d969b7}]
23:49:21     INFO -  GECKO(4304) | --DOCSHELL 0000023EB3A4F800 == 0 [pid = 3016] [id = {a2432f96-8ee0-426d-aed5-2244484dcd00}]
23:49:21     INFO -  GECKO(4304) | --DOMWINDOW == 1 (000001F3A8205800) [pid = 4548] [serial = 4] [outer = 0000000000000000] [url = about:blank]
23:49:21     INFO -  GECKO(4304) | --DOMWINDOW == 0 (000001F3A82C4C00) [pid = 4548] [serial = 5] [outer = 0000000000000000] [url = about:blank]
23:49:21     INFO -  GECKO(4304) | --DOCSHELL 000001D06496F800 == 0 [pid = 8140] [id = {037864ee-527d-4cf2-be82-ab57c0271474}]
23:49:22     INFO -  GECKO(4304) | --DOMWINDOW == 1 (0000023EAD827E00) [pid = 3016] [serial = 5] [outer = 0000000000000000] [url = about:newtab]
23:49:22     INFO -  GECKO(4304) | --DOMWINDOW == 0 (0000023EB3AC3400) [pid = 3016] [serial = 7] [outer = 0000000000000000] [url = about:newtab]
23:49:22     INFO -  GECKO(4304) | --DOMWINDOW == 1 (000001D064927C00) [pid = 8140] [serial = 1] [outer = 0000000000000000] [url = http://example.com/browser/devtools/client/inspector/animation/test/doc_multi_timings.html]
23:49:22     INFO -  GECKO(4304) | --DOMWINDOW == 0 (000001D06AEAC400) [pid = 8140] [serial = 3] [outer = 0000000000000000] [url = http://example.com/browser/devtools/client/inspector/animation/test/doc_multi_timings.html]
23:49:25     INFO -  GECKO(4304) | --DOMWINDOW == 22 (00000282514B2800) [pid = 4304] [serial = 24] [outer = 0000000000000000] [url = about:blank]
23:49:28     INFO -  GECKO(4304) | --DOMWINDOW == 21 (000002823D523A00) [pid = 4304] [serial = 27] [outer = 0000000000000000] [url = chrome://devtools/content/inspector/markup/markup.xhtml]
23:49:28     INFO -  GECKO(4304) | --DOMWINDOW == 20 (0000028247026800) [pid = 4304] [serial = 21] [outer = 0000000000000000] [url = chrome://devtools/content/inspector/index.xhtml]
23:49:28     INFO -  GECKO(4304) | --DOMWINDOW == 19 (0000028247684C00) [pid = 4304] [serial = 29] [outer = 0000000000000000] [url = about:blank]
23:49:28     INFO -  GECKO(4304) | --DOMWINDOW == 18 (000002824CC09000) [pid = 4304] [serial = 18] [outer = 0000000000000000] [url = about:blank]
23:49:28     INFO -  GECKO(4304) | --DOMWINDOW == 17 (000002824FBB4C00) [pid = 4304] [serial = 20] [outer = 0000000000000000] [url = about:devtools-toolbox]
23:49:28     INFO -  GECKO(4304) | --DOMWINDOW == 16 (000002824E481400) [pid = 4304] [serial = 11] [outer = 0000000000000000] [url = about:blank]
23:49:28     INFO -  GECKO(4304) | --DOMWINDOW == 15 (00000282465DB400) [pid = 4304] [serial = 30] [outer = 0000000000000000] [url = about:blank]
23:49:28     INFO -  GECKO(4304) | --DOMWINDOW == 14 (000002824CB24000) [pid = 4304] [serial = 19] [outer = 0000000000000000] [url = about:blank]
23:49:30     INFO -  GECKO(4304) | Completed ShutdownLeaks collections in process 536
23:49:30     INFO -  GECKO(4304) | Completed ShutdownLeaks collections in process 4548
23:49:30     INFO -  GECKO(4304) | Completed ShutdownLeaks collections in process 2200
23:49:31     INFO -  GECKO(4304) | Completed ShutdownLeaks collections in process 3016
23:49:31     INFO -  GECKO(4304) | --DOMWINDOW == 13 (000002824E480C00) [pid = 4304] [serial = 28] [outer = 0000000000000000] [url = chrome://devtools/content/inspector/markup/markup.xhtml]
23:49:31     INFO -  GECKO(4304) | --DOMWINDOW == 12 (000002825255C000) [pid = 4304] [serial = 22] [outer = 0000000000000000] [url = about:blank]
23:49:31     INFO -  GECKO(4304) | Completed ShutdownLeaks collections in process 8140
23:49:34     INFO -  35 INFO Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/FileUtils.jsm" line: 170}]
23:49:35     INFO -  GECKO(4304) | [Parent 4304, Lazy Idle] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/widget/windows/WinUtils.cpp, line 1470
23:49:42     INFO -  GECKO(4304) | Completed ShutdownLeaks collections in process 4304
23:49:42     INFO -  36 INFO TEST-START | Shutdown
23:49:42     INFO -  37 INFO Browser Chrome Test Summary
23:49:42     INFO -  38 INFO Passed:  5
23:49:42  WARNING -  39 INFO Failed:  1
23:49:42  WARNING -  One or more unittests failed.
23:49:42     INFO -  40 INFO Todo:    0
23:49:42     INFO -  41 INFO Mode:    e10s
23:49:42     INFO -  42 INFO *** End BrowserChrome Test Results ***

Comment hidden (Intermittent Failures Robot)

5 failures in 623 pushes (0.008 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 5

Platform breakdown:
* windows10-64-ccov: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1475441&startday=2018-07-09&endday=2018-07-15&tree=trunk

Comment hidden (Intermittent Failures Robot)

14 failures in 653 pushes (0.021 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 13
* autoland: 1

Platform breakdown:
* linux64-ccov: 12
* windows7-32: 1
* windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1475441&startday=2018-07-16&endday=2018-07-22&tree=trunk

Andreea Pavel [:apavel]

Comment 3

•

6 years ago

This failure seems to have been introduced with https://bugzilla.mozilla.org/show_bug.cgi?id=1468475 

https://hg.mozilla.org/integration/autoland/rev/12b86e5e0725#l4.2

This has also a tier1 failure here: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=99ac85a273af610206c5077fed6a5841d9678291&selectedJob=188766819 but it's intermittent not perma. 


:mantaroh can you please give your input here?

Flags: needinfo?(mantaroh)

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Updated

•

6 years ago

Keywords: intermittent-failure

Summary: Perma fail [tier 2] devtools/client/inspector/animation/test/browser_animation_rewind-button.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. → Intermittent devtools/client/inspector/animation/test/browser_animation_rewind-button.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort.

Comment hidden (Intermittent Failures Robot)

26 failures in 760 pushes (0.034 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 22
* try: 3
* mozilla-inbound: 1

Platform breakdown:
* linux64-ccov: 25
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1475441&startday=2018-07-23&endday=2018-07-29&tree=trunk

Natalia Csoregi [:nataliaCs]

Comment 5

•

6 years ago

There have been 32 failures in the last 7 days, all of them on Linux x64 CCov debug.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=190638415&repo=mozilla-central&lineNumber=46759

[task 2018-07-28T00:45:13.733Z] 00:45:13     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2018-07-28T00:45:13.733Z] 00:45:13     INFO - Got event: 'TabClose' on [object XULElement].
[task 2018-07-28T00:45:13.734Z] 00:45:13     INFO - Tab removed and finished closing
[task 2018-07-28T00:45:13.734Z] 00:45:13     INFO - Buffered messages finished
[task 2018-07-28T00:45:13.734Z] 00:45:13     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/animation/test/browser_animation_rewind-button.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 
[task 2018-07-28T00:45:13.735Z] 00:45:13     INFO - GECKO(2308) | MEMORY STAT | vsize 2475MB | residentFast 754MB | heapAllocated 242MB
[task 2018-07-28T00:45:13.735Z] 00:45:13     INFO - TEST-OK | devtools/client/inspector/animation/test/browser_animation_rewind-button.js | took 118354ms

Whiteboard: [stockwell needswork]

Mantaroh Yoshinaga[:mantaroh]

Assignee

Comment 6

•

6 years ago

(In reply to Andreea Pavel [:apavel] from comment #3)
> This failure seems to have been introduced with
> https://bugzilla.mozilla.org/show_bug.cgi?id=1468475 
> 
> https://hg.mozilla.org/integration/autoland/rev/12b86e5e0725#l4.2
> 
> This has also a tier1 failure here:
> https://treeherder.mozilla.org/#/
> jobs?repo=autoland&revision=99ac85a273af610206c5077fed6a5841d9678291&selected
> Job=188766819 but it's intermittent not perma. 
> 
> 
> :mantaroh can you please give your input here?

Thanks apavel,

Sorry for my late reply. I'll look into this intermittent bug.

Component: Inspector → Animation Inspector

Flags: needinfo?(mantaroh)

Mantaroh Yoshinaga[:mantaroh]

Assignee

Comment 7

•

6 years ago

As far as I can see the test failure, test looks passing. However, mochitest didn't finished. So we might need to add the equestLongerTimeout.

WIP: https://treeherder.mozilla.org/#/jobs?repo=try&revision=40c7b4fc5d773af0282270116f06f7a2e46cc166

Mantaroh Yoshinaga[:mantaroh]

Assignee

Comment 8

•

6 years ago

Now, I'm going to try to separate this test:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=9b4e213db810f76ca2b2c9a5a51d2b741601dadb

Mantaroh Yoshinaga[:mantaroh]

Assignee

Comment 9

•

6 years ago

(In reply to Mantaroh Yoshinaga[:mantaroh] from comment #8)
> Now, I'm going to try to separate this test:
> https://treeherder.mozilla.org/#/
> jobs?repo=try&revision=9b4e213db810f76ca2b2c9a5a51d2b741601dadb

Try result looks failed due to timeout, because, this test remove the animated element after animation inspector is opened. So this test will render twice. I'll try changing this removing code to before the opening the animation inspector.

Greg Mierzwinski [:sparky]

Comment 10

•

6 years ago

I've been able to (so far) reliably reproduce an error similar to this while trying to disable telemetry on the linux64-ccov build: https://treeherder.mozilla.org/#/jobs?repo=try&revision=094e5accd4569f41dd0dd8351803132c5a217984&filter-searchStr=dt4

Here are the changes I made: https://hg.mozilla.org/try/rev/fb6a68e2ac69b6f597da4f2ae6309b7ca354853d

Comment hidden (Intermittent Failures Robot)

38 failures in 2579 pushes (0.015 failures/push) were associated with this bug in the last 7 days.

This is the #50 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* mozilla-central: 35
* try: 3

Platform breakdown:
* linux64: 1
* linux64-ccov: 37

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1475441&startday=2018-08-06&endday=2018-08-12&tree=all

Mantaroh Yoshinaga[:mantaroh]

Assignee

Comment 12

•

6 years ago

Attached file Bug 1475441 - Add requestLongerTimeout(2) and remove unnecessary code of removing animations. r?daisuke — Details

This test removed the animations after opening the animation inspector.
This removing animation code is unnecessary since the target document has not
these animation class. As a result of it, that test will take the long times.
However, this test will timeout even if removing that code. So this patch will
add requestLongerTimeout(2) for intermittent failure of the ccov test.

Daisuke Akatsuka (:daisuke)

Comment 13

•

6 years ago

Comment on attachment 8999829 [details]
Bug 1475441 - Add requestLongerTimeout(2) and remove unnecessary code of removing animations. r?daisuke

Daisuke Akatsuka (:daisuke) has approved the revision.

Attachment #8999829 - Flags: review+

Pulsebot

Comment 14

•

6 years ago

Pushed by mantaroh@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/e6584141d581
Add requestLongerTimeout(2) and remove unnecessary code of removing animations. r=daisuke

Daisuke Akatsuka (:daisuke)

Updated

•

6 years ago

Assignee: nobody → mantaroh

Narcis Beleuzu [:NarcisB]

Comment 15

•

6 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/e6584141d581

Status: NEW → RESOLVED

Closed: 6 years ago

status-firefox63: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → Firefox 63

Comment hidden (Intermittent Failures Robot)

11 failures in 2672 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-central: 11

Platform breakdown:
* linux64-ccov: 11

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1475441&startday=2018-08-13&endday=2018-08-19&tree=all