Closed
Bug 1906870
Opened 2 years ago
Closed 1 year ago
Intermittent netwerk/test/marionette/test_purge_http_cache_at_shutdown.py PurgeHTTPCacheAtShutdownTestCase.test_asetup | single tracking bug
Categories
(Core :: Networking, defect, P5)
Core
Networking
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, intermittent-testcase)
Filed by: tszentpeteri [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=465600947&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/AcSrhT2URByNv-5LhPfkAQ/runs/0/artifacts/public/logs/live_backing.log
[task 2024-07-09T12:26:35.744Z] 12:26:35 INFO - TEST-START | browser/components/sessionstore/test/marionette/test_restore_manually.py TestSessionRestoreManually.test_restore
[task 2024-07-09T12:26:35.745Z] 12:26:35 INFO - 1720527995745 Marionette DEBUG Accepted connection 2 from 127.0.0.1:44622
[task 2024-07-09T12:26:35.747Z] 12:26:35 INFO - 1720527995746 Marionette DEBUG Closed connection 1
[task 2024-07-09T12:26:35.748Z] 12:26:35 INFO - 1720527995748 Marionette DEBUG 2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2024-07-09T12:26:35.750Z] 12:26:35 INFO - 1720527995750 Marionette DEBUG Waiting for initial application window
[task 2024-07-09T12:26:35.752Z] 12:26:35 INFO - 1720527995752 RemoteAgent TRACE [3] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=5000 waitForExplicitStart=false
[task 2024-07-09T12:26:35.754Z] 12:26:35 INFO - 1720527995753 RemoteAgent TRACE [3] ProgressListener Setting unload timer (5000ms)
[task 2024-07-09T12:26:35.755Z] 12:26:35 INFO - 1720527995754 RemoteAgent TRACE [3] Wait for initial navigation: isInitial=false, isLoadingDocument=false
[task 2024-07-09T12:26:35.756Z] 12:26:35 INFO - 1720527995755 RemoteAgent TRACE [3] Document already finished loading: data:text/html;charset=utf-8,%3Ca%20id%3D%27link%27%20href%3D%27http%3A//127.0.0.1%3A41663/slow%27%20target%3D%27other%27%3Eclick%3C/a%3E
[task 2024-07-09T12:26:35.756Z] 12:26:35 INFO - 1720527995756 RemoteAgent TRACE [3] ProgressListener Stop: has error=false url=data:text/html;charset=utf-8,%3Ca%20id%3D%27link%27%20href%3D%27http%3A//127.0.0.1%3A41663/slow%27%20target%3D%27other%27%3Eclick%3C/a%3E
[task 2024-07-09T12:26:35.760Z] 12:26:35 INFO - 1720527995759 Marionette DEBUG 2 <- [1,1,null,{"sessionId":"38d40360-9e96-4569-b1d3-144c02f9ff73","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"130.0a1","platformName":"linux","unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:130.0) Gecko/20100101 Firefox/130.0","moz:buildID":"20240709112944","moz:headless":false,"moz:platformVersion":"4.4.0-1014-aws","moz:processID":5133,"moz:profile":"/tmp/tmp8q8l8trh.mozrunner","moz:shutdownTimeout":60000,"pageLoadStrategy":"normal","timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"setWindowRect":true,"strictFileInteractability":true,"moz:accessibilityChecks":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2024-07-09T12:26:35.761Z] 12:26:35 INFO - 1720527995761 Marionette DEBUG 2 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2024-07-09T12:26:35.762Z] 12:26:35 INFO - 1720527995762 Marionette DEBUG 2 <- [1,2,null,{"value":null}]
[task 2024-07-09T12:26:35.764Z] 12:26:35 INFO - 1720527995764 Marionette DEBUG 2 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2024-07-09T12:26:35.766Z] 12:26:35 INFO - 1720527995765 Marionette DEBUG 2 <- [1,3,null,{"value":null}]
[task 2024-07-09T12:26:35.767Z] 12:26:35 INFO - 1720527995767 Marionette DEBUG 2 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2024-07-09T12:26:35.772Z] 12:26:35 INFO - 1720527995771 Marionette DEBUG 2 <- [1,4,null,{"value":null}]
[task 2024-07-09T12:26:35.775Z] 12:26:35 INFO - 1720527995775 Marionette DEBUG 2 -> [0,5,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:35.777Z] 12:26:35 INFO - 1720527995775 Marionette DEBUG 2 <- [1,5,null,{"value":"content"}]
[task 2024-07-09T12:26:35.778Z] 12:26:35 INFO - 1720527995777 Marionette DEBUG 2 -> [0,6,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:35.778Z] 12:26:35 INFO - 1720527995778 Marionette DEBUG 2 <- [1,6,null,{"value":null}]
[task 2024-07-09T12:26:35.779Z] 12:26:35 INFO - 1720527995779 Marionette DEBUG 2 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2024-07-09T12:26:35.780Z] 12:26:35 INFO - 1720527995780 Marionette DEBUG 2 <- [1,7,null,{"value":"b071eacd-3a0c-4b1b-98dd-fabab9058567"}]
[task 2024-07-09T12:26:35.781Z] 12:26:35 INFO - 1720527995781 Marionette DEBUG 2 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2024-07-09T12:26:35.782Z] 12:26:35 INFO - 1720527995781 Marionette DEBUG 2 <- [1,8,null,{"value":null}]
[task 2024-07-09T12:26:35.783Z] 12:26:35 INFO - 1720527995782 Marionette DEBUG 2 -> [0,9,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:35.783Z] 12:26:35 INFO - 1720527995783 Marionette DEBUG 2 <- [1,9,null,{"value":"content"}]
[task 2024-07-09T12:26:35.784Z] 12:26:35 INFO - 1720527995784 Marionette DEBUG 2 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:35.785Z] 12:26:35 INFO - 1720527995784 Marionette DEBUG 2 <- [1,10,null,{"value":null}]
[task 2024-07-09T12:26:35.786Z] 12:26:35 INFO - 1720527995786 Marionette DEBUG 2 -> [0,11,"WebDriver:GetWindowHandles",{}]
[task 2024-07-09T12:26:35.787Z] 12:26:35 INFO - 1720527995786 Marionette DEBUG 2 <- [1,11,null,["b071eacd-3a0c-4b1b-98dd-fabab9058567"]]
[task 2024-07-09T12:26:35.788Z] 12:26:35 INFO - 1720527995787 Marionette DEBUG 2 -> [0,12,"Marionette:SetContext",{"value":"content"}]
[task 2024-07-09T12:26:35.788Z] 12:26:35 INFO - 1720527995788 Marionette DEBUG 2 <- [1,12,null,{"value":null}]
[task 2024-07-09T12:26:35.790Z] 12:26:35 INFO - 1720527995789 Marionette DEBUG 2 -> [0,13,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:35.790Z] 12:26:35 INFO - 1720527995790 Marionette DEBUG 2 <- [1,13,null,{"value":"content"}]
[task 2024-07-09T12:26:35.791Z] 12:26:35 INFO - 1720527995791 Marionette DEBUG 2 -> [0,14,"Marionette:SetContext",{"value":"content"}]
[task 2024-07-09T12:26:35.792Z] 12:26:35 INFO - 1720527995792 Marionette DEBUG 2 <- [1,14,null,{"value":null}]
<...>
[task 2024-07-09T12:26:42.314Z] 12:26:42 INFO - 1720528002313 RemoteAgent TRACE Received DOM event focus for [object HTMLDocument]
[task 2024-07-09T12:26:42.316Z] 12:26:42 INFO - 1720528002315 Marionette DEBUG 1 <- [1,67,null,{"value":null}]
[task 2024-07-09T12:26:42.317Z] 12:26:42 INFO - 1720528002316 Marionette DEBUG 1 -> [0,68,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:42.317Z] 12:26:42 INFO - 1720528002316 Marionette DEBUG 1 <- [1,68,null,{"value":"chrome"}]
[task 2024-07-09T12:26:42.318Z] 12:26:42 INFO - 1720528002317 Marionette DEBUG 1 -> [0,69,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:42.319Z] 12:26:42 INFO - 1720528002317 Marionette DEBUG 1 <- [1,69,null,{"value":null}]
[task 2024-07-09T12:26:42.319Z] 12:26:42 INFO - 1720528002318 Marionette DEBUG 1 -> [0,70,"WebDriver:GetWindowHandle",{}]
[task 2024-07-09T12:26:42.319Z] 12:26:42 INFO - 1720528002318 Marionette DEBUG 1 <- [1,70,null,{"value":"9a2f8131-d2e6-4dde-ab64-801017b5ae06"}]
[task 2024-07-09T12:26:42.320Z] 12:26:42 INFO - 1720528002319 Marionette DEBUG 1 -> [0,71,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:42.320Z] 12:26:42 INFO - 1720528002319 Marionette DEBUG 1 <- [1,71,null,{"value":null}]
[task 2024-07-09T12:26:42.320Z] 12:26:42 INFO - 1720528002320 Marionette DEBUG 1 -> [0,72,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:42.321Z] 12:26:42 INFO - 1720528002320 Marionette DEBUG 1 <- [1,72,null,{"value":"chrome"}]
[task 2024-07-09T12:26:42.321Z] 12:26:42 INFO - 1720528002321 Marionette DEBUG 1 -> [0,73,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:42.321Z] 12:26:42 INFO - 1720528002321 Marionette DEBUG 1 <- [1,73,null,{"value":null}]
[task 2024-07-09T12:26:42.322Z] 12:26:42 INFO - 1720528002322 Marionette DEBUG 1 -> [0,74,"WebDriver:SwitchToWindow",{"handle":"9a2f8131-d2e6-4dde-ab64-801017b5ae06","focus":true}]
[task 2024-07-09T12:26:42.323Z] 12:26:42 INFO - 1720528002322 Marionette DEBUG 1 <- [1,74,null,{"value":null}]
[task 2024-07-09T12:26:42.324Z] 12:26:42 INFO - 1720528002323 Marionette DEBUG 1 -> [0,75,"WebDriver:ExecuteScript",{"script":"return gBrowser.tabs.map(tab => {\n return tab.linkedBrowser.currentURI.spec;\n });","args":[],"newSandbox":true,"sandbox":"default","line":188,"filename":"tests/browser/components/sessionstore/test/marionette/session_store_test_case.py"}]
[task 2024-07-09T12:26:42.326Z] 12:26:42 INFO - 1720528002325 Marionette DEBUG 1 <- [1,75,null,{"value":["data:text/html;charset=utf-8,<html><head><title>sit</title></head><body></body></html>"]}]
[task 2024-07-09T12:26:42.326Z] 12:26:42 INFO - 1720528002326 Marionette DEBUG 1 -> [0,76,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:42.327Z] 12:26:42 INFO - 1720528002326 Marionette DEBUG 1 <- [1,76,null,{"value":null}]
[task 2024-07-09T12:26:42.327Z] 12:26:42 INFO - 1720528002327 Marionette DEBUG 1 -> [0,77,"WebDriver:SwitchToWindow",{"handle":"9a2f8131-d2e6-4dde-ab64-801017b5ae06","focus":true}]
[task 2024-07-09T12:26:42.328Z] 12:26:42 INFO - 1720528002327 Marionette DEBUG 1 <- [1,77,null,{"value":null}]
[task 2024-07-09T12:26:42.328Z] 12:26:42 INFO - 1720528002328 Marionette DEBUG 1 -> [0,78,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:42.329Z] 12:26:42 INFO - 1720528002328 Marionette DEBUG 1 <- [1,78,null,{"value":"chrome"}]
[task 2024-07-09T12:26:42.330Z] 12:26:42 INFO - 1720528002329 Marionette DEBUG 1 -> [0,79,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:42.330Z] 12:26:42 INFO - 1720528002330 Marionette DEBUG 1 <- [1,79,null,{"value":null}]
[task 2024-07-09T12:26:42.331Z] 12:26:42 INFO - 1720528002330 Marionette DEBUG 1 -> [0,80,"WebDriver:GetWindowHandles",{}]
[task 2024-07-09T12:26:42.332Z] 12:26:42 INFO - 1720528002331 Marionette DEBUG 1 <- [1,80,null,["22281860-9364-4a98-ad8b-738f23fd44f0","9a2f8131-d2e6-4dde-ab64-801017b5ae06"]]
[task 2024-07-09T12:26:42.332Z] 12:26:42 INFO - 1720528002331 Marionette DEBUG 1 -> [0,81,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:42.332Z] 12:26:42 INFO - 1720528002331 Marionette DEBUG 1 <- [1,81,null,{"value":null}]
[task 2024-07-09T12:26:42.343Z] 12:26:42 INFO - 1720528002342 Marionette DEBUG 1 -> [0,82,"WebDriver:ExecuteAsyncScript",{"script":"function getAllBrowserWindows() {\n return Array.from(Services.wm.getEnumerator(\"navigator:browser\"));\n ... et windows = getAllBrowserWindows();\n let value = 500;\n promiseResize(value, windows[1]).then(resolve);","args":[],"newSandbox":true,"sandbox":"default","scriptTimeout":null,"line":60,"filename":"tests/browser/components/sessionstore/test/marionette/test_restore_manually.py"}]
[task 2024-07-09T12:26:42.561Z] 12:26:42 INFO - console.error: CustomizableUI:
[task 2024-07-09T12:26:42.562Z] 12:26:42 INFO - TypeError: can't access property "localName", aNode is null -- resource:///modules/CustomizableUI.sys.mjs:1724
[task 2024-07-09T12:26:42.665Z] 12:26:42 INFO - 1720528002665 Marionette DEBUG 1 <- [1,82,null,{"value":null}]
[task 2024-07-09T12:26:42.668Z] 12:26:42 INFO - 1720528002668 Marionette DEBUG 1 -> [0,83,"Marionette:AcceptConnections",{"value":false}]
[task 2024-07-09T12:26:42.669Z] 12:26:42 INFO - 1720528002669 Marionette INFO Stopped listening on port 2828
[task 2024-07-09T12:26:42.670Z] 12:26:42 INFO - 1720528002669 Marionette DEBUG 1 <- [1,83,null,{"value":null}]
[task 2024-07-09T12:26:42.672Z] 12:26:42 INFO - 1720528002672 Marionette DEBUG 1 -> [0,84,"Marionette:Quit",{}]
[task 2024-07-09T12:26:42.794Z] 12:26:42 INFO - 1720528002793 Marionette TRACE [14] MarionetteCommands actor destroyed for window id 30
[task 2024-07-09T12:26:42.795Z] 12:26:42 INFO - 1720528002794 Marionette TRACE [1] MarionetteCommands actor destroyed for window id 2
[task 2024-07-09T12:26:43.228Z] 12:26:43 INFO - 1720528003227 Marionette TRACE Received observer notification quit-application
[task 2024-07-09T12:26:43.231Z] 12:26:43 INFO - 1720528003230 Marionette TRACE Received observer notification quit-application
[task 2024-07-09T12:26:43.233Z] 12:26:43 INFO - 1720528003232 Marionette DEBUG Marionette stopped listening
[task 2024-07-09T12:26:43.233Z] 12:26:43 INFO - 1720528003233 Marionette DEBUG 1 <- [1,84,null,{"cause":"shutdown","forced":false,"in_app":true}]
[task 2024-07-09T12:26:43.239Z] 12:26:43 INFO - 1720528003239 Marionette DEBUG Closed connection 1
[task 2024-07-09T12:26:43.583Z] 12:26:43 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /tmp/tmpl8hzslub.mozrunner
[task 2024-07-09T12:26:43.704Z] 12:26:43 INFO - ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2024-07-09T12:26:43.724Z] 12:26:43 INFO - ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2024-07-09T12:26:44.911Z] 12:26:44 INFO - 1720528004911 Marionette INFO Marionette enabled
[task 2024-07-09T12:26:44.912Z] 12:26:44 INFO - 1720528004911 Marionette TRACE Received observer notification final-ui-startup
[task 2024-07-09T12:26:44.932Z] 12:26:44 INFO - 1720528004932 Marionette INFO Listening on port 2828
[task 2024-07-09T12:26:44.933Z] 12:26:44 INFO - 1720528004932 Marionette DEBUG Marionette is listening
[task 2024-07-09T12:26:45.029Z] 12:26:45 INFO - 1720528005029 Marionette DEBUG Accepted connection 0 from 127.0.0.1:44668
[task 2024-07-09T12:26:45.038Z] 12:26:45 INFO - 1720528005037 Marionette DEBUG Closed connection 0
[task 2024-07-09T12:26:45.040Z] 12:26:45 INFO - 1720528005038 Marionette DEBUG Accepted connection 1 from 127.0.0.1:44670
[task 2024-07-09T12:26:45.062Z] 12:26:45 INFO - 1720528005062 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2024-07-09T12:26:45.064Z] 12:26:45 INFO - 1720528005064 Marionette DEBUG Waiting for initial application window
[task 2024-07-09T12:26:46.351Z] 12:26:46 INFO - console.error: ({})
[task 2024-07-09T12:26:47.262Z] 12:26:47 INFO - 1720528007262 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2024-07-09T12:26:47.266Z] 12:26:47 INFO - 1720528007265 RemoteAgent TRACE [3] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=5000 waitForExplicitStart=false
[task 2024-07-09T12:26:47.269Z] 12:26:47 INFO - 1720528007265 RemoteAgent TRACE [3] ProgressListener Setting unload timer (5000ms)
[task 2024-07-09T12:26:47.272Z] 12:26:47 INFO - 1720528007266 RemoteAgent TRACE [3] Wait for initial navigation: isInitial=false, isLoadingDocument=false
[task 2024-07-09T12:26:47.275Z] 12:26:47 INFO - 1720528007266 RemoteAgent TRACE [3] Document already finished loading: about:home
[task 2024-07-09T12:26:47.278Z] 12:26:47 INFO - 1720528007266 RemoteAgent TRACE [3] ProgressListener Stop: has error=false url=about:home
[task 2024-07-09T12:26:47.283Z] 12:26:47 INFO - 1720528007277 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"efc14090-df3a-4d09-aa08-542694da9ced","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"130.0a1","platformName":"linux","unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:130.0) Gecko/20100101 Firefox/130.0","moz:buildID":"20240709112944","moz:headless":false,"moz:platformVersion":"4.4.0-1014-aws","moz:processID":5700,"moz:profile":"/tmp/tmpl8hzslub.mozrunner","moz:shutdownTimeout":60000,"pageLoadStrategy":"normal","timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"setWindowRect":true,"strictFileInteractability":true,"moz:accessibilityChecks":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2024-07-09T12:26:47.286Z] 12:26:47 INFO - 1720528007279 Marionette DEBUG 1 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:47.288Z] 12:26:47 INFO - 1720528007280 Marionette DEBUG 1 <- [1,2,null,{"value":null}]
[task 2024-07-09T12:26:47.291Z] 12:26:47 INFO - 1720528007281 Marionette DEBUG 1 -> [0,3,"WebDriver:ExecuteScript",{"script":"const lazy = {};\n ChromeUtils.defineESModuleGetters(lazy, {\n SessionStore: \"resource:///modules/ses ... ionStore.restoreLastSession();\n await closedWindowsObserver;\n }\n checkForWindowHeight();","args":[],"newSandbox":true,"sandbox":"default","line":98,"filename":"tests/browser/components/sessionstore/test/marionette/test_restore_manually.py"}]
[task 2024-07-09T12:26:47.294Z] 12:26:47 INFO - 1720528007283 RemoteAgent TRACE WebDriverProcessData actor created for PID 5700
[task 2024-07-09T12:26:47.296Z] 12:26:47 INFO - 1720528007284 Marionette TRACE [1] MarionetteCommands actor created for window id 2
[task 2024-07-09T12:26:47.300Z] 12:26:47 INFO - 1720528007294 RemoteAgent TRACE Received observer notification domwindowopened
[task 2024-07-09T12:26:47.302Z] 12:26:47 INFO - 1720528007297 Marionette DEBUG 1 <- [1,3,null,{"value":null}]
[task 2024-07-09T12:26:47.305Z] 12:26:47 INFO - 1720528007299 Marionette DEBUG 1 -> [0,4,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:47.308Z] 12:26:47 INFO - 1720528007299 Marionette DEBUG 1 <- [1,4,null,{"value":"chrome"}]
[task 2024-07-09T12:26:47.459Z] 12:26:47 INFO - console.error: CustomizableUI:
[task 2024-07-09T12:26:47.461Z] 12:26:47 INFO - TypeError: can't access property "localName", aNode is null -- resource:///modules/CustomizableUI.sys.mjs:1724
[task 2024-07-09T12:26:47.465Z] 12:26:47 INFO - 1720528007464 Marionette DEBUG 1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:47.465Z] 12:26:47 INFO - 1720528007465 Marionette DEBUG 1 <- [1,5,null,{"value":null}]
[task 2024-07-09T12:26:47.757Z] 12:26:47 INFO - 1720528007756 Marionette TRACE Received observer notification browser-delayed-startup-finished
[task 2024-07-09T12:26:47.802Z] 12:26:47 INFO - 1720528007802 Marionette TRACE Remoteness change detected. Set new top-level browsing context to 3
[task 2024-07-09T12:26:48.155Z] 12:26:48 INFO - console.error: CustomizableUI:
[task 2024-07-09T12:26:48.156Z] 12:26:48 INFO - TypeError: can't access property "localName", aNode is null -- resource:///modules/CustomizableUI.sys.mjs:1724
[task 2024-07-09T12:26:48.171Z] 12:26:48 INFO - 1720528008171 Marionette DEBUG 1 -> [0,6,"WebDriver:GetWindowHandles",{}]
[task 2024-07-09T12:26:48.172Z] 12:26:48 INFO - 1720528008171 Marionette DEBUG 1 <- [1,6,null,["2c787c1e-f0e1-40ab-b880-488c44b1cab8","52d1ed77-230e-4ad6-a481-975928e40b6c"]]
[task 2024-07-09T12:26:48.192Z] 12:26:48 INFO - console.error: CustomizableUI:
[task 2024-07-09T12:26:48.193Z] 12:26:48 INFO - TypeError: can't access property "localName", aNode is null -- resource:///modules/CustomizableUI.sys.mjs:1724
[task 2024-07-09T12:26:48.217Z] 12:26:48 INFO - 1720528008217 Marionette DEBUG 1 -> [0,7,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:48.218Z] 12:26:48 INFO - 1720528008217 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2024-07-09T12:26:48.222Z] 12:26:48 INFO - 1720528008220 Marionette DEBUG 1 -> [0,8,"WebDriver:ExecuteScript",{"script":"const lazy = {};\n ChromeUtils.defineESModuleGetters(lazy, {\n SessionStore: \"resource:///mod ... });\n let state = SessionStore.getCurrentState()\n return state.windows[1][\"height\"]","args":[],"newSandbox":true,"sandbox":"default","line":132,"filename":"tests/browser/components/sessionstore/test/marionette/test_restore_manually.py"}]
[task 2024-07-09T12:26:48.239Z] 12:26:48 INFO - 1720528008238 Marionette DEBUG 1 <- [1,8,null,{"value":500}]
[task 2024-07-09T12:26:48.244Z] 12:26:48 INFO - 1720528008243 Marionette DEBUG 1 -> [0,9,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:48.245Z] 12:26:48 INFO - 1720528008244 Marionette DEBUG 1 <- [1,9,null,{"value":"chrome"}]
[task 2024-07-09T12:26:48.246Z] 12:26:48 INFO - 1720528008245 Marionette DEBUG 1 -> [0,10,"WebDriver:DeleteSession",{}]
[task 2024-07-09T12:26:48.246Z] 12:26:48 INFO - 1720528008245 Marionette TRACE [1] MarionetteCommands actor destroyed for window id 2
[task 2024-07-09T12:26:48.248Z] 12:26:48 INFO - 1720528008248 Marionette DEBUG 1 <- [1,10,null,{"value":null}]
[task 2024-07-09T12:26:48.298Z] 12:26:48 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /tmp/tmp89urcvq2.mozrunner
[task 2024-07-09T12:26:48.758Z] 12:26:48 INFO - ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2024-07-09T12:26:48.791Z] 12:26:48 INFO - 1720528008791 Marionette INFO Marionette enabled
[task 2024-07-09T12:26:48.797Z] 12:26:48 INFO - 1720528008792 Marionette TRACE Received observer notification final-ui-startup
[task 2024-07-09T12:26:48.838Z] 12:26:48 INFO - ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2024-07-09T12:26:48.857Z] 12:26:48 INFO - 1720528008857 Marionette INFO Listening on port 2828
[task 2024-07-09T12:26:48.866Z] 12:26:48 INFO - 1720528008866 Marionette DEBUG Marionette is listening
[task 2024-07-09T12:26:48.877Z] 12:26:48 INFO - 1720528008877 Marionette DEBUG Accepted connection 0 from 127.0.0.1:44682
[task 2024-07-09T12:26:48.894Z] 12:26:48 INFO - 1720528008893 Marionette DEBUG Accepted connection 1 from 127.0.0.1:44684
[task 2024-07-09T12:26:48.895Z] 12:26:48 INFO - 1720528008894 Marionette DEBUG Closed connection 0
[task 2024-07-09T12:26:49.103Z] 12:26:49 INFO - 1720528009103 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2024-07-09T12:26:49.108Z] 12:26:49 INFO - 1720528009108 Marionette DEBUG Waiting for initial application window
[task 2024-07-09T12:26:52.047Z] 12:26:52 INFO - console.error: ({})
[task 2024-07-09T12:26:53.615Z] 12:26:53 INFO - 1720528013614 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2024-07-09T12:26:53.621Z] 12:26:53 INFO - 1720528013621 RemoteAgent TRACE [9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=5000 waitForExplicitStart=false
[task 2024-07-09T12:26:53.623Z] 12:26:53 INFO - 1720528013621 RemoteAgent TRACE [9] ProgressListener Setting unload timer (5000ms)
[task 2024-07-09T12:26:53.623Z] 12:26:53 INFO - 1720528013621 RemoteAgent TRACE [9] Wait for initial navigation: isInitial=false, isLoadingDocument=false
[task 2024-07-09T12:26:53.623Z] 12:26:53 INFO - 1720528013621 RemoteAgent TRACE [9] Document already finished loading: about:blank
[task 2024-07-09T12:26:53.624Z] 12:26:53 INFO - 1720528013621 RemoteAgent TRACE [9] ProgressListener Stop: has error=false url=about:blank
[task 2024-07-09T12:26:53.658Z] 12:26:53 INFO - 1720528013657 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"b7f494e4-1f92-42e9-b387-f801556bff03","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"130.0a1","platformName":"linux","unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:130.0) Gecko/20100101 Firefox/130.0","moz:buildID":"20240709112944","moz:headless":false,"moz:platformVersion":"4.4.0-1014-aws","moz:processID":5948,"moz:profile":"/tmp/tmp89urcvq2.mozrunner","moz:shutdownTimeout":60000,"pageLoadStrategy":"normal","timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"setWindowRect":true,"strictFileInteractability":true,"moz:accessibilityChecks":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2024-07-09T12:26:53.669Z] 12:26:53 INFO - 1720528013666 Marionette DEBUG 1 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:53.670Z] 12:26:53 INFO - 1720528013666 Marionette DEBUG 1 <- [1,2,null,{"value":null}]
[task 2024-07-09T12:26:53.670Z] 12:26:53 INFO - 1720528013668 Marionette DEBUG 1 -> [0,3,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:53.671Z] 12:26:53 INFO - 1720528013669 Marionette DEBUG 1 <- [1,3,null,{"value":"chrome"}]
[task 2024-07-09T12:26:53.671Z] 12:26:53 INFO - 1720528013669 Marionette DEBUG 1 -> [0,4,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:53.672Z] 12:26:53 INFO - 1720528013669 Marionette DEBUG 1 <- [1,4,null,{"value":null}]
[task 2024-07-09T12:26:53.673Z] 12:26:53 INFO - 1720528013672 Marionette DEBUG 1 -> [0,5,"WebDriver:GetWindowHandles",{}]
[task 2024-07-09T12:26:53.677Z] 12:26:53 INFO - 1720528013677 Marionette DEBUG 1 <- [1,5,null,["7d556fe8-d682-4484-80d0-a331741d132d"]]
[task 2024-07-09T12:26:53.679Z] 12:26:53 INFO - 1720528013679 Marionette DEBUG 1 -> [0,6,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:53.680Z] 12:26:53 INFO - 1720528013679 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2024-07-09T12:26:53.681Z] 12:26:53 INFO - 1720528013681 Marionette DEBUG 1 -> [0,7,"Marionette:GetContext",{}]
[task 2024-07-09T12:26:53.681Z] 12:26:53 INFO - 1720528013681 Marionette DEBUG 1 <- [1,7,null,{"value":"chrome"}]
[task 2024-07-09T12:26:53.682Z] 12:26:53 INFO - 1720528013682 Marionette DEBUG 1 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2024-07-09T12:26:53.683Z] 12:26:53 INFO - 1720528013682 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2024-07-09T12:26:53.684Z] 12:26:53 INFO - 1720528013683 Marionette DEBUG 1 -> [0,9,"WebDriver:GetWindowHandles",{}]
[task 2024-07-09T12:26:53.684Z] 12:26:53 INFO - 1720528013684 Marionette DEBUG 1 <- [1,9,null,["dff360f4-6374-444b-bb72-83e64792c944"]]
[task 2024-07-09T12:26:53.685Z] 12:26:53 INFO - 1720528013685 Marionette DEBUG 1 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:26:53.686Z] 12:26:53 INFO - 1720528013685 Marionette DEBUG 1 <- [1,10,null,{"value":null}]
[task 2024-07-09T12:26:53.687Z] 12:26:53 INFO - 1720528013687 Marionette DEBUG 1 -> [0,11,"WebDriver:DeleteSession",{}]
[task 2024-07-09T12:26:53.697Z] 12:26:53 INFO - 1720528013694 Marionette DEBUG 1 <- [1,11,null,{"value":null}]
[task 2024-07-09T12:26:53.701Z] 12:26:53 INFO - TEST-PASS | browser/components/sessionstore/test/marionette/test_restore_manually.py TestSessionRestoreManually.test_restore | took 17955ms
[task 2024-07-09T12:26:53.702Z] 12:26:53 INFO - TEST-START | browser/components/sessionstore/test/marionette/test_restore_manually_with_pinned_tabs.py TestSessionRestoreWithPinnedTabs.test_no_restore_with_quit
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•2 years ago
|
||
[task 2024-07-09T12:33:47.987Z] 12:33:47 INFO - 1720528427986 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2024-07-09T12:33:47.994Z] 12:33:47 INFO - 1720528427994 RemoteAgent TRACE [9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=5000 waitForExplicitStart=false
[task 2024-07-09T12:33:48.002Z] 12:33:48 INFO - 1720528428001 RemoteAgent TRACE [9] ProgressListener Setting unload timer (5000ms)
[task 2024-07-09T12:33:48.003Z] 12:33:48 INFO - 1720528428003 RemoteAgent TRACE [9] Wait for initial navigation: isInitial=false, isLoadingDocument=false
[task 2024-07-09T12:33:48.003Z] 12:33:48 INFO - 1720528428003 RemoteAgent TRACE [9] Document already finished loading: about:blank
[task 2024-07-09T12:33:48.004Z] 12:33:48 INFO - 1720528428004 RemoteAgent TRACE [9] ProgressListener Stop: has error=false url=about:blank
[task 2024-07-09T12:33:48.027Z] 12:33:48 INFO - 1720528428026 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"415c16b2-ae6d-4aea-8607-e03b5c533c8a","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"130.0a1","platformName":"linux","unhandledPromptBehavior":"dismiss and notify","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:130.0) Gecko/20100101 Firefox/130.0","moz:buildID":"20240709112944","moz:headless":false,"moz:platformVersion":"4.4.0-1014-aws","moz:processID":23600,"moz:profile":"/tmp/tmp3ypuhdrr.mozrunner","moz:shutdownTimeout":60000,"pageLoadStrategy":"normal","timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"setWindowRect":true,"strictFileInteractability":true,"moz:accessibilityChecks":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2024-07-09T12:33:48.054Z] 12:33:48 INFO - 1720528428054 Marionette DEBUG 1 -> [0,2,"Marionette:SetContext",{"value":"content"}]
[task 2024-07-09T12:33:48.054Z] 12:33:48 INFO - 1720528428054 Marionette DEBUG 1 <- [1,2,null,{"value":null}]
[task 2024-07-09T12:33:48.060Z] 12:33:48 INFO - 1720528428059 Marionette DEBUG 1 -> [0,3,"Marionette:GetContext",{}]
[task 2024-07-09T12:33:48.061Z] 12:33:48 INFO - 1720528428061 Marionette DEBUG 1 <- [1,3,null,{"value":"content"}]
[task 2024-07-09T12:33:48.063Z] 12:33:48 INFO - 1720528428062 Marionette DEBUG 1 -> [0,4,"Marionette:SetContext",{"value":"chrome"}]
[task 2024-07-09T12:33:48.063Z] 12:33:48 INFO - 1720528428062 Marionette DEBUG 1 <- [1,4,null,{"value":null}]
[task 2024-07-09T12:33:48.065Z] 12:33:48 INFO - 1720528428065 Marionette DEBUG 1 -> [0,5,"WebDriver:ExecuteScript",{"script":"return Services.dirsvc.get(\"UpdRootD\", Ci.nsIFile).parent.parent.path;","args":[],"newSandbox":true,"sandbox":"default","line":41,"filename":"tests/netwerk/test/marionette/test_purge_http_cache_at_shutdown.py"}]
[task 2024-07-09T12:33:48.079Z] 12:33:48 INFO - 1720528428078 RemoteAgent TRACE WebDriverProcessData actor created for PID 23600
[task 2024-07-09T12:33:48.080Z] 12:33:48 INFO - 1720528428080 Marionette TRACE [1] MarionetteCommands actor created for window id 2
[task 2024-07-09T12:33:48.089Z] 12:33:48 INFO - 1720528428089 Marionette DEBUG 1 <- [1,5,null,{"value":"/builds/worker/workspace/build"}]
[task 2024-07-09T12:33:48.091Z] 12:33:48 INFO - 1720528428090 Marionette DEBUG 1 -> [0,6,"Marionette:SetContext",{"value":"content"}]
[task 2024-07-09T12:33:48.091Z] 12:33:48 INFO - 1720528428090 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2024-07-09T12:33:48.093Z] 12:33:48 INFO - 1720528428092 Marionette DEBUG 1 -> [0,7,"Marionette:AcceptConnections",{"value":false}]
[task 2024-07-09T12:33:48.093Z] 12:33:48 INFO - 1720528428093 Marionette INFO Stopped listening on port 2828
[task 2024-07-09T12:33:48.094Z] 12:33:48 INFO - 1720528428094 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2024-07-09T12:33:48.100Z] 12:33:48 INFO - 1720528428100 Marionette DEBUG 1 -> [0,8,"Marionette:Quit",{}]
[task 2024-07-09T12:33:48.170Z] 12:33:48 INFO - 1720528428170 Marionette TRACE [1] MarionetteCommands actor destroyed for window id 2
[task 2024-07-09T12:33:48.523Z] 12:33:48 INFO - 1720528428523 Marionette TRACE Received observer notification quit-application
[task 2024-07-09T12:33:48.527Z] 12:33:48 INFO - 1720528428526 Marionette TRACE Received observer notification quit-application
[task 2024-07-09T12:33:48.528Z] 12:33:48 INFO - 1720528428527 Marionette DEBUG Marionette stopped listening
[task 2024-07-09T12:33:48.528Z] 12:33:48 INFO - 1720528428527 Marionette DEBUG 1 <- [1,8,null,{"cause":"shutdown","forced":false,"in_app":true}]
[task 2024-07-09T12:33:48.538Z] 12:33:48 INFO - 1720528428538 Marionette DEBUG Closed connection 1
[task 2024-07-09T12:33:48.992Z] 12:33:48 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /tmp/tmp1sefczuy.mozrunner
[task 2024-07-09T12:33:49.444Z] 12:33:49 INFO - Inconsistency detected by ld.so: ../elf/dl-tls.c: 481: _dl_allocate_tls_init: Assertion `listp->slotinfo[cnt].gen <= GL(dl_tls_generation)' failed!
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - TEST-UNEXPECTED-ERROR | netwerk/test/marionette/test_purge_http_cache_at_shutdown.py PurgeHTTPCacheAtShutdownTestCase.test_asetup | OSError: Process has been unexpectedly closed (Exit code: 127) (Reason: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors)
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - Traceback (most recent call last):
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_harness/marionette_test/testcases.py", line 231, in run
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - self.tearDown()
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/netwerk/test/marionette/test_purge_http_cache_at_shutdown.py", line 28, in tearDown
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - super().tearDown()
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_harness/marionette_test/testcases.py", line 406, in tearDown
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - self.marionette.start_session()
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/decorators.py", line 34, in _
[task 2024-07-09T12:33:49.507Z] 12:33:49 INFO - m._handle_socket_failure()
[task 2024-07-09T12:33:49.508Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/marionette.py", line 853, in _handle_socket_failure
[task 2024-07-09T12:33:49.508Z] 12:33:49 INFO - reraise(
[task 2024-07-09T12:33:49.508Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/six.py", line 718, in reraise
[task 2024-07-09T12:33:49.509Z] 12:33:49 INFO - raise value.with_traceback(tb)
[task 2024-07-09T12:33:49.509Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2024-07-09T12:33:49.510Z] 12:33:49 INFO - return func(*args, **kwargs)
[task 2024-07-09T12:33:49.510Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/marionette.py", line 1363, in start_session
[task 2024-07-09T12:33:49.510Z] 12:33:49 INFO - self.start_binary(timeout)
[task 2024-07-09T12:33:49.510Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/marionette.py", line 660, in start_binary
[task 2024-07-09T12:33:49.511Z] 12:33:49 INFO - reraise(IOError, IOError(msg.format(timeout)), sys.exc_info()[2])
[task 2024-07-09T12:33:49.511Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/six.py", line 718, in reraise
[task 2024-07-09T12:33:49.512Z] 12:33:49 INFO - raise value.with_traceback(tb)
[task 2024-07-09T12:33:49.512Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/marionette.py", line 650, in start_binary
[task 2024-07-09T12:33:49.513Z] 12:33:49 INFO - self.raise_for_port(timeout=timeout)
[task 2024-07-09T12:33:49.513Z] 12:33:49 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/marionette.py", line 744, in raise_for_port
[task 2024-07-09T12:33:49.513Z] 12:33:49 INFO - raise socket.timeout(
[task 2024-07-09T12:33:49.514Z] 12:33:49 INFO - TEST-INFO took 6831ms
|
||
Comment 3•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
|
Reporter | |
Comment 4•2 years ago
|
||
| treeherder | ||
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=469465279&repo=mozilla-beta
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 7•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: REOPENED → RESOLVED
Closed: 2 years ago → 1 year ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•