Perma toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | Test timed out
Categories
(WebExtensions :: General, defect, P2)
Tracking
(firefox95 fixed)
| Tracking | Status | |
|---|---|---|
| firefox95 | --- | fixed |
People
(Reporter: abutkovits, Assigned: rpl)
References
Details
Attachments
(2 external files)
[task 2021-10-02T07:20:26.730Z] 07:20:26 INFO - GECKO(7046) | Console message: Warning: attempting to write 33169 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 2021-10-02T07:20:26.773Z] 07:20:26 INFO - GECKO(7046) | [Child 7047, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp:2864
[task 2021-10-02T07:21:10.861Z] 07:21:10 INFO - GECKO(7046) | 1633159270860 addons.xpi ERROR System addon update list error Error: got node name: html, expected: updates
[task 2021-10-02T07:21:10.863Z] 07:21:10 INFO - GECKO(7046) | Console message: [JavaScript Error: "1633159270860 addons.xpi ERROR System addon update list error Error: got node name: html, expected: updates" {file: "resource://gre/modules/Log.jsm" line: 723}]
[task 2021-10-02T07:21:10.863Z] 07:21:10 INFO - GECKO(7046) | append@resource://gre/modules/Log.jsm:723:12
[task 2021-10-02T07:21:10.864Z] 07:21:10 INFO - GECKO(7046) | log@resource://gre/modules/Log.jsm:379:16
[task 2021-10-02T07:21:10.864Z] 07:21:10 INFO - GECKO(7046) | error@resource://gre/modules/Log.jsm:387:10
[task 2021-10-02T07:21:10.864Z] 07:21:10 INFO - GECKO(7046) | updateSystemAddons/res<@resource://gre/modules/addons/XPIInstall.jsm:4042:25
[task 2021-10-02T07:25:48.709Z] 07:25:48 INFO - TEST-INFO | started process screencapture
[task 2021-10-02T07:25:48.830Z] 07:25:48 INFO - TEST-INFO | screencapture: exit 0
[task 2021-10-02T07:25:48.830Z] 07:25:48 INFO - Buffered messages logged at 07:20:25
[task 2021-10-02T07:25:48.830Z] 07:25:48 INFO - Error: Unable to restore focus, expect failures and timeouts.
[task 2021-10-02T07:25:48.831Z] 07:25:48 INFO - Buffered messages logged at 07:20:26
[task 2021-10-02T07:25:48.831Z] 07:25:48 INFO - add_task | Entering test setup
[task 2021-10-02T07:25:48.832Z] 07:25:48 INFO - Extension loaded
[task 2021-10-02T07:25:48.832Z] 07:25:48 INFO - adding listener for onBeforeRequest
[task 2021-10-02T07:25:48.832Z] 07:25:48 INFO - adding listener for onBeforeSendHeaders
[task 2021-10-02T07:25:48.833Z] 07:25:48 INFO - adding listener for onSendHeaders
[task 2021-10-02T07:25:48.833Z] 07:25:48 INFO - adding listener for onBeforeRedirect
[task 2021-10-02T07:25:48.833Z] 07:25:48 INFO - adding listener for onHeadersReceived
[task 2021-10-02T07:25:48.834Z] 07:25:48 INFO - adding listener for onResponseStarted
[task 2021-10-02T07:25:48.834Z] 07:25:48 INFO - adding listener for onCompleted
[task 2021-10-02T07:25:48.835Z] 07:25:48 INFO - adding listener for onErrorOccurred
[task 2021-10-02T07:25:48.835Z] 07:25:48 INFO - add_task | Leaving test setup
[task 2021-10-02T07:25:48.835Z] 07:25:48 INFO - add_task | Entering test test_webRequest_links
[task 2021-10-02T07:25:48.836Z] 07:25:48 INFO - onBeforeRequest 1791 http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_style_bad.css
[task 2021-10-02T07:25:48.836Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | received onBeforeRequest
[task 2021-10-02T07:25:48.837Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | resource type is correct - Expected: stylesheet, Actual: stylesheet
[task 2021-10-02T07:25:48.837Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | origin is correct - Expected: http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html, Actual: http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html
[task 2021-10-02T07:25:48.838Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | tabId 1
[task 2021-10-02T07:25:48.838Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | requestId 1791
[task 2021-10-02T07:25:48.839Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | valid resource type stylesheet
[task 2021-10-02T07:25:48.839Z] 07:25:48 INFO - onBeforeRequest cancel request
[task 2021-10-02T07:25:48.840Z] 07:25:48 INFO - onErrorOccurred 1791 http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_style_bad.css
[task 2021-10-02T07:25:48.840Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | received onErrorOccurred
[task 2021-10-02T07:25:48.840Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | resource type is correct - Expected: stylesheet, Actual: stylesheet
[task 2021-10-02T07:25:48.841Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | origin is correct - Expected: http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html, Actual: http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html
[task 2021-10-02T07:25:48.842Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | correct requestId - Expected: 1791, Actual: 1791
[task 2021-10-02T07:25:48.842Z] 07:25:48 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | correct tabId - Expected: 1, Actual: 1
[task 2021-10-02T07:25:48.842Z] 07:25:48 INFO - Buffered messages finished
[task 2021-10-02T07:25:48.843Z] 07:25:48 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | Test timed out. -
[task 2021-10-02T07:25:49.789Z] 07:25:49 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-10-02T07:25:49.790Z] 07:25:49 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | Extension left running at test shutdown
[task 2021-10-02T07:25:49.790Z] 07:25:49 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2021-10-02T07:25:49.790Z] 07:25:49 INFO - ExtensionTestUtils.loadExtension/<@SimpleTest/ExtensionTestUtils.js:117:18
[task 2021-10-02T07:25:49.790Z] 07:25:49 INFO - executeCleanupFunction@SimpleTest/SimpleTest.js:1487:13
[task 2021-10-02T07:25:49.790Z] 07:25:49 INFO - SimpleTest.finish@SimpleTest/SimpleTest.js:1501:3
[task 2021-10-02T07:25:49.790Z] 07:25:49 INFO - killTest@SimpleTest/TestRunner.js:194:22
[task 2021-10-02T07:25:49.798Z] 07:25:49 INFO - GECKO(7046) | [Child 7047, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2021-10-02T07:25:49.803Z] 07:25:49 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-10-02T07:25:49.804Z] 07:25:49 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | no tasks awaiting on messages - got "[\"done\"]", expected "[]"
[task 2021-10-02T07:25:49.804Z] 07:25:49 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:500:14
[task 2021-10-02T07:25:49.804Z] 07:25:49 INFO - ExtensionTestUtils.loadExtension/<@SimpleTest/ExtensionTestUtils.js:36:18
[task 2021-10-02T07:25:49.804Z] 07:25:49 INFO - executeCleanupFunction@SimpleTest/SimpleTest.js:1487:13
[task 2021-10-02T07:25:50.832Z] 07:25:50 INFO - GECKO(7046) | MEMORY STAT | vsize 6715MB | residentFast 142MB | heapAllocated 15MB
[task 2021-10-02T07:25:51.967Z] 07:25:51 INFO - TEST-OK | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | took 329885ms
[task 2021-10-02T07:25:55.230Z] 07:25:55 INFO - Error: Unable to restore focus, expect failures and timeouts.
[task 2021-10-02T07:25:55.243Z] 07:25:55 ERROR - TEST-UNEXPECTED-FAIL | /tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html logged result after SimpleTest.finish(): Extension left running at test shutdown
[task 2021-10-02T07:25:55.244Z] 07:25:55 ERROR - TEST-UNEXPECTED-FAIL | /tests/toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html logged result after SimpleTest.finish(): no tasks awaiting on messages
[task 2021-10-02T07:25:55.260Z] 07:25:55 INFO - TEST-START | toolkit/components/extensions/test/mochitest/test_ext_webrequest_errors.html
[task 2021-10-02T07:25:58.937Z] 07:25:58 INFO - GECKO(7046) | 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_ext_webrequest_errors.html" line: 0}]
[task 2021-10-02T07:26:00.032Z] 07:26:00 INFO - GECKO(7046) | Console message: Warning: attempting to write 33249 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 2021-10-02T07:26:00.073Z] 07:26:00 INFO - GECKO(7046) | [Child 7047, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp:2864
[task 2021-10-02T07:26:00.254Z] 07:26:00 INFO - GECKO(7046) | [Parent 7046, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/netwerk/protocol/res/SubstitutingProtocolHandler.cpp:415
[task 2021-10-02T07:26:00.278Z] 07:26:00 INFO - GECKO(7046) | [Parent 7046, Main Thread] WARNING: 'aOwner->IsDiscarded()', file /builds/worker/workspace/obj-build/dist/include/mozilla/dom/SyncedContextInlines.h:92
[task 2021-10-02T07:26:00.286Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/checkouts/gecko/widget/cocoa/nsAppShell.mm:798
[task 2021-10-02T07:26:00.289Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:527
[task 2021-10-02T07:26:00.291Z] 07:26:00 INFO - GECKO(7046) | [Child 7047, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2021-10-02T07:26:00.297Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:527
[task 2021-10-02T07:26:00.305Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:527
[task 2021-10-02T07:26:00.310Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:527
[task 2021-10-02T07:26:00.312Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3357
[task 2021-10-02T07:26:00.314Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:527
[task 2021-10-02T07:26:00.316Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:527
[task 2021-10-02T07:26:00.316Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:527
[task 2021-10-02T07:26:00.318Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:527
[task 2021-10-02T07:26:00.321Z] 07:26:00 INFO - GECKO(7046) | [Child 7312, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4438
[task 2021-10-02T07:26:01.070Z] 07:26:01 INFO - GECKO(7046) | MEMORY STAT | vsize 6715MB | residentFast 142MB | heapAllocated 15MB
[task 2021-10-02T07:26:02.229Z] 07:26:02 INFO - TEST-OK | toolkit/components/extensions/test/mochitest/test_ext_webrequest_errors.html | took 6969ms
[task 2021-10-02T07:26:05.513Z] 07:26:05 INFO - Error: Unable to restore focus, expect failures and timeouts. ```
| Reporter | ||
Updated•5 years ago
|
| Reporter | ||
Updated•5 years ago
|
| Comment hidden (Intermittent Failures Robot) |
Comment 2•5 years ago
|
||
This is permafailing when a specific combination of tests run: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&searchStr=mochitest-plain&revision=acab07e8dc6a0d57a544cb677a0740f3375bc250
- Manifests run:
- docshell/test/mochitest/mochitest.ini
- dom/security/test/csp/mochitest.ini
- toolkit/components/extensions/test/mochitest/mochitest-remote.ini
- toolkit/components/extensions/test/mochitest/mochitest.ini
Example of job with all tests scheduled: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&selectedTaskRun=UuD8acRrTJWfvK8UN9n81Q.0&searchStr=mochitest-plain&test_paths=toolkit%2Fcomponents%2Fextensions%2Ftest%2Fmochitest&revision=9f585ad859364068120a85f87cc93b936dde5d11 . Noticed that the failure is not present.
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=353486397&repo=autoland&lineNumber=11831
[task 2021-10-03T08:47:37.847Z] 08:47:37 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | correct tabId - Expected: 1, Actual: 1
[task 2021-10-03T08:47:37.848Z] 08:47:37 INFO - Buffered messages finished
[task 2021-10-03T08:47:37.848Z] 08:47:37 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | Test timed out. -
[task 2021-10-03T08:47:38.805Z] 08:47:38 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-10-03T08:47:38.805Z] 08:47:38 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_webrequest_basic.html | Extension left running at test shutdown
[task 2021-10-03T08:47:38.805Z] 08:47:38 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2021-10-03T08:47:38.805Z] 08:47:38 INFO - ExtensionTestUtils.loadExtension/<@SimpleTest/ExtensionTestUtils.js:117:18
[task 2021-10-03T08:47:38.805Z] 08:47:38 INFO - executeCleanupFunction@SimpleTest/SimpleTest.js:1487:13
[task 2021-10-03T08:47:38.805Z] 08:47:38 INFO - SimpleTest.finish@SimpleTest/SimpleTest.js:1501:3
[task 2021-10-03T08:47:38.805Z] 08:47:38 INFO - killTest@SimpleTest/TestRunner.js:194:22
[task 2021-10-03T08:47:38.816Z] 08:47:38 INFO - GECKO(3376) | [Child 3377, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2021-10-03T08:47:38.821Z] 08:47:38 INFO - Not taking screenshot here: see the one that was previously logged
Luca, is there any chance you could take a look at this?
Thank you!
| Comment hidden (Intermittent Failures Robot) |
| Assignee | ||
Comment 4•5 years ago
|
||
(In reply to Natalia Csoregi [:nataliaCs] from comment #2)
...
Luca, is there any chance you could take a look at this?
Sure, I'm looking into this (and not clearing the needinfo assigned to me yet, on purpose)
| Assignee | ||
Comment 5•5 years ago
|
||
The underlying reason for the test to fail for a timeout seems to be the same
ones that D94613 was meant to fix.
That patch has been attached and pushed to autoland from Bug 1633189
(see https://bugzilla.mozilla.org/show_bug.cgi?id=1633189#c46), but it seems that
it has been backed out (https://bugzilla.mozilla.org/show_bug.cgi?id=1633189#c47)
and instead we ended up landing a patch (D123339) that skipped the test in
linux-asan-opt.
This patch currently includes the subset of D94613 that does fix the timeout
failures for me locally, without the other changes which look like
prettier-related changes.
Updated•5 years ago
|
| Assignee | ||
Comment 6•5 years ago
|
||
Comment 7•5 years ago
|
||
Changing severity to S? because of intermittent test failure.
| Assignee | ||
Comment 8•5 years ago
|
||
Updated•5 years ago
|
Updated•5 years ago
|
Updated•5 years ago
|
| Assignee | ||
Comment 9•5 years ago
|
||
The last push to try looks pretty good:
The second patch attached is fixing an issue in another mochitest plain test, turned out that it wasn't related to the test_ext_webRequest_basic.html permafailure but the test_ext_new_tab_processType.html is still leaving a tab opened
after the test is completed and that was still something to fix.
As an additional side note (I also added it to the commit message part of the first patch, the one that fixes the perma failures):
-
the favicon requests are only triggered when "browser.chrome.guess_favicon" is set to true
-
mochitest-common.ini is supposed to be setting that pref for all the tests listed in that ini file, but it looks that is the case when the tests run on the build infrastructure, but the prefs listed in mochitest-common.ini are not being picked out when running the same test locally (which was initially preventing me to reproduce the same failure locally)
-
to be able to reproduce the same issue locally I had to set the pref through the command line options (using
mach mochitest --setpref "browser.chrome.guess_favicon=true" ...)
I think it would be good to look more closely into this side of the issue as part of a separate follow up, e.g. we may either:
-
look into making sure that
mach mochitestwould also pick up those prefs from mochitest-common.ini as it seems to happen when the same test runs on the build infrastructure -
or we may move those prefs into the ini files that include mochitest-common.ini and add a comment in mochitest-common.ini to explicitly point out that no prefs should be added into the common ini file
Comment 10•5 years ago
|
||
Comment 11•5 years ago
|
||
| bugherder | ||
https://hg.mozilla.org/mozilla-central/rev/7a1d883c3039
https://hg.mozilla.org/mozilla-central/rev/37746dfa9f06
Description
•