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

[task 2019-09-21T10:55:53.961Z] 10:55:53 INFO - TEST-START | dom/tests/mochitest/storageevent/test_storageSessionStorageEventCheckNoPropagation.html
[task 2019-09-21T10:55:53.964Z] 10:55:53 INFO - GECKO(2870) | --DOMWINDOW == 12 (0x7f7da85dd880) [pid = 3024] [serial = 15] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:53.965Z] 10:55:53 INFO - GECKO(2870) | --DOMWINDOW == 11 (0x7f7da85dd6a0) [pid = 3024] [serial = 14] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:54.043Z] 10:55:54 INFO - GECKO(2870) | ++DOMWINDOW == 12 (0x7f7da4d6b400) [pid = 3024] [serial = 21] [outer = 0x7f7da85dd100]
[task 2019-09-21T10:55:54.119Z] 10:55:54 INFO - GECKO(2870) | ++DOCSHELL 0x7f7da85e0000 == 3 [pid = 3024] [id = {80ed31d5-86dc-4a0e-a638-3932ba1f8ac5}]
[task 2019-09-21T10:55:54.119Z] 10:55:54 INFO - GECKO(2870) | ++DOMWINDOW == 13 (0x7f7da85dd2e0) [pid = 3024] [serial = 22] [outer = (nil)]
[task 2019-09-21T10:55:54.119Z] 10:55:54 INFO - GECKO(2870) | [Child 3024, Main Thread] WARNING: '!mWindow->GetCurrentInnerWindow()', file /builds/worker/workspace/build/src/dom/ipc/nsQueryActor.h, line 20
[task 2019-09-21T10:55:54.127Z] 10:55:54 INFO - GECKO(2870) | ++DOMWINDOW == 14 (0x7f7da4d74000) [pid = 3024] [serial = 23] [outer = 0x7f7da85dd2e0]
[task 2019-09-21T10:55:54.167Z] 10:55:54 INFO - GECKO(2870) | --DOMWINDOW == 13 (0x7f7da71a1400) [pid = 3024] [serial = 17] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:54.168Z] 10:55:54 INFO - GECKO(2870) | --DOMWINDOW == 12 (0x7f7da4d0bc00) [pid = 3024] [serial = 12] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-09-21T10:55:54.169Z] 10:55:54 INFO - GECKO(2870) | --DOMWINDOW == 11 (0x7f7da71a2000) [pid = 3024] [serial = 7] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/storageevent/test_storageLocalStorageEventCheckNoPropagation.html]
[task 2019-09-21T10:55:54.170Z] 10:55:54 INFO - GECKO(2870) | --DOMWINDOW == 10 (0x7f7da719b400) [pid = 3024] [serial = 16] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:54.190Z] 10:55:54 INFO - GECKO(2870) | [Child 3024, Main Thread] WARNING: CompleteRedirectSetup failed, HttpChannelChild already open?: file /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 2125
[task 2019-09-21T10:55:54.251Z] 10:55:54 INFO - GECKO(2870) | --DOCSHELL 0x7fe8974dc800 == 3 [pid = 2920] [id = {eff02b2c-1ed8-44cc-9dac-78a03fb8ed9e}] [url = moz-extension://0c79d6bd-a78e-4b90-a3b2-2e60f0ebc1ff/_generated_background_page.html]
[task 2019-09-21T10:55:54.306Z] 10:55:54 INFO - GECKO(2870) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp1V6q_V.mozrunner/runtests_leaks_tab_pid3132.log
[task 2019-09-21T10:55:54.444Z] 10:55:54 INFO - GECKO(2870) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-21T10:55:54.525Z] 10:55:54 INFO - GECKO(2870) | [2019-09-21T10:55:54Z WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-21T10:55:54.525Z] 10:55:54 INFO - GECKO(2870) | [2019-09-21T10:55:54Z WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-21T10:55:54.532Z] 10:55:54 INFO - GECKO(2870) | ++DOCSHELL 0x7f211bdb5000 == 1 [pid = 3132] [id = {7b28b12d-3ce2-4680-8eb2-2c0ee83209a6}]
[task 2019-09-21T10:55:54.568Z] 10:55:54 INFO - GECKO(2870) | ++DOMWINDOW == 1 (0x7f211cddbf20) [pid = 3132] [serial = 1] [outer = (nil)]
[task 2019-09-21T10:55:54.569Z] 10:55:54 INFO - GECKO(2870) | ++DOMWINDOW == 2 (0x7f211bd23000) [pid = 3132] [serial = 2] [outer = 0x7f211cddbf20]
[task 2019-09-21T10:55:54.610Z] 10:55:54 INFO - GECKO(2870) | ++DOMWINDOW == 3 (0x7f211cd09000) [pid = 3132] [serial = 3] [outer = 0x7f211cddbf20]
[task 2019-09-21T10:55:54.639Z] 10:55:54 INFO - GECKO(2870) | ++DOCSHELL 0x7f211cd35000 == 2 [pid = 3132] [id = {7a046d78-0714-41be-b447-9f03868b1747}]
[task 2019-09-21T10:55:54.639Z] 10:55:54 INFO - GECKO(2870) | ++DOMWINDOW == 4 (0x7f211cddc100) [pid = 3132] [serial = 4] [outer = (nil)]
[task 2019-09-21T10:55:54.639Z] 10:55:54 INFO - GECKO(2870) | [Child 3132, Main Thread] WARNING: '!mWindow->GetCurrentInnerWindow()', file /builds/worker/workspace/build/src/dom/ipc/nsQueryActor.h, line 20
[task 2019-09-21T10:55:54.660Z] 10:55:54 INFO - GECKO(2870) | [Child 3132, Main Thread] WARNING: CompleteRedirectSetup failed, HttpChannelChild already open?: file /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 2125
[task 2019-09-21T10:55:54.661Z] 10:55:54 INFO - GECKO(2870) | [Child 3132, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/workspace/build/src/dom/base/WindowDestroyedEvent.cpp, line 106
[task 2019-09-21T10:55:54.737Z] 10:55:54 INFO - GECKO(2870) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp1V6q_V.mozrunner/runtests_leaks_tab_pid3158.log
[task 2019-09-21T10:55:54.839Z] 10:55:54 INFO - GECKO(2870) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-21T10:55:54.927Z] 10:55:54 INFO - GECKO(2870) | [2019-09-21T10:55:54Z WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-21T10:55:54.927Z] 10:55:54 INFO - GECKO(2870) | [2019-09-21T10:55:54Z WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-21T10:55:54.935Z] 10:55:54 INFO - GECKO(2870) | ++DOCSHELL 0x7f9eb44b4800 == 1 [pid = 3158] [id = {94cb0ada-f077-4920-9aad-14433415a43e}]
[task 2019-09-21T10:55:54.975Z] 10:55:54 INFO - GECKO(2870) | ++DOMWINDOW == 1 (0x7f9eb53d9f20) [pid = 3158] [serial = 1] [outer = (nil)]
[task 2019-09-21T10:55:54.975Z] 10:55:54 INFO - GECKO(2870) | ++DOMWINDOW == 2 (0x7f9eb4423000) [pid = 3158] [serial = 2] [outer = 0x7f9eb53d9f20]
[task 2019-09-21T10:55:55.012Z] 10:55:55 INFO - GECKO(2870) | [Parent 2870, QuotaManager IO] WARNING: '!outputStream', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 2326
[task 2019-09-21T10:55:55.012Z] 10:55:55 INFO - GECKO(2870) | [Parent 2870, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8147
[task 2019-09-21T10:55:55.012Z] 10:55:55 INFO - GECKO(2870) | [Parent 2870, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8008
[task 2019-09-21T10:55:55.012Z] 10:55:55 INFO - GECKO(2870) | [Parent 2870, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7918
[task 2019-09-21T10:55:55.012Z] 10:55:55 INFO - GECKO(2870) | [Parent 2870, QuotaManager IO] WARNING: '!outputStream', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 2326
[task 2019-09-21T10:55:55.012Z] 10:55:55 INFO - GECKO(2870) | [Parent 2870, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8147
[task 2019-09-21T10:55:55.012Z] 10:55:55 INFO - GECKO(2870) | [Parent 2870, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8008
[task 2019-09-21T10:55:55.012Z] 10:55:55 INFO - GECKO(2870) | [Parent 2870, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7918
[task 2019-09-21T10:55:55.014Z] 10:55:55 INFO - GECKO(2870) | ++DOMWINDOW == 3 (0x7f9eb4e7f400) [pid = 3158] [serial = 3] [outer = 0x7f9eb53d9f20]
[task 2019-09-21T10:55:55.054Z] 10:55:55 INFO - GECKO(2870) | JavaScript error: http://example.org/tests/dom/tests/mochitest/storageevent/interOriginFrame.js, line 10: Error: Failed to pass in newParentLocation
[task 2019-09-21T10:55:56.086Z] 10:55:56 INFO - GECKO(2870) | --DOMWINDOW == 11 (0x7efc4b823c00) [pid = 2870] [serial = 11] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:56.086Z] 10:55:56 INFO - GECKO(2870) | --DOMWINDOW == 10 (0x7efc4e8b2800) [pid = 2870] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:57.872Z] 10:55:57 INFO - GECKO(2870) | --DOMWINDOW == 5 (0x7fe1963c8c00) [pid = 2942] [serial = 5] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:57.874Z] 10:55:57 INFO - GECKO(2870) | --DOMWINDOW == 4 (0x7fe19622fc00) [pid = 2942] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:57.908Z] 10:55:57 INFO - GECKO(2870) | --DOMWINDOW == 3 (0x7fe197284f20) [pid = 2942] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:58.251Z] 10:55:58 INFO - GECKO(2870) | --DOCSHELL 0x7f7da85e0000 == 2 [pid = 3024] [id = {80ed31d5-86dc-4a0e-a638-3932ba1f8ac5}] [url = about:blank]
[task 2019-09-21T10:55:58.251Z] 10:55:58 INFO - GECKO(2870) | --DOMWINDOW == 9 (0x7f7da4d11800) [pid = 3024] [serial = 19] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/storageevent/test_storageNotifications.html]
[task 2019-09-21T10:55:58.251Z] 10:55:58 INFO - GECKO(2870) | --DOMWINDOW == 8 (0x7f7da4d6d000) [pid = 3024] [serial = 18] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-09-21T10:55:58.251Z] 10:55:58 INFO - GECKO(2870) | --DOMWINDOW == 7 (0x7f7da4d0f800) [pid = 3024] [serial = 13] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/storageevent/test_storageLocalStorageEventCheckPropagation.html]
[task 2019-09-21T10:55:58.313Z] 10:55:58 INFO - GECKO(2870) | --DOMWINDOW == 6 (0x7f7da85dd2e0) [pid = 3024] [serial = 22] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:58.353Z] 10:55:58 INFO - GECKO(2870) | --DOMWINDOW == 11 (0x7fe897479000) [pid = 2920] [serial = 8] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:58.354Z] 10:55:58 INFO - GECKO(2870) | --DOMWINDOW == 10 (0x7fe897476800) [pid = 2920] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:58.355Z] 10:55:58 INFO - GECKO(2870) | --DOMWINDOW == 9 (0x7fe896b22c00) [pid = 2920] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:58.356Z] 10:55:58 INFO - GECKO(2870) | --DOMWINDOW == 8 (0x7fe897474400) [pid = 2920] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:55:58.411Z] 10:55:58 INFO - GECKO(2870) | --DOMWINDOW == 7 (0x7fe897c835c0) [pid = 2920] [serial = 7] [outer = (nil)] [url = moz-extension://0c79d6bd-a78e-4b90-a3b2-2e60f0ebc1ff/_generated_background_page.html]
[task 2019-09-21T10:56:01.931Z] 10:56:01 INFO - GECKO(2870) | --DOMWINDOW == 2 (0x7fe1963c7400) [pid = 2942] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:56:02.341Z] 10:56:02 INFO - GECKO(2870) | --DOMWINDOW == 5 (0x7f7da4d04c00) [pid = 3024] [serial = 20] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-09-21T10:56:02.341Z] 10:56:02 INFO - GECKO(2870) | --DOMWINDOW == 4 (0x7f7da4d74000) [pid = 3024] [serial = 23] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:56:02.442Z] 10:56:02 INFO - GECKO(2870) | --DOMWINDOW == 6 (0x7fe8967c2400) [pid = 2920] [serial = 12] [outer = (nil)] [url = moz-extension://0c79d6bd-a78e-4b90-a3b2-2e60f0ebc1ff/_generated_background_page.html]
[task 2019-09-21T10:56:02.643Z] 10:56:02 INFO - GECKO(2870) | --DOCSHELL 0x7f211cd35000 == 1 [pid = 3132] [id = {7a046d78-0714-41be-b447-9f03868b1747}] [url = ]
[task 2019-09-21T10:56:02.643Z] 10:56:02 INFO - GECKO(2870) | --DOMWINDOW == 3 (0x7f211cddc100) [pid = 3132] [serial = 4] [outer = (nil)] [url = ]
[task 2019-09-21T10:56:06.762Z] 10:56:06 INFO - GECKO(2870) | --DOMWINDOW == 2 (0x7f211bd23000) [pid = 3132] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-21T10:56:07.179Z] 10:56:07 INFO - GECKO(2870) | --DOMWINDOW == 2 (0x7f9eb4423000) [pid = 3158] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-21T11:01:20.025Z] 11:01:20 INFO - TEST-INFO | started process screentopng
[task 2019-09-21T11:01:20.262Z] 11:01:20 INFO - TEST-INFO | screentopng: exit 0
[task 2019-09-21T11:01:20.264Z] 11:01:20 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/storageevent/test_storageSessionStorageEventCheckNoPropagation.html | Test timed out.
[task 2019-09-21T11:01:20.264Z] 11:01:20 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - reportError@SimpleTest/TestRunner.js:121:22
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:18
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.265Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.266Z] 11:01:20 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-09-21T11:01:20.266Z] 11:01:20 INFO - TestRunner.runTests/<@SimpleTest/TestRunner.js:388:20
[task 2019-09-21T11:01:20.266Z] 11:01:20 INFO - promise callbackTestRunner.runTests@SimpleTest/TestRunner.js:375:50
[task 2019-09-21T11:01:20.266Z] 11:01:20 INFO - RunSet.runtests@SimpleTest/setup.js:201:14
[task 2019-09-21T11:01:20.267Z] 11:01:20 INFO - RunSet.runall@SimpleTest/setup.js:180:12
[task 2019-09-21T11:01:20.267Z] 11:01:20 INFO - hookupTests@SimpleTest/setup.js:273:12
[task 2019-09-21T11:01:20.267Z] 11:01:20 INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:48:13
[task 2019-09-21T11:01:20.267Z] 11:01:20 INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:61:28
[task 2019-09-21T11:01:20.268Z] 11:01:20 INFO - EventHandlerNonNullgetTestManifest@http://mochi.test:8888/manifestLibrary.js:57:3
[task 2019-09-21T11:01:20.268Z] 11:01:20 INFO - hookup@SimpleTest/setup.js:253:20
[task 2019-09-21T11:01:20.268Z] 11:01:20 INFO - EventHandlerNonNull@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp&cleanupCrashes=true:11:1
[task 2019-09-21T11:01:21.033Z] 11:01:21 INFO - GECKO(2870) | MEMORY STAT | vsize 2523MB | residentFast 140MB | heapAllocated 11MB
[task 2019-09-21T11:01:21.042Z] 11:01:21 INFO - TEST-OK | dom/tests/mochitest/storageevent/test_storageSessionStorageEventCheckNoPropagation.html | took 327078ms

Fails since Bug 1582523 got to central: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&group_state=expanded&searchStr=linux%2Cx64%2Cdebug%2Cmochitests%2Cwith%2Cfission%2Cenabled%2Ctest-linux64%2Fdebug-mochitest-fis-e10s-10%2Cm-fis%2810%29&fromchange=52cb15e3f79439a2e7207eb1f4a785a58c675d08&tochange=c221a75fbf2957b6254fedb96436b5efbf0fd147&selectedJob=267621402

https://hg.mozilla.org/mozilla-central/rev/96933b2e1a06

Yaron, this test still times out (https://treeherder.mozilla.org/#/jobs?repo=try&author=kmadan%40mozilla.com&fromchange=acc1e6f36ccb4d550c1220dcbf2af0cad26b867b&selectedJob=274884543) so cannot be unskipped just yet.

Jens suggested you for looking into this.

This seems to be some timing issue, because I am getting successful runs of this test -- sometimes. I'll have to investigate more to figure out what's going on here.

The inner iframe sends a message M to the outer iframe when it
finishes loading, with the intention that the outer iframe will
send the message further to the top-level page. If, however, the
outer iframe's load handler didn't fire yet when it processes M,
it will throw an exception instead of forwarding M. This causes M
to get lost, and the test hangs.

https://hg.mozilla.org/mozilla-central/rev/7bb91b38719e