Closed Bug 1775558 Opened 2 years ago Closed 1 year ago

Intermittent browser/components/extensions/test/browser/browser_ext_contextMenus_targetUrlPatterns.js | single tracking bug

Categories

(WebExtensions :: Untriaged, defect, P5)

Product:
WebExtensions
Component:
Untriaged
Type:
defect

Tracking

(firefox118 fixed)

Status:
RESOLVED FIXED
Milestone:
118 Branch
Tracking Flags:
Tracking Status
firefox118 --- fixed

People

(Reporter: jmaher, Assigned: rpl)

References

Details

(Keywords: intermittent-failure, intermittent-testcase, Whiteboard: [stockwell needswork:owner])

Attachments

(1 file)

Bug 1775558 - await on promiseDocumentFlushed before call to openExtensionContextMenu. r?willdurand!
48 bytes, text/x-phabricator-request
Details | Review
No description provided.

Additional information about this bug failures and frequency patterns can be found by running: ./mach test-info failure-report --bug 1775558

Severity: -- → S4
Priority: P3 → P5

Update:

There have been 30 failures within the last 7 days:

  • 16 failures on Linux 18.04 x64 WebRender opt
  • 13 failures on Linux 18.04 x64 WebRender Shippable opt
  • 1 failure on OS X 10.15 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=415668323&repo=autoland&lineNumber=4723

[task 2023-05-13T13:31:08.417Z] 13:31:08     INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_contextMenus_targetUrlPatterns.js | Menu item with targetUrlPattern="<all_urls>" should not be shown at http:// - 
[task 2023-05-13T13:31:08.417Z] 13:31:08     INFO - Leaving test bound unsupportedSchemes
[task 2023-05-13T13:31:08.417Z] 13:31:08     INFO - Entering test bound unsupportedSchemeWithoutPattern
[task 2023-05-13T13:31:08.418Z] 13:31:08     INFO - Extension loaded
[task 2023-05-13T13:31:08.418Z] 13:31:08     INFO - Console message: Warning: attempting to write 13788 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.
[task 2023-05-13T13:31:08.419Z] 13:31:08     INFO - Console message: [JavaScript Error: "TypeError: doc is null" {file: "resource:///actors/ContextMenuChild.sys.mjs" line: 571}]
[task 2023-05-13T13:31:08.419Z] 13:31:08     INFO - Buffered messages finished
[task 2023-05-13T13:31:08.419Z] 13:31:08     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_contextMenus_targetUrlPatterns.js | Test timed out - 
[task 2023-05-13T13:31:08.420Z] 13:31:08     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_contextMenus_targetUrlPatterns.js | Extension left running at test shutdown - 
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - Stack trace:
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - chrome://mochikit/content/browser-test.js:test_ok:1584
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:132
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - chrome://mochikit/content/browser-test.js:nextTest:703
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1440
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1380
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1122
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1056
[task 2023-05-13T13:31:08.421Z] 13:31:08     INFO - GECKO(2493) | [Child 2495, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:57

Tomislav, as the owner of this component, can you help us assign the bug to someone?
Thank you.

Flags: needinfo?(tomica)
Whiteboard: [stockwell needswork:owner]
Flags: needinfo?(tomica)

Update

There have been 32 failures within the last 7 days:

  • 13 failures on Linux 18.04 x64 WebRender opt
  • 12 failures on Linux 18.04 x64 WebRender Shippable opt
  • 6 failures on OS X 10.15 WebRender Shippable opt
  • 1 failure on Windows 11 x86 22H2 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=422352414&repo=autoland&lineNumber=5224

[task 2023-07-11T23:16:03.907Z] 23:16:03     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_contextMenus_targetUrlPatterns.js | Test timed out - 
[task 2023-07-11T23:16:03.908Z] 23:16:03     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-07-11T23:16:03.911Z] 23:16:03     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_contextMenus_targetUrlPatterns.js | Extension left running at test shutdown - 
[task 2023-07-11T23:16:03.911Z] 23:16:03     INFO - Stack trace:
[task 2023-07-11T23:16:03.911Z] 23:16:03     INFO - chrome://mochikit/content/browser-test.js:test_ok:1580
[task 2023-07-11T23:16:03.911Z] 23:16:03     INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:132
[task 2023-07-11T23:16:03.912Z] 23:16:03     INFO - chrome://mochikit/content/browser-test.js:nextTest:702
[task 2023-07-11T23:16:03.912Z] 23:16:03     INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1437
[task 2023-07-11T23:16:03.912Z] 23:16:03     INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1379
[task 2023-07-11T23:16:03.912Z] 23:16:03     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1120
[task 2023-07-11T23:16:03.912Z] 23:16:03     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1056
[task 2023-07-11T23:16:03.912Z] 23:16:03     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-07-11T23:16:03.913Z] 23:16:03     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_contextMenus_targetUrlPatterns.js | Uncaught exception received from previously timed out test bound invalidHttpUrlWithoutPattern - popupshown listener on #contentAreaContextMenu not removed before the end of test
[task 2023-07-11T23:16:03.913Z] 23:16:03     INFO - Entering test bound privileged_are_allowed_to_use_restrictedSchemes

