1830523 - perma leakcheck | utility 400 bytes leaked (ObserverLists, PerThreadData, SourceList)

Status: RESOLVED FIXED

(Core :: IPC, defect, P5)

Description

[Treeherder Bug Filer]

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

---

repro locally with `mach test --headless --profiler xxx`

Comment 1

[:gerard-majax]

0:17.42 INFO Serial Numbers of Leaked Objects:
 0:17.42 INFO 2 @0x7f9aa6978740 (0 references; 0 from COMPtrs)
 0:17.42 INFO allocation stack:
Initializing stack-fixing for the first stack frame, this may take a while...
 0:33.34 INFO #00: mozilla::IOInterposer::Init() [/home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/build/IOInterposer.cpp:401]
 0:33.36 INFO #01: ActivePS::ActivePS(PSAutoLock const&, mozilla::TimeStamp const&, mozilla::PowerOfTwo<unsigned int>, double, unsigned int, char const**, unsigned int, unsigned long, mozilla::Maybe<double> const&, mozilla::UniquePtr<mozilla::ProfileBufferChunkManagerWithLocalLimit, mozilla::DefaultDelete<mozilla::ProfileBufferChunkManagerWithLocalLimi
t> >) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:844]
 0:33.37 INFO #02: ActivePS::Create(PSAutoLock const&, mozilla::TimeStamp const&, mozilla::PowerOfTwo<unsigned int>, double, unsigned int, char const**, unsigned int, unsigned long, mozilla::Maybe<double> const&, mozilla::UniquePtr<mozilla::ProfileBufferChunkManagerWithLocalLimit, mozilla::DefaultDelete<mozilla::ProfileBufferChunkManagerWithLocalLimit>
 >) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:940]
 0:33.37 INFO #03: locked_profiler_start(PSAutoLock const&, mozilla::PowerOfTwo<unsigned int>, double, unsigned int, char const**, unsigned int, unsigned long, mozilla::Maybe<double> const&) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:5788]
 0:33.37 INFO #04: profiler_init(void*) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:5294]
 0:33.37 INFO #05: XRE_InitChildProcess(int, char**, XREChildData const*) [/home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsEmbedFunctions.cpp:330]
 0:33.44 INFO #06: content_process_main(mozilla::Bootstrap*, int, char**) [/home/alex/codaz/Mozilla/gecko-cinnabar/ipc/contentproc/plugin-container.cpp:58]
 0:33.44 INFO #07: main [/home/alex/codaz/Mozilla/gecko-cinnabar/browser/app/nsBrowserApp.cpp:375]
 0:33.44 INFO #08: ??? [/lib/x86_64-linux-gnu/libc.so.6 + 0x23a90]
 0:33.44 INFO #09: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x23b49]
 0:33.44 INFO #10: ??? [/home/alex/codaz/Mozilla/gecko-cinnabar/obj-browser-dbg/dist/bin/firefox + 0x4a1a9]
 0:33.44 INFO #11: ??? (???:???)
 0:33.44 INFO 1 @0x7f9aa6903080 (0 references; 0 from COMPtrs)
 0:33.44 INFO allocation stack:
 0:33.44 INFO #00: mozilla::IOInterposer::RegisterCurrentThread(bool) [/home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/build/IOInterposer.cpp:511]
 0:33.44 INFO #01: mozilla::IOInterposer::Init() [/home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/build/IOInterposer.cpp:401]
 0:33.44 INFO #02: ActivePS::ActivePS(PSAutoLock const&, mozilla::TimeStamp const&, mozilla::PowerOfTwo<unsigned int>, double, unsigned int, char const**, unsigned int, unsigned long, mozilla::Maybe<double> const&, mozilla::UniquePtr<mozilla::ProfileBufferChunkManagerWithLocalLimit, mozilla::DefaultDelete<mozilla::ProfileBufferChunkManagerWithLocalLimi
t> >) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:844]
 0:33.44 INFO #03: ActivePS::Create(PSAutoLock const&, mozilla::TimeStamp const&, mozilla::PowerOfTwo<unsigned int>, double, unsigned int, char const**, unsigned int, unsigned long, mozilla::Maybe<double> const&, mozilla::UniquePtr<mozilla::ProfileBufferChunkManagerWithLocalLimit, mozilla::DefaultDelete<mozilla::ProfileBufferChunkManagerWithLocalLimit>
 >) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:940]
 0:33.44 INFO #04: locked_profiler_start(PSAutoLock const&, mozilla::PowerOfTwo<unsigned int>, double, unsigned int, char const**, unsigned int, unsigned long, mozilla::Maybe<double> const&) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:5788]
 0:33.44 INFO #05: profiler_init(void*) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:5294]
 0:33.44 INFO #06: XRE_InitChildProcess(int, char**, XREChildData const*) [/home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsEmbedFunctions.cpp:330]
 0:33.44 INFO #07: content_process_main(mozilla::Bootstrap*, int, char**) [/home/alex/codaz/Mozilla/gecko-cinnabar/ipc/contentproc/plugin-container.cpp:58]
 0:33.44 INFO #08: main [/home/alex/codaz/Mozilla/gecko-cinnabar/browser/app/nsBrowserApp.cpp:375]
 0:33.44 INFO #09: ??? [/lib/x86_64-linux-gnu/libc.so.6 + 0x23a90]
 0:33.44 INFO #10: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x23b49]
 0:33.44 INFO #11: ??? [/home/alex/codaz/Mozilla/gecko-cinnabar/obj-browser-dbg/dist/bin/firefox + 0x4a1a9]
 0:33.44 INFO #12: ??? (???:???)
 0:33.44 INFO 3 @0x7f9aa69f8920 (1 references; 0 from COMPtrs)
 0:33.44 INFO allocation stack:
 0:33.44 INFO #00: RefPtr<(anonymous namespace)::ObserverLists const>::assign_with_AddRef((anonymous namespace)::ObserverLists const*) [/home/alex/codaz/Mozilla/gecko-cinnabar/obj-browser-dbg/dist/include/mozilla/RefPtr.h:66]
 0:33.44 INFO #01: mozilla::IOInterposer::Register(mozilla::IOInterposeObserver::Operation, mozilla::IOInterposeObserver*) [/home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/build/IOInterposer.cpp:493]
 0:33.44 INFO #02: ActivePS::ActivePS(PSAutoLock const&, mozilla::TimeStamp const&, mozilla::PowerOfTwo<unsigned int>, double, unsigned int, char const**, unsigned int, unsigned long, mozilla::Maybe<double> const&, mozilla::UniquePtr<mozilla::ProfileBufferChunkManagerWithLocalLimit, mozilla::DefaultDelete<mozilla::ProfileBufferChunkManagerWithLocalLimi
t> >) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:0]
 0:33.44 INFO #03: ActivePS::Create(PSAutoLock const&, mozilla::TimeStamp const&, mozilla::PowerOfTwo<unsigned int>, double, unsigned int, char const**, unsigned int, unsigned long, mozilla::Maybe<double> const&, mozilla::UniquePtr<mozilla::ProfileBufferChunkManagerWithLocalLimit, mozilla::DefaultDelete<mozilla::ProfileBufferChunkManagerWithLocalLimit>
 >) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:940]
 0:33.44 INFO #04: locked_profiler_start(PSAutoLock const&, mozilla::PowerOfTwo<unsigned int>, double, unsigned int, char const**, unsigned int, unsigned long, mozilla::Maybe<double> const&) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:5788]
 0:33.44 INFO #05: profiler_init(void*) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:5294]
 0:33.44 INFO #06: XRE_InitChildProcess(int, char**, XREChildData const*) [/home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsEmbedFunctions.cpp:330]
 0:33.44 INFO #07: content_process_main(mozilla::Bootstrap*, int, char**) [/home/alex/codaz/Mozilla/gecko-cinnabar/ipc/contentproc/plugin-container.cpp:58]
 0:33.44 INFO #08: main [/home/alex/codaz/Mozilla/gecko-cinnabar/browser/app/nsBrowserApp.cpp:375]
 0:33.44 INFO #09: ??? [/lib/x86_64-linux-gnu/libc.so.6 + 0x23a90]
 0:33.44 INFO #10: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x23b49]
 0:33.44 INFO #11: ??? [/home/alex/codaz/Mozilla/gecko-cinnabar/obj-browser-dbg/dist/bin/firefox + 0x4a1a9]
 0:33.44 INFO #12: ??? (???:???)
 0:33.44 INFO 8 @0x7f9a936d8190 (1 references; 0 from COMPtrs)
 0:33.44 INFO allocation stack:
 0:33.44 INFO #00: RefPtr<(anonymous namespace)::ObserverLists const>::assign_with_AddRef((anonymous namespace)::ObserverLists const*) [/home/alex/codaz/Mozilla/gecko-cinnabar/obj-browser-dbg/dist/include/mozilla/RefPtr.h:66]
 0:33.44 INFO #01: mozilla::IOInterposer::Unregister(mozilla::IOInterposeObserver::Operation, mozilla::IOInterposeObserver*) [/home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/build/IOInterposer.cpp:502]
 0:33.44 INFO #02: ActivePS::~ActivePS() [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:0]
 0:33.44 INFO #03: ActivePS::Destroy(PSAutoLock const&) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:964]
 0:33.44 INFO #04: locked_profiler_stop(PSAutoLock const&) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:6062]
 0:33.44 INFO #05: profiler_shutdown(IsFastShutdown) [/home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:5356]
 0:33.44 INFO #06: XRE_InitChildProcess(int, char**, XREChildData const*) [/home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsEmbedFunctions.cpp:685]
 0:33.44 INFO #07: content_process_main(mozilla::Bootstrap*, int, char**) [/home/alex/codaz/Mozilla/gecko-cinnabar/ipc/contentproc/plugin-container.cpp:58]
 0:33.44 INFO #08: main [/home/alex/codaz/Mozilla/gecko-cinnabar/browser/app/nsBrowserApp.cpp:375]
 0:33.44 INFO #09: ??? [/lib/x86_64-linux-gnu/libc.so.6 + 0x23a90]
 0:33.44 INFO #10: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x23b49]
 0:33.44 INFO #11: ??? [/home/alex/codaz/Mozilla/gecko-cinnabar/obj-browser-dbg/dist/bin/firefox + 0x4a1a9]
 0:33.44 INFO #12: ??? (???:???)

Comment 2

[:gerard-majax]

Gerald, do you have an idea what is wrong? this is making my investigation of bug 1827894 much more painful

Comment 3

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

I don't see anything obvious at a glance.
in comment 1, the first three allocations seem related to some static storage, it's not entirely surprising that this could leak; however the last one in in the IOInterposer::Unregister call, so that should have balanced previous allocations instead of adding one, quite strange. 🤔

As a workaround for your investigation, you could disable all "IO" features in about:profiling, it would prevent these calls.
To forcefully prevent these features from tests (without having to modify all tests), you could modify ActivePS::ShouldInterposeIOs() to just return false;.

Sorry I cannot invest more time on this at the moment. Florian may know some of this code but I see he's not available -> Forwarding NI to Nazim on the Profiler team... Please ping me again with more details, if you think I can help further. Good luck! 😄

Comment 4

[Intermittent Failures Robot]

1 failures in 3177 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1830523&startday=2023-04-24&endday=2023-04-30&tree=all

Comment 5

[:gerard-majax]

Looks like it can repro with just BUILD_DEBUG=1 ./mach test --headless ./browser/base/content/test/performance/browser_startup_mainthreadio.js --appname=dist.

:Gijs maybe you have an idea? Something likely missing on Utility (and RDD per bug 1830524)

Comment 6

[:Gijs (he/him)]

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

Looks like it can repro with just BUILD_DEBUG=1 ./mach test --headless ./browser/base/content/test/performance/browser_startup_mainthreadio.js --appname=dist.

:Gijs maybe you have an idea? Something likely missing on Utility (and RDD per bug 1830524)

I don't, unfortunately, I know basically nothing about the profiler internals. :canova and Gerald Squelart are your best bet - but it also looks (from casual hg log poking) like Nika made a refcounting change to the profiler in bug 1824465 so perhaps she has ideas here.

Comment 7

[:gerard-majax]

Attachment: Bug 1830523 - Fix utility leak on IOInterposer r?#xpcom-reviewers!

Comment 8

[Nika Layzell [:nika] (ni? for response)]

Looking at the code it appears that IOInterposer::Init is forcibly initialized when the profiler is initialized (1, 2) since bug 1522497. This was done to make sure that we can interpose I/O during early startup, before the IOInterposer would otherwise be initialized.

The profiler will never clear the IOInterposer however, that is only done by ~IOInterposerInit(), meaning that if the profiler starts the IOInterposer in a process which doesn't have the IOInterposer enabled by default in XPCOM startup, we'll end up leaking the associated state.

I'm thinking a nice workaround for this might be to take advantage of the fact that IOInterposer::Init is idempotent, and that it appears to be safe to call IOInterposer::Clear even if you've never initialized it. If the IOInterposerInit was changed to be more like this:

class MOZ_RAII AutoIOInterposer {
 public:
  IOInterposerInit() = default;
  void Init() {
#if defined(EARLY_BETA_OR_EARLIER)
    IOInterposer::Init();
#endif
  }
  ~IOInterposerInit() {
#if defined(EARLY_BETA_OR_EARLIER)
    IOInterposer::Clear();
#endif
  }
};

we could change the existing call sites to all construct an AutoIOInterposer (rather than a Maybe<AutoIOInterposer>, and then only call Init in the processes where we want the interposer enabled by-default. Other processes would still get the interposer, and it would still be cleaned up, but only if the profiler gets enabled.

Comment 10

[:gerard-majax]

Attachment: Bug 1830523 - Make IOInterposer RAII to avoid leaks r?#xpcom-reviewers!

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/abee5c7fa7ed
Make IOInterposer RAII to avoid leaks r=emilio

Comment 12

[Cosmin Sabou [:CosminS]]

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