1861551 - Intermittent /webdriver/tests/bidi/browsing_context/load/load.py | test_page_with_base_tag - AssertionError

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO - TEST-PASS | /webdriver/tests/bidi/browsing_context/load/load.py | test_document_write 
[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/bidi/browsing_context/load/load.py | test_page_with_base_tag - AssertionError
[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7f526efe8510>
[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO - subscribe_events = <function subscribe_events.<locals>.subscribe_events at 0x7f526ef54b90>
[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO - inline = <function inline.<locals>.inline at 0x7f526ef54ef0>
[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO - new_tab = {'context': 'b67cba29-6d7d-4ca6-9d57-1de08dde2026'}
[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7f526ef54170>
[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO - 
[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO -     async def test_page_with_base_tag(
[task 2023-10-27T00:39:21.051Z] 00:39:21     INFO -         bidi_session, subscribe_events, inline, new_tab, wait_for_event
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -     ):
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -         await subscribe_events(events=[CONTEXT_LOAD_EVENT])
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -     
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -         on_entry = wait_for_event(CONTEXT_LOAD_EVENT)
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -         url = inline("""<base href="/relative-path">""")
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -         result = await bidi_session.browsing_context.navigate(
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -             context=new_tab["context"], url=url
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -         )
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -         event = await on_entry
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -     
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -         assert_navigation_info(
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -             event,
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO - >           {"context": new_tab["context"], "navigation": result["navigation"], "url": url},
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO -         )
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO - 
[task 2023-10-27T00:39:21.052Z] 00:39:21     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7f526efe8510>
[task 2023-10-27T00:39:21.053Z] 00:39:21     INFO - event      = {'context': 'b67cba29-6d7d-4ca6-9d57-1de08dde2026',
[task 2023-10-27T00:39:21.053Z] 00:39:21     INFO -  'navigation': '6c6f34cc-451b-4305-bb5a-efbfe0d69c63',
[task 2023-10-27T00:39:21.053Z] 00:39:21     INFO -  'timestamp': 1698367160568,
[task 2023-10-27T00:39:21.053Z] 00:39:21     INFO -  'url': 'https://web-platform.test:8443/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cbase+href%3D%22%2Frelative-path%22%3E&mime=text%2Fhtml&charset=UTF-8'}
[task 2023-10-27T00:39:21.053Z] 00:39:21     INFO - inline     = <function inline.<locals>.inline at 0x7f526ef54ef0>
[task 2023-10-27T00:39:21.053Z] 00:39:21     INFO - new_tab    = {'context': 'b67cba29-6d7d-4ca6-9d57-1de08dde2026'}
[task 2023-10-27T00:39:21.053Z] 00:39:21     INFO - on_entry   = <Future finished result={'context': 'b67cba29-6d7...-1de08dde2026', 'navigation': '6c6f34cc-451...-efbfe0d69c63', 'timestamp': 1698367160568, 'url': 'https://web-...charset=UTF-8'}>
[task 2023-10-27T00:39:21.053Z] 00:39:21     INFO - result     = {'navigation': '1e6f0c7d-94ba-45a2-9820-c391eb8d7911',
[task 2023-10-27T00:39:21.054Z] 00:39:21     INFO -  'url': 'https://web-platform.test:8443/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cbase+href%3D%22%2Frelative-path%22%3E&mime=text%2Fhtml&charset=UTF-8'}
[task 2023-10-27T00:39:21.054Z] 00:39:21     INFO - subscribe_events = <function subscribe_events.<locals>.subscribe_events at 0x7f526ef54b90>
[task 2023-10-27T00:39:21.054Z] 00:39:21     INFO - url        = 'https://web-platform.test:8443/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cbase+href%3D%22%2Frelative-path%22%3E&mime=text%2Fhtml&charset=UTF-8'
[task 2023-10-27T00:39:21.054Z] 00:39:21     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7f526ef54170>
[task 2023-10-27T00:39:21.054Z] 00:39:21     INFO - 
[task 2023-10-27T00:39:21.054Z] 00:39:21     INFO - tests/web-platform/tests/webdriver/tests/bidi/browsing_context/load/load.py:174: 

Comment 1

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

The problem here is that the navigation info is wrong for the load event:
https://treeherder.mozilla.org/logviewer?job_id=433970025&repo=autoland&lineNumber=11349-11356

[task 2023-10-27T00:39:21.181Z] 00:39:21     INFO - STDOUT: >           assert event["navigation"] == expected_navigation_info["navigation"]
[task 2023-10-27T00:39:21.182Z] 00:39:21     INFO - STDOUT: E           AssertionError
[task 2023-10-27T00:39:21.182Z] 00:39:21     INFO - STDOUT: event      = {'context': 'b67cba29-6d7d-4ca6-9d57-1de08dde2026',
[task 2023-10-27T00:39:21.182Z] 00:39:21     INFO -  'navigation': '6c6f34cc-451b-4305-bb5a-efbfe0d69c63',
[task 2023-10-27T00:39:21.182Z] 00:39:21     INFO -  'timestamp': 1698367160568,
[task 2023-10-27T00:39:21.182Z] 00:39:21     INFO -  'url': 'https://web-platform.test:8443/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cbase+href%3D%22%2Frelative-path%22%3E&mime=text%2Fhtml&charset=UTF-8'}
[task 2023-10-27T00:39:21.183Z] 00:39:21     INFO - STDOUT: expected_navigation_info = {'context': 'b67cba29-6d7d-4ca6-9d57-1de08dde2026',
[task 2023-10-27T00:39:21.183Z] 00:39:21     INFO -  'navigation': '1e6f0c7d-94ba-45a2-9820-c391eb8d7911',
[task 2023-10-27T00:39:21.183Z] 00:39:21     INFO -  'url': 'https://web-platform.test:8443/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cbase+href%3D%22%2Frelative-path%22%3E&mime=text%2Fhtml&charset=UTF-8'}

Julian, I didn't further check but I assume it's something already known?

Comment 2

[Julian Descottes [:jdescottes]]

Thanks for the ping, I don't know if we have it tracked already.

Basically we have a navigation with wait=none which resolves before the NavigationListener had time to forward the navigation to the parent process. We capture the navigation in content, but the command resolves before we communicate it to the parent.

We could wait internally for navigation-started, but I think we might have edge cases where a command will not actually start a navigation and might not lead to a navigation-started event?

Overall I think we should address this by creating the navigation id from the navigate command. This is actually in-line with the spec which expects the navigation id to be created from bidi and forwarded to html's navigate. I imagine this can show up in any test doing a wait=none navigation and asserting navigation ids, so let's file a bug for the overall issue in case other intermittents show up.

Comment 3

[Intermittent Failures Robot]

1 failures in 3657 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1861551&startday=2023-10-23&endday=2023-10-29&tree=all

Comment 4

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

Fixed via bug 1861655.