Closed Bug 1517570 Opened 6 years ago Closed 6 years ago

Intermittent /webdriver/tests/minimize_window/user_prompts.py | test_accept[capabilities0-prompt-] - assert not True

Categories

(Remote Protocol :: Marionette, defect, P5)

Product:
Remote Protocol
Component:
Marionette
Version:
Version 3
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure)

Filed by: rmaries [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=219828814&repo=autoland https://queue.taskcluster.net/v1/task/BnDUjzoaTimBexveNuMJmw/runs/0/artifacts/public/logs/live_backing.log [task 2019-01-03T18:55:37.179Z] 18:55:37 INFO - STDOUT: Module already imported so cannot be rewritten: tests.support.fixtures [task 2019-01-03T18:55:37.182Z] 18:55:37 INFO - STDOUT: -- Docs: http://doc.pytest.org/en/latest/warnings.html [task 2019-01-03T18:55:37.183Z] 18:55:37 INFO - STDOUT: ============== 1 failed, 17 passed, 2 warnings in 121.92 seconds =============== [task 2019-01-03T18:55:37.185Z] 18:55:37 INFO - [task 2019-01-03T18:55:37.186Z] 18:55:37 INFO - TEST-PASS | /webdriver/tests/minimize_window/user_prompts.py | test_accept[capabilities0-alert-None] [task 2019-01-03T18:55:37.186Z] 18:55:37 INFO - TEST-PASS | /webdriver/tests/minimize_window/user_prompts.py | test_accept[capabilities0-confirm-True] [task 2019-01-03T18:55:37.187Z] 18:55:37 INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/minimize_window/user_prompts.py | test_accept[capabilities0-prompt-] - assert not True [task 2019-01-03T18:55:37.187Z] 18:55:37 INFO - check_user_prompt_closed_without_exception = <function check_user_prompt_closed_without_exception at 0x7fd7010a16e0> [task 2019-01-03T18:55:37.187Z] 18:55:37 INFO - dialog_type = 'prompt', retval = '' [task 2019-01-03T18:55:37.188Z] 18:55:37 INFO - [task 2019-01-03T18:55:37.188Z] 18:55:37 INFO - @pytest.mark.capabilities({"unhandledPromptBehavior": "accept"}) [task 2019-01-03T18:55:37.188Z] 18:55:37 INFO - @pytest.mark.parametrize("dialog_type, retval", [ [task 2019-01-03T18:55:37.190Z] 18:55:37 INFO - ("alert", None), [task 2019-01-03T18:55:37.190Z] 18:55:37 INFO - ("confirm", True), [task 2019-01-03T18:55:37.191Z] 18:55:37 INFO - ("prompt", ""), [task 2019-01-03T18:55:37.192Z] 18:55:37 INFO - ]) [task 2019-01-03T18:55:37.192Z] 18:55:37 INFO - def test_accept(check_user_prompt_closed_without_exception, dialog_type, retval): [task 2019-01-03T18:55:37.193Z] 18:55:37 INFO - > check_user_prompt_closed_without_exception(dialog_type, retval) [task 2019-01-03T18:55:37.193Z] 18:55:37 INFO - [task 2019-01-03T18:55:37.193Z] 18:55:37 INFO - check_user_prompt_closed_without_exception = <function check_user_prompt_closed_without_exception at 0x7fd7010a16e0> [task 2019-01-03T18:55:37.196Z] 18:55:37 INFO - dialog_type = 'prompt' [task 2019-01-03T18:55:37.196Z] 18:55:37 INFO - retval = '' [task 2019-01-03T18:55:37.197Z] 18:55:37 INFO - [task 2019-01-03T18:55:37.198Z] 18:55:37 INFO - tests/web-platform/tests/webdriver/tests/minimize_window/user_prompts.py:68: [task 2019-01-03T18:55:37.198Z] 18:55:37 INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ [task 2019-01-03T18:55:37.199Z] 18:55:37 INFO - [task 2019-01-03T18:55:37.199Z] 18:55:37 INFO - dialog_type = 'prompt', retval = '' [task 2019-01-03T18:55:37.200Z] 18:55:37 INFO - [task 2019-01-03T18:55:37.200Z] 18:55:37 INFO - def check_user_prompt_closed_without_exception(dialog_type, retval): [task 2019-01-03T18:55:37.200Z] 18:55:37 INFO - > assert not document_hidden(session) [task 2019-01-03T18:55:37.201Z] 18:55:37 INFO - E assert not True [task 2019-01-03T18:55:37.202Z] 18:55:37 INFO - E + where True = document_hidden(<Session 5a345abb-f4b1-4ba8-bb86-8f3cabd014e4>) [task 2019-01-03T18:55:37.202Z] 18:55:37 INFO - [task 2019-01-03T18:55:37.203Z] 18:55:37 INFO - create_dialog = <function create_dialog at 0x7fd7010a1320> [task 2019-01-03T18:55:37.203Z] 18:55:37 INFO - dialog_type = 'prompt' [task 2019-01-03T18:55:37.203Z] 18:55:37 INFO - retval = '' [task 2019-01-03T18:55:37.204Z] 18:55:37 INFO - session = <Session 5a345abb-f4b1-4ba8-bb86-8f3cabd014e4> [task 2019-01-03T18:55:37.204Z] 18:55:37 INFO - [task 2019-01-03T18:55:37.204Z] 18:55:37 INFO - tests/web-platform/tests/webdriver/tests/minimize_window/user_prompts.py:17: AssertionError [task 2019-01-03T18:55:37.206Z] 18:55:37 INFO - ............... [task 2019-01-03T18:55:37.206Z] 18:55:37 INFO - TEST-OK | /webdriver/tests/minimize_window/user_prompts.py | took 121974ms [task 2019-01-03T18:55:37.227Z] 18:55:37 INFO - Closing logging queue [task 2019-01-03T18:55:37.227Z] 18:55:37 INFO - queue closed [task 2019-01-03T18:55:37.229Z] 18:55:37 INFO - Starting runner [task 2019-01-03T18:55:37.256Z] 18:55:37 INFO - PID 31902 | 1546541737252 webdriver::httpapi DEBUG Creating routes [task 2019-01-03T18:55:37.260Z] 18:55:37 INFO - PID 31902 | 1546541737257 geckodriver DEBUG Listening on 127.0.0.1:4444 [task 2019-01-03T18:55:37.761Z] 18:55:37 INFO - WebDriver HTTP server listening at http://127.0.0.1:4444/
Here the relevant log lines for the failure: [task 2019-01-03T18:53:48.688Z] 18:53:48 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/minimize_window/user_prompts.py::test_accept[capabilities0-prompt-] [task 2019-01-03T18:53:48.689Z] 18:53:48 INFO - PID 30263 | 1546541628638 webdriver::server DEBUG -> POST /session/5a345abb-f4b1-4ba8-bb86-8f3cabd014e4/window/rect {"width": 800, "height": 600} [task 2019-01-03T18:53:48.691Z] 18:53:48 INFO - PID 30263 | 1546541628639 Marionette DEBUG 0 -> [0,102,"WebDriver:SetWindowRect",{"height":600,"width":800}] [task 2019-01-03T18:53:48.692Z] 18:53:48 INFO - PID 30263 | 1546541628643 Marionette DEBUG 0 <- [1,102,null,{"x":0,"y":0,"width":800,"height":600,"state":"normal"}] [task 2019-01-03T18:53:48.693Z] 18:53:48 INFO - PID 30263 | 1546541628643 webdriver::server DEBUG <- 200 OK {"value":{"x":0,"y":0,"width":800,"height":600}} [task 2019-01-03T18:53:48.693Z] 18:53:48 INFO - PID 30263 | 1546541628645 webdriver::server DEBUG -> POST /session/5a345abb-f4b1-4ba8-bb86-8f3cabd014e4/frame {"id": null} [task 2019-01-03T18:53:48.694Z] 18:53:48 INFO - PID 30263 | 1546541628646 Marionette DEBUG 0 -> [0,103,"WebDriver:SwitchToFrame",{}] [task 2019-01-03T18:53:48.695Z] 18:53:48 INFO - PID 30263 | 1546541628649 Marionette DEBUG 0 <- [1,103,null,{"value":null}] [task 2019-01-03T18:53:48.695Z] 18:53:48 INFO - PID 30263 | 1546541628650 webdriver::server DEBUG <- 200 OK {"value":null} [task 2019-01-03T18:53:48.696Z] 18:53:48 INFO - PID 30263 | 1546541628654 webdriver::server DEBUG -> POST /session/5a345abb-f4b1-4ba8-bb86-8f3cabd014e4/window/rect {"width": 800, "height": 600} [task 2019-01-03T18:53:48.697Z] 18:53:48 INFO - PID 30263 | 1546541628655 Marionette DEBUG 0 -> [0,104,"WebDriver:SetWindowRect",{"height":600,"width":800}] [task 2019-01-03T18:53:48.697Z] 18:53:48 INFO - PID 30263 | 1546541628658 Marionette DEBUG 0 <- [1,104,null,{"x":0,"y":0,"width":800,"height":600,"state":"normal"}] [task 2019-01-03T18:53:48.698Z] 18:53:48 INFO - PID 30263 | 1546541628658 webdriver::server DEBUG <- 200 OK {"value":{"x":0,"y":0,"width":800,"height":600}} [task 2019-01-03T18:53:48.699Z] 18:53:48 INFO - PID 30263 | 1546541628661 webdriver::server DEBUG -> POST /session/5a345abb-f4b1-4ba8-bb86-8f3cabd014e4/execute/sync {"args": [], "script": "return document.hidden"} [task 2019-01-03T18:53:48.699Z] 18:53:48 INFO - PID 30263 | 1546541628662 Marionette DEBUG 0 -> [0,105,"WebDriver:ExecuteScript",{"args":[],"script":"return document.hidden"}] [task 2019-01-03T18:53:48.700Z] 18:53:48 INFO - PID 30263 | 1546541628666 Marionette DEBUG 0 <- [1,105,null,{"value":true}] [task 2019-01-03T18:53:48.701Z] 18:53:48 INFO - PID 30263 | 1546541628672 webdriver::server DEBUG <- 200 OK {"value":true} [task 2019-01-03T18:53:48.749Z] 18:53:48 INFO - STDOUT: FAILED Even `Set Window Rect` was run twice, and reports the state as normal, the window is still minimized. At least that is returned by the execute script command which uses `document.hidden`. Please note the timing of the above commands. It's all happening under 100ms, which I cannot believe is possible for restoring a window from minimized state. Having a bit more logging output might be helpful, in case we wrongly detect the window state in that command, and actually do not trigger a window restoration.
Depends on: 1510940

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

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