1476490 - Intermittent dom/tests/mochitest/fetch/test_fetch_cached_redirect.html | Test timed out.

Status: RESOLVED INCOMPLETE

(Core :: DOM: Core & HTML, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: toros [at] mozilla.com

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

https://queue.taskcluster.net/v1/task/T_pbD-9RTfWHBLma_0bF5A/runs/0/artifacts/public/logs/live_backing.log

[task 2018-07-17T22:48:23.496Z] 22:48:23     INFO - TEST-START | dom/tests/mochitest/fetch/test_fetch_cached_redirect.html
[task 2018-07-17T22:48:23.524Z] 22:48:23     INFO - GECKO(1395) | --DOMWINDOW == 17 (0x7f4c7624fa00) [pid = 1450] [serial = 31] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/fetch/message_receiver.html]
[task 2018-07-17T22:48:23.654Z] 22:48:23     INFO - GECKO(1395) | ++DOMWINDOW == 18 (0x7f4c75052000) [pid = 1450] [serial = 40] [outer = 0x7f4c83869800]
[task 2018-07-17T22:48:24.034Z] 22:48:24     INFO - GECKO(1395) | --DOMWINDOW == 17 (0x7f4c794a7c00) [pid = 1450] [serial = 32] [outer = (nil)] [url = about:blank]
[task 2018-07-17T22:48:24.035Z] 22:48:24     INFO - GECKO(1395) | --DOMWINDOW == 16 (0x7f4c76229000) [pid = 1450] [serial = 33] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2018-07-17T22:48:24.218Z] 22:48:24     INFO - GECKO(1395) | --DOMWINDOW == 15 (0x7f4c7b8c4400) [pid = 1450] [serial = 37] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/fetch/message_receiver.html]
[task 2018-07-17T22:48:24.219Z] 22:48:24     INFO - GECKO(1395) | --DOMWINDOW == 14 (0x7f4c76252600) [pid = 1450] [serial = 23] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/fetch/reroute.html?test_fetch_basic_http]
[task 2018-07-17T22:48:24.243Z] 22:48:24     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: NS_ENSURE_TRUE(global) failed: file /builds/worker/workspace/build/src/dom/serviceworkers/ServiceWorkerRegistrationImpl.cpp, line 111
[task 2018-07-17T22:48:24.245Z] 22:48:24     INFO - GECKO(1395) | ++DOCSHELL 0x7f4c7500c800 == 3 [pid = 1450] [id = {1aca0848-b806-490e-94e7-4ba2a8ffed21}]
[task 2018-07-17T22:48:24.246Z] 22:48:24     INFO - GECKO(1395) | ++DOMWINDOW == 15 (0x7f4c76252600) [pid = 1450] [serial = 41] [outer = (nil)]
[task 2018-07-17T22:48:24.253Z] 22:48:24     INFO - GECKO(1395) | ++DOMWINDOW == 16 (0x7f4c75053c00) [pid = 1450] [serial = 42] [outer = 0x7f4c76252600]
[task 2018-07-17T22:48:24.335Z] 22:48:24     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 596
[task 2018-07-17T22:48:24.376Z] 22:48:24     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: 'mIsWorkerScript || (mState != ServiceWorkerState::Parsed && mState != ServiceWorkerState::Installing)', file /builds/worker/workspace/build/src/dom/workers/ScriptLoader.cpp, line 1759
[task 2018-07-17T22:48:24.623Z] 22:48:24     INFO - GECKO(1395) | --DOMWINDOW == 15 (0x7f4c75056c00) [pid = 1450] [serial = 38] [outer = (nil)] [url = about:blank]
[task 2018-07-17T22:48:24.623Z] 22:48:24     INFO - GECKO(1395) | --DOMWINDOW == 14 (0x7f4c7b5f7000) [pid = 1450] [serial = 22] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/fetch/test_fetch_basic_http_sw_reroute.html]
[task 2018-07-17T22:48:24.624Z] 22:48:24     INFO - GECKO(1395) | --DOMWINDOW == 13 (0x7f4c7b5f7c00) [pid = 1450] [serial = 24] [outer = (nil)] [url = about:blank]
[task 2018-07-17T22:48:25.272Z] 22:48:25     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 596
[task 2018-07-17T22:48:25.316Z] 22:48:25     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 596
[task 2018-07-17T22:48:25.334Z] 22:48:25     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 596
[task 2018-07-17T22:48:25.375Z] 22:48:25     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 596
[task 2018-07-17T22:48:28.760Z] 22:48:28     INFO - GECKO(1395) | --DOMWINDOW == 12 (0x7f4c75051000) [pid = 1450] [serial = 39] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2018-07-17T22:48:32.511Z] 22:48:32     INFO - GECKO(1395) | --DOMWINDOW == 11 (0x7f4c7624ce00) [pid = 1450] [serial = 35] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/fetch/reroute.html?test_fetch_basic]
[task 2018-07-17T22:48:32.512Z] 22:48:32     INFO - GECKO(1395) | --DOMWINDOW == 10 (0x7f4c75070a00) [pid = 1450] [serial = 29] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/fetch/reroute.html?test_fetch_basic]
[task 2018-07-17T22:48:36.523Z] 22:48:36     INFO - GECKO(1395) | --DOMWINDOW == 9 (0x7f4c7622f800) [pid = 1450] [serial = 36] [outer = (nil)] [url = about:blank]
[task 2018-07-17T22:48:36.523Z] 22:48:36     INFO - GECKO(1395) | --DOMWINDOW == 8 (0x7f4c75058400) [pid = 1450] [serial = 30] [outer = (nil)] [url = about:blank]
[task 2018-07-17T22:48:36.525Z] 22:48:36     INFO - GECKO(1395) | --DOMWINDOW == 7 (0x7f4c75052400) [pid = 1450] [serial = 28] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/fetch/test_fetch_basic_sw_empty_reroute.html]
[task 2018-07-17T22:48:36.525Z] 22:48:36     INFO - GECKO(1395) | --DOMWINDOW == 6 (0x7f4c76229400) [pid = 1450] [serial = 34] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/fetch/test_fetch_basic_sw_reroute.html]
[task 2018-07-17T22:53:25.469Z] 22:53:25     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: '!aInstallEventSuccess', file /builds/worker/workspace/build/src/dom/serviceworkers/ServiceWorkerUpdateJob.cpp, line 585
[task 2018-07-17T22:53:25.470Z] 22:53:25     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 596
[task 2018-07-17T22:53:25.470Z] 22:53:25     INFO - GECKO(1395) | [Child 1450, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 596
[task 2018-07-17T22:53:25.487Z] 22:53:25     INFO - GECKO(1395) | [Parent 1395, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 596
[task 2018-07-17T22:53:25.488Z] 22:53:25     INFO - GECKO(1395) | [Child 1488, Main Thread] WARNING: '!window', file /builds/worker/workspace/build/src/dom/cache/CacheStorage.cpp, line 596
[task 2018-07-17T22:58:34.913Z] 22:58:34     INFO - TEST-INFO | started process screentopng
[task 2018-07-17T22:58:35.199Z] 22:58:35     INFO - TEST-INFO | screentopng: exit 0
[task 2018-07-17T22:58:35.199Z] 22:58:35     INFO - Buffered messages logged at 22:48:23
[task 2018-07-17T22:58:35.200Z] 22:58:35     INFO - TEST-PASS | dom/tests/mochitest/fetch/test_fetch_cached_redirect.html | didn't crash 
[task 2018-07-17T22:58:35.201Z] 22:58:35     INFO - TEST-PASS | dom/tests/mochitest/fetch/test_fetch_cached_redirect.html | Worker: true: didn't crash 
[task 2018-07-17T22:58:35.202Z] 22:58:35     INFO - Buffered messages logged at 22:48:24
[task 2018-07-17T22:58:35.203Z] 22:58:35     INFO - TEST-PASS | dom/tests/mochitest/fetch/test_fetch_cached_redirect.html | NestedWorker: true: didn't crash 
[task 2018-07-17T22:58:35.203Z] 22:58:35     INFO - Buffered messages finished
[task 2018-07-17T22:58:35.204Z] 22:58:35     INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/fetch/test_fetch_cached_redirect.html | Test timed out. 
[task 2018-07-17T22:58:35.205Z] 22:58:35     INFO -     reportError@SimpleTest/TestRunner.js:121:7
[task 2018-07-17T22:58:35.205Z] 22:58:35     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2018-07-17T22:58:35.206Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.206Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.207Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.207Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.208Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.209Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.210Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.210Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.210Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.211Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.211Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.212Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.212Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.212Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.213Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.214Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.214Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.214Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.214Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.215Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.215Z] 22:58:35     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2018-07-17T22:58:35.215Z] 22:58:35     INFO -     TestRunner.runTests/<@SimpleTest/TestRunner.js:381:9
[task 2018-07-17T22:58:35.215Z] 22:58:35     INFO -     promise callback*TestRunner.runTests@SimpleTest/TestRunner.js:368:5
[task 2018-07-17T22:58:35.216Z] 22:58:35     INFO -     RunSet.runtests@SimpleTest/setup.js:194:3
[task 2018-07-17T22:58:35.216Z] 22:58:35     INFO -     RunSet.runall@SimpleTest/setup.js:173:5
[task 2018-07-17T22:58:35.217Z] 22:58:35     INFO -     hookupTests@SimpleTest/setup.js:266:5
[task 2018-07-17T22:58:35.217Z] 22:58:35     INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5
[task 2018-07-17T22:58:35.217Z] 22:58:35     INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11
[task 2018-07-17T22:58:35.217Z] 22:58:35     INFO - EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3
[task 2018-07-17T22:58:35.218Z] 22:58:35     INFO -     hookup@SimpleTest/setup.js:246:5
[task 2018-07-17T22:58:35.218Z] 22:58:35     INFO - EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp&cleanupCrashes=true:11:1
[task 2018-07-17T22:58:35.924Z] 22:58:35     INFO - GECKO(1395) | MEMORY STAT | vsize 1658MB | residentFast 140MB | heapAllocated 18MB
[task 2018-07-17T22:58:35.941Z] 22:58:35     INFO - TEST-OK | dom/tests/mochitest/fetch/test_fetch_cached_redirect.html | took 612442ms

Comment 1

[Joel Maher ( :jmaher ) (UTC -8)]

unable to reproduce this specific failure in test-verify mode:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&filter-searchStr=linux%20-bf&tochange=e9cd9d73e5a8f6fcb9223798453cdaa9f206399a&fromchange=547144f5596c1a146b208d68d93950a6313080ca

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* linux64: 1

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

Comment 3

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1
* mozilla-beta: 1

Platform breakdown:
* linux32-nightly: 1
* linux64: 1

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