Closed Bug 1900732 Opened 2 years ago Closed 1 year ago

Intermittent toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html | single tracking bug

Categories

(WebExtensions :: General, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, intermittent-testcase)

Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=461108145&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/dEWcR3L_RPSHTb6_xzurLw/runs/0/artifacts/public/logs/live_backing.log


[task 2024-06-05T03:04:13.960Z] 03:04:13     INFO - TEST-OK | toolkit/components/extensions/test/mochitest/test_ext_clipboard_image.html | took 1412ms
[task 2024-06-05T03:04:14.135Z] 03:04:14     INFO - TEST-START | toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html
[task 2024-06-05T03:04:14.510Z] 03:04:14     INFO - GECKO(7109) | [Parent 7109, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1215
[task 2024-06-05T03:04:14.637Z] 03:04:14     INFO - GECKO(7109) | [Child 7240, Main Thread] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:380
[task 2024-06-05T03:04:14.637Z] 03:04:14     INFO - GECKO(7109) | [Child 7240, Main Thread] WARNING: Couldn't suspend pump: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:35
[task 2024-06-05T03:04:14.694Z] 03:04:14     INFO - GECKO(7109) | [Child 7240, Main Thread] WARNING: NS_ENSURE_TRUE(mPumpingData) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:379
[task 2024-06-05T03:04:14.694Z] 03:04:14     INFO - GECKO(7109) | [Child 7240, Main Thread] WARNING: Couldn't suspend pump: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:35
[task 2024-06-05T03:04:14.695Z] 03:04:14     INFO - GECKO(7109) | [Child 7240, Main Thread] WARNING: NS_ENSURE_TRUE(mPumpingData) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:379
[task 2024-06-05T03:04:14.695Z] 03:04:14     INFO - GECKO(7109) | [Child 7240, Main Thread] WARNING: Couldn't suspend pump: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:35
[task 2024-06-05T03:04:14.695Z] 03:04:14     INFO - GECKO(7109) | [Child 7240, Main Thread] WARNING: NS_ENSURE_TRUE(mPumpingData) failed: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:379
[task 2024-06-05T03:04:14.695Z] 03:04:14     INFO - GECKO(7109) | [Child 7240, Main Thread] WARNING: Couldn't suspend pump: file /builds/worker/checkouts/gecko/netwerk/base/nsBaseChannel.cpp:35
[task 2024-06-05T03:04:14.733Z] 03:04:14     INFO - GECKO(7109) | Console message: [JavaScript Warning: "Storage access automatically granted for origin “https://example.com” on “https://mochi.test:8888”."]
[task 2024-06-05T03:04:15.394Z] 03:04:15     INFO - GECKO(7109) | [Parent 7109, Main Thread] WARNING: '!top', file /builds/worker/checkouts/gecko/dom/xul/MenuBarListener.cpp:99
[task 2024-06-05T03:09:40.516Z] 03:09:40     INFO - TEST-INFO | started process screentopng
[task 2024-06-05T03:09:40.642Z] 03:09:40     INFO - TEST-INFO | screentopng: exit 0
[task 2024-06-05T03:09:40.643Z] 03:09:40     INFO - Buffered messages logged at 03:04:14
[task 2024-06-05T03:09:40.643Z] 03:09:40     INFO - add_task | Entering test_contentscript_about_blank
[task 2024-06-05T03:09:40.644Z] 03:09:40     INFO - Extension loaded
[task 2024-06-05T03:09:40.644Z] 03:09:40     INFO - Buffered messages finished
[task 2024-06-05T03:09:40.645Z] 03:09:40     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html | Test timed out. - 
[task 2024-06-05T03:09:41.527Z] 03:09:41     INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html | Extension left running at test shutdown 
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - SimpleTest.ok@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:426:16
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - ExtensionTestUtils.loadExtension/<@https://mochi.test:8888/tests/SimpleTest/ExtensionTestUtils.js:132:18
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - executeCleanupFunction@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:1568:13
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - SimpleTest.finish@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:1582:3
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - killTest@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:200:22
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - async*delayedKillTest@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:243:17
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:241:17
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.530Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - setTimeout handler*TestRunner._checkForHangs@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:255:15
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - TestRunner.runTests/<@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:535:16
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - Async*TestRunner.runTests@https://mochi.test:8888/tests/SimpleTest/TestRunner.js:522:48
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - RunSet.runtests@https://mochi.test:8888/tests/SimpleTest/setup.js:285:14
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - RunSet.runall@https://mochi.test:8888/tests/SimpleTest/setup.js:264:12
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - getPrefList/<@https://mochi.test:8888/tests/SimpleTest/setup.js:351:14
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - loadFile/req.onload@https://mochi.test:8888/tests/SimpleTest/setup.js:80:19
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - EventHandlerNonNull*loadFile@https://mochi.test:8888/tests/SimpleTest/setup.js:75:3
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - getPrefList@https://mochi.test:8888/tests/SimpleTest/setup.js:349:13
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - hookupTests@https://mochi.test:8888/tests/SimpleTest/setup.js:372:5
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - parseTestManifest@https://mochi.test:8888/manifestLibrary.js:53:13
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - getTestManifest/req.onload@https://mochi.test:8888/manifestLibrary.js:66:28
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - EventHandlerNonNull*getTestManifest@https://mochi.test:8888/manifestLibrary.js:62:3
[task 2024-06-05T03:09:41.531Z] 03:09:41     INFO - hookup@https://mochi.test:8888/tests/SimpleTest/setup.js:337:20
[task 2024-06-05T03:09:41.531Z] 03:09:41     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 2024-06-05T03:09:41.538Z] 03:09:41     INFO - GECKO(7109) | [Parent 7109, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:163
[task 2024-06-05T03:09:41.538Z] 03:09:41     INFO - GECKO(7109) | [Parent 7109, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:163
[task 2024-06-05T03:09:41.545Z] 03:09:41     INFO - GECKO(7109) | [Parent 7109, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-06-05T03:09:41.545Z] 03:09:41     INFO - GECKO(7109) | [Parent 7109, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-06-05T03:09:41.580Z] 03:09:41     INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-06-05T03:09:41.581Z] 03:09:41     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html | no tasks awaiting on messages - got "[\"all:top\",\"all:about:blank\",\"all:about:srcdoc\"]", expected "[]"
[task 2024-06-05T03:09:41.581Z] 03:09:41     INFO - SimpleTest.is@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:509:14
[task 2024-06-05T03:09:41.582Z] 03:09:41     INFO - ExtensionTestUtils.loadExtension/<@https://mochi.test:8888/tests/SimpleTest/ExtensionTestUtils.js:51:18
[task 2024-06-05T03:09:41.583Z] 03:09:41     INFO - executeCleanupFunction@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:1568:13
[task 2024-06-05T03:09:41.824Z] 03:09:41     INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-06-05T03:09:41.825Z] 03:09:41     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html | Test left extra windows or tabs: {"extraWindows":{},"extraTabs":{"0":"about:blank"}}
[task 2024-06-05T03:09:41.825Z] 03:09:41     INFO -  
[task 2024-06-05T03:09:41.826Z] 03:09:41     INFO - SimpleTest.ok@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:426:16
[task 2024-06-05T03:09:41.827Z] 03:09:41     INFO - @https://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/head.js:26:9
[task 2024-06-05T03:09:41.828Z] 03:09:41     INFO - async*executeCleanupFunction@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:1568:13
[task 2024-06-05T03:09:41.828Z] 03:09:41     INFO - executeCleanupFunction@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:1578:7
[task 2024-06-05T03:09:41.836Z] 03:09:41     INFO - GECKO(7109) | MEMORY STAT | vsize 2593MB | residentFast 142MB | heapAllocated 9MB
[task 2024-06-05T03:09:45.859Z] 03:09:45     INFO - Error: Unable to restore focus, expect failures and timeouts.
[task 2024-06-05T03:09:45.881Z] 03:09:45     INFO - GECKO(7109) | [WARN  neqo_transport::stats] [Client ...] Dropped received packet: Coalesced packet has different DCID; Total: 1
[task 2024-06-05T03:09:45.882Z] 03:09:45     INFO - GECKO(7109) | [WARN  neqo_transport::stats] [Client ...] Dropped received packet: Decryption failure; Total: 2
[task 2024-06-05T03:09:45.882Z] 03:09:45     INFO - GECKO(7109) | [WARN  neqo_transport] Crypto operation failed NssError { name: "SEC_ERROR_BAD_DATA", code: -8190, desc: "security library: received bad data." }
[task 2024-06-05T03:09:45.883Z] 03:09:45     INFO - GECKO(7109) | [WARN  neqo_transport::stats] [Client ...] Dropped received packet: Decryption failure; Total: 3
[task 2024-06-05T03:09:45.890Z] 03:09:45    ERROR - TEST-UNEXPECTED-FAIL | /tests/toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html logged result after SimpleTest.finish(): Extension left running at test shutdown
[task 2024-06-05T03:09:45.891Z] 03:09:45    ERROR - TEST-UNEXPECTED-FAIL | /tests/toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html logged result after SimpleTest.finish(): no tasks awaiting on messages
[task 2024-06-05T03:09:45.893Z] 03:09:45    ERROR - TEST-UNEXPECTED-FAIL | /tests/toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html logged result after SimpleTest.finish(): Test left extra windows or tabs: {"extraWindows":{},"extraTabs":{"0":"about:blank"}}
[task 2024-06-05T03:09:45.893Z] 03:09:45    ERROR - 
[task 2024-06-05T03:09:45.909Z] 03:09:45     INFO - TEST-OK | toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html | took 331774ms

The reported test failures indicate that some scripts did unexpectedly not execute when the result was queried.

1, 2, or both were missing from the expectations expressed at https://searchfox.org/mozilla-central/rev/c5ed4a89fd7a8c878df552e5d53fe50e0088c15b/toolkit/components/extensions/test/mochitest/test_ext_contentscript_about_blank.html#330-336

15 april was the last reported failure on m-c or autoland, so I'm declaring this fixed by bug 1792685. That bug fixes the source of intermittent failures by ensuring that any scheduled scripts run to completion before reporting results with get_seenScripts.js.

Status: NEW → RESOLVED
Closed: 1 year ago
Depends on: 1792685
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.