Closed Bug 2004191 Opened 1 month ago Closed 1 month ago

browsingContext.navigate with wait=none doesn't always contain the real target URL

Categories

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

defect

Tracking

(firefox-esr140 unaffected, firefox145 unaffected, firefox146 unaffected, firefox147 fixed, firefox148 fixed)

RESOLVED FIXED
148 Branch
Tracking Status
firefox-esr140 --- unaffected
firefox145 --- unaffected
firefox146 --- unaffected
firefox147 --- fixed
firefox148 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: sajidanwar)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [webdriver:m18][webdriver:external][webdriver:relnote])

Attachments

(3 files)

Filed by: sstanca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=538609606&repo=autoland&task=W-IeEOn1RBe_ICXpOTBdyQ.0
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/W-IeEOn1RBe_ICXpOTBdyQ/runs/0/artifacts/public/logs/live_backing.log


[task 2025-12-05T00:45:52.882+00:00] 00:45:52     INFO - TEST-PASS | /webdriver/tests/bidi/browsing_context/navigate/navigate.py | test_interactive_simultaneous_navigation 
[task 2025-12-05T00:45:52.882+00:00] 00:45:52     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/bidi/browsing_context/navigate/navigate.py | test_relative_url - AssertionError
[task 2025-12-05T00:45:52.883+00:00] 00:45:52     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7fbd7c856150>
[task 2025-12-05T00:45:52.883+00:00] 00:45:52     INFO - new_tab = {'context': 'ce655d67-db00-428c-8f05-24ea6e43dbee'}
[task 2025-12-05T00:45:52.883+00:00] 00:45:52     INFO - url = <function url.<locals>.url at 0x7fbd7c83fec0>
[task 2025-12-05T00:45:52.884+00:00] 00:45:52     INFO - 
[task 2025-12-05T00:45:52.884+00:00] 00:45:52     INFO -     async def test_relative_url(bidi_session, new_tab, url):
[task 2025-12-05T00:45:52.884+00:00] 00:45:52     INFO -         url_before = url("/webdriver/tests/bidi/browsing_context/support/empty.html")
[task 2025-12-05T00:45:52.884+00:00] 00:45:52     INFO -     
[task 2025-12-05T00:45:52.884+00:00] 00:45:52     INFO -         await navigate_and_assert(bidi_session, new_tab, url_before, wait="none")
[task 2025-12-05T00:45:52.884+00:00] 00:45:52     INFO -     
[task 2025-12-05T00:45:52.885+00:00] 00:45:52     INFO -         relative_url = "other.html"
[task 2025-12-05T00:45:52.886+00:00] 00:45:52     INFO -         url_after = url_before.replace("empty.html", relative_url)
[task 2025-12-05T00:45:52.886+00:00] 00:45:52     INFO - >       await navigate_and_assert(
[task 2025-12-05T00:45:52.887+00:00] 00:45:52     INFO -             bidi_session, new_tab, relative_url, wait="none", expected_url=url_after
[task 2025-12-05T00:45:52.887+00:00] 00:45:52     INFO -         )
[task 2025-12-05T00:45:52.888+00:00] 00:45:52     INFO - 
[task 2025-12-05T00:45:52.888+00:00] 00:45:52     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7fbd7c856150>
[task 2025-12-05T00:45:52.889+00:00] 00:45:52     INFO - new_tab    = {'context': 'ce655d67-db00-428c-8f05-24ea6e43dbee'}
[task 2025-12-05T00:45:52.889+00:00] 00:45:52     INFO - relative_url = 'other.html'
[task 2025-12-05T00:45:52.890+00:00] 00:45:52     INFO - url        = <function url.<locals>.url at 0x7fbd7c83fec0>
[task 2025-12-05T00:45:52.890+00:00] 00:45:52     INFO - url_after  = 'https://web-platform.test:8443/webdriver/tests/bidi/browsing_context/support/other.html'
[task 2025-12-05T00:45:52.891+00:00] 00:45:52     INFO - url_before = 'https://web-platform.test:8443/webdriver/tests/bidi/browsing_context/support/empty.html'
[task 2025-12-05T00:45:52.891+00:00] 00:45:52     INFO - 
[task 2025-12-05T00:45:52.891+00:00] 00:45:52     INFO - tests/web-platform/tests/webdriver/tests/bidi/browsing_context/navigate/navigate.py:90: 
[task 2025-12-05T00:45:52.891+00:00] 00:45:52     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2025-12-05T00:45:52.891+00:00] 00:45:52     INFO - 
[task 2025-12-05T00:45:52.891+00:00] 00:45:52     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7fbd7c856150>
[task 2025-12-05T00:45:52.892+00:00] 00:45:52     INFO - context = {'context': 'ce655d67-db00-428c-8f05-24ea6e43dbee'}
[task 2025-12-05T00:45:52.893+00:00] 00:45:52     INFO - url = 'other.html', wait = 'none', expected_error = False
[task 2025-12-05T00:45:52.893+00:00] 00:45:52     INFO - expected_url = 'https://web-platform.test:8443/webdriver/tests/bidi/browsing_context/support/other.html'
[task 2025-12-05T00:45:52.894+00:00] 00:45:52     INFO - 
[task 2025-12-05T00:45:52.895+00:00] 00:45:52     INFO -     async def navigate_and_assert(
[task 2025-12-05T00:45:52.895+00:00] 00:45:52     INFO -         bidi_session, context, url, wait="complete", expected_error=False, expected_url=None
[task 2025-12-05T00:45:52.895+00:00] 00:45:52     INFO -     ):
[task 2025-12-05T00:45:52.895+00:00] 00:45:52     INFO -         if expected_url is None:
[task 2025-12-05T00:45:52.896+00:00] 00:45:52     INFO -             expected_url = url
[task 2025-12-05T00:45:52.897+00:00] 00:45:52     INFO -     
[task 2025-12-05T00:45:52.897+00:00] 00:45:52     INFO -         if expected_error:
[task 2025-12-05T00:45:52.898+00:00] 00:45:52     INFO -             with pytest.raises(UnknownErrorException):
[task 2025-12-05T00:45:52.899+00:00] 00:45:52     INFO -                 await bidi_session.browsing_context.navigate(
[task 2025-12-05T00:45:52.899+00:00] 00:45:52     INFO -                     context=context['context'], url=url, wait=wait
[task 2025-12-05T00:45:52.899+00:00] 00:45:52     INFO -                 )
[task 2025-12-05T00:45:52.899+00:00] 00:45:52     INFO -     
[task 2025-12-05T00:45:52.899+00:00] 00:45:52     INFO -         else:
[task 2025-12-05T00:45:52.899+00:00] 00:45:52     INFO -             result = await bidi_session.browsing_context.navigate(
[task 2025-12-05T00:45:52.900+00:00] 00:45:52     INFO -                 context=context['context'], url=url, wait=wait
[task 2025-12-05T00:45:52.901+00:00] 00:45:52     INFO -             )
[task 2025-12-05T00:45:52.901+00:00] 00:45:52     INFO - >           assert result["url"] == expected_url
[task 2025-12-05T00:45:52.902+00:00] 00:45:52     INFO - E           AssertionError
[task 2025-12-05T00:45:52.903+00:00] 00:45:52     INFO - 
[task 2025-12-05T00:45:52.903+00:00] 00:45:52     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7fbd7c856150>
[task 2025-12-05T00:45:52.904+00:00] 00:45:52     INFO - context    = {'context': 'ce655d67-db00-428c-8f05-24ea6e43dbee'}
[task 2025-12-05T00:45:52.905+00:00] 00:45:52     INFO - expected_error = False
[task 2025-12-05T00:45:52.905+00:00] 00:45:52     INFO - expected_url = 'https://web-platform.test:8443/webdriver/tests/bidi/browsing_context/support/other.html'
[task 2025-12-05T00:45:52.906+00:00] 00:45:52     INFO - result     = {'navigation': '9eae80f8-d1ad-4a87-b0c6-f8d78f0ec12f',
[task 2025-12-05T00:45:52.906+00:00] 00:45:52     INFO -  'url': 'https://web-platform.test:8443/webdriver/tests/bidi/browsing_context/support/empty.html'}
[task 2025-12-05T00:45:52.907+00:00] 00:45:52     INFO - url        = 'other.html'
[task 2025-12-05T00:45:52.908+00:00] 00:45:52     INFO - wait       = 'none'
[task 2025-12-05T00:45:52.908+00:00] 00:45:52     INFO - 
[task 2025-12-05T00:45:52.908+00:00] 00:45:52     INFO - tests/web-platform/tests/webdriver/tests/bidi/browsing_context/navigate/__init__.py:24: AssertionError
[task 2025-12-05T00:45:52.908+00:00] 00:45:52     INFO - ..........
[task 2025-12-05T00:45:52.908+00:00] 00:45:52     INFO - TEST-OK | /webdriver/tests/bidi/browsing_context/navigate/navigate.py | took 26816ms

Hi Sajid! Could you please take a look at this? It seems that this appeared after Bug 1740584 landed on Autoland, as it can be seen here.

Thank you!

Severity: S4 → --
Flags: needinfo?(sajidanwar94)
Keywords: regression
Priority: P5 → --
Regressed by: 1740584

Set release status flags based on info from the regressing bug 1740584

Set release status flags based on info from the regressing bug 1740584

Hi Serban, I spent some looking at this and I haven't made much progress. In my original patches, there doesn't appear to be anything that would explicitly affect this test. In this test, it's using WebDriver to load an empty page and immediately navigate to another empty page. There's no SVG, no font metrics and font-relative units used, so I don't see any opportunities for interactions here.

In the related intermittent bug report from 1 month ago for the same test, the failure results look to be the same as this one. I was thinking of taking some to see if I could un-flake this test on the assumption that I just got unlucky with the regression appearing on my commit, but otherwise not really sure what's going on yet.

Emilio, maybe you can help given that you mentored Sajid on that regressing bug? Thanks.

Flags: needinfo?(sajidanwar94) → needinfo?(emilio)

I don't understand how the test can be affected by that change. It's switching navigation between two blank documents, so none of the code that Sajid wrote should matter in practice.

Well, in fairness, we could query the root font metrics, and that might be not the fastest if it's the first time in the process or something. Maybe that's what's going on? The empty.html load becomes slightly slower? I notice that this is the only test that uses wait="none", and I could imagine it causing problems.

Henrik do you know why this test uses wait="none"? In general not waiting before triggering another navigation seems something that could cause this...

Flags: needinfo?(emilio) → needinfo?(hskupin)

I don't see why we need none here given that we are not testing an interrupted navigation. Julian, do you remember why you added it? If not we should remove it to use complete or change it to interactive which should be also enough.

Flags: needinfo?(hskupin) → needinfo?(jdescottes)

We used to use interactive prior to the spec changes from https://github.com/w3c/webdriver-bidi/pull/855

Per spec, we expect none to work for a relative URL navigation since it should still wait until navigationCommitted to be emitted.
Switching to interactive or complete would relax the assertion a bit too much.

Flags: needinfo?(jdescottes)

Happening on Linux as well

Summary: Frequent Android /webdriver/tests/bidi/browsing_context/navigate/navigate.py | test_relative_url - AssertionError → Frequen /webdriver/tests/bidi/browsing_context/navigate/navigate.py | test_relative_url - AssertionError
Summary: Frequen /webdriver/tests/bidi/browsing_context/navigate/navigate.py | test_relative_url - AssertionError → Frequent /webdriver/tests/bidi/browsing_context/navigate/navigate.py | test_relative_url - AssertionError

I looked a bit at the logs, and the good thing is that the navigation to other.html happens, we compute the correct url etc... but for some reason the payload we return for the navigate command still contains empty.html

Could there be some issue where the aborted navigation on empty.html is triggering an event in the listener of the other.html navigation (before the "committed" event of other.html) that's making it return the wrong URL?

I haven't had time to look since last night but will try to look into this later today.

In any case I don't think this is an issue with Sajid's patch. If only it uncovered a pre-existing issue.

I added a 100ms thread sleep in the restyling code, which gives me about a 1/10 repro rate on my Linux desktop. I've captured traces of the test_relative_url test comparing a successful run against a failed run. The crucial difference seems to be:

  • Passed: When navigating to the second document other.html, there are two onStateChange notifications on the WebProgressListener -- the first being a "start" and the second being a "stop". The request in both notifications have the correct other.html URL. The listener updates its tracked targetURI on the "start", and resolves the navigation promise on the "stop". The test sees the correct other.html URL.

  • Failed: When navigating to the second document other.html. there are no onStateChange notifications. Instead, there's only the navigation-committed event that's emitted when the document is first created (ref 1, ref 2). Although the committed event has the loaded URL in its data, the listener does not update its tracked targetURI. Since wait === 'none', the listener resolves the navigation promise. The test sees the old empty.html URL.

It seems like a problem to me that only one (state change notifications) or the other (committed event) were fired in either result. I would have expected to see both come through every time?

One simple way to resolve the flaky test itself, I think, is to update the navigation-committed handler to take the URL from the event and track it as the targetURI. This seems conceptually the same as the start state change handler updating the targetURI so it feels reasonable to me. I've made a small commit and verified from traces that it fixes the previously failing iterations of the test. I've pushed it to try, waiting for results: https://treeherder.mozilla.org/jobs?revision=05edef3a9392a231e5d75628ef6d53298e0e21fd&repo=try (first time using try, hopefully I set it up right...)

(In reply to Sajid Anwar [:sajidanwar] from comment #16)

One simple way to resolve the flaky test itself, I think, is to update the navigation-committed handler to take the URL from the event and track it as the targetURI. This seems conceptually the same as the start state change handler updating the targetURI so it feels reasonable to me. I've made a small commit and verified from traces that it fixes the previously failing iterations of the test. I've pushed it to try, waiting for results: https://treeherder.mozilla.org/jobs?revision=05edef3a9392a231e5d75628ef6d53298e0e21fd&repo=try (first time using try, hopefully I set it up right...)

Thanks for taking a look, and yes reusing the URL from the event is what we should do here.

Sajid: I looked at your patch and it seems good to me, I actually had a similar one on try as well. Happy to review! Note you'll also need to slightly update an xpcshell test: remote/shared/test/xpcshell/test_Navigate.js and to change recent expectation changes synced from upstream https://github.com/mozilla-firefox/firefox/blob/457d28841be017165fe378819d460a2ccbbbfc88/testing/web-platform/meta/webdriver/tests/bidi/browsing_context/navigate/navigate.py.ini

Flags: needinfo?(sajidanwar94)
Assignee: nobody → sajidanwar94
Status: NEW → ASSIGNED

Thanks Julian for the xpcshell test pointer. I updated the expectation to remove the test_relative_url metadata entirely since that's new, I'm assuming that's auto-generated from failures when syncing from upstream? Hopefully this patch will resolve the test failures entirely on all platforms.

Also submitted a try for this updated patch: https://treeherder.mozilla.org/jobs?repo=try&landoCommitID=167495. Wasn't 100% on which tasks to pick, so I did wdspec-* and xpcshell-* for an Android profile.

Flags: needinfo?(sajidanwar94)
Blocks: 1994026
See Also: 1994026
Severity: -- → S4
Priority: -- → P5
Whiteboard: [webdriver:m18] [webdriver:external]
Pushed by jdescottes@mozilla.com: https://github.com/mozilla-firefox/firefox/commit/2cc27953b96f https://hg.mozilla.org/integration/autoland/rev/47d8989a0511 Update WebDriver navigation to retain URL on navigation-committed event. r=jdescottes
Status: ASSIGNED → RESOLVED
Closed: 1 month ago
Resolution: --- → FIXED
Target Milestone: --- → 148 Branch

Sajid, given that this also affects mozilla-beta would you mind uplifting your patch? Thanks!

Flags: needinfo?(sajidanwar94)

firefox-beta Uplift Approval Request

  • User impact if declined: Low impact regression in WebDriver BiDi introduced into Firefox 147 that is resolved by this patch. The regression was identified in an existing WPT test that was succeeding in Firefox 146 and earlier; decelining the patch will result in a new WPT failure in Firefox 147.
  • Code covered by automated testing: yes
  • Fix verified in Nightly: yes
  • Needs manual QE test: no
  • Steps to reproduce for manual QE testing:
  • Risk associated with taking this patch: low
  • Explanation of risk level: Low risk as regression is isolated to an edge case in WebDriver Bidi with existing WPT coverage that succeeded in previous Firefox versions. The Firefox 147 change caused that WPT to fail, and this patch makes a very small change to the WebDriver code to resolve that WPT test.
  • String changes made/needed: No.
  • Is Android affected?: yes
Attachment #9531765 - Flags: approval-mozilla-beta?

Sure! I've created an uplift request for firefox-beta: https://lando.moz.tools/D275621/. Here's the patch in Phabricator with my answers to the uplift assessment: https://phabricator.services.mozilla.com/D275621. If anyone has feedback on the uplift assessment, let me know and I can update it.

Flags: needinfo?(sajidanwar94)
Flags: in-testsuite+
Attachment #9531765 - Flags: approval-mozilla-beta? → approval-mozilla-beta+

Since the bug was fixed further failures were classified against this bug but with a way lower frequency. As such I think we should rename this bug to reflect the actual changes in our WebDriver BiDi implementation and let sheriffs see the single failure bug 1994026 for classifications.

Severity: S4 → S3
Priority: P5 → P3
Summary: Frequent /webdriver/tests/bidi/browsing_context/navigate/navigate.py | test_relative_url - AssertionError → Internal "navigation-committed" event payload doesn't always contain the real target URL
Whiteboard: [webdriver:m18] [webdriver:external] → [webdriver:m18][webdriver:external]
Priority: P3 → P2
Whiteboard: [webdriver:m18][webdriver:external] → [webdriver:m18][webdriver:external][webdriver:relnote]

Summary was misleading, the event was fine, but it wasn't used in to build the payload of the response to browsingContext.navigate.

Summary: Internal "navigation-committed" event payload doesn't always contain the real target URL → browsingContext.navigate with wait=none doesn't always contain the real target URL
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: