1755755 - Intermittent linux debug/Windows 10 opt /webdriver/tests/bidi/browsing_context/context_created/context_created.py | test_navigate_creates_iframes , test_navigate_creates_nested_iframes - AssertionError

Status: RESOLVED WORKSFORME

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-02-16T18:26:32.275Z] 18:26:32     INFO - TEST-PASS | /webdriver/tests/bidi/browsing_context/context_created/context_created.py | test_evaluate_window_open_without_url 
[task 2022-02-16T18:26:32.275Z] 18:26:32     INFO - TEST-PASS | /webdriver/tests/bidi/browsing_context/context_created/context_created.py | test_evaluate_window_open_with_url 
[task 2022-02-16T18:26:32.276Z] 18:26:32     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/bidi/browsing_context/context_created/context_created.py | test_navigate_creates_iframes - AssertionError
[task 2022-02-16T18:26:32.276Z] 18:26:32     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7f65182a47b8>
[task 2022-02-16T18:26:32.276Z] 18:26:32     INFO - current_session = <Session 95587c1c-31f1-4460-a859-13376fe3ee0c>
[task 2022-02-16T18:26:32.276Z] 18:26:32     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7f651826ed90>
[task 2022-02-16T18:26:32.276Z] 18:26:32     INFO - inline = <function inline.<locals>.inline at 0x7f651826eea0>
[task 2022-02-16T18:26:32.276Z] 18:26:32     INFO - 
[task 2022-02-16T18:26:32.276Z] 18:26:32     INFO -     async def test_navigate_creates_iframes(bidi_session, current_session, wait_for_event, inline):
[task 2022-02-16T18:26:32.277Z] 18:26:32     INFO -         # Unsubscribe in case a previous tests subscribed to the event
[task 2022-02-16T18:26:32.277Z] 18:26:32     INFO -         await bidi_session.session.unsubscribe(events=[CONTEXT_CREATED_EVENT])
[task 2022-02-16T18:26:32.277Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.277Z] 18:26:32     INFO -         top_level_context_id = current_session.window_handle
[task 2022-02-16T18:26:32.277Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.277Z] 18:26:32     INFO -         url_iframe1 = inline("<div>foo</div>")
[task 2022-02-16T18:26:32.277Z] 18:26:32     INFO -         url_iframe2 = inline("<div>bar</div>")
[task 2022-02-16T18:26:32.277Z] 18:26:32     INFO -         url_page = inline(
[task 2022-02-16T18:26:32.278Z] 18:26:32     INFO -             f"<iframe src='{url_iframe1}'></iframe><iframe src='{url_iframe2}'></iframe>"
[task 2022-02-16T18:26:32.278Z] 18:26:32     INFO -         )
[task 2022-02-16T18:26:32.278Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.278Z] 18:26:32     INFO -         events = []
[task 2022-02-16T18:26:32.278Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.279Z] 18:26:32     INFO -         async def on_event(method, data):
[task 2022-02-16T18:26:32.279Z] 18:26:32     INFO -             events.append(data)
[task 2022-02-16T18:26:32.279Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.279Z] 18:26:32     INFO -         remove_listener = bidi_session.add_event_listener(CONTEXT_CREATED_EVENT, on_event)
[task 2022-02-16T18:26:32.279Z] 18:26:32     INFO -         await bidi_session.session.subscribe(events=[CONTEXT_CREATED_EVENT])
[task 2022-02-16T18:26:32.280Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.280Z] 18:26:32     INFO -         current_session.url = url_page
[task 2022-02-16T18:26:32.281Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.281Z] 18:26:32     INFO -         wait = AsyncPoll(
[task 2022-02-16T18:26:32.282Z] 18:26:32     INFO -             current_session,
[task 2022-02-16T18:26:32.282Z] 18:26:32     INFO -             message="Didn't receive context created events for frames")
[task 2022-02-16T18:26:32.282Z] 18:26:32     INFO -         await wait.until(lambda _: len(events) >= 2)
[task 2022-02-16T18:26:32.282Z] 18:26:32     INFO -         assert len(events) == 2
[task 2022-02-16T18:26:32.282Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.283Z] 18:26:32     INFO -         assert_browsing_context(
[task 2022-02-16T18:26:32.283Z] 18:26:32     INFO -             events[0],
[task 2022-02-16T18:26:32.284Z] 18:26:32     INFO -             children=None,
[task 2022-02-16T18:26:32.284Z] 18:26:32     INFO -             context=None,
[task 2022-02-16T18:26:32.284Z] 18:26:32     INFO -             url=url_iframe1,
[task 2022-02-16T18:26:32.285Z] 18:26:32     INFO -             parent=top_level_context_id,
[task 2022-02-16T18:26:32.287Z] 18:26:32     INFO -         )
[task 2022-02-16T18:26:32.287Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.288Z] 18:26:32     INFO -         assert_browsing_context(
[task 2022-02-16T18:26:32.288Z] 18:26:32     INFO -             events[1],
[task 2022-02-16T18:26:32.288Z] 18:26:32     INFO -             children=None,
[task 2022-02-16T18:26:32.288Z] 18:26:32     INFO -             context=None,
[task 2022-02-16T18:26:32.288Z] 18:26:32     INFO -             url=url_iframe2,
[task 2022-02-16T18:26:32.288Z] 18:26:32     INFO - >           parent=top_level_context_id,
[task 2022-02-16T18:26:32.288Z] 18:26:32     INFO -         )
[task 2022-02-16T18:26:32.288Z] 18:26:32     INFO - 
[task 2022-02-16T18:26:32.288Z] 18:26:32     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7f65182a47b8>
[task 2022-02-16T18:26:32.293Z] 18:26:32     INFO - current_session = <Session 95587c1c-31f1-4460-a859-13376fe3ee0c>
[task 2022-02-16T18:26:32.293Z] 18:26:32     INFO - events     = [{'children': None,
[task 2022-02-16T18:26:32.293Z] 18:26:32     INFO -   'context': '12884901889',
[task 2022-02-16T18:26:32.293Z] 18:26:32     INFO -   'parent': '8cebf623-bb2d-4088-9ea3-940aae95f2cf',
[task 2022-02-16T18:26:32.294Z] 18:26:32     INFO -   'url': 'http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cdiv%3Efoo%3C%2Fdiv%3E&mime=text%2Fhtml&charset=UTF-8'},
[task 2022-02-16T18:26:32.294Z] 18:26:32     INFO -  {'children': None,
[task 2022-02-16T18:26:32.294Z] 18:26:32     INFO -   'context': '12884901890',
[task 2022-02-16T18:26:32.294Z] 18:26:32     INFO -   'parent': '8cebf623-bb2d-4088-9ea3-940aae95f2cf',
[task 2022-02-16T18:26:32.295Z] 18:26:32     INFO -   'url': 'about:blank'}]
[task 2022-02-16T18:26:32.295Z] 18:26:32     INFO - inline     = <function inline.<locals>.inline at 0x7f651826eea0>
[task 2022-02-16T18:26:32.295Z] 18:26:32     INFO - on_event   = <function test_navigate_creates_iframes.<locals>.on_event at 0x7f651826e8c8>
[task 2022-02-16T18:26:32.295Z] 18:26:32     INFO - remove_listener = <function BidiSession.add_event_listener.<locals>.<lambda> at 0x7f651826ea60>
[task 2022-02-16T18:26:32.295Z] 18:26:32     INFO - top_level_context_id = '8cebf623-bb2d-4088-9ea3-940aae95f2cf'
[task 2022-02-16T18:26:32.296Z] 18:26:32     INFO - url_iframe1 = 'http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cdiv%3Efoo%3C%2Fdiv%3E&mime=text%2Fhtml&charset=UTF-8'
[task 2022-02-16T18:26:32.296Z] 18:26:32     INFO - url_iframe2 = 'http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cdiv%3Ebar%3C%2Fdiv%3E&mime=text%2Fhtml&charset=UTF-8'
[task 2022-02-16T18:26:32.296Z] 18:26:32     INFO - url_page   = 'http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Ciframe+src%3D%27http%3A%2F%2Fweb-platform.test%3A8000%2Fwebdriver%2Ftests%2Fsupport%2Finline.py%3Fdoc%3D%253C%2521doctype%2Bhtml%253E%250A%253Cmeta%2Bcharset%253DUTF-8%253E%250A%253Cdiv%253Efoo%253C%252Fdiv%253E%26mime%3Dtext%252Fhtml%26charset%3DUTF-8%27%3E%3C%2Fiframe%3E%3Ciframe+src%3D%27http%3A%2F%2Fweb-platform.test%3A8000%2Fwebdriver%2Ftests%2Fsupport%2Finline.py%3Fdoc%3D%253C%2521doctype%2Bhtml%253E%250A%253Cmeta%2Bcharset%253DUTF-8%253E%250A%253Cdiv%253Ebar%253C%252Fdiv%253E%26mime%3Dtext%252Fhtml%26charset%3DUTF-8%27%3E%3C%2Fiframe%3E&mime=text%2Fhtml&charset=UTF-8'
[task 2022-02-16T18:26:32.296Z] 18:26:32     INFO - wait       = <tests.support.sync.AsyncPoll object at 0x7f65182d7828>
[task 2022-02-16T18:26:32.296Z] 18:26:32     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7f651826ed90>
[task 2022-02-16T18:26:32.306Z] 18:26:32     INFO - 
[task 2022-02-16T18:26:32.306Z] 18:26:32     INFO - tests/web-platform/tests/webdriver/tests/bidi/browsing_context/context_created/context_created.py:149: 
[task 2022-02-16T18:26:32.306Z] 18:26:32     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2022-02-16T18:26:32.306Z] 18:26:32     INFO - 
[task 2022-02-16T18:26:32.306Z] 18:26:32     INFO - info = {'children': None, 'context': '12884901890', 'parent': '8cebf623-bb2d-4088-9ea3-940aae95f2cf', 'url': 'about:blank'}
[task 2022-02-16T18:26:32.307Z] 18:26:32     INFO - children = None, context = None
[task 2022-02-16T18:26:32.307Z] 18:26:32     INFO - url = 'http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cdiv%3Ebar%3C%2Fdiv%3E&mime=text%2Fhtml&charset=UTF-8'
[task 2022-02-16T18:26:32.307Z] 18:26:32     INFO - parent = '8cebf623-bb2d-4088-9ea3-940aae95f2cf'
[task 2022-02-16T18:26:32.307Z] 18:26:32     INFO - 
[task 2022-02-16T18:26:32.308Z] 18:26:32     INFO -     def assert_browsing_context(info, children, context, url, parent=None):
[task 2022-02-16T18:26:32.308Z] 18:26:32     INFO -         assert "children" in info
[task 2022-02-16T18:26:32.308Z] 18:26:32     INFO -         if children is not None:
[task 2022-02-16T18:26:32.308Z] 18:26:32     INFO -             assert isinstance(info["children"], list)
[task 2022-02-16T18:26:32.308Z] 18:26:32     INFO -         assert info["children"] == children
[task 2022-02-16T18:26:32.308Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.308Z] 18:26:32     INFO -         assert "context" in info
[task 2022-02-16T18:26:32.308Z] 18:26:32     INFO -         assert isinstance(info["context"], str)
[task 2022-02-16T18:26:32.309Z] 18:26:32     INFO -         # TODO: Always check for context once we can can get the context for frames
[task 2022-02-16T18:26:32.309Z] 18:26:32     INFO -         # by using browsingContext.getTree.
[task 2022-02-16T18:26:32.309Z] 18:26:32     INFO -         if context is not None:
[task 2022-02-16T18:26:32.309Z] 18:26:32     INFO -             assert info["context"] == context
[task 2022-02-16T18:26:32.309Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.309Z] 18:26:32     INFO -         # parent context is optional but will always be present because emitted
[task 2022-02-16T18:26:32.310Z] 18:26:32     INFO -         # events only contain the current browsing context and no childs.
[task 2022-02-16T18:26:32.310Z] 18:26:32     INFO -         assert "parent" in info
[task 2022-02-16T18:26:32.310Z] 18:26:32     INFO -         if children is not None:
[task 2022-02-16T18:26:32.310Z] 18:26:32     INFO -             assert isinstance(info["parent"], str)
[task 2022-02-16T18:26:32.310Z] 18:26:32     INFO -         assert info["parent"] == parent
[task 2022-02-16T18:26:32.310Z] 18:26:32     INFO -     
[task 2022-02-16T18:26:32.310Z] 18:26:32     INFO -         assert "url" in info
[task 2022-02-16T18:26:32.310Z] 18:26:32     INFO -         assert isinstance(info["url"], str)
[task 2022-02-16T18:26:32.310Z] 18:26:32     INFO - >       assert info["url"] == url
[task 2022-02-16T18:26:32.311Z] 18:26:32     INFO - E       AssertionError
[task 2022-02-16T18:26:32.311Z] 18:26:32     INFO - 
[task 2022-02-16T18:26:32.311Z] 18:26:32     INFO - children   = None
[task 2022-02-16T18:26:32.311Z] 18:26:32     INFO - context    = None
[task 2022-02-16T18:26:32.311Z] 18:26:32     INFO - info       = {'children': None,
[task 2022-02-16T18:26:32.311Z] 18:26:32     INFO -  'context': '12884901890',
[task 2022-02-16T18:26:32.312Z] 18:26:32     INFO -  'parent': '8cebf623-bb2d-4088-9ea3-940aae95f2cf',
[task 2022-02-16T18:26:32.312Z] 18:26:32     INFO -  'url': 'about:blank'}
[task 2022-02-16T18:26:32.312Z] 18:26:32     INFO - parent     = '8cebf623-bb2d-4088-9ea3-940aae95f2cf'
[task 2022-02-16T18:26:32.312Z] 18:26:32     INFO - url        = 'http://web-platform.test:8000/webdriver/tests/support/inline.py?doc=%3C%21doctype+html%3E%0A%3Cmeta+charset%3DUTF-8%3E%0A%3Cdiv%3Ebar%3C%2Fdiv%3E&mime=text%2Fhtml&charset=UTF-8'
[task 2022-02-16T18:26:32.312Z] 18:26:32     INFO - 
[task 2022-02-16T18:26:32.312Z] 18:26:32     INFO - tests/web-platform/tests/webdriver/tests/bidi/browsing_context/context_created/__init__.py:23: AssertionError
[task 2022-02-16T18:26:32.313Z] 18:26:32     INFO - .
[task 2022-02-16T18:26:32.313Z] 18:26:32     INFO - TEST-OK | /webdriver/tests/bidi/browsing_context/context_created/context_created.py | took 19996ms

Comment 1

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

The problem here is that we send out the browsing context created event for an iframe with an url of about:blank but not the actual target page. I thought that we do not load the initial about:blank for iframes, but we probably do? Olli, could you please tell us if that is true? Thanks!

Comment 2

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

All failures so far are Linux debug. Maybe it's just the slowness of the build which is causing the initial about:blank page to be displayed longer than expected?

Comment 3

[Olli Pettay [:smaug][[e-mail]]]

iframes aren't any special when it comes to about:blank.
They may get the initial, non-loaded about:blank lazily and if there is no src attribute, another about:blank is loaded.

Comment 4

[Intermittent Failures Robot]

18 failures in 3281 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 12
• mozilla-central: 4
• try: 2

Platform and build breakdown:

• linux1804-64-qr: 17
  • debug: 17
• windows10-32-2004-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1755755&startday=2022-02-14&endday=2022-02-20&tree=all

Comment 5

[Intermittent Failures Robot]

11 failures in 2992 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 5
• autoland: 6

Platform and build breakdown:

• linux1804-64-qr: 10
  • debug: 10
• windows10-32-2004-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1755755&startday=2022-02-21&endday=2022-02-27&tree=all

Comment 6

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

Thanks Olli. As it looks like we would clearly need a fix for bug 1756532 then.

