Intermittent toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html | message queue is empty - got "[\"onBeforeRequest\"]", expected "[]"
Categories
(WebExtensions :: General, defect, P5)
Tracking
(firefox-esr102 wontfix, firefox113 wontfix, firefox114 fixed)
People
(Reporter: intermittent-bug-filer, Assigned: robwu)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [retriggered][stockwell disabled][addons-jira])
Attachments
(2 files)
(deleted),
patch
|
aryx
:
review+
|
Details | Diff | Splinter Review |
(deleted),
text/x-phabricator-request
|
Details |
Filed by: dvarga [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=193681320&repo=mozilla-central https://queue.taskcluster.net/v1/task/P1GDGxlCS9W4mm1p6qwlZw/runs/0/artifacts/public/logs/live_backing.log [task 2018-08-13T17:05:46.688Z] 17:05:46 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html | null principal documentUrl for sandboxed request [task 2018-08-13T17:05:46.688Z] 17:05:46 INFO - Buffered messages logged at 17:05:46 [task 2018-08-13T17:05:46.689Z] 17:05:46 INFO - AddTask.js | Leaving test test_webRequest_main_frame [task 2018-08-13T17:05:46.689Z] 17:05:46 INFO - Buffered messages finished [task 2018-08-13T17:05:46.689Z] 17:05:46 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html | message queue is empty - got "[\"onBeforeRequest\"]", expected "[]" [task 2018-08-13T17:05:46.689Z] 17:05:46 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:312:5 [task 2018-08-13T17:05:46.689Z] 17:05:46 INFO - ExtensionTestUtils.loadExtension/<@SimpleTest/ExtensionTestUtils.js:27:7 [task 2018-08-13T17:05:46.692Z] 17:05:46 INFO - executeCleanupFunction@SimpleTest/SimpleTest.js:1227:19 [task 2018-08-13T17:05:46.693Z] 17:05:46 INFO - executeCleanupFunction@SimpleTest/SimpleTest.js:1236:13 [task 2018-08-13T17:05:46.694Z] 17:05:46 INFO - SimpleTest.finish@SimpleTest/SimpleTest.js:1240:5 [task 2018-08-13T17:05:46.694Z] 17:05:46 INFO - add_task/</<@SimpleTest/AddTask.js:72:11 [task 2018-08-13T17:05:46.695Z] 17:05:46 INFO - async*add_task/<@SimpleTest/AddTask.js:31:10 [task 2018-08-13T17:05:46.695Z] 17:05:46 INFO - setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:676:12 [task 2018-08-13T17:05:46.696Z] 17:05:46 INFO - add_task@SimpleTest/AddTask.js:30:7 [task 2018-08-13T17:05:46.697Z] 17:05:46 INFO - @toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html:190:1 [task 2018-08-13T17:05:46.697Z] 17:05:46 INFO - GECKO(3067) | MEMORY STAT | vsize 1744MB | residentFast 371MB | heapAllocated 34MB [task 2018-08-13T17:05:46.699Z] 17:05:46 INFO - TEST-OK | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html | took 7198ms [task 2018-08-13T17:05:46.699Z] 17:05:46 INFO - GECKO(3067) | [Parent 3067, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/DOMEventTargetHelper.h, line 146 [task 2018-08-13T17:05:46.700Z] 17:05:46 INFO - GECKO(3067) | [Parent 3067, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/DOMEventTargetHelper.h, line 146 [task 2018-08-13T17:05:46.701Z] 17:05:46 ERROR - /tests/toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html logged result after SimpleTest.finish(): message queue is empty [task 2018-08-13T17:05:46.702Z] 17:05:46 INFO - GECKO(3067) | ++DOMWINDOW == 26 (0x7f3eac56e000) [pid = 3123] [serial = 352] [outer = 0x7f3eb378d800] [task 2018-08-13T17:05:46.703Z] 17:05:46 INFO - TEST-START | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_redirect_data_uri.html [task 2018-08-13T17:05:46.780Z] 17:05:46 INFO - GECKO(3067) | ++DOMWINDOW == 27 (0x7f3eac56c400) [pid = 3123] [serial = 353] [outer = 0x7f3eb378d800] [task 2018-08-13T17:05:47.971Z] 17:05:47 INFO - GECKO(3067) | Console message: Warning: attempting to write 9598 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes. [task 2018-08-13T17:05:47.972Z] 17:05:47 INFO - GECKO(3067) | Console message: [JavaScript Warning: "The character encoding of a framed document was not declared. The document may appear different if viewed without the document framing it." {file: "http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_redirect_data_uri.html" line: 0}] [task 2018-08-13T17:05:48.053Z] 17:05:48 INFO - GECKO(3067) | [Parent 3067, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 342 [task 2018-08-13T17:05:48.135Z] 17:05:48 INFO - GECKO(3067) | ++DOCSHELL 0x7f5fea777800 == 9 [pid = 3067] [id = {cf97e0e9-7e32-470b-aadc-67f0a16ebaab}] [task 2018-08-13T17:05:48.137Z] 17:05:48 INFO - GECKO(3067) | ++DOMWINDOW == 35 (0x7f5ff9b2dc00) [pid = 3067] [serial = 482] [outer = (nil)]
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 5•6 years ago
|
||
There have been 34 failures in the last week. Failures occur only on debug. The most affected platform is linux64-qr. Recent relevant log: https://treeherder.mozilla.org/logviewer.html#?job_id=198202225&repo=mozilla-inbound&lineNumber=20401 [task 2018-09-08T05:26:37.879Z] 05:26:37 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html | sub_frame has ancestors [task 2018-09-08T05:26:37.883Z] 05:26:37 INFO - AddTask.js | Leaving test test_webRequest_main_frame [task 2018-09-08T05:26:37.884Z] 05:26:37 INFO - Buffered messages finished [task 2018-09-08T05:26:37.885Z] 05:26:37 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html | message queue is empty - got "[\"onBeforeRequest\"]", expected "[]" [task 2018-09-08T05:26:37.886Z] 05:26:37 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:312:5 [task 2018-09-08T05:26:37.887Z] 05:26:37 INFO - ExtensionTestUtils.loadExtension/<@SimpleTest/ExtensionTestUtils.js:27:7 [task 2018-09-08T05:26:37.888Z] 05:26:37 INFO - executeCleanupFunction@SimpleTest/SimpleTest.js:1227:19 [task 2018-09-08T05:26:37.889Z] 05:26:37 INFO - executeCleanupFunction@SimpleTest/SimpleTest.js:1236:13 [task 2018-09-08T05:26:37.893Z] 05:26:37 INFO - SimpleTest.finish@SimpleTest/SimpleTest.js:1240:5 [task 2018-09-08T05:26:37.894Z] 05:26:37 INFO - add_task/</<@SimpleTest/AddTask.js:72:11 [task 2018-09-08T05:26:37.894Z] 05:26:37 INFO - async*add_task/<@SimpleTest/AddTask.js:31:10 [task 2018-09-08T05:26:37.894Z] 05:26:37 INFO - setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:676:12 [task 2018-09-08T05:26:37.895Z] 05:26:37 INFO - add_task@SimpleTest/AddTask.js:30:7 [task 2018-09-08T05:26:37.895Z] 05:26:37 INFO - @toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html:190:1 [task 2018-09-08T05:26:37.895Z] 05:26:37 INFO - GECKO(3370) | MEMORY STAT | vsize 1548MB | residentFast 169MB | heapAllocated 32MB [task 2018-09-08T05:26:37.896Z] 05:26:37 INFO - TEST-OK | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_webrequest_frameId.html | took 7619ms
Comment hidden (Intermittent Failures Robot) |
Comment 7•6 years ago
|
||
In the last 7 days there are 92 failures associated with this bug. This started to increase after https://bugzilla.mozilla.org/show_bug.cgi?id=1480951 landed. Did some retriggers and this is the result: https://tinyurl.com/yahx6hn2 Intermittent Failures View: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2018-09-04&endday=2018-09-11&tree=all&bug=1482983 :mconley, Could you please have a look at this frequently failing bug? Thanks!
Comment hidden (Intermittent Failures Robot) |
Comment 10•6 years ago
|
||
I added a patch to disable test_ext_webrequest_frameId.html
Updated•6 years ago
|
![]() |
||
Updated•6 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 12•6 years ago
|
||
Pushed by ebalazs@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/3059f63d7f56 Disable test_ext_webrequest_frameId.html on linux webrender for frequent failures caused by 1480951. r=aryx
Comment 13•6 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/3059f63d7f56
Comment hidden (Intermittent Failures Robot) |
Updated•6 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•6 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Updated•3 years ago
|
Updated•3 years ago
|
Updated•3 years ago
|
Assignee | ||
Comment 64•1 year ago
|
||
I ran all webRequest tests again and encountered this failure again. This is not the first time I'm seeing it. The failure is not even necessary, so I'll attach a patch.
Updated•1 year ago
|
Assignee | ||
Comment 65•1 year ago
|
||
The test was getting stuck because it was expecting a favicon.ico
request that never happened. The test logic was copied from
test_ext_webrequest_filter.html which suffers from exactly the same
issue. Since the favicon.ico test was meant to serve as a regression
test, this patch fixes only one of the two tests.
Comment 66•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Assignee | ||
Comment 67•1 year ago
|
||
Why did the bot close this bug when there is a patch?
Assignee | ||
Updated•1 year ago
|
Comment 68•1 year ago
|
||
Pushed by rob@robwu.nl: https://hg.mozilla.org/integration/autoland/rev/d59210a65575 Fix intermittent test failure in test_ext_webrequest_frameId.html r=rpl
Comment 69•1 year ago
|
||
Backed out for causing failures on test_ext_webrequest_frameId.html
- backout: https://hg.mozilla.org/integration/autoland/rev/b60a5fd35be9bd4cbc2bcbb073a2dbc57a14642a
- push: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&selectedTaskRun=GAGxufejRhOwmDFiTjMrUg.0&revision=d59210a65575c1769326cba0fa9fcd2e8a5faa7e
- failure log: https://treeherder.mozilla.org/logviewer?job_id=414539195&repo=autoland&lineNumber=8821
[task 2023-05-03T20:23:48.070Z] 20:23:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_frameId.html | Got only one request for file_simple_sandboxed_subframe.html
[task 2023-05-03T20:23:48.070Z] 20:23:48 INFO - Waiting for request 12 out of 13
[task 2023-05-03T20:23:48.071Z] 20:23:48 INFO - Expecting one of: example.txt
[task 2023-05-03T20:23:48.071Z] 20:23:48 INFO - Buffered messages finished
[task 2023-05-03T20:23:48.072Z] 20:23:48 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_webrequest_frameId.html | Test timed out. -
[task 2023-05-03T20:23:48.890Z] 20:23:48 INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-05-03T20:23:48.894Z] 20:23:48 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_webrequest_frameId.html | Extension left running at test shutdown
[task 2023-05-03T20:23:48.894Z] 20:23:48 INFO - SimpleTest.ok@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:424:16
[task 2023-05-03T20:23:48.894Z] 20:23:48 INFO - ExtensionTestUtils.loadExtension/<@https://mochi.test:8888/tests/SimpleTest/ExtensionTestUtils.js:132:18
[task 2023-05-03T20:23:48.894Z] 20:23:48 INFO - executeCleanupFunction@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:1527:13
[task 2023-05-03T20:23:48.894Z] 20:23:48 INFO - SimpleTest.finish@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:1541:3
[task 2023-05-03T20:23:48.895Z] 20:23:48 INFO - killTest@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:202:22
[task 2023-05-03T20:23:48.895Z] 20:23:48 INFO - async*delayedKillTest@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:239:17
[task 2023-05-03T20:23:48.895Z] 20:23:48 INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:237:17
[task 2023-05-03T20:23:48.898Z] 20:23:48 INFO - TestRunner.runTests/<@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:530:16
[task 2023-05-03T20:23:48.899Z] 20:23:48 INFO - Async*TestRunner.runTests@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:517:48
[task 2023-05-03T20:23:48.899Z] 20:23:48 INFO - RunSet.runtests@https://mochi.test:8888/tests/SimpleTest/setup.js:276:14
[task 2023-05-03T20:23:48.899Z] 20:23:48 INFO - RunSet.runall@https://mochi.test:8888/tests/SimpleTest/setup.js:255:12
[task 2023-05-03T20:23:48.899Z] 20:23:48 INFO - getPrefList/<@https://mochi.test:8888/tests/SimpleTest/setup.js:342:14
[task 2023-05-03T20:23:48.899Z] 20:23:48 INFO - loadFile/req.onload@https://mochi.test:8888/tests/SimpleTest/setup.js:80:19
[task 2023-05-03T20:23:48.900Z] 20:23:48 INFO - EventHandlerNonNull*loadFile@https://mochi.test:8888/tests/SimpleTest/setup.js:75:3
[task 2023-05-03T20:23:48.900Z] 20:23:48 INFO - getPrefList@https://mochi.test:8888/tests/SimpleTest/setup.js:340:13
[task 2023-05-03T20:23:48.900Z] 20:23:48 INFO - hookupTests@https://mochi.test:8888/tests/SimpleTest/setup.js:363:5
[task 2023-05-03T20:23:48.900Z] 20:23:48 INFO - parseTestManifest@https://mochi.test:8888/manifestLibrary.js:53:13
[task 2023-05-03T20:23:48.900Z] 20:23:48 INFO - getTestManifest/req.onload@https://mochi.test:8888/manifestLibrary.js:66:28
[task 2023-05-03T20:23:48.900Z] 20:23:48 INFO - EventHandlerNonNull*getTestManifest@https://mochi.test:8888/manifestLibrary.js:62:3
[task 2023-05-03T20:23:48.900Z] 20:23:48 INFO - hookup@https://mochi.test:8888/tests/SimpleTest/setup.js:328:20
[task 2023-05-03T20:23:48.900Z] 20:23:48 INFO - EventHandlerNonNull*@https://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp&cleanupCrashes=true&ignorePrefsFile=ignorePrefs.json:10:32
[task 2023-05-03T20:23:48.904Z] 20:23:48 INFO - GECKO(5377) | [Parent 5377, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:163
[task 2023-05-03T20:23:48.905Z] 20:23:48 INFO - GECKO(5377) | [Parent 5377, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:163
[task 2023-05-03T20:23:48.914Z] 20:23:48 INFO - GECKO(5377) | [Parent 5377, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57
[task 2023-05-03T20:23:48.927Z] 20:23:48 INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-05-03T20:23:48.929Z] 20:23:48 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_webrequest_frameId.html | message queue is empty - got "[\"tab-created\"]", expected "[]"
Comment 70•1 year ago
|
||
Backout merged to central: https://hg.mozilla.org/mozilla-central/rev/b60a5fd35be9
Assignee | ||
Comment 71•1 year ago
|
||
The test failed on http3 tests, because in that test configuration, there is only a https server, no http.
When I run the test locally in that configuration, ./mach test toolkit/components/extensions/test/mochitest/test_ext_webrequest_frameId.html --tag=remote-webextensions --headless --use-http3-server
, I see the following:
Console message: [JavaScript Error: "Blocked loading mixed active content “http://example.org/example.txt”" {file: "https://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_simple_xhr.html?topframe=true&nocache=0.7112531975458067" line: 14}]
Without --use-http3-server
, I see the following at some point:
INFO Checking details for request 3: {"requestId":"24","url":"http://example.org/example.txt","originUrl":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_simple_xhr.html?topframe=true&nocache=0.02077408161558536",
(... cut off by me)
This looks like a class of problems that may be relevant to others who are interested in re-enabling more tests without skip-if = http3
.
I fixed this particular test by changing http to https at https://searchfox.org/mozilla-central/rev/85b4f7363292b272eb9b606e00de2c37a6be73f0/toolkit/components/extensions/test/mochitest/file_simple_xhr.html#13
Comment 72•1 year ago
|
||
Pushed by rob@robwu.nl: https://hg.mozilla.org/integration/autoland/rev/87f16577a95a Fix intermittent test failure in test_ext_webrequest_frameId.html r=rpl
Comment 73•1 year ago
|
||
bugherder |
Updated•1 year ago
|
Description
•