William, can you please assign this to someone?
Thank you.

Flags: needinfo?(wdurand)
Whiteboard: [stockwell unknown] → [stockwell needswork:owner]

Update:
There have been 41 total failures in the last 7 days.
There are:

  • 21 failures on linux1804-64-qr opt
  • 14 failures on linux1804-64-shippable-qr opt
  • 1 failure on macosx1015-64-qr opt
  • 4 failures on macosx1015-64-shippable-qr opt
  • 1 failure on windows11-64-2009-shippable-qr opt

Recent failure log.

Luca, as the owner of this component, can you help us assign the bug to someone? Thank you.

Flags: needinfo?(lgreco)

The timeout failure is hit consistently after the error [JavaScript Error: "TypeError: doc is null" {file: "resource:///actors/ContextMenuChild.sys.mjs" line: 559}] is logged in the console, that is a error that I've seen and investigated before in other intermittents triggered in tests that are using BrowserTestUtils.synthesizeMouseAtCenter, e.g. see Bug 1484789 comment 29.

That underlying issue hit by BrowserTestUtils.synthesizeMouseAtCenter has been also reported by Rob as Bug 1478596, which I'm linking to this bugzilla issue as a seealso.

For this test the call to BrowserTestUtils.synthesizeMouseAtCenter is originated by the openContextMenu helper defined in the head.js file here, through the call to openExtensionContextMenu helper also defined in the head.js file.

There are other tests calling openExtensionContextMenu which are apparently not failing intermittently as often as this one, and so I suspect the chance to hit the issue may be raised a bit by the fact that this test is opening a tab from the test extension side and then as soon as the script loaded in the new tab is hit then it calls openExtensionContextMenu, while some other test like browser_ext_contextMenus.js (which doesn't seem to have any intermittent bugzilla issue open) is opening a new tab using BrowserTestUtils.openNewForegroundTab, awaiting on it and then proceeding with the test of the test and the call to openExtensionContextMenu, my guess is that this sequence is less likely to hit the race that makes BrowserTestUtils.synthesizeMouseAtCenter to hit the "TypeError: doc is null" error.

I couldn't hit this issue often enough locally (I managed to hit it only once in a while) and so I may need to try to hit it in a try push and then try again after applying some changes to the test, e.g. to open the new tab BrowserTestUtils.openNewForegroundTab as browser_ext_contextMenus.js, to confirm if those changes would be enough to stop the intermittency.

Flags: needinfo?(wdurand)
Flags: needinfo?(lgreco)
See Also: → 1478596
Flags: needinfo?(lgreco)
Assignee: nobody → lgreco
Status: NEW → ASSIGNED

As I mentioned in comment 63 yesterday, I proceeded with digging into it some more through some try pushes (given I wasn't able to hit it often enough locally) and based on a number of runs I did with and without the patch attached in comment 64, it seems that awaiting explicitly on promiseDocumentFlushed before calling openExtensionContextMenu the test is not hitting the "TypeError: doc is null" error which was making it to timeout intermittently:

And so it seems that the patch attached may be worth a shot (and in practice it requires less rework of the test than changing the test to open the new tab using BrowserTestUtils.openNewForegroundTab would have required).

Flags: needinfo?(lgreco)
Pushed by luca.greco@alcacoop.it: https://hg.mozilla.org/integration/autoland/rev/588683fe0bb9 await on promiseDocumentFlushed before call to openExtensionContextMenu. r=willdurand

https://hg.mozilla.org/mozilla-central/rev/588683fe0bb9

Status: ASSIGNED → RESOLVED
Closed: 1 year ago
status-firefox118: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 118 Branch

It looks like we are hitting a different one now (from another test task part of the same test file):

These two failure (one hit on the test-verify job when this patch was in autoland, and another one later on) are related to the test case that is covering the reader mode and the underlying issue seems to be the one related to this logged error:

[task 2023-08-03T14:58:36.963Z] 14:58:36     INFO - Console message: [JavaScript Error: "Error: The specified tab cannot be placed into reader mode." {file: "undefined" line: 0}]
[task 2023-08-03T14:58:36.963Z] 14:58:36     INFO - applySafeWithoutClone@resource://gre/modules/ExtensionCommon.sys.mjs:635:24
[task 2023-08-03T14:58:36.963Z] 14:58:36     INFO - wrapPromise/</<@resource://gre/modules/ExtensionCommon.sys.mjs:963:20
[task 2023-08-03T14:58:36.963Z] 14:58:36     INFO - JSActor query*_send@resource://gre/modules/ConduitsChild.sys.mjs:61:11
[task 2023-08-03T14:58:36.963Z] 14:58:36     INFO - _send@resource://gre/modules/ConduitsParent.sys.mjs:288:18
[task 2023-08-03T14:58:36.963Z] 14:58:36     INFO - reply@resource://gre/modules/ExtensionParent.sys.mjs:1091:20
[task 2023-08-03T14:58:36.964Z] 14:58:36     INFO - recvAPICall/<@resource://gre/modules/ExtensionParent.sys.mjs:1129:18
[task 2023-08-03T14:58:36.964Z] 14:58:36     INFO - JSActor query*_send@resource://gre/modules/ConduitsChild.sys.mjs:61:11
[task 2023-08-03T14:58:36.965Z] 14:58:36     INFO - _send@resource://gre/modules/ConduitsChild.sys.mjs:111:18
[task 2023-08-03T14:58:36.965Z] 14:58:36     INFO - callParentAsyncFunction@resource://gre/modules/ExtensionChild.sys.mjs:894:18
[task 2023-08-03T14:58:36.965Z] 14:58:36     INFO - callAsyncFunction@resource://gre/modules/ExtensionChild.sys.mjs:622:33
[task 2023-08-03T14:58:36.965Z] 14:58:36     INFO - stub@resource://gre/modules/Schemas.sys.mjs:2893:30
[task 2023-08-03T14:58:36.965Z] 14:58:36     INFO - background/<@moz-extension://37d4a4be-2499-431a-b67e-73a051cbe6b3/%7B6f16078e-d93d-43c7-93af-592c90f9fd42%7D.js:24:22
[task 2023-08-03T14:58:36.966Z] 14:58:36     INFO - listenerWrapper@chrome://extensions/content/child/ext-test.js:172:22
[task 2023-08-03T14:58:36.966Z] 14:58:36     INFO - applySafeWithoutClone@resource://gre/modules/ExtensionCommon.sys.mjs:635:24
[task 2023-08-03T14:58:36.966Z] 14:58:36     INFO - applySafe@resource://gre/modules/ExtensionCommon.sys.mjs:618:19
[task 2023-08-03T14:58:36.967Z] 14:58:36     INFO - addListener/async/<@resource://gre/modules/ExtensionCommon.sys.mjs:2757:39
[task 2023-08-03T14:58:36.967Z] 14:58:36     INFO - promise callback*async@resource://gre/modules/ExtensionCommon.sys.mjs:2754:34
[task 2023-08-03T14:58:36.967Z] 14:58:36     INFO - handler@chrome://extensions/content/child/ext-test.js:359:20
[task 2023-08-03T14:58:36.967Z] 14:58:36     INFO - emit@resource://gre/modules/ExtensionCommon.sys.mjs:328:32
[task 2023-08-03T14:58:36.967Z] 14:58:36     INFO - receiveMessage@resource://gre/modules/ExtensionChild.sys.mjs:534:13
[task 2023-08-03T14:58:36.967Z] 14:58:36     INFO - MessageListener.receiveMessage*BrowserExtensionContent@resource://gre/modules/ExtensionChild.sys.mjs:410:19
[task 2023-08-03T14:58:36.967Z] 14:58:36     INFO - extensions<@resource://gre/modules/ExtensionProcessScript.sys.mjs:52:10
[task 2023-08-03T14:58:36.967Z] 14:58:36     INFO - get@resource://gre/modules/ExtensionUtils.sys.mjs:91:20
[task 2023-08-03T14:58:36.967Z] 14:58:36     INFO - initExtensionDocument@resource://gre/modules/ExtensionProcessScript.sys.mjs:379:32
[task 2023-08-03T14:58:36.968Z] 14:58:36     INFO - 
[task 2023-08-03T14:58:36.968Z] 14:58:36     INFO - Buffered messages finished
[task 2023-08-03T14:58:36.969Z] 14:58:36     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_contextMenus_targetUrlPatterns.js | Test timed out - 
[task 2023-08-03T14:58:36.969Z] 14:58:36     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-08-03T14:58:36.970Z] 14:58:36     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_contextMenus_targetUrlPatterns.js | no tasks awaiting on messages - Got "[\"readerModeEntered\"]", expected "[]"

The underlying issue may be a different race, but I wouldn't exclude it may be due to similar underlying reasons (the test to trying out to enter the reader mode too soon after opening the new tab).

If that intermittent is hit frequently enough, I'll take a more deeper look into it.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: