Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=380850776&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/fn8Q_F37QDKLdFJ6Usy2zQ/runs/0/artifacts/public/logs/live_backing.log
[task 2022-06-10T04:44:54.727Z] 04:44:54 INFO - TEST-START | dom/url/tests/test_worker_url_exceptions.html
[task 2022-06-10T04:44:55.038Z] 04:44:55 INFO - GECKO(4817) | MEMORY STAT | vsize 130550508MB | residentFast 336MB
[task 2022-06-10T04:44:55.059Z] 04:44:55 INFO - TEST-OK | dom/url/tests/test_worker_url_exceptions.html | took 332ms
[task 2022-06-10T04:44:55.154Z] 04:44:55 INFO - TEST-START | Shutdown
[task 2022-06-10T04:44:55.159Z] 04:44:55 INFO - Passed: 1602
[task 2022-06-10T04:44:55.159Z] 04:44:55 INFO - Failed: 0
[task 2022-06-10T04:44:55.160Z] 04:44:55 INFO - Todo: 0
[task 2022-06-10T04:44:55.161Z] 04:44:55 INFO - Mode: e10s
[task 2022-06-10T04:44:55.161Z] 04:44:55 INFO - Slowest: 1929ms - /tests/dom/url/tests/test_bloburl_location.html
[task 2022-06-10T04:44:55.163Z] 04:44:55 INFO - SimpleTest FINISHED
[task 2022-06-10T04:44:55.163Z] 04:44:55 INFO - TEST-INFO | Ran 1 Loops
[task 2022-06-10T04:44:55.163Z] 04:44:55 INFO - SimpleTest FINISHED
[task 2022-06-10T04:44:55.425Z] 04:44:55 INFO - GECKO(4817) | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 577: NotFoundError: No such JSWindowActor 'SpecialPowers'
[task 2022-06-10T04:44:55.528Z] 04:44:55 INFO - GECKO(4817) | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 577: NotFoundError: No such JSWindowActor 'AppTestDelegate'
[task 2022-06-10T04:44:55.539Z] 04:44:55 INFO - GECKO(4817) | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 577: NotFoundError: No such JSWindowActor 'AppTestDelegate'
[task 2022-06-10T04:44:55.733Z] 04:44:55 INFO - GECKO(4817) | 1654836295732 Marionette TRACE Received observer notification quit-application
[task 2022-06-10T04:44:55.734Z] 04:44:55 INFO - GECKO(4817) | 1654836295733 Marionette INFO Stopped listening on port 2828
[task 2022-06-10T04:44:55.737Z] 04:44:55 INFO - GECKO(4817) | 1654836295736 Marionette DEBUG Marionette stopped listening
[task 2022-06-10T04:45:01.500Z] 04:45:01 INFO - TEST-INFO | Main app process: exit 0
[task 2022-06-10T04:45:01.503Z] 04:45:01 INFO - runtests.py | Application ran for: 0:00:33.406508
[task 2022-06-10T04:45:01.503Z] 04:45:01 INFO - zombiecheck | Reading PID log: /tmp/tmpyoaxq5z2pidlog
[task 2022-06-10T04:45:01.503Z] 04:45:01 INFO - ==> process 4817 launched child process 4833
<...>
[task 2022-06-10T04:45:01.505Z] 04:45:01 INFO - zombiecheck | Checking for orphan process with PID: 4985
[task 2022-06-10T04:45:01.505Z] 04:45:01 INFO - Stopping web server
[task 2022-06-10T04:45:01.512Z] 04:45:01 INFO - Server shut down.
[task 2022-06-10T04:45:01.540Z] 04:45:01 INFO - Web server killed.
[task 2022-06-10T04:45:01.540Z] 04:45:01 INFO - Stopping web socket server
[task 2022-06-10T04:45:01.560Z] 04:45:01 INFO - Stopping ssltunnel
[task 2022-06-10T04:45:01.581Z] 04:45:01 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2022-06-10T04:45:01.581Z] 04:45:01 INFO - runtests.py | Running tests: end.
[task 2022-06-10T04:45:01.621Z] 04:45:01 INFO - Buffered messages finished
[task 2022-06-10T04:45:01.622Z] 04:45:01 INFO - Running manifest: parser/htmlparser/tests/mochitest/mochitest.ini
[task 2022-06-10T04:45:01.637Z] 04:45:01 INFO - Setting pipeline to PAUSED ...
[task 2022-06-10T04:45:01.637Z] 04:45:01 INFO - Pipeline is PREROLLING ...
[task 2022-06-10T04:45:01.638Z] 04:45:01 INFO - Pipeline is PREROLLED ...
[task 2022-06-10T04:45:01.639Z] 04:45:01 INFO - Setting pipeline to PLAYING ...
[task 2022-06-10T04:45:01.639Z] 04:45:01 INFO - New clock: GstSystemClock
[task 2022-06-10T04:45:01.672Z] 04:45:01 INFO - Got EOS from element "pipeline0".
[task 2022-06-10T04:45:01.672Z] 04:45:01 INFO - Execution ended after 0:00:00.033445123
[task 2022-06-10T04:45:01.673Z] 04:45:01 INFO - Setting pipeline to PAUSED ...
[task 2022-06-10T04:45:01.673Z] 04:45:01 INFO - Setting pipeline to READY ...
[task 2022-06-10T04:45:01.673Z] 04:45:01 INFO - (gst-launch-1.0:5116): GStreamer-CRITICAL **: 04:45:01.672: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2022-06-10T04:45:01.673Z] 04:45:01 INFO - Setting pipeline to NULL ...
[task 2022-06-10T04:45:01.673Z] 04:45:01 INFO - Freeing pipeline ...
[task 2022-06-10T04:45:01.726Z] 04:45:01 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-06-10T04:45:01.987Z] 04:45:01 INFO - PID 5132 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2022-06-10T04:45:02.269Z] 04:45:02 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-06-10T04:45:02.270Z] 04:45:02 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-06-10T04:45:02.273Z] 04:45:02 INFO - MochitestServer : launching ['/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmp4zftqa_o.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2022-06-10T04:45:02.274Z] 04:45:02 INFO - runtests.py | Server pid: 5144
[task 2022-06-10T04:45:02.277Z] 04:45:02 INFO - runtests.py | Websocket server pid: 5147
[task 2022-06-10T04:45:02.278Z] 04:45:02 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-06-10T04:45:02.283Z] 04:45:02 INFO - runtests.py | SSL tunnel pid: 5151
[task 2022-06-10T04:45:02.638Z] 04:45:02 INFO - runtests.py | Running with scheme: http
[task 2022-06-10T04:45:02.638Z] 04:45:02 INFO - runtests.py | Running with e10s: True
[task 2022-06-10T04:45:02.638Z] 04:45:02 INFO - runtests.py | Running with fission: True
[task 2022-06-10T04:45:02.638Z] 04:45:02 INFO - runtests.py | Running with cross-origin iframes: False
[task 2022-06-10T04:45:02.638Z] 04:45:02 INFO - runtests.py | Running with serviceworker_e10s: True
[task 2022-06-10T04:45:02.638Z] 04:45:02 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2022-06-10T04:45:02.638Z] 04:45:02 INFO - runtests.py | Running tests: start.
[task 2022-06-10T04:45:02.638Z] 04:45:02 INFO -
[task 2022-06-10T04:45:02.646Z] 04:45:02 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmp4zftqa_o.mozrunner
[task 2022-06-10T04:45:02.650Z] 04:45:02 INFO - runtests.py | Application pid: 5171
[task 2022-06-10T04:45:02.650Z] 04:45:02 INFO - TEST-INFO | started process GECKO(5171)
[task 2022-06-10T04:45:05.559Z] 04:45:05 INFO - GECKO(5171) | 1654836305558 Marionette INFO Marionette enabled
[task 2022-06-10T04:45:05.568Z] 04:45:05 INFO - GECKO(5171) | 1654836305567 Marionette TRACE Received observer notification final-ui-startup
[task 2022-06-10T04:45:05.576Z] 04:45:05 INFO - GECKO(5171) | 1654836305576 Marionette INFO Listening on port 2828
[task 2022-06-10T04:45:05.577Z] 04:45:05 INFO - GECKO(5171) | 1654836305576 Marionette DEBUG Marionette is listening
[task 2022-06-10T04:45:06.225Z] 04:45:06 INFO - GECKO(5171) | 1654836306224 Marionette DEBUG Accepted connection 0 from 127.0.0.1:37186
[task 2022-06-10T04:45:06.444Z] 04:45:06 INFO - GECKO(5171) | 1654836306443 Marionette DEBUG Closed connection 0
[task 2022-06-10T04:45:06.450Z] 04:45:06 INFO - GECKO(5171) | 1654836306449 Marionette DEBUG Accepted connection 1 from 127.0.0.1:37188
[task 2022-06-10T04:45:06.626Z] 04:45:06 INFO - GECKO(5171) | 1654836306625 Marionette DEBUG Closed connection 1
[task 2022-06-10T04:45:06.627Z] 04:45:06 INFO - GECKO(5171) | 1654836306626 Marionette DEBUG Accepted connection 2 from 127.0.0.1:37190
[task 2022-06-10T04:45:07.846Z] 04:45:07 INFO - GECKO(5171) | 1654836307845 Marionette DEBUG 2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-06-10T04:45:07.867Z] 04:45:07 INFO - GECKO(5171) | 1654836307866 Marionette DEBUG Waiting for initial application window
[task 2022-06-10T04:45:10.949Z] 04:45:10 INFO - GECKO(5171) | ==5171==ERROR: ThreadSanitizer failed to allocate 0xfe69f31a7000 (279731003617280) bytes at address 8d8cac4d000 (errno: 12)
[task 2022-06-10T04:45:10.985Z] 04:45:10 INFO - GECKO(5171) | Exiting due to channel error.
[task 2022-06-10T04:45:10.985Z] 04:45:10 INFO - GECKO(5171) | Exiting due to channel error.
[task 2022-06-10T04:45:10.986Z] 04:45:10 INFO - runtests.py | Waiting for browser...
[task 2022-06-10T04:45:12.009Z] 04:45:12 INFO - TEST-INFO | Main app process: killed by SIGIOT
[task 2022-06-10T04:45:12.009Z] 04:45:12 INFO - Buffered messages finished
[task 2022-06-10T04:45:12.011Z] 04:45:12 ERROR - TEST-UNEXPECTED-FAIL | automation.py | application terminated with exit code -6
[task 2022-06-10T04:45:12.011Z] 04:45:12 INFO - runtests.py | Application ran for: 0:00:09.362874
[task 2022-06-10T04:45:12.011Z] 04:45:12 INFO - zombiecheck | Reading PID log: /tmp/tmpd1v_366dpidlog
[task 2022-06-10T04:45:12.011Z] 04:45:12 INFO - ==> process 5171 launched child process 5187
[task 2022-06-10T04:45:12.011Z] 04:45:12 INFO - ==> process 5171 launched child process 5249
[task 2022-06-10T04:45:12.011Z] 04:45:12 INFO - ==> process 5171 launched child process 5272
[task 2022-06-10T04:45:12.011Z] 04:45:12 INFO - zombiecheck | Checking for orphan process with PID: 5272
[task 2022-06-10T04:45:12.011Z] 04:45:12 INFO - zombiecheck | Checking for orphan process with PID: 5249
[task 2022-06-10T04:45:12.013Z] 04:45:12 INFO - zombiecheck | Checking for orphan process with PID: 5187
[task 2022-06-10T04:45:12.014Z] 04:45:12 INFO - Traceback (most recent call last):
[task 2022-06-10T04:45:12.014Z] 04:45:12 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 3501, in doTests
[task 2022-06-10T04:45:12.015Z] 04:45:12 INFO - crashAsPass=options.crashAsPass,
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 2811, in runApp
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - six.reraise(exc, value, tb)
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 696, in reraise
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - raise value
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 2671, in runApp
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - self.marionette.start_session()
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 37, in _
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - m._handle_socket_failure()
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 712, in _handle_socket_failure
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - reraise(exc_cls, exc, tb)
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 696, in reraise
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - raise value
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2022-06-10T04:45:12.016Z] 04:45:12 INFO - return func(*args, **kwargs)
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 1240, in start_session
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - resp = self._send_message("WebDriver:NewSession", capabilities)
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 37, in _
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - m._handle_socket_failure()
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 712, in _handle_socket_failure
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - reraise(exc_cls, exc, tb)
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 696, in reraise
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - raise value
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - return func(*args, **kwargs)
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 661, in _send_message
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - msg = self.client.request(name, params)
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/transport.py", line 383, in request
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - return self.receive()
[task 2022-06-10T04:45:12.017Z] 04:45:12 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/transport.py", line 230, in receive
[task 2022-06-10T04:45:12.018Z] 04:45:12 INFO - raise socket.error("No data received over socket")
[task 2022-06-10T04:45:12.018Z] 04:45:12 INFO - OSError: No data received over socket
[task 2022-06-10T04:45:12.018Z] 04:45:12 ERROR - Automation Error: Received unexpected exception while running application
[task 2022-06-10T04:45:12.018Z] 04:45:12 ERROR -
[task 2022-06-10T04:45:12.018Z] 04:45:12 INFO - Stopping web server
[task 2022-06-10T04:45:12.055Z] 04:45:12 INFO - Server shut down.
[task 2022-06-10T04:45:12.075Z] 04:45:12 INFO - Web server killed.
[task 2022-06-10T04:45:12.076Z] 04:45:12 INFO - Stopping web socket server
[task 2022-06-10T04:45:12.096Z] 04:45:12 INFO - Stopping ssltunnel
[task 2022-06-10T04:45:12.116Z] 04:45:12 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2022-06-10T04:45:12.116Z] 04:45:12 INFO - runtests.py | Running tests: end.
Description
•