Closed Bug 1750334 Opened 2 years ago Closed 2 years ago

Intermittent [tier2] testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestModalDialogs.test_http_auth_dismiss | marionette_driver.errors.TimeoutException: Timed out after 300.0 seconds

Categories

(Testing :: Marionette Client and Harness, defect, P5)

defect

Tracking

(firefox-esr91 unaffected, firefox96 unaffected, firefox97 fixed, firefox98 fixed)

RESOLVED FIXED
98 Branch
Tracking Status
firefox-esr91 --- unaffected
firefox96 --- unaffected
firefox97 --- fixed
firefox98 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=364209767&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Hic-d5n6S6ClGloIQnP8nw/runs/0/artifacts/public/logs/live_backing.log


[task 2022-01-15T06:03:00.308Z] 06:03:00     INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestModalDialogs.test_dont_detect_content_and_tab_modal_type_in_another_tab_for_type_tab
[task 2022-01-15T06:03:00.308Z] 06:03:00     INFO -  1642226580307	Marionette	DEBUG	Closed connection 22
[task 2022-01-15T06:03:00.310Z] 06:03:00     INFO -  1642226580307	Marionette	DEBUG	Accepted connection 23 from 127.0.0.1:43156
[task 2022-01-15T06:03:00.311Z] 06:03:00     INFO -  1642226580308	Marionette	DEBUG	23 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-01-15T06:03:00.312Z] 06:03:00     INFO -  1642226580311	RemoteAgent	TRACE	Initial navigation already completed
[task 2022-01-15T06:03:00.313Z] 06:03:00     INFO -  1642226580312	Marionette	DEBUG	23 <- [1,1,null,{"sessionId":"dd6a9289-32d2-4559-b172-a7f442edf97d","capabilities":{"browserName":"firefox","browserVersion":"98.0a ... 5.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2022-01-15T06:03:00.314Z] 06:03:00     INFO -  1642226580313	Marionette	DEBUG	23 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2022-01-15T06:03:00.315Z] 06:03:00     INFO -  1642226580314	Marionette	DEBUG	23 <- [1,2,null,{"value":null}]
[task 2022-01-15T06:03:00.315Z] 06:03:00     INFO -  1642226580314	Marionette	DEBUG	23 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2022-01-15T06:03:00.316Z] 06:03:00     INFO -  1642226580315	Marionette	DEBUG	23 <- [1,3,null,{"value":null}]
[task 2022-01-15T06:03:00.317Z] 06:03:00     INFO -  1642226580316	Marionette	DEBUG	23 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2022-01-15T06:03:00.318Z] 06:03:00     INFO -  1642226580316	Marionette	DEBUG	23 <- [1,4,null,{"value":null}]
[task 2022-01-15T06:03:00.319Z] 06:03:00     INFO -  1642226580317	Marionette	DEBUG	23 -> [0,5,"Marionette:GetContext",{}]
[task 2022-01-15T06:03:00.319Z] 06:03:00     INFO -  1642226580317	Marionette	DEBUG	23 <- [1,5,null,{"value":"content"}]
[task 2022-01-15T06:03:00.320Z] 06:03:00     INFO -  1642226580318	Marionette	DEBUG	23 -> [0,6,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-01-15T06:03:00.320Z] 06:03:00     INFO -  1642226580318	Marionette	DEBUG	23 <- [1,6,null,{"value":null}]
[task 2022-01-15T06:03:00.320Z] 06:03:00     INFO -  1642226580319	Marionette	DEBUG	23 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2022-01-15T06:03:00.321Z] 06:03:00     INFO -  1642226580321	Marionette	DEBUG	23 <- [1,7,null,{"value":"7015101d-5924-4a03-a6ec-c3a71887e26b"}]
[task 2022-01-15T06:03:00.322Z] 06:03:00     INFO -  1642226580322	Marionette	DEBUG	23 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.323Z] 06:03:00     INFO -  1642226580322	Marionette	DEBUG	23 <- [1,8,null,{"value":null}]
[task 2022-01-15T06:03:00.324Z] 06:03:00     INFO -  1642226580323	Marionette	DEBUG	23 -> [0,9,"Marionette:GetContext",{}]
[task 2022-01-15T06:03:00.325Z] 06:03:00     INFO -  1642226580323	Marionette	DEBUG	23 <- [1,9,null,{"value":"content"}]
[task 2022-01-15T06:03:00.326Z] 06:03:00     INFO -  1642226580323	Marionette	DEBUG	23 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-01-15T06:03:00.326Z] 06:03:00     INFO -  1642226580324	Marionette	DEBUG	23 <- [1,10,null,{"value":null}]
[task 2022-01-15T06:03:00.327Z] 06:03:00     INFO -  1642226580326	Marionette	DEBUG	23 -> [0,11,"WebDriver:GetWindowHandles",{}]
[task 2022-01-15T06:03:00.327Z] 06:03:00     INFO -  1642226580327	Marionette	DEBUG	23 <- [1,11,null,["7015101d-5924-4a03-a6ec-c3a71887e26b"]]
[task 2022-01-15T06:03:00.329Z] 06:03:00     INFO -  1642226580328	Marionette	DEBUG	23 -> [0,12,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.329Z] 06:03:00     INFO -  1642226580328	Marionette	DEBUG	23 <- [1,12,null,{"value":null}]
[task 2022-01-15T06:03:00.330Z] 06:03:00     INFO -  1642226580329	Marionette	DEBUG	23 -> [0,13,"Marionette:GetContext",{}]
[task 2022-01-15T06:03:00.331Z] 06:03:00     INFO -  1642226580330	Marionette	DEBUG	23 <- [1,13,null,{"value":"content"}]
[task 2022-01-15T06:03:00.332Z] 06:03:00     INFO -  1642226580330	Marionette	DEBUG	23 -> [0,14,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.332Z] 06:03:00     INFO -  1642226580331	Marionette	DEBUG	23 <- [1,14,null,{"value":null}]
[task 2022-01-15T06:03:00.333Z] 06:03:00     INFO -  1642226580333	Marionette	DEBUG	23 -> [0,15,"WebDriver:GetWindowHandle",{}]
[task 2022-01-15T06:03:00.334Z] 06:03:00     INFO -  1642226580333	Marionette	DEBUG	23 <- [1,15,null,{"value":"c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf"}]
[task 2022-01-15T06:03:00.335Z] 06:03:00     INFO -  1642226580334	Marionette	DEBUG	23 -> [0,16,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.336Z] 06:03:00     INFO -  1642226580334	Marionette	DEBUG	23 <- [1,16,null,{"value":null}]
[task 2022-01-15T06:03:00.336Z] 06:03:00     INFO -  1642226580335	Marionette	DEBUG	23 -> [0,17,"Marionette:GetContext",{}]
[task 2022-01-15T06:03:00.337Z] 06:03:00     INFO -  1642226580336	Marionette	DEBUG	23 <- [1,17,null,{"value":"content"}]
[task 2022-01-15T06:03:00.338Z] 06:03:00     INFO -  1642226580337	Marionette	DEBUG	23 -> [0,18,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.338Z] 06:03:00     INFO -  1642226580337	Marionette	DEBUG	23 <- [1,18,null,{"value":null}]
[task 2022-01-15T06:03:00.339Z] 06:03:00     INFO -  1642226580339	Marionette	DEBUG	23 -> [0,19,"WebDriver:GetWindowHandles",{}]
[task 2022-01-15T06:03:00.340Z] 06:03:00     INFO -  1642226580339	Marionette	DEBUG	23 <- [1,19,null,["c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf"]]
[task 2022-01-15T06:03:00.341Z] 06:03:00     INFO -  1642226580340	Marionette	DEBUG	23 -> [0,20,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.342Z] 06:03:00     INFO -  1642226580341	Marionette	DEBUG	23 <- [1,20,null,{"value":null}]
[task 2022-01-15T06:03:00.342Z] 06:03:00     INFO -  1642226580342	Marionette	DEBUG	23 -> [0,21,"Marionette:GetContext",{}]
[task 2022-01-15T06:03:00.343Z] 06:03:00     INFO -  1642226580342	Marionette	DEBUG	23 <- [1,21,null,{"value":"content"}]
[task 2022-01-15T06:03:00.344Z] 06:03:00     INFO -  1642226580343	Marionette	DEBUG	23 -> [0,22,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.344Z] 06:03:00     INFO -  1642226580344	Marionette	DEBUG	23 <- [1,22,null,{"value":null}]
[task 2022-01-15T06:03:00.345Z] 06:03:00     INFO -  1642226580345	Marionette	DEBUG	23 -> [0,23,"WebDriver:GetWindowHandles",{}]
[task 2022-01-15T06:03:00.346Z] 06:03:00     INFO -  1642226580345	Marionette	DEBUG	23 <- [1,23,null,["c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf"]]
[task 2022-01-15T06:03:00.347Z] 06:03:00     INFO -  1642226580346	Marionette	DEBUG	23 -> [0,24,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.347Z] 06:03:00     INFO -  1642226580346	Marionette	DEBUG	23 <- [1,24,null,{"value":null}]
[task 2022-01-15T06:03:00.348Z] 06:03:00     INFO -  1642226580347	Marionette	DEBUG	23 -> [0,25,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2022-01-15T06:03:00.357Z] 06:03:00     INFO -  1642226580357	Marionette	TRACE	Received DOM event TabOpen for [object XULElement]
[task 2022-01-15T06:03:00.383Z] 06:03:00     INFO -  1642226580382	RemoteAgent	TRACE	Initial navigation already completed
[task 2022-01-15T06:03:00.385Z] 06:03:00     INFO -  1642226580384	Marionette	DEBUG	23 <- [1,25,null,{"handle":"beca7320-86da-43cd-8909-f5e8ebb9c912","type":"tab"}]
[task 2022-01-15T06:03:00.396Z] 06:03:00     INFO -  1642226580396	Marionette	DEBUG	23 -> [0,26,"Marionette:GetContext",{}]
[task 2022-01-15T06:03:00.397Z] 06:03:00     INFO -  1642226580396	Marionette	DEBUG	23 <- [1,26,null,{"value":"content"}]
[task 2022-01-15T06:03:00.399Z] 06:03:00     INFO -  1642226580398	Marionette	DEBUG	23 -> [0,27,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.400Z] 06:03:00     INFO -  1642226580398	Marionette	DEBUG	23 <- [1,27,null,{"value":null}]
[task 2022-01-15T06:03:00.401Z] 06:03:00     INFO -  1642226580401	Marionette	DEBUG	23 -> [0,28,"WebDriver:GetWindowHandles",{}]
[task 2022-01-15T06:03:00.403Z] 06:03:00     INFO -  1642226580402	Marionette	DEBUG	23 <- [1,28,null,["c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf","beca7320-86da-43cd-8909-f5e8ebb9c912"]]
[task 2022-01-15T06:03:00.405Z] 06:03:00     INFO -  1642226580404	Marionette	DEBUG	23 -> [0,29,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.406Z] 06:03:00     INFO -  1642226580405	Marionette	DEBUG	23 <- [1,29,null,{"value":null}]
[task 2022-01-15T06:03:00.408Z] 06:03:00     INFO -  1642226580408	Marionette	DEBUG	23 -> [0,30,"Marionette:GetContext",{}]
[task 2022-01-15T06:03:00.410Z] 06:03:00     INFO -  1642226580408	Marionette	DEBUG	23 <- [1,30,null,{"value":"content"}]
[task 2022-01-15T06:03:00.415Z] 06:03:00     INFO -  1642226580414	Marionette	DEBUG	23 -> [0,31,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.416Z] 06:03:00     INFO -  1642226580415	Marionette	DEBUG	23 <- [1,31,null,{"value":null}]
[task 2022-01-15T06:03:00.417Z] 06:03:00     INFO -  1642226580417	Marionette	DEBUG	23 -> [0,32,"WebDriver:GetWindowHandles",{}]
[task 2022-01-15T06:03:00.418Z] 06:03:00     INFO -  1642226580417	Marionette	DEBUG	23 <- [1,32,null,["c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf","beca7320-86da-43cd-8909-f5e8ebb9c912"]]
[task 2022-01-15T06:03:00.420Z] 06:03:00     INFO -  1642226580419	Marionette	DEBUG	23 -> [0,33,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.420Z] 06:03:00     INFO -  1642226580419	Marionette	DEBUG	23 <- [1,33,null,{"value":null}]
[task 2022-01-15T06:03:00.422Z] 06:03:00     INFO -  1642226580422	Marionette	DEBUG	23 -> [0,34,"WebDriver:SwitchToWindow",{"handle":"beca7320-86da-43cd-8909-f5e8ebb9c912","focus":true}]
[task 2022-01-15T06:03:00.430Z] 06:03:00     INFO -  1642226580429	Marionette	TRACE	Received DOM event TabSelect for [object XULElement]
[task 2022-01-15T06:03:00.437Z] 06:03:00     INFO -  1642226580436	Marionette	DEBUG	23 <- [1,34,null,{"value":null}]
[task 2022-01-15T06:03:00.439Z] 06:03:00     INFO -  1642226580438	Marionette	DEBUG	23 -> [0,35,"WebDriver:ExecuteScript",{"script":"return window.browsingContext.id;","args":[],"newSandbox":true,"sandbox":"system","line":52,"filename":"tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py"}]
[task 2022-01-15T06:03:00.440Z] 06:03:00     INFO -  1642226580439	Marionette	TRACE	[87] MarionetteCommands actor created for window id 2147483658
[task 2022-01-15T06:03:00.443Z] 06:03:00     INFO -  1642226580441	Marionette	DEBUG	23 <- [1,35,null,{"value":87}]
[task 2022-01-15T06:03:00.448Z] 06:03:00     INFO -  1642226580447	Marionette	DEBUG	23 -> [0,36,"Marionette:GetContext",{}]
[task 2022-01-15T06:03:00.449Z] 06:03:00     INFO -  1642226580447	Marionette	DEBUG	23 <- [1,36,null,{"value":"content"}]
[task 2022-01-15T06:03:00.449Z] 06:03:00     INFO -  1642226580448	Marionette	DEBUG	23 -> [0,37,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-01-15T06:03:00.449Z] 06:03:00     INFO -  1642226580448	Marionette	DEBUG	23 <- [1,37,null,{"value":null}]
[task 2022-01-15T06:03:00.451Z] 06:03:00     INFO -  1642226580450	Marionette	DEBUG	23 -> [0,38,"WebDriver:ExecuteScript",{"script":"const { Services } = ChromeUtils.import(\"resource://gre/modules/Services.jsm\");\ ... dbox":"default","line":78,"filename":"tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py"}]
[task 2022-01-15T06:03:00.451Z] 06:03:00     INFO -  1642226580451	Marionette	TRACE	[14] MarionetteCommands actor created for window id 2
[task 2022-01-15T06:03:00.453Z] 06:03:00     INFO -  1642226580453	Marionette	DEBUG	23 <- [1,38,null,{"value":null}]
[task 2022-01-15T06:03:00.455Z] 06:03:00     INFO -  1642226580454	Marionette	DEBUG	23 -> [0,39,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:03:00.456Z] 06:03:00     INFO -  1642226580454	Marionette	DEBUG	23 <- [1,39,null,{"value":null}]
[task 2022-01-15T06:03:00.457Z] 06:03:00     INFO -  1642226580456	Marionette	DEBUG	23 -> [0,40,"WebDriver:SwitchToWindow",{"handle":"c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf","focus":true}]
[task 2022-01-15T06:03:00.467Z] 06:03:00     INFO -  1642226580466	Marionette	TRACE	Received DOM event TabSelect for [object XULElement]
[task 2022-01-15T06:03:00.474Z] 06:03:00     INFO -  1642226580473	Marionette	DEBUG	23 <- [1,40,null,{"value":null}]
[task 2022-01-15T06:03:00.479Z] 06:03:00     INFO -  1642226580478	Marionette	DEBUG	23 -> [0,41,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:00.480Z] 06:03:00     INFO -  1642226580479	Marionette	DEBUG	23 <- [1,41,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"},null]
[task 2022-01-15T06:03:00.578Z] 06:03:00     INFO -  1642226580577	Marionette	DEBUG	23 -> [0,42,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:00.579Z] 06:03:00     INFO -  1642226580577	Marionette	DEBUG	23 <- [1,42,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"},null]
[task 2022-01-15T06:03:00.678Z] 06:03:00     INFO -  1642226580677	Marionette	DEBUG	23 -> [0,43,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:00.679Z] 06:03:00     INFO -  1642226580678	Marionette	DEBUG	23 <- [1,43,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"},null]
[task 2022-01-15T06:03:00.756Z] 06:03:00     INFO -  1642226580756	Marionette	TRACE	Received observer notification common-dialog-loaded
[task 2022-01-15T06:03:00.779Z] 06:03:00     INFO -  1642226580778	Marionette	DEBUG	23 -> [0,44,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:00.780Z] 06:03:00     INFO -  1642226580779	Marionette	DEBUG	23 <- [1,44,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:00.878Z] 06:03:00     INFO -  1642226580877	Marionette	DEBUG	23 -> [0,45,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:00.879Z] 06:03:00     INFO -  1642226580878	Marionette	DEBUG	23 <- [1,45,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:00.978Z] 06:03:00     INFO -  1642226580978	Marionette	DEBUG	23 -> [0,46,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:00.980Z] 06:03:00     INFO -  1642226580978	Marionette	DEBUG	23 <- [1,46,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.078Z] 06:03:01     INFO -  1642226581078	Marionette	DEBUG	23 -> [0,47,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.080Z] 06:03:01     INFO -  1642226581078	Marionette	DEBUG	23 <- [1,47,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.179Z] 06:03:01     INFO -  1642226581178	Marionette	DEBUG	23 -> [0,48,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.180Z] 06:03:01     INFO -  1642226581179	Marionette	DEBUG	23 <- [1,48,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.279Z] 06:03:01     INFO -  1642226581278	Marionette	DEBUG	23 -> [0,49,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.284Z] 06:03:01     INFO -  1642226581279	Marionette	DEBUG	23 <- [1,49,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.379Z] 06:03:01     INFO -  1642226581378	Marionette	DEBUG	23 -> [0,50,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.380Z] 06:03:01     INFO -  1642226581378	Marionette	DEBUG	23 <- [1,50,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.479Z] 06:03:01     INFO -  1642226581478	Marionette	DEBUG	23 -> [0,51,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.480Z] 06:03:01     INFO -  1642226581479	Marionette	DEBUG	23 <- [1,51,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.579Z] 06:03:01     INFO -  1642226581579	Marionette	DEBUG	23 -> [0,52,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.581Z] 06:03:01     INFO -  1642226581580	Marionette	DEBUG	23 <- [1,52,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.679Z] 06:03:01     INFO -  1642226581679	Marionette	DEBUG	23 -> [0,53,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.680Z] 06:03:01     INFO -  1642226581679	Marionette	DEBUG	23 <- [1,53,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.779Z] 06:03:01     INFO -  1642226581779	Marionette	DEBUG	23 -> [0,54,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.781Z] 06:03:01     INFO -  1642226581779	Marionette	DEBUG	23 <- [1,54,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.880Z] 06:03:01     INFO -  1642226581879	Marionette	DEBUG	23 -> [0,55,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.881Z] 06:03:01     INFO -  1642226581879	Marionette	DEBUG	23 <- [1,55,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:01.980Z] 06:03:01     INFO -  1642226581979	Marionette	DEBUG	23 -> [0,56,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:01.981Z] 06:03:01     INFO -  1642226581979	Marionette	DEBUG	23 <- [1,56,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:02.080Z] 06:03:02     INFO -  1642226582079	Marionette	DEBUG	23 -> [0,57,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:02.081Z] 06:03:02     INFO -  1642226582080	Marionette	DEBUG	23 <- [1,57,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:02.180Z] 06:03:02     INFO -  1642226582179	Marionette	DEBUG	23 -> [0,58,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:02.181Z] 06:03:02     INFO -  1642226582180	Marionette	DEBUG	23 <- [1,58,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:02.280Z] 06:03:02     INFO -  1642226582279	Marionette	DEBUG	23 -> [0,59,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:02.281Z] 06:03:02     INFO -  1642226582280	Marionette	DEBUG	23 <- [1,59,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:02.380Z] 06:03:02     INFO -  1642226582380	Marionette	DEBUG	23 -> [0,60,"WebDriver:GetAlertText",{}]
[task 2022-01-15T06:03:02.381Z] 06:03:02     INFO -  1642226582380	Marionette	DEBUG	23 <- [1,60,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm: ... ules/Prompter.jsm:94:7\n@tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py:91:35\n"},null]
[task 2022-01-15T06:03:02.481Z] 06:03:02     INFO -  1642226582480	Marionette	DEBUG	23 -> [0,61,"WebDriver:SwitchToWindow",{"handle":"beca7320-86da-43cd-8909-f5e8ebb9c912","focus":true}]
[task 2022-01-15T06:03:02.482Z] 06:03:02     INFO -  1642226582480	Marionette	TRACE	Found open tab modal prompt
[....]
[task 2022-01-15T06:08:02.860Z] 06:08:02     INFO -  1642226882855	Marionette	DEBUG	24 <- [1,3044,null,{"value":null}]
[task 2022-01-15T06:08:02.863Z] 06:08:02     INFO -  1642226882856	Marionette	DEBUG	24 -> [0,3045,"Marionette:GetContext",{}]
[task 2022-01-15T06:08:02.866Z] 06:08:02     INFO -  1642226882857	Marionette	DEBUG	24 <- [1,3045,null,{"value":"content"}]
[task 2022-01-15T06:08:02.869Z] 06:08:02     INFO -  1642226882857	Marionette	DEBUG	24 -> [0,3046,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-01-15T06:08:02.872Z] 06:08:02     INFO -  1642226882857	Marionette	DEBUG	24 <- [1,3046,null,{"value":null}]
[task 2022-01-15T06:08:02.872Z] 06:08:02     INFO -  1642226882858	Marionette	DEBUG	24 -> [0,3047,"WebDriver:TakeScreenshot",{"id":null,"full":true,"hash":false,"scroll":true}]
[task 2022-01-15T06:08:02.896Z] 06:08:02     INFO -  1642226882895	Marionette	DEBUG	24 <- [1,3047,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAQQCAYAAAC9RfbYAAAgAElEQVR4XuzdCdBsZ1kn8HNDFrLdpNRQAQIpUpiaQBIpF2AALTQKKi ... YTIECAAAECBAgQIECAAAECBAiMBATA0dmmEiBAgAABAgQIECBAgAABAgQI/AQEwN/nFhMgQIAAAQIECBAgQIAAAQIECIwEAs7zg2C1miERAAAAAElFTkSuQmCC"}]
[task 2022-01-15T06:08:02.934Z] 06:08:02     INFO -  1642226882933	Marionette	DEBUG	24 -> [0,3048,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:08:02.935Z] 06:08:02     INFO -  1642226882933	Marionette	DEBUG	24 <- [1,3048,null,{"value":null}]
[task 2022-01-15T06:08:02.938Z] 06:08:02     INFO -  1642226882934	Marionette	DEBUG	24 -> [0,3049,"Marionette:GetContext",{}]
[task 2022-01-15T06:08:02.939Z] 06:08:02     INFO -  1642226882934	Marionette	DEBUG	24 <- [1,3049,null,{"value":"content"}]
[task 2022-01-15T06:08:02.941Z] 06:08:02     INFO -  1642226882935	Marionette	DEBUG	24 -> [0,3050,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:08:02.943Z] 06:08:02     INFO -  1642226882935	Marionette	DEBUG	24 <- [1,3050,null,{"value":null}]
[task 2022-01-15T06:08:02.946Z] 06:08:02     INFO -  1642226882936	Marionette	DEBUG	24 -> [0,3051,"WebDriver:GetPageSource",{}]
[task 2022-01-15T06:08:02.948Z] 06:08:02     INFO -  1642226882943	Marionette	TRACE	[94] MarionetteCommands actor created for window id 8589934595
[task 2022-01-15T06:08:02.951Z] 06:08:02     INFO -  1642226882945	Marionette	DEBUG	24 <- [1,3051,null,{"value":"<html><head><title>HTTP Authentication</title>\n</head><body><p id=\"status\">restricted</p></body></html>"}]
[task 2022-01-15T06:08:02.952Z] 06:08:02     INFO -  1642226882947	Marionette	DEBUG	24 -> [0,3052,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:08:02.954Z] 06:08:02     INFO -  1642226882948	Marionette	DEBUG	24 <- [1,3052,null,{"value":null}]
[task 2022-01-15T06:08:03.019Z] 06:08:03     INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestModalDialogs.test_http_auth_dismiss | marionette_driver.errors.TimeoutException: Timed out after 300.0 seconds
[task 2022-01-15T06:08:03.020Z] 06:08:03     INFO - Traceback (most recent call last):
[task 2022-01-15T06:08:03.020Z] 06:08:03     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_harness/marionette_test/testcases.py", line 202, in run
[task 2022-01-15T06:08:03.021Z] 06:08:03     INFO -     testMethod()
[task 2022-01-15T06:08:03.021Z] 06:08:03     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py", line 148, in test_http_auth_dismiss
[task 2022-01-15T06:08:03.021Z] 06:08:03     INFO -     self.wait_for_alert(timeout=self.marionette.timeout.page_load)
[task 2022-01-15T06:08:03.021Z] 06:08:03     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py", line 45, in wait_for_alert
[task 2022-01-15T06:08:03.021Z] 06:08:03     INFO -     Wait(self.marionette, timeout=timeout).until(lambda _: self.alert_present)
[task 2022-01-15T06:08:03.021Z] 06:08:03     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/wait.py", line 161, in until
[task 2022-01-15T06:08:03.021Z] 06:08:03     INFO -     cause=last_exc,
[task 2022-01-15T06:08:03.021Z] 06:08:03     INFO - TEST-INFO took 300390ms
[task 2022-01-15T06:08:03.021Z] 06:08:03     INFO -  1642226882956	Marionette	DEBUG	24 -> [0,3053,"WebDriver:DismissAlert",{}]
[task 2022-01-15T06:08:03.022Z] 06:08:03     INFO -  1642226882956	Marionette	DEBUG	24 <- [1,3053,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.js ... ote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"},null]
[task 2022-01-15T06:08:03.023Z] 06:08:03     INFO -  1642226882957	Marionette	DEBUG	24 -> [0,3054,"Marionette:GetContext",{}]
[task 2022-01-15T06:08:03.023Z] 06:08:03     INFO -  1642226882957	Marionette	DEBUG	24 <- [1,3054,null,{"value":"content"}]
[task 2022-01-15T06:08:03.024Z] 06:08:03     INFO -  1642226882958	Marionette	DEBUG	24 -> [0,3055,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:08:03.025Z] 06:08:03     INFO -  1642226882958	Marionette	DEBUG	24 <- [1,3055,null,{"value":null}]
[task 2022-01-15T06:08:03.025Z] 06:08:03     INFO -  1642226882958	Marionette	DEBUG	24 -> [0,3056,"WebDriver:GetWindowHandles",{}]
[task 2022-01-15T06:08:03.026Z] 06:08:03     INFO -  1642226882958	Marionette	DEBUG	24 <- [1,3056,null,["c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf","4eac5ee0-432a-45ea-aeb6-53ed869f4d71"]]
[task 2022-01-15T06:08:03.026Z] 06:08:03     INFO -  1642226882959	Marionette	DEBUG	24 -> [0,3057,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:08:03.027Z] 06:08:03     INFO -  1642226882959	Marionette	DEBUG	24 <- [1,3057,null,{"value":null}]
[task 2022-01-15T06:08:03.027Z] 06:08:03     INFO -  1642226882960	Marionette	DEBUG	24 -> [0,3058,"WebDriver:SwitchToWindow",{"handle":"4eac5ee0-432a-45ea-aeb6-53ed869f4d71","focus":true}]
[task 2022-01-15T06:08:03.028Z] 06:08:03     INFO -  1642226882962	Marionette	DEBUG	24 <- [1,3058,null,{"value":null}]
[task 2022-01-15T06:08:03.028Z] 06:08:03     INFO -  1642226882962	Marionette	DEBUG	24 -> [0,3059,"WebDriver:CloseWindow",{}]
[task 2022-01-15T06:08:03.028Z] 06:08:03     INFO -  1642226882974	Marionette	TRACE	Received DOM event TabClose for [object XULElement]
[task 2022-01-15T06:08:03.029Z] 06:08:03     INFO -  1642226882988	Marionette	TRACE	Received observer notification message-manager-disconnect
[task 2022-01-15T06:08:03.030Z] 06:08:03     INFO -  1642226882989	Marionette	DEBUG	24 <- [1,3059,null,["c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf"]]
[task 2022-01-15T06:08:03.030Z] 06:08:03     INFO -  1642226882996	Marionette	DEBUG	24 -> [0,3060,"WebDriver:SwitchToWindow",{"handle":"c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf","focus":true}]
[task 2022-01-15T06:08:03.031Z] 06:08:03     INFO -  1642226882998	Marionette	DEBUG	24 <- [1,3060,null,{"value":null}]
[task 2022-01-15T06:08:03.032Z] 06:08:03     INFO -  1642226882999	Marionette	DEBUG	24 -> [0,3061,"Marionette:GetContext",{}]
[task 2022-01-15T06:08:03.032Z] 06:08:03     INFO -  1642226883000	Marionette	DEBUG	24 <- [1,3061,null,{"value":"content"}]
[task 2022-01-15T06:08:03.033Z] 06:08:03     INFO -  1642226883001	Marionette	DEBUG	24 -> [0,3062,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-01-15T06:08:03.034Z] 06:08:03     INFO -  1642226883001	Marionette	DEBUG	24 <- [1,3062,null,{"value":null}]
[task 2022-01-15T06:08:03.034Z] 06:08:03     INFO -  1642226883002	Marionette	DEBUG	24 -> [0,3063,"WebDriver:GetWindowHandles",{}]
[task 2022-01-15T06:08:03.035Z] 06:08:03     INFO -  1642226883002	Marionette	DEBUG	24 <- [1,3063,null,["7015101d-5924-4a03-a6ec-c3a71887e26b"]]
[task 2022-01-15T06:08:03.035Z] 06:08:03     INFO -  1642226883004	Marionette	DEBUG	24 -> [0,3064,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:08:03.036Z] 06:08:03     INFO -  1642226883005	Marionette	DEBUG	24 <- [1,3064,null,{"value":null}]
[task 2022-01-15T06:08:03.037Z] 06:08:03     INFO -  1642226883005	Marionette	DEBUG	24 -> [0,3065,"WebDriver:SwitchToWindow",{"handle":"7015101d-5924-4a03-a6ec-c3a71887e26b","focus":true}]
[task 2022-01-15T06:08:03.037Z] 06:08:03     INFO -  1642226883006	Marionette	DEBUG	24 <- [1,3065,null,{"value":null}]
[task 2022-01-15T06:08:03.038Z] 06:08:03     INFO -  1642226883006	Marionette	DEBUG	24 -> [0,3066,"Marionette:GetContext",{}]
[task 2022-01-15T06:08:03.038Z] 06:08:03     INFO -  1642226883006	Marionette	DEBUG	24 <- [1,3066,null,{"value":"content"}]
[task 2022-01-15T06:08:03.039Z] 06:08:03     INFO -  1642226883007	Marionette	DEBUG	24 -> [0,3067,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-01-15T06:08:03.040Z] 06:08:03     INFO -  1642226883007	Marionette	DEBUG	24 <- [1,3067,null,{"value":null}]
[task 2022-01-15T06:08:03.040Z] 06:08:03     INFO -  1642226883007	Marionette	DEBUG	24 -> [0,3068,"WebDriver:GetWindowHandles",{}]
[task 2022-01-15T06:08:03.041Z] 06:08:03     INFO -  1642226883008	Marionette	DEBUG	24 <- [1,3068,null,["7015101d-5924-4a03-a6ec-c3a71887e26b"]]
[task 2022-01-15T06:08:03.041Z] 06:08:03     INFO -  1642226883009	Marionette	DEBUG	24 -> [0,3069,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:08:03.042Z] 06:08:03     INFO -  1642226883009	Marionette	DEBUG	24 <- [1,3069,null,{"value":null}]
[task 2022-01-15T06:08:03.043Z] 06:08:03     INFO -  1642226883010	Marionette	DEBUG	24 -> [0,3070,"Marionette:GetContext",{}]
[task 2022-01-15T06:08:03.043Z] 06:08:03     INFO -  1642226883010	Marionette	DEBUG	24 <- [1,3070,null,{"value":"content"}]
[task 2022-01-15T06:08:03.044Z] 06:08:03     INFO -  1642226883011	Marionette	DEBUG	24 -> [0,3071,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:08:03.044Z] 06:08:03     INFO -  1642226883011	Marionette	DEBUG	24 <- [1,3071,null,{"value":null}]
[task 2022-01-15T06:08:03.045Z] 06:08:03     INFO -  1642226883011	Marionette	DEBUG	24 -> [0,3072,"WebDriver:GetWindowHandles",{}]
[task 2022-01-15T06:08:03.045Z] 06:08:03     INFO -  1642226883012	Marionette	DEBUG	24 <- [1,3072,null,["c7c8365d-9e9c-4db2-b87d-c9b6f25c4acf"]]
[task 2022-01-15T06:08:03.046Z] 06:08:03     INFO -  1642226883012	Marionette	DEBUG	24 -> [0,3073,"Marionette:SetContext",{"value":"content"}]
[task 2022-01-15T06:08:03.047Z] 06:08:03     INFO -  1642226883012	Marionette	DEBUG	24 <- [1,3073,null,{"value":null}]
[task 2022-01-15T06:08:03.047Z] 06:08:03     INFO -  1642226883013	Marionette	DEBUG	24 -> [0,3074,"WebDriver:DeleteSession",{}]
[task 2022-01-15T06:08:03.048Z] 06:08:03     INFO -  1642226883015	Marionette	DEBUG	24 <- [1,3074,null,{"value":null}]

There is some hiccup with loading the page where the alert is even closing again:

https://treeherder.mozilla.org/logviewer?job_id=364209767&repo=autoland&lineNumber=64900-64910

[task 2022-01-15T06:03:02.736Z] 06:03:02     INFO -  1642226582694	Marionette	DEBUG	24 -> [0,43,"WebDriver:Navigate",{"url":"http://127.0.0.1:45602/http_auth"}]
[task 2022-01-15T06:03:02.736Z] 06:03:02     INFO -  1642226582723	Marionette	WARN	Ignoring event 'DOMContentLoaded' because document has an invalid readyState of 'complete'.
[task 2022-01-15T06:03:02.748Z] 06:03:02     INFO -  1642226582747	Marionette	TRACE	[94] Received event beforeunload for about:blank
[task 2022-01-15T06:03:02.753Z] 06:03:02     INFO -  1642226582752	Marionette	TRACE	Received event DOMModalDialogClosed
[task 2022-01-15T06:03:02.767Z] 06:03:02     INFO -  1642226582765	Marionette	TRACE	Remoteness change detected. Set new top-level browsing context to 94
[task 2022-01-15T06:03:02.777Z] 06:03:02     INFO -  1642226582775	Marionette	TRACE	[94] Received event pagehide for about:blank
[task 2022-01-15T06:03:02.780Z] 06:03:02     INFO -  1642226582779	Marionette	TRACE	[94] Received event beforeunload for about:blank
[task 2022-01-15T06:03:02.788Z] 06:03:02     INFO -  1642226582787	Marionette	TRACE	[94] Received event pagehide for about:blank
[task 2022-01-15T06:03:02.815Z] 06:03:02     INFO -  1642226582814	Marionette	TRACE	[94] Received event DOMContentLoaded for http://127.0.0.1:45602/http_auth
[task 2022-01-15T06:03:02.818Z] 06:03:02     INFO -  1642226582817	Marionette	TRACE	[94] Received event pageshow for http://127.0.0.1:45602/http_auth
[task 2022-01-15T06:03:02.821Z] 06:03:02     INFO -  1642226582821	Marionette	DEBUG	24 <- [1,43,null,{"value":null}]

I'm hoping that bug 1747359 will fix this problem.

Depends on: 1747359
Assignee: nobody → hskupin
Status: NEW → RESOLVED
Closed: 2 years ago
Keywords: regression
Regressed by: 1739369
Resolution: --- → FIXED
Target Milestone: --- → 98 Branch

Set release status flags based on info from the regressing bug 1739369

Has Regression Range: --- → yes
Product: Testing → Remote Protocol
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Component: Marionette → Marionette Client and Harness
Product: Remote Protocol → Testing
You need to log in before you can comment on or make changes to this bug.