Closed Bug 1632676 Opened 5 years ago Closed 4 years ago

Intermittent /webdriver/tests/close_window/close.py | test_close_browsing_context_with_dismissed_beforeunload_prompt - AssertionError: assert [] == ['18']

Categories

(Remote Protocol :: Marionette, defect, P5)

Version 3
defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

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


[task 2020-04-23T21:40:01.504Z] 21:40:01 INFO - PID 1777 | 1587678001488 webdriver::server DEBUG <- 200 OK {"value":"18"}
[task 2020-04-23T21:40:01.523Z] 21:40:01 INFO - PID 1777 | 1587678001508 webdriver::server DEBUG -> GET /session/40519fea-ea4e-d141-845d-373c430c2a52/window
[task 2020-04-23T21:40:01.527Z] 21:40:01 INFO - PID 1777 | 1587678001512 Marionette DEBUG 0 -> [0,3,"WebDriver:GetWindowHandle",{}]
[task 2020-04-23T21:40:01.527Z] 21:40:01 INFO - PID 1777 | 1587678001513 Marionette DEBUG 0 <- [1,3,null,{"value":"18"}]
[task 2020-04-23T21:40:01.527Z] 21:40:01 INFO - PID 1777 | 1587678001516 webdriver::server DEBUG <- 200 OK {"value":"18"}
[task 2020-04-23T21:40:01.564Z] 21:40:01 INFO - PID 1777 | 1587678001542 webdriver::server DEBUG -> GET /session/40519fea-ea4e-d141-845d-373c430c2a52/window/handles
[task 2020-04-23T21:40:01.590Z] 21:40:01 INFO - PID 1777 | 1587678001555 Marionette DEBUG 0 -> [0,4,"WebDriver:GetWindowHandles",{}]
[task 2020-04-23T21:40:01.591Z] 21:40:01 INFO - PID 1777 | 1587678001556 Marionette DEBUG 0 <- [1,4,null,["18"]]
[task 2020-04-23T21:40:01.591Z] 21:40:01 INFO - PID 1777 | 1587678001558 webdriver::server DEBUG <- 200 OK {"value":["18"]}
[task 2020-04-23T21:40:01.592Z] 21:40:01 INFO - PID 1777 | 1587678001571 webdriver::server DEBUG -> POST /session/40519fea-ea4e-d141-845d-373c430c2a52/window {"handle": "18"}
[task 2020-04-23T21:40:01.592Z] 21:40:01 INFO - PID 1777 | 1587678001574 Marionette DEBUG 0 -> [0,5,"WebDriver:SwitchToWindow",{"handle":"18","name":"18"}]
[task 2020-04-23T21:40:01.592Z] 21:40:01 INFO - PID 1777 | 1587678001575 Marionette DEBUG 0 <- [1,5,null,{"value":null}]
[task 2020-04-23T21:40:01.594Z] 21:40:01 INFO - PID 1777 | 1587678001576 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-04-23T21:40:01.595Z] 21:40:01 INFO - PID 1777 | 1587678001579 webdriver::server DEBUG -> POST /session/40519fea-ea4e-d141-845d-373c430c2a52/alert/dismiss {}
[task 2020-04-23T21:40:01.596Z] 21:40:01 INFO - PID 1777 | 1587678001579 Marionette DEBUG 0 -> [0,6,"WebDriver:DismissAlert",{}]
[task 2020-04-23T21:40:01.598Z] 21:40:01 INFO - PID 1777 | 1587678001580 Marionette DEBUG 0 <- [1,6,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:175:5\nNoSuchAle ... t@chrome://marionette/content/server.js:249:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:501:20\n"},null]
[task 2020-04-23T21:40:01.598Z] 21:40:01 INFO - PID 1777 | 1587678001581 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:175:5\nNoSuchAlertError@chrome://marionette/content/error.js:376:5\nGeckoDriver.prototype._checkIfAlertIsPresent@chrome://marionette/content/driver.js:3388:11\nGeckoDriver.prototype.dismissDialog@chrome://marionette/content/driver.js:3301:8\ndespatch@chrome://marionette/content/server.js:305:40\nexecute@chrome://marionette/content/server.js:275:16\nonPacket/<@chrome://marionette/content/server.js:248:20\nonPacket@chrome://marionette/content/server.js:249:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:501:20\n"}}
[task 2020-04-23T21:40:01.600Z] 21:40:01 INFO - PID 1777 | 1587678001584 webdriver::server DEBUG -> POST /session/40519fea-ea4e-d141-845d-373c430c2a52/window {"handle": "18"}
[task 2020-04-23T21:40:01.600Z] 21:40:01 INFO - PID 1777 | 1587678001585 Marionette DEBUG 0 -> [0,7,"WebDriver:SwitchToWindow",{"handle":"18","name":"18"}]
[task 2020-04-23T21:40:01.600Z] 21:40:01 INFO - PID 1777 | 1587678001592 Marionette DEBUG 0 <- [1,7,null,{"value":null}]
[task 2020-04-23T21:40:01.602Z] 21:40:01 INFO - PID 1777 | 1587678001596 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-04-23T21:40:01.630Z] 21:40:01 INFO - PID 1777 | 1587678001614 webdriver::server DEBUG -> GET /session/40519fea-ea4e-d141-845d-373c430c2a52/window
[task 2020-04-23T21:40:01.630Z] 21:40:01 INFO - PID 1777 | 1587678001618 Marionette DEBUG 0 -> [0,8,"WebDriver:GetWindowHandle",{}]
[task 2020-04-23T21:40:01.630Z] 21:40:01 INFO - PID 1777 | 1587678001622 Marionette DEBUG 0 <- [1,8,null,{"value":"18"}]
[task 2020-04-23T21:40:01.631Z] 21:40:01 INFO - PID 1777 | 1587678001624 webdriver::server DEBUG <- 200 OK {"value":"18"}
[task 2020-04-23T21:40:01.639Z] 21:40:01 INFO - PID 1777 | 1587678001631 webdriver::server DEBUG -> GET /session/40519fea-ea4e-d141-845d-373c430c2a52/window/handles
[task 2020-04-23T21:40:01.641Z] 21:40:01 INFO - PID 1777 | 1587678001633 Marionette DEBUG 0 -> [0,9,"WebDriver:GetWindowHandles",{}]
[task 2020-04-23T21:40:01.641Z] 21:40:01 INFO - PID 1777 | 1587678001634 Marionette DEBUG 0 <- [1,9,null,["18"]]
[task 2020-04-23T21:40:01.642Z] 21:40:01 INFO - PID 1777 | 1587678001635 webdriver::server DEBUG <- 200 OK {"value":["18"]}
[task 2020-04-23T21:40:01.663Z] 21:40:01 INFO - PID 1777 | 1587678001660 webdriver::server DEBUG -> POST /session/40519fea-ea4e-d141-845d-373c430c2a52/window {"handle": "18"}
[task 2020-04-23T21:40:01.688Z] 21:40:01 INFO - PID 1777 | 1587678001664 Marionette DEBUG 0 -> [0,10,"WebDriver:SwitchToWindow",{"handle":"18","name":"18"}]
[task 2020-04-23T21:40:01.688Z] 21:40:01 INFO - PID 1777 | 1587678001666 Marionette DEBUG 0 <- [1,10,null,{"value":null}]
[task 2020-04-23T21:40:01.688Z] 21:40:01 INFO - PID 1777 | 1587678001668 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-04-23T21:40:01.689Z] 21:40:01 INFO - PID 1777 | 1587678001673 webdriver::server DEBUG -> POST /session/40519fea-ea4e-d141-845d-373c430c2a52/window/rect {"width": 800, "height": 600}
[task 2020-04-23T21:40:01.689Z] 21:40:01 INFO - PID 1777 | 1587678001675 Marionette DEBUG 0 -> [0,11,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2020-04-23T21:40:01.736Z] 21:40:01 INFO - PID 1777 | 1587678001726 Marionette DEBUG 0 <- [1,11,null,{"x":4,"y":23,"width":800,"height":600}]
[task 2020-04-23T21:40:01.737Z] 21:40:01 INFO - PID 1777 | 1587678001727 webdriver::server DEBUG <- 200 OK {"value":{"x":4,"y":23,"width":800,"height":600}}
[task 2020-04-23T21:40:01.738Z] 21:40:01 INFO - PID 1777 | DEBUG: Adding blocker ScriptPreloader: Saving bytecode cache for phase xpcom-will-shutdown
[task 2020-04-23T21:40:01.741Z] 21:40:01 INFO - PID 1777 | 1587678001730 webdriver::server DEBUG -> POST /session/40519fea-ea4e-d141-845d-373c430c2a52/frame {"id": null}
[task 2020-04-23T21:40:01.742Z] 21:40:01 INFO - PID 1777 | 1587678001731 Marionette DEBUG 0 -> [0,12,"WebDriver:SwitchToFrame",{"id":null}]
[task 2020-04-23T21:40:01.745Z] 21:40:01 INFO - PID 1777 | 1587678001735 Marionette DEBUG 0 <- [1,12,null,{"value":null}]
[task 2020-04-23T21:40:01.749Z] 21:40:01 INFO - PID 1777 | 1587678001735 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2020-04-23T21:40:01.751Z] 21:40:01 INFO - STDOUT: =================================== FAILURES ===================================
[task 2020-04-23T21:40:01.751Z] 21:40:01 INFO - STDOUT: ________ test_close_browsing_context_with_dismissed_beforeunload_prompt ________
[task 2020-04-23T21:40:01.753Z] 21:40:01 INFO - STDOUT: session = <Session 0287b5c4-e713-234b-9334-6a9d7cb63f2b>
[task 2020-04-23T21:40:01.754Z] 21:40:01 INFO - STDOUT: create_window = <function create_window at 0x10c90be60>
[task 2020-04-23T21:40:01.754Z] 21:40:01 INFO - STDOUT: def test_close_browsing_context_with_dismissed_beforeunload_prompt(session, create_window):
[task 2020-04-23T21:40:01.756Z] 21:40:01 INFO - STDOUT: original_handles = session.handles
[task 2020-04-23T21:40:01.757Z] 21:40:01 INFO - STDOUT:
[task 2020-04-23T21:40:01.757Z] 21:40:01 INFO - STDOUT: new_handle = create_window()
[task 2020-04-23T21:40:01.759Z] 21:40:01 INFO - STDOUT: session.window_handle = new_handle
[task 2020-04-23T21:40:01.760Z] 21:40:01 INFO - STDOUT:
[task 2020-04-23T21:40:01.760Z] 21:40:01 INFO - STDOUT: session.url = inline("""
[task 2020-04-23T21:40:01.760Z] 21:40:01 INFO - STDOUT: <input type="text">
[task 2020-04-23T21:40:01.762Z] 21:40:01 INFO - STDOUT: <script>
[task 2020-04-23T21:40:01.763Z] 21:40:01 INFO - STDOUT: window.addEventListener("beforeunload", function (event) {
[task 2020-04-23T21:40:01.763Z] 21:40:01 INFO - STDOUT: event.preventDefault();
[task 2020-04-23T21:40:01.765Z] 21:40:01 INFO - STDOUT: });
[task 2020-04-23T21:40:01.766Z] 21:40:01 INFO - STDOUT: </script>
[task 2020-04-23T21:40:01.766Z] 21:40:01 INFO - STDOUT: """)
[task 2020-04-23T21:40:01.769Z] 21:40:01 INFO - STDOUT:
[task 2020-04-23T21:40:01.769Z] 21:40:01 INFO - STDOUT: session.find.css("input", all=False).send_keys("foo")
[task 2020-04-23T21:40:01.770Z] 21:40:01 INFO - STDOUT:
[task 2020-04-23T21:40:01.770Z] 21:40:01 INFO - STDOUT: response = close(session)
[task 2020-04-23T21:40:01.770Z] 21:40:01 INFO - STDOUT: > handles = assert_success(response, original_handles)
[task 2020-04-23T21:40:01.770Z] 21:40:01 INFO - STDOUT: create_window = <function create_window at 0x10c90be60>
[task 2020-04-23T21:40:01.771Z] 21:40:01 INFO - STDOUT: new_handle = '4294967304'
[task 2020-04-23T21:40:01.771Z] 21:40:01 INFO - STDOUT: original_handles = ['18']
[task 2020-04-23T21:40:01.773Z] 21:40:01 INFO - STDOUT: response = <Responsetatus=200 body={"value": []}>
[task 2020-04-23T21:40:01.773Z] 21:40:01 INFO - STDOUT: session = <Session 0287b5c4-e713-234b-9334-6a9d7cb63f2b>
[task 2020-04-23T21:40:01.773Z] 21:40:01 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/close_window/close.py
[task 2020-04-23T21:40:01.774Z] 21:40:01 INFO - STDOUT: :48:
[task 2020-04-23T21:40:01.774Z] 21:40:01 INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-04-23T21:40:01.776Z] 21:40:01 INFO - STDOUT: response = <Responsetatus=200 body={"value": []}>, value = ['18']
[task 2020-04-23T21:40:01.776Z] 21:40:01 INFO - STDOUT: def assert_success(response, value=None):
[task 2020-04-23T21:40:01.777Z] 21:40:01 INFO - STDOUT: """
[task 2020-04-23T21:40:01.777Z] 21:40:01 INFO - STDOUT: Verify that the provided webdriver.Response instance described
[task 2020-04-23T21:40:01.779Z] 21:40:01 INFO - STDOUT: a valid success response as defined by dfn-send-a-response and
[task 2020-04-23T21:40:01.779Z] 21:40:01 INFO - STDOUT: the provided response value.
[task 2020-04-23T21:40:01.779Z] 21:40:01 INFO - STDOUT:
[task 2020-04-23T21:40:01.780Z] 21:40:01 INFO - STDOUT: :param response: webdriver.Response instance.
[task 2020-04-23T21:40:01.780Z] 21:40:01 INFO - STDOUT: :param value: Expected value of the response body, if any.
[task 2020-04-23T21:40:01.786Z] 21:40:01 INFO - STDOUT: """
[task 2020-04-23T21:40:01.786Z] 21:40:01 INFO - STDOUT: assert response.status == 200, str(response.error)
[task 2020-04-23T21:40:01.786Z] 21:40:01 INFO - STDOUT:
[task 2020-04-23T21:40:01.787Z] 21:40:01 INFO - STDOUT: if value is not None:
[task 2020-04-23T21:40:01.787Z] 21:40:01 INFO - STDOUT: > assert response.body["value"] == value
[task 2020-04-23T21:40:01.787Z] 21:40:01 INFO - STDOUT: E AssertionError: assert [] == ['18']
[task 2020-04-23T21:40:01.788Z] 21:40:01 INFO - STDOUT: E Right contains more items, first extra item: '18'
[task 2020-04-23T21:40:01.788Z] 21:40:01 INFO - STDOUT: E Full diff:
[task 2020-04-23T21:40:01.788Z] 21:40:01 INFO - STDOUT: E - []
[task 2020-04-23T21:40:01.789Z] 21:40:01 INFO - STDOUT: E + [u'18']
[task 2020-04-23T21:40:01.789Z] 21:40:01 INFO - STDOUT: response = <Responsetatus=200 body={"value": []}>
[task 2020-04-23T21:40:01.789Z] 21:40:01 INFO - STDOUT: value = ['18']
[task 2020-04-23T21:40:01.790Z] 21:40:01 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/support/asserts.py
[task 2020-04-23T21:40:01.790Z] 21:40:01 INFO - STDOUT: :70: AssertionError
[task 2020-04-23T21:40:01.790Z] 21:40:01 INFO - STDOUT: =============================== warnings summary ===============================
[task 2020-04-23T21:40:01.791Z] 21:40:01 INFO - STDOUT: <undetermined location>
[task 2020-04-23T21:40:01.791Z] 21:40:01 INFO - STDOUT: Module already imported so cannot be rewritten: mozlog
[task 2020-04-23T21:40:01.791Z] 21:40:01 INFO - STDOUT: -- Docs: http://doc.pytest.org/en/latest/warnings.html
[task 2020-04-23T21:40:01.793Z] 21:40:01 INFO - STDOUT: =============== 1 failed, 3 passed, 1 warnings in 17.74 seconds ================
[task 2020-04-23T21:40:01.849Z] 21:40:01 INFO -
[task 2020-04-23T21:40:01.849Z] 21:40:01 INFO - TEST-PASS | /webdriver/tests/close_window/close.py | test_no_browsing_context
[task 2020-04-23T21:40:01.849Z] 21:40:01 INFO - TEST-PASS | /webdriver/tests/close_window/close.py | test_close_browsing_context
[task 2020-04-23T21:40:01.849Z] 21:40:01 INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/close_window/close.py | test_close_browsing_context_with_dismissed_beforeunload_prompt - AssertionError: assert [] == ['18']
[task 2020-04-23T21:40:01.849Z] 21:40:01 INFO - session = <Session 0287b5c4-e713-234b-9334-6a9d7cb63f2b>

The problem here is actually a content crash:

[task 2020-04-23T21:39:48.766Z] 21:39:48     INFO - PID 1777 | 1587677988742	Marionette	DEBUG	0 -> [0,65,"WebDriver:CloseWindow",{}]
[task 2020-04-23T21:39:48.829Z] 21:39:48     INFO - PID 1777 | 1587677988821	Marionette	TRACE	Received observer notification message-manager-disconnect
[task 2020-04-23T21:39:48.843Z] 21:39:48     INFO - PID 1777 | 1587677988831	Marionette	TRACE	[21] Frame script loaded
[task 2020-04-23T21:39:48.843Z] 21:39:48     INFO - PID 1777 | 1587677988831	Marionette	TRACE	[21] Frame script registered
[task 2020-04-23T21:39:48.845Z] 21:39:48     INFO - PID 1777 | 1587677988842	Marionette	TRACE	[23] Frame script loaded
[task 2020-04-23T21:39:48.845Z] 21:39:48     INFO - PID 1777 | 1587677988842	Marionette	TRACE	[23] Frame script registered
[task 2020-04-23T21:39:48.864Z] 21:39:48     INFO - PID 1777 | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down

To know more about the crash we would need bug 1490906 fixed.

Depends on: 1490906
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
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.