1926855 - Trying to retrieve the active window after calling "browsingContext.close" can fail due to a race condition

Status: NEW

(Remote Protocol :: WebDriver BiDi, defect, P2)

Description

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

When closing a browser window by calling the browsingContext.close command for the last remaining tab, a call to Services.focus.activeWindow afterward can return a value that is not equal to the browsing window that's open. This does only happen for some some milliseconds given that waiting a bit longer makes it return the correct value. Failures in combination with the new browser.getClientWindows command can be seen here:

https://treeherder.mozilla.org/logviewer?job_id=479529446&repo=try&lineNumber=1664-1670

[task 2024-10-23T15:52:17.722Z] 15:52:17     INFO - PID 669 | 1729698737719	RemoteAgent	DEBUG	WebDriverBiDiConnection 86bfc61f-9509-4266-aa9c-746ee49dd633 -> {"id":4,"method":"browsingContext.close","params":{"context":"a3c4d7aa-0b01-4bd5-bec2-f3b3cb46cb73"}}
[task 2024-10-23T15:52:17.722Z] 15:52:17     INFO - PID 669 | 1729698737720	RemoteAgent	TRACE	Received command browsingContext.close for destination ROOT
[task 2024-10-23T15:52:17.724Z] 15:52:17     INFO - PID 669 | 1729698737723	RemoteAgent	DEBUG	WebDriverBiDiConnection 86bfc61f-9509-4266-aa9c-746ee49dd633 <- {"type":"success","id":4,"result":{}}
[task 2024-10-23T15:52:17.735Z] 15:52:17     INFO - PID 669 | 1729698737734	RemoteAgent	TRACE	[a3c4d7aa-0b01-4bd5-bec2-f3b3cb46cb73] Navigation already marked as finished, navigationId: 032859f7-9b6e-459e-ab5d-738bff5d06bc
[task 2024-10-23T15:52:17.778Z] 15:52:17     INFO - PID 669 | 1729698737777	RemoteAgent	DEBUG	WebDriverBiDiConnection 86bfc61f-9509-4266-aa9c-746ee49dd633 -> {"id":5,"method":"browser.getClientWindows","params":{}}
[task 2024-10-23T15:52:17.779Z] 15:52:17     INFO - PID 669 | 1729698737777	RemoteAgent	TRACE	Received command browser.getClientWindows for destination ROOT
[task 2024-10-23T15:52:17.779Z] 15:52:17     INFO - PID 669 | 1729698737777	RemoteAgent	DEBUG	WebDriverBiDiConnection 86bfc61f-9509-4266-aa9c-746ee49dd633 <- {"type":"success","id":5,"result":{"clientWindows":[{"active":false,"clientWindow":"6af0e13d-abde-4d92-9c34-439598c9070f","height":600,"state":"normal","width":800,"x":100,"y":100}]}}

Waiting an extra 1s in the test makes the failures to go away:
https://treeherder.mozilla.org/jobs?repo=try&revision=46e6734187d6aa300d68196a63f7853d02f56482

As such we should probably wait when closing the window to get an activate notification on any open window, or if that cannot easily be done we maybe could check Services.focus.activeWindow directly for validity before returning.

Comment 1

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

This issue actually only happens on Linux (non Wayland) jobs.

Comment 2

[Dan]

Thanks @whimboo. I will pick this up

Comment 3

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

It's strange. In a new try build the related tests are now in Wd1 and no longer in Wd2. With that change of chunk the tests are no longer perma-fail but started to always pass:

https://treeherder.mozilla.org/jobs?repo=try&revision=845b389d418fba341b9ad6164754df1951713bb8

I assume that there was some other test running before the affected ones which caused the active state not have been immediately updated.

For now I would suggest that we land the new tests as expected pass on Linux non-Wayland and observe test failures over the next one or two weeks.

Comment 4

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

This is very suspicious. In both cases whether the test runs in Wd1 or in Wd2 it is the very first test file that gets run. Here the try jobs that were running:

• with failures: https://treeherder.mozilla.org/logviewer?job_id=479529446&repo=try&lineNumber=1536
• without failures: https://treeherder.mozilla.org/logviewer?job_id=481228934&repo=try&lineNumber=1526

I just got it again for a try build running with the remote.events.async.enabled preference turned on:
https://treeherder.mozilla.org/logviewer?job_id=482280948&repo=try&lineNumber=1464

Comment 5

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

Bug 1929494 is the actual intermittent failure bug and we got 5 failures this week.