Closed
Bug 1730894
Opened 4 years ago
Closed 4 years ago
Intermittent [tier 2] testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_frameset | marionette_driver.errors.NoSuchWindowException: Browsing context has been discarded
Categories
(Testing :: Marionette Client and Harness, defect, P5)
Testing
Marionette Client and Harness
Tracking
(Not tracked)
RESOLVED
WORKSFORME
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: mlaza [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=351613480&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZHnk4rANQ2OhfQ9fkW8qkA/runs/0/artifacts/public/logs/live_backing.log
[task 2021-09-15T10:53:20.512Z] 10:53:20 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_frameset
[task 2021-09-15T10:53:20.515Z] 10:53:20 INFO - 1631703200514 Marionette DEBUG Accepted connection 497 from 127.0.0.1:37778
[task 2021-09-15T10:53:20.517Z] 10:53:20 INFO - 1631703200516 Marionette DEBUG Closed connection 496
[task 2021-09-15T10:53:20.520Z] 10:53:20 INFO - 1631703200519 Marionette DEBUG 497 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-09-15T10:53:20.529Z] 10:53:20 INFO - 1631703200529 Marionette DEBUG 497 <- [1,1,null,{"sessionId":"34e2dcbf-217e-41d2-9b2e-93b764ad3bdb","capabilities":{"browserName":"firefox","browserVersion":"94.0a ... .mozrunner","moz:shutdownTimeout":300000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-09-15T10:53:20.533Z] 10:53:20 INFO - 1631703200533 Marionette DEBUG 497 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-09-15T10:53:20.535Z] 10:53:20 INFO - 1631703200535 Marionette DEBUG 497 <- [1,2,null,{"value":null}]
[task 2021-09-15T10:53:20.539Z] 10:53:20 INFO - 1631703200538 Marionette DEBUG 497 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-09-15T10:53:20.541Z] 10:53:20 INFO - 1631703200541 Marionette DEBUG 497 <- [1,3,null,{"value":null}]
[task 2021-09-15T10:53:20.545Z] 10:53:20 INFO - 1631703200545 Marionette DEBUG 497 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-09-15T10:53:20.548Z] 10:53:20 INFO - 1631703200547 Marionette DEBUG 497 <- [1,4,null,{"value":null}]
[task 2021-09-15T10:53:20.552Z] 10:53:20 INFO - 1631703200551 Marionette DEBUG 497 -> [0,5,"WebDriver:GetChromeWindowHandle",{}]
[task 2021-09-15T10:53:20.554Z] 10:53:20 INFO - 1631703200554 Marionette DEBUG 497 <- [1,5,null,{"value":"42b817b8-cbd6-4903-9017-183ed87f9bad"}]
[task 2021-09-15T10:53:20.558Z] 10:53:20 INFO - 1631703200557 Marionette DEBUG 497 -> [0,6,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-09-15T10:53:20.560Z] 10:53:20 INFO - 1631703200559 Marionette DEBUG 497 <- [1,6,null,["42b817b8-cbd6-4903-9017-183ed87f9bad"]]
[task 2021-09-15T10:53:20.563Z] 10:53:20 INFO - 1631703200562 Marionette DEBUG 497 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2021-09-15T10:53:20.564Z] 10:53:20 INFO - 1631703200564 Marionette DEBUG 497 <- [1,7,null,{"value":"6a522b11-2bcc-4175-8dc3-2fdabef72d92"}]
[task 2021-09-15T10:53:20.566Z] 10:53:20 INFO - 1631703200565 Marionette DEBUG 497 -> [0,8,"WebDriver:GetWindowHandles",{}]
[task 2021-09-15T10:53:20.567Z] 10:53:20 INFO - 1631703200567 Marionette DEBUG 497 <- [1,8,null,["6a522b11-2bcc-4175-8dc3-2fdabef72d92"]]
[task 2021-09-15T10:53:20.569Z] 10:53:20 INFO - 1631703200569 Marionette DEBUG 497 -> [0,9,"WebDriver:GetWindowHandles",{}]
[task 2021-09-15T10:53:20.571Z] 10:53:20 INFO - 1631703200570 Marionette DEBUG 497 <- [1,9,null,["6a522b11-2bcc-4175-8dc3-2fdabef72d92"]]
[task 2021-09-15T10:53:20.572Z] 10:53:20 INFO - 1631703200572 Marionette DEBUG 497 -> [0,10,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2021-09-15T10:53:20.588Z] 10:53:20 INFO - 1631703200587 Marionette TRACE Received DOM event TabOpen for [object XULElement]
[task 2021-09-15T10:53:20.712Z] 10:53:20 INFO - 1631703200711 Marionette TRACE Received event beforeunload for about:blank
[task 2021-09-15T10:53:20.731Z] 10:53:20 INFO - 1631703200730 Marionette TRACE Received event pagehide for about:blank
[task 2021-09-15T10:53:20.765Z] 10:53:20 INFO - 1631703200764 Marionette TRACE Received event DOMContentLoaded for about:blank
[task 2021-09-15T10:53:20.776Z] 10:53:20 INFO - 1631703200775 Marionette TRACE Received event pageshow for about:blank
[task 2021-09-15T10:53:20.778Z] 10:53:20 INFO - 1631703200777 Marionette DEBUG 497 <- [1,10,null,{"handle":"eeed7887-02b8-4147-9e77-6a4af07e8abe","type":"tab"}]
[task 2021-09-15T10:53:20.783Z] 10:53:20 INFO - 1631703200782 Marionette DEBUG 497 -> [0,11,"WebDriver:GetWindowHandles",{}]
[task 2021-09-15T10:53:20.790Z] 10:53:20 INFO - 1631703200789 Marionette DEBUG 497 <- [1,11,null,["6a522b11-2bcc-4175-8dc3-2fdabef72d92","eeed7887-02b8-4147-9e77-6a4af07e8abe"]]
[task 2021-09-15T10:53:20.793Z] 10:53:20 INFO - 1631703200793 Marionette DEBUG 497 -> [0,12,"WebDriver:GetWindowHandles",{}]
[task 2021-09-15T10:53:20.796Z] 10:53:20 INFO - 1631703200795 Marionette DEBUG 497 <- [1,12,null,["6a522b11-2bcc-4175-8dc3-2fdabef72d92","eeed7887-02b8-4147-9e77-6a4af07e8abe"]]
[task 2021-09-15T10:53:20.798Z] 10:53:20 INFO - 1631703200798 Marionette DEBUG 497 -> [0,13,"WebDriver:SwitchToWindow",{"handle":"eeed7887-02b8-4147-9e77-6a4af07e8abe","focus":true}]
[task 2021-09-15T10:53:20.814Z] 10:53:20 INFO - 1631703200814 Marionette TRACE Received DOM event TabSelect for [object XULElement]
[task 2021-09-15T10:53:20.831Z] 10:53:20 INFO - 1631703200830 Marionette DEBUG 497 <- [1,13,null,{"value":null}]
[task 2021-09-15T10:53:20.840Z] 10:53:20 INFO - 1631703200840 Marionette DEBUG 497 -> [0,14,"WebDriver:GetTimeouts",{}]
[task 2021-09-15T10:53:20.841Z] 10:53:20 INFO - 1631703200841 Marionette DEBUG 497 <- [1,14,null,{"implicit":0,"pageLoad":300000,"script":30000}]
[task 2021-09-15T10:53:20.844Z] 10:53:20 INFO - 1631703200844 Marionette DEBUG 497 -> [0,15,"WebDriver:ExecuteScript",{"script":"return window.history.length;","args":[],"newSandbox":true,"sandbox":"default","line":77,"filename":"tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py"}]
[task 2021-09-15T10:53:20.850Z] 10:53:20 INFO - 1631703200846 Marionette TRACE [704] MarionetteCommands actor created for window id 8589934649
[task 2021-09-15T10:53:20.854Z] 10:53:20 INFO - 1631703200854 Marionette DEBUG 497 <- [1,15,null,{"value":1}]
[task 2021-09-15T10:53:20.856Z] 10:53:20 INFO - 1631703200856 Marionette DEBUG 497 -> [0,16,"WebDriver:Navigate",{"url":"http://127.0.0.1:41563/frameset.html"}]
[task 2021-09-15T10:53:20.864Z] 10:53:20 INFO - 1631703200864 Marionette TRACE [704] Received event beforeunload for about:blank
[task 2021-09-15T10:53:20.888Z] 10:53:20 INFO - 1631703200888 Marionette TRACE Remoteness change detected. Set new top-level browsing context to 706
...
[task 2021-09-15T10:53:22.271Z] 10:53:22 INFO - SUMMARY: AddressSanitizer: SEGV (/builds/worker/workspace/build/application/firefox/libxul.so+0xdc3014b)
[task 2021-09-15T10:53:22.271Z] 10:53:22 INFO - ==4017==ABORTING
[task 2021-09-15T10:53:22.316Z] 10:53:22 INFO - llvm-symbolizer: Unknown command line argument '--inlines'. Try: '/usr/bin/llvm-symbolizer -help'
[task 2021-09-15T10:53:22.317Z] 10:53:22 INFO - llvm-symbolizer: Did you mean '-inlining'?
[task 2021-09-15T10:53:22.349Z] 10:53:22 INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x39008C,name=PContent::Msg_FlushTabState) Channel error: cannot send/recv
[task 2021-09-15T10:53:22.350Z] 10:53:22 INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x390143,name=PContent::Msg_CommitBrowsingContextTransaction) Channel error: cannot send/recv
[task 2021-09-15T10:53:22.351Z] 10:53:22 INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x2300A1,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
[task 2021-09-15T10:53:22.353Z] 10:53:22 INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x2300A1,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
[task 2021-09-15T10:53:22.354Z] 10:53:22 INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x2300A1,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
[task 2021-09-15T10:53:22.447Z] 10:53:22 INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x390078,name=PContent::Msg_DestroyBrowsingContextGroup) Channel error: cannot send/recv
[task 2021-09-15T10:53:22.452Z] 10:53:22 INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x390078,name=PContent::Msg_DestroyBrowsingContextGroup) Channel error: cannot send/recv
[task 2021-09-15T10:53:22.455Z] 10:53:22 INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x390078,name=PContent::Msg_DestroyBrowsingContextGroup) Channel error: cannot send/recv
[task 2021-09-15T10:53:22.473Z] 10:53:22 INFO - 1631703202472 Marionette TRACE Remoteness change detected. Set new top-level browsing context to 712
[task 2021-09-15T10:53:22.485Z] 10:53:22 ERROR - A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2021-09-15T10:53:22.490Z] 10:53:22 INFO - DEBUG: Adding blocker SessionStore: flushing all windows for phase quit-application-granted
[task 2021-09-15T10:53:22.492Z] 10:53:22 INFO - DEBUG: Starting phase quit-application-granted
[task 2021-09-15T10:53:22.515Z] 10:53:22 INFO - DEBUG: Spinning the event loop
[task 2021-09-15T10:53:22.519Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: wikipedia@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.521Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: webcompat@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.522Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: webcompat-reporter@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.524Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: screenshots@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.524Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: pictureinpicture@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.525Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: google@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.526Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: formautofill@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.528Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: doh-rollout@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.531Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: default-theme@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.532Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: ddg@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.533Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: bing@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.534Z] 10:53:22 INFO - DEBUG: Adding blocker Extension shutdown: amazondotcom@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.620Z] 10:53:22 INFO - DEBUG: Completed blocker XPIProvider shutdown for phase quit-application-granted
[task 2021-09-15T10:53:22.663Z] 10:53:22 INFO - 1631703202662 Marionette TRACE [712] Received event beforeunload for about:blank
[task 2021-09-15T10:53:22.667Z] 10:53:22 INFO - 1631703202663 Marionette TRACE [712] Received event beforeunload for about:blank
[task 2021-09-15T10:53:22.677Z] 10:53:22 INFO - DEBUG: Completed blocker SessionStore: flushing all windows for phase quit-application-granted
[task 2021-09-15T10:53:22.677Z] 10:53:22 INFO - DEBUG: Finished phase quit-application-granted
[task 2021-09-15T10:53:22.679Z] 10:53:22 INFO - DEBUG: Adding blocker ShieldRecipeClient: Cleaning up for phase profile-before-change
[task 2021-09-15T10:53:22.682Z] 10:53:22 INFO - 1631703202682 Marionette TRACE Received observer notification quit-application
[task 2021-09-15T10:53:22.685Z] 10:53:22 INFO - 1631703202682 Marionette INFO Stopped listening on port 2828
[task 2021-09-15T10:53:22.687Z] 10:53:22 INFO - 1631703202683 Marionette DEBUG Marionette stopped listening
[task 2021-09-15T10:53:22.697Z] 10:53:22 INFO - DEBUG: Adding blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2021-09-15T10:53:22.757Z] 10:53:22 INFO - 1631703202756 Marionette TRACE Canceled page load listener because the top-browsing context has been closed
[task 2021-09-15T10:53:22.761Z] 10:53:22 INFO - 1631703202760 Marionette DEBUG 497 <- [1,19,null,{"value":null}]
[task 2021-09-15T10:53:22.865Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: wikipedia@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.870Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: webcompat@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.872Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: webcompat-reporter@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.872Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: screenshots@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.872Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: pictureinpicture@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.872Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: google@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.873Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: formautofill@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.875Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: doh-rollout@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.875Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: default-theme@mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.876Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: ddg@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.876Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: bing@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.877Z] 10:53:22 INFO - DEBUG: Completed blocker Extension shutdown: amazondotcom@search.mozilla.org for phase profile-change-teardown
[task 2021-09-15T10:53:22.878Z] 10:53:22 INFO - DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2021-09-15T10:53:22.881Z] 10:53:22 INFO - DEBUG: Completed blocker ShieldRecipeClient: Cleaning up for phase profile-before-change
[task 2021-09-15T10:53:22.913Z] 10:53:22 INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-09-15T10:53:22.916Z] 10:53:22 INFO - 1631703202916 Marionette DEBUG 497 -> [0,20,"WebDriver:GetCurrentURL",{}]
[task 2021-09-15T10:53:22.918Z] 10:53:22 INFO - 1631703202917 Marionette DEBUG 497 <- [1,20,{"error":"no such window","message":"Browsing context has been discarded","stacktrace":"WebDriverError@chrome://remote/ ... ote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"},null]
[task 2021-09-15T10:53:22.921Z] 10:53:22 INFO - 1631703202921 Marionette DEBUG 497 -> [0,21,"Marionette:GetContext",{}]
[task 2021-09-15T10:53:22.923Z] 10:53:22 INFO - 1631703202922 Marionette DEBUG 497 <- [1,21,null,{"value":"content"}]
[task 2021-09-15T10:53:22.924Z] 10:53:22 INFO - 1631703202923 Marionette DEBUG 497 -> [0,22,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-09-15T10:53:22.925Z] 10:53:22 INFO - 1631703202924 Marionette DEBUG 497 <- [1,22,null,{"value":null}]
[task 2021-09-15T10:53:22.926Z] 10:53:22 INFO - 1631703202926 Marionette DEBUG 497 -> [0,23,"WebDriver:TakeScreenshot",{"id":null,"full":true,"hash":false,"scroll":true}]
[task 2021-09-15T10:53:22.928Z] 10:53:22 INFO - 1631703202927 Marionette DEBUG 497 <- [1,23,{"error":"no such window","message":"Browsing context has been discarded","stacktrace":"WebDriverError@chrome://remote/ ... ote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"},null]
[task 2021-09-15T10:53:22.929Z] 10:53:22 INFO - 1631703202929 Marionette DEBUG 497 -> [0,24,"Marionette:SetContext",{"value":"content"}]
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - Failed to gather test failure debug: Browsing context has been discarded
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - stacktrace:
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm:181:5
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - NoSuchWindowError@chrome://remote/content/shared/webdriver/Errors.jsm:415:5
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - assert.that/<@chrome://remote/content/shared/webdriver/Assert.jsm:435:13
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - assert.open@chrome://remote/content/shared/webdriver/Assert.jsm:143:4
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - GeckoDriver.prototype.takeScreenshot@chrome://remote/content/marionette/driver.js:2186:10
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - despatch@chrome://remote/content/marionette/server.js:306:40
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - execute@chrome://remote/content/marionette/server.js:279:16
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - onPacket/<@chrome://remote/content/marionette/server.js:252:20
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - onPacket@chrome://remote/content/marionette/server.js:253:9
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING - _onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20
[task 2021-09-15T10:53:22.932Z] 10:53:22 WARNING -
[task 2021-09-15T10:53:22.932Z] 10:53:22 INFO - 1631703202929 Marionette DEBUG 497 <- [1,24,null,{"value":null}]
[task 2021-09-15T10:53:22.937Z] 10:53:22 INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_frameset | marionette_driver.errors.NoSuchWindowException: Browsing context has been discarded
[task 2021-09-15T10:53:22.937Z] 10:53:22 INFO - stacktrace:
[task 2021-09-15T10:53:22.937Z] 10:53:22 INFO - WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm:181:5
[task 2021-09-15T10:53:22.937Z] 10:53:22 INFO - NoSuchWindowError@chrome://remote/content/shared/webdriver/Errors.jsm:415:5
[task 2021-09-15T10:53:22.937Z] 10:53:22 INFO - assert.that/<@chrome://remote/content/shared/webdriver/Assert.jsm:435:13
[task 2021-09-15T10:53:22.937Z] 10:53:22 INFO - assert.open@chrome://remote/content/shared/webdriver/Assert.jsm:143:4
[task 2021-09-15T10:53:22.937Z] 10:53:22 INFO - GeckoDriver.prototype.getCurrentUrl@chrome://remote/content/marionette/driver.js:825:10
[task 2021-09-15T10:53:22.937Z] 10:53:22 INFO - despatch@chrome://remote/content/marionette/server.js:306:40
[task 2021-09-15T10:53:22.937Z] 10:53:22 INFO - execute@chrome://remote/content/marionette/server.js:279:16
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - onPacket/<@chrome://remote/content/marionette/server.js:252:20
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - onPacket@chrome://remote/content/marionette/server.js:253:9
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - _onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - Traceback (most recent call last):
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_harness/marionette_test/testcases.py", line 202, in run
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - testMethod()
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 496, in test_frameset
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - self.run_bfcache_test(test_pages)
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 415, in run_bfcache_test
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - check_page_status(page, index + 1)
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 393, in check_page_status
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - self.assertEqual(self.marionette.get_url(), page["url"])
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 1481, in get_url
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - return self._send_message("WebDriver:GetCurrentURL", key="value")
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - return func(*args, **kwargs)
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 630, in _send_message
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - self._handle_error(err)
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 652, in _handle_error
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - raise errors.lookup(error)(message, stacktrace=stacktrace)
[task 2021-09-15T10:53:22.938Z] 10:53:22 INFO - TEST-INFO took 2423ms
[task 2021-09-15T10:53:22.939Z] 10:53:22 INFO - 1631703202939 Marionette DEBUG 497 -> [0,25,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-09-15T10:53:22.940Z] 10:53:22 INFO - 1631703202940 Marionette DEBUG 497 <- [1,25,null,{"value":null}]
[task 2021-09-15T10:53:22.942Z] 10:53:22 INFO - 1631703202941 Marionette DEBUG 497 -> [0,26,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-09-15T10:53:22.943Z] 10:53:22 INFO - 1631703202942 Marionette DEBUG 497 <- [1,26,null,{"value":null}]
[task 2021-09-15T10:53:22.944Z] 10:53:22 INFO - 1631703202944 Marionette DEBUG 497 -> [0,27,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-09-15T10:53:22.945Z] 10:53:22 INFO - 1631703202945 Marionette DEBUG 497 <- [1,27,null,{"value":null}]
[task 2021-09-15T10:53:22.947Z] 10:53:22 INFO - 1631703202946 Marionette DEBUG 497 -> [0,28,"WebDriver:GetWindowHandles",{}]
[task 2021-09-15T10:53:22.947Z] 10:53:22 INFO - 1631703202947 Marionette DEBUG 497 <- [1,28,null,[]]
[task 2021-09-15T10:53:22.949Z] 10:53:22 INFO - 1631703202949 Marionette DEBUG 497 -> [0,29,"Marionette:GetContext",{}]
[task 2021-09-15T10:53:22.950Z] 10:53:22 INFO - 1631703202950 Marionette DEBUG 497 <- [1,29,null,{"value":"content"}]
[task 2021-09-15T10:53:22.952Z] 10:53:22 INFO - 1631703202951 Marionette DEBUG 497 -> [0,30,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-09-15T10:53:22.952Z] 10:53:22 INFO - 1631703202952 Marionette DEBUG 497 <- [1,30,null,{"value":null}]
[task 2021-09-15T10:53:22.954Z] 10:53:22 INFO - 1631703202954 Marionette DEBUG 497 -> [0,31,"WebDriver:TakeScreenshot",{"id":null,"full":true,"hash":false,"scroll":true}]
[task 2021-09-15T10:53:22.955Z] 10:53:22 INFO - 1631703202955 Marionette DEBUG 497 <- [1,31,{"error":"no such window","message":"Browsing context has been discarded","stacktrace":"WebDriverError@chrome://remote/ ... ote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"},null]
[task 2021-09-15T10:53:22.957Z] 10:53:22 INFO - 1631703202957 Marionette DEBUG 497 -> [0,32,"Marionette:SetContext",{"value":"content"}]
[task 2021-09-15T10:53:22.958Z] 10:53:22 INFO - 1631703202958 Marionette DEBUG 497 <- [1,32,null,{"value":null}]
[task 2021-09-15T10:53:22.961Z] 10:53:22 WARNING - Failed to gather test failure debug: Browsing context has been discarded
[task 2021-09-15T10:53:22.962Z] 10:53:22 WARNING - stacktrace:
[task 2021-09-15T10:53:22.962Z] 10:53:22 WARNING - WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm:181:5
[task 2021-09-15T10:53:22.962Z] 10:53:22 WARNING - NoSuchWindowError@chrome://remote/content/shared/webdriver/Errors.jsm:415:5
[task 2021-09-15T10:53:22.962Z] 10:53:22 WARNING - assert.that/<@chrome://remote/content/shared/webdriver/Assert.jsm:435:13
[task 2021-09-15T10:53:22.962Z] 10:53:22 WARNING - assert.open@chrome://remote/content/shared/webdriver/Assert.jsm:143:4
[task 2021-09-15T10:53:22.962Z] 10:53:22 WARNING - GeckoDriver.prototype.takeScreenshot@chrome://remote/content/marionette/driver.js:2186:10
[task 2021-09-15T10:53:22.963Z] 10:53:22 WARNING - despatch@chrome://remote/content/marionette/server.js:306:40
[task 2021-09-15T10:53:22.963Z] 10:53:22 WARNING - execute@chrome://remote/content/marionette/server.js:279:16
[task 2021-09-15T10:53:22.963Z] 10:53:22 WARNING - onPacket/<@chrome://remote/content/marionette/server.js:252:20
[task 2021-09-15T10:53:22.963Z] 10:53:22 WARNING - onPacket@chrome://remote/content/marionette/server.js:253:9
[task 2021-09-15T10:53:22.963Z] 10:53:22 WARNING - _onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20
[task 2021-09-15T10:53:22.963Z] 10:53:22 WARNING -
[task 2021-09-15T10:53:22.963Z] 10:53:22 ERROR - test_end for testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_frameset logged while not in progress. Logged with data: {"message": "IndexError: list index out of range", "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_navigation.py\", line 71, 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 37, in close_all_tabs\n self.start_tab = current_window_handles[0]\n", "extra": {"class_name": "test_navigation.TestBackForwardNavigation", "method_name": "test_frameset"}, "test": "testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_frameset", "status": "ERROR"}
[task 2021-09-15T10:53:22.964Z] 10:53:22 INFO - 1631703202963 Marionette DEBUG 497 -> [0,33,"WebDriver:DeleteSession",{}]
[task 2021-09-15T10:53:22.967Z] 10:53:22 INFO - 1631703202966 Marionette DEBUG 497 <- [1,33,{"error":"unknown error","message":"[Exception... \"Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE ... ote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"},null]
[task 2021-09-15T10:53:22.969Z] 10:53:22 INFO - Marionette threw an error: [Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsICertOverrideService.setDisableAllSecurityChecksAndLetAttackersInterceptMyData]" nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)" location: "JS frame :: chrome://remote/content/marionette/cert.js :: allowAllCerts.disable :: line 55" data: no]
[task 2021-09-15T10:53:22.969Z] 10:53:22 INFO - allowAllCerts.disable@chrome://remote/content/marionette/cert.js:55:23
[task 2021-09-15T10:53:22.969Z] 10:53:22 INFO - destroy@chrome://remote/content/shared/webdriver/Session.jsm:202:19
[task 2021-09-15T10:53:22.969Z] 10:53:22 INFO - deleteSession@chrome://remote/content/webdriver-bidi/WebDriverBiDi.jsm:132:18
[task 2021-09-15T10:53:22.969Z] 10:53:22 INFO - GeckoDriver.prototype.deleteSession@chrome://remote/content/marionette/driver.js:2145:31
[task 2021-09-15T10:53:22.969Z] 10:53:22 INFO - despatch@chrome://remote/content/marionette/server.js:306:40
[task 2021-09-15T10:53:22.969Z] 10:53:22 INFO - execute@chrome://remote/content/marionette/server.js:279:16
[task 2021-09-15T10:53:22.969Z] 10:53:22 INFO - onPacket/<@chrome://remote/content/marionette/server.js:252:20
[task 2021-09-15T10:53:22.970Z] 10:53:22 INFO - onPacket@chrome://remote/content/marionette/server.js:253:9
[task 2021-09-15T10:53:22.970Z] 10:53:22 INFO - _onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20
[task 2021-09-15T10:53:22.972Z] 10:53:22 INFO - JavaScript error: chrome://remote/content/marionette/driver.js, line 2134: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]
[task 2021-09-15T10:53:22.996Z] 10:53:22 INFO - DEBUG: Starting phase profile-change-teardown
|
||
Updated•4 years ago
|
Component: IPC → Marionette
Product: Core → Testing
|
||
Comment 1•4 years ago
|
||
Gabriele, do you have an idea why this content process crash for an ASAN build doesn't cause Firefox to correctly shutdown? As such we also cannot find a minidump, and log the crash details. It's the first time that I see that, and I wonder if that is ASAN specific.
Flags: needinfo?(gsvelto)
|
||
Comment 2•4 years ago
|
||
ASAN builds have the crash reporter disabled so you can't get minidumps from them. That being said a content process crashing shouldn't cause issues with the main process.
Flags: needinfo?(gsvelto)
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 4•4 years ago
|
||
I see. So I assume that for ASAN builds we shouldn't set the MOZ_CRASHREPORTER_SHUTDOWN environment variable then?
Also the tab crashes, and as such the related browsing context is gone. So the failure message of this bug makes sense, whereby it's all during teardown of the test when we try to grab a screenshot and the page source. Both indeed wouldn't work for that tab. Based on the answer of the above question we have to look for possible solutions.
Flags: needinfo?(gsvelto)
|
|
||
Comment 5•4 years ago
|
||
IIRC MOZ_CRASHREPORTER_SHUTDOWN does not depend on MOZ_CRASHREPORTER. We detect crashes even when we don't take minidumps of them, so it should work just as well.
Flags: needinfo?(gsvelto)
|
|
||
Comment 6•4 years ago
|
||
In such a case nothing seems to be broken here. The crash is caused by a navigation, and as result Firefox shuts down. That means the browser window gets closed, which will result in a non-available browsing context for successive Marionette commands. Someone might say we shouldn't accept new commands during shutdown, so that we could raise more clear failure messages. But I don't think that's important right now, and we don't have the bandwidth for. Lets see how this bug evolves. As it looks like we only had these failures during two days last week.
|
|
||
Comment 7•4 years ago
|
||
No more failures of this type. I'm going to close the bug as WFM.
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → WORKSFORME
|
||
Updated•3 years ago
|
Product: Testing → Remote Protocol
|
|
||
Comment 8•3 years ago
|
||
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Component: Marionette → Marionette Client and Harness
Product: Remote Protocol → Testing
You need to log in
before you can comment on or make changes to this bug.
Description
•