Intermittent dom/tests/mochitest/bugs/test_bug440572.html | received the right number of messages. - got 3, expected 4
Categories
(Core :: DOM: Core & HTML, defect, P3)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr68 | --- | unaffected |
firefox74 | --- | wontfix |
firefox75 | --- | wontfix |
firefox76 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: alchen)
References
Details
(Keywords: intermittent-failure, regression, Whiteboard: [stockwell unknown])
Attachments
(1 file)
Filed by: dluca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=269535496&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/FVIYjhnPT9-3hP4q94z3hw/runs/0/artifacts/public/logs/live_backing.log
INFO - TEST-START | dom/tests/mochitest/bugs/test_bug440572.html
[task 2019-10-02T23:50:42.145Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 41
[task 2019-10-02T23:50:42.181Z] 23:50:42 INFO - GECKO(4216) | [Parent 4216, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4516
[task 2019-10-02T23:50:42.204Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 27 (0x7f7237994000) [pid = 4388] [serial = 123] [outer = 0x7f723a79c6a0]
[task 2019-10-02T23:50:42.286Z] 23:50:42 INFO - GECKO(4216) | ++DOCSHELL 0x7f72377ae000 == 4 [pid = 4388] [id = {23779eb1-c8d5-47a1-a8b6-d9b7cd8aa33b}]
[task 2019-10-02T23:50:42.286Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 28 (0x7f7239b7eb60) [pid = 4388] [serial = 124] [outer = (nil)]
[task 2019-10-02T23:50:42.286Z] 23:50:42 INFO - GECKO(4216) | ++DOCSHELL 0x7f72377ae800 == 5 [pid = 4388] [id = {b64dabcb-f4e9-442e-9047-b7adb41dfd16}]
[task 2019-10-02T23:50:42.287Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 29 (0x7f7239b7ef20) [pid = 4388] [serial = 125] [outer = (nil)]
[task 2019-10-02T23:50:42.287Z] 23:50:42 INFO - GECKO(4216) | ++DOCSHELL 0x7f7237921800 == 6 [pid = 4388] [id = {b5027ae2-7862-4e20-8139-716aca0a83bd}]
[task 2019-10-02T23:50:42.287Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 30 (0x7f7239b7f100) [pid = 4388] [serial = 126] [outer = (nil)]
[task 2019-10-02T23:50:42.287Z] 23:50:42 INFO - GECKO(4216) | ++DOCSHELL 0x7f7237922000 == 7 [pid = 4388] [id = {26f0ca9d-82ad-4bb6-9555-774bba43ffae}]
[task 2019-10-02T23:50:42.287Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 31 (0x7f7239b7f2e0) [pid = 4388] [serial = 127] [outer = (nil)]
[task 2019-10-02T23:50:42.342Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 41
[task 2019-10-02T23:50:42.342Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 41
[task 2019-10-02T23:50:42.498Z] 23:50:42 INFO - GECKO(4216) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpkaJJ34.mozrunner/runtests_leaks_tab_pid4586.log
[task 2019-10-02T23:50:42.620Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 41
[task 2019-10-02T23:50:42.620Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 41
[task 2019-10-02T23:50:42.621Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 41
[task 2019-10-02T23:50:42.621Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 41
[task 2019-10-02T23:50:42.636Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 41
[task 2019-10-02T23:50:42.637Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 41
[task 2019-10-02T23:50:42.673Z] 23:50:42 INFO - GECKO(4216) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-10-02T23:50:42.702Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/workspace/build/src/dom/base/WindowDestroyedEvent.cpp, line 106
[task 2019-10-02T23:50:42.703Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/workspace/build/src/dom/base/WindowDestroyedEvent.cpp, line 106
[task 2019-10-02T23:50:42.703Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/workspace/build/src/dom/base/WindowDestroyedEvent.cpp, line 106
[task 2019-10-02T23:50:42.703Z] 23:50:42 INFO - GECKO(4216) | [Child 4388, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/workspace/build/src/dom/base/WindowDestroyedEvent.cpp, line 106
[task 2019-10-02T23:50:42.703Z] 23:50:42 INFO - GECKO(4216) | --DOMWINDOW == 30 (0x7f7239b7eb60) [pid = 4388] [serial = 124] [outer = (nil)] [url = ]
[task 2019-10-02T23:50:42.704Z] 23:50:42 INFO - GECKO(4216) | --DOMWINDOW == 29 (0x7f7239b7ef20) [pid = 4388] [serial = 125] [outer = (nil)] [url = ]
[task 2019-10-02T23:50:42.704Z] 23:50:42 INFO - GECKO(4216) | --DOMWINDOW == 28 (0x7f7239b7f100) [pid = 4388] [serial = 126] [outer = (nil)] [url = ]
[task 2019-10-02T23:50:42.704Z] 23:50:42 INFO - GECKO(4216) | --DOMWINDOW == 27 (0x7f7239b7f2e0) [pid = 4388] [serial = 127] [outer = (nil)] [url = ]
[task 2019-10-02T23:50:42.827Z] 23:50:42 INFO - GECKO(4216) | ++DOCSHELL 0x7f9377fc1000 == 1 [pid = 4586] [id = {61b5ecff-8724-47dc-9560-ded4d9e4d9b9}]
[task 2019-10-02T23:50:42.875Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 1 (0x7f93918f14c0) [pid = 4586] [serial = 1] [outer = (nil)]
[task 2019-10-02T23:50:42.875Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 2 (0x7f9377f32400) [pid = 4586] [serial = 2] [outer = 0x7f93918f14c0]
[task 2019-10-02T23:50:42.899Z] 23:50:42 INFO - GECKO(4216) | --DOCSHELL 0x7f7237928800 == 6 [pid = 4388] [id = {d1f33baf-09e7-4d7a-8cce-da6338ed948a}] [url = http://mochi.test:8888/tests/dom/tests/mochitest/bugs/iframe_bug430276-2.html]
[task 2019-10-02T23:50:42.900Z] 23:50:42 INFO - GECKO(4216) | --DOMWINDOW == 26 (0x7f72377d7000) [pid = 4388] [serial = 101] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/tests/mochitest/bugs/test_bug427744.html]
[task 2019-10-02T23:50:42.902Z] 23:50:42 INFO - GECKO(4216) | --DOMWINDOW == 25 (0x7f7239b40c00) [pid = 4388] [serial = 100] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-10-02T23:50:42.904Z] 23:50:42 INFO - GECKO(4216) | --DOMWINDOW == 24 (0x7f7237779c00) [pid = 4388] [serial = 102] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-10-02T23:50:42.912Z] 23:50:42 INFO - GECKO(4216) | ++DOCSHELL 0x7f937909c800 == 2 [pid = 4586] [id = {fd1042b9-e85b-4251-bbb7-840738bdf4e6}]
[task 2019-10-02T23:50:42.912Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 3 (0x7f93918f1a60) [pid = 4586] [serial = 3] [outer = (nil)]
[task 2019-10-02T23:50:42.916Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 4 (0x7f9379065c00) [pid = 4586] [serial = 4] [outer = 0x7f93918f1a60]
[task 2019-10-02T23:50:42.932Z] 23:50:42 INFO - GECKO(4216) | ++DOCSHELL 0x7f93790a0000 == 3 [pid = 4586] [id = {1e2dca6e-58c4-45aa-8c20-23df913473ab}]
[task 2019-10-02T23:50:42.933Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 5 (0x7f9378852020) [pid = 4586] [serial = 5] [outer = (nil)]
[task 2019-10-02T23:50:42.934Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 6 (0x7f9379068000) [pid = 4586] [serial = 6] [outer = 0x7f9378852020]
[task 2019-10-02T23:50:42.942Z] 23:50:42 INFO - GECKO(4216) | ++DOCSHELL 0x7f93790a3000 == 4 [pid = 4586] [id = {7deb70d3-2fba-4de8-aaaa-3e81a78a2ef6}]
[task 2019-10-02T23:50:42.943Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 7 (0x7f93788527a0) [pid = 4586] [serial = 7] [outer = (nil)]
[task 2019-10-02T23:50:42.946Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 8 (0x7f937906a400) [pid = 4586] [serial = 8] [outer = 0x7f93788527a0]
[task 2019-10-02T23:50:42.974Z] 23:50:42 INFO - GECKO(4216) | ++DOMWINDOW == 9 (0x7f937906ec00) [pid = 4586] [serial = 9] [outer = 0x7f93918f14c0]
[task 2019-10-02T23:50:43.004Z] 23:50:43 INFO - GECKO(4216) | ++DOMWINDOW == 10 (0x7f9378f7a000) [pid = 4586] [serial = 10] [outer = 0x7f93918f1a60]
[task 2019-10-02T23:50:43.025Z] 23:50:43 INFO - GECKO(4216) | ++DOMWINDOW == 11 (0x7f9378f7c000) [pid = 4586] [serial = 11] [outer = 0x7f9378852020]
[task 2019-10-02T23:50:43.045Z] 23:50:43 INFO - GECKO(4216) | ++DOMWINDOW == 12 (0x7f9378f7e000) [pid = 4586] [serial = 12] [outer = 0x7f93788527a0]
[task 2019-10-02T23:50:43.187Z] 23:50:43 INFO - TEST-INFO | started process screentopng
[task 2019-10-02T23:50:43.976Z] 23:50:43 INFO - TEST-INFO | screentopng: exit 0
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - Buffered messages logged at 23:50:43
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - Buffered messages finished
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | received the right number of messages. - got 3, expected 4
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:322:16
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - runtests@dom/tests/mochitest/bugs/test_bug440572.html:30:5
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - onload@dom/tests/mochitest/bugs/test_bug440572.html:1:1
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | test in frame failed.
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | "dump" in frame failed.
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | "open" in frame failed.
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | parent["close"] should be the WebIDL property of Window.
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - GECKO(4216) | MEMORY STAT | vsize 2531MB | residentFast 154MB | heapAllocated 16MB
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - TEST-OK | dom/tests/mochitest/bugs/test_bug440572.html | took 1116ms
[task 2019-10-02T23:50:43.977Z] 23:50:43 INFO - GECKO(4216) | [Parent 4216, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4516
[task 2019-10-02T23:50:43.977Z] 23:50:43 ERROR - /tests/dom/tests/mochitest/bugs/test_bug440572.html logged result after SimpleTest.finish(): wrong sender!
[task 2019-10-02T23:50:43.978Z] 23:50:43 INFO - GECKO(4216) | ++DOMWINDOW == 25 (0x7f7237779c00) [pid = 4388] [serial = 128] [outer = 0x7f723a79c6a0]
[task 2019-10-02T23:50:43.980Z] 23:50:43 INFO - GECKO(4216) | [Parent 4216, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4516
[task 2019-10-02T23:50:43.980Z] 23:50:43 INFO - TEST-START | dom/tests/mochitest/bugs/test_bug456151.html
Comment 1•5 years ago
|
||
Nika, could you look into this spike in failure rate after Bug 1576714 landed: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2Cx64%2Cquantumrender%2Cdebug%2Cmochitests%2Cwith%2Cfission%2Cenabled%2Ctest-linux64-qr%2Fdebug-mochitest-fis-e10s-8%2Cm-fis%288%29&tochange=ecb0e3d35a47ef3e11938d256522e187aee57450&fromchange=6d734cb4e0cac938e1e3758b44c750f401e0f5b6&group_state=expanded&selectedJob=269711916
Comment 2•5 years ago
|
||
My patch changed timing during process-switching navigations. I'm guessing this test was already buggy with fission before, but the new timing changes made this more frequent.
A quick look at the test suggests that it is dependent on the load event in the embedder not firing until after messages from each cross-origin subframe have been received. I am inclined to think that this test's reliance on this timing is broken, but there's a chance that this ordering is one which we want to guarantee. Either way, it's not likely to be a "new" bug.
If we look at a test failure log, the messages are clearly arriving after the checks are being made: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=269711916&repo=autoland&lineNumber=13131
First the load event fires:
INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | received the right number of messages. - got +0, expected 4
INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | test in frame failed. - got undefined, expected "success"
INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | "dump" in frame failed. - got undefined, expected "success"
INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | "open" in frame failed. - got undefined, expected "success"
INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | parent["close"] should be the WebIDL property of Window.
... and then the messages start arriving
INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
INFO - TEST-OK | dom/tests/mochitest/bugs/test_bug440572.html | took 1068ms
Comment hidden (Intermittent Failures Robot) |
Comment 4•5 years ago
•
|
||
There have been 32 failures within the last 7 days, all of them on Linux x64 QuantumRender debug (fission).
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=270982765&repo=autoland&lineNumber=13147
[task 2019-10-12T03:15:15.162Z] 03:15:15 INFO - GECKO(4044) | ++DOCSHELL 0x7f3f7e842000 == 4 [pid = 4390] [id = {429e498b-9ff8-420a-bd1a-41e808213bcd}]
[task 2019-10-12T03:15:15.162Z] 03:15:15 INFO - GECKO(4044) | ++DOMWINDOW == 7 (0x7f3f7e14b7a0) [pid = 4390] [serial = 7] [outer = (nil)]
[task 2019-10-12T03:15:15.162Z] 03:15:15 INFO - GECKO(4044) | ++DOMWINDOW == 8 (0x7f3f7e80c800) [pid = 4390] [serial = 8] [outer = 0x7f3f7e14b7a0]
[task 2019-10-12T03:15:15.210Z] 03:15:15 INFO - GECKO(4044) | ++DOMWINDOW == 9 (0x7f3f7e810400) [pid = 4390] [serial = 9] [outer = 0x7f3f7e8d94c0]
[task 2019-10-12T03:15:15.246Z] 03:15:15 INFO - GECKO(4044) | ++DOMWINDOW == 10 (0x7f3f7d4cb800) [pid = 4390] [serial = 10] [outer = 0x7f3f7e8d9a60]
[task 2019-10-12T03:15:15.266Z] 03:15:15 INFO - GECKO(4044) | ++DOMWINDOW == 11 (0x7f3f7d4cdc00) [pid = 4390] [serial = 11] [outer = 0x7f3f7e14b020]
[task 2019-10-12T03:15:15.282Z] 03:15:15 INFO - GECKO(4044) | ++DOMWINDOW == 12 (0x7f3f7d4cfc00) [pid = 4390] [serial = 12] [outer = 0x7f3f7e14b7a0]
[task 2019-10-12T03:15:15.405Z] 03:15:15 INFO - TEST-INFO | started process screentopng
[task 2019-10-12T03:15:16.193Z] 03:15:16 INFO - TEST-INFO | screentopng: exit 0
[task 2019-10-12T03:15:16.194Z] 03:15:16 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | received the right number of messages. - got +0, expected 4
[task 2019-10-12T03:15:16.194Z] 03:15:16 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:322:16
[task 2019-10-12T03:15:16.195Z] 03:15:16 INFO - runtests@dom/tests/mochitest/bugs/test_bug440572.html:30:5
[task 2019-10-12T03:15:16.195Z] 03:15:16 INFO - onload@dom/tests/mochitest/bugs/test_bug440572.html:1:1
[task 2019-10-12T03:15:16.196Z] 03:15:16 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-12T03:15:16.197Z] 03:15:16 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | test in frame failed. - got undefined, expected "success"
[task 2019-10-12T03:15:16.197Z] 03:15:16 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:322:16
[task 2019-10-12T03:15:16.198Z] 03:15:16 INFO - runtests@dom/tests/mochitest/bugs/test_bug440572.html:31:5
[task 2019-10-12T03:15:16.199Z] 03:15:16 INFO - onload@dom/tests/mochitest/bugs/test_bug440572.html:1:1
[task 2019-10-12T03:15:16.199Z] 03:15:16 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-12T03:15:16.200Z] 03:15:16 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | "dump" in frame failed. - got undefined, expected "success"
[task 2019-10-12T03:15:16.201Z] 03:15:16 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:322:16
[task 2019-10-12T03:15:16.201Z] 03:15:16 INFO - runtests@dom/tests/mochitest/bugs/test_bug440572.html:32:5
[task 2019-10-12T03:15:16.202Z] 03:15:16 INFO - onload@dom/tests/mochitest/bugs/test_bug440572.html:1:1
[task 2019-10-12T03:15:16.203Z] 03:15:16 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-12T03:15:16.203Z] 03:15:16 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | "open" in frame failed. - got undefined, expected "success"
[task 2019-10-12T03:15:16.204Z] 03:15:16 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:322:16
[task 2019-10-12T03:15:16.205Z] 03:15:16 INFO - runtests@dom/tests/mochitest/bugs/test_bug440572.html:33:5
[task 2019-10-12T03:15:16.206Z] 03:15:16 INFO - onload@dom/tests/mochitest/bugs/test_bug440572.html:1:1
[task 2019-10-12T03:15:16.206Z] 03:15:16 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | parent["close"] should be the WebIDL property of Window.
[task 2019-10-12T03:15:16.207Z] 03:15:16 INFO - GECKO(4044) | MEMORY STAT | vsize 2525MB | residentFast 141MB | heapAllocated 16MB
[task 2019-10-12T03:15:16.207Z] 03:15:16 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
[task 2019-10-12T03:15:16.208Z] 03:15:16 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
[task 2019-10-12T03:15:16.209Z] 03:15:16 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
[task 2019-10-12T03:15:16.209Z] 03:15:16 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug440572.html | wrong sender!
[task 2019-10-12T03:15:16.210Z] 03:15:16 INFO - TEST-OK | dom/tests/mochitest/bugs/test_bug440572.html | took 1094ms
[task 2019-10-12T03:15:16.211Z] 03:15:16 ERROR - /tests/dom/tests/mochitest/bugs/test_bug440572.html logged result after SimpleTest.finish(): wrong sender!
Comment hidden (Intermittent Failures Robot) |
Comment 6•5 years ago
|
||
it has been enabled on Fission but then we saw higher failure frequency.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 9•5 years ago
|
||
There are 22 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-10-23&endday=2019-10-30&tree=trunk&bug=1585859
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=273631538&repo=autoland&lineNumber=13777
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 17•5 years ago
|
||
There are 26 total failures in the last 7 days.
debug: linux64-qr, linux64
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=281833934&repo=autoland&lineNumber=11009
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 20•5 years ago
|
||
Hi Chris, This bug has been enabled for Fission. I'm thinking we should remove it from fission-mochitests meta bug as well as Fission M4.1, though there appears intermittent failures. What do you think?
Comment 21•5 years ago
|
||
(In reply to Hsin-Yi Tsai [:hsinyi] from comment #20)
This bug has been enabled for Fission. I'm thinking we should remove it from fission-mochitests meta bug as well as Fission M4.1, though there appears intermittent failures. What do you think?
This test runs in both Fission and non-Fission mode, but it fails much more frequently in Fission mode (40 Fission failures vs 8 non-Fission failures over the last two weeks). Comment 1 says the failure rate increased after Nika fixed bug 1576714.
So this intermittent test failure still looks like a Fission bug, but perhaps a lower priority than P2.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 24•5 years ago
|
||
In the last 7 days, there have been 40 failures on linux64-qr platform, debug build type.
An example of a recent log file:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=284498438&repo=autoland&lineNumber=10969
And the relevant part of the log:
[task 2020-01-11T02:03:39.400Z] 02:03:39 INFO - TEST-START | dom/tests/mochitest/bugs/test_bug440572.html
[task 2020-01-11T02:03:39.476Z] 02:03:39 INFO - GECKO(5385) | [Parent 5385, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2020-01-11T02:03:39.512Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
[task 2020-01-11T02:03:39.655Z] 02:03:39 INFO - GECKO(5385) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp8D086O.mozrunner/runtests_leaks_tab_pid5995.log
[task 2020-01-11T02:03:39.679Z] 02:03:39 INFO - GECKO(5385) | [Child 5995, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 721
[task 2020-01-11T02:03:39.740Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
[task 2020-01-11T02:03:39.741Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
[task 2020-01-11T02:03:39.741Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: NS_ENSURE_TRUE(request) failed: file /builds/worker/workspace/build/src/netwerk/base/nsLoadGroup.cpp, line 584
[task 2020-01-11T02:03:39.741Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/workspace/build/src/dom/base/WindowDestroyedEvent.cpp, line 106
[task 2020-01-11T02:03:39.748Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
[task 2020-01-11T02:03:39.748Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
[task 2020-01-11T02:03:39.748Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: NS_ENSURE_TRUE(request) failed: file /builds/worker/workspace/build/src/netwerk/base/nsLoadGroup.cpp, line 584
[task 2020-01-11T02:03:39.764Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/workspace/build/src/dom/base/WindowDestroyedEvent.cpp, line 106
[task 2020-01-11T02:03:39.820Z] 02:03:39 INFO - GECKO(5385) | [Parent 5385, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2020-01-11T02:03:39.837Z] 02:03:39 INFO - GECKO(5385) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2020-01-11T02:03:39.837Z] 02:03:39 INFO - GECKO(5385) | [Parent 5385, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2020-01-11T02:03:39.837Z] 02:03:39 INFO - GECKO(5385) | [Child 5995, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/workspace/build/src/dom/media/CubebUtils.cpp, line 381
[task 2020-01-11T02:03:39.857Z] 02:03:39 INFO - GECKO(5385) | [Parent 5385, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2020-01-11T02:03:39.859Z] 02:03:39 INFO - GECKO(5385) | [Parent 5385, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2020-01-11T02:03:39.981Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
[task 2020-01-11T02:03:39.982Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
[task 2020-01-11T02:03:39.982Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: NS_ENSURE_TRUE(request) failed: file /builds/worker/workspace/build/src/netwerk/base/nsLoadGroup.cpp, line 584
[task 2020-01-11T02:03:39.984Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
[task 2020-01-11T02:03:39.985Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
[task 2020-01-11T02:03:39.986Z] 02:03:39 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: NS_ENSURE_TRUE(request) failed: file /builds/worker/workspace/build/src/netwerk/base/nsLoadGroup.cpp, line 584
[task 2020-01-11T02:03:40.008Z] 02:03:40 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/workspace/build/src/dom/base/WindowDestroyedEvent.cpp, line 106
[task 2020-01-11T02:03:40.008Z] 02:03:40 INFO - GECKO(5385) | [Child 5561, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/workspace/build/src/dom/base/WindowDestroyedEvent.cpp, line 106
[task 2020-01-11T02:03:40.024Z] 02:03:40 INFO - GECKO(5385) | [Child 5995, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1822
[task 2020-01-11T02:03:40.065Z] 02:03:40 INFO - GECKO(5385) | [Child 5995, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 848
[task 2020-01-11T02:03:40.308Z] 02:03:40 INFO - TEST-INFO | started process screentopng
[task 2020-01-11T02:03:41.074Z] 02:03:41 INFO - TEST-INFO | screentopng: exit 0
[task 2020-01-11T02:03:41.075Z] 02:03:41 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/bugs/test_bug440572.html | received the right number of messages. - got +0, expected 4
[task 2020-01-11T02:03:41.075Z] 02:03:41 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:325:16
[task 2020-01-11T02:03:41.075Z] 02:03:41 INFO - runtests@dom/tests/mochitest/bugs/test_bug440572.html:30:5
[task 2020-01-11T02:03:41.075Z] 02:03:41 INFO - onload@dom/tests/mochitest/bugs/test_bug440572.html:1:1
[task 2020-01-11T02:03:41.075Z] 02:03:41 INFO - Not taking screenshot here: see the one that was previously logged
Chris, this is how orange Factor looks for the last 30 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-12-12&endday=2020-01-11&tree=trunk&bug=1585859. Can you please take a look again?
For Comment 1, there was a spike 3 months ago.
Thank you!
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 27•5 years ago
|
||
I have been mistakenly added to this ticket for more info. Since one of the contributors of this ticket has a similar name as myself.
Updated•5 years ago
|
Comment hidden (typo) |
Comment 29•5 years ago
|
||
WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
Matt, does this warning indicate a bug in DocumentChannel or a bug in the caller?
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 34•5 years ago
|
||
(In reply to Chris Peterson [:cpeterson] from comment #29)
WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 64
Matt, does this warning indicate a bug in DocumentChannel or a bug in the caller?
Neither, it's just overzealous. I'll remove it in bug 1612683.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 37•5 years ago
|
||
Over the last 7 days there are a total of 32 failures on this bug. These happen on windows10-64-qr, linux1804-64-qr and linux1804-64
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=291938739&repo=autoland&lineNumber=3814
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 42•5 years ago
|
||
Comment 43•5 years ago
|
||
Comment 44•5 years ago
|
||
bugherder |
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Description
•