Closed Bug 1665549 Opened 4 years ago Closed 4 years ago

Intermittent [Tier2] Fis Wd | test_no_browsing_context - assert 200 == 404

Categories

(Remote Protocol :: Marionette, defect, P5)

Product:
Remote Protocol
Component:
Marionette
Type:
defect

Tracking

(Fission Milestone:M7, firefox83 fixed)

Status:
RESOLVED FIXED
Milestone:
83 Branch
Project Flags:
Fission Milestone M7
Tracking Flags:
Tracking Status
firefox83 --- fixed

People

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

References

Details

(Keywords: intermittent-failure)

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

...
[task 2020-09-17T03:26:01.598Z] 03:26:01 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/add_cookie/add.py::test_add_cookie_with_invalid_samesite_type[same_site2]
[task 2020-09-17T03:26:01.602Z] 03:26:01 INFO - PID 25896 | 1600313161596 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window/rect {"width": 800, "height": 600}
[task 2020-09-17T03:26:01.618Z] 03:26:01 INFO - PID 25896 | 1600313161609 Marionette DEBUG 0 -> [0,305,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2020-09-17T03:26:01.619Z] 03:26:01 INFO - PID 25896 | 1600313161611 Marionette DEBUG 0 <- [1,305,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2020-09-17T03:26:01.620Z] 03:26:01 INFO - PID 25896 | 1600313161612 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2020-09-17T03:26:01.621Z] 03:26:01 INFO - PID 25896 | 1600313161614 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window/rect {"y": 100, "x": 100}
[task 2020-09-17T03:26:01.626Z] 03:26:01 INFO - PID 25896 | 1600313161620 Marionette DEBUG 0 -> [0,306,"WebDriver:SetWindowRect",{"x":100,"y":100}]
[task 2020-09-17T03:26:01.627Z] 03:26:01 INFO - PID 25896 | 1600313161623 Marionette DEBUG 0 <- [1,306,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2020-09-17T03:26:01.628Z] 03:26:01 INFO - PID 25896 | 1600313161625 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2020-09-17T03:26:01.634Z] 03:26:01 INFO - PID 25896 | 1600313161630 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/url {"url": "http://web-platform.test:8000/common/blank.html"}
[task 2020-09-17T03:26:01.634Z] 03:26:01 INFO - PID 25896 | 1600313161631 Marionette DEBUG 0 -> [0,307,"WebDriver:Navigate",{"url":"http://web-platform.test:8000/common/blank.html"}]
[task 2020-09-17T03:26:01.650Z] 03:26:01 INFO - PID 25896 | 1600313161643 Marionette TRACE Received message beforeunload for http://web-platform.test:8000/common/blank.html
[task 2020-09-17T03:26:01.686Z] 03:26:01 INFO - PID 25896 | 1600313161677 Marionette TRACE Received message pagehide for http://web-platform.test:8000/common/blank.html
[task 2020-09-17T03:26:01.722Z] 03:26:01 INFO - PID 25896 | 1600313161715 Marionette TRACE Received message DOMContentLoaded for http://web-platform.test:8000/common/blank.html
[task 2020-09-17T03:26:01.722Z] 03:26:01 INFO - PID 25896 | 1600313161716 Marionette TRACE Received message pageshow for http://web-platform.test:8000/common/blank.html
[task 2020-09-17T03:26:01.722Z] 03:26:01 INFO - PID 25896 | 1600313161717 Marionette DEBUG 0 <- [1,307,null,{"value":null}]
[task 2020-09-17T03:26:01.730Z] 03:26:01 INFO - PID 25896 | 1600313161726 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-09-17T03:26:01.730Z] 03:26:01 INFO - PID 25896 | 1600313161728 webdriver::server DEBUG -> DELETE /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/cookie
[task 2020-09-17T03:26:01.751Z] 03:26:01 INFO - PID 25896 | 1600313161739 Marionette DEBUG 0 -> [0,308,"WebDriver:DeleteAllCookies",{}]
[task 2020-09-17T03:26:01.751Z] 03:26:01 INFO - PID 25896 | 1600313161743 Marionette DEBUG 0 <- [1,308,null,{"value":null}]
[task 2020-09-17T03:26:01.752Z] 03:26:01 INFO - PID 25896 | 1600313161744 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-09-17T03:26:01.752Z] 03:26:01 INFO - STDOUT: PASSED
[task 2020-09-17T03:26:01.752Z] 03:26:01 INFO - PID 25896 | 1600313161745 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/cookie {"cookie": {"name": "hello", "value": "world", "sameSite": {}}}
[task 2020-09-17T03:26:01.753Z] 03:26:01 INFO - PID 25896 | 1600313161745 webdriver::server DEBUG <- 400 Bad Request {"value":{"error":"invalid argument","message":"invalid type: map, expected a string at line 1 column 59","stacktrace":""}}
[task 2020-09-17T03:26:01.753Z] 03:26:01 INFO - PID 25896 | 1600313161748 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/timeouts {"implicit": 0}
[task 2020-09-17T03:26:01.761Z] 03:26:01 INFO - PID 25896 | 1600313161755 Marionette DEBUG 0 -> [0,309,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2020-09-17T03:26:01.761Z] 03:26:01 INFO - PID 25896 | 1600313161756 Marionette DEBUG 0 <- [1,309,null,{"value":null}]
[task 2020-09-17T03:26:01.763Z] 03:26:01 INFO - PID 25896 | 1600313161757 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-09-17T03:26:01.765Z] 03:26:01 INFO - PID 25896 | 1600313161759 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/timeouts {"pageLoad": 300000}
[task 2020-09-17T03:26:01.766Z] 03:26:01 INFO - PID 25896 | 1600313161760 Marionette DEBUG 0 -> [0,310,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2020-09-17T03:26:01.768Z] 03:26:01 INFO - PID 25896 | 1600313161761 Marionette DEBUG 0 <- [1,310,null,{"value":null}]
[task 2020-09-17T03:26:01.770Z] 03:26:01 INFO - PID 25896 | 1600313161762 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-09-17T03:26:01.770Z] 03:26:01 INFO - PID 25896 | 1600313161765 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/timeouts {"script": 30000}
[task 2020-09-17T03:26:01.791Z] 03:26:01 INFO - PID 25896 | 1600313161783 Marionette DEBUG 0 -> [0,311,"WebDriver:SetTimeouts",{"script":30000}]
[task 2020-09-17T03:26:01.792Z] 03:26:01 INFO - PID 25896 | 1600313161784 Marionette DEBUG 0 <- [1,311,null,{"value":null}]
[task 2020-09-17T03:26:01.793Z] 03:26:01 INFO - PID 25896 | 1600313161785 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-09-17T03:26:01.794Z] 03:26:01 INFO - PID 25896 | 1600313161786 webdriver::server DEBUG -> GET /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window
[task 2020-09-17T03:26:01.794Z] 03:26:01 INFO - PID 25896 | 1600313161788 Marionette DEBUG 0 -> [0,312,"WebDriver:GetWindowHandle",{}]
[task 2020-09-17T03:26:01.795Z] 03:26:01 INFO - PID 25896 | 1600313161788 Marionette DEBUG 0 <- [1,312,null,{"value":"17"}]
[task 2020-09-17T03:26:01.795Z] 03:26:01 INFO - PID 25896 | 1600313161789 webdriver::server DEBUG <- 200 OK {"value":"17"}
[task 2020-09-17T03:26:01.797Z] 03:26:01 INFO - PID 25896 | 1600313161790 webdriver::server DEBUG -> GET /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window
[task 2020-09-17T03:26:01.798Z] 03:26:01 INFO - PID 25896 | 1600313161792 Marionette DEBUG 0 -> [0,313,"WebDriver:GetWindowHandle",{}]
[task 2020-09-17T03:26:01.799Z] 03:26:01 INFO - PID 25896 | 1600313161792 Marionette DEBUG 0 <- [1,313,null,{"value":"17"}]
[task 2020-09-17T03:26:01.799Z] 03:26:01 INFO - PID 25896 | 1600313161793 webdriver::server DEBUG <- 200 OK {"value":"17"}
[task 2020-09-17T03:26:01.802Z] 03:26:01 INFO - PID 25896 | 1600313161797 webdriver::server DEBUG -> GET /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window/handles
[task 2020-09-17T03:26:01.802Z] 03:26:01 INFO - PID 25896 | 1600313161798 Marionette DEBUG 0 -> [0,314,"WebDriver:GetWindowHandles",{}]
[task 2020-09-17T03:26:01.803Z] 03:26:01 INFO - PID 25896 | 1600313161800 Marionette DEBUG 0 <- [1,314,null,["17"]]
[task 2020-09-17T03:26:01.804Z] 03:26:01 INFO - PID 25896 | 1600313161801 webdriver::server DEBUG <- 200 OK {"value":["17"]}
[task 2020-09-17T03:26:01.808Z] 03:26:01 INFO - PID 25896 | 1600313161804 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window {"handle": "17"}
[task 2020-09-17T03:26:01.808Z] 03:26:01 INFO - PID 25896 | 1600313161805 Marionette DEBUG 0 -> [0,315,"WebDriver:SwitchToWindow",{"handle":"17","name":"17"}]
[task 2020-09-17T03:26:01.810Z] 03:26:01 INFO - PID 25896 | 1600313161806 Marionette DEBUG 0 <- [1,315,null,{"value":null}]
[task 2020-09-17T03:26:01.810Z] 03:26:01 INFO - PID 25896 | 1600313161807 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-09-17T03:26:01.813Z] 03:26:01 INFO - PID 25896 | 1600313161811 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/alert/dismiss {}
[task 2020-09-17T03:26:01.815Z] 03:26:01 INFO - PID 25896 | 1600313161812 Marionette DEBUG 0 -> [0,316,"WebDriver:DismissAlert",{}]
[task 2020-09-17T03:26:01.817Z] 03:26:01 INFO - PID 25896 | 1600313161813 Marionette DEBUG 0 <- [1,316,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nNoSuchA ... t@chrome://marionette/content/server.js:241:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"},null]
[task 2020-09-17T03:26:01.819Z] 03:26:01 INFO - PID 25896 | 1600313161815 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nNoSuchAlertError@chrome://marionette/content/error.js:382:5\nGeckoDriver.prototype._checkIfAlertIsPresent@chrome://marionette/content/driver.js:3398:11\nGeckoDriver.prototype.dismissDialog@chrome://marionette/content/driver.js:3301:8\ndespatch@chrome://marionette/content/server.js:297:40\nexecute@chrome://marionette/content/server.js:267:16\nonPacket/<@chrome://marionette/content/server.js:240:20\nonPacket@chrome://marionette/content/server.js:241:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"}}
[task 2020-09-17T03:26:01.821Z] 03:26:01 INFO - PID 25896 | 1600313161817 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window {"handle": "17"}
[task 2020-09-17T03:26:01.822Z] 03:26:01 INFO - PID 25896 | 1600313161819 Marionette DEBUG 0 -> [0,317,"WebDriver:SwitchToWindow",{"handle":"17","name":"17"}]
[task 2020-09-17T03:26:01.824Z] 03:26:01 INFO - PID 25896 | 1600313161821 Marionette DEBUG 0 <- [1,317,null,{"value":null}]
[task 2020-09-17T03:26:01.827Z] 03:26:01 INFO - PID 25896 | 1600313161822 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-09-17T03:26:01.829Z] 03:26:01 INFO - PID 25896 | 1600313161825 webdriver::server DEBUG -> GET /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window
[task 2020-09-17T03:26:01.830Z] 03:26:01 INFO - PID 25896 | 1600313161826 Marionette DEBUG 0 -> [0,318,"WebDriver:GetWindowHandle",{}]
[task 2020-09-17T03:26:01.831Z] 03:26:01 INFO - PID 25896 | 1600313161826 Marionette DEBUG 0 <- [1,318,null,{"value":"17"}]
[task 2020-09-17T03:26:01.831Z] 03:26:01 INFO - PID 25896 | 1600313161827 webdriver::server DEBUG <- 200 OK {"value":"17"}
[task 2020-09-17T03:26:01.832Z] 03:26:01 INFO - PID 25896 | 1600313161829 webdriver::server DEBUG -> GET /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window/handles
[task 2020-09-17T03:26:01.840Z] 03:26:01 INFO - PID 25896 | 1600313161832 Marionette DEBUG 0 -> [0,319,"WebDriver:GetWindowHandles",{}]
[task 2020-09-17T03:26:01.841Z] 03:26:01 INFO - PID 25896 | 1600313161833 Marionette DEBUG 0 <- [1,319,null,["17"]]
[task 2020-09-17T03:26:01.842Z] 03:26:01 INFO - PID 25896 | 1600313161834 webdriver::server DEBUG <- 200 OK {"value":["17"]}
[task 2020-09-17T03:26:01.842Z] 03:26:01 INFO - PID 25896 | 1600313161836 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window {"handle": "17"}
[task 2020-09-17T03:26:01.843Z] 03:26:01 INFO - PID 25896 | 1600313161838 Marionette DEBUG 0 -> [0,320,"WebDriver:SwitchToWindow",{"handle":"17","name":"17"}]
[task 2020-09-17T03:26:01.843Z] 03:26:01 INFO - PID 25896 | 1600313161839 Marionette DEBUG 0 <- [1,320,null,{"value":null}]
[task 2020-09-17T03:26:01.845Z] 03:26:01 INFO - PID 25896 | 1600313161840 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-09-17T03:26:01.845Z] 03:26:01 INFO - PID 25896 | 1600313161841 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/window/rect {"width": 800, "height": 600}
[task 2020-09-17T03:26:01.847Z] 03:26:01 INFO - PID 25896 | 1600313161843 Marionette DEBUG 0 -> [0,321,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2020-09-17T03:26:01.848Z] 03:26:01 INFO - PID 25896 | 1600313161847 Marionette DEBUG 0 <- [1,321,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2020-09-17T03:26:01.854Z] 03:26:01 INFO - PID 25896 | 1600313161848 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2020-09-17T03:26:01.854Z] 03:26:01 INFO - PID 25896 | 1600313161850 webdriver::server DEBUG -> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/frame {"id": null}
[task 2020-09-17T03:26:01.854Z] 03:26:01 INFO - PID 25896 | 1600313161851 Marionette DEBUG 0 -> [0,322,"WebDriver:SwitchToFrame",{"id":null}]
[task 2020-09-17T03:26:01.863Z] 03:26:01 INFO - PID 25896 | 1600313161857 Marionette DEBUG 0 <- [1,322,null,{"value":null}]
[task 2020-09-17T03:26:01.864Z] 03:26:01 INFO - PID 25896 | 1600313161858 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-09-17T03:26:01.865Z] 03:26:01 INFO - STDOUT: =================================== FAILURES ===================================
[task 2020-09-17T03:26:01.865Z] 03:26:01 INFO - STDOUT: ___________________________ test_no_browsing_context ___________________________
[task 2020-09-17T03:26:01.866Z] 03:26:01 INFO - STDOUT: session = <Session d57e4396-076d-4e11-b90d-35bb8e5ae4e3>, closed_frame = None
[task 2020-09-17T03:26:01.867Z] 03:26:01 INFO - STDOUT: def test_no_browsing_context(session, closed_frame):
[task 2020-09-17T03:26:01.869Z] 03:26:01 INFO - STDOUT: new_cookie = {
[task 2020-09-17T03:26:01.870Z] 03:26:01 INFO - STDOUT: "name": "hello",
[task 2020-09-17T03:26:01.871Z] 03:26:01 INFO - STDOUT: "value": "world",
[task 2020-09-17T03:26:01.871Z] 03:26:01 INFO - STDOUT: }
[task 2020-09-17T03:26:01.872Z] 03:26:01 INFO - STDOUT:
[task 2020-09-17T03:26:01.873Z] 03:26:01 INFO - STDOUT: response = add_cookie(session, new_cookie)
[task 2020-09-17T03:26:01.873Z] 03:26:01 INFO - STDOUT: > assert_error(response, "no such window")
[task 2020-09-17T03:26:01.874Z] 03:26:01 INFO - STDOUT: closed_frame = None
[task 2020-09-17T03:26:01.874Z] 03:26:01 INFO - STDOUT: new_cookie = {'name': 'hello', 'value': 'world'}
[task 2020-09-17T03:26:01.875Z] 03:26:01 INFO - STDOUT: response = <Responsetatus=200 body={"value": null}>
[task 2020-09-17T03:26:01.875Z] 03:26:01 INFO - STDOUT: session = <Session d57e4396-076d-4e11-b90d-35bb8e5ae4e3>
[task 2020-09-17T03:26:01.876Z] 03:26:01 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/add_cookie/add.py
[task 2020-09-17T03:26:01.876Z] 03:26:01 INFO - STDOUT: :54:
[task 2020-09-17T03:26:01.876Z] 03:26:01 INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-09-17T03:26:01.877Z] 03:26:01 INFO - STDOUT: response = <Responsetatus=200 body={"value": null}>
[task 2020-09-17T03:26:01.877Z] 03:26:01 INFO - STDOUT: error_code = 'no such window'
[task 2020-09-17T03:26:01.877Z] 03:26:01 INFO - STDOUT: def assert_error(response, error_code):
[task 2020-09-17T03:26:01.878Z] 03:26:01 INFO - STDOUT: """
[task 2020-09-17T03:26:01.879Z] 03:26:01 INFO - STDOUT: Verify that the provided webdriver.Response instance described
[task 2020-09-17T03:26:01.880Z] 03:26:01 INFO - STDOUT: a valid error response as defined by dfn-send-an-error and
[task 2020-09-17T03:26:01.880Z] 03:26:01 INFO - STDOUT: the provided error code.
[task 2020-09-17T03:26:01.881Z] 03:26:01 INFO - STDOUT:
[task 2020-09-17T03:26:01.881Z] 03:26:01 INFO - STDOUT: :param response: webdriver.Response instance.
[task 2020-09-17T03:26:01.881Z] 03:26:01 INFO - STDOUT: :param error_code: String value of the expected error code
[task 2020-09-17T03:26:01.883Z] 03:26:01 INFO - STDOUT: """
[task 2020-09-17T03:26:01.883Z] 03:26:01 INFO - STDOUT: > assert response.status == errors[error_code]
[task 2020-09-17T03:26:01.884Z] 03:26:01 INFO - STDOUT: E assert 200 == 404
[task 2020-09-17T03:26:01.884Z] 03:26:01 INFO - STDOUT: E + where 200 = <Responsetatus=200 body={"value": null}>.status
[task 2020-09-17T03:26:01.885Z] 03:26:01 INFO - STDOUT: error_code = 'no such window'
[task 2020-09-17T03:26:01.887Z] 03:26:01 INFO - STDOUT: response = <Responsetatus=200 body={"value": null}>
[task 2020-09-17T03:26:01.887Z] 03:26:01 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/support/asserts.py
[task 2020-09-17T03:26:01.887Z] 03:26:01 INFO - STDOUT: :52: AssertionError
[task 2020-09-17T03:26:01.889Z] 03:26:01 INFO - STDOUT: ===================== 1 failed, 15 passed in 14.19 seconds =====================
[task 2020-09-17T03:26:01.915Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.916Z] 03:26:01 INFO - TEST-PASS | /webdriver/tests/add_cookie/add.py | test_null_parameter_value
[task 2020-09-17T03:26:01.916Z] 03:26:01 INFO - TEST-PASS | /webdriver/tests/add_cookie/add.py | test_null_response_value
[task 2020-09-17T03:26:01.916Z] 03:26:01 INFO - TEST-PASS | /webdriver/tests/add_cookie/add.py | test_no_top_browsing_context
[task 2020-09-17T03:26:01.917Z] 03:26:01 INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/add_cookie/add.py | test_no_browsing_context - assert 200 == 404
[task 2020-09-17T03:26:01.919Z] 03:26:01 INFO - session = <Session d57e4396-076d-4e11-b90d-35bb8e5ae4e3>, closed_frame = None
[task 2020-09-17T03:26:01.919Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.919Z] 03:26:01 INFO - def test_no_browsing_context(session, closed_frame):
[task 2020-09-17T03:26:01.919Z] 03:26:01 INFO - new_cookie = {
[task 2020-09-17T03:26:01.919Z] 03:26:01 INFO - "name": "hello",
[task 2020-09-17T03:26:01.919Z] 03:26:01 INFO - "value": "world",
[task 2020-09-17T03:26:01.919Z] 03:26:01 INFO - }
[task 2020-09-17T03:26:01.919Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - response = add_cookie(session, new_cookie)
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - > assert_error(response, "no such window")
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - closed_frame = None
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - new_cookie = {'name': 'hello', 'value': 'world'}
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - response = <Responsetatus=200 body={"value": null}>
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - session = <Session d57e4396-076d-4e11-b90d-35bb8e5ae4e3>
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - tests/web-platform/tests/webdriver/tests/add_cookie/add.py:54:
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - response = <Responsetatus=200 body={"value": null}>
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - error_code = 'no such window'
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - def assert_error(response, error_code):
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - """
[task 2020-09-17T03:26:01.920Z] 03:26:01 INFO - Verify that the provided webdriver.Response instance described
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO - a valid error response as defined by dfn-send-an-error and
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO - the provided error code.
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO - :param response: webdriver.Response instance.
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO - :param error_code: String value of the expected error code
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO - """
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO - > assert response.status == errors[error_code]
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO - E assert 200 == 404
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO - E + where 200 = <Responsetatus=200 body={"value": null}>.status
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.921Z] 03:26:01 INFO - error_code = 'no such window'
[task 2020-09-17T03:26:01.922Z] 03:26:01 INFO - response = <Responsetatus=200 body={"value": null}>
[task 2020-09-17T03:26:01.922Z] 03:26:01 INFO -
[task 2020-09-17T03:26:01.922Z] 03:26:01 INFO - tests/web-platform/tests/webdriver/tests/support/asserts.py:52: AssertionError
[task 2020-09-17T03:26:01.925Z] 03:26:01 INFO - ............
[task 2020-09-17T03:26:01.925Z] 03:26:01 INFO - TEST-OK | /webdriver/tests/add_cookie/add.py | took 14517ms
[task 2020-09-17T03:26:02.000Z] 03:26:02 INFO - Closing logging queue
[task 2020-09-17T03:26:02.000Z] 03:26:02 INFO - queue closed

Here the real failing lines:

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=315908372&repo=autoland&lineNumber=46305-46319

[task 2020-09-17T03:25:58.236Z] 03:25:58     INFO - PID 25896 | 1600313158229	Marionette	DEBUG	0 -> [0,71,"WebDriver:ElementClick",{"id":"e36e5afd-76bd-4441-8c06-6cdb0d74c693"}]
[task 2020-09-17T03:25:58.313Z] 03:25:58     INFO - PID 25896 | [Child 26042, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp, line 348
[task 2020-09-17T03:25:58.313Z] 03:25:58     INFO - PID 25896 | [Child 26042, Main Thread] WARNING: NS_ENSURE_TRUE(wc) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp, line 344
[task 2020-09-17T03:25:58.320Z] 03:25:58     INFO - PID 25896 | 1600313158309	Marionette	TRACE	[38] Frame with id 6442450946 got removed
[task 2020-09-17T03:25:58.323Z] 03:25:58     INFO - PID 25896 | 1600313158310	Marionette	TRACE	Canceled page load listener because current frame has been removed
[task 2020-09-17T03:25:58.324Z] 03:25:58     INFO - PID 25896 | 1600313158311	Marionette	DEBUG	0 <- [1,71,null,{"value":null}]
[task 2020-09-17T03:25:58.326Z] 03:25:58     INFO - PID 25896 | [Child 26128, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp, line 172
[task 2020-09-17T03:25:58.326Z] 03:25:58     INFO - PID 25896 | [Child 26128, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp, line 172
[task 2020-09-17T03:25:58.327Z] 03:25:58     INFO - PID 25896 | [Child 26128, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp, line 172
[task 2020-09-17T03:25:58.328Z] 03:25:58     INFO - PID 25896 | 1600313158312	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2020-09-17T03:25:58.329Z] 03:25:58     INFO - PID 25896 | [Child 26128, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp, line 172
[task 2020-09-17T03:25:58.330Z] 03:25:58     INFO - PID 25896 | 1600313158316	webdriver::server	DEBUG	-> POST /session/d57e4396-076d-4e11-b90d-35bb8e5ae4e3/cookie {"cookie": {"name": "hello", "value": "world"}}
[task 2020-09-17T03:25:58.330Z] 03:25:58     INFO - PID 25896 | [Child 26128, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp, line 348
[task 2020-09-17T03:25:58.330Z] 03:25:58     INFO - PID 25896 | 1600313158318	Marionette	DEBUG	0 -> [0,72,"WebDriver:AddCookie",{"cookie":{"httpOnly":false,"name":"hello","secure":false,"value":"world"}}]
[task 2020-09-17T03:25:58.331Z] 03:25:58     INFO - PID 25896 | 1600313158323	Marionette	DEBUG	0 <- [1,72,null,{"value":null}]

The current frame seems to get closed but the add cookie command doesn't return a no such window error. There are also other tests with the same assertion message. So making this bug more generic to Wdspec tests.

Summary: Intermittent /webdriver/tests/add_cookie/add.py | test_no_browsing_context - assert 200 == 404 → Intermittent Wd | test_no_browsing_context - assert 200 == 404

Most likely a race which needs to be investigate / fixed via bug 1666204.

Depends on: 1666204

Checking the log again this is most likely a problem with a delayed click due to the synchronous capabilities update with the parent process. This has been removed with the patch on bug 1394354, and as such this failure should no longer happen.

Depends on: 1394354

As it looks like bug 1666204 hasn't been fixed yet. But maybe this turned into a Fission only bug. Lets observe the failures over the next days.

Summary: Intermittent Wd | test_no_browsing_context - assert 200 == 404 → Intermittent [Tier2] Fis Wd | test_no_browsing_context - assert 200 == 404
Whiteboard: [marionette-fission-mvp]

Tracking for Fission Beta milestone (M7).

Fission Milestone: --- → M7

No more failures since my patch on bug 1666204 got landed. Marking as fixed.

Assignee: nobody → hskupin
Status: NEW → RESOLVED
Closed: 4 years ago
status-firefox83: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 83 Branch
Resolution: FIXED → WORKSFORME
Whiteboard: [marionette-fission-mvp]
Resolution: WORKSFORME → FIXED
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.