Closed Bug 1658016 Opened 5 years ago Closed 5 years ago

Intermittent /webdriver/tests/take_element_screenshot/user_prompts.py | test_accept_and_notify[capabilities0-alert-None] - AssertionError: assert 'unknown error' == 'unexpected alert open'

Categories

(Remote Protocol :: Marionette, defect, P5)

Product:
Remote Protocol
Component:
Marionette
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: assertion, intermittent-failure)

Filed by: archaeopteryx [at] coole-files.de
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=312411909&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ceMwGut3QW2pbBky-ErsQg/runs/0/artifacts/public/logs/live_backing.log

[task 2020-08-07T16:36:34.107Z] 16:36:34 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/take_element_screenshot/user_prompts.py
[task 2020-08-07T16:36:34.108Z] 16:36:34 INFO - STDOUT: :87:
[task 2020-08-07T16:36:34.108Z] 16:36:34 INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-08-07T16:36:34.108Z] 16:36:34 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/take_element_screenshot/user_prompts.py
[task 2020-08-07T16:36:34.109Z] 16:36:34 INFO - STDOUT: :46: in check_user_prompt_closed_with_exception
[task 2020-08-07T16:36:34.109Z] 16:36:34 INFO - STDOUT: assert_error(response, "unexpected alert open")
[task 2020-08-07T16:36:34.109Z] 16:36:34 INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-08-07T16:36:34.109Z] 16:36:34 INFO - STDOUT: response = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2020-08-07T16:36:34.109Z] 16:36:34 INFO - STDOUT: error_code = 'unexpected alert open'
[task 2020-08-07T16:36:34.109Z] 16:36:34 INFO - STDOUT: def assert_error(response, error_code):
[task 2020-08-07T16:36:34.110Z] 16:36:34 INFO - STDOUT: """
[task 2020-08-07T16:36:34.110Z] 16:36:34 INFO - STDOUT: Verify that the provided webdriver.Response instance described
[task 2020-08-07T16:36:34.110Z] 16:36:34 INFO - STDOUT: a valid error response as defined by dfn-send-an-error and
[task 2020-08-07T16:36:34.110Z] 16:36:34 INFO - STDOUT: the provided error code.
[task 2020-08-07T16:36:34.110Z] 16:36:34 INFO - STDOUT:
[task 2020-08-07T16:36:34.111Z] 16:36:34 INFO - STDOUT: :param response: webdriver.Response instance.
[task 2020-08-07T16:36:34.111Z] 16:36:34 INFO - STDOUT: :param error_code: String value of the expected error code
[task 2020-08-07T16:36:34.111Z] 16:36:34 INFO - STDOUT: """
[task 2020-08-07T16:36:34.111Z] 16:36:34 INFO - STDOUT: assert response.status == errors[error_code]
[task 2020-08-07T16:36:34.130Z] 16:36:34 INFO - STDOUT: assert "value" in response.body
[task 2020-08-07T16:36:34.130Z] 16:36:34 INFO - STDOUT: > assert response.body["value"]["error"] == error_code
[task 2020-08-07T16:36:34.130Z] 16:36:34 INFO - STDOUT: E AssertionError: assert 'unknown error' == 'unexpected alert open'
[task 2020-08-07T16:36:34.131Z] 16:36:34 INFO - STDOUT: E - unknown error
[task 2020-08-07T16:36:34.132Z] 16:36:34 INFO - STDOUT: E + unexpected alert open
[task 2020-08-07T16:36:34.132Z] 16:36:34 INFO - STDOUT: error_code = 'unexpected alert open'
[task 2020-08-07T16:36:34.135Z] 16:36:34 INFO - STDOUT: response = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2020-08-07T16:36:34.135Z] 16:36:34 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/support/asserts.py
[task 2020-08-07T16:36:34.136Z] 16:36:34 INFO - STDOUT: :54: AssertionError
[task 2020-08-07T16:36:34.136Z] 16:36:34 INFO - STDOUT: =============================== warnings summary ===============================
[task 2020-08-07T16:36:34.136Z] 16:36:34 INFO - STDOUT: <undetermined location>
[task 2020-08-07T16:36:34.136Z] 16:36:34 INFO - STDOUT: Module already imported so cannot be rewritten: mozlog
[task 2020-08-07T16:36:34.136Z] 16:36:34 INFO - STDOUT: Module already imported so cannot be rewritten: tests.support.fixtures
[task 2020-08-07T16:36:34.139Z] 16:36:34 INFO - STDOUT: -- Docs: http://doc.pytest.org/en/latest/warnings.html
[task 2020-08-07T16:36:34.139Z] 16:36:34 INFO - STDOUT: =============== 1 failed, 17 passed, 2 warnings in 29.37 seconds ===============
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO -
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - TEST-PASS | /webdriver/tests/take_element_screenshot/user_prompts.py | test_accept[capabilities0-alert-None]
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - TEST-PASS | /webdriver/tests/take_element_screenshot/user_prompts.py | test_accept[capabilities0-confirm-True]
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - TEST-PASS | /webdriver/tests/take_element_screenshot/user_prompts.py | test_accept[capabilities0-prompt-]
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/take_element_screenshot/user_prompts.py | test_accept_and_notify[capabilities0-alert-None] - AssertionError: assert 'unknown error' == 'unexpected alert open'
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - check_user_prompt_closed_with_exception = <function check_user_prompt_closed_with_exception at 0x1054ce578>
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - dialog_type = 'alert', retval = None
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO -
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - @pytest.mark.capabilities({"unhandledPromptBehavior": "accept and notify"})
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - @pytest.mark.parametrize("dialog_type, retval", [
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - ("alert", None),
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - ("confirm", True),
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - ("prompt", ""),
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - ])
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - def test_accept_and_notify(check_user_prompt_closed_with_exception, dialog_type, retval):
[task 2020-08-07T16:36:34.141Z] 16:36:34 INFO - > check_user_prompt_closed_with_exception(dialog_type, retval)
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO -
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - check_user_prompt_closed_with_exception = <function check_user_prompt_closed_with_exception at 0x1054ce578>
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - dialog_type = 'alert'
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - retval = None
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO -
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - tests/web-platform/tests/webdriver/tests/take_element_screenshot/user_prompts.py:87:
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - tests/web-platform/tests/webdriver/tests/take_element_screenshot/user_prompts.py:46: in check_user_prompt_closed_with_exception
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - assert_error(response, "unexpected alert open")
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO -
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - response = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - error_code = 'unexpected alert open'
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO -
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - def assert_error(response, error_code):
[task 2020-08-07T16:36:34.142Z] 16:36:34 INFO - """
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - Verify that the provided webdriver.Response instance described
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - a valid error response as defined by dfn-send-an-error and
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - the provided error code.
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO -
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - :param response: webdriver.Response instance.
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - :param error_code: String value of the expected error code
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - """
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - assert response.status == errors[error_code]
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - assert "value" in response.body
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - > assert response.body["value"]["error"] == error_code
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - E AssertionError: assert 'unknown error' == 'unexpected alert open'
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - E - unknown error
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - E + unexpected alert open
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO -
[task 2020-08-07T16:36:34.143Z] 16:36:34 INFO - error_code = 'unexpected alert open'
[task 2020-08-07T16:36:34.144Z] 16:36:34 INFO - response = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2020-08-07T16:36:34.144Z] 16:36:34 INFO -
[task 2020-08-07T16:36:34.144Z] 16:36:34 INFO - tests/web-platform/tests/webdriver/tests/support/asserts.py:54: AssertionError
[task 2020-08-07T16:36:34.147Z] 16:36:34 INFO - ..............
[task 2020-08-07T16:36:34.147Z] 16:36:34 INFO - TEST-OK | /webdriver/tests/take_element_screenshot/user_prompts.py | took 29418ms

