Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=428089174&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/JKa7GhUvTnKcXO2c0_vanw/runs/0/artifacts/public/logs/live_backing.log
[task 2023-09-06T01:54:55.766Z] 01:54:55 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_crash.py TestCrash.test_crash_chrome_process
[task 2023-09-06T01:54:55.767Z] 01:54:55 INFO - Suppressing GECKO output. To view, add `print(self.new_out.getvalue())` to the end of this test.
[task 2023-09-06T01:54:55.768Z] 01:54:55 INFO - 1693965295768 Marionette DEBUG Accepted connection 114 from 127.0.0.1:63165
[task 2023-09-06T01:54:55.777Z] 01:54:55 INFO - 1693965295780 Marionette DEBUG 114 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-09-06T01:54:55.783Z] 01:54:55 INFO - 1693965295781 Marionette DEBUG Waiting for initial application window
[task 2023-09-06T01:54:55.784Z] 01:54:55 INFO - 1693965295783 RemoteAgent TRACE [131] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=40000 waitForExplicitStart=false
[task 2023-09-06T01:54:55.784Z] 01:54:55 INFO - 1693965295783 RemoteAgent TRACE [131] ProgressListener Setting unload timer (40000ms)
[task 2023-09-06T01:54:55.784Z] 01:54:55 INFO - 1693965295783 RemoteAgent TRACE [131] Document already finished loading: http://127.0.0.1:62774/test.html
[task 2023-09-06T01:54:55.785Z] 01:54:55 INFO - 1693965295783 RemoteAgent TRACE [131] ProgressListener Stop: has error=false
[task 2023-09-06T01:54:55.787Z] 01:54:55 INFO - 1693965295786 Marionette DEBUG 114 <- [1,1,null,{"sessionId":"b35285be-ea1e-44db-be78-3104971d6aba","capabilities":{"browserName":"firefox","browserVersion":"119.0a1","platformName":"windows","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20230906010613","moz:headless":false,"moz:platformVersion":"10.0","moz:processID":10220,"moz:profile":"C:\\Users\\task_169396314393606\\AppData\\Local\\Temp\\tmpzkib7_d0.mozrunner","moz:shutdownTimeout":60000,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2023-09-06T01:54:55.788Z] 01:54:55 INFO - 1693965295788 Marionette DEBUG 114 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2023-09-06T01:54:55.789Z] 01:54:55 INFO - 1693965295788 Marionette DEBUG 114 <- [1,2,null,{"value":null}]
[task 2023-09-06T01:54:55.790Z] 01:54:55 INFO - 1693965295790 Marionette DEBUG 114 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2023-09-06T01:54:55.790Z] 01:54:55 INFO - 1693965295790 Marionette DEBUG 114 <- [1,3,null,{"value":null}]
[task 2023-09-06T01:54:55.792Z] 01:54:55 INFO - 1693965295791 Marionette DEBUG 114 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2023-09-06T01:54:55.792Z] 01:54:55 INFO - 1693965295792 Marionette DEBUG 114 <- [1,4,null,{"value":null}]
[task 2023-09-06T01:54:55.798Z] 01:54:55 INFO - 1693965295798 Marionette DEBUG 114 -> [0,5,"Marionette:GetContext",{}]
[task 2023-09-06T01:54:55.798Z] 01:54:55 INFO - 1693965295798 Marionette DEBUG 114 <- [1,5,null,{"value":"content"}]
[task 2023-09-06T01:54:55.799Z] 01:54:55 INFO - 1693965295799 Marionette DEBUG 114 -> [0,6,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-09-06T01:54:55.800Z] 01:54:55 INFO - 1693965295799 Marionette DEBUG 114 <- [1,6,null,{"value":null}]
[task 2023-09-06T01:54:55.802Z] 01:54:55 INFO - 1693965295801 Marionette DEBUG 114 -> [0,7,"WebDriver:ExecuteScript",{"script":"const { AppConstants } = ChromeUtils.importESModule(\n \"resource://gre/modules/AppConstants.sys.mjs\"\n );\n return AppConstants.MOZ_CRASHREPORTER;","args":[],"newSandbox":true,"sandbox":"default","line":32,"filename":"Z:\\task_169396314393606\\build\\tests\\marionette\\tests\\testing\\marionette\\harness\\marionette_harness\\tests\\unit\\test_crash.py"}]
[task 2023-09-06T01:54:55.805Z] 01:54:55 INFO - 1693965295805 RemoteAgent TRACE WebDriverProcessData actor created for PID 10220
[task 2023-09-06T01:54:55.805Z] 01:54:55 INFO - 1693965295805 Marionette TRACE [1] MarionetteCommands actor created for window id 2
[task 2023-09-06T01:54:55.811Z] 01:54:55 INFO - 1693965295810 Marionette DEBUG 114 <- [1,7,null,{"value":true}]
[task 2023-09-06T01:54:55.811Z] 01:54:55 INFO - DEBUG: Adding blocker Transaction (46) for phase protections.sqlite#0: waiting for clients
[task 2023-09-06T01:54:55.813Z] 01:54:55 INFO - 1693965295813 Marionette DEBUG 114 -> [0,8,"Marionette:SetContext",{"value":"content"}]
[task 2023-09-06T01:54:55.814Z] 01:54:55 INFO - 1693965295813 Marionette DEBUG 114 <- [1,8,null,{"value":null}]
[task 2023-09-06T01:54:55.814Z] 01:54:55 INFO - DEBUG: Completed blocker Transaction (46) for phase protections.sqlite#0: waiting for clients
[task 2023-09-06T01:54:55.815Z] 01:54:55 INFO - DEBUG: Adding blocker Transaction (47) for phase protections.sqlite#0: waiting for clients
[task 2023-09-06T01:54:55.816Z] 01:54:55 INFO - 1693965295816 Marionette DEBUG 114 -> [0,9,"Marionette:SetContext",{"value":"content"}]
[task 2023-09-06T01:54:55.816Z] 01:54:55 INFO - 1693965295816 Marionette DEBUG 114 <- [1,9,null,{"value":null}]
[task 2023-09-06T01:54:55.817Z] 01:54:55 INFO - DEBUG: Completed blocker Transaction (47) for phase protections.sqlite#0: waiting for clients
[task 2023-09-06T01:54:55.818Z] 01:54:55 INFO - 1693965295818 Marionette DEBUG 114 -> [0,10,"WebDriver:Navigate",{"url":"about:crashparent"}]
[task 2023-09-06T01:54:55.820Z] 01:54:55 INFO - 1693965295821 Marionette TRACE [131] Received event beforeunload for http://127.0.0.1:62774/test.html
[task 2023-09-06T01:54:55.825Z] 01:54:55 INFO - Hit MOZ_CRASH(Crash via about:crashparent) at /builds/worker/checkouts/gecko/docshell/base/nsAboutRedirector.cpp:39
[task 2023-09-06T01:54:55.981Z] 01:54:55 INFO - #01: DumpBidiLine[Z:\task_169396314393606\build\application\firefox\xul.dll +0x6bc577a]
[task 2023-09-06T01:54:55.993Z] 01:54:55 INFO - #02: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0x5eb41f]
[task 2023-09-06T01:54:55.993Z] 01:54:55 INFO - #03: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0x5dfbb8]
[task 2023-09-06T01:54:55.993Z] 01:54:55 INFO - #04: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xccf321]
[task 2023-09-06T01:54:55.994Z] 01:54:55 INFO - #05: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xcca90e]
[task 2023-09-06T01:54:55.994Z] 01:54:55 INFO - #06: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xcc99a3]
[task 2023-09-06T01:54:55.994Z] 01:54:55 INFO - #07: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xcdf6cc]
[task 2023-09-06T01:54:55.994Z] 01:54:55 INFO - #08: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xd5c2c9]
[task 2023-09-06T01:54:55.994Z] 01:54:55 INFO - #09: VR_RuntimePath[Z:\task_169396314393606\build\application\firefox\xul.dll +0x4a33c0d]
[task 2023-09-06T01:54:55.994Z] 01:54:55 INFO - #10: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xee87af]
[task 2023-09-06T01:54:55.994Z] 01:54:55 INFO - #11: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xee6b38]
[task 2023-09-06T01:54:55.995Z] 01:54:55 INFO - #12: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xee7364]
[task 2023-09-06T01:54:55.995Z] 01:54:55 INFO - #13: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xee795e]
[task 2023-09-06T01:54:55.995Z] 01:54:55 INFO - #14: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0x3de1ae]
[task 2023-09-06T01:54:55.995Z] 01:54:55 INFO - #15: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0x3d18b5]
[task 2023-09-06T01:54:55.995Z] 01:54:55 INFO - #16: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0x3cfb48]
[task 2023-09-06T01:54:55.995Z] 01:54:55 INFO - #17: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0x3cffba]
[task 2023-09-06T01:54:55.996Z] 01:54:55 INFO - #18: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0x3e0b77]
[task 2023-09-06T01:54:55.996Z] 01:54:55 INFO - #19: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0x3f8f87]
[task 2023-09-06T01:54:55.996Z] 01:54:55 INFO - #20: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0x4004d5]
[task 2023-09-06T01:54:55.996Z] 01:54:55 INFO - #21: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xeeccda]
[task 2023-09-06T01:54:55.996Z] 01:54:55 INFO - #22: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xe6f310]
[task 2023-09-06T01:54:55.996Z] 01:54:55 INFO - #23: ???[Z:\task_169396314393606\build\application\firefox\xul.dll +0xe6f1cf]
[task 2023-09-06T01:54:55.996Z] 01:54:55 INFO - #24: VR_RuntimePath[Z:\task_169396314393606\build\application\firefox\xul.dll +0x50b80c8]
[task 2023-09-06T01:54:55.997Z] 01:54:55 INFO - #25: VR_RuntimePath[Z:\task_169396314393606\build\application\firefox\xul.dll +0x5195c4a]
[task 2023-09-06T01:54:55.997Z] 01:54:55 INFO - #26: GIFFT_TimingDistributionCancel[Z:\task_169396314393606\build\application\firefox\xul.dll +0x7210da8]
[task 2023-09-06T01:54:55.997Z] 01:54:55 INFO - #27: GIFFT_TimingDistributionCancel[Z:\task_169396314393606\build\application\firefox\xul.dll +0x73ae22a]
[task 2023-09-06T01:54:55.997Z] 01:54:55 INFO - #28: GIFFT_TimingDistributionCancel[Z:\task_169396314393606\build\application\firefox\xul.dll +0x73b1281]
[task 2023-09-06T01:54:55.997Z] 01:54:55 INFO - #29: GIFFT_TimingDistributionCancel[Z:\task_169396314393606\build\application\firefox\xul.dll +0x73b1e17]
[task 2023-09-06T01:54:55.997Z] 01:54:55 INFO - #30: ???[Z:\task_169396314393606\build\application\firefox\firefox.exe +0x17d8]
[task 2023-09-06T01:54:55.998Z] 01:54:55 INFO - #31: ???[Z:\task_169396314393606\build\application\firefox\firefox.exe +0x120f]
[task 2023-09-06T01:54:55.998Z] 01:54:55 INFO - #32: TargetNtUnmapViewOfSection[Z:\task_169396314393606\build\application\firefox\firefox.exe +0x963c8]
[task 2023-09-06T01:54:55.998Z] 01:54:55 INFO - #33: BaseThreadInitThunk[C:\Windows\System32\KERNEL32.DLL +0x1269d]
[task 2023-09-06T01:54:55.998Z] 01:54:55 INFO - #34: RtlUserThreadStart[C:\Windows\SYSTEM32\ntdll.dll +0x5a9f8]
[task 2023-09-06T01:54:56.216Z] 01:54:56 INFO - [GPU 6244, IPC I/O Child] WARNING: [8AE50F1C6D228547.1A5F44160998D608]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.216Z] 01:54:56 INFO - [GPU 6244, IPC I/O Child] WARNING: [8AE50F1C6D228547.1A5F44160998D608]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.223Z] 01:54:56 INFO - [GPU 6244, IPC I/O Child] WARNING: [8AE50F1C6D228547.1A5F44160998D608]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.223Z] 01:54:56 INFO - [GPU 6244, IPC I/O Child] WARNING: [8AE50F1C6D228547.1A5F44160998D608]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.223Z] 01:54:56 INFO - [GPU 6244, IPC I/O Child] WARNING: [8AE50F1C6D228547.1A5F44160998D608]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.223Z] 01:54:56 INFO - [GPU 6244, IPC I/O Child] WARNING: [8AE50F1C6D228547.1A5F44160998D608]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.223Z] 01:54:56 INFO - [GPU 6244, IPC I/O Child] WARNING: [8AE50F1C6D228547.1A5F44160998D608]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.223Z] 01:54:56 INFO - [Child 9480, IPC I/O Child] WARNING: [4E0BF3F4484C6EE7.608D82CB05786359]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.223Z] 01:54:56 INFO - Exiting due to channel error.
[task 2023-09-06T01:54:56.223Z] 01:54:56 INFO - [Utility 9016, IPC I/O Child] WARNING: [5B3777893C907225.73395C5B49D407D7]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.223Z] 01:54:56 INFO - [Utility 9016, IPC I/O Child] WARNING: [5B3777893C907225.73395C5B49D407D7]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-09-06T01:54:56.279Z] 01:54:56 INFO - Application command: Z:\task_169396314393606\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile C:\Users\task_169396314393606\AppData\Local\Temp\tmpzkib7_d0.mozrunner
[task 2023-09-06T01:55:00.230Z] 01:55:00 INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_crash.py TestCrash.test_crash_chrome_process | took 4466ms
[task 2023-09-06T01:55:00.241Z] 01:55:00 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_crash.py TestCrash.test_crash_content_process
Description
•