From a209c86c55a47170f2ad23c5756a4a4e607419dd Mon Sep 17 00:00:00 2001 From: toofar Date: Sat, 27 Apr 2024 13:40:52 +1200 Subject: Delay QEvent driven mouse clicks by 10ms On CI with Qt 6.7 we are seeing several tests failing in a flaky, but frequent, manner. These tests all seem to be doing :click-element and sending a "fake" click, as in one driven by QEvents, to a button on the test page after opening the page in an existing tab. In the logs we see that the element was identified with JS correctly but we don't see any evidence of the actual click after that. I've been testing locally with `python3 -m pytest tests/end2end/features/test_prompts_bdd.py -k test_javascript_confirm`. Delaying the click event by as little as 5ms seems to make the tests consistently pass. I'm setting it to an arbitrary 10ms here for no good reason. It's unfortunate that we have to change production code to make tests pass, it's unlikely that a 10ms window will affect real usage, and the problem is only immediately after a navigation. If we can't find a better way to resolve this and want to get rid of the 10ms delay when no needed we could maybe look at when the last navigation time for the tab was to decide whether to delay or not. I also tried changing all the "open in" lines in the failing tests to be "open in new tab" and that seemed to make the flaky tests pass consistently too. But relying on people writing tests in a specific way wouldn't really be fixing the problem. Additionally, running just one test at a time (with `taskset -c 1 ...`) made all the tests pass consistently. So it seems like the root cause could have something to do with that, somehow. Or maybe just running the pytest process and the browser process on the same CPU causes enough of a delay to not trigger it. I don't know what the root cause of this change is, or if we can use a more event based way of knowing when the page (or its focus proxy) is ready to receive events. I've tried digging through events and debugging webengine and haven't got anywhere, hopefully this delay is painless enough that it'll do. To summarize, the page, or focus proxy, doesn't process events (all events, just mouse events?) immediately after navigating. I initially tried delaying all events in `tab.send_event()`, but that caused some caret tests to fail (the `selectionfollow_with_link_tabbing` e2e ones), not sure why. So I walked back to just delaying click events. I've seen some intermittent flakyness in `test_misc_bdd.py::test_clicking_on_focused_element` and `tests/end2end/features/test_keyinput_bdd.py::test_fakekey_sending_keychain_to_the_website` which may indicate that `:fake-key` needs the same treatment. We'll see how things stand once it's been stable on the main branch for a while instead of being muddled up in this investigation branch. I thought the issue might be that the RenderWidgetHostViewQt was being swapped out on the new page load and the old one being sent the event. So I added a bunch of debug logging to try to get a better view of that. None of this debug logging is showing up when the tests fail so it seems that isn't the case. The tests failing in the last four bleeding edge qt6 tests before these changes were (test, count): ('tests/end2end/features/test_keyinput_bdd.py::test_fakekey_sending_special_key_to_the_website', 2), ('tests/end2end/features/test_prompts_bdd.py::test_using_contentjavascriptalert', 2), ('tests/end2end/features/test_editor_bdd.py::test_select_two_files_with_multiple_files_command', 2), ('tests/end2end/features/test_misc_bdd.py::test_clicking_first_element_matching_a_selector', 2), ('tests/end2end/features/test_misc_bdd.py::test_clicking_on_focused_element', 2), ('tests/end2end/features/test_prompts_bdd.py::test_javascript_prompt_with_default', 2), ('tests/end2end/features/test_prompts_bdd.py::test_using_contentjavascriptprompt', 2), ('tests/end2end/features/test_prompts_bdd.py::test_javascript_confirm__aborted', 2), ('tests/end2end/features/test_editor_bdd.py::test_file_selector_deleting_temporary_file', 1), ('tests/end2end/features/test_keyinput_bdd.py::test_fakekey_sending_keychain_to_the_website', 1), ('tests/end2end/features/test_prompts_bdd.py::test_javascript_confirm__no', 1), ('tests/end2end/features/test_prompts_bdd.py::test_javascript_confirm_with_default_value', 1), ('tests/end2end/test_insert_mode.py::test_insert_mode[100-input.html-qute-input-keypress-awesomequtebrowser]', 1), ('tests/end2end/features/test_misc_bdd.py::test_clicking_an_element_by_position', 1), ('tests/end2end/features/test_prompts_bdd.py::test_javascript_confirm__yes', 1), ('tests/end2end/features/test_prompts_bdd.py::test_javascript_confirm_with_invalid_value', 1), ('tests/end2end/test_insert_mode.py::test_insert_mode[125-input.html-qute-input-keypress-awesomequtebrowser]', 1), ('tests/end2end/features/test_editor_bdd.py::test_select_two_files_with_single_file_command', 1), ('tests/end2end/features/test_keyinput_bdd.py::test_fakekey_sending_key_to_the_website', 1), ('tests/end2end/features/test_misc_bdd.py::test_clicking_an_element_by_id_with_dot', 1), ('tests/end2end/features/test_prompts_bdd.py::test_javascript_alert_with_value', 1) For debugging in GBD under test I ran the test process under GDB and passed a script to GDB to print out a message, and then continue, when it hit a breakpoint. Unfortunately, the tests always passed when run under GDB. For that I changed `_executable_args()` in quteprocess to return `"gdb", "-q -x handleMouseEvent-breakpoint -args".split() + [executable] + args` where `handleMouseEvent-breakpoint` is: set breakpoint pending on set debuginfod enabled off break RenderWidgetHostViewQtDelegateClient::handleMouseEvent commands call (void) fprintf(stderr, "Entering handleMouseEvent\n") continue end run The tests were consistently passing, but erroring on the invalid gdb log lines. --- qutebrowser/browser/webelem.py | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/qutebrowser/browser/webelem.py b/qutebrowser/browser/webelem.py index 2356ad086..721ab83df 100644 --- a/qutebrowser/browser/webelem.py +++ b/qutebrowser/browser/webelem.py @@ -355,10 +355,14 @@ class AbstractWebElement(collections.abc.MutableMapping): # type: ignore[type-a QMouseEvent(QEvent.Type.MouseButtonRelease, pos, button, Qt.MouseButton.NoButton, modifiers), ] - for evt in events: - self._tab.send_event(evt) + def _send_events_after_delay() -> None: + """Delay clicks to workaround timing issue in e2e tests on 6.7.""" + for evt in events: + self._tab.send_event(evt) - QTimer.singleShot(0, self._move_text_cursor) + QTimer.singleShot(0, self._move_text_cursor) + + QTimer.singleShot(10, _send_events_after_delay) def _click_editable(self, click_target: usertypes.ClickTarget) -> None: """Fake a click on an editable input field.""" -- cgit v1.2.3-54-g00ecf