The problem here seems to be actually a crash of Firefox:

[task 2020-08-07T16:36:12.728Z] 16:36:12     INFO - PID 1020 | 1596818172682	Marionette	DEBUG	0 -> [0,7,"WebDriver:GetAlertText",{}]
[task 2020-08-07T16:36:12.728Z] 16:36:12     INFO - PID 1020 | 1596818172682	Marionette	DEBUG	0 <- [1,7,null,{"value":"alert"}]
[task 2020-08-07T16:36:12.728Z] 16:36:12     INFO - PID 1020 | 1596818172683	webdriver::server	DEBUG	<- 200 OK {"value":"alert"}
[task 2020-08-07T16:36:12.728Z] 16:36:12     INFO - PID 1020 | 1596818172685	webdriver::server	DEBUG	-> GET /session/cdb3fea9-f0b5-5c47-bec6-8f2201bb541d/element/37169c9f-d169-9e4d-9ce9-264792be6e79/screenshot
[task 2020-08-07T16:36:12.728Z] 16:36:12     INFO - PID 1020 | 1596818172685	Marionette	DEBUG	0 -> [0,8,"WebDriver:TakeScreenshot",{"full":false,"highlights":[],"id":"37169c9f-d169-9e4d-9ce9-264792be6e79"}]
[task 2020-08-07T16:36:12.728Z] 16:36:12     INFO - PID 1020 | 1596818172689	Marionette	TRACE	Received event DOMModalDialogClosed
[task 2020-08-07T16:36:12.980Z] 16:36:12     INFO - PID 1020 | Exiting due to channel error.
[task 2020-08-07T16:36:12.980Z] 16:36:12     INFO - PID 1020 | 1596818172970	webdriver::server	DEBUG	Deleting session
[task 2020-08-07T16:36:12.980Z] 16:36:12     INFO - PID 1020 | Exiting due to channel error.
[task 2020-08-07T16:36:12.982Z] 16:36:12     INFO - PID 1020 | Exiting due to channel error.
[task 2020-08-07T16:36:13.177Z] 16:36:13     INFO - PID 1020 | 1596818173133	geckodriver::marionette	DEBUG	Browser process stopped: exit code: 1
[task 2020-08-07T16:36:13.177Z] 16:36:13     INFO - PID 1020 | 1596818173143	webdriver::server	DEBUG	<- 500 Internal Server Error {"value":{"error":"unknown error","message":"Failed to decode response from marionette","stacktrace":""}}

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 5 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.