1838381 - AbortError issues after 200ms navigation timeout "No navigation detected: about:blank" when creating WebDriver session

Status: RESOLVED FIXED

(Remote Protocol :: Marionette, defect, P1)

Description

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

This is a clone of bug 1832891 where a fix has been landed for the initial navigation when opening new windows and tabs. But there is still an issue with the very first initial navigation during WebDriver:NewSession right after the browser has been started.

Because we do not wait long enough and miss the additional page load, all commands that get run immediately after the new session has been created could fail because the underlying browsing context gets replaced.

There are a couple of different intermittent failures that are caused by this broken behavior. We are going to add them all to the dependency list.

We should consider this bug for M7 inclusion.

Comment 2

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

(In reply to Olli Pettay [:smaug][[e-mail]] from bug 1830616 comment #15)

There is no way to know that. window.open() (no params) may not load anything, as an example.
Or someone may load something to it later using relevant window's location object or so.

Our problem right now is actually the initial load of the very first tab after opening Firefox. Here only about:blank is present (as set via prefs) but we see different behavior on Android, which does a sync load for the initial about:blank, but compared to desktop stays on this page instead of asynchronously loading about:blank again. But on desktop the async load could be delayed and right now we only wait 200ms, and if we do not see another navigation we assume it's done. We could increase this timeout, but then creating a new session on Android will always run into this timeout.

If there is no way to detect another load precisely maybe we should use a multiplier for desktop only?

Comment 3

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

I pushed a try build which only increases the maximal unload timeout to 5s for desktop but not Android:
https://treeherder.mozilla.org/jobs?repo=try&revision=5ab262fff8701bfcaa4d92e87bf1ee6aff7be237

Comment 4

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

After experimenting a bit more with GeckoView I noticed that you can also pass an initial URL to be loaded when a GeckoView application starts. Therefore just pass -a android.intent.action.VIEW -d http://mozilla.org, and the Mozilla website should be loaded. Sadly this doesn't happen and Marionette is stalled during WebDriver:NewSession waiting for the page to be finished loading. Visually I can see as well that nothing is loading and it says on about:blank.

Here some lines from the adb logcat:

06-16 17:52:49.252  3905  3930 I Gecko   : 1686930769252	Marionette	DEBUG	Waiting for initial application window
06-16 17:52:49.253  3905  3930 I Gecko   : DevTools listening on ws://127.0.0.1:9222/devtools/browser/5011b1a3-6e80-490c-8b4d-b2f69d67d174
06-16 17:52:49.254  3905  3930 I Gecko   : 1686930769254	RemoteAgent	TRACE	[2] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=200 waitForExplicitStart=false
06-16 17:52:49.254  3905  3930 I Gecko   : 1686930769254	RemoteAgent	TRACE	[2] ProgressListener Document already loading https://www.mozilla.org/
06-16 17:52:49.254  3905  3930 I Gecko   : 1686930769254	RemoteAgent	TRACE	[2] ProgressListener Check loading state: isStart=true isStop=false
06-16 17:52:49.254  3905  3930 I Gecko   : 1686930769254	RemoteAgent	TRACE	[2] ProgressListener state=start: https://www.mozilla.org/
06-16 17:52:49.255  3905  3930 D GeckoIdleService: Get idle time: time since reset 6 msec
06-16 17:52:49.255  3905  3930 I Gecko   : console.error: (new SyntaxError("The URI is malformed.", (void 0), 133))
06-16 17:52:49.255  3905  3930 E GeckoConsole: [JavaScript Error: "SyntaxError: The URI is malformed."]

I'm unsure if the listed SyntaxError entries are related to loading that page, or if it's something else. But there is indeed no further progress for loading the page. Olivia, do you know what might be wrong with that?

Comment 5

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

(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #3)

I pushed a try build which only increases the maximal unload timeout to 5s for desktop but not Android:
https://treeherder.mozilla.org/jobs?repo=try&revision=5ab262fff8701bfcaa4d92e87bf1ee6aff7be237

All the triggered Wd jobs for this try build do no longer show the failure. As such I would go ahead and submit a patch which only increases the unloadTimeout to 5s on desktop but not on Android. Once we know if the observed behavior in comment 4 is a bug in GeckoView and has fixed we could remove the workaround again.

Comment 6

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

Attachment: Bug 1838381 - Extend waitForInitialPageLoaded for "WebDriver:NewSession" for desktop builds.

Comment 7

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

Causes a higher amount of failures which can be seen on blocked bugs. As such we have to get it fixed soon.

Comment 8

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

Also because we do not seem to wait for the initial page to have loaded for WebDriver BiDi i'm making this a Marionette only bug and will file a new one for the WebDriver BiDi 'new session' code path.

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/eca52f74d619
Extend waitForInitialPageLoaded for "WebDriver:NewSession" for desktop builds. r=webdriver-reviewers,Sasha

Comment 10

[Cristian Tuns]

https://hg.mozilla.org/mozilla-central/rev/eca52f74d619

Comment 11

[Olivia Hall [:olivia]]

After experimenting a bit more with GeckoView I noticed that you can also pass an initial URL to be loaded when a GeckoView application starts. Therefore just pass -a android.intent.action.VIEW -d http://mozilla.org, and the Mozilla website should be loaded. Sadly this doesn't happen and Marionette is stalled during WebDriver:NewSession waiting for the page to be finished loading. Visually I can see as well that nothing is loading and it says on about:blank.

That is interesting, could you give the full command you are sending and how you are sending it? I tested some using adb shell am start -a "android.intent.action.VIEW" -d "http://mozilla.org" and it let me pick GeckoView Example or adb shell am start -a android.intent.action.VIEW -n org.mozilla.geckoview.test_runner/.TestRunnerActivity -d http://mozilla.org to directly launch through the Test Runner. (I'm not sure how critical the quotes are, seems to work both ways for me.)

This could also be something with how GV Test Runner is setup. I noticed the test runner didn't show up in the list of items that could respond to the VIEW intent without the package name included. Is this what Marionette uses to set the flags and such?

Comment 12

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

Thank you for the reply Olivia! Given that this bug is fixed now, I went ahead and filed bug 1839583 to further investigate this problem.

Comment 13

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

Once Firefox 116 has been released we may consider uplifting the fix to 115ESR to stop the race condition. But we should wait some additional weeks to see if it might cause some regression for users.

Comment 14

[Ryan VanderMeulen [:RyanVM]]

Is this still something you wanted to uplift to ESR?

Comment 15

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

Comment on attachment 9339794 [details]
Bug 1838381 - Extend waitForInitialPageLoaded for "WebDriver:NewSession" for desktop builds.

Beta/Release Uplift Approval Request

• User impact if declined: There are chances for WebDriver users to hit issues with sporadically unloaded documents because of a race condition after starting the WebDriver session and not completely awaiting the initial page to be loaded.
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: No
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): It only increases the timeout for waiting for an initial navigation on desktop systems, and this should only be visible for slow builds or on slow platforms.
• String changes made/needed: no
• Is Android affected?: No

Comment 16

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

Comment on attachment 9339794 [details]
Bug 1838381 - Extend waitForInitialPageLoaded for "WebDriver:NewSession" for desktop builds.

ESR Uplift Approval Request

• If this is not a sec:{high,crit} bug, please state case for ESR consideration: Can cause intermittent failures for WebDriver related tests.
• User impact if declined: There are chances for WebDriver users to hit issues with sporadically unloaded documents because of a race condition after starting the WebDriver session and not completely awaiting the initial page to be loaded.
• Fix Landed on Version: 116
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): It only increases the timeout for waiting for an initial navigation on desktop systems, and this should only be visible for slow builds or on slow platforms.

Comment 17

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9339794 [details]
Bug 1838381 - Extend waitForInitialPageLoaded for "WebDriver:NewSession" for desktop builds.

Approved for 115.2esr.

Comment 18

[Pulsebot]

https://hg.mozilla.org/releases/mozilla-esr115/rev/36e2eb16b3b3