1666406 - Intermittent /webdriver/tests/find_elements/find.py | test_no_browsing_context - assert 200 == 404

Status: RESOLVED DUPLICATE of bug 1665549

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2020-09-22T05:29:33.018Z] 05:29:33     INFO - TEST-PASS | /webdriver/tests/find_elements/find.py | test_no_top_browsing_context 
[task 2020-09-22T05:29:33.019Z] 05:29:33     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/find_elements/find.py | test_no_browsing_context - assert 200 == 404
[task 2020-09-22T05:29:33.019Z] 05:29:33     INFO - session = <Session 919ee0e1-48d8-4c2c-af59-8ce5d747fb80>, closed_frame = None
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - 
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -     def test_no_browsing_context(session, closed_frame):
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -         response = find_elements(session, "css selector", "foo")
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - >       assert_error(response, "no such window")
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - 
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - closed_frame = None
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - response   = <Responsetatus=200 body={"value": []}>
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - session    = <Session 919ee0e1-48d8-4c2c-af59-8ce5d747fb80>
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - 
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - tests/web-platform/tests/webdriver/tests/find_elements/find.py:28: 
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - 
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - response = <Responsetatus=200 body={"value": []}>, error_code = 'no such window'
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - 
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -     def assert_error(response, error_code):
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -         """
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -         Verify that the provided webdriver.Response instance described
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -         a valid error response as defined by `dfn-send-an-error` and
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -         the provided error code.
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -     
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -         :param response: ``webdriver.Response`` instance.
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -         :param error_code: String value of the expected error code
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO -         """
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - >       assert response.status == errors[error_code]
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - E       assert 200 == 404
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - E        +  where 200 = <Responsetatus=200 body={"value": []}>.status
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - 
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - error_code = 'no such window'
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - response   = <Responsetatus=200 body={"value": []}>
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - 
[task 2020-09-22T05:29:33.033Z] 05:29:33     INFO - tests/web-platform/tests/webdriver/tests/support/asserts.py:52: AssertionError```

Comment 1

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

Also looks like a race between closing the frame and running the next command:

[task 2020-09-22T05:29:27.556Z] 05:29:27     INFO - PID 5093 | 1600752567552	Marionette	DEBUG	0 -> [0,52,"WebDriver:ElementClick",{"id":"7669a411-de41-4db5-aadd-18d148d6ba9e"}]
[task 2020-09-22T05:29:27.657Z] 05:29:27     INFO - PID 5093 | 1600752567653	Marionette	TRACE	[38] Frame with id 6442450946 got removed
[task 2020-09-22T05:29:27.657Z] 05:29:27     INFO - PID 5093 | 1600752567653	Marionette	TRACE	Canceled page load listener because current frame has been removed
[task 2020-09-22T05:29:27.659Z] 05:29:27     INFO - PID 5093 | 1600752567653	Marionette	DEBUG	0 <- [1,52,null,{"value":null}]
[task 2020-09-22T05:29:27.660Z] 05:29:27     INFO - PID 5093 | 1600752567654	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2020-09-22T05:29:27.660Z] 05:29:27     INFO - PID 5093 | 1600752567656	webdriver::server	DEBUG	-> POST /session/919ee0e1-48d8-4c2c-af59-8ce5d747fb80/elements {"using": "css selector", "value": "foo"}
[task 2020-09-22T05:29:27.661Z] 05:29:27     INFO - PID 5093 | 1600752567657	Marionette	DEBUG	0 -> [0,53,"WebDriver:FindElements",{"using":"css selector","value":"foo"}]
[task 2020-09-22T05:29:27.681Z] 05:29:27     INFO - PID 5093 | 1600752567672	Marionette	DEBUG	0 <- [1,53,null,[]]

It would need a fix on bug 1666204.

Comment 2

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

Actually this is bug 1665549.

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux1804-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1666406&startday=2020-09-21&endday=2020-09-27&tree=all

Comment 4

[BMO Automation]

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