Closed Bug 1770558 Opened 2 years ago Closed 2 years ago

Intermittent LeakSanitizer | leak at RefPtr, mozilla::RemoteDecoderManagerChild::LaunchUtilityProcessIfNeeded, mozilla::RemoteDecoderManagerChild::Supports, mozilla::RemoteDecoderModule::Supports

Categories

(Core :: Audio/Video: Playback, defect, P5)

Product:
Core
Component:
Audio/Video: Playback
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
102 Branch
Tracking Flags:
Tracking Status
firefox102 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: gerard-majax)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Bug 1770558 - Ensure proper handling of returned promise r?alwu!
48 bytes, text/x-phabricator-request
Details | Review

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=378848866&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/A6mNhvStQy6dkSkrg6i3uQ/runs/0/artifacts/public/logs/live_backing.log

[task 2022-05-21T07:44:31.357Z] 07:44:31     INFO - TEST-START | /media-capabilities/idlharness.any.worker.html
<...>
[task 2022-05-21T07:44:38.641Z] 07:44:38     INFO - PID 13993 | Indirect leak of 32 byte(s) in 1 object(s) allocated from:
[task 2022-05-21T07:44:38.642Z] 07:44:38     INFO - PID 13993 |     #0 0x55f26661915e in malloc /builds/worker/fetches/llvm-project/compiler-rt/lib/asan/asan_malloc_linux.cpp:69:3
[task 2022-05-21T07:44:38.642Z] 07:44:38     INFO - PID 13993 |     #1 0x7f7c02c47a5e in Alloc /builds/worker/checkouts/gecko/xpcom/string/nsSubstring.cpp:206:42
[task 2022-05-21T07:44:38.642Z] 07:44:38     INFO - PID 13993 |     #2 0x7f7c02c47a5e in nsTSubstring<char>::StartBulkWriteImpl(unsigned long, unsigned long, bool, unsigned long, unsigned long, unsigned long) /builds/worker/checkouts/gecko/xpcom/string/nsTSubstring.cpp:196:32
[task 2022-05-21T07:44:38.642Z] 07:44:38     INFO - PID 13993 |     #3 0x7f7c02c57583 in nsTSubstring<char>::Assign(char const*, unsigned long, std::nothrow_t const&) /builds/worker/checkouts/gecko/xpcom/string/nsTSubstring.cpp:399:12
[task 2022-05-21T07:44:38.642Z] 07:44:38     INFO - PID 13993 |     #4 0x7f7c02c46a44 in nsTSubstring<char>::Assign(nsTSubstring<char> const&) /builds/worker/checkouts/gecko/xpcom/string/nsTSubstring.cpp:446:8
[task 2022-05-21T07:44:38.643Z] 07:44:38     INFO - PID 13993 |     #5 0x7f7c02eceabd in nsThread::SetThreadNameInternal(nsTSubstring<char> const&) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:640:9
[task 2022-05-21T07:44:38.644Z] 07:44:38     INFO - PID 13993 |     #6 0x7f7c02ec8879 in NS_SetCurrentThreadName(char const*) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:478:13
[task 2022-05-21T07:44:38.644Z] 07:44:38     INFO - PID 13993 |     #7 0x7f7c0ecc5e8d in mozilla::profiler::ThreadRegistry::Register(mozilla::profiler::ThreadRegistration::OnThreadRef) /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:6162:5
[task 2022-05-21T07:44:38.645Z] 07:44:38     INFO - PID 13993 |     #8 0x7f7c0ecc5b0f in mozilla::profiler::ThreadRegistration::ThreadRegistration(char const*, void const*) /builds/worker/checkouts/gecko/tools/profiler/core/ProfilerThreadRegistration.cpp:49:3
[task 2022-05-21T07:44:38.645Z] 07:44:38     INFO - PID 13993 |     #9 0x7f7c0ecc8956 in mozilla::profiler::ThreadRegistration::RegisterThread(char const*, void const*) /builds/worker/checkouts/gecko/tools/profiler/core/ProfilerThreadRegistration.cpp:139:32
[task 2022-05-21T07:44:38.648Z] 07:44:38     INFO - PID 13993 |     #10 0x7f7c02ecb61a in nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:370:5
[task 2022-05-21T07:44:38.648Z] 07:44:38     INFO - PID 13993 |     #11 0x7f7c294ac6de in _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5
[task 2022-05-21T07:44:38.648Z] 07:44:38     INFO - PID 13993 |     #12 0x7f7c291dc6da in start_thread /tmp/glibc/nptl/pthread_create.c:463
[task 2022-05-21T07:44:38.649Z] 07:44:38     INFO - PID 13993 | -----------------------------------------------------
[task 2022-05-21T07:44:38.649Z] 07:44:38     INFO - PID 13993 | Suppressions used:
[task 2022-05-21T07:44:38.649Z] 07:44:38     INFO - PID 13993 |   count      bytes template
[task 2022-05-21T07:44:38.650Z] 07:44:38     INFO - PID 13993 |      12        384 nsComponentManagerImpl
[task 2022-05-21T07:44:38.650Z] 07:44:38     INFO - PID 13993 |       2        288 libfontconfig.so
[task 2022-05-21T07:44:38.650Z] 07:44:38     INFO - PID 13993 | -----------------------------------------------------
[task 2022-05-21T07:44:38.650Z] 07:44:38     INFO - PID 13993 | Waiting in WillDestroyCurrentMessageLoop for pid 14623
[task 2022-05-21T07:44:38.651Z] 07:44:38     INFO - PID 13993 | Waiting in WillDestroyCurrentMessageLoop for pid 14581
[task 2022-05-21T07:44:39.536Z] 07:44:39     INFO - PID 13993 | -----------------------------------------------------
[task 2022-05-21T07:44:39.537Z] 07:44:39     INFO - PID 13993 | Suppressions used:
[task 2022-05-21T07:44:39.538Z] 07:44:39     INFO - PID 13993 |   count      bytes template
[task 2022-05-21T07:44:39.538Z] 07:44:39     INFO - PID 13993 |       9        280 nsComponentManagerImpl
[task 2022-05-21T07:44:39.539Z] 07:44:39     INFO - PID 13993 |     633      18115 libfontconfig.so
[task 2022-05-21T07:44:39.540Z] 07:44:39     INFO - PID 13993 |       1          9 libglib-2.0.so
[task 2022-05-21T07:44:39.540Z] 07:44:39     INFO - PID 13993 |       2        416 mozJSComponentLoader
[task 2022-05-21T07:44:39.540Z] 07:44:39     INFO - PID 13993 |       1         32 XPCWrappedNativeJSOps
[task 2022-05-21T07:44:39.540Z] 07:44:39     INFO - PID 13993 | -----------------------------------------------------
[task 2022-05-21T07:44:39.599Z] 07:44:39     INFO - Browser exited with return code 0
[task 2022-05-21T07:44:39.600Z] 07:44:39     INFO - ERROR | LeakSanitizer | SUMMARY: AddressSanitizer: 1488 byte(s) leaked in 11 allocation(s).
[task 2022-05-21T07:44:39.601Z] 07:44:39     INFO - LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2022-05-21T07:44:39.601Z] 07:44:39     INFO - This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2022-05-21T07:44:39.604Z] 07:44:39     INFO - Allowed depth was 4
[task 2022-05-21T07:44:39.604Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at RefPtr, mozilla::RemoteDecoderManagerChild::LaunchUtilityProcessIfNeeded, mozilla::RemoteDecoderManagerChild::Supports, mozilla::RemoteDecoderModule::Supports
[task 2022-05-21T07:44:39.604Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::MozPromise, mozilla::MozPromise, mozilla::MozPromise, mozilla::MozPromise
[task 2022-05-21T07:44:39.604Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at MakeUnique, mozilla::dom::WorkerThread::WorkerThread, MakeSafeRefPtr, mozilla::dom::WorkerThread::Create
[task 2022-05-21T07:44:39.604Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at MakeRefPtr, InvokeAsync, InvokeAsync, mozilla::RemoteDecoderManagerChild::LaunchUtilityProcessIfNeeded
[task 2022-05-21T07:44:39.604Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at nsThread::nsThread, mozilla::dom::WorkerThread::WorkerThread, MakeSafeRefPtr, mozilla::dom::WorkerThread::Create
[task 2022-05-21T07:44:39.604Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at MakeSafeRefPtr, mozilla::dom::WorkerThread::Create, mozilla::dom::workerinternals::RuntimeService::ScheduleWorker, mozilla::dom::workerinternals::RuntimeService::RegisterWorker
[task 2022-05-21T07:44:39.605Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at Alloc, nsTSubstring, nsTSubstring, nsTSubstring
[task 2022-05-21T07:44:39.605Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at NewPage, mozilla::Queue, mozilla::detail::EventQueueInternal, mozilla::ThreadEventQueue::PutEventInternal
[task 2022-05-21T07:44:39.605Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at Then, mozilla::RemoteDecoderManagerChild::LaunchUtilityProcessIfNeeded, mozilla::RemoteDecoderManagerChild::Supports, mozilla::RemoteDecoderModule::Supports
[task 2022-05-21T07:44:39.605Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at Realloc, nsTArray_base, nsTArray_Impl, AppendElement
[task 2022-05-21T07:44:39.605Z] 07:44:39     INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at MakeNotNull, mozilla::dom::WorkerThread::WorkerThread, MakeSafeRefPtr, mozilla::dom::WorkerThread::Create
[task 2022-05-21T07:44:39.607Z] 07:44:39     INFO - Closing logging queue
[task 2022-05-21T07:44:39.607Z] 07:44:39     INFO - queue closed
[task 2022-05-21T07:44:39.618Z] 07:44:39     INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-05-21T07:44:39.626Z] 07:44:39     INFO - LSan enabled.
[task 2022-05-21T07:44:39.627Z] 07:44:39     INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-05-21T07:44:39.627Z] 07:44:39     INFO - UBSan enabled.
[task 2022-05-21T07:44:39.628Z] 07:44:39     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmp8uhc8wrk
[task 2022-05-21T07:44:39.635Z] 07:44:39     INFO - PID 14519 | 1653119065079	Marionette	INFO	Marionette enabled
[task 2022-05-21T07:44:39.636Z] 07:44:39     INFO - PID 14519 | 1653119065086	Marionette	INFO	Listening on port 45986
[task 2022-05-21T07:44:39.636Z] 07:44:39     INFO - PID 14519 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpmwicku9d/search.json.mozlz4", (void 0)))
[task 2022-05-21T07:44:39.636Z] 07:44:39     INFO - Starting runner
[task 2022-05-21T07:44:40.546Z] 07:44:40     INFO - TEST-START | /navigation-api/per-entry-events/dispose-after-bfcache.html

The Bugbug bot thinks this bug should belong to the 'Core::Gecko Profiler' component, and is moving the bug to that component. Please correct in case you think the bot is wrong.

Component: General → Gecko Profiler

It looks like the root of this leak (because it is the only "direct" leak, where the others are "indirect") is a Promise created somewhere around this code in RemoteDecoderManagerChild. It looks like that code may have changed in bug 1755316.

I haven't looked at this code in any depth, but a lot of these kinds of runnable-ish leaks happen when one is created after shutdown has started, so they can't get dispatched properly and there's no clean up of it.

Component: Gecko Profiler → Audio/Video: Playback

This comment is just to show the "direct leak" part of the log

[task 2022-05-21T07:44:38.416Z] 07:44:38     INFO - PID 13993 | =================================================================
[task 2022-05-21T07:44:38.417Z] 07:44:38     INFO - PID 13993 | LeakSanitizer: detected memory leaks
[task 2022-05-21T07:44:38.418Z] 07:44:38     INFO - PID 13993 | Direct leak of 72 byte(s) in 1 object(s) allocated from:
[task 2022-05-21T07:44:38.419Z] 07:44:38     INFO - PID 13993 |     #0 0x55f26661915e in malloc /builds/worker/fetches/llvm-project/compiler-rt/lib/asan/asan_malloc_linux.cpp:69:3
[task 2022-05-21T07:44:38.420Z] 07:44:38     INFO - PID 13993 |     #1 0x55f26665d0ed in moz_xmalloc /builds/worker/checkouts/gecko/memory/mozalloc/mozalloc.cpp:52:15
[task 2022-05-21T07:44:38.432Z] 07:44:38     INFO - PID 13993 |     #2 0x7f7c03d602dc in operator new /builds/worker/workspace/obj-build/dist/include/mozilla/cxxalloc.h:33:10
[task 2022-05-21T07:44:38.432Z] 07:44:38     INFO - PID 13993 |     #3 0x7f7c03d602dc in mozilla::MozPromise<bool, nsresult, false>::ThenValueBase::Dispatch(mozilla::MozPromise<bool, nsresult, false>*) /builds/worker/workspace/obj-build/dist/include/mozilla/MozPromise.h:533:33
[task 2022-05-21T07:44:38.433Z] 07:44:38     INFO - PID 13993 |     #4 0x7f7c03d60109 in mozilla::MozPromise<bool, nsresult, false>::DispatchAll() /builds/worker/workspace/obj-build/dist/include/mozilla/MozPromise.h:1137:18
[task 2022-05-21T07:44:38.433Z] 07:44:38     INFO - PID 13993 |     #5 0x7f7c03d6229b in void mozilla::MozPromise<bool, nsresult, false>::Private::Resolve<bool const&>(bool const&, char const*) /builds/worker/workspace/obj-build/dist/include/mozilla/MozPromise.h:1221:5
[task 2022-05-21T07:44:38.434Z] 07:44:38     INFO - PID 13993 |     #6 0x7f7c03d60185 in mozilla::MozPromise<bool, nsresult, false>::DispatchAll() /builds/worker/workspace/obj-build/dist/include/mozilla/MozPromise.h:1142:7
[task 2022-05-21T07:44:38.434Z] 07:44:38     INFO - PID 13993 |     #7 0x7f7c03d6229b in void mozilla::MozPromise<bool, nsresult, false>::Private::Resolve<bool const&>(bool const&, char const*) /builds/worker/workspace/obj-build/dist/include/mozilla/MozPromise.h:1221:5
[task 2022-05-21T07:44:38.435Z] 07:44:38     INFO - PID 13993 |     #8 0x7f7c044adaba in mozilla::MozPromise<bool, nsresult, false>::ChainTo(already_AddRefed<mozilla::MozPromise<bool, nsresult, false>::Private>, char const*) /builds/worker/workspace/obj-build/dist/include/mozilla/MozPromise.h:1077:7
[task 2022-05-21T07:44:38.436Z] 07:44:38     INFO - PID 13993 |     #9 0x7f7c08ce89fd in InvokeCallbackMethod<true, (lambda at /builds/worker/checkouts/gecko/dom/media/ipc/RemoteDecoderManagerChild.cpp:533:13), RefPtr<mozilla::MozPromise<bool, nsresult, false> > ((lambda at /builds/worker/checkouts/gecko/dom/media/ipc/RemoteDecoderManagerChild.cpp:533:13)::*)(mozilla::MozPromise<mozilla::Tuple<nsresult, mozilla::ipc::Endpoint<mozilla::PRemoteDecoderManagerChild> >, mozilla::ipc::ResponseRejectReason, true>::ResolveOrRejectValue &&) const, mozilla::MozPromise<mozilla::Tuple<nsresult, mozilla::ipc::Endpoint<mozilla::PRemoteDecoderManagerChild> >, mozilla::ipc::ResponseRejectReason, true>::ResolveOrRejectValue, RefPtr<mozilla::MozPromise<bool, nsresult, false>::Private> > /builds/worker/workspace/obj-build/dist/include/mozilla/MozPromise.h:648:10
[task 2022-05-21T07:44:38.436Z] 07:44:38     INFO - PID 13993 |     #10 0x7f7c08ce89fd in mozilla::MozPromise<mozilla::Tuple<nsresult, mozilla::ipc::Endpoint<mozilla::PRemoteDecoderManagerChild> >, mozilla::ipc::ResponseRejectReason, true>::ThenValue<mozilla::RemoteDecoderManagerChild::LaunchUtilityProcessIfNeeded()::$_8::operator()() const::'lambda'(mozilla::MozPromise<mozilla::Tuple<nsresult, mozilla::ipc::Endpoint<mozilla::PRemoteDecoderManagerChild> >, mozilla::ipc::ResponseRejectReason, true>::ResolveOrRejectValue&&)>::DoResolveOrRejectInternal(mozilla::MozPromise<mozilla::Tuple<nsresult, mozilla::ipc::Endpoint<mozilla::PRemoteDecoderManagerChild> >, mozilla::ipc::ResponseRejectReason, true>::ResolveOrRejectValue&) /builds/worker/workspace/obj-build/dist/include/mozilla/MozPromise.h:914:7
[task 2022-05-21T07:44:38.437Z] 07:44:38     INFO - PID 13993 |     #11 0x7f7c04560602 in mozilla::MozPromise<mozilla::Tuple<nsresult, mozilla::ipc::Endpoint<mozilla::PRemoteDecoderManagerChild> >, mozilla::ipc::ResponseRejectReason, true>::ThenValueBase::ResolveOrRejectRunnable::Run() /builds/worker/workspace/obj-build/dist/include/mozilla/MozPromise.h:487:21
[task 2022-05-21T07:44:38.437Z] 07:44:38     INFO - PID 13993 |     #12 0x7f7c02eb852b in mozilla::SimpleTaskQueue::DrainTasks() /builds/worker/workspace/obj-build/dist/include/mozilla/TaskDispatcher.h:44:10
[task 2022-05-21T07:44:38.437Z] 07:44:38     INFO - PID 13993 |     #13 0x7f7c02ed4fb2 in nsThread::DrainDirectTasks() /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1384:16
[task 2022-05-21T07:44:38.438Z] 07:44:38     INFO - PID 13993 |     #14 0x7f7c02ed33d3 in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1202:3
[task 2022-05-21T07:44:38.439Z] 07:44:38     INFO - PID 13993 |     #15 0x7f7c02edd3cc in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:465:10
[task 2022-05-21T07:44:38.440Z] 07:44:38     INFO - PID 13993 |     #16 0x7f7c0446dc99 in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:330:5
[task 2022-05-21T07:44:38.440Z] 07:44:38     INFO - PID 13993 |     #17 0x7f7c0430fbc1 in RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:380:10
[task 2022-05-21T07:44:38.441Z] 07:44:38     INFO - PID 13993 |     #18 0x7f7c0430fbc1 in RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:373:3
[task 2022-05-21T07:44:38.442Z] 07:44:38     INFO - PID 13993 |     #19 0x7f7c0430fbc1 in MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:355:3
[task 2022-05-21T07:44:38.442Z] 07:44:38     INFO - PID 13993 |     #20 0x7f7c02ecb66c in nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:378:10
[task 2022-05-21T07:44:38.443Z] 07:44:38     INFO - PID 13993 |     #21 0x7f7c294ac6de in _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5
[task 2022-05-21T07:44:38.444Z] 07:44:38     INFO - PID 13993 |     #22 0x7f7c291dc6da in start_thread /tmp/glibc/nptl/pthread_create.c:463
Assignee: nobody → lissyx+mozillians

I've already fixed something with bug 1770086 but it's still very unclear for me when the Then() triggers https://searchfox.org/mozilla-central/rev/8bd5597baef9be63fc4689a69e550d607dc68444/dom/media/ipc/RemoteDecoderManagerChild.cpp#553.

Would it trigger on a promise rejection?

Also, doing

RefPtr<...> p = InvokeAsync(...);
[...]
p = p->Then(...);
[...]
sLaunchUtilityPromise = p;

Dont we risk doing the leak as well?

I'm not super sure which RefPtr we are leaking here.

Andrew, if you have hints about this Then() I'm happy to hear :)

Flags: needinfo?(continuation)

I was worried this could be a regression from bug 1770086 but it is not: https://treeherder.mozilla.org/jobs?repo=try&revision=976cc0f647392100fa3ff427093258af33bf6a90

Depends on: 1770703

(In reply to Alexandre LISSY :gerard-majax from comment #5)

Andrew, if you have hints about this Then() I'm happy to hear :)

I'm not sure, sorry. I assume there's some kind of thread dispatch, so maybe that could happen too late in shutdown?

Flags: needinfo?(continuation)

(In reply to Andrew McCreight [:mccr8] from comment #9)

(In reply to Alexandre LISSY :gerard-majax from comment #5)

Andrew, if you have hints about this Then() I'm happy to hear :)

I'm not sure, sorry. I assume there's some kind of thread dispatch, so maybe that could happen too late in shutdown?

That was also my take, however:

Attachment #9277913 - Attachment description: Bug 1770558 - Change promise chaining to avoid leakage of static at racy shutdown r?alwu! → Bug 1770558 - Ensure proper handling of returned promise r?alwu!
Pushed by alissy@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/fa34be82b4a6
Ensure proper handling of returned promise r=alwu

https://hg.mozilla.org/mozilla-central/rev/fa34be82b4a6

Status: NEW → RESOLVED
Closed: 2 years ago
status-firefox102: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 102 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: