Intermittent Mn | after FATAL ERROR: Non-local network connections [...] aus5.mozilla.org (35.244.181.201) was made.
Categories
(Remote Protocol :: Agent, defect, P5)
Tracking
(firefox-esr91 unaffected, firefox97 unaffected, firefox98 unaffected, firefox99 wontfix, firefox100 wontfix, firefox101 wontfix, firefox114 wontfix, firefox115 wontfix, firefox116 affected)
Tracking | Status | |
---|---|---|
firefox-esr91 | --- | unaffected |
firefox97 | --- | unaffected |
firefox98 | --- | unaffected |
firefox99 | --- | wontfix |
firefox100 | --- | wontfix |
firefox101 | --- | wontfix |
firefox114 | --- | wontfix |
firefox115 | --- | wontfix |
firefox116 | --- | affected |
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Regression)
Details
(Keywords: intermittent-failure, regression)
Crash Data
Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=367187599&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/S62OcnP4T1yDzCm4KyhTKw/runs/0/artifacts/public/logs/live_backing.log
[task 2022-02-09T05:07:37.146Z] 05:07:37 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_chrome.py TestSwitchToWindowContent.test_switch_to_unloaded_tab
[task 2022-02-09T05:07:37.147Z] 05:07:37 INFO - 1644383257146 Marionette DEBUG Closed connection 18
[task 2022-02-09T05:07:37.148Z] 05:07:37 INFO - 1644383257147 Marionette DEBUG Accepted connection 19 from 127.0.0.1:57148
[task 2022-02-09T05:07:37.149Z] 05:07:37 INFO - 1644383257149 Marionette DEBUG 19 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-02-09T05:07:37.153Z] 05:07:37 INFO - 1644383257152 RemoteAgent TRACE [18] Document already finished loading: http://127.0.0.1:35807/test_iframe.html
[task 2022-02-09T05:07:37.154Z] 05:07:37 INFO - 1644383257153 Marionette DEBUG 19 <- [1,1,null,{"sessionId":"00d5d358-1530-4f73-9358-537b5df36aae","capabilities":{"browserName":"firefox","browserVersion":"99.0a ... .mozrunner","moz:shutdownTimeout":300000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2022-02-09T05:07:37.155Z] 05:07:37 INFO - 1644383257155 Marionette DEBUG 19 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2022-02-09T05:07:37.156Z] 05:07:37 INFO - 1644383257155 Marionette DEBUG 19 <- [1,2,null,{"value":null}]
[task 2022-02-09T05:07:37.157Z] 05:07:37 INFO - 1644383257157 Marionette DEBUG 19 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2022-02-09T05:07:37.158Z] 05:07:37 INFO - 1644383257157 Marionette DEBUG 19 <- [1,3,null,{"value":null}]
[task 2022-02-09T05:07:37.159Z] 05:07:37 INFO - 1644383257159 Marionette DEBUG 19 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2022-02-09T05:07:37.160Z] 05:07:37 INFO - 1644383257159 Marionette DEBUG 19 <- [1,4,null,{"value":null}]
[task 2022-02-09T05:07:37.161Z] 05:07:37 INFO - 1644383257161 Marionette DEBUG 19 -> [0,5,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.162Z] 05:07:37 INFO - 1644383257161 Marionette DEBUG 19 <- [1,5,null,{"value":"content"}]
[task 2022-02-09T05:07:37.163Z] 05:07:37 INFO - 1644383257163 Marionette DEBUG 19 -> [0,6,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-02-09T05:07:37.164Z] 05:07:37 INFO - 1644383257163 Marionette DEBUG 19 <- [1,6,null,{"value":null}]
[task 2022-02-09T05:07:37.165Z] 05:07:37 INFO - 1644383257165 Marionette DEBUG 19 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2022-02-09T05:07:37.166Z] 05:07:37 INFO - 1644383257165 Marionette DEBUG 19 <- [1,7,null,{"value":"a2f09c1b-25b8-47f5-8e94-1eef113ca4aa"}]
[task 2022-02-09T05:07:37.167Z] 05:07:37 INFO - 1644383257166 Marionette DEBUG 19 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.168Z] 05:07:37 INFO - 1644383257167 Marionette DEBUG 19 <- [1,8,null,{"value":null}]
[task 2022-02-09T05:07:37.169Z] 05:07:37 INFO - 1644383257169 Marionette DEBUG 19 -> [0,9,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.170Z] 05:07:37 INFO - 1644383257169 Marionette DEBUG 19 <- [1,9,null,{"value":"content"}]
[task 2022-02-09T05:07:37.172Z] 05:07:37 INFO - 1644383257171 Marionette DEBUG 19 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-02-09T05:07:37.172Z] 05:07:37 INFO - 1644383257172 Marionette DEBUG 19 <- [1,10,null,{"value":null}]
[task 2022-02-09T05:07:37.174Z] 05:07:37 INFO - 1644383257173 Marionette DEBUG 19 -> [0,11,"WebDriver:GetWindowHandles",{}]
[task 2022-02-09T05:07:37.175Z] 05:07:37 INFO - 1644383257174 Marionette DEBUG 19 <- [1,11,null,["a2f09c1b-25b8-47f5-8e94-1eef113ca4aa"]]
[task 2022-02-09T05:07:37.176Z] 05:07:37 INFO - 1644383257176 Marionette DEBUG 19 -> [0,12,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.177Z] 05:07:37 INFO - 1644383257176 Marionette DEBUG 19 <- [1,12,null,{"value":null}]
[task 2022-02-09T05:07:37.178Z] 05:07:37 INFO - 1644383257177 Marionette DEBUG 19 -> [0,13,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.179Z] 05:07:37 INFO - 1644383257178 Marionette DEBUG 19 <- [1,13,null,{"value":"content"}]
[task 2022-02-09T05:07:37.180Z] 05:07:37 INFO - 1644383257179 Marionette DEBUG 19 -> [0,14,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.181Z] 05:07:37 INFO - 1644383257180 Marionette DEBUG 19 <- [1,14,null,{"value":null}]
[task 2022-02-09T05:07:37.182Z] 05:07:37 INFO - 1644383257182 Marionette DEBUG 19 -> [0,15,"WebDriver:GetWindowHandle",{}]
[task 2022-02-09T05:07:37.184Z] 05:07:37 INFO - 1644383257183 Marionette DEBUG 19 <- [1,15,null,{"value":"d1cfb9b3-2465-43b0-9f20-ee9455ceb03c"}]
[task 2022-02-09T05:07:37.185Z] 05:07:37 INFO - 1644383257184 Marionette DEBUG 19 -> [0,16,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.185Z] 05:07:37 INFO - 1644383257185 Marionette DEBUG 19 <- [1,16,null,{"value":null}]
[task 2022-02-09T05:07:37.187Z] 05:07:37 INFO - 1644383257186 Marionette DEBUG 19 -> [0,17,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.188Z] 05:07:37 INFO - 1644383257186 Marionette DEBUG 19 <- [1,17,null,{"value":"content"}]
[task 2022-02-09T05:07:37.189Z] 05:07:37 INFO - 1644383257189 Marionette DEBUG 19 -> [0,18,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.190Z] 05:07:37 INFO - 1644383257189 Marionette DEBUG 19 <- [1,18,null,{"value":null}]
[task 2022-02-09T05:07:37.191Z] 05:07:37 INFO - 1644383257191 Marionette DEBUG 19 -> [0,19,"WebDriver:GetWindowHandles",{}]
[task 2022-02-09T05:07:37.192Z] 05:07:37 INFO - 1644383257192 Marionette DEBUG 19 <- [1,19,null,["d1cfb9b3-2465-43b0-9f20-ee9455ceb03c"]]
[task 2022-02-09T05:07:37.193Z] 05:07:37 INFO - 1644383257193 Marionette DEBUG 19 -> [0,20,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.194Z] 05:07:37 INFO - 1644383257194 Marionette DEBUG 19 <- [1,20,null,{"value":null}]
[task 2022-02-09T05:07:37.195Z] 05:07:37 INFO - 1644383257195 Marionette DEBUG 19 -> [0,21,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.196Z] 05:07:37 INFO - 1644383257195 Marionette DEBUG 19 <- [1,21,null,{"value":"content"}]
[task 2022-02-09T05:07:37.197Z] 05:07:37 INFO - 1644383257197 Marionette DEBUG 19 -> [0,22,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-02-09T05:07:37.198Z] 05:07:37 INFO - 1644383257197 Marionette DEBUG 19 <- [1,22,null,{"value":null}]
[task 2022-02-09T05:07:37.200Z] 05:07:37 INFO - 1644383257199 Marionette DEBUG 19 -> [0,23,"WebDriver:ExecuteScript",{"script":"Components.utils.import(\"resource://gre/modules/AppConstants.jsm\");\n\n ... efault","line":76,"filename":"tests/testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_content.py"}]
[task 2022-02-09T05:07:37.201Z] 05:07:37 INFO - 1644383257201 Marionette TRACE [1] MarionetteCommands actor created for window id 2
[task 2022-02-09T05:07:37.205Z] 05:07:37 INFO - 1644383257205 Marionette DEBUG 19 <- [1,23,null,{"value":0}]
[task 2022-02-09T05:07:37.207Z] 05:07:37 INFO - 1644383257207 Marionette DEBUG 19 -> [0,24,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.208Z] 05:07:37 INFO - 1644383257207 Marionette DEBUG 19 <- [1,24,null,{"value":null}]
[task 2022-02-09T05:07:37.209Z] 05:07:37 INFO - 1644383257209 Marionette DEBUG 19 -> [0,25,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.210Z] 05:07:37 INFO - 1644383257210 Marionette DEBUG 19 <- [1,25,null,{"value":"content"}]
[task 2022-02-09T05:07:37.248Z] 05:07:37 INFO - 1644383257247 Marionette DEBUG 19 -> [0,26,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.249Z] 05:07:37 INFO - 1644383257247 Marionette DEBUG 19 <- [1,26,null,{"value":null}]
[task 2022-02-09T05:07:37.251Z] 05:07:37 INFO - 1644383257251 Marionette DEBUG 19 -> [0,27,"WebDriver:GetWindowHandles",{}]
[task 2022-02-09T05:07:37.252Z] 05:07:37 INFO - 1644383257252 Marionette DEBUG 19 <- [1,27,null,["d1cfb9b3-2465-43b0-9f20-ee9455ceb03c"]]
[task 2022-02-09T05:07:37.256Z] 05:07:37 INFO - 1644383257255 Marionette DEBUG 19 -> [0,28,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.256Z] 05:07:37 INFO - 1644383257256 Marionette DEBUG 19 <- [1,28,null,{"value":null}]
[task 2022-02-09T05:07:37.259Z] 05:07:37 INFO - 1644383257259 Marionette DEBUG 19 -> [0,29,"WebDriver:Navigate",{"url":"data:text/html;charset=utf-8,%3Cp%3Efoo"}]
[task 2022-02-09T05:07:37.267Z] 05:07:37 INFO - 1644383257267 Marionette TRACE [18] Received event beforeunload for http://127.0.0.1:35807/test_iframe.html
[task 2022-02-09T05:07:37.382Z] 05:07:37 INFO - 1644383257381 Marionette TRACE [18] Received event pagehide for http://127.0.0.1:35807/test_iframe.html
[task 2022-02-09T05:07:37.422Z] 05:07:37 INFO - DEBUG: Adding blocker Transaction (3) for phase content-prefs.sqlite#0: waiting for clients
[task 2022-02-09T05:07:37.441Z] 05:07:37 INFO - 1644383257441 Marionette TRACE [18] Received event DOMContentLoaded for data:text/html;charset=utf-8,%3Cp%3Efoo
[task 2022-02-09T05:07:37.449Z] 05:07:37 INFO - 1644383257448 Marionette TRACE [18] Received event pageshow for data:text/html;charset=utf-8,%3Cp%3Efoo
[task 2022-02-09T05:07:37.452Z] 05:07:37 INFO - 1644383257452 Marionette DEBUG 19 <- [1,29,null,{"value":null}]
[task 2022-02-09T05:07:37.477Z] 05:07:37 INFO - DEBUG: Completed blocker Transaction (3) for phase content-prefs.sqlite#0: waiting for clients
[task 2022-02-09T05:07:37.498Z] 05:07:37 INFO - 1644383257497 Marionette DEBUG 19 -> [0,30,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.500Z] 05:07:37 INFO - 1644383257500 Marionette DEBUG 19 <- [1,30,null,{"value":"content"}]
[task 2022-02-09T05:07:37.508Z] 05:07:37 INFO - 1644383257507 Marionette DEBUG 19 -> [0,31,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.509Z] 05:07:37 INFO - 1644383257509 Marionette DEBUG 19 <- [1,31,null,{"value":null}]
[task 2022-02-09T05:07:37.511Z] 05:07:37 INFO - 1644383257511 Marionette DEBUG 19 -> [0,32,"WebDriver:GetWindowHandles",{}]
[task 2022-02-09T05:07:37.513Z] 05:07:37 INFO - 1644383257512 Marionette DEBUG 19 <- [1,32,null,["d1cfb9b3-2465-43b0-9f20-ee9455ceb03c"]]
[task 2022-02-09T05:07:37.551Z] 05:07:37 INFO - 1644383257550 Marionette DEBUG 19 -> [0,33,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.552Z] 05:07:37 INFO - 1644383257550 Marionette DEBUG 19 <- [1,33,null,{"value":null}]
[task 2022-02-09T05:07:37.569Z] 05:07:37 INFO - 1644383257569 Marionette DEBUG 19 -> [0,34,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2022-02-09T05:07:37.587Z] 05:07:37 INFO - 1644383257586 Marionette TRACE Received DOM event TabOpen for [object XULElement]
[task 2022-02-09T05:07:37.698Z] 05:07:37 INFO - 1644383257697 RemoteAgent TRACE [60] ProgressListener state=start: about:blank
[task 2022-02-09T05:07:37.800Z] 05:07:37 INFO - 1644383257799 RemoteAgent TRACE [60] ProgressListener state=stop: about:blank
[task 2022-02-09T05:07:37.804Z] 05:07:37 INFO - 1644383257803 Marionette DEBUG 19 <- [1,34,null,{"handle":"1f07a81a-b7f8-4513-ae85-8653e49155e9","type":"tab"}]
[task 2022-02-09T05:07:37.815Z] 05:07:37 INFO - 1644383257814 Marionette DEBUG 19 -> [0,35,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.816Z] 05:07:37 INFO - 1644383257815 Marionette DEBUG 19 <- [1,35,null,{"value":"content"}]
[task 2022-02-09T05:07:37.818Z] 05:07:37 INFO - 1644383257818 Marionette DEBUG 19 -> [0,36,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.819Z] 05:07:37 INFO - 1644383257819 Marionette DEBUG 19 <- [1,36,null,{"value":null}]
[task 2022-02-09T05:07:37.828Z] 05:07:37 INFO - 1644383257826 Marionette DEBUG 19 -> [0,37,"WebDriver:GetWindowHandles",{}]
[task 2022-02-09T05:07:37.828Z] 05:07:37 INFO - 1644383257827 Marionette DEBUG 19 <- [1,37,null,["d1cfb9b3-2465-43b0-9f20-ee9455ceb03c","1f07a81a-b7f8-4513-ae85-8653e49155e9"]]
[task 2022-02-09T05:07:37.830Z] 05:07:37 INFO - 1644383257829 Marionette DEBUG 19 -> [0,38,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.831Z] 05:07:37 INFO - 1644383257830 Marionette DEBUG 19 <- [1,38,null,{"value":null}]
[task 2022-02-09T05:07:37.833Z] 05:07:37 INFO - 1644383257832 Marionette DEBUG 19 -> [0,39,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.834Z] 05:07:37 INFO - 1644383257833 Marionette DEBUG 19 <- [1,39,null,{"value":"content"}]
[task 2022-02-09T05:07:37.837Z] 05:07:37 INFO - 1644383257837 Marionette DEBUG 19 -> [0,40,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.839Z] 05:07:37 INFO - 1644383257838 Marionette DEBUG 19 <- [1,40,null,{"value":null}]
[task 2022-02-09T05:07:37.844Z] 05:07:37 INFO - 1644383257844 Marionette DEBUG 19 -> [0,41,"WebDriver:GetWindowHandles",{}]
[task 2022-02-09T05:07:37.845Z] 05:07:37 INFO - 1644383257845 Marionette DEBUG 19 <- [1,41,null,["d1cfb9b3-2465-43b0-9f20-ee9455ceb03c","1f07a81a-b7f8-4513-ae85-8653e49155e9"]]
[task 2022-02-09T05:07:37.847Z] 05:07:37 INFO - 1644383257847 Marionette DEBUG 19 -> [0,42,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.849Z] 05:07:37 INFO - 1644383257848 Marionette DEBUG 19 <- [1,42,null,{"value":null}]
[task 2022-02-09T05:07:37.850Z] 05:07:37 INFO - 1644383257850 Marionette DEBUG 19 -> [0,43,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.851Z] 05:07:37 INFO - 1644383257851 Marionette DEBUG 19 <- [1,43,null,{"value":"content"}]
[task 2022-02-09T05:07:37.854Z] 05:07:37 INFO - 1644383257852 Marionette DEBUG 19 -> [0,44,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.855Z] 05:07:37 INFO - 1644383257853 Marionette DEBUG 19 <- [1,44,null,{"value":null}]
[task 2022-02-09T05:07:37.858Z] 05:07:37 INFO - 1644383257855 Marionette DEBUG 19 -> [0,45,"WebDriver:GetWindowHandle",{}]
[task 2022-02-09T05:07:37.860Z] 05:07:37 INFO - 1644383257856 Marionette DEBUG 19 <- [1,45,null,{"value":"d1cfb9b3-2465-43b0-9f20-ee9455ceb03c"}]
[task 2022-02-09T05:07:37.862Z] 05:07:37 INFO - 1644383257858 Marionette DEBUG 19 -> [0,46,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.864Z] 05:07:37 INFO - 1644383257858 Marionette DEBUG 19 <- [1,46,null,{"value":null}]
[task 2022-02-09T05:07:37.866Z] 05:07:37 INFO - 1644383257860 Marionette DEBUG 19 -> [0,47,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.869Z] 05:07:37 INFO - 1644383257861 Marionette DEBUG 19 <- [1,47,null,{"value":"content"}]
[task 2022-02-09T05:07:37.872Z] 05:07:37 INFO - 1644383257862 Marionette DEBUG 19 -> [0,48,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-02-09T05:07:37.873Z] 05:07:37 INFO - 1644383257863 Marionette DEBUG 19 <- [1,48,null,{"value":null}]
[task 2022-02-09T05:07:37.874Z] 05:07:37 INFO - 1644383257866 Marionette DEBUG 19 -> [0,49,"WebDriver:ExecuteScript",{"script":"Components.utils.import(\"resource://gre/modules/AppConstants.jsm\");\n\n ... efault","line":76,"filename":"tests/testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_content.py"}]
[task 2022-02-09T05:07:37.876Z] 05:07:37 INFO - 1644383257876 Marionette DEBUG 19 <- [1,49,null,{"value":0}]
[task 2022-02-09T05:07:37.879Z] 05:07:37 INFO - 1644383257878 Marionette DEBUG 19 -> [0,50,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.880Z] 05:07:37 INFO - 1644383257879 Marionette DEBUG 19 <- [1,50,null,{"value":null}]
[task 2022-02-09T05:07:37.882Z] 05:07:37 INFO - 1644383257881 Marionette DEBUG 19 -> [0,51,"WebDriver:SwitchToWindow",{"handle":"1f07a81a-b7f8-4513-ae85-8653e49155e9","focus":true}]
[task 2022-02-09T05:07:37.896Z] 05:07:37 INFO - 1644383257896 Marionette TRACE Received DOM event TabSelect for [object XULElement]
[task 2022-02-09T05:07:37.929Z] 05:07:37 INFO - 1644383257929 Marionette DEBUG 19 <- [1,51,null,{"value":null}]
[task 2022-02-09T05:07:37.934Z] 05:07:37 INFO - 1644383257934 Marionette DEBUG 19 -> [0,52,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.935Z] 05:07:37 INFO - 1644383257934 Marionette DEBUG 19 <- [1,52,null,{"value":"content"}]
[task 2022-02-09T05:07:37.938Z] 05:07:37 INFO - 1644383257938 Marionette DEBUG 19 -> [0,53,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.939Z] 05:07:37 INFO - 1644383257939 Marionette DEBUG 19 <- [1,53,null,{"value":null}]
[task 2022-02-09T05:07:37.941Z] 05:07:37 INFO - 1644383257941 Marionette DEBUG 19 -> [0,54,"WebDriver:GetWindowHandle",{}]
[task 2022-02-09T05:07:37.943Z] 05:07:37 INFO - 1644383257942 Marionette DEBUG 19 <- [1,54,null,{"value":"1f07a81a-b7f8-4513-ae85-8653e49155e9"}]
[task 2022-02-09T05:07:37.945Z] 05:07:37 INFO - 1644383257944 Marionette DEBUG 19 -> [0,55,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.946Z] 05:07:37 INFO - 1644383257945 Marionette DEBUG 19 <- [1,55,null,{"value":null}]
[task 2022-02-09T05:07:37.948Z] 05:07:37 INFO - 1644383257947 Marionette DEBUG 19 -> [0,56,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:37.949Z] 05:07:37 INFO - 1644383257948 Marionette DEBUG 19 <- [1,56,null,{"value":"content"}]
[task 2022-02-09T05:07:37.951Z] 05:07:37 INFO - 1644383257950 Marionette DEBUG 19 -> [0,57,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-02-09T05:07:37.951Z] 05:07:37 INFO - 1644383257951 Marionette DEBUG 19 <- [1,57,null,{"value":null}]
[task 2022-02-09T05:07:37.955Z] 05:07:37 INFO - 1644383257954 Marionette DEBUG 19 -> [0,58,"WebDriver:ExecuteScript",{"script":"Components.utils.import(\"resource://gre/modules/AppConstants.jsm\");\n\n ... efault","line":76,"filename":"tests/testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_content.py"}]
[task 2022-02-09T05:07:37.962Z] 05:07:37 INFO - 1644383257961 Marionette DEBUG 19 <- [1,58,null,{"value":1}]
[task 2022-02-09T05:07:37.964Z] 05:07:37 INFO - 1644383257964 Marionette DEBUG 19 -> [0,59,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-09T05:07:37.965Z] 05:07:37 INFO - 1644383257965 Marionette DEBUG 19 <- [1,59,null,{"value":null}]
[task 2022-02-09T05:07:37.968Z] 05:07:37 INFO - 1644383257968 Marionette DEBUG 19 -> [0,60,"WebDriver:Navigate",{"url":"data:text/html;charset=utf-8,%3Cp%3Ebar"}]
[task 2022-02-09T05:07:37.977Z] 05:07:37 INFO - 1644383257976 Marionette TRACE [60] Received event beforeunload for about:blank
[task 2022-02-09T05:07:38.014Z] 05:07:38 INFO - 1644383258013 Marionette TRACE Remoteness change detected. Set new top-level browsing context to 60
[task 2022-02-09T05:07:38.062Z] 05:07:38 INFO - 1644383258061 Marionette TRACE [60] Received event pagehide for about:blank
[task 2022-02-09T05:07:38.109Z] 05:07:38 INFO - 1644383258108 Marionette TRACE [60] Received event beforeunload for about:blank
[task 2022-02-09T05:07:38.130Z] 05:07:38 INFO - 1644383258130 Marionette TRACE [60] Received event pagehide for about:blank
[task 2022-02-09T05:07:38.162Z] 05:07:38 INFO - DEBUG: Adding blocker Transaction (4) for phase content-prefs.sqlite#0: waiting for clients
[task 2022-02-09T05:07:38.260Z] 05:07:38 INFO - 1644383258259 Marionette TRACE [60] Received event DOMContentLoaded for data:text/html;charset=utf-8,%3Cp%3Ebar
[task 2022-02-09T05:07:38.266Z] 05:07:38 INFO - DEBUG: Completed blocker Transaction (4) for phase content-prefs.sqlite#0: waiting for clients
[task 2022-02-09T05:07:38.268Z] 05:07:38 INFO - 1644383258267 Marionette TRACE [60] Received event pageshow for data:text/html;charset=utf-8,%3Cp%3Ebar
[task 2022-02-09T05:07:38.279Z] 05:07:38 INFO - 1644383258279 Marionette DEBUG 19 <- [1,60,null,{"value":null}]
[task 2022-02-09T05:07:38.289Z] 05:07:38 INFO - 1644383258288 Marionette DEBUG 19 -> [0,61,"Marionette:GetContext",{}]
[task 2022-02-09T05:07:38.294Z] 05:07:38 INFO - 1644383258289 Marionette DEBUG 19 <- [1,61,null,{"value":"content"}]
[task 2022-02-09T05:07:38.299Z] 05:07:38 INFO - 1644383258290 Marionette DEBUG 19 -> [0,62,"Marionette:AcceptConnections",{"value":false}]
[task 2022-02-09T05:07:38.303Z] 05:07:38 INFO - 1644383258290 Marionette INFO Stopped listening on port 2828
[task 2022-02-09T05:07:38.306Z] 05:07:38 INFO - 1644383258290 Marionette DEBUG 19 <- [1,62,null,{"value":null}]
[task 2022-02-09T05:07:38.309Z] 05:07:38 INFO - 1644383258296 Marionette DEBUG 19 -> [0,63,"Marionette:Quit",{"flags":["eRestart"]}]
[task 2022-02-09T05:07:38.338Z] 05:07:38 INFO - DEBUG: Adding blocker SessionStore: flushing all windows for phase quit-application-granted
[task 2022-02-09T05:07:38.352Z] 05:07:38 INFO - DEBUG: Adding blocker ShieldRecipeClient: Cleaning up for phase profile-before-change
[task 2022-02-09T05:07:38.357Z] 05:07:38 INFO - DEBUG: Starting phase quit-application-granted
[task 2022-02-09T05:07:38.363Z] 05:07:38 INFO - DEBUG: Spinning the event loop
[task 2022-02-09T05:07:38.368Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: wikipedia@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.369Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: webcompat@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.371Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: webcompat-reporter@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.372Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: screenshots@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.373Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: pictureinpicture@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.374Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: google@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.376Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: formautofill@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.377Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: doh-rollout@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.378Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: default-theme@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.380Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: ddg@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.382Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: bing@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.383Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: amazondotcom@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.385Z] 05:07:38 INFO - DEBUG: Adding blocker Extension shutdown: addons-search-detection@mozilla.com for phase profile-change-teardown
[task 2022-02-09T05:07:38.526Z] 05:07:38 INFO - DEBUG: Completed blocker XPIProvider shutdown for phase quit-application-granted
[task 2022-02-09T05:07:38.658Z] 05:07:38 INFO - DEBUG: Completed blocker ShieldRecipeClient: Cleaning up for phase profile-before-change
[task 2022-02-09T05:07:38.679Z] 05:07:38 INFO - DEBUG: Completed blocker SessionStore: flushing all windows for phase quit-application-granted
[task 2022-02-09T05:07:38.682Z] 05:07:38 INFO - DEBUG: Finished phase quit-application-granted
[task 2022-02-09T05:07:38.684Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: wikipedia@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.686Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: webcompat@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.687Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: webcompat-reporter@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.689Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: screenshots@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.691Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: pictureinpicture@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.692Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: google@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.699Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: formautofill@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.701Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: doh-rollout@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.705Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: default-theme@mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.707Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: ddg@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.707Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: bing@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.709Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: amazondotcom@search.mozilla.org for phase profile-change-teardown
[task 2022-02-09T05:07:38.709Z] 05:07:38 INFO - DEBUG: Completed blocker Extension shutdown: addons-search-detection@mozilla.com for phase profile-change-teardown
[task 2022-02-09T05:07:38.964Z] 05:07:38 INFO - 1644383258963 Marionette TRACE Received observer notification quit-application
[task 2022-02-09T05:07:38.966Z] 05:07:38 INFO - 1644383258964 Marionette TRACE Received observer notification quit-application
[task 2022-02-09T05:07:38.966Z] 05:07:38 INFO - 1644383258964 Marionette DEBUG Marionette stopped listening
[task 2022-02-09T05:07:38.970Z] 05:07:38 INFO - DEBUG: Adding blocker SessionFile: Finish writing Session Restore data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-02-09T05:07:38.972Z] 05:07:38 INFO - 1644383258972 Marionette DEBUG 19 <- [1,63,null,{"cause":"restart","forced":false}]
[task 2022-02-09T05:07:38.990Z] 05:07:38 INFO - JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-02-09T05:07:38.994Z] 05:07:38 INFO - ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-02-09T05:07:38.996Z] 05:07:38 INFO - ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-02-09T05:07:39.159Z] 05:07:39 INFO - DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2022-02-09T05:07:39.172Z] 05:07:39 INFO - DEBUG: Starting phase xpcom-will-shutdown
[task 2022-02-09T05:07:39.175Z] 05:07:39 INFO - DEBUG: Spinning the event loop
[task 2022-02-09T05:07:39.177Z] 05:07:39 INFO - DEBUG: Finished phase xpcom-will-shutdown
[task 2022-02-09T05:07:39.181Z] 05:07:39 INFO - JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-02-09T05:07:39.268Z] 05:07:39 INFO - FATAL ERROR: Non-local network connections are disabled and a connection attempt to aus5.mozilla.org (35.244.181.201) was made.
[task 2022-02-09T05:07:39.270Z] 05:07:39 INFO - You should only access hostnames available via the test networking proxy (if running mochitests) or from a test-specific httpd.js server (if running xpcshell tests). Browser services should be disabled or redirected to a local server.
[task 2022-02-09T05:07:39.271Z] 05:07:39 INFO - AddressSanitizer:DEADLYSIGNAL
[task 2022-02-09T05:07:39.272Z] 05:07:39 INFO - =================================================================
[task 2022-02-09T05:07:39.273Z] 05:07:39 ERROR - ==5161==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000001 (pc 0x7f81eae775aa bp 0x7f81e0646cf0 sp 0x7f81e0646500 T4)
[task 2022-02-09T05:07:39.274Z] 05:07:39 INFO - ==5161==The signal is caused by a WRITE memory access.
[task 2022-02-09T05:07:39.274Z] 05:07:39 INFO - ==5161==Hint: address points to the zero page.
[task 2022-02-09T05:07:39.322Z] 05:07:39 INFO - DEBUG: Adding blocker ContentParent: id=619000732380 for phase xpcom-will-shutdown
[task 2022-02-09T05:07:39.326Z] 05:07:39 INFO - DEBUG: Adding blocker ContentParent: id=619000732380 for phase profile-before-change
[task 2022-02-09T05:07:39.619Z] 05:07:39 INFO - llvm-symbolizer: Unknown command line argument '--inlines'. Try: '/usr/bin/llvm-symbolizer -help'
[task 2022-02-09T05:07:39.619Z] 05:07:39 INFO - llvm-symbolizer: Did you mean '-inlining'?
[task 2022-02-09T05:07:39.623Z] 05:07:39 INFO - ==5161==WARNING: Can't read from symbolizer at fd 41
[task 2022-02-09T05:07:39.723Z] 05:07:39 INFO - llvm-symbolizer: Unknown command line argument '--inlines'. Try: '/usr/bin/llvm-symbolizer -help'
[task 2022-02-09T05:07:39.723Z] 05:07:39 INFO - llvm-symbolizer: Did you mean '-inlining'?
[task 2022-02-09T05:07:39.725Z] 05:07:39 INFO - ==5161==WARNING: Can't read from symbolizer at fd 41
[task 2022-02-09T05:07:39.784Z] 05:07:39 INFO - llvm-symbolizer: Unknown command line argument '--inlines'. Try: '/usr/bin/llvm-symbolizer -help'
[task 2022-02-09T05:07:39.785Z] 05:07:39 INFO - llvm-symbolizer: Did you mean '-inlining'?
[task 2022-02-09T05:07:39.786Z] 05:07:39 INFO - ==5161==WARNING: Can't read from symbolizer at fd 41
[task 2022-02-09T05:07:39.846Z] 05:07:39 INFO - llvm-symbolizer: Unknown command line argument '--inlines'. Try: '/usr/bin/llvm-symbolizer -help'
[task 2022-02-09T05:07:39.847Z] 05:07:39 INFO - llvm-symbolizer: Did you mean '-inlining'?
[task 2022-02-09T05:07:39.849Z] 05:07:39 INFO - ==5161==WARNING: Can't read from symbolizer at fd 41
[task 2022-02-09T05:07:39.876Z] 05:07:39 INFO - ==5161==WARNING: Failed to use and restart external symbolizer!
[task 2022-02-09T05:07:39.878Z] 05:07:39 INFO - #0 0x7f81eae775aa (/builds/worker/workspace/build/application/firefox/libxul.so+0x44c15aa)
[task 2022-02-09T05:07:39.880Z] 05:07:39 INFO - #1 0x7f81eae7c5d1 (/builds/worker/workspace/build/application/firefox/libxul.so+0x44c65d1)
[task 2022-02-09T05:07:39.880Z] 05:07:39 INFO - #2 0x7f81eaec7cda (/builds/worker/workspace/build/application/firefox/libxul.so+0x4511cda)
[task 2022-02-09T05:07:39.885Z] 05:07:39 INFO - #3 0x7f81eaacfd3b (/builds/worker/workspace/build/application/firefox/libxul.so+0x4119d3b)
[task 2022-02-09T05:07:39.886Z] 05:07:39 INFO - #4 0x7f81eaadaa2c (/builds/worker/workspace/build/application/firefox/libxul.so+0x4124a2c)
[task 2022-02-09T05:07:39.886Z] 05:07:39 INFO - #5 0x7f81eae8d391 (/builds/worker/workspace/build/application/firefox/libxul.so+0x44d7391)
[task 2022-02-09T05:07:39.886Z] 05:07:39 INFO - #6 0x7f81eae8efec (/builds/worker/workspace/build/application/firefox/libxul.so+0x44d8fec)
[task 2022-02-09T05:07:39.886Z] 05:07:39 INFO - #7 0x7f81eaacfd3b (/builds/worker/workspace/build/application/firefox/libxul.so+0x4119d3b)
[task 2022-02-09T05:07:39.887Z] 05:07:39 INFO - #8 0x7f81eaadaa2c (/builds/worker/workspace/build/application/firefox/libxul.so+0x4124a2c)
[task 2022-02-09T05:07:39.887Z] 05:07:39 INFO - #9 0x7f81ebc7f958 (/builds/worker/workspace/build/application/firefox/libxul.so+0x52c9958)
[task 2022-02-09T05:07:39.887Z] 05:07:39 INFO - #10 0x7f81ebb900c1 (/builds/worker/workspace/build/application/firefox/libxul.so+0x51da0c1)
[task 2022-02-09T05:07:39.887Z] 05:07:39 INFO - #11 0x7f81eaac7d14 (/builds/worker/workspace/build/application/firefox/libxul.so+0x4111d14)
[task 2022-02-09T05:07:39.887Z] 05:07:39 INFO - #12 0x7f820e2c2ade (/builds/worker/workspace/build/application/firefox/libnspr4.so+0x7eade)
[task 2022-02-09T05:07:39.888Z] 05:07:39 INFO - #13 0x7f820df016da (/lib/x86_64-linux-gnu/libpthread.so.0+0x76da)
[task 2022-02-09T05:07:39.888Z] 05:07:39 INFO - #14 0x7f820cedfa3e (/lib/x86_64-linux-gnu/libc.so.6+0x121a3e)
[task 2022-02-09T05:07:39.888Z] 05:07:39 INFO - AddressSanitizer can not provide additional info.
[task 2022-02-09T05:07:39.888Z] 05:07:39 INFO - SUMMARY: AddressSanitizer: SEGV (/builds/worker/workspace/build/application/firefox/libxul.so+0x44c15aa)
[task 2022-02-09T05:07:39.889Z] 05:07:39 INFO - Thread T4 (Socket Thread) created by T0 here:
[task 2022-02-09T05:07:39.889Z] 05:07:39 INFO - #0 0x555e7409a46c (/builds/worker/workspace/build/application/firefox/firefox+0xbe46c)
[task 2022-02-09T05:07:39.889Z] 05:07:39 INFO - #1 0x7f820e2b2b74 (/builds/worker/workspace/build/application/firefox/libnspr4.so+0x6eb74)
[task 2022-02-09T05:07:39.889Z] 05:07:39 INFO - #2 0x7f820e2a3e1e (/builds/worker/workspace/build/application/firefox/libnspr4.so+0x5fe1e)
[task 2022-02-09T05:07:39.890Z] 05:07:39 INFO - #3 0x7f81eaacb035 (/builds/worker/workspace/build/application/firefox/libxul.so+0x4115035)
[task 2022-02-09T05:07:39.890Z] 05:07:39 INFO - #4 0x7f81eaad880f (/builds/worker/workspace/build/application/firefox/libxul.so+0x412280f)
[task 2022-02-09T05:07:39.890Z] 05:07:39 INFO - #5 0x7f81eaae41b1 (/builds/worker/workspace/build/application/firefox/libxul.so+0x412e1b1)
[task 2022-02-09T05:07:39.890Z] 05:07:39 INFO - #6 0x7f81eae8ade1 (/builds/worker/workspace/build/application/firefox/libxul.so+0x44d4de1)
[task 2022-02-09T05:07:39.890Z] 05:07:39 INFO - #7 0x7f81eaa43704 (/builds/worker/workspace/build/application/firefox/libxul.so+0x408d704)
[task 2022-02-09T05:07:39.891Z] 05:07:39 INFO - #8 0x7f81eaa7d677 (/builds/worker/workspace/build/application/firefox/libxul.so+0x40c7677)
[task 2022-02-09T05:07:39.891Z] 05:07:39 INFO - #9 0x7f81eaa7f4f4 (/builds/worker/workspace/build/application/firefox/libxul.so+0x40c94f4)
[task 2022-02-09T05:07:39.891Z] 05:07:39 INFO - #10 0x7f81eaa84742 (/builds/worker/workspace/build/application/firefox/libxul.so+0x40ce742)
[task 2022-02-09T05:07:39.891Z] 05:07:39 INFO - #11 0x7f81ea8f3e5d (/builds/worker/workspace/build/application/firefox/libxul.so+0x3f3de5d)
[task 2022-02-09T05:07:39.891Z] 05:07:39 INFO - #12 0x7f81eaddfe0b (/builds/worker/workspace/build/application/firefox/libxul.so+0x4429e0b)
[task 2022-02-09T05:07:39.891Z] 05:07:39 INFO - #13 0x7f81eade9eb0 (/builds/worker/workspace/build/application/firefox/libxul.so+0x4433eb0)
[task 2022-02-09T05:07:39.891Z] 05:07:39 INFO - #14 0x7f81eaddd8ac (/builds/worker/workspace/build/application/firefox/libxul.so+0x44278ac)
[task 2022-02-09T05:07:39.891Z] 05:07:39 INFO - #15 0x7f81eade0a9b (/builds/worker/workspace/build/application/firefox/libxul.so+0x442aa9b)
[task 2022-02-09T05:07:39.892Z] 05:07:39 INFO - #16 0x7f81eaa416da (/builds/worker/workspace/build/application/firefox/libxul.so+0x408b6da)
[task 2022-02-09T05:07:39.892Z] 05:07:39 INFO - #17 0x7f81eaa7d677 (/builds/worker/workspace/build/application/firefox/libxul.so+0x40c7677)
[task 2022-02-09T05:07:39.892Z] 05:07:39 INFO - #18 0x7f81eaa7f4f4 (/builds/worker/workspace/build/application/firefox/libxul.so+0x40c94f4)
[task 2022-02-09T05:07:39.892Z] 05:07:39 INFO - #19 0x7f81ec9851b3 (/builds/worker/workspace/build/application/firefox/libxul.so+0x5fcf1b3)
[task 2022-02-09T05:07:39.893Z] 05:07:39 INFO - #20 0x7f81ec985629 (/builds/worker/workspace/build/application/firefox/libxul.so+0x5fcf629)
[task 2022-02-09T05:07:39.893Z] 05:07:39 INFO - #21 0x7f81ec72cec0 (/builds/worker/workspace/build/application/firefox/libxul.so+0x5d76ec0)
[task 2022-02-09T05:07:39.894Z] 05:07:39 INFO - #22 0x7f81ec6bf538 (/builds/worker/workspace/build/application/firefox/libxul.so+0x5d09538)
[task 2022-02-09T05:07:39.894Z] 05:07:39 INFO - #23 0x7f81f2b7b02c (/builds/worker/workspace/build/application/firefox/libxul.so+0xc1c502c)
[task 2022-02-09T05:07:39.895Z] 05:07:39 INFO - #24 0x7f81eaa754e6 (/builds/worker/workspace/build/application/firefox/libxul.so+0x40bf4e6)
[task 2022-02-09T05:07:39.895Z] 05:07:39 INFO - #25 0x7f81eab3f4b3 (/builds/worker/workspace/build/application/firefox/libxul.so+0x41894b3)
[task 2022-02-09T05:07:39.896Z] 05:07:39 INFO - #26 0x7f81f610b3d6 (/builds/worker/workspace/build/application/firefox/libxul.so+0xf7553d6)
[task 2022-02-09T05:07:39.897Z] 05:07:39 INFO - #27 0x7f81f612187e (/builds/worker/workspace/build/application/firefox/libxul.so+0xf76b87e)
[task 2022-02-09T05:07:39.897Z] 05:07:39 INFO - #28 0x7f81f61225d3 (/builds/worker/workspace/build/application/firefox/libxul.so+0xf76c5d3)
[task 2022-02-09T05:07:39.898Z] 05:07:39 INFO - #29 0x555e740e5034 (/builds/worker/workspace/build/application/firefox/firefox+0x109034)
[task 2022-02-09T05:07:39.898Z] 05:07:39 INFO - #30 0x7f820cddfb96 (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)
[task 2022-02-09T05:07:39.898Z] 05:07:39 INFO - ==5161==ABORTING
[task 2022-02-09T05:07:39.920Z] 05:07:39 INFO - llvm-symbolizer: Unknown command line argument '--inlines'. Try: '/usr/bin/llvm-symbolizer -help'
[task 2022-02-09T05:07:39.920Z] 05:07:39 INFO - llvm-symbolizer: Did you mean '-inlining'?
[task 2022-02-09T05:07:39.967Z] 05:07:39 INFO - Exiting due to channel error.
[task 2022-02-09T05:07:39.969Z] 05:07:39 INFO - Exiting due to channel error.
[task 2022-02-09T05:07:39.971Z] 05:07:39 INFO - Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=0.59042) Exiting due to channel error.
[task 2022-02-09T05:14:49.213Z] 05:14:49 INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_chrome.py TestSwitchToWindowContent.test_switch_to_unloaded_tab | OSError: Process has been unexpectedly closed (Exit code: 1) (Reason: Process unexpectedly quit without restarting (exit code: 1))
[task 2022-02-09T05:14:49.213Z] 05:14:49 INFO - Traceback (most recent call last):
[task 2022-02-09T05:14:49.213Z] 05:14:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_harness/marionette_test/testcases.py", line 202, in run
[task 2022-02-09T05:14:49.214Z] 05:14:49 INFO - testMethod()
[task 2022-02-09T05:14:49.214Z] 05:14:49 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_content.py", line 179, in test_switch_to_unloaded_tab
[task 2022-02-09T05:14:49.214Z] 05:14:49 INFO - self.marionette.restart(in_app=True)
[task 2022-02-09T05:14:49.215Z] 05:14:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 37, in _
[task 2022-02-09T05:14:49.215Z] 05:14:49 INFO - m._handle_socket_failure()
[task 2022-02-09T05:14:49.215Z] 05:14:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 758, in _handle_socket_failure
[task 2022-02-09T05:14:49.216Z] 05:14:49 INFO - IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2022-02-09T05:14:49.216Z] 05:14:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 702, in reraise
[task 2022-02-09T05:14:49.216Z] 05:14:49 INFO - raise value.with_traceback(tb)
[task 2022-02-09T05:14:49.217Z] 05:14:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2022-02-09T05:14:49.217Z] 05:14:49 INFO - return func(*args, **kwargs)
[task 2022-02-09T05:14:49.217Z] 05:14:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 1150, in restart
[task 2022-02-09T05:14:49.218Z] 05:14:49 INFO - tb,
[task 2022-02-09T05:14:49.218Z] 05:14:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 702, in reraise
[task 2022-02-09T05:14:49.218Z] 05:14:49 INFO - raise value.with_traceback(tb)
[task 2022-02-09T05:14:49.219Z] 05:14:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 1130, in restart
[task 2022-02-09T05:14:49.219Z] 05:14:49 INFO - self.raise_for_port(timeout=timeout_restart, check_process_status=False)
[task 2022-02-09T05:14:49.219Z] 05:14:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 638, in raise_for_port
[task 2022-02-09T05:14:49.220Z] 05:14:49 INFO - self.host, self.port
[task 2022-02-09T05:14:49.220Z] 05:14:49 INFO - TEST-INFO took 432062ms
[task 2022-02-09T05:14:49.221Z] 05:14:49 ERROR - test_end for testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_chrome.py TestSwitchToWindowContent.test_switch_to_unloaded_tab logged while not in progress. Logged with data: {"message": "marionette_driver.errors.InvalidSessionIdException: Please start a session", "expected": "PASS", "stack": "Traceback (most recent call last):\n File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_harness/marionette_test/testcases.py\", line 235, in run\n self.tearDown()\n File \"/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_content.py\", line 37, in tearDown\n self.close_all_tabs()\n File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_harness/runner/mixins/window_manager.py\", line 33, in close_all_tabs\n current_window_handles = self.marionette.window_handles\n File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py\", line 1373, in window_handles\n with self.using_context(\"content\"):\n File \"/usr/lib/python3.6/contextlib.py\", line 81, in __enter__\n return next(self.gen)\n File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py\", line 1454, in using_context\n scope = self._send_message(\"Marionette:GetContext\", key=\"value\")\n File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py\", line 27, in _\n return func(*args, **kwargs)\n File \"/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py\", line 658, in _send_message\n raise errors.InvalidSessionIdException(\"Please start a session\")\n", "extra": {"class_name": "test_switch_window_content.TestSwitchToWindowContent", "method_name": "test_switch_to_unloaded_tab"}, "test": "testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_chrome.py TestSwitchToWindowContent.test_switch_to_unloaded_tab", "status": "ERROR"}
[task 2022-02-09T05:14:49.221Z] 05:14:49 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_chrome.py TestSwitchToWindowContent.test_switch_to_window_after_remoteness_change
Updated•3 years ago
|
Comment 1•3 years ago
|
||
Regressed by bug 1272255. We are now crashing if Firefox is trying to access some non-local addresses. Here it's aus5.mozilla.org that Firefox usually uses for update checks. about:config
shows the following entries:
extensions.systemAddon.update.url
media.gmp-manager.certs.1.commonName
media.gmp-manager.certs.2.commonName
media.gmp-manager.url
The extensions.systemAddon.update.url
we replace and for gmp-manager we set media.gmp-manager.updateEnabled
to false
so that it basically should not check for updates. And the latter is also what other harnesses do in testing/profile
. But I cannot find settings that modify extensions.systemAddon.update.url
. Maybe that's related here? Generally it would be great if the crash message would contain the full URL.
So far it happened only once for a Linux ASAN build and I'm not able to reproduce locally.
Updated•3 years ago
|
Comment 2•3 years ago
|
||
I agree that having better logs for such crashes would make investigations much easier.
Comment 3•3 years ago
|
||
Valentin, do you know why we only print the host and IP for such a triggered crash in Firefox?
05:07:39 INFO - FATAL ERROR: Non-local network connections are disabled and a connection attempt to aus5.mozilla.org (35.244.181.201) was made.
It would be great to see the full URL so that it will become much easier to actually investigate the issue. Maybe it's just the host/ip due to privacy issues, so that we do not leak API keys or similar in log files?
Comment 4•3 years ago
|
||
We only show the IP because the crash is happens in nsSocketTransport2.cpp. The socket isn't aware of the upper layers.
Presumably this happens because any of the background requests (update, gmp, extensions) may happen during the test run.
An easy fix for this is to simply add an IP override for that (like here
Or you could set network.dns.native-is-localhost=true
pref for the duration of the test.
Comment 5•3 years ago
|
||
Thanks Valentin. Interesting pointer regarding the DNS override but I think that we wanna try to catch all of that via a correctly updated list of preferences for these jobs running in our CI and locally via mach.
Given that this failure here happened only once so far, I don't see a need to further investigate this bug anytime soon. Once we see an increased amount of failures we will have a look.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 13•3 years ago
|
||
The aus5.mozilla.org is used for media.gmp-manager.url at https://searchfox.org/mozilla-central/rev/f8db81665dc2833fff09dc7eef200539ac1fd351/modules/libpref/init/all.js#4102
We do not override this pref for now, but most test harness do via media.gmp-manager.url.override https://searchfox.org/mozilla-central/search?path=&q=media.gmp-manager.url
Note also that the failures usually happen during a restart in test_switch_to_unloaded_tab
Comment 14•3 years ago
|
||
Hmm even though we don't set this preference, we do set media.gmp-manager.updateEnabled
to false. Looking at the code, this should disable all usage of media.gmp-manager.url
.
Comment 15•3 years ago
|
||
(In reply to Julian Descottes [:jdescottes] from comment #13)
The aus5.mozilla.org is used for media.gmp-manager.url at https://searchfox.org/mozilla-central/rev/f8db81665dc2833fff09dc7eef200539ac1fd351/modules/libpref/init/all.js#4102
aus5.mozilla.org is used for various update checks including extensions and general Firefox updates. So it's not only for the GMP manager. But all of them we have turned off. So it's really interesting what exactly tries to connect this server in ASAN builds only.
Comment 16•3 years ago
|
||
(In reply to Henrik Skupin (:whimboo) [⌚️UTC+1] from comment #15)
aus5.mozilla.org is used for various update checks including extensions and general Firefox updates.
Yes, but I was looking at the ones we didn't override explicitly with mock URLs. This one stood out because it's turned off via another pref.
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 30•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Reporter | ||
Comment 31•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=391635517&repo=mozilla-esr102
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 35•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Reporter | ||
Comment 36•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=398479630&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment 38•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Updated•2 years ago
|
Comment 39•2 years ago
|
||
Reporter | ||
Comment 40•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=409676701&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 48•1 year ago
|
||
Copying crash signatures from duplicate bugs.
Comment hidden (Intermittent Failures Robot) |
Comment 50•1 year ago
|
||
I can actually reproduce that bug permanently locally when applying the patch from D177134 to my local tree and adding a throw new Error()
after new lazy.ServerSocket(this.port, flags, backlog);
.
That surprises me given that we disable automatic updates via the app.update.disabledForTesting
preference in geckoinstance.py. This means the preference is set before Firefox gets started.
Why does Firefox still try to reach aus5.mozilla.org to look for updates?
Here the updater log output:
1683897262575 Marionette DEBUG Could not bind to port 2828 (Error)
1683897262892 Marionette DEBUG Could not bind to port 2828 (NS_ERROR_SOCKET_ADDRESS_IN_USE)
[GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
*** UTM:SVC TimerManager:registerTimer - timerID: browser-cleanup-thumbnails interval: 3600 skipFirst: false
console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
*** UTM:SVC TimerManager:registerTimer - timerID: region-update-timer interval: 604800 skipFirst: false
console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
*** AUS:SVC RestartOnLastWindowClosed.#maybeEnableOrDisable - Enabling
*** AUS:SVC Creating UpdateService
*** AUS:SVC Logging current UpdateService status:
*** AUS:SVC UpdateService.canUsuallyCheckForUpdates - able to check for updates
*** AUS:SVC UpdateService.canCheckForUpdates - able to check for updates
*** AUS:SVC getCanApplyUpdates - testing write access /Users/henrik/Library/Caches/Mozilla/updates/Users/henrik/code/gecko-obj/opt/dist/Nightly/update.test
*** AUS:SVC getCanApplyUpdates - bypass the write since elevation can be used on Mac OS X
*** AUS:SVC getElevationRequired - recursively testing write access on /Users/henrik/code/gecko-obj/opt/dist/Nightly.app
*** AUS:SVC getElevationRequired - able to write to application bundle, elevation not required
*** AUS:SVC gCanStageUpdatesSession - testing write access /Users/henrik/Library/Caches/Mozilla/updates/Users/henrik/code/gecko-obj/opt/dist/Nightly/update.test
*** AUS:SVC gCanStageUpdatesSession - able to stage updates
*** AUS:SVC getElevationRequired - recursively testing write access on /Users/henrik/code/gecko-obj/opt/dist/Nightly.app
*** AUS:SVC getElevationRequired - able to write to application bundle, elevation not required
*** AUS:SVC Elevation required: false
*** AUS:SVC Other instance of the application currently running: false
*** AUS:SVC Downloading: false
*** AUS:SVC End of UpdateService status
*** AUS:SVC UpdateService.canUsuallyCheckForUpdates - able to check for updates
*** AUS:SVC UpdateService.canCheckForUpdates - able to check for updates
*** AUS:SVC CheckerService:checkForUpdates - checkType: 2
*** AUS:SVC CheckerService:checkForUpdates - Making new check request for check id 1.
*** AUS:SVC waitForOtherInstances - beginning polling
*** AUS:SVC waitForOtherInstances - no other instances found, exiting
*** AUS:SVC CheckerService:getUpdateURL - checkType: 2
1683897263456 Marionette DEBUG Could not bind to port 2828 (NS_ERROR_SOCKET_ADDRESS_IN_USE)
*** AUS:SVC CheckerService:getUpdateURL - update URL: https://aus5.mozilla.org/update/6/Firefox/115.0a1/20230511094802/Darwin_aarch64-gcc3/en-US/default/Darwin%2022.4.0/ISET:NEON,MEM:32768/default/default/update.xml?force=1
*** AUS:SVC CheckerService:#updateCheck - sending request to: https://aus5.mozilla.org/update/6/Firefox/115.0a1/20230511094802/Darwin_aarch64-gcc3/en-US/default/Darwin%2022.4.0/ISET:NEON,MEM:32768/default/default/update.xml?force=1
1683897263579 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
Comment 51•1 year ago
|
||
Oh wait. We are not enabling Marionette and as such the nsIMarionette interface returns false
for the running
property. That means the app.update.disabledForTesting
preference has no affect at this time.
This actually seems to be a race condition and maybe the first check for an update has to be post-poned even more? Or is there a way to actually completely disable update checks? That might be a better choice for us.
Comment 52•1 year ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+1] from comment #51)
Oh wait. We are not enabling Marionette and as such the nsIMarionette interface returns
false
for therunning
property. That means theapp.update.disabledForTesting
preference has no affect at this time.
Ah, that would do it.
This actually seems to be a race condition and maybe the first check for an update has to be post-poned even more? Or is there a way to actually completely disable update checks? That might be a better choice for us.
Can you set an enterprise policy? You could use DisableAppUpdate
.
Comment 53•1 year ago
|
||
(In reply to Robin Steuber (they/them) [:bytesized] from comment #52)
This actually seems to be a race condition and maybe the first check for an update has to be post-poned even more? Or is there a way to actually completely disable update checks? That might be a better choice for us.
Can you set an enterprise policy? You could use
DisableAppUpdate
.
No, that's something we cannot do. When I read the the enterprise documentation it looks like the policy needs to be set as file and it has to be located within the application folder which we may not have access to. Also given that such a Firefox instance can run on a users or CI system (even in parallel to an already running Firefox instance) I would be against using that technique. If something goes wrong (in the case we have access) with removing this file we would leave the system under some policy and that's not acceptable.
Comment 54•1 year ago
|
||
I'm afraid that we very intentionally don't allow update checks to be disabled without either (a) administrator privileges and/or direct access to the installation directory (i.e. Enterprise Policies) or (b) the Application Update Service being able to verify that it is running within a test framework.
(In reply to Henrik Skupin [:whimboo][⌚️UTC+1] from comment #51)
Oh wait. We are not enabling Marionette and as such the nsIMarionette interface returnsfalse
for therunning
property.
How are the tests being conducted if not by Marionette? Is there something that the update service could do to check that such a test is running? Then we could add that to the get UpdateService.disabledForTesting()
implementation.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 57•1 year ago
|
||
(In reply to Robin Steuber (they/them) [:bytesized] from comment #54)
(In reply to Henrik Skupin [:whimboo][⌚️UTC+1] from comment #51)
Oh wait. We are not enabling Marionette and as such the nsIMarionette interface returnsfalse
for therunning
property.How are the tests being conducted if not by Marionette? Is there something that the update service could do to check that such a test is running? Then we could add that to the
get UpdateService.disabledForTesting()
implementation.
The problem here is actually the delay until Marionette has created its server socket and we consider it to be running. This particular flag is currently already checked. In case there are port conflicts we actually retry to create the server socket again on the previously selected port. As such there can be a delay. As such I'm not sure how much users of WebDriver might actually run into this issue that a update check is performed. Important is that it's not getting applied - but here we haven't heard anything yet.
Regarding this bug the failure only happens in our CI and when running Marionette via mach marionette-test
because we do not allow remote connections by setting the MOZ_DISABLE_NONLOCAL_CONNECTIONS
environment variable.
Robin, would it already help to maybe set the next update check to some minutes into the future so that there is enough time for Firefox to get started, and Marionette / Remote Agent to be enabled?
I also filed bug 1834306 so that we get the Marionette and Remote Agent checks added to Cu.isInAutomation
directly given that some components don't take it into account at all.
Updated•1 year ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 59•1 year ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+1] from comment #57)
Robin, would it already help to maybe set the next update check to some minutes into the future so that there is enough time for Firefox to get started, and Marionette / Remote Agent to be enabled?
Would two minutes be long enough? I believe that a two minute delay could be achieved just by setting some prefs.
First you would want to bypass the out-of-date check by setting app.update.checkInstallTime
to false
so that we bypass this whole block.
Then you could delay the first UpdateTimerManager
timer by setting app.update.timerFirstInterval
to 120000
(2 minutes in milliseconds). We currently cap that value at 2 minutes though, so if that isn't long enough we will either need to raise the cap or consider some other ways of delaying UpdateTimerManager
.
Comment 60•1 year ago
|
||
Oh yes, two minutes would be absolutely fine but we would actually have to set this before starting Firefox. Also when running restart tests we might run into the same problem for the new Firefox instance. Maybe for the latter case we can update the timer again before requesting Firefox to shutdown for a restart.
The number of failures is still low here so maybe for now we could simply ignore it.
But for users of our protocols in general would app.update.autodownload
help to at least stop downloading the update automatically? We really don't want to see an update getting applied.
Comment 61•1 year ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+1] from comment #60)
But for users of our protocols in general would
app.update.autodownload
help to at least stop downloading the update automatically? We really don't want to see an update getting applied.
I wouldn't really recommend this route, but I'll describe what would be involved.
You are probably looking for app.update.auto
. But that setting is actually no longer (consistently) stored as a regular pref. It now needs to be set via UpdateUtils.setAppUpdateAutoEnabled
. This would not prevent update checks, but Firefox wouldn't download updates unless the user accepted the update prompt.
It's also worth mentioning that the reason that this pref is like this is that the setting is installation-specific, not profile-specific. I have generally tried to make most of the things that involve Application Update installation-specific since updating the application inherently affects the whole installation, not just a single profile. Also this allows update settings to apply to the Background Update Agent. This seems like it might be a problem given that you previously said this may be running on a shared installation.
It also sounds like you may be hoping to change this pref before Firefox starts, which would be kind of a problem. On non-Windows, it could be set how a normal pref is set, but we may be changing that in the future. On Windows, it's stored in a JSON file in the update directory. This means that (a) you would have to actually find the installation's update directory, which is a little tricky since it involves computing a CITY hash of the lower-cased wide string of the installation directory, and (b) that file isn't exactly meant to be an API and I don't think I would call its format "stable".
Comment 62•1 year ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+1] from comment #60)
Maybe for the latter case we can update the timer again before requesting Firefox to shutdown for a restart.
If I'm understanding what you are saying here, I don't think that that is necessary. app.update.timerFirstInterval
is a static pref that controls how long until the UpdateTimerManager
starts on every startup. There should be no need change it again unless you create a new profile.
Comment 63•1 year ago
|
||
Sorry that I don't have a ton of good news for you here, but we try pretty hard to prevent local malware from preventing Firefox from updating. And what you are trying to do is fairly indistinguishable from that, really.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 66•1 year ago
|
||
(In reply to Robin Steuber (they/them) [:bytesized] from comment #62)
If I'm understanding what you are saying here, I don't think that that is necessary.
app.update.timerFirstInterval
is a static pref that controls how long until theUpdateTimerManager
starts on every startup. There should be no need change it again unless you create a new profile.
This is great to know and I think that using this preference would be fine to at least workaround the startup issues.
There is one thing through which I have seen recently. During shutdown which means after quit-application-granted
we are still firing this timer which we probably should avoid. For an example see these lines of a Marionette test that fails regarding the ping:
https://treeherder.mozilla.org/logviewer?job_id=418135920&repo=autoland&lineNumber=92602-92632
Comment 67•1 year ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #66)
During shutdown which means after
quit-application-granted
we are still firing this timer which we probably should avoid.
It looks to me like we shut down UpdateTimerManager
on profile-before-change
, but perhaps it ought to be earlier than that? Do you know if quit-application-granted
is before that? I'm not super clear on the order of events during shutdown or at what point we know that the shutdown definitely won't abort.
Comment 68•1 year ago
|
||
That's a good question and I cannot really answer it. But I would say that you are doing it right and that maybe Marionette should also delay the shutdown of the server socket until profile-before-change
and not do it already for quit-application
. As such the socket would stay around longer and also nsIMarionette.running
would report true
. That probably would avoid running an application check during shutdown.
Gijs, maybe you could tell us if profile-before-change
is the right point during shutdown to also shutdown certain components? Thanks a lot!
Comment 69•1 year ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #68)
That's a good question and I cannot really answer it. But I would say that you are doing it right and that maybe Marionette should also delay the shutdown of the server socket until
profile-before-change
and not do it already forquit-application
. As such the socket would stay around longer and alsonsIMarionette.running
would reporttrue
. That probably would avoid running an application check during shutdown.Gijs, maybe you could tell us if
profile-before-change
is the right point during shutdown to also shutdown certain components? Thanks a lot!
This question is not one I can really answer straightforwardly - it depends what those components are doing?
Our shutdown phases are what I believe is technically called "a mess". Certainly quit-application
is one of the earlier phases where you could start shutting things down. I think there's a list here:
Which corresponds to observer topics here:
Typically, you'd want to make sure that whatever phase/topic you pick, you (a) make sure it's before (or latest at the same time) as things you depend on (e.g. don't leave your component running until after, say, indexeddb code shuts down, if your component depends on said indexeddb code), and (b) ensure that there's no possibility after that point of re-starting-up in response to some API call, after which your component will never shut down (because the thing you're hooking to shut down has already happened). The AppShutdown (Services.startup
from JS) code can help with this.
(In reply to Robin Steuber (they/them) [:bytesized] from comment #54)
How are the tests being conducted if not by Marionette? Is there something that the update service could do to check that such a test is running? Then we could add that to the
get UpdateService.disabledForTesting()
implementation.
Can we not "just" use Cu.isInAutomation()
, rather than checking marionette or changing when it shuts down? That would be a less invasive change.
Despite the method name, that method (which returns a bool) really just checks (a) that the MOZ_DISABLE_NONLOCAL_CONNECTIONS
thing is set (coincidentally, the thing that is more directly causing the crashes here!) and that (b) the turn_off_all_security_so_that_viruses_can_take_over_this_computer
pref is set (which is also test-specific). If for some reason we need to support a case where the second is not true, you could check xpc::AreNonLocalConnectionsDisabled()
in C++, or manually check the env var - but that's a little more expensive (and the xpc
method has some read-only-page defense in depth stuff) so may not want to be something you do.
Comment 70•1 year ago
|
||
(In reply to :Gijs (he/him) from comment #69)
Can we not "just" use
Cu.isInAutomation()
, rather than checking marionette or changing when it shuts down? That would be a less invasive change.
The update system does check Cu.isInAutomation()
.
Comment 71•1 year ago
|
||
(In reply to Robin Steuber (they/them) [:bytesized] from comment #70)
(In reply to :Gijs (he/him) from comment #69)
Can we not "just" use
Cu.isInAutomation()
, rather than checking marionette or changing when it shuts down? That would be a less invasive change.The update system does check
Cu.isInAutomation()
.
Huh. So why is that insufficient here - :whimboo, do you know?
Comment 72•1 year ago
|
||
So Cu.isInAutomation()
only checks the mTurnOffAllSecurityPref
(as mentioned above) and then asserts that non-local connections are disabled. Note that this is not enough for Marionette and Remote Agent which are used by WebDriver clients to run automated tests for web pages. As such we added particular checks for both separately.
But that is not optimal given that we cannot keep up with any component in tree that checks the Cu.isInAutomation
flag. As such I filed bug 1834306 recently to update the check, whereby I'm not sure how easy it will actually be. The mTurnOffAllSecurityPref
will never be set by Marionette / geckodriver given that tests are run on beta / release builds, and no check for non-local connections can be performed because tests run against live web pages. Only in our own CI both should be taken care of.
I'm happy to continue the discussion for Cu.isInAutomation
on the other bug, and keep this bug for a potential fix for the update checks.
Comment 73•1 year ago
|
||
Another alternative to fix our CI failures would be if the Marionette unit tests would use a pre-configured profile from testing/profiles
similar to other tests, but this would not prevent Firefox to check for updates under such a situation for consumers of Webdriver.
Updated•1 year ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•1 year ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Reporter | ||
Updated•1 year ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•1 year ago
|
Reporter | ||
Updated•1 year ago
|
Description
•