1548441 - Intermittent dom/media/test/test_preload_suspend.html | v1 got suspended, count=2 - got 2, expected 1

Status: RESOLVED WORKSFORME

(Core :: Audio/Video: Playback, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=244077661&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/W9pXzchvQ_eXyFDuwNvr5A/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-05-02T02:48:39.944Z] 02:48:39 INFO - TEST-START | dom/media/test/test_preload_suspend.html
[task 2019-05-02T02:48:40.022Z] 02:48:40 INFO - GECKO(1777) | ++DOMWINDOW == 12 (0x7f616bffcc00) [pid = 1852] [serial = 708] [outer = 0x7f617a0c6a60]
[task 2019-05-02T02:48:40.104Z] 02:48:40 INFO - GECKO(1777) | ++DOCSHELL 0x7f616c01e800 == 3 [pid = 1852] [id = {a32c8878-adb0-4498-b352-8f282867bbb1}]
[task 2019-05-02T02:48:40.108Z] 02:48:40 INFO - GECKO(1777) | ++DOMWINDOW == 13 (0x7f616d5974c0) [pid = 1852] [serial = 709] [outer = (nil)]
[task 2019-05-02T02:48:40.145Z] 02:48:40 INFO - GECKO(1777) | ++DOMWINDOW == 14 (0x7f616bffd000) [pid = 1852] [serial = 710] [outer = 0x7f616d5974c0]
[task 2019-05-02T02:48:40.504Z] 02:48:40 INFO - [1749, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
[task 2019-05-02T02:48:41.289Z] 02:48:41 INFO - TEST-INFO | started process screentopng
[task 2019-05-02T02:48:41.540Z] 02:48:41 INFO - [1749, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
[task 2019-05-02T02:48:41.767Z] 02:48:41 INFO - TEST-INFO | screentopng: exit 0
[task 2019-05-02T02:48:41.769Z] 02:48:41 INFO - Buffered messages logged at 02:48:40
[task 2019-05-02T02:48:41.772Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | A valid string reason is expected
[task 2019-05-02T02:48:41.774Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | Reason cannot be empty
[task 2019-05-02T02:48:41.775Z] 02:48:41 INFO - Started Thu May 02 2019 02:48:40 GMT+0000 (Coordinated Universal Time) (1556765320.181s)
[task 2019-05-02T02:48:41.777Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [started v1 t=0.023] Length of array should match number of running tests
[task 2019-05-02T02:48:41.778Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [started v2 t=0.029] Length of array should match number of running tests
[task 2019-05-02T02:48:41.779Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | v1 got suspended, count=1
[task 2019-05-02T02:48:41.781Z] 02:48:41 INFO - Buffered messages logged at 02:48:41
[task 2019-05-02T02:48:41.782Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | v2 got suspended, count=1
[task 2019-05-02T02:48:41.787Z] 02:48:41 INFO - [finished v2] remaining= v1
[task 2019-05-02T02:48:41.789Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [finished v2 t=1.035] Length of array should match number of running tests
[task 2019-05-02T02:48:41.790Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [started v3 t=1.047] Length of array should match number of running tests
[task 2019-05-02T02:48:41.791Z] 02:48:41 INFO - Buffered messages finished
[task 2019-05-02T02:48:41.792Z] 02:48:41 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_preload_suspend.html | v1 got suspended, count=2 - got 2, expected 1
[task 2019-05-02T02:48:41.792Z] 02:48:41 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:320:16
[task 2019-05-02T02:48:41.792Z] 02:48:41 INFO - checkSuspendCount@dom/media/test/test_preload_suspend.html:17:3
[task 2019-05-02T02:48:41.793Z] 02:48:41 INFO - onsuspend@dom/media/test/test_preload_suspend.html:33:7
[task 2019-05-02T02:48:41.793Z] 02:48:41 INFO - EventHandlerNonNullstartTest@dom/media/test/test_preload_suspend.html:99:3
[task 2019-05-02T02:48:41.793Z] 02:48:41 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1834:12
[task 2019-05-02T02:48:41.793Z] 02:48:41 INFO - MediaTestManager/this.runTests/<@dom/media/test/manifest.js:1754:12
[task 2019-05-02T02:48:41.794Z] 02:48:41 INFO - [finished v1] remaining= v3
[task 2019-05-02T02:48:41.794Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [finished v1 t=1.113] Length of array should match number of running tests
[task 2019-05-02T02:48:41.795Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [started v4 t=1.122] Length of array should match number of running tests
[task 2019-05-02T02:48:41.795Z] 02:48:41 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | v4 got suspended, count=1
[task 2019-05-02T02:48:42.488Z] 02:48:42 INFO - [1749, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
[task 2019-05-02T02:48:42.647Z] 02:48:42 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-05-02T02:48:42.648Z] 02:48:42 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_preload_suspend.html | v3 got suspended, count=1 - got 2, expected 1
[task 2019-05-02T02:48:42.650Z] 02:48:42 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:320:16
[task 2019-05-02T02:48:42.650Z] 02:48:42 INFO - checkSuspendCount@dom/media/test/test_preload_suspend.html:17:3
[task 2019-05-02T02:48:42.650Z] 02:48:42 INFO - EventHandlerNonNullstartTest@dom/media/test/test_preload_suspend.html:99:3
[task 2019-05-02T02:48:42.651Z] 02:48:42 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1834:12
[task 2019-05-02T02:48:42.651Z] 02:48:42 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1813:12
[task 2019-05-02T02:48:42.652Z] 02:48:42 INFO - checkSuspendCount@dom/media/test/test_preload_suspend.html:20:13
[task 2019-05-02T02:48:42.653Z] 02:48:42 INFO - EventHandlerNonNullstartTest@dom/media/test/test_preload_suspend.html:99:3
[task 2019-05-02T02:48:42.653Z] 02:48:42 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1834:12
[task 2019-05-02T02:48:42.654Z] 02:48:42 INFO - MediaTestManager/this.runTests/<@dom/media/test/manifest.js:1754:12
[task 2019-05-02T02:48:42.670Z] 02:48:42 INFO - [finished v3] remaining= v4
[task 2019-05-02T02:48:42.678Z] 02:48:42 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [finished v3 t=2.487] Length of array should match number of running tests
[task 2019-05-02T02:48:42.694Z] 02:48:42 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [started v6 t=2.508] Length of array should match number of running tests
[task 2019-05-02T02:48:42.731Z] 02:48:42 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | v4 got suspended, count=2
[task 2019-05-02T02:48:42.731Z] 02:48:42 INFO - [finished v4] remaining= v6
[task 2019-05-02T02:48:42.737Z] 02:48:42 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [finished v4 t=2.547] Length of array should match number of running tests
[task 2019-05-02T02:48:42.754Z] 02:48:42 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | v6 got suspended, count=1
[task 2019-05-02T02:48:43.484Z] 02:48:43 INFO - [1749, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
[task 2019-05-02T02:48:43.684Z] 02:48:43 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-05-02T02:48:43.684Z] 02:48:43 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_preload_suspend.html | v6 got suspended, count=2 - got 2, expected 1
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:320:16
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - checkSuspendCount@dom/media/test/test_preload_suspend.html:17:3
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - onsuspend@dom/media/test/test_preload_suspend.html:80:7
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - EventHandlerNonNullstartTest@dom/media/test/test_preload_suspend.html:99:3
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1834:12
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1813:12
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - checkSuspendCount@dom/media/test/test_preload_suspend.html:20:13
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - EventHandlerNonNullstartTest@dom/media/test/test_preload_suspend.html:99:3
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1834:12
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1813:12
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - checkSuspendCount@dom/media/test/test_preload_suspend.html:20:13
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - EventHandlerNonNullstartTest@dom/media/test/test_preload_suspend.html:99:3
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1834:12
[task 2019-05-02T02:48:43.685Z] 02:48:43 INFO - MediaTestManager/this.runTests/<@dom/media/test/manifest.js:1754:12
[task 2019-05-02T02:48:43.705Z] 02:48:43 INFO - [finished v6] remaining=
[task 2019-05-02T02:48:43.705Z] 02:48:43 INFO - TEST-PASS | dom/media/test/test_preload_suspend.html | [finished v6 t=3.511] Length of array should match number of running tests
[task 2019-05-02T02:48:44.179Z] 02:48:44 INFO - GECKO(1777) | [Child 1852, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 4803
[task 2019-05-02T02:48:44.179Z] 02:48:44 INFO - GECKO(1777) | [Child 1852, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 4803
[task 2019-05-02T02:48:44.180Z] 02:48:44 INFO - GECKO(1777) | [Child 1852, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 4803
[task 2019-05-02T02:48:44.181Z] 02:48:44 INFO - GECKO(1777) | [Child 1852, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 4803
[task 2019-05-02T02:48:44.359Z] 02:48:44 INFO - GECKO(1777) | --DOMWINDOW == 13 (0x7f616d171000) [pid = 1852] [serial = 707] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-05-02T02:48:44.359Z] 02:48:44 INFO - GECKO(1777) | --DOMWINDOW == 12 (0x7f616bff5000) [pid = 1852] [serial = 706] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/media/test/test_preload_attribute.html]
[task 2019-05-02T02:48:44.360Z] 02:48:44 INFO - GECKO(1777) | --DOMWINDOW == 11 (0x7f616bff8c00) [pid = 1852] [serial = 705] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-05-02T02:48:44.360Z] 02:48:44 INFO - GECKO(1777) | --DOMWINDOW == 10 (0x7f616d596f20) [pid = 1852] [serial = 703] [outer = (nil)] [url = about:blank]
[task 2019-05-02T02:48:44.361Z] 02:48:44 INFO - GECKO(1777) | --DOMWINDOW == 9 (0x7f616dfe2c00) [pid = 1852] [serial = 704] [outer = (nil)] [url = about:blank]
[task 2019-05-02T02:48:44.361Z] 02:48:44 INFO - GECKO(1777) | --DOMWINDOW == 8 (0x7f616bff7c00) [pid = 1852] [serial = 702] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/media/test/test_preload_actions.html]
[task 2019-05-02T02:48:44.418Z] 02:48:44 INFO - Finished at Thu May 02 2019 02:48:44 GMT+0000 (Coordinated Universal Time) (1556765324.402s)
[task 2019-05-02T02:48:44.418Z] 02:48:44 INFO - Running time: 4.222s
[task 2019-05-02T02:48:44.419Z] 02:48:44 INFO - GECKO(1777) | MEMORY STAT | vsize 2715MB | residentFast 184MB | heapAllocated 18MB
[task 2019-05-02T02:48:44.436Z] 02:48:44 INFO - TEST-OK | dom/media/test/test_preload_suspend.html | took 4491ms

Comment 1

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

Times of failure indicate it's from bug 1540573.

Comment 2

[Andreea Pavel [:apavel]]

Bug 1540573 got backed out here: https://hg.mozilla.org/integration/autoland/rev/0bb9da8fe6af

Comment 3

[Intermittent Failures Robot]

60 failures in 807 pushes (0.074 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 50
• mozilla-inbound: 7
• mozilla-central: 3

Platform breakdown:

• linux32: 7
• linux64-qr: 9
• linux32-shippable: 9
• linux64: 10
• osx-10-10-shippable: 1
• linux64-shippable: 12
• linux64-shippable-qr: 5
• windows7-32-shippable: 4
• windows10-64-shippable: 1
• windows10-64: 1
• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1548441&startday=2019-05-03&endday=2019-05-03&tree=all

Comment 4

[Intermittent Failures Robot]

65 failures in 4131 pushes (0.016 failures/push) were associated with this bug in the last 7 days.

This is the #34 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:

• autoland: 55
• mozilla-inbound: 7
• mozilla-central: 3

Platform breakdown:

• linux64: 11
• linux32: 8
• linux32-shippable: 10
• linux64-shippable-qr: 6
• windows7-32-shippable: 5
• linux64-qr: 9
• osx-10-10-shippable: 1
• linux64-shippable: 12
• windows10-64-shippable: 1
• windows10-64: 1
• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1548441&startday=2019-04-29&endday=2019-05-05&tree=all