WPT test /webdriver/tests/bidi/input/perform_actions/invalid.py slow in CI and local

[Lightning00Blade]

The test file contains 400 test and runs in 60sec on my CloudTop and timeout on CI as well, on WPT infra it run in 23sec so the test pass. We should find a way to either speed it up, split it or increase the timeout only for it.

[whimboo]

Do you have logs which indicate why it is that slow on your CloudTop?

[OrKoN]

@whimboo it also times out for me locally for Firefox:

python3 ./wpt run --channel=nightly firefox webdriver/tests/bidi/input/perform_actions/invalid.py

Interestingly, setting the timeout multiplier to 1 makes it faster and finish in 7 sec:

python3 ./wpt run --channel=nightly firefox webdriver/tests/bidi/input/perform_actions/invalid.py --timeout-multiplier=1

[Lightning00Blade]

Here are logs - WPT https://gist.github.com/Lightning00Blade/715b201c0921841fd2d884b118fb8a43,
ChromeDriver logs - https://gist.github.com/Lightning00Blade/fdd4f73660694e7784dacc00fb00bff4

[whimboo]

Here are logs - https://gist.github.com/Lightning00Blade/715b201c0921841fd2d884b118fb8a43

Interesting there are around 100ms between each test. Formerly I found a bug with Chrome and Set Window Rect but that should be fixed via web-platform-tests/wpt#43853. Maybe you could check with debug logs enabled?

@whimboo it also times out for me locally for Firefox:

python3 ./wpt run --channel=nightly firefox webdriver/tests/bidi/input/perform_actions/invalid.py

Interestingly, setting the timeout multiplier to 1 makes it faster and finish in 7 sec:

python3 ./wpt run --channel=nightly firefox webdriver/tests/bidi/input/perform_actions/invalid.py --timeout-multiplier=1

I don't see timeouts when checking the history on wpt.fyi.

Also running it locally it takes 12s whether which timeout multiplier is set - also note that it should not make a difference in runtime related to the value as set. Maybe run with --webdriver-arg=-vv to get trace logs which might indicate where that extra time is needed on your local machine.

[whimboo]

@Lightning00Blade It indeed still tries to set the window bounds!?

[1709038965.937][DEBUG]: DevTools WebSocket Response: Browser.setWindowBounds (id=84) (session_id=) browser {
}
[1709038966.037][DEBUG]: DevTools WebSocket Command: Browser.getWindowForTarget (id=85) (session_id=) browser {
   "targetId": "180609E95ACB8F511498B285F40695F5"
}

This should really not happen with my patch. Are you really on the latest wpt revision?

[Lightning00Blade]

@whimboo Can you link me the link me the PR, I will double check but this is the last update we did for WPT submodule - #1899

[whimboo]

See my 2nd last comment: web-platform-tests/wpt#43853

[OrKoN]

So it looks like it is flaky, sometimes it ends within 7sec, sometimes times out after 30sec. Timing out log https://gist.githubusercontent.com/OrKoN/79e9ba8995db27fbf51bfe71d6f9fc28/raw/e10ead37d89d7baee486d7f59e7fad8a2cbe5d46/gistfile1.txt

[whimboo]

This is interesting:

 0:08.48 pid:43164 1709045559009	webdriver::server	DEBUG	<- 200 OK {"value":["14d9c636-71b7-4acc-a1c5-2b31a627f25a"]}
 0:34.55 DEBUG Got command: 'log'
 0:34.55 INFO STDOUT: webdriver/tests/bidi/input/perform_actions/invalid.py::test_params_input_source_action_sequence_actions_actions_invalid_type[None-pointer] 
 0:34.55 DEBUG Got command: 'log'
 0:34.55 INFO STDOUT: ERROR
 0:34.55 DEBUG Got command: 'log'
 0:34.55 INFO STDOUT: webdriver/tests/bidi/input/perform_actions/invalid.py::test_params_input_source_action_sequence_actions_actions_invalid_type[None-wheel] 

Usually it should look like:

0:07.57 DEBUG Got command: 'log'
 0:07.57 INFO STDOUT: webdriver/tests/bidi/input/perform_actions/invalid.py::test_params_context_invalid_type[value3] 
 0:07.57 pid:43164 1709045558098	RemoteAgent	INFO	Perform WebSocket upgrade for incoming connection from 127.0.0.1:58608

It's not clear to me what's going on at this point. Would you mind filing a bug for that so that we can track the work in Bugzilla? Also please mention how often this happens, and if that doesn't happen when you modify the timeout multiplier. Thanks.

[OrKoN]

@whimboo I filed https://bugzilla.mozilla.org/show_bug.cgi?id=1882533

[Lightning00Blade]

So If i comment out - https://github.com/web-platform-tests/wpt/blob/master/webdriver/tests/support/helpers.py#L54
The test run consistently in 12 sec, if I enable them they take around 45-60 sec.

[Lightning00Blade]

So the fall where it fails is here - web-platform-tests/wpt@d2b7ac0#diff-5bca3d8b5c6c48d3020bc6bfcc2d5b6b95882e8c9de3fb35c237293d18b25ed5R67
is_maximized return true.
CC @nechaev-chromium let's chat offline

[nechaev-chromium]

For the context:
The timeout mentioned earlier by Maxim is in chrome_impl::SetWindowBounds.
This is how the timeout appeared: chromedriver:2663.
Another bug report chromium:41403879 relates to the code below the timeout in question. The complaint was that due to window animations on MacOS the state did not change in time therefore causing flakiness.