Comment 7

[Intermittent Failures Robot]

14 failures in 3063 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 8
• mozilla-central: 6

Platform and build breakdown:

• linux1804-64-qr: 12
  • debug: 12
• windows10-64-2004-ccov-qr: 1
  • opt: 1
• windows10-64-2004-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1755755&startday=2022-02-28&endday=2022-03-06&tree=all

Comment 8

[Intermittent Failures Robot]

9 failures in 2837 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 8
• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-qr: 7
  • debug: 7
• linux1804-64-asan-qr: 1
  • opt: 1
• windows10-64-2004-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1755755&startday=2022-03-07&endday=2022-03-13&tree=all

Comment 9

[Intermittent Failures Robot]

10 failures in 3304 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 5
• autoland: 5

Platform and build breakdown:

• linux1804-64-qr: 9
  • debug: 9
• windows10-64-2004-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1755755&startday=2022-03-14&endday=2022-03-20&tree=all

Comment 10

[Intermittent Failures Robot]

5 failures in 3341 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3
• mozilla-central: 2

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1
• windows10-64-2004-ccov-qr: 1
  • opt: 1
• linux1804-64-qr: 3
  • debug: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1755755&startday=2022-03-21&endday=2022-03-27&tree=all

Comment 11

[Intermittent Failures Robot]

2 failures in 3323 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• autoland: 1

Platform and build breakdown:

• linux1804-64-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1755755&startday=2022-03-28&endday=2022-04-03&tree=all

Comment 12

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

Last time this failure happened was March 30th. So not sure how much bug 1756532 is related here and if it has finally fixed this bug to occur. Lets wait until next week and if we still see no failures lets close it.

Comment 13

[BMO Automation]

Moving bug to Remote Protocol::Marionette component per bug 1815831.