High frequency testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_focus_after_navigation | marionette_driver.errors.NoSuchElementException: Unable to locate element: :focus
Categories
(Testing :: Marionette Client and Harness, defect, P5)
Tracking
(firefox-esr102 unaffected, firefox110 unaffected, firefox111 unaffected, firefox112 fixed)
Tracking | Status | |
---|---|---|
firefox-esr102 | --- | unaffected |
firefox110 | --- | unaffected |
firefox111 | --- | unaffected |
firefox112 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: sefeng)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [retriggered])
Attachments
(1 file)
Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=405781401&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/X0D9Je2-SnClj7hEU94K1A/runs/0/artifacts/public/logs/live_backing.log
INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_focus_after_navigation
[task 2023-02-15T21:12:55.560Z] 21:12:55 INFO - 1676495575560 Marionette DEBUG Accepted connection 543 from 127.0.0.1:50033
[task 2023-02-15T21:12:55.560Z] 21:12:55 INFO - 1676495575560 Marionette DEBUG 543 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-02-15T21:12:55.561Z] 21:12:55 INFO - 1676495575560 Marionette DEBUG Waiting for initial application window
[task 2023-02-15T21:12:55.561Z] 21:12:55 INFO - 1676495575561 RemoteAgent TRACE [535] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=200 waitForExplicitStart=false
[task 2023-02-15T21:12:55.561Z] 21:12:55 INFO - 1676495575561 RemoteAgent TRACE [535] ProgressListener Setting unload timer (200ms)
[task 2023-02-15T21:12:55.561Z] 21:12:55 INFO - 1676495575561 RemoteAgent TRACE [535] Document already finished loading: http://127.0.0.1:49234/test.html
[task 2023-02-15T21:12:55.562Z] 21:12:55 INFO - 1676495575561 RemoteAgent TRACE [535] ProgressListener Stop: has error=false
[task 2023-02-15T21:12:55.562Z] 21:12:55 INFO - 1676495575562 Marionette DEBUG 543 <- [1,1,null,{"sessionId":"070238ff-a849-4afc-9b8a-f75f568d48cf","capabilities":{"browserName":"firefox","browserVersion":"112.0a1","platformName":"mac","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20230215202750","moz:headless":false,"moz:platformVersion":"19.6.0","moz:processID":1107,"moz:profile":"/var/folders/l4/gqq0rv4x3252x7yrx9lgp66r000014/T/tmp3o6i9p6w.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2023-02-15T21:12:55.563Z] 21:12:55 INFO - 1676495575562 Marionette DEBUG 543 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
<...>
INFO - DEBUG: Adding blocker ContentParent: id=12c2d1000 for phase quit-application-granted
[task 2023-02-15T21:12:58.012Z] 21:12:58 INFO - 1676495578012 Marionette DEBUG 1 -> [0,9,"Marionette:GetContext",{}]
[task 2023-02-15T21:12:58.012Z] 21:12:58 INFO - 1676495578012 Marionette DEBUG 1 <- [1,9,null,{"value":"content"}]
[task 2023-02-15T21:12:58.014Z] 21:12:58 INFO - 1676495578013 Marionette DEBUG 1 -> [0,10,"Marionette:SetContext",{"value":"content"}]
[task 2023-02-15T21:12:58.014Z] 21:12:58 INFO - 1676495578014 Marionette DEBUG 1 <- [1,10,null,{"value":null}]
[task 2023-02-15T21:12:58.015Z] 21:12:58 INFO - 1676495578015 Marionette DEBUG 1 -> [0,11,"WebDriver:GetPageSource",{}]
[task 2023-02-15T21:12:58.016Z] 21:12:58 INFO - 1676495578015 Marionette DEBUG 1 <- [1,11,null,{"value":"<html><head></head><body><input autofocus=\"\"></body></html>"}]
[task 2023-02-15T21:12:58.016Z] 21:12:58 INFO - 1676495578016 Marionette DEBUG 1 -> [0,12,"Marionette:SetContext",{"value":"content"}]
[task 2023-02-15T21:12:58.017Z] 21:12:58 INFO - 1676495578016 Marionette DEBUG 1 <- [1,12,null,{"value":null}]
[task 2023-02-15T21:12:58.095Z] 21:12:58 INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_focus_after_navigation | marionette_driver.errors.NoSuchElementException: Unable to locate element: :focus
[task 2023-02-15T21:12:58.095Z] 21:12:58 INFO - stacktrace:
[task 2023-02-15T21:12:58.095Z] 21:12:58 INFO - RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8
[task 2023-02-15T21:12:58.095Z] 21:12:58 INFO - WebDriverError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:180:5
[task 2023-02-15T21:12:58.095Z] 21:12:58 INFO - NoSuchElementError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:392:5
[task 2023-02-15T21:12:58.095Z] 21:12:58 INFO - element.find/</<@chrome://remote/content/marionette/element.sys.mjs:134:16
[task 2023-02-15T21:12:58.095Z] 21:12:58 INFO - Traceback (most recent call last):
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - File "/opt/worker/tasks/task_167649534374099/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 198, in run
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - testMethod()
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - File "/opt/worker/tasks/task_167649534374099/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/decorators.py", line 59, in skip_wrapper
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - return test_item(self, *args, **kwargs)
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - File "/opt/worker/tasks/task_167649534374099/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 320, in test_focus_after_navigation
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - focus_el = self.marionette.find_element(By.CSS_SELECTOR, ":focus")
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - File "/opt/worker/tasks/task_167649534374099/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 1843, in find_element
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - return self._send_message("WebDriver:FindElement", body, key="value")
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - File "/opt/worker/tasks/task_167649534374099/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - return func(*args, **kwargs)
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - File "/opt/worker/tasks/task_167649534374099/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 663, in _send_message
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - self._handle_error(err)
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - File "/opt/worker/tasks/task_167649534374099/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 675, in _handle_error
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - raise errors.lookup(error)(message, stacktrace=stacktrace)
[task 2023-02-15T21:12:58.096Z] 21:12:58 INFO - TEST-INFO took 2458ms
[task 2023-02-15T21:12:58.097Z] 21:12:58 INFO - 1676495578019 Marionette DEBUG 1 -> [0,13,"WebDriver:SetTimeouts",{"script":30000}]
[task 2023-02-15T21:12:58.097Z] 21:12:58 INFO - 1676495578019 Marionette DEBUG 1 <- [1,13,null,{"value":null}]
INFO - 1676495578020 Marionette DEBUG 1 -> [0,14,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2023-02-15T21:12:58.097Z] 21:12:58 INFO - 1676495578020 Marionette DEBUG 1 <- [1,14,null,{"value":null}]
[task 2023-02-15T21:12:58.098Z] 21:12:58 INFO - 1676495578021 Marionette DEBUG 1 -> [0,15,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2023-02-15T21:12:58.098Z] 21:12:58 INFO - 1676495578021 Marionette DEBUG 1 <- [1,15,null,{"value":null}]
[task 2023-02-15T21:12:58.098Z] 21:12:58 INFO - 1676495578023 Marionette DEBUG 1 -> [0,16,"Marionette:GetContext",{}]
[task 2023-02-15T21:12:58.098Z] 21:12:58 INFO - 1676495578023 Marionette DEBUG 1 <- [1,16,null,{"value":"content"}]
[task 2023-02-15T21:12:58.099Z] 21:12:58 INFO - 1676495578024 Marionette DEBUG 1 -> [0,17,"Marionette:SetContext",{"value":"content"}]
[task 2023-02-15T21:12:58.099Z] 21:12:58 INFO - 1676495578024 Marionette DEBUG 1 <- [1,17,null,{"value":null}]
[task 2023-02-15T21:12:58.099Z] 21:12:58 INFO - 1676495578024 Marionette DEBUG 1 -> [0,18,"WebDriver:GetWindowHandles",{}]
[task 2023-02-15T21:12:58.099Z] 21:12:58 INFO - 1676495578024 Marionette DEBUG 1 <- [1,18,null,["328a4df7-e9ac-4ab2-a6a5-5c9ec75e2557","a5a0cea7-4cd5-4f1b-b2b7-f9324047cf81"]]
[task 2023-02-15T21:12:58.100Z] 21:12:58 INFO - 1676495578025 Marionette DEBUG 1 -> [0,19,"Marionette:SetContext",{"value":"content"}]
[task 2023-02-15T21:12:58.100Z] 21:12:58 INFO - 1676495578026 Marionette DEBUG 1 <- [1,19,null,{"value":null}]
[task 2023-02-15T21:12:58.100Z] 21:12:58 INFO - 1676495578026 Marionette DEBUG 1 -> [0,20,"WebDriver:SwitchToWindow",{"handle":"a5a0cea7-4cd5-4f1b-b2b7-f9324047cf81","focus":true}]
[task 2023-02-15T21:12:58.101Z] 21:12:58 INFO - 1676495578027 Marionette DEBUG 1 <- [1,20,null,{"value":null}]
[task 2023-02-15T21:12:58.101Z] 21:12:58 INFO - 1676495578028 Marionette DEBUG 1 -> [0,21,"WebDriver:CloseWindow",{}]
[task 2023-02-15T21:12:58.101Z] 21:12:58 INFO - DEBUG: Adding blocker Interactions.jsm:: store for phase Places Clients shutdown
[task 2023-02-15T21:12:58.101Z] 21:12:58 INFO - 1676495578048 RemoteAgent TRACE Received DOM event TabClose for [object XULElement]
[task 2023-02-15T21:12:58.102Z] 21:12:58 INFO - 1676495578053 Marionette TRACE [12] MarionetteCommands actor destroyed for window id 4294967298
[task 2023-02-15T21:12:58.102Z] 21:12:58 INFO - 1676495578061 Marionette TRACE Received observer notification message-manager-disconnect
[task 2023-02-15T21:12:58.102Z] 21:12:58 INFO - 1676495578062 Marionette TRACE Received observer notification message-manager-disconnect
[task 2023-02-15T21:12:58.102Z] 21:12:58 INFO - 1676495578062 Marionette DEBUG 1 <- [1,21,null,["328a4df7-e9ac-4ab2-a6a5-5c9ec75e2557"]]
[task 2023-02-15T21:12:58.103Z] 21:12:58 INFO - 1676495578081 Marionette DEBUG 1 -> [0,22,"WebDriver:SwitchToWindow",{"handle":"328a4df7-e9ac-4ab2-a6a5-5c9ec75e2557","focus":true}]
[task 2023-02-15T21:12:58.103Z] 21:12:58 INFO - 1676495578081 Marionette DEBUG 1 <- [1,22,null,{"value":null}]
[task 2023-02-15T21:12:58.104Z] 21:12:58 INFO - DEBUG: Adding blocker ContentParent: id=12c2d4700 for phase xpcom-will-shutdown
[task 2023-02-15T21:12:58.104Z] 21:12:58 INFO - DEBUG: Adding blocker ContentParent: id=12c2d4700 for phase profile-before-change
[task 2023-02-15T21:12:58.105Z] 21:12:58 INFO - DEBUG: Adding blocker ContentParent: id=12c2d4700 for phase quit-application-granted
[task 2023-02-15T21:12:58.105Z] 21:12:58 INFO - 1676495578084 Marionette DEBUG 1 -> [0,23,"Marionette:GetContext",{}]
[task 2023-02-15T21:12:58.105Z] 21:12:58 INFO - 1676495578084 Marionette DEBUG 1 <- [1,23,null,{"value":"content"}]
[task 2023-02-15T21:12:58.105Z] 21:12:58 INFO - 1676495578086 Marionette DEBUG 1 -> [0,24,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-02-15T21:12:58.106Z] 21:12:58 INFO - 1676495578086 Marionette DEBUG 1 <- [1,24,null,{"value":null}]
[task 2023-02-15T21:12:58.106Z] 21:12:58 INFO - DEBUG: Adding blocker Transaction (4) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-02-15T21:12:58.106Z] 21:12:58 INFO - 1676495578104 Marionette DEBUG 1 -> [0,25,"WebDriver:GetWindowHandles",{}]
[task 2023-02-15T21:12:58.106Z] 21:12:58 INFO - 1676495578104 Marionette DEBUG 1 <- [1,25,null,["17720d03-9f5b-46d3-97d5-7258e14a7b6f"]]
[task 2023-02-15T21:12:58.107Z] 21:12:58 INFO - DEBUG: Adding blocker protections.sqlite#0: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2023-02-15T21:12:58.113Z] 21:12:58 INFO - DEBUG: Adding blocker TrackingDBService: Shutting down the content blocking database. for phase profile-before-change
[task 2023-02-15T21:12:58.113Z] 21:12:58 INFO - 1676495578111 Marionette DEBUG 1 -> [0,26,"Marionette:SetContext",{"value":"content"}]
[task 2023-02-15T21:12:58.113Z] 21:12:58 INFO - 1676495578111 Marionette DEBUG 1 <- [1,26,null,{"value":null}]
[task 2023-02-15T21:12:58.113Z] 21:12:58 INFO - DEBUG: Completed blocker Transaction (4) for phase content-prefs.sqlite#0: waiting for clients
<...>
Comment 1•2 years ago
|
||
@Sean, this is also a fallout from bug 1444491 as backfills and retriggers indicate
Comment 2•2 years ago
|
||
Set release status flags based on info from the regressing bug 1444491
Assignee | ||
Comment 4•2 years ago
|
||
ah Sorry I cleared my NI in the wrong bug, but I am making a patch for this also
Assignee | ||
Comment 5•2 years ago
|
||
Need to call rAF to ensure autofocus candidates are flushed.
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 9•2 years ago
|
||
Sefeng, given that different tests are failing more or less it might be good to move the patch to another Marionette specific bug.
I also wonder if such a change might require a WebDriver specification change. I'll discuss with James.
Updated•2 years ago
|
Comment 10•2 years ago
|
||
Comment 11•2 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Description
•