Closed Bug 1757610 Opened 3 years ago Closed 2 years ago

Intermittent LeakSanitizer | leak at MakeUnique, mozilla::baseprofiler::ChunkedJSONWriteFunc::AllocChunk, mozilla::baseprofiler::ChunkedJSONWriteFunc::Write, mozilla::JSONWriter::EndCollection

Categories

(Core :: Gecko Profiler, defect, P3)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1790318
Tracking Status
firefox-esr91 --- unaffected
firefox97 --- unaffected
firefox98 --- unaffected
firefox99 --- wontfix
firefox100 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

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

It looks like chunks of a generated json profile leaked, and a RunnableFunction.

I see above: "JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'" and then a few IPC errors due to a channel closing, maybe that's linked?

Anyway I think this is due to bug 1668867, where the profile json is now generated in a separate thread, and then forwarded through a RunnableFunction to the IPC thread.
The direct leak is from the NS_NewRunnableFunction, maybe it's not dispatched correctly and just gets leaked?
We probably need to take better measures in such a situation, to handle failed dispatches.

I don't think the leak is high-priority: It's only happening when the profiler is running; and given the channel getting closed, it would be near the end of the process lifetime, so all this memory will go away soon anyway.

Component: Performance Tools (Profiler/Timeline) → Gecko Profiler
Priority: P5 → P3
Product: DevTools → Core
Regressed by: 1668867

Set release status flags based on info from the regressing bug 1668867

Has Regression Range: --- → yes

Set release status flags based on info from the regressing bug 1668867

In bug 1612799 that recently landed, the MakeUnique call was changed to MakeUniqueFallible. So failures will progressively shift from the former to the latter.
Marking this bug here as duplicate of bug 1790318, which captures the udpated MakeUniqueFallible signature.

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.