Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=390367115&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/He0y29CJTL2LrfgnWiw3lw/runs/0/artifacts/public/logs/live_backing.log
[task 2022-09-13T15:42:20.103Z] 15:42:20 INFO - TEST-START | toolkit/components/extensions/test/mochitest/test_ext_contentscript_canvas.html
[task 2022-09-13T15:42:20.310Z] 15:42:20 INFO - GECKO(11861) | Console message: Warning: attempting to write 5377 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2022-09-13T15:42:20.316Z] 15:42:20 INFO - GECKO(11861) | Console message: Warning: attempting to write 5457 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2022-09-13T15:42:20.590Z] 15:42:20 INFO - GECKO(11861) | Console message: [JavaScript Warning: "Storage access automatically granted for origin “https://example.org” on “http://mochi.test:8888”."]
[task 2022-09-13T15:42:20.828Z] 15:42:20 INFO - GECKO(11861) | (firefox-default:11861): Gdk-ERROR **: 15:42:20.825: The program 'firefox-default' received an X Window System error.
[task 2022-09-13T15:42:20.829Z] 15:42:20 INFO - GECKO(11861) | This probably reflects a bug in the program.
[task 2022-09-13T15:42:20.829Z] 15:42:20 INFO - GECKO(11861) | The error was 'BadShmSeg (invalid shared segment parameter)'.
[task 2022-09-13T15:42:20.829Z] 15:42:20 INFO - GECKO(11861) | (Details: serial 7487 error_code 128 request_code 130 (MIT-SHM) minor_code 2)
[task 2022-09-13T15:42:20.829Z] 15:42:20 INFO - GECKO(11861) | (Note to programmers: normally, X errors are reported asynchronously;
[task 2022-09-13T15:42:20.830Z] 15:42:20 INFO - GECKO(11861) | that is, you will receive the error a while after causing it.
[task 2022-09-13T15:42:20.831Z] 15:42:20 INFO - GECKO(11861) | To debug your program, run it with the GDK_SYNCHRONIZE environment
[task 2022-09-13T15:42:20.831Z] 15:42:20 INFO - GECKO(11861) | variable to change this behavior. You can then get a meaningful
[task 2022-09-13T15:42:20.834Z] 15:42:20 INFO - GECKO(11861) | backtrace from your debugger if you break on the gdk_x_error() function.)
[task 2022-09-13T15:42:20.917Z] 15:42:20 INFO - GECKO(11861) | Exiting due to channel error.
[task 2022-09-13T15:42:20.920Z] 15:42:20 INFO - GECKO(11861) | Exiting due to channel error.
[task 2022-09-13T15:42:20.924Z] 15:42:20 INFO - GECKO(11861) | Exiting due to channel error.
[task 2022-09-13T15:42:20.931Z] 15:42:20 INFO - GECKO(11861) | Exiting due to channel error.
[task 2022-09-13T15:42:20.934Z] 15:42:20 INFO - GECKO(11861) | Exiting due to channel error.
[task 2022-09-13T15:42:21.031Z] 15:42:21 INFO - TEST-INFO | Main app process: killed by SIGTRAP
[task 2022-09-13T15:42:21.032Z] 15:42:21 INFO - Buffered messages logged at 15:42:20
[task 2022-09-13T15:42:21.032Z] 15:42:21 INFO - add_task | Entering test_drawWindow
[task 2022-09-13T15:42:21.034Z] 15:42:21 INFO - Extension loaded
[task 2022-09-13T15:42:21.034Z] 15:42:21 INFO - Extension loaded
[task 2022-09-13T15:42:21.035Z] 15:42:21 INFO - Buffered messages finished
[task 2022-09-13T15:42:21.036Z] 15:42:21 ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_contentscript_canvas.html | application terminated with exit code -5
[task 2022-09-13T15:42:21.036Z] 15:42:21 INFO - runtests.py | Application ran for: 0:01:25.208334
[task 2022-09-13T15:42:21.036Z] 15:42:21 INFO - zombiecheck | Reading PID log: /tmp/tmpdnq73nhypidlog
[task 2022-09-13T15:42:21.037Z] 15:42:21 INFO - ==> process 11861 launched child process 11878
[task 2022-09-13T15:42:21.037Z] 15:42:21 INFO - ==> process 11861 launched child process 11928
[task 2022-09-13T15:42:21.038Z] 15:42:21 INFO - ==> process 11861 launched child process 11950
[task 2022-09-13T15:42:21.040Z] 15:42:21 INFO - ==> process 11861 launched child process 11978
[task 2022-09-13T15:42:21.041Z] 15:42:21 INFO - ==> process 11861 launched child process 12036
[task 2022-09-13T15:42:21.042Z] 15:42:21 INFO - ==> process 11861 launched child process 12065
[task 2022-09-13T15:42:21.042Z] 15:42:21 INFO - ==> process 11861 launched child process 12096
[task 2022-09-13T15:42:21.043Z] 15:42:21 INFO - ==> process 11861 launched child process 12130
[task 2022-09-13T15:42:21.044Z] 15:42:21 INFO - ==> process 11861 launched child process 12148
[task 2022-09-13T15:42:21.045Z] 15:42:21 INFO - ==> process 11861 launched child process 12193
[task 2022-09-13T15:42:21.046Z] 15:42:21 INFO - ==> process 11861 launched child process 12221
[task 2022-09-13T15:42:21.046Z] 15:42:21 INFO - ==> process 11861 launched child process 12253
[task 2022-09-13T15:42:21.047Z] 15:42:21 INFO - ==> process 11861 launched child process 12276
[task 2022-09-13T15:42:21.048Z] 15:42:21 INFO - ==> process 11861 launched child process 12303
[task 2022-09-13T15:42:21.049Z] 15:42:21 INFO - ==> process 11861 launched child process 12329
[task 2022-09-13T15:42:21.050Z] 15:42:21 INFO - ==> process 11861 launched child process 12351
[task 2022-09-13T15:42:21.050Z] 15:42:21 INFO - ==> process 11861 launched child process 12375
[task 2022-09-13T15:42:21.051Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12096
[task 2022-09-13T15:42:21.052Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12065
[task 2022-09-13T15:42:21.053Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12130
[task 2022-09-13T15:42:21.053Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12193
[task 2022-09-13T15:42:21.054Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12036
[task 2022-09-13T15:42:21.054Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 11878
[task 2022-09-13T15:42:21.055Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12329
[task 2022-09-13T15:42:21.056Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 11978
[task 2022-09-13T15:42:21.056Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 11950
[task 2022-09-13T15:42:21.057Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12303
[task 2022-09-13T15:42:21.057Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12253
[task 2022-09-13T15:42:21.058Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12148
[task 2022-09-13T15:42:21.058Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12276
[task 2022-09-13T15:42:21.059Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12375
[task 2022-09-13T15:42:21.060Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 11928
[task 2022-09-13T15:42:21.060Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12221
[task 2022-09-13T15:42:21.061Z] 15:42:21 INFO - zombiecheck | Checking for orphan process with PID: 12351
[task 2022-09-13T15:42:21.061Z] 15:42:21 INFO - runtests.py | Running with scheme: https
[task 2022-09-13T15:42:21.062Z] 15:42:21 INFO - runtests.py | Running with e10s: True
[task 2022-09-13T15:42:21.062Z] 15:42:21 INFO - runtests.py | Running with fission: False
[task 2022-09-13T15:42:21.063Z] 15:42:21 INFO - runtests.py | Running with cross-origin iframes: False
[task 2022-09-13T15:42:21.064Z] 15:42:21 INFO - runtests.py | Running with serviceworker_e10s: True
[task 2022-09-13T15:42:21.064Z] 15:42:21 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2022-09-13T15:42:21.065Z] 15:42:21 INFO - runtests.py | Running tests: start.
[task 2022-09-13T15:42:21.065Z] 15:42:21 INFO -
[task 2022-09-13T15:42:21.093Z] 15:42:21 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmps5enb67m.mozrunner
[task 2022-09-13T15:42:21.103Z] 15:42:21 INFO - runtests.py | Application pid: 12398
[task 2022-09-13T15:42:21.103Z] 15:42:21 INFO - TEST-INFO | started process GECKO(12398)
[task 2022-09-13T15:42:23.119Z] 15:42:23 INFO - GECKO(12398) | 1663083743118 Marionette INFO Marionette enabled
[task 2022-09-13T15:42:23.123Z] 15:42:23 INFO - GECKO(12398) | 1663083743121 Marionette TRACE Received observer notification final-ui-startup
[task 2022-09-13T15:42:23.126Z] 15:42:23 INFO - GECKO(12398) | 1663083743124 Marionette INFO Listening on port 2828
[task 2022-09-13T15:42:23.128Z] 15:42:23 INFO - GECKO(12398) | 1663083743124 Marionette DEBUG Marionette is listening
[task 2022-09-13T15:42:23.257Z] 15:42:23 INFO - GECKO(12398) | 1663083743256 Marionette DEBUG Accepted connection 0 from 127.0.0.1:47762
[task 2022-09-13T15:42:23.410Z] 15:42:23 INFO - GECKO(12398) | 1663083743409 Marionette DEBUG Accepted connection 1 from 127.0.0.1:47764
[task 2022-09-13T15:42:23.414Z] 15:42:23 INFO - GECKO(12398) | 1663083743412 Marionette DEBUG Closed connection 0
[task 2022-09-13T15:42:23.702Z] 15:42:23 INFO - GECKO(12398) | 1663083743701 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-09-13T15:42:23.714Z] 15:42:23 INFO - GECKO(12398) | 1663083743713 Marionette DEBUG Waiting for initial application window
[task 2022-09-13T15:42:28.084Z] 15:42:28 INFO - GECKO(12398) | 1663083748080 Marionette TRACE Received observer notification browser-idle-startup-tasks-finished
[task 2022-09-13T15:42:28.107Z] 15:42:28 INFO - GECKO(12398) | 1663083748105 RemoteAgent TRACE [5] Document already finished loading: about:blank
[task 2022-09-13T15:42:28.163Z] 15:42:28 INFO - GECKO(12398) | 1663083748161 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"de78779e-a8af-4deb-a63b-f4649cd8b22d","capabilities":{"browserName":"firefox","browserVersion":"106.0 ... wnTimeout":300000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2022-09-13T15:42:28.225Z] 15:42:28 INFO - GECKO(12398) | 1663083748223 Marionette DEBUG 1 -> [0,2,"Addon:Install",{"path":"/tmp/tmpk34_4mo9.zip","temporary":false}]
[task 2022-09-13T15:42:28.638Z] 15:42:28 INFO - GECKO(12398) | 1663083748637 Marionette DEBUG 1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2022-09-13T15:42:28.680Z] 15:42:28 INFO - GECKO(12398) | 1663083748676 Marionette DEBUG 1 -> [0,3,"Addon:Install",{"path":"/tmp/tmp3c3ol0br.zip","temporary":false}]
[task 2022-09-13T15:42:28.824Z] 15:42:28 INFO - GECKO(12398) | 1663083748822 Marionette DEBUG 1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2022-09-13T15:42:28.827Z] 15:42:28 INFO - GECKO(12398) | 1663083748826 Marionette DEBUG 1 -> [0,4,"Marionette:GetContext",{}]
[task 2022-09-13T15:42:28.830Z] 15:42:28 INFO - GECKO(12398) | 1663083748828 Marionette DEBUG 1 <- [1,4,null,{"value":"content"}]
[task 2022-09-13T15:42:28.835Z] 15:42:28 INFO - GECKO(12398) | 1663083748833 Marionette DEBUG 1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-09-13T15:42:28.840Z] 15:42:28 INFO - GECKO(12398) | 1663083748835 Marionette DEBUG 1 <- [1,5,null,{"value":null}]
[task 2022-09-13T15:42:28.845Z] 15:42:28 INFO - GECKO(12398) | 1663083748841 Marionette DEBUG 1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, ... ry=%2Ftmp&cleanupCrashes=true"}],"newSandbox":true,"sandbox":"default","line":2016,"filename":"tests/mochitest/runtests.py"}]
[task 2022-09-13T15:42:28.858Z] 15:42:28 INFO - GECKO(12398) | 1663083748857 Marionette TRACE [1] MarionetteCommands actor created for window id 2
[task 2022-09-13T15:42:28.878Z] 15:42:28 INFO - GECKO(12398) | 1663083748876 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2022-09-13T15:42:28.885Z] 15:42:28 INFO - GECKO(12398) | 1663083748881 Marionette DEBUG 1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2022-09-13T15:42:28.886Z] 15:42:28 INFO - GECKO(12398) | 1663083748882 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2022-09-13T15:42:28.890Z] 15:42:28 INFO - GECKO(12398) | 1663083748888 Marionette DEBUG 1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2022-09-13T15:42:28.899Z] 15:42:28 INFO - GECKO(12398) | 1663083748897 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2022-09-13T15:42:28.948Z] 15:42:28 INFO - runtests.py | Waiting for browser...
[task 2022-09-13T15:42:28.982Z] 15:42:28 INFO - GECKO(12398) | 1663083748979 Marionette DEBUG Closed connection 1
[task 2022-09-13T15:42:30.195Z] 15:42:30 INFO - TEST-START | toolkit/components/extensions/test/mochitest/test_ext_storage_manager_capabilities.html
Description
•