Open Bug 1589762 Opened 4 months ago Updated 2 days ago

Intermittent fission dom/serviceworkers/test/test_eventsource_intercept.html | Something went wrong

Categories

(Core :: DOM: Service Workers, defect, P3)

defect

Tracking

()

Fission Milestone M7
Tracking Status
firefox72 --- disabled
firefox73 --- disabled
firefox74 --- affected

People

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

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=271932470&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/DNORr4KcTAenMkS8QC0LFg/runs/0/artifacts/public/logs/live_backing.log


[task 2019-10-18T16:55:49.002Z] 16:55:49 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | Unregister should return true.
[task 2019-10-18T16:55:49.002Z] 16:55:49 INFO - Going to intercept and test mixed content cors responses
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - Buffered messages finished
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_eventsource_intercept.html | Something went wrong
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - testFrame/</window.onmessage@dom/serviceworkers/test/test_eventsource_intercept.html:26:17
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - EventHandlerNonNulltestFrame/<@dom/serviceworkers/test/test_eventsource_intercept.html:22:7
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - testFrame@dom/serviceworkers/test/test_eventsource_intercept.html:19:12
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - runTest/<@dom/serviceworkers/test/test_eventsource_intercept.html:83:16
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - promise callback
runTest@dom/serviceworkers/test/test_eventsource_intercept.html:82:8
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - Async*@dom/serviceworkers/test/test_eventsource_intercept.html:94:17
[task 2019-10-18T16:55:49.003Z] 16:55:49 INFO - GECKO(1154) | [Parent 1154, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 575
[task 2019-10-18T16:55:49.581Z] 16:55:49 INFO - GECKO(1154) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp5M5ugq.mozrunner/runtests_leaks_tab_pid1443.log
[task 2019-10-18T16:55:49.602Z] 16:55:49 INFO - GECKO(1154) | [Child 1443, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 732
[task 2019-10-18T16:55:49.678Z] 16:55:49 INFO - GECKO(1154) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-10-18T16:55:49.779Z] 16:55:49 INFO - GECKO(1154) | [Child 1443, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1786
[task 2019-10-18T16:56:00.734Z] 16:56:00 INFO - GECKO(1154) | --DOMWINDOW == 2 (0x7f427f8aa000) [pid = 1417] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-10-18T16:56:17.741Z] 16:56:17 INFO - GECKO(1154) | [Parent 1154, IPDL Background] WARNING: 'aResult.IsReject()', file /builds/worker/workspace/build/src/dom/workers/remoteworkers/RemoteWorkerController.cpp, line 444
[task 2019-10-18T16:56:17.742Z] 16:56:17 INFO - GECKO(1154) | [Parent 1154, IPDL Background] WARNING: 'aResult.IsReject()', file /builds/worker/workspace/build/src/dom/workers/remoteworkers/RemoteWorkerControllerParent.cpp, line 108
[task 2019-10-18T17:01:01.181Z] 17:01:01 INFO - Not taking screenshot here: see the one that was previously logged

This failure has been observed intermittently on the ubuntu1804 test image, in mochitest-plain-headless.

try: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&selectedJob=280054870&revision=ef82da214b0ab380436ae1860bd63b9a0c5ff000
log: https://firefoxci.taskcluster-artifacts.net/A43xaqjaT7a9nDDoo2LTzg/0/public/logs/live_backing.log

context:

[task 2019-12-06T18:56:18.647Z] 18:56:18     INFO - TEST-START | dom/serviceworkers/test/test_eventsource_intercept.html
[task 2019-12-06T18:56:19.450Z] 18:56:19     INFO - TEST-INFO | started process screentopng
[task 2019-12-06T18:56:19.671Z] 18:56:19     INFO - TEST-INFO | screentopng: exit 0
[task 2019-12-06T18:56:19.672Z] 18:56:19     INFO - Buffered messages logged at 18:56:18
[task 2019-12-06T18:56:19.673Z] 18:56:19     INFO - Going to intercept and test opaque responses
[task 2019-12-06T18:56:19.674Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a CORS request 
[task 2019-12-06T18:56:19.674Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a no-store request 
[task 2019-12-06T18:56:19.674Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should not work with opaque responses 
[task 2019-12-06T18:56:19.674Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | Unregister should return true. 
[task 2019-12-06T18:56:19.674Z] 18:56:19     INFO - Going to intercept and test cors responses
[task 2019-12-06T18:56:19.675Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a CORS request 
[task 2019-12-06T18:56:19.675Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a no-store request 
[task 2019-12-06T18:56:19.675Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should work with cors responses 
[task 2019-12-06T18:56:19.675Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | Unregister should return true. 
[task 2019-12-06T18:56:19.675Z] 18:56:19     INFO - Going to intercept and test synthetic responses
[task 2019-12-06T18:56:19.676Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should work with synthetic responses 
[task 2019-12-06T18:56:19.676Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a CORS request 
[task 2019-12-06T18:56:19.676Z] 18:56:19     INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | Unregister should return true. 
[task 2019-12-06T18:56:19.676Z] 18:56:19     INFO - Going to intercept and test mixed content cors responses
[task 2019-12-06T18:56:19.676Z] 18:56:19     INFO - Buffered messages finished
[task 2019-12-06T18:56:19.678Z] 18:56:19     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_eventsource_intercept.html | Something went wrong 
[task 2019-12-06T18:56:19.678Z] 18:56:19     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-12-06T18:56:19.678Z] 18:56:19     INFO -     testFrame/</window.onmessage@dom/serviceworkers/test/test_eventsource_intercept.html:26:17
[task 2019-12-06T18:56:19.678Z] 18:56:19     INFO -     EventHandlerNonNull*testFrame/<@dom/serviceworkers/test/test_eventsource_intercept.html:22:7
[task 2019-12-06T18:56:19.678Z] 18:56:19     INFO -     testFrame@dom/serviceworkers/test/test_eventsource_intercept.html:19:12
[task 2019-12-06T18:56:19.679Z] 18:56:19     INFO -     runTest/<@dom/serviceworkers/test/test_eventsource_intercept.html:83:16
[task 2019-12-06T18:56:19.679Z] 18:56:19     INFO -     promise callback*runTest@dom/serviceworkers/test/test_eventsource_intercept.html:82:8
[task 2019-12-06T18:56:19.679Z] 18:56:19     INFO -     Async*@dom/serviceworkers/test/test_eventsource_intercept.html:94:17
[task 2019-12-06T19:01:40.870Z] 19:01:40     INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-12-06T19:01:40.870Z] 19:01:40     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_eventsource_intercept.html | Test timed out. 
[task 2019-12-06T19:01:40.871Z] 19:01:40     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-12-06T19:01:40.871Z] 19:01:40     INFO -     reportError@SimpleTest/TestRunner.js:121:22
[task 2019-12-06T19:01:40.871Z] 19:01:40     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:18
[task 2019-12-06T19:01:40.871Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.872Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.872Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.873Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.873Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.873Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.874Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.874Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.875Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.875Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.875Z] 19:01:40     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:40.876Z] 19:01:40     INFO -     TestRunner.runTests/<@SimpleTest/TestRunner.js:388:20
[task 2019-12-06T19:01:40.876Z] 19:01:40     INFO -     promise callback*TestRunner.runTests@SimpleTest/TestRunner.js:375:50
[task 2019-12-06T19:01:40.876Z] 19:01:40     INFO -     RunSet.runtests@SimpleTest/setup.js:201:14
[task 2019-12-06T19:01:40.876Z] 19:01:40     INFO -     RunSet.runall@SimpleTest/setup.js:180:12
[task 2019-12-06T19:01:40.877Z] 19:01:40     INFO -     hookupTests@SimpleTest/setup.js:273:12
[task 2019-12-06T19:01:40.877Z] 19:01:40     INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:48:13
[task 2019-12-06T19:01:40.877Z] 19:01:40     INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:61:28
[task 2019-12-06T19:01:40.878Z] 19:01:40     INFO - EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:57:3
[task 2019-12-06T19:01:40.878Z] 19:01:40     INFO -     hookup@SimpleTest/setup.js:253:20
[task 2019-12-06T19:01:40.878Z] 19:01:40     INFO - EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp&cleanupCrashes=true:11:1
[task 2019-12-06T19:01:41.877Z] 19:01:41     INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-12-06T19:01:41.877Z] 19:01:41     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_eventsource_intercept.html | This test left a service worker registered without cleaning it up 
[task 2019-12-06T19:01:41.878Z] 19:01:41     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-12-06T19:01:41.878Z] 19:01:41     INFO -     afterCleanup@SimpleTest/SimpleTest.js:1192:28
[task 2019-12-06T19:01:41.878Z] 19:01:41     INFO -     async*executeCleanupFunction@SimpleTest/SimpleTest.js:1232:13
[task 2019-12-06T19:01:41.878Z] 19:01:41     INFO -     SimpleTest.finish@SimpleTest/SimpleTest.js:1251:5
[task 2019-12-06T19:01:41.879Z] 19:01:41     INFO -     killTest@SimpleTest/TestRunner.js:130:22
[task 2019-12-06T19:01:41.879Z] 19:01:41     INFO -     async*delayedKillTest@SimpleTest/TestRunner.js:159:17
[task 2019-12-06T19:01:41.879Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:157:17
[task 2019-12-06T19:01:41.879Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.880Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.880Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.881Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.882Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.882Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.883Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.884Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.885Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.885Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.886Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.886Z] 19:01:41     INFO -     TestRunner.runTests/<@SimpleTest/TestRunner.js:388:20
[task 2019-12-06T19:01:41.887Z] 19:01:41     INFO -     promise callback*TestRunner.runTests@SimpleTest/TestRunner.js:375:50
[task 2019-12-06T19:01:41.888Z] 19:01:41     INFO -     RunSet.runtests@SimpleTest/setup.js:201:14
[task 2019-12-06T19:01:41.889Z] 19:01:41     INFO -     RunSet.runall@SimpleTest/setup.js:180:12
[task 2019-12-06T19:01:41.890Z] 19:01:41     INFO -     hookupTests@SimpleTest/setup.js:273:12
[task 2019-12-06T19:01:41.890Z] 19:01:41     INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:48:13
[task 2019-12-06T19:01:41.891Z] 19:01:41     INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:61:28
[task 2019-12-06T19:01:41.892Z] 19:01:41     INFO - EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:57:3
[task 2019-12-06T19:01:41.892Z] 19:01:41     INFO -     hookup@SimpleTest/setup.js:253:20
[task 2019-12-06T19:01:41.893Z] 19:01:41     INFO - EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp&cleanupCrashes=true:11:1
[task 2019-12-06T19:01:41.894Z] 19:01:41     INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-12-06T19:01:41.895Z] 19:01:41     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_eventsource_intercept.html | Left over worker: https://example.com/tests/dom/serviceworkers/test/eventsource/eventsource_mixed_content_cors_response_intercept_worker.js (scope: https://example.com/tests/dom/serviceworkers/test/eventsource/) 
[task 2019-12-06T19:01:41.895Z] 19:01:41     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-12-06T19:01:41.896Z] 19:01:41     INFO -     afterCleanup@SimpleTest/SimpleTest.js:1194:32
[task 2019-12-06T19:01:41.897Z] 19:01:41     INFO -     async*executeCleanupFunction@SimpleTest/SimpleTest.js:1232:13
[task 2019-12-06T19:01:41.898Z] 19:01:41     INFO -     SimpleTest.finish@SimpleTest/SimpleTest.js:1251:5
[task 2019-12-06T19:01:41.898Z] 19:01:41     INFO -     killTest@SimpleTest/TestRunner.js:130:22
[task 2019-12-06T19:01:41.899Z] 19:01:41     INFO -     async*delayedKillTest@SimpleTest/TestRunner.js:159:17
[task 2019-12-06T19:01:41.900Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:157:17
[task 2019-12-06T19:01:41.901Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.901Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.902Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.902Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.903Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.903Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.904Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.904Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.905Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO -     TestRunner.runTests/<@SimpleTest/TestRunner.js:388:20
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO -     promise callback*TestRunner.runTests@SimpleTest/TestRunner.js:375:50
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO -     RunSet.runtests@SimpleTest/setup.js:201:14
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO -     RunSet.runall@SimpleTest/setup.js:180:12
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO -     hookupTests@SimpleTest/setup.js:273:12
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:48:13
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:61:28
[task 2019-12-06T19:01:41.908Z] 19:01:41     INFO - EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:57:3
[task 2019-12-06T19:01:41.909Z] 19:01:41     INFO -     hookup@SimpleTest/setup.js:253:20
[task 2019-12-06T19:01:41.909Z] 19:01:41     INFO - EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp&cleanupCrashes=true:11:1
[task 2019-12-06T19:01:41.909Z] 19:01:41     INFO - GECKO(5320) | MEMORY STAT | vsize 2467MB | residentFast 112MB | heapAllocated 9MB
[task 2019-12-06T19:01:41.909Z] 19:01:41     INFO - TEST-OK | dom/serviceworkers/test/test_eventsource_intercept.html | took 323235ms
[task 2019-12-06T19:01:41.915Z] 19:01:41    ERROR - /tests/dom/serviceworkers/test/test_eventsource_intercept.html logged result after SimpleTest.finish(): This test left a service worker registered without cleaning it up
[task 2019-12-06T19:01:41.917Z] 19:01:41    ERROR - /tests/dom/serviceworkers/test/test_eventsource_intercept.html logged result after SimpleTest.finish(): Left over worker: https://example.com/tests/dom/serviceworkers/test/eventsource/eventsource_mixed_content_cors_response_intercept_worker.js (scope: https://example.com/tests/dom/serviceworkers/test/eventsource/)
Priority: -- → P3

This has 23 total failures in the last 7 days, 68 total failures in the last 30 and it only fails on mochitest fission opt builds windows10-64 and linux64.
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-12-23&endday=2019-12-30&tree=trunk&bug=1589762

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=282815263&repo=mozilla-central
Looks to have spiked since https://hg.mozilla.org/mozilla-central/rev/243d10dad9d810f0261d9c5bfb88fac2cd46cbff got into central.
Neha, could you please assign this to someone from the fission team? Thank you.

Fission Milestone: --- → ?
Flags: needinfo?(nkochar)
Summary: Intermittent dom/serviceworkers/test/test_eventsource_intercept.html | Something went wrong → Intermittent fission dom/serviceworkers/test/test_eventsource_intercept.html | Something went wrong

This bug failed 42 times in the last 7 days. Occurs on linux64, linux64-qr, windows10-64 and windows10-64-qr on debug and opt build types.

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

Jens: Could you please take a look at this bug or assign someone to do so?

Flags: needinfo?(jstutte)

I see in the recent log:

TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_eventsource_intercept.html | Something went wrong 

In this testcase and its loaded files I see at least 3 points, where "Something went wrong" appears. I would suggest as a start to make the error messages more explicit and unique in order to be able to identify the source. :ssengupta, can you take a look?

Flags: needinfo?(jstutte) → needinfo?(ssengupta)
Fission Milestone: ? → M7
Assignee: nobody → ssengupta
Flags: needinfo?(ssengupta)
Flags: needinfo?(nkochar)

There are 63 total failures in the last 7 days on linux1804-64 opt, linux1804-64-qr opt, linux64-qr debug and opt, windows10-64 opt and windows10-64-qr opt.

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

[task 2020-01-20T16:50:35.696Z] 16:50:35 INFO - TEST-START | dom/serviceworkers/test/test_eventsource_intercept.html
[task 2020-01-20T16:50:36.500Z] 16:50:36 INFO - TEST-INFO | started process screenshot
[task 2020-01-20T16:50:36.565Z] 16:50:36 INFO - TEST-INFO | screenshot: exit 0
[task 2020-01-20T16:50:36.565Z] 16:50:36 INFO - Buffered messages logged at 16:50:35
[task 2020-01-20T16:50:36.565Z] 16:50:36 INFO - Going to intercept and test opaque responses
[task 2020-01-20T16:50:36.565Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a CORS request
[task 2020-01-20T16:50:36.565Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a no-store request
[task 2020-01-20T16:50:36.565Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should not work with opaque responses
[task 2020-01-20T16:50:36.565Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | Unregister should return true.
[task 2020-01-20T16:50:36.566Z] 16:50:36 INFO - Going to intercept and test cors responses
[task 2020-01-20T16:50:36.566Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a CORS request
[task 2020-01-20T16:50:36.566Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a no-store request
[task 2020-01-20T16:50:36.566Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should work with cors responses
[task 2020-01-20T16:50:36.566Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | Unregister should return true.
[task 2020-01-20T16:50:36.566Z] 16:50:36 INFO - Going to intercept and test synthetic responses
[task 2020-01-20T16:50:36.566Z] 16:50:36 INFO - Buffered messages logged at 16:50:36
[task 2020-01-20T16:50:36.566Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should make a CORS request
[task 2020-01-20T16:50:36.566Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | EventSource should work with synthetic responses
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - TEST-PASS | dom/serviceworkers/test/test_eventsource_intercept.html | Unregister should return true.
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - Going to intercept and test mixed content cors responses
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - Buffered messages finished
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_eventsource_intercept.html | Something went wrong
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - testFrame/</window.onmessage@dom/serviceworkers/test/test_eventsource_intercept.html:26:17
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - EventHandlerNonNulltestFrame/<@dom/serviceworkers/test/test_eventsource_intercept.html:22:7
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - testFrame@dom/serviceworkers/test/test_eventsource_intercept.html:19:12
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - runTest/<@dom/serviceworkers/test/test_eventsource_intercept.html:83:16
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - promise callback
runTest@dom/serviceworkers/test/test_eventsource_intercept.html:82:8
[task 2020-01-20T16:50:36.567Z] 16:50:36 INFO - Async*@dom/serviceworkers/test/test_eventsource_intercept.html:94:17
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_eventsource_intercept.html | Test timed out.
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - reportError@SimpleTest/TestRunner.js:121:22
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:18
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.619Z] 16:55:57 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - TestRunner.runTests/<@SimpleTest/TestRunner.js:388:20
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - promise callback
TestRunner.runTests@SimpleTest/TestRunner.js:375:50
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - RunSet.runtests@SimpleTest/setup.js:201:14
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - RunSet.runall@SimpleTest/setup.js:180:12
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - hookupTests@SimpleTest/setup.js:273:12
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:48:13
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:61:28
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - EventHandlerNonNullgetTestManifest@http://mochi.test:8888/manifestLibrary.js:57:3
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - hookup@SimpleTest/setup.js:253:20
[task 2020-01-20T16:55:57.620Z] 16:55:57 INFO - EventHandlerNonNull
@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=c%3A%5Cusers%5Ctask_1579537205%5Cappdata%5Clocal%5Ctemp&cleanupCrashes=true:11:1
[task 2020-01-20T16:55:58.619Z] 16:55:58 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-01-20T16:55:58.619Z] 16:55:58 INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_eventsource_intercept.html | This test left a service worker registered without cleaning it up
[task 2020-01-20T16:55:58.619Z] 16:55:58 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2020-01-20T16:55:58.619Z] 16:55:58 INFO - afterCleanup@SimpleTest/SimpleTest.js:1219:28
[task 2020-01-20T16:55:58.619Z] 16:55:58 INFO - asyncexecuteCleanupFunction@SimpleTest/SimpleTest.js:1259:13
[task 2020-01-20T16:55:58.619Z] 16:55:58 INFO - SimpleTest.finish@SimpleTest/SimpleTest.js:1278:5
[task 2020-01-20T16:55:58.619Z] 16:55:58 INFO - killTest@SimpleTest/TestRunner.js:130:22
[task 2020-01-20T16:55:58.619Z] 16:55:58 INFO - async
delayedKillTest@SimpleTest/TestRunner.js:159:17

Subhamoy are there any updates here?

Flags: needinfo?(ssengupta)

https://pernos.co/debug/DGxuIulw79_JfzU7H3TAaA/index.html

I have been able to reproduce it and generate Pernosco session out of it. Will investigate further.

Flags: needinfo?(ssengupta)

Update:
There have been 26 failures within the last 7 days:

  • 9 failures on Windows 10 x64 QuantumRender opt
  • 5 failures on Windows 10 x64 opt
  • 3 failures on Linux 18.04 x64 QuantumRender opt
  • 9 failures on Linux 18.04 x64 opt

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

Here is a 'good' run as Pernosco session to compare with: https://pernos.co/debug/4SFYYAzkwgaLPcW5Ju1i1Q/index.html

The following call not being executed is the apparent reason for failure:
https://searchfox.org/mozilla-central/source/dom/base/EventSource.cpp#753

Hopefully this gets done soon :)

You need to log in before you can comment on or make changes to this bug.