Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=367647093&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/agipBLa_TNmq4Rkr2D8I1g/runs/0/artifacts/public/logs/live_backing.log
[task 2022-02-12T10:43:35.073Z] 10:43:35 INFO - TEST-START | dom/media/webrtc/tests/mochitests/test_unfocused_pref.html
[task 2022-02-12T10:43:35.352Z] 10:43:35 INFO - GECKO(5995) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2022-02-12T10:43:35.355Z] 10:43:35 INFO - GECKO(5995) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2022-02-12T10:43:38.082Z] 10:43:38 INFO - GECKO(5995) | MEMORY STAT | vsize 20983762MB | residentFast 1756MB
[task 2022-02-12T10:43:38.562Z] 10:43:38 INFO - TEST-OK | dom/media/webrtc/tests/mochitests/test_unfocused_pref.html | took 3487ms
[task 2022-02-12T10:43:38.712Z] 10:43:38 INFO - TEST-START | Shutdown
[task 2022-02-12T10:43:38.713Z] 10:43:38 INFO - Passed: 70858
[task 2022-02-12T10:43:38.715Z] 10:43:38 INFO - Failed: 0
[task 2022-02-12T10:43:38.717Z] 10:43:38 INFO - Todo: 2911
[task 2022-02-12T10:43:38.718Z] 10:43:38 INFO - Mode: e10s
[task 2022-02-12T10:43:38.720Z] 10:43:38 INFO - Slowest: 20365ms - /tests/dom/media/webrtc/tests/mochitests/test_getUserMedia_basicScreenshare.html
[task 2022-02-12T10:43:38.723Z] 10:43:38 INFO - SimpleTest FINISHED
[task 2022-02-12T10:43:38.734Z] 10:43:38 INFO - TEST-INFO | Ran 1 Loops
[task 2022-02-12T10:43:38.737Z] 10:43:38 INFO - SimpleTest FINISHED
[task 2022-02-12T10:43:38.938Z] 10:43:38 INFO - GECKO(5995) | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 575: NotFoundError: No such JSWindowActor 'SpecialPowers'
[task 2022-02-12T10:43:39.023Z] 10:43:39 INFO - GECKO(5995) | 1644662619022 Marionette TRACE Received observer notification quit-application
[task 2022-02-12T10:43:39.026Z] 10:43:39 INFO - GECKO(5995) | 1644662619022 Marionette INFO Stopped listening on port 2828
[task 2022-02-12T10:43:39.029Z] 10:43:39 INFO - GECKO(5995) | 1644662619023 Marionette DEBUG Marionette stopped listening
[task 2022-02-12T10:43:39.218Z] 10:43:39 INFO - GECKO(5995) | JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-02-12T10:43:39.222Z] 10:43:39 INFO - GECKO(5995) | ###!!! [Parent][PBackgroundParent] Error: RunMessage(msgname=PRemoteWorkerService::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-02-12T10:43:39.248Z] 10:43:39 INFO - GECKO(5995) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-02-12T10:43:39.283Z] 10:43:39 INFO - GECKO(5995) | ###!!! [Parent][PBackgroundParent] Error: Send(msgname=PCameras::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-02-12T10:43:39.369Z] 10:43:39 INFO - GECKO(5995) | JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-02-12T10:43:39.374Z] 10:43:39 INFO - GECKO(5995) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-02-12T10:43:39.375Z] 10:43:39 INFO - GECKO(5995) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-02-12T10:43:39.378Z] 10:43:39 INFO - GECKO(5995) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-02-12T10:43:42.817Z] 10:43:42 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:42.818Z] 10:43:42 INFO - GECKO(5995) | Suppressions used:
[task 2022-02-12T10:43:42.819Z] 10:43:42 INFO - GECKO(5995) | count bytes template
[task 2022-02-12T10:43:42.819Z] 10:43:42 INFO - GECKO(5995) | 13 416 nsComponentManagerImpl
[task 2022-02-12T10:43:42.820Z] 10:43:42 INFO - GECKO(5995) | 2 288 libfontconfig.so
[task 2022-02-12T10:43:42.821Z] 10:43:42 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:42.871Z] 10:43:42 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:42.871Z] 10:43:42 INFO - GECKO(5995) | Suppressions used:
[task 2022-02-12T10:43:42.871Z] 10:43:42 INFO - GECKO(5995) | count bytes template
[task 2022-02-12T10:43:42.871Z] 10:43:42 INFO - GECKO(5995) | 13 416 nsComponentManagerImpl
[task 2022-02-12T10:43:42.871Z] 10:43:42 INFO - GECKO(5995) | 2 288 libfontconfig.so
[task 2022-02-12T10:43:42.872Z] 10:43:42 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:43.139Z] 10:43:43 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:43.140Z] 10:43:43 INFO - GECKO(5995) | Suppressions used:
[task 2022-02-12T10:43:43.140Z] 10:43:43 INFO - GECKO(5995) | count bytes template
[task 2022-02-12T10:43:43.141Z] 10:43:43 INFO - GECKO(5995) | 13 416 nsComponentManagerImpl
[task 2022-02-12T10:43:43.142Z] 10:43:43 INFO - GECKO(5995) | 2 288 libfontconfig.so
[task 2022-02-12T10:43:43.143Z] 10:43:43 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:43.686Z] 10:43:43 INFO - GECKO(5995) | Waiting in WillDestroyCurrentMessageLoop for pid 6089
[task 2022-02-12T10:43:43.898Z] 10:43:43 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:43.899Z] 10:43:43 INFO - GECKO(5995) | Suppressions used:
[task 2022-02-12T10:43:43.900Z] 10:43:43 INFO - GECKO(5995) | count bytes template
[task 2022-02-12T10:43:43.900Z] 10:43:43 INFO - GECKO(5995) | 1 32 nsComponentManagerImpl
[task 2022-02-12T10:43:43.901Z] 10:43:43 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:45.063Z] 10:43:45 INFO - GECKO(5995) | =================================================================
[task 2022-02-12T10:43:45.063Z] 10:43:45 ERROR - GECKO(5995) | ==6089==ERROR: LeakSanitizer: detected memory leaks
[task 2022-02-12T10:43:45.071Z] 10:43:45 INFO - GECKO(5995) | Direct leak of 131072 byte(s) in 1 object(s) allocated from:
[task 2022-02-12T10:43:45.082Z] 10:43:45 INFO - GECKO(5995) | #0 0x561a754f3d6d in malloc /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cpp:129:3
[task 2022-02-12T10:43:45.082Z] 10:43:45 INFO - GECKO(5995) | #1 0x7f5fc055aeaa in sctp_hashinit_flags /builds/worker/checkouts/gecko/netwerk/sctp/src/netinet/sctputil.c
[task 2022-02-12T10:43:45.082Z] 10:43:45 INFO - GECKO(5995) | #2 0x7f5fc050dc79 in sctp_pcb_init /builds/worker/checkouts/gecko/netwerk/sctp/src/netinet/sctp_pcb.c:6590:34
[task 2022-02-12T10:43:45.082Z] 10:43:45 INFO - GECKO(5995) | #3 0x7f5fc0521590 in sctp_init /builds/worker/checkouts/gecko/netwerk/sctp/src/netinet/sctp_usrreq.c:142:2
[task 2022-02-12T10:43:45.082Z] 10:43:45 INFO - GECKO(5995) | #4 0x7f5fc055fb7a in usrsctp_init /builds/worker/checkouts/gecko/netwerk/sctp/src/user_socket.c:112:2
<...>
[task 2022-02-12T10:43:45.241Z] 10:43:45 INFO - GECKO(5995) | #30 0x7f5fcae10a8e in Interpret(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:3309:16
[task 2022-02-12T10:43:45.241Z] 10:43:45 INFO - GECKO(5995) | #31 0x7f5fcadf58a1 in js::RunScript(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:394:13
[task 2022-02-12T10:43:45.242Z] 10:43:45 INFO - GECKO(5995) | #32 0x7f5fcae2465f in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:544:13
[task 2022-02-12T10:43:45.243Z] 10:43:45 INFO - GECKO(5995) | #33 0x7f5fcae267ab in js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:589:8
[task 2022-02-12T10:43:45.243Z] 10:43:45 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:45.244Z] 10:43:45 INFO - GECKO(5995) | Suppressions used:
[task 2022-02-12T10:43:45.244Z] 10:43:45 INFO - GECKO(5995) | count bytes template
[task 2022-02-12T10:43:45.245Z] 10:43:45 INFO - GECKO(5995) | 13 416 nsComponentManagerImpl
[task 2022-02-12T10:43:45.245Z] 10:43:45 INFO - GECKO(5995) | 2 288 libfontconfig.so
[task 2022-02-12T10:43:45.246Z] 10:43:45 INFO - GECKO(5995) | 2 65568 nr_reg_local_init
[task 2022-02-12T10:43:45.246Z] 10:43:45 INFO - GECKO(5995) | 195 18592 r_log_register
[task 2022-02-12T10:43:45.247Z] 10:43:45 INFO - GECKO(5995) | 69 3176 nr_reg_set
[task 2022-02-12T10:43:45.247Z] 10:43:45 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:45.248Z] 10:43:45 INFO - GECKO(5995) | SUMMARY: AddressSanitizer: 147888 byte(s) leaked in 7 allocation(s).
[task 2022-02-12T10:43:45.265Z] 10:43:45 INFO - GECKO(5995) | Waiting in WillDestroyCurrentMessageLoop for pid 6249
[task 2022-02-12T10:43:49.125Z] 10:43:49 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:49.126Z] 10:43:49 INFO - GECKO(5995) | Suppressions used:
[task 2022-02-12T10:43:49.127Z] 10:43:49 INFO - GECKO(5995) | count bytes template
[task 2022-02-12T10:43:49.127Z] 10:43:49 INFO - GECKO(5995) | 10 312 nsComponentManagerImpl
[task 2022-02-12T10:43:49.128Z] 10:43:49 INFO - GECKO(5995) | 633 18115 libfontconfig.so
[task 2022-02-12T10:43:49.130Z] 10:43:49 INFO - GECKO(5995) | 4 16407 libglib-2.0.so
[task 2022-02-12T10:43:49.131Z] 10:43:49 INFO - GECKO(5995) | 2 416 mozJSComponentLoader
[task 2022-02-12T10:43:49.131Z] 10:43:49 INFO - GECKO(5995) | 2 48 XPCWrappedNativeJSOps
[task 2022-02-12T10:43:49.132Z] 10:43:49 INFO - GECKO(5995) | -----------------------------------------------------
[task 2022-02-12T10:43:49.354Z] 10:43:49 INFO - TEST-INFO | Main app process: exit 0
[task 2022-02-12T10:43:49.355Z] 10:43:49 INFO - TEST-INFO | LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2022-02-12T10:43:49.357Z] 10:43:49 INFO - TEST-INFO | LeakSanitizer | This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2022-02-12T10:43:49.358Z] 10:43:49 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at sctp_add_vtag_to_timewait, sctp_free_assoc, sctp_inpcb_free, sctp_close
[task 2022-02-12T10:43:49.363Z] 10:43:49 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at sctp_hashinit_flags, sctp_pcb_init, sctp_init, usrsctp_init
[task 2022-02-12T10:43:49.364Z] 10:43:49 INFO - runtests.py | Application ran for: 0:14:03.381810
[task 2022-02-12T10:43:49.365Z] 10:43:49 INFO - zombiecheck | Reading PID log: /tmp/tmpwnis3amtpidlog
[task 2022-02-12T10:43:49.366Z] 10:43:49 INFO - ==> process 5995 launched child process 6013
[task 2022-02-12T10:43:49.367Z] 10:43:49 INFO - ==> process 5995 launched child process 6065
[task 2022-02-12T10:43:49.368Z] 10:43:49 INFO - ==> process 5995 launched child process 6089
[task 2022-02-12T10:43:49.369Z] 10:43:49 INFO - ==> process 5995 launched child process 6116
[task 2022-02-12T10:43:49.370Z] 10:43:49 INFO - ==> process 5995 launched child process 6154
[task 2022-02-12T10:43:49.371Z] 10:43:49 INFO - ==> process 5995 launched child process 6249
[task 2022-02-12T10:43:49.372Z] 10:43:49 INFO - ==> process 5995 launched child process 7587
[task 2022-02-12T10:43:49.372Z] 10:43:49 INFO - ==> process 5995 launched child process 8026
[task 2022-02-12T10:43:49.373Z] 10:43:49 INFO - ==> process 5995 launched child process 8764
[task 2022-02-12T10:43:49.374Z] 10:43:49 INFO - ==> process 5995 launched child process 9385
[task 2022-02-12T10:43:49.375Z] 10:43:49 INFO - ==> process 5995 launched child process 9399
[task 2022-02-12T10:43:49.375Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 7587
[task 2022-02-12T10:43:49.376Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 6116
[task 2022-02-12T10:43:49.377Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 6089
[task 2022-02-12T10:43:49.378Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 6154
[task 2022-02-12T10:43:49.378Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 6249
[task 2022-02-12T10:43:49.379Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 9385
[task 2022-02-12T10:43:49.380Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 6065
[task 2022-02-12T10:43:49.381Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 9399
[task 2022-02-12T10:43:49.382Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 8026
[task 2022-02-12T10:43:49.382Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 8764
[task 2022-02-12T10:43:49.383Z] 10:43:49 INFO - zombiecheck | Checking for orphan process with PID: 6013
[task 2022-02-12T10:43:49.384Z] 10:43:49 INFO - Stopping web server
[task 2022-02-12T10:43:49.385Z] 10:43:49 INFO - Server shut down.
[task 2022-02-12T10:43:49.406Z] 10:43:49 INFO - Web server killed.
[task 2022-02-12T10:43:49.406Z] 10:43:49 INFO - Stopping web socket server
[task 2022-02-12T10:43:49.426Z] 10:43:49 INFO - Stopping ssltunnel
[task 2022-02-12T10:43:49.447Z] 10:43:49 INFO - websocket/process bridge listening on port 8191
[task 2022-02-12T10:43:49.508Z] 10:43:49 INFO - Stopping websocket/process bridge
[task 2022-02-12T10:43:49.508Z] 10:43:49 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2022-02-12T10:43:49.509Z] 10:43:49 INFO - runtests.py | Running tests: end.
[task 2022-02-12T10:43:49.549Z] 10:43:49 INFO - Buffered messages finished
[task 2022-02-12T10:43:49.549Z] 10:43:49 INFO - Running manifest: dom/media/webspeech/recognition/test/mochitest.ini
[task 2022-02-12T10:43:49.579Z] 10:43:49 INFO - Setting pipeline to PAUSED ...
[task 2022-02-12T10:43:49.580Z] 10:43:49 INFO - Pipeline is PREROLLING ...
[task 2022-02-12T10:43:49.582Z] 10:43:49 INFO - Pipeline is PREROLLED ...
[task 2022-02-12T10:43:49.582Z] 10:43:49 INFO - Setting pipeline to PLAYING ...
[task 2022-02-12T10:43:49.583Z] 10:43:49 INFO - New clock: GstSystemClock
[task 2022-02-12T10:43:49.615Z] 10:43:49 INFO - Got EOS from element "pipeline0".
[task 2022-02-12T10:43:49.616Z] 10:43:49 INFO - Execution ended after 0:00:00.033415729
[task 2022-02-12T10:43:49.616Z] 10:43:49 INFO - Setting pipeline to PAUSED ...
[task 2022-02-12T10:43:49.617Z] 10:43:49 INFO - Setting pipeline to READY ...
[task 2022-02-12T10:43:49.617Z] 10:43:49 INFO - (gst-launch-1.0:9477): GStreamer-CRITICAL **: 10:43:49.616: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2022-02-12T10:43:49.618Z] 10:43:49 INFO - Setting pipeline to NULL ...
[task 2022-02-12T10:43:49.619Z] 10:43:49 INFO - Freeing pipeline ...
[task 2022-02-12T10:43:49.655Z] 10:43:49 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-02-12T10:43:49.661Z] 10:43:49 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-02-12T10:43:49.661Z] 10:43:49 INFO - UBSan enabled.
[task 2022-02-12T10:43:49.966Z] 10:43:49 INFO - PID 9492 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2022-02-12T10:43:50.063Z] 10:43:50 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-02-12T10:43:50.067Z] 10:43:50 INFO - LSan enabled.
[task 2022-02-12T10:43:50.068Z] 10:43:50 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-02-12T10:43:50.068Z] 10:43:50 INFO - UBSan enabled.
[task 2022-02-12T10:43:50.069Z] 10:43:50 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-02-12T10:43:50.072Z] 10:43:50 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-02-12T10:43:50.072Z] 10:43:50 INFO - UBSan enabled.
[task 2022-02-12T10:43:50.081Z] 10:43:50 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/tmpdrrpv5bo.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-02-12T10:43:50.082Z] 10:43:50 INFO - runtests.py | Server pid: 9502
[task 2022-02-12T10:43:50.095Z] 10:43:50 INFO - runtests.py | Websocket server pid: 9505
[task 2022-02-12T10:43:50.103Z] 10:43:50 INFO - runtests.py | websocket/process bridge pid: 9509
[task 2022-02-12T10:43:50.607Z] 10:43:50 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-02-12T10:43:50.613Z] 10:43:50 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-02-12T10:43:50.615Z] 10:43:50 INFO - UBSan enabled.
[task 2022-02-12T10:43:50.620Z] 10:43:50 INFO - runtests.py | SSL tunnel pid: 9524
[task 2022-02-12T10:43:50.622Z] 10:43:50 INFO - runtests.py | Running with scheme: http
[task 2022-02-12T10:43:50.622Z] 10:43:50 INFO - runtests.py | Running with e10s: True
[task 2022-02-12T10:43:50.622Z] 10:43:50 INFO - runtests.py | Running with fission: False
[task 2022-02-12T10:43:50.622Z] 10:43:50 INFO - runtests.py | Running with cross-origin iframes: False
[task 2022-02-12T10:43:50.622Z] 10:43:50 INFO - runtests.py | Running with serviceworker_e10s: True
[task 2022-02-12T10:43:50.624Z] 10:43:50 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2022-02-12T10:43:50.624Z] 10:43:50 INFO - runtests.py | Running tests: start.
[task 2022-02-12T10:43:50.624Z] 10:43:50 INFO -
[task 2022-02-12T10:43:50.645Z] 10:43:50 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpdrrpv5bo.mozrunner
[task 2022-02-12T10:43:50.653Z] 10:43:50 INFO - runtests.py | Application pid: 9532
[task 2022-02-12T10:43:50.654Z] 10:43:50 INFO - TEST-INFO | started process GECKO(9532)
[task 2022-02-12T10:43:52.006Z] 10:43:52 INFO - GECKO(9532) | 1644662632005 Marionette INFO Marionette enabled
[task 2022-02-12T10:43:52.209Z] 10:43:52 INFO - GECKO(9532) | 1644662632208 Marionette TRACE Received observer notification toplevel-window-ready
[task 2022-02-12T10:43:57.853Z] 10:43:57 INFO - GECKO(9532) | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpdrrpv5bo.mozrunner/search.json.mozlz4", (void 0)))
[task 2022-02-12T10:44:00.040Z] 10:44:00 INFO - GECKO(9532) | 1644662640039 Marionette TRACE Received observer notification marionette-startup-requested
[task 2022-02-12T10:44:00.042Z] 10:44:00 INFO - GECKO(9532) | 1644662640041 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2022-02-12T10:44:00.083Z] 10:44:00 INFO - GECKO(9532) | 1644662640082 Marionette TRACE All scripts recorded.
[task 2022-02-12T10:44:00.089Z] 10:44:00 INFO - GECKO(9532) | 1644662640088 Marionette INFO Listening on port 2828
[task 2022-02-12T10:44:00.091Z] 10:44:00 INFO - GECKO(9532) | 1644662640089 Marionette DEBUG Marionette is listening
[task 2022-02-12T10:44:00.145Z] 10:44:00 INFO - GECKO(9532) | 1644662640144 Marionette DEBUG Accepted connection 0 from 127.0.0.1:50818
[task 2022-02-12T10:44:00.157Z] 10:44:00 INFO - GECKO(9532) | 1644662640156 Marionette DEBUG Accepted connection 1 from 127.0.0.1:50820
[task 2022-02-12T10:44:00.167Z] 10:44:00 INFO - GECKO(9532) | 1644662640166 Marionette DEBUG Closed connection 0
[task 2022-02-12T10:44:00.210Z] 10:44:00 INFO - GECKO(9532) | 1644662640209 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-02-12T10:44:00.253Z] 10:44:00 INFO - GECKO(9532) | 1644662640251 RemoteAgent TRACE [19] Document already finished loading: about:blank
[task 2022-02-12T10:44:00.270Z] 10:44:00 INFO - GECKO(9532) | 1644662640268 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"9a599eff-a171-4d34-baf1-27fdef767963","capabilities":{"browserName":"firefox","browserVersion":"99.0a ... .mozrunner","moz:shutdownTimeout":300000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2022-02-12T10:44:00.303Z] 10:44:00 INFO - GECKO(9532) | 1644662640302 Marionette DEBUG 1 -> [0,2,"Addon:Install",{"path":"/tmp/tmp6txq2jdt.zip","temporary":false}]
[task 2022-02-12T10:44:00.601Z] 10:44:00 INFO - GECKO(9532) | 1644662640600 Marionette DEBUG 1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2022-02-12T10:44:00.672Z] 10:44:00 INFO - GECKO(9532) | 1644662640671 Marionette DEBUG 1 -> [0,3,"Addon:Install",{"path":"/tmp/tmp1rvjph_s.zip","temporary":false}]
[task 2022-02-12T10:44:00.758Z] 10:44:00 INFO - GECKO(9532) | 1644662640757 Marionette DEBUG 1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2022-02-12T10:44:00.762Z] 10:44:00 INFO - GECKO(9532) | 1644662640761 Marionette DEBUG 1 -> [0,4,"Marionette:GetContext",{}]
[task 2022-02-12T10:44:00.764Z] 10:44:00 INFO - GECKO(9532) | 1644662640763 Marionette DEBUG 1 <- [1,4,null,{"value":"content"}]
[task 2022-02-12T10:44:00.766Z] 10:44:00 INFO - GECKO(9532) | 1644662640765 Marionette DEBUG 1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-02-12T10:44:00.767Z] 10:44:00 INFO - GECKO(9532) | 1644662640766 Marionette DEBUG 1 <- [1,5,null,{"value":null}]
[task 2022-02-12T10:44:00.770Z] 10:44:00 INFO - GECKO(9532) | 1644662640768 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":1989,"filename":"tests/mochitest/runtests.py"}]
[task 2022-02-12T10:44:00.790Z] 10:44:00 INFO - GECKO(9532) | 1644662640789 Marionette TRACE [7] MarionetteCommands actor created for window id 2
[task 2022-02-12T10:44:00.805Z] 10:44:00 INFO - GECKO(9532) | 1644662640803 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2022-02-12T10:44:00.811Z] 10:44:00 INFO - GECKO(9532) | 1644662640810 Marionette DEBUG 1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-12T10:44:00.812Z] 10:44:00 INFO - GECKO(9532) | 1644662640811 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2022-02-12T10:44:00.866Z] 10:44:00 INFO - GECKO(9532) | 1644662640864 Marionette DEBUG 1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2022-02-12T10:44:00.875Z] 10:44:00 INFO - GECKO(9532) | 1644662640871 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2022-02-12T10:44:00.890Z] 10:44:00 INFO - runtests.py | Waiting for browser...
[task 2022-02-12T10:44:00.907Z] 10:44:00 INFO - GECKO(9532) | 1644662640906 Marionette DEBUG Closed connection 1
[task 2022-02-12T10:44:01.937Z] 10:44:01 INFO - SimpleTest START
[task 2022-02-12T10:44:01.940Z] 10:44:01 INFO - Dumping test context:
[task 2022-02-12T10:44:01.940Z] 10:44:01 INFO - fission.autostart=false
[task 2022-02-12T10:44:01.963Z] 10:44:01 INFO - TEST-START | dom/media/webspeech/recognition/test/test_abort.html
Description
•