See https://bugzilla.mozilla.org/show_bug.cgi?id=1774630#c11. No Email response for the request with 100 runs yet. Asked in chat.mozilla.org's #Pernosco channel, waiting for a response from there.

(In reply to Mirko Brodesser (:mbrodesser) from comment #1)

See https://bugzilla.mozilla.org/show_bug.cgi?id=1774630#c11. No Email response for the request with 100 runs yet. Asked in chat.mozilla.org's #Pernosco channel, waiting for a response from there.

Response from #Pernosco channel: that run (plus some I triggered afterwards) didn't reproduce the issue.

Perhaps running that test together with a bunch of the tests which are executed before it may reproduce the issue locally.

Reproduced on Try with additional logging (https://treeherder.mozilla.org/logviewer?job_id=383023745&repo=try&lineNumber=4900). It indicates https://searchfox.org/mozilla-central/rev/9379d512333cb143ed6ee5df5a40274f40d6ce87/dom/events/test/browser_navigator_clipboard_readText.js#246 times out. Adding more logging to narrow this down.

Another Try run, https://treeherder.mozilla.org/logviewer?job_id=383258691&repo=try&lineNumber=4961, revealed OnUserReactedToPasteMenuPopup was called after the native mouse event was created (https://searchfox.org/mozilla-central/rev/9379d512333cb143ed6ee5df5a40274f40d6ce87/dom/events/test/browser_navigator_clipboard_readText.js#32,37). Perhaps, the "AndWaitForEvent" part wasn't fulfilled. Checking with additional logging.

Indeed, the event isn't received (https://treeherder.mozilla.org/logviewer?job_id=383281524&repo=try&lineNumber=4979), hence the timeout.

Unfortunately time-consuming to debug without local failures and Pernosco runs. Tried running the previous tests via ./mach mochitest -f browser dom/events/test/ locally; no failure.

Local non-failing run:

0:44.67 GECKO(38181) MB: 7 12:40:43 GMT+0200 (Central European Summer Time)
 0:44.67 GECKO(38181) MB: promiseNativeMouseEventAndWaitForEvent
 0:44.67 GECKO(38181) MB: synthesizeNativeMouseEvent
 0:44.67 GECKO(38181) MB: type=click sendNativeMouseEvent
 0:44.68 GECKO(38181) MB: SetClickCountmd
 0:44.72 GECKO(38181) MB: SetClickCountmu; mCC=1
 0:44.73 GECKO(38181) MB: 'WaitForEvent' resolved

Failing Try run:

[task 2022-07-05T11:29:56.702Z] 11:29:56     INFO - GECKO(11001) | MB: 7 11:29:56 GMT+0000 (Coordinated Universal Time)
[task 2022-07-05T11:29:56.703Z] 11:29:56     INFO - GECKO(11001) | MB: promiseNativeMouseEventAndWaitForEvent
[task 2022-07-05T11:29:56.704Z] 11:29:56     INFO - GECKO(11001) | MB: synthesizeNativeMouseEvent
[task 2022-07-05T11:29:56.705Z] 11:29:56     INFO - GECKO(11001) | MB: type=click sendNativeMouseEvent
[task 2022-07-05T11:30:41.158Z] 11:30:41     INFO - TEST-INFO | started process screentopng

That indicates, EventStateManager::SetClickCount isn't called in the failing case.

From another failed Try run:

[task 2022-07-05T10:54:48.285Z] 10:54:48     INFO - GECKO(11188) | MB: 7 10:54:48 GMT+0000 (Coordinated Universal Time)
[task 2022-07-05T10:54:48.285Z] 10:54:48     INFO - GECKO(11188) | MB: promiseNativeMouseEventAndWaitForEvent
[task 2022-07-05T10:54:48.286Z] 10:54:48     INFO - GECKO(11188) | MB: synthesizeNativeMouseEvent
[task 2022-07-05T10:54:48.286Z] 10:54:48     INFO - GECKO(11188) | MB: type=click sendNativeMouseEvent
[task 2022-07-05T10:54:48.289Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: Button 1 press
[task 2022-07-05T10:54:48.289Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: CaptureRollupEvents() 0
[task 2022-07-05T10:54:48.290Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: ReleaseGrabs
[task 2022-07-05T10:54:48.290Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]:   remove mContainer grab [7fbc6a531400]
[task 2022-07-05T10:54:48.291Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: nsWindow::Show state 0 frame Frame(7fbc71a7d020) menupopup
[task 2022-07-05T10:54:48.291Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: nsWindow::NativeShow hide
[task 2022-07-05T10:54:48.295Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: nsWindow::OnWindowStateEvent for 7fbc6ab61c60 changed 0x1 new_window_state 0x81
[task 2022-07-05T10:54:48.295Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: 	early return because no interesting bits changed
[task 2022-07-05T10:54:48.296Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: nsWindow::OnWindowStateEvent for 7fbc6ab9a150 changed 0x1 new_window_state 0x81
[task 2022-07-05T10:54:48.296Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: nsWindow::SetHasMappedToplevel() state 0
[task 2022-07-05T10:54:48.297Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]:   hidden, quit.
[task 2022-07-05T10:54:48.297Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: 	quick return because IS_MOZ_CONTAINER(aWidget) is true
[task 2022-07-05T10:54:48.298Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: OnLeaveNotify
[task 2022-07-05T10:54:48.299Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: OnEnterNotify
[task 2022-07-05T10:54:48.299Z] 10:54:48     INFO - GECKO(11188) | [Child 11587: Main Thread]: D/Clipboard OnUserReactedToPasteMenuPopup
[task 2022-07-05T10:54:48.300Z] 10:54:48     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/WidgetPopup [7fbc6a531400]: Button 1 release
[task 2022-07-05T10:54:54.624Z] 10:54:54     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: GetScreenBounds 159,58 -> 1280 x 1040, unscaled 159,58 -> 1280 x 1040
[task 2022-07-05T10:54:54.626Z] 10:54:54     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: GetScreenBounds 159,58 -> 1280 x 1040, unscaled 159,58 -> 1280 x 1040
[task 2022-07-05T10:54:54.627Z] 10:54:54     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: GetScreenBounds 159,58 -> 1280 x 1040, unscaled 159,58 -> 1280 x 1040
[task 2022-07-05T10:54:54.629Z] 10:54:54     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: GetScreenBounds 159,58 -> 1280 x 1040, unscaled 159,58 -> 1280 x 1040
[task 2022-07-05T10:54:54.630Z] 10:54:54     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: nsWindow::GetWorkspaceID()
[task 2022-07-05T10:54:54.631Z] 10:54:54     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]:   got workspace ID 0
[task 2022-07-05T10:55:09.636Z] 10:55:09     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: GetScreenBounds 159,58 -> 1280 x 1040, unscaled 159,58 -> 1280 x 1040
[task 2022-07-05T10:55:09.638Z] 10:55:09     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: GetScreenBounds 159,58 -> 1280 x 1040, unscaled 159,58 -> 1280 x 1040
[task 2022-07-05T10:55:09.640Z] 10:55:09     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: GetScreenBounds 159,58 -> 1280 x 1040, unscaled 159,58 -> 1280 x 1040
[task 2022-07-05T10:55:09.641Z] 10:55:09     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: GetScreenBounds 159,58 -> 1280 x 1040, unscaled 159,58 -> 1280 x 1040
[task 2022-07-05T10:55:09.641Z] 10:55:09     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]: nsWindow::GetWorkspaceID()
[task 2022-07-05T10:55:09.643Z] 10:55:09     INFO - GECKO(11188) | [Parent 11188: Main Thread]: D/Widget [7fbc8e01e000]:   got workspace ID 0
[task 2022-07-05T10:55:32.518Z] 10:55:32     INFO - TEST-INFO | started process screentopng

That indicates nsWindow::OnButtonPressEvent and nsWindow::OnButtonReleaseEvent were called.

#c7 and #c8 lead to the question why EventStateManager::SetClickCount wasn't called. To be investigated.

Tried (https://treeherder.mozilla.org/logviewer?job_id=383394485&repo=try&lineNumber=4939) Edgar's test-fix for the corresponding Windows-ticket. The test still fails on Try.

Another Try run reveals:

[task 2022-07-06T13:02:54.966Z] 13:02:54     INFO - GECKO(11240) | MB: 7 13:02:54 GMT+0000 (Coordinated Universal Time)
[task 2022-07-06T13:02:54.967Z] 13:02:54     INFO - GECKO(11240) | MB: promiseNativeMouseEventAndWaitForEvent
[task 2022-07-06T13:02:54.968Z] 13:02:54     INFO - GECKO(11240) | MB: synthesizeNativeMouseEvent
[task 2022-07-06T13:02:54.968Z] 13:02:54     INFO - GECKO(11240) | MB: type=click sendNativeMouseEvent
[task 2022-07-06T13:02:54.972Z] 13:02:54     INFO - GECKO(11240) | MB: PreHandleEvent 17
[task 2022-07-06T13:02:54.973Z] 13:02:54     INFO - GECKO(11240) | MB: PreHandleEvent 16
[task 2022-07-06T13:02:54.974Z] 13:02:54     INFO - GECKO(11240) | MB: PreHandleEvent 31
[task 2022-07-06T13:02:54.974Z] 13:02:54     INFO - GECKO(11240) | MB: PreHandleEvent mu
[task 2022-07-06T13:02:54.982Z] 13:02:54     INFO - GECKO(11240) | MB: PreHandleEvent 13
[task 2022-07-06T13:02:54.983Z] 13:02:54     INFO - GECKO(11240) | MB: PreHandleEvent 16
[task 2022-07-06T13:02:54.984Z] 13:02:54     INFO - GECKO(11240) | MB: PreHandleEvent 13
[task 2022-07-06T13:02:55.046Z] 13:02:55     INFO - GECKO(11240) | MB: PreHandleEvent 13
[task 2022-07-06T13:03:39.357Z] 13:03:39     INFO - TEST-INFO | started process screentopng

That is, EventStateManager::PreHandleEvent is called for the eMouseUp event but SetClickCount isn't called. Moreover, PreHandleEvent isn't called for the eMouseDown event; it's unclear, why.

The failure didn't reproduce during the last six Try runs. Perhaps something else fixed it meanwhile (I've rebased). Will re-enable the test.

Didn't fail in the last six Try runs.

https://hg.mozilla.org/mozilla-central/rev/07332d23331e