1927689 - Intermittent remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | single tracking bug

Reporter

Description

•

1 year ago

treeherder

Filed by: amarc [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=480196264&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZjdEf-X2TLGTJl1hbKbvSg/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZjdEf-X2TLGTJl1hbKbvSg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2024-10-29T06:56:18.709Z] 06:56:18     INFO - TEST-PASS | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | Caught the expected error when navigating - 
[task 2024-10-29T06:56:18.710Z] 06:56:18     INFO - Buffered messages finished
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - TEST-UNEXPECTED-FAIL | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | Missing expected exception Caught the expected error when navigating - 
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - Stack trace:
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - chrome://mochitests/content/browser/remote/shared/messagehandler/test/browser/browser_handle_command_retry.js:test_forced_no_retry_cross_group:193
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - chrome://mochikit/content/browser-test.js:handleTask:1145
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1217
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1358
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1134
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - GECKO(3412) | 1730184978571	RemoteAgent	TRACE	Received command retry.cleanup for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - GECKO(3412) | 1730184978580	RemoteAgent	TRACE	Created MessageHandler WINDOW_GLOBAL for session session-id-no-retry
[task 2024-10-29T06:56:18.712Z] 06:56:18     INFO - GECKO(3412) | 1730184978580	RemoteAgent	TRACE	Received command retry.cleanup for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:18.712Z] 06:56:18     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 2024-10-29T06:56:18.713Z] 06:56:18     INFO - GECKO(3412) | 1730184978660	RemoteAgent	TRACE	MessageHandler ROOT for session session-id-no-retry is being destroyed
[task 2024-10-29T06:56:18.713Z] 06:56:18     INFO - GECKO(3412) | 1730184978661	RemoteAgent	TRACE	Unregistered MessageHandler ROOT for session session-id-no-retry
[task 2024-10-29T06:56:18.714Z] 06:56:18     INFO - GECKO(3412) | 1730184978681	RemoteAgent	TRACE	MessageHandler WINDOW_GLOBAL for session session-id-no-retry is being destroyed
[task 2024-10-29T06:56:18.714Z] 06:56:18     INFO - GECKO(3412) | 1730184978681	RemoteAgent	TRACE	Unregistered MessageHandler WINDOW_GLOBAL for session session-id-no-retry
[task 2024-10-29T06:56:18.714Z] 06:56:18     INFO - Leaving test bound test_forced_no_retry_cross_group
[task 2024-10-29T06:56:18.714Z] 06:56:18     INFO - Entering test bound test_forced_retry
[task 2024-10-29T06:56:18.748Z] 06:56:18     INFO - GECKO(3412) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/jr/0y7sf5nx7zn6rqcb6xrhyr_c000014/T/tmpkolldxff.mozrunner/runtests_leaks_tab_pid3452.log
[task 2024-10-29T06:56:18.857Z] 06:56:18     INFO - GECKO(3412) | [Child 3452: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 124820c00 == 1 [pid = 3452] [id = 0]
[task 2024-10-29T06:56:18.858Z] 06:56:18     INFO - GECKO(3412) | [Child 3452: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (108a25a00) [pid = 3452] [serial = 1] [outer = 0]
[task 2024-10-29T06:56:18.859Z] 06:56:18     INFO - GECKO(3412) | [Child 3452: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (124823800) [pid = 3452] [serial = 2] [outer = 108a25a00]
[task 2024-10-29T06:56:19.407Z] 06:56:19     INFO - GECKO(3412) | [Child 3445: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 11df08c00 == 0 [pid = 3445] [id = 0] [url = https://example.net/document-builder.sjs?headers=Cross-Origin-Opener-Policy:same-origin&html=NET]
[task 2024-10-29T06:56:19.407Z] 06:56:19     INFO - GECKO(3412) | [Child 3445: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (10a726600) [pid = 3445] [serial = 1] [outer = 0] [url = https://example.net/document-builder.sjs?headers=Cross-Origin-Opener-Policy:same-origin&html=NET]
[task 2024-10-29T06:56:19.408Z] 06:56:19     INFO - GECKO(3412) | [Child 3445: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (11df0e800) [pid = 3445] [serial = 3] [outer = 0] [url = https://example.net/document-builder.sjs?headers=Cross-Origin-Opener-Policy:same-origin&html=NET]
[task 2024-10-29T06:56:19.408Z] 06:56:19     INFO - GECKO(3412) | [Child 3445: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (11df0bc00) [pid = 3445] [serial = 2] [outer = 0] [url = about:blank]
[task 2024-10-29T06:56:19.418Z] 06:56:19     INFO - GECKO(3412) | [Parent 3412, Main Thread] WARNING: BounceTrackingState::OnDocumentStartRequest failed.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/netwerk/ipc/DocumentLoadListener.cpp:2631
[task 2024-10-29T06:56:19.540Z] 06:56:19     INFO - GECKO(3412) | [Child 3452: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (124823c00) [pid = 3452] [serial = 3] [outer = 108a25a00]
[task 2024-10-29T06:56:19.634Z] 06:56:19     INFO - GECKO(3412) | [Child 3419: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (11e71c000) [pid = 3419] [serial = 4] [outer = 0] [url = about:blank]
[task 2024-10-29T06:56:19.634Z] 06:56:19     INFO - GECKO(3412) | [Child 3419: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (11e71a000) [pid = 3419] [serial = 3] [outer = 0] [url = about:blank]
[task 2024-10-29T06:56:19.786Z] 06:56:19     INFO - GECKO(3412) | 1730184979785	RemoteAgent	TRACE	Created MessageHandler ROOT for session session-id-retry
[task 2024-10-29T06:56:19.786Z] 06:56:19     INFO - GECKO(3412) | 1730184979785	RemoteAgent	TRACE	Received command retry.blockedOneTime for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:19.786Z] 06:56:19     INFO - GECKO(3412) | 1730184979786	RemoteAgent	TRACE	Received command retry.blockedTenTimes for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:19.787Z] 06:56:19     INFO - GECKO(3412) | 1730184979786	RemoteAgent	TRACE	Received command retry.blockedElevenTimes for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:19.788Z] 06:56:19     INFO - Reload one time
[task 2024-10-29T06:56:19.797Z] 06:56:19     INFO - GECKO(3412) | 1730184979796	RemoteAgent	TRACE	Created MessageHandler WINDOW_GLOBAL for session session-id-retry
[task 2024-10-29T06:56:19.797Z] 06:56:19     INFO - GECKO(3412) | 1730184979796	RemoteAgent	TRACE	Received command retry.blockedOneTime for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:19.800Z] 06:56:19     INFO - GECKO(3412) | 1730184979799	RemoteAgent	TRACE	Received command retry.blockedTenTimes for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:19.801Z] 06:56:19     INFO - GECKO(3412) | 1730184979800	RemoteAgent	TRACE	Received command retry.blockedElevenTimes for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:19.838Z] 06:56:19     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 2024-10-29T06:56:19.855Z] 06:56:19     INFO - GECKO(3412) | 1730184979854	RemoteAgent	TRACE	[20] 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 2024-10-29T06:56:19.883Z] 06:56:19     INFO - GECKO(3412) | 1730184979882	RemoteAgent	TRACE	[dcd4c1b0-6e7b-461c-987d-5b02d854bbe2] Navigation started for url: https://example.com/document-builder.sjs?html=tab (15abaaa6-8cb0-4e10-8016-91990d9dcf18)
[task 2024-10-29T06:56:20.189Z] 06:56:20     INFO - GECKO(3412) | 1730184980188	RemoteAgent	TRACE	[20] 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 2024-10-29T06:56:20.238Z] 06:56:20     INFO - GECKO(3412) | [Child 3452: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (124ec9400) [pid = 3452] [serial = 4] [outer = 108a25a00]
[task 2024-10-29T06:56:20.280Z] 06:56:20     INFO - GECKO(3412) | 1730184980279	RemoteAgent	TRACE	[20] 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 2024-10-29T06:56:20.281Z] 06:56:20     INFO - GECKO(3412) | 1730184980279	RemoteAgent	TRACE	[20] 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 2024-10-29T06:56:20.300Z] 06:56:20     INFO - GECKO(3412) | 1730184980299	RemoteAgent	TRACE	[20] 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 2024-10-29T06:56:20.300Z] 06:56:20     INFO - GECKO(3412) | 1730184980299	RemoteAgent	TRACE	[20] 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 2024-10-29T06:56:20.392Z] 06:56:20     INFO - GECKO(3412) | 1730184980391	RemoteAgent	TRACE	RootTransport retrying command retry.blockedOneTime for browsing context 20, attempt: 1.
[task 2024-10-29T06:56:20.393Z] 06:56:20     INFO - GECKO(3412) | 1730184980391	RemoteAgent	TRACE	MessageHandler WINDOW_GLOBAL for session session-id-retry is being destroyed
[task 2024-10-29T06:56:20.393Z] 06:56:20     INFO - GECKO(3412) | 1730184980392	RemoteAgent	TRACE	Unregistered MessageHandler WINDOW_GLOBAL for session session-id-retry
[task 2024-10-29T06:56:20.394Z] 06:56:20     INFO - GECKO(3412) | 1730184980392	RemoteAgent	TRACE	RootTransport retrying command retry.blockedElevenTimes for browsing context 20, attempt: 1.
[task 2024-10-29T06:56:20.394Z] 06:56:20     INFO - GECKO(3412) | 1730184980393	RemoteAgent	TRACE	RootTransport retrying command retry.blockedTenTimes for browsing context 20, attempt: 1.
[task 2024-10-29T06:56:20.551Z] 06:56:20     INFO - GECKO(3412) | 1730184980550	RemoteAgent	TRACE	[dcd4c1b0-6e7b-461c-987d-5b02d854bbe2] Navigation finished for url: https://example.com/document-builder.sjs?html=tab (15abaaa6-8cb0-4e10-8016-91990d9dcf18)
[task 2024-10-29T06:56:20.565Z] 06:56:20     INFO - blockedOneTime should resolve on the first retry
[task 2024-10-29T06:56:20.636Z] 06:56:20     INFO - GECKO(3412) | 1730184980635	RemoteAgent	TRACE	Created MessageHandler WINDOW_GLOBAL for session session-id-retry
[task 2024-10-29T06:56:20.637Z] 06:56:20     INFO - GECKO(3412) | 1730184980635	RemoteAgent	TRACE	Received command retry.blockedOneTime for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:20.648Z] 06:56:20     INFO - GECKO(3412) | 1730184980647	RemoteAgent	TRACE	Received command retry.blockedElevenTimes for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:20.649Z] 06:56:20     INFO - GECKO(3412) | 1730184980648	RemoteAgent	TRACE	Received command retry.blockedTenTimes for destination WINDOW_GLOBAL
[task 2024-10-29T06:56:20.655Z] 06:56:20     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 2024-10-29T06:56:20.679Z] 06:56:20     INFO - TEST-PASS | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | The command was called twice (initial call + 1 retry) -

amarc

Updated

•

1 year ago

Keywords: regression

Regressed by: 1927073

Iulian Moraru

Updated

•

1 year ago

Keywords: regression → intermittent-testcase

No longer regressed by: 1927073

Summary: Intermittent TV remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | Missing expected exception Caught the expected error when navigating - → Intermittent TV remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | single tracking bug

Iulian Moraru

Updated

•

1 year ago

Keywords: regression

Regressed by: 1927073

BugBot [:suhaib / :marco/ :calixte]

Comment 1

•

1 year ago

:whimboo, since you are the author of the regressor, bug 1927073, could you take a look?

For more information, please visit BugBot documentation.

Flags: needinfo?(hskupin)

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 2

•

1 year ago

The failure is not obviously clear. The raised error can even be seen in the log:
https://treeherder.mozilla.org/logviewer?job_id=480196264&repo=autoland&lineNumber=30431-30436

[task 2024-10-29T06:56:18.708Z] 06:56:18     INFO - Navigate to example.net with COOP headers to destroy browsing context
[task 2024-10-29T06:56:18.708Z] 06:56:18     INFO - Buffered messages logged at 06:56:18
[task 2024-10-29T06:56:18.709Z] 06:56:18     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 2024-10-29T06:56:18.709Z] 06:56:18     INFO - TEST-PASS | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | Caught the expected error when navigating - 
[task 2024-10-29T06:56:18.710Z] 06:56:18     INFO - Buffered messages finished
[task 2024-10-29T06:56:18.711Z] 06:56:18     INFO - TEST-UNEXPECTED-FAIL | remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | Missing expected exception Caught the expected error when navigating -

I run the test in verify mode a couple of times but cannot reproduce the failure. Also all the other TV jobs for my landing are working fine:
https://treeherder.mozilla.org/jobs?repo=autoland&revision=d9461994ee82a3124ac366e3d5339f5451b7ea95&searchStr=tv

As such lets observe this failure. It might be a one-off.

Flags: needinfo?(hskupin)

BugBot [:suhaib / :marco/ :calixte]

Comment 3

•

1 year ago

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

status-firefox132: --- → unaffected

status-firefox133: --- → unaffected

status-firefox134: --- → affected

status-firefox-esr128: --- → unaffected

Serban Stanca [:SerbanS]

Updated

•

1 year ago

Summary: Intermittent TV remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | single tracking bug → Intermittent remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | single tracking bug

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 5

•

1 year ago

This fails for slow builds as well. So it might be a race condition.

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+1]

Updated

•

11 months ago

Depends on: 1941264

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 17

•

11 months ago

The regression is now covered by bug 1941264.

Keywords: regression

No longer regressed by: 1927073

Summary: Intermittent remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | single tracking bug → Intermittent ASAN, CCOV remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | single tracking bug

Henrik Skupin [:whimboo][⌚️UTC+1]

Updated

•

11 months ago

Summary: Intermittent ASAN, CCOV remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | single tracking bug → Intermittent remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | single tracking bug

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 34

•

13 days ago

All the latest failures were wrongly classified. There is no more such failure since a month.

Status: NEW → RESOLVED

Closed: 13 days ago

Resolution: --- → INCOMPLETE

	1proc	1proc-s	a11y-checks	a11y-checks-s	a11y-checks-swr	condprof	condprof-s	fis	fis-hv	fis-hv-s	fis-s	headless	headless-s	http2	http3	msix	msix-s	no_variant	nofis	nofis-aab	nofis-s	nofis-ship	nofis-ship-s	nofis-spi	nofis-swr	nofis-swr-s	nogpu	nogpu-s	s	spi	spi-nw	spi-nw-1proc	spi-nw-s	spi-s	swr	swr-s	wr-dc1-p	xorig	xorig-s
linux1804-64-asan-qr/opt																		6
windows11-64-2009-asan-qr/opt																		5

	1proc	1proc-s	fis	fis-hv	fis-hv-s	fis-s	headless	http2	http3	mda-gpu-s	no_variant	nofis	nofis-aab	nofis-s	nofis-ship	nofis-ship-s	nofis-spi	nofis-swr	nofis-swr-s	nogpu	nogpu-s	s	spi	spi-nw	spi-nw-1proc	spi-nw-s	swr	swr-s	wmfme	xorig	xorig-s
linux1804-64-asan-qr/opt											3
linux2204-64-wayland/debug											1
windows11-64-2009-asan-qr/opt											7

	1proc	1proc-s	a11y-checks-swr	a11y-checks-swr-s	fis	fis-hv	fis-hv-s	fis-s	headless	headless-s	http2	http3	msix	no_variant	nofis	nofis-aab	nofis-s	nofis-ship	nofis-ship-s	nofis-spi	nofis-swr	nogpu	nogpu-s	s	spi-nw	swr	swr-s	wmfme	wmfme-s	xorig	xorig-s
linux1804-64-asan-qr/opt														3
windows11-64-2009-asan-qr/opt														3

	no_variant
linux1804-64-asan-qr/opt	8
linux1804-64-ccov-qr/opt	1
windows11-64-2009-asan-qr/opt	2

	no_variant
linux1804-64-asan-qr/-/opt	6
windows11-64-2009-asan-qr/-/opt	8
windows11-64-2009-qr/-/debug	1

	no_variant
linux1804-64-asan-qr--/opt	7
windows11-64-2009-asan-qr--/opt	1

	no_variant
linux1804-64-asan-qr--/opt	5
windows10-64--/asan	1
windows11-64-2009-asan-qr--/opt	1

	no_variant
linux1804-64-asan-qr--/opt	4
windows10-64--/asan	4
windows11-64--/asan	3

	no_variant
linux1804-64-asan-qr--/opt	4
linux2204-64-wayland--/debug	1
macosx1470-64--/debug	2
windows11-64--/asan	2

Intermittent remote/shared/messagehandler/test/browser/browser_handle_command_retry.js | single tracking bug

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Summary

Repository breakdown:

Platform and build breakdown:

Table

For more details, see:

Repository breakdown:

Table

For more details, see:

Repository breakdown: