Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=369586195&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BEUpsw9TQIOmsAJ_QmLcYA/runs/0/artifacts/public/logs/live_backing.log
[task 2022-03-01T17:15:44.985Z] 17:15:44 INFO - TEST-START | devtools/client/performance-new/test/browser/browser_webchannel-enable-menu-button.js
[task 2022-03-01T17:15:46.223Z] 17:15:46 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:46.223Z] 17:15:46 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:46.223Z] 17:15:46 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:46.223Z] 17:15:46 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:46.223Z] 17:15:46 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:46.223Z] 17:15:46 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:46.690Z] 17:15:46 INFO - GECKO(3705) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:46.691Z] 17:15:46 INFO - GECKO(3705) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:46.731Z] 17:15:46 INFO - GECKO(3705) | MEMORY STAT | vsize 20984052MB | residentFast 1459MB
[task 2022-03-01T17:15:46.733Z] 17:15:46 INFO - TEST-OK | devtools/client/performance-new/test/browser/browser_webchannel-enable-menu-button.js | took 1748ms
[task 2022-03-01T17:15:46.769Z] 17:15:46 INFO - checking window state
[task 2022-03-01T17:15:47.496Z] 17:15:47 INFO - GECKO(3705) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:47.496Z] 17:15:47 INFO - GECKO(3705) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:47.504Z] 17:15:47 INFO - GECKO(3705) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:47.512Z] 17:15:47 INFO - GECKO(3705) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:47.512Z] 17:15:47 INFO - GECKO(3705) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:48.521Z] 17:15:48 INFO - GECKO(3705) | Completed ShutdownLeaks collections in process 3790
[task 2022-03-01T17:15:48.556Z] 17:15:48 INFO - GECKO(3705) | Completed ShutdownLeaks collections in process 3841
[task 2022-03-01T17:15:48.559Z] 17:15:48 INFO - GECKO(3705) | Completed ShutdownLeaks collections in process 3833
[task 2022-03-01T17:15:48.615Z] 17:15:48 INFO - GECKO(3705) | Completed ShutdownLeaks collections in process 3835
[task 2022-03-01T17:15:48.634Z] 17:15:48 INFO - GECKO(3705) | Completed ShutdownLeaks collections in process 3808
[task 2022-03-01T17:15:48.735Z] 17:15:48 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:48.736Z] 17:15:48 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:48.738Z] 17:15:48 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:48.738Z] 17:15:48 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:48.738Z] 17:15:48 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:48.738Z] 17:15:48 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:48.797Z] 17:15:48 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:48.798Z] 17:15:48 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:48.799Z] 17:15:48 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:48.799Z] 17:15:48 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:48.799Z] 17:15:48 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:48.799Z] 17:15:48 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:48.817Z] 17:15:48 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:48.817Z] 17:15:48 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:48.818Z] 17:15:48 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:48.818Z] 17:15:48 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:48.819Z] 17:15:48 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:48.819Z] 17:15:48 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:48.864Z] 17:15:48 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:48.864Z] 17:15:48 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:48.865Z] 17:15:48 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:48.865Z] 17:15:48 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:48.866Z] 17:15:48 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:48.866Z] 17:15:48 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:49.894Z] 17:15:49 INFO - GECKO(3705) | Completed ShutdownLeaks collections in process 3705
[task 2022-03-01T17:15:49.895Z] 17:15:49 INFO - TEST-START | Shutdown
[task 2022-03-01T17:15:49.896Z] 17:15:49 INFO - Browser Chrome Test Summary
[task 2022-03-01T17:15:49.897Z] 17:15:49 INFO - Passed: 177
[task 2022-03-01T17:15:49.897Z] 17:15:49 INFO - Failed: 0
[task 2022-03-01T17:15:49.897Z] 17:15:49 INFO - Todo: 0
[task 2022-03-01T17:15:49.897Z] 17:15:49 INFO - Mode: e10s
[task 2022-03-01T17:15:49.898Z] 17:15:49 INFO - *** End BrowserChrome Test Results ***
[task 2022-03-01T17:15:50.337Z] 17:15:50 INFO - GECKO(3705) | 1646154950335 Marionette TRACE Received observer notification quit-application
[task 2022-03-01T17:15:50.338Z] 17:15:50 INFO - GECKO(3705) | 1646154950335 Marionette INFO Stopped listening on port 2828
[task 2022-03-01T17:15:50.338Z] 17:15:50 INFO - GECKO(3705) | 1646154950336 Marionette DEBUG Marionette stopped listening
[task 2022-03-01T17:15:50.499Z] 17:15:50 INFO - GECKO(3705) | JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-03-01T17:15:50.502Z] 17:15:50 INFO - GECKO(3705) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:50.504Z] 17:15:50 INFO - GECKO(3705) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:50.589Z] 17:15:50 INFO - GECKO(3705) | JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-03-01T17:15:50.590Z] 17:15:50 INFO - GECKO(3705) | JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-03-01T17:15:50.599Z] 17:15:50 INFO - GECKO(3705) | JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-03-01T17:15:50.609Z] 17:15:50 INFO - GECKO(3705) | JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-03-01T17:15:50.618Z] 17:15:50 INFO - GECKO(3705) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:50.619Z] 17:15:50 INFO - GECKO(3705) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:50.630Z] 17:15:50 INFO - GECKO(3705) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:50.633Z] 17:15:50 INFO - GECKO(3705) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:50.639Z] 17:15:50 INFO - GECKO(3705) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:50.641Z] 17:15:50 INFO - GECKO(3705) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:50.657Z] 17:15:50 INFO - GECKO(3705) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-01T17:15:53.331Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.332Z] 17:15:53 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:53.333Z] 17:15:53 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:53.334Z] 17:15:53 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:53.335Z] 17:15:53 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:53.335Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.580Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.580Z] 17:15:53 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:53.580Z] 17:15:53 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:53.580Z] 17:15:53 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:53.580Z] 17:15:53 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:53.581Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.678Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.678Z] 17:15:53 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:53.678Z] 17:15:53 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:53.678Z] 17:15:53 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:53.678Z] 17:15:53 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:53.678Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.695Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.696Z] 17:15:53 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:53.697Z] 17:15:53 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:53.698Z] 17:15:53 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:53.699Z] 17:15:53 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:53.699Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.704Z] 17:15:53 INFO - GECKO(3705) | Waiting in WillDestroyCurrentMessageLoop for pid 3808
[task 2022-03-01T17:15:53.746Z] 17:15:53 INFO - GECKO(3705) | Waiting in WillDestroyCurrentMessageLoop for pid 3833
[task 2022-03-01T17:15:53.781Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.781Z] 17:15:53 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:53.782Z] 17:15:53 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:53.782Z] 17:15:53 INFO - GECKO(3705) | 13 416 nsComponentManagerImpl
[task 2022-03-01T17:15:53.783Z] 17:15:53 INFO - GECKO(3705) | 2 288 libfontconfig.so
[task 2022-03-01T17:15:53.783Z] 17:15:53 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:53.822Z] 17:15:53 INFO - GECKO(3705) | Waiting in WillDestroyCurrentMessageLoop for pid 3841
[task 2022-03-01T17:15:58.486Z] 17:15:58 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:58.487Z] 17:15:58 INFO - GECKO(3705) | Suppressions used:
[task 2022-03-01T17:15:58.488Z] 17:15:58 INFO - GECKO(3705) | count bytes template
[task 2022-03-01T17:15:58.489Z] 17:15:58 INFO - GECKO(3705) | 13 400 nsComponentManagerImpl
[task 2022-03-01T17:15:58.489Z] 17:15:58 INFO - GECKO(3705) | 633 18115 libfontconfig.so
[task 2022-03-01T17:15:58.489Z] 17:15:58 INFO - GECKO(3705) | 1 9 libglib-2.0.so
[task 2022-03-01T17:15:58.489Z] 17:15:58 INFO - GECKO(3705) | 2 416 mozJSComponentLoader
[task 2022-03-01T17:15:58.489Z] 17:15:58 INFO - GECKO(3705) | 2 48 XPCWrappedNativeJSOps
[task 2022-03-01T17:15:58.490Z] 17:15:58 INFO - GECKO(3705) | -----------------------------------------------------
[task 2022-03-01T17:15:58.733Z] 17:15:58 INFO - TEST-INFO | Main app process: exit 0
[task 2022-03-01T17:15:58.733Z] 17:15:58 INFO - TEST-INFO | LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2022-03-01T17:15:58.734Z] 17:15:58 INFO - TEST-INFO | LeakSanitizer | This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2022-03-01T17:15:58.734Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at MakeUnique, mozilla::baseprofiler::ChunkedJSONWriteFunc::AllocChunk, mozilla::baseprofiler::ChunkedJSONWriteFunc::Write, mozilla::JSONWriter::EndCollection
[task 2022-03-01T17:15:58.735Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at maybe_pod_realloc, pod_realloc, growTo, mozilla::Vector
[task 2022-03-01T17:15:58.735Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at MakeUnique, mozilla::ProfilerChild::GatherProfileThreadFunction, _pt_root, start_thread
[task 2022-03-01T17:15:58.735Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at maybe_pod_malloc, pod_malloc, mozilla::detail::VectorImpl, append
[task 2022-03-01T17:15:58.736Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::PProfilerChild::OnMessageReceived, mozilla::ipc::MessageChannel::DispatchAsyncMessage, mozilla::ipc::MessageChannel::DispatchMessage, mozilla::ipc::MessageChannel::MessageTask::Run
[task 2022-03-01T17:15:58.736Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at _M_init_functor, _M_init_functor, function, mozilla::PProfilerChild::OnMessageReceived
[task 2022-03-01T17:15:58.736Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::ipc::ActorLifecycleProxy::GetWeakProxy, mozilla::ipc::IPDLResolverInner::IPDLResolverInner, mozilla::PProfilerChild::OnMessageReceived, mozilla::ipc::MessageChannel::DispatchAsyncMessage
[task 2022-03-01T17:15:58.737Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at pod_malloc, mozilla::BufferList, Pickle::Pickle, IPC::Message::Message
[task 2022-03-01T17:15:58.737Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at MakeUnique, mozilla::baseprofiler::ChunkedJSONWriteFunc::AllocChunk, MakeUnique, mozilla::baseprofiler::SpliceableChunkedJSONWriter::SpliceableChunkedJSONWriter
[task 2022-03-01T17:15:58.737Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at MakeRefPtr, mozilla::ProfilerChild::RecvGatherProfile, mozilla::PProfilerChild::OnMessageReceived, mozilla::ipc::MessageChannel::DispatchAsyncMessage
[task 2022-03-01T17:15:58.738Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::ChildProfilerController::SetupProfilerChild, applyImpl, apply, mozilla::detail::RunnableMethodImpl
[task 2022-03-01T17:15:58.738Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at RefPtr, mozilla::ProfilerChild::RecvGatherProfile, mozilla::PProfilerChild::OnMessageReceived, mozilla::ipc::MessageChannel::DispatchAsyncMessage
[task 2022-03-01T17:15:58.738Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at NS_NewRunnableFunction, mozilla::ProfilerChild::GatherProfileThreadFunction, _pt_root, start_thread
[task 2022-03-01T17:15:58.739Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at IPC::Message::IPDLMessage, Reply_GatherProfile, mozilla::PProfilerChild::OnMessageReceived, mozilla::ipc::MessageChannel::DispatchAsyncMessage
[task 2022-03-01T17:15:58.739Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at MakeUnique, mozilla::baseprofiler::SpliceableChunkedJSONWriter::SpliceableChunkedJSONWriter, MakeUnique, mozilla::ProfilerChild::GatherProfileThreadFunction
[task 2022-03-01T17:15:58.739Z] 17:15:58 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::ipc::MessageChannel::MessageChannel, mozilla::ipc::IToplevelProtocol::IToplevelProtocol, mozilla::PProfilerChild::PProfilerChild, mozilla::ProfilerChild::ProfilerChild
[task 2022-03-01T17:15:58.739Z] 17:15:58 INFO - runtests.py | Application ran for: 0:02:47.122806
[task 2022-03-01T17:15:58.740Z] 17:15:58 INFO - zombiecheck | Reading PID log: /tmp/tmphsu_kp7jpidlog
[task 2022-03-01T17:15:58.740Z] 17:15:58 INFO - ==> process 3705 launched child process 3726
[task 2022-03-01T17:15:58.740Z] 17:15:58 INFO - ==> process 3705 launched child process 3790
[task 2022-03-01T17:15:58.741Z] 17:15:58 INFO - ==> process 3705 launched child process 3808
[task 2022-03-01T17:15:58.741Z] 17:15:58 INFO - ==> process 3705 launched child process 3833
[task 2022-03-01T17:15:58.741Z] 17:15:58 INFO - ==> process 3705 launched child process 3835
[task 2022-03-01T17:15:58.741Z] 17:15:58 INFO - ==> process 3705 launched child process 3841
[task 2022-03-01T17:15:58.741Z] 17:15:58 INFO - ==> process 3705 launched child process 3944
[task 2022-03-01T17:15:58.742Z] 17:15:58 INFO - ==> process 3705 launched child process 3963
[task 2022-03-01T17:15:58.742Z] 17:15:58 INFO - ==> process 3705 launched child process 4201
[task 2022-03-01T17:15:58.742Z] 17:15:58 INFO - ==> process 3705 launched child process 4295
[task 2022-03-01T17:15:58.743Z] 17:15:58 INFO - ==> process 3705 launched child process 4307
[task 2022-03-01T17:15:58.743Z] 17:15:58 INFO - ==> process 3705 launched child process 4361
[task 2022-03-01T17:15:58.743Z] 17:15:58 INFO - ==> process 3705 launched child process 4363
[task 2022-03-01T17:15:58.743Z] 17:15:58 INFO - ==> process 3705 launched child process 4392
[task 2022-03-01T17:15:58.744Z] 17:15:58 INFO - ==> process 3705 launched child process 4418
[task 2022-03-01T17:15:58.744Z] 17:15:58 INFO - ==> process 3705 launched child process 4486
[task 2022-03-01T17:15:58.744Z] 17:15:58 INFO - ==> process 3705 launched child process 4516
[task 2022-03-01T17:15:58.744Z] 17:15:58 INFO - ==> process 3705 launched child process 4518
[task 2022-03-01T17:15:58.745Z] 17:15:58 INFO - ==> process 3705 launched child process 4520
[task 2022-03-01T17:15:58.745Z] 17:15:58 INFO - ==> process 3705 launched child process 4637
[task 2022-03-01T17:15:58.745Z] 17:15:58 INFO - ==> process 3705 launched child process 4669
[task 2022-03-01T17:15:58.746Z] 17:15:58 INFO - ==> process 3705 launched child process 4720
[task 2022-03-01T17:15:58.746Z] 17:15:58 INFO - ==> process 3705 launched child process 4760
[task 2022-03-01T17:15:58.746Z] 17:15:58 INFO - ==> process 3705 launched child process 4821
[task 2022-03-01T17:15:58.746Z] 17:15:58 INFO - ==> process 3705 launched child process 4876
[task 2022-03-01T17:15:58.747Z] 17:15:58 INFO - ==> process 3705 launched child process 4902
[task 2022-03-01T17:15:58.747Z] 17:15:58 INFO - ==> process 3705 launched child process 4904
[task 2022-03-01T17:15:58.747Z] 17:15:58 INFO - ==> process 3705 launched child process 4908
[task 2022-03-01T17:15:58.747Z] 17:15:58 INFO - ==> process 3705 launched child process 5036
[task 2022-03-01T17:15:58.748Z] 17:15:58 INFO - ==> process 3705 launched child process 5071
[task 2022-03-01T17:15:58.748Z] 17:15:58 INFO - ==> process 3705 launched child process 5086
[task 2022-03-01T17:15:58.748Z] 17:15:58 INFO - ==> process 3705 launched child process 5088
[task 2022-03-01T17:15:58.749Z] 17:15:58 INFO - ==> process 3705 launched child process 5154
[task 2022-03-01T17:15:58.749Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 3841
[task 2022-03-01T17:15:58.749Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4486
[task 2022-03-01T17:15:58.750Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4361
[task 2022-03-01T17:15:58.750Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4363
[task 2022-03-01T17:15:58.750Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4876
[task 2022-03-01T17:15:58.751Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 3726
[task 2022-03-01T17:15:58.751Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4760
[task 2022-03-01T17:15:58.752Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4637
[task 2022-03-01T17:15:58.752Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 5154
[task 2022-03-01T17:15:58.752Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4516
[task 2022-03-01T17:15:58.753Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4518
[task 2022-03-01T17:15:58.753Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4902
[task 2022-03-01T17:15:58.754Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4392
[task 2022-03-01T17:15:58.754Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4520
[task 2022-03-01T17:15:58.754Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4904
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4908
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 5036
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4669
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4418
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4295
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 3790
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 5071
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4307
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4821
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 5086
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 3835
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 3808
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 5088
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 3944
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4201
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 4720
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 3833
[task 2022-03-01T17:15:58.758Z] 17:15:58 INFO - zombiecheck | Checking for orphan process with PID: 3963
[task 2022-03-01T17:15:58.759Z] 17:15:58 INFO - Stopping web server
[task 2022-03-01T17:15:58.759Z] 17:15:58 INFO - Server shut down.
[task 2022-03-01T17:15:58.775Z] 17:15:58 INFO - Web server killed.
[task 2022-03-01T17:15:58.775Z] 17:15:58 INFO - Stopping web socket server
[task 2022-03-01T17:15:58.795Z] 17:15:58 INFO - Stopping ssltunnel
[task 2022-03-01T17:15:58.816Z] 17:15:58 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2022-03-01T17:15:58.816Z] 17:15:58 INFO - runtests.py | Running tests: end.
[task 2022-03-01T17:15:58.867Z] 17:15:58 INFO - Buffered messages finished
[task 2022-03-01T17:15:58.867Z] 17:15:58 INFO - Running manifest: devtools/server/tests/browser/browser.ini
[task 2022-03-01T17:15:58.949Z] 17:15:58 INFO - Setting pipeline to PAUSED ...
[task 2022-03-01T17:15:58.949Z] 17:15:58 INFO - Pipeline is PREROLLING ...
[task 2022-03-01T17:15:58.954Z] 17:15:58 INFO - Pipeline is PREROLLED ...
[task 2022-03-01T17:15:58.954Z] 17:15:58 INFO - Setting pipeline to PLAYING ...
[task 2022-03-01T17:15:58.954Z] 17:15:58 INFO - New clock: GstSystemClock
[task 2022-03-01T17:15:58.987Z] 17:15:58 INFO - Got EOS from element "pipeline0".
[task 2022-03-01T17:15:58.987Z] 17:15:58 INFO - Execution ended after 0:00:00.033447250
[task 2022-03-01T17:15:58.988Z] 17:15:58 INFO - Setting pipeline to PAUSED ...
[task 2022-03-01T17:15:58.988Z] 17:15:58 INFO - Setting pipeline to READY ...
[task 2022-03-01T17:15:58.989Z] 17:15:58 INFO - (gst-launch-1.0:5245): GStreamer-CRITICAL **: 17:15:58.987: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2022-03-01T17:15:58.989Z] 17:15:58 INFO - Setting pipeline to NULL ...
[task 2022-03-01T17:15:58.989Z] 17:15:58 INFO - Freeing pipeline ...
[task 2022-03-01T17:15:59.049Z] 17:15:59 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-03-01T17:15:59.055Z] 17:15:59 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-03-01T17:15:59.055Z] 17:15:59 INFO - UBSan enabled.
[task 2022-03-01T17:15:59.363Z] 17:15:59 INFO - PID 5257 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2022-03-01T17:15:59.554Z] 17:15:59 INFO - Increasing default timeout to 90 seconds
[task 2022-03-01T17:15:59.555Z] 17:15:59 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-03-01T17:15:59.558Z] 17:15:59 INFO - LSan enabled.
[task 2022-03-01T17:15:59.559Z] 17:15:59 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-03-01T17:15:59.559Z] 17:15:59 INFO - UBSan enabled.
[task 2022-03-01T17:15:59.559Z] 17:15:59 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-03-01T17:15:59.563Z] 17:15:59 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-03-01T17:15:59.564Z] 17:15:59 INFO - UBSan enabled.
[task 2022-03-01T17:15:59.568Z] 17:15:59 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/tmpp50p5saw.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-03-01T17:15:59.568Z] 17:15:59 INFO - runtests.py | Server pid: 5270
[task 2022-03-01T17:15:59.571Z] 17:15:59 INFO - runtests.py | Websocket server pid: 5273
[task 2022-03-01T17:15:59.572Z] 17:15:59 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-03-01T17:15:59.576Z] 17:15:59 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-03-01T17:15:59.576Z] 17:15:59 INFO - UBSan enabled.
[task 2022-03-01T17:15:59.581Z] 17:15:59 INFO - runtests.py | SSL tunnel pid: 5279
[task 2022-03-01T17:15:59.783Z] 17:15:59 INFO - runtests.py | Running with scheme: http
[task 2022-03-01T17:15:59.784Z] 17:15:59 INFO - runtests.py | Running with e10s: True
[task 2022-03-01T17:15:59.784Z] 17:15:59 INFO - runtests.py | Running with fission: True
[task 2022-03-01T17:15:59.785Z] 17:15:59 INFO - runtests.py | Running with cross-origin iframes: False
[task 2022-03-01T17:15:59.785Z] 17:15:59 INFO - runtests.py | Running with serviceworker_e10s: True
[task 2022-03-01T17:15:59.786Z] 17:15:59 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2022-03-01T17:15:59.786Z] 17:15:59 INFO - runtests.py | Running tests: start.
[task 2022-03-01T17:15:59.786Z] 17:15:59 INFO -
[task 2022-03-01T17:15:59.801Z] 17:15:59 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpp50p5saw.mozrunner
[task 2022-03-01T17:15:59.805Z] 17:15:59 INFO - runtests.py | Application pid: 5298
[task 2022-03-01T17:15:59.805Z] 17:15:59 INFO - TEST-INFO | started process GECKO(5298)
[task 2022-03-01T17:16:01.143Z] 17:16:01 INFO - GECKO(5298) | 1646154961142 Marionette INFO Marionette enabled
[task 2022-03-01T17:16:01.375Z] 17:16:01 INFO - GECKO(5298) | 1646154961374 Marionette TRACE Received observer notification toplevel-window-ready
[task 2022-03-01T17:16:06.382Z] 17:16:06 INFO - GECKO(5298) | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpp50p5saw.mozrunner/search.json.mozlz4", (void 0)))
[task 2022-03-01T17:16:08.072Z] 17:16:08 INFO - GECKO(5298) | 1646154968071 Marionette TRACE Received observer notification marionette-startup-requested
[task 2022-03-01T17:16:08.074Z] 17:16:08 INFO - GECKO(5298) | 1646154968071 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2022-03-01T17:16:08.123Z] 17:16:08 INFO - GECKO(5298) | 1646154968120 Marionette TRACE All scripts recorded.
[task 2022-03-01T17:16:08.138Z] 17:16:08 INFO - GECKO(5298) | 1646154968137 Marionette INFO Listening on port 2828
[task 2022-03-01T17:16:08.140Z] 17:16:08 INFO - GECKO(5298) | 1646154968138 Marionette DEBUG Marionette is listening
[task 2022-03-01T17:16:08.267Z] 17:16:08 INFO - GECKO(5298) | 1646154968266 Marionette DEBUG Accepted connection 0 from 127.0.0.1:46908
[task 2022-03-01T17:16:08.274Z] 17:16:08 INFO - GECKO(5298) | 1646154968273 Marionette DEBUG Closed connection 0
[task 2022-03-01T17:16:08.276Z] 17:16:08 INFO - GECKO(5298) | 1646154968273 Marionette DEBUG Accepted connection 1 from 127.0.0.1:46910
[task 2022-03-01T17:16:08.306Z] 17:16:08 INFO - GECKO(5298) | 1646154968304 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-03-01T17:16:08.366Z] 17:16:08 INFO - GECKO(5298) | 1646154968365 RemoteAgent TRACE [19] Document already finished loading: about:blank
[task 2022-03-01T17:16:08.381Z] 17:16:08 INFO - GECKO(5298) | 1646154968379 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"46c933ce-cd7a-44f7-8018-e2ac24c808b9","capabilities":{"browserName":"firefox","browserVersion":"99.0a ... .mozrunner","moz:shutdownTimeout":300000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2022-03-01T17:16:08.402Z] 17:16:08 INFO - GECKO(5298) | 1646154968401 Marionette DEBUG 1 -> [0,2,"Addon:Install",{"path":"/tmp/tmp6bato8ok.zip","temporary":false}]
[task 2022-03-01T17:16:08.562Z] 17:16:08 INFO - GECKO(5298) | 1646154968561 Marionette DEBUG 1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2022-03-01T17:16:08.603Z] 17:16:08 INFO - GECKO(5298) | 1646154968602 Marionette DEBUG 1 -> [0,3,"Addon:Install",{"path":"/tmp/tmpnyt9q0a6.zip","temporary":false}]
[task 2022-03-01T17:16:08.645Z] 17:16:08 INFO - GECKO(5298) | 1646154968643 Marionette DEBUG 1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2022-03-01T17:16:08.650Z] 17:16:08 INFO - GECKO(5298) | 1646154968649 Marionette DEBUG 1 -> [0,4,"Marionette:GetContext",{}]
[task 2022-03-01T17:16:08.651Z] 17:16:08 INFO - GECKO(5298) | 1646154968650 Marionette DEBUG 1 <- [1,4,null,{"value":"content"}]
[task 2022-03-01T17:16:08.653Z] 17:16:08 INFO - GECKO(5298) | 1646154968652 Marionette DEBUG 1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-03-01T17:16:08.654Z] 17:16:08 INFO - GECKO(5298) | 1646154968653 Marionette DEBUG 1 <- [1,5,null,{"value":null}]
[task 2022-03-01T17:16:08.658Z] 17:16:08 INFO - GECKO(5298) | 1646154968657 Marionette DEBUG 1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, ... hrome","testUrl":"about:blank"}],"newSandbox":true,"sandbox":"default","line":1989,"filename":"tests/mochitest/runtests.py"}]
[task 2022-03-01T17:16:08.667Z] 17:16:08 INFO - GECKO(5298) | 1646154968666 Marionette TRACE [7] MarionetteCommands actor created for window id 2
[task 2022-03-01T17:16:08.715Z] 17:16:08 INFO - GECKO(5298) | 1646154968714 Marionette TRACE Received observer notification domwindowopened
[task 2022-03-01T17:16:08.726Z] 17:16:08 INFO - GECKO(5298) | 1646154968724 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2022-03-01T17:16:08.728Z] 17:16:08 INFO - GECKO(5298) | 1646154968727 Marionette DEBUG 1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2022-03-01T17:16:08.729Z] 17:16:08 INFO - GECKO(5298) | 1646154968728 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2022-03-01T17:16:08.800Z] 17:16:08 INFO - GECKO(5298) | 1646154968799 Marionette DEBUG 1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2022-03-01T17:16:08.804Z] 17:16:08 INFO - GECKO(5298) | 1646154968803 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2022-03-01T17:16:08.821Z] 17:16:08 INFO - runtests.py | Waiting for browser...
[task 2022-03-01T17:16:08.828Z] 17:16:08 INFO - GECKO(5298) | 1646154968822 Marionette DEBUG Closed connection 1
[task 2022-03-01T17:16:09.793Z] 17:16:09 INFO - *** Start BrowserChrome Test Results ***
[task 2022-03-01T17:16:09.881Z] 17:16:09 INFO - checking window state
[task 2022-03-01T17:16:09.977Z] 17:16:09 INFO - TEST-START | devtools/server/tests/browser/browser_accessibility_highlighter_infobar.js
Description
•