Open Bug 1941264 Opened 1 month ago Updated 1 month ago

Intermittent ASAN remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | Missing expected exception Caught the expected error when navigating

Categories

(Remote Protocol :: Agent, defect, P5)

defect

Tracking

(firefox-esr128 unaffected, firefox134 affected, firefox135 affected, firefox136 affected)

Tracking Status
firefox-esr128 --- unaffected
firefox134 --- affected
firefox135 --- affected
firefox136 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression)

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


[task 2025-01-12T11:02:35.206Z] 11:02:35     INFO - 
[task 2025-01-12T11:02:35.207Z] 11:02:35     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.com/document-builder.sjs?html=tab" line: 0}]
[task 2025-01-12T11:02:35.207Z] 11:02:35     INFO - Call a module method which will throw
[task 2025-01-12T11:02:35.208Z] 11:02:35     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.com/document-builder.sjs?html=tab" line: 0}]
[task 2025-01-12T11:02:35.209Z] 11:02:35     INFO - Leaving test bound test_default_retry
[task 2025-01-12T11:02:35.209Z] 11:02:35     INFO - Entering test bound test_forced_no_retry
[task 2025-01-12T11:02:35.210Z] 11:02:35     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.com/document-builder.sjs?html=tab" line: 0}]
[task 2025-01-12T11:02:35.211Z] 11:02:35     INFO - Call a module method which will throw
[task 2025-01-12T11:02:35.211Z] 11:02:35     INFO - Buffered messages logged at 11:02:33
[task 2025-01-12T11:02:35.212Z] 11:02:35     INFO - Console message: [JavaScript Error: "DiscardedBrowsingContextError: Actor 'MessageHandlerFrame' destroyed before query 'MessageHandlerFrameParent:sendCommand' was resolved" {file: "chrome://remote/content/shared/RemoteError.sys.mjs" line: 8}]
[task 2025-01-12T11:02:35.212Z] 11:02:35     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.com/document-builder.sjs?html=tab" line: 0}]
[task 2025-01-12T11:02:35.213Z] 11:02:35     INFO - TEST-PASS | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | Caught the expected error when reloading - 
[task 2025-01-12T11:02:35.214Z] 11:02:35     INFO - Leaving test bound test_forced_no_retry
[task 2025-01-12T11:02:35.214Z] 11:02:35     INFO - Entering test bound test_forced_no_retry_cross_group
[task 2025-01-12T11:02:35.215Z] 11:02:35     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.com/document-builder.sjs?html=COM%3Cscript%20type=%27text/javascript%27%3Ewindow.onunload%20=%20function()%20{};%3C/script%3E" line: 0}]
[task 2025-01-12T11:02:35.216Z] 11:02:35     INFO - TEST-PASS | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | blockedOneTime should not have resolved yet - 
[task 2025-01-12T11:02:35.227Z] 11:02:35     INFO - TEST-PASS | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | waitForDiscardedBrowsingContext should not have resolved yet - 
[task 2025-01-12T11:02:35.228Z] 11:02:35     INFO - Navigate to example.net with COOP headers to destroy browsing context
[task 2025-01-12T11:02:35.230Z] 11:02:35     INFO - Buffered messages logged at 11:02:34
[task 2025-01-12T11:02:35.230Z] 11:02:35     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.net/document-builder.sjs?headers=Cross-Origin-Opener-Policy:same-origin&html=NET" line: 0}]
[task 2025-01-12T11:02:35.231Z] 11:02:35     INFO - TEST-PASS | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | Caught the expected error when navigating - 
[task 2025-01-12T11:02:35.232Z] 11:02:35     INFO - Buffered messages finished
[task 2025-01-12T11:02:35.239Z] 11:02:35     INFO - TEST-UNEXPECTED-FAIL | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | Missing expected exception Caught the expected error when navigating - 
[task 2025-01-12T11:02:35.240Z] 11:02:35     INFO - Stack trace:
[task 2025-01-12T11:02:35.241Z] 11:02:35     INFO - chrome://mochitests/content/browser/remote/shared/messagehandler/test/browser/browser_handle_command_retry.js:test_forced_no_retry_cross_group:192
[task 2025-01-12T11:02:35.242Z] 11:02:35     INFO - chrome://mochikit/content/browser-test.js:handleTask:1147
[task 2025-01-12T11:02:35.243Z] 11:02:35     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1219
[task 2025-01-12T11:02:35.243Z] 11:02:35     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1360
[task 2025-01-12T11:02:35.244Z] 11:02:35     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1136
[task 2025-01-12T11:02:35.246Z] 11:02:35     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058

This seems to be an issue with retrying a command and the JSWindowActor getting destroyed while navigating:

[task 2025-01-12T11:02:32.427Z] 11:02:32     INFO - GECKO(9952) | 1736679752426	RemoteAgent	TRACE	Received command retry.blockedOneTime for destination WINDOW_GLOBAL
[task 2025-01-12T11:02:32.437Z] 11:02:32     INFO - GECKO(9952) | 1736679752436	RemoteAgent	TRACE	[45] NavigationListenerChild Loading state: flags: 131088, status: 0,  isStart: false, isStop: true, isNetwork: false, isBindingAborted: false, targetURI: https://example.com/document-builder.sjs?html=tab
[task 2025-01-12T11:02:32.444Z] 11:02:32     INFO - GECKO(9952) | 1736679752443	RemoteAgent	TRACE	[7b94705f-690d-407a-a009-218b7b2224a5] Navigation finished for url: https://example.com/document-builder.sjs?html=tab (56bd1e98-1607-4178-b2a0-b490eb603793)
[task 2025-01-12T11:02:32.445Z] 11:02:32     INFO - GECKO(9952) | 1736679752445	RemoteAgent	TRACE	Received command retry.cleanup for destination WINDOW_GLOBAL
[task 2025-01-12T11:02:32.447Z] 11:02:32     INFO - GECKO(9952) | 1736679752446	RemoteAgent	TRACE	Received command retry.cleanup for destination WINDOW_GLOBAL
[task 2025-01-12T11:02:32.460Z] 11:02:32     INFO - GECKO(9952) | 1736679752458	RemoteAgent	TRACE	MessageHandler ROOT for session session-id-no-retry is being destroyed
[task 2025-01-12T11:02:32.460Z] 11:02:32     INFO - GECKO(9952) | 1736679752458	RemoteAgent	TRACE	Unregistered MessageHandler ROOT for session session-id-no-retry
[task 2025-01-12T11:02:32.468Z] 11:02:32     INFO - GECKO(9952) | 1736679752466	RemoteAgent	TRACE	MessageHandler WINDOW_GLOBAL for session session-id-no-retry is being destroyed
[task 2025-01-12T11:02:32.468Z] 11:02:32     INFO - GECKO(9952) | 1736679752466	RemoteAgent	TRACE	Unregistered MessageHandler WINDOW_GLOBAL for session session-id-no-retry
[task 2025-01-12T11:02:32.910Z] 11:02:32     INFO - GECKO(9952) | 1736679752909	RemoteAgent	TRACE	Created MessageHandler ROOT for session session-id-no-retry
[task 2025-01-12T11:02:32.913Z] 11:02:32     INFO - GECKO(9952) | 1736679752911	RemoteAgent	TRACE	Received command retry.blockedOneTime for destination WINDOW_GLOBAL
[task 2025-01-12T11:02:32.939Z] 11:02:32     INFO - GECKO(9952) | 1736679752938	RemoteAgent	TRACE	Created MessageHandler WINDOW_GLOBAL for session session-id-no-retry
[task 2025-01-12T11:02:32.942Z] 11:02:32     INFO - GECKO(9952) | 1736679752941	RemoteAgent	TRACE	Received command retry.blockedOneTime for destination WINDOW_GLOBAL
[task 2025-01-12T11:02:32.986Z] 11:02:32     INFO - GECKO(9952) | 1736679752984	RemoteAgent	TRACE	[46] NavigationListenerChild Loading state: flags: 983041, status: 0,  isStart: true, isStop: false, isNetwork: true, isBindingAborted: false, targetURI: https://example.com/document-builder.sjs?html=tab
[task 2025-01-12T11:02:33.001Z] 11:02:33     INFO - GECKO(9952) | 1736679752987	RemoteAgent	TRACE	[166db638-7c98-445e-ad22-602bfc494613] Navigation started for url: https://example.com/document-builder.sjs?html=tab (7f45d868-a114-4e54-a543-5ceeb986ab1a)
[task 2025-01-12T11:02:33.134Z] 11:02:33     INFO - GECKO(9952) | 1736679753133	RemoteAgent	TRACE	[46] NavigationListenerChild Loading state: flags: 196610, status: 0,  isStart: false, isStop: false, isNetwork: false, isBindingAborted: false, targetURI: https://example.com/document-builder.sjs?html=tab
[task 2025-01-12T11:02:33.162Z] 11:02:33     INFO - GECKO(9952) | 1736679753161	RemoteAgent	TRACE	[46] NavigationListenerChild Loading state: flags: 196612, status: 0,  isStart: false, isStop: false, isNetwork: false, isBindingAborted: false, targetURI: https://example.com/document-builder.sjs?html=tab
[task 2025-01-12T11:02:33.174Z] 11:02:33     INFO - GECKO(9952) | JavaScript error: chrome://remote/content/shared/RemoteError.sys.mjs, line 8: DiscardedBrowsingContextError: Actor 'MessageHandlerFrame' destroyed before query 'MessageHandlerFrameParent:sendCommand' was resolved

Whenever this failure is logged it seems to as well happen for the retry.blockedOneTime test command. This is interesting because a discarded browsing context we actually would expect for the retry.waitForDiscardedBrowsingContext test command.

Blocks: 1927689

Moving the regression to bug 1927689.

Keywords: regression
Regressed by: 1927073

Set release status flags based on info from the regressing bug 1927073

The interesting fact for this failure is that it started on December 29th on autoland and then also appeared first on beta on December 30th. We didn't land any patches and as well didn't uplift. Maybe it was wrongly classified before?

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