Intermittent LeakSanitizer | leak at NS_NewPipe2, mozilla::RemoteLazyInputStream::EnsureAsyncRemoteStream, operator, std::_Function_handler
Categories
(Core :: Storage: IndexedDB, defect, P5)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr91 | --- | unaffected |
firefox-esr102 | --- | fixed |
firefox103 | --- | unaffected |
firefox104 | --- | fixed |
firefox105 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: nika)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [retriggered])
Attachments
(2 files, 1 obsolete file)
48 bytes,
text/x-phabricator-request
|
diannaS
:
approval-mozilla-beta+
RyanVM
:
approval-mozilla-esr102+
|
Details | Review |
48 bytes,
text/x-phabricator-request
|
diannaS
:
approval-mozilla-beta+
RyanVM
:
approval-mozilla-esr102+
|
Details | Review |
Filed by: bszekely [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=385764077&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/c-jJisELSOKU2WV5OGRZZg/runs/0/artifacts/public/logs/live_backing.log
[task 2022-07-29T06:29:32.723Z] 06:29:32 INFO - TEST-START | /IndexedDB/writer-starvation.htm
[task 2022-07-29T06:29:32.731Z] 06:29:32 INFO - Closing window f09edc37-5adf-41b8-abe2-50f965aaa9f3
[task 2022-07-29T06:29:33.786Z] 06:29:33 INFO - .
[task 2022-07-29T06:29:33.787Z] 06:29:33 INFO - TEST-OK | /IndexedDB/writer-starvation.htm | took 1066ms
[task 2022-07-29T06:29:33.789Z] 06:29:33 INFO - Restarting browser for new test group
[task 2022-07-29T06:29:33.790Z] 06:29:33 INFO - PID 1330 | 1659076173789 Marionette INFO Stopped listening on port 39522
[task 2022-07-29T06:29:34.185Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=619002fc8380 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3595
[task 2022-07-29T06:29:34.185Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=619002fc8380 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1799
[task 2022-07-29T06:29:34.189Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=6190027c7780 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3595
[task 2022-07-29T06:29:34.191Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=6190027c7780 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1799
[task 2022-07-29T06:29:34.194Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=61900250b780 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3595
[task 2022-07-29T06:29:34.196Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=61900250b780 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1799
[task 2022-07-29T06:29:34.219Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=619002fc8380 - ShutDownProcess: Closing channel.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1834
[task 2022-07-29T06:29:34.222Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=619002fc8380 - RemoveShutdownBlockers: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3697
[task 2022-07-29T06:29:34.226Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=6190027c7780 - ShutDownProcess: Closing channel.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1834
[task 2022-07-29T06:29:34.229Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=6190027c7780 - RemoveShutdownBlockers: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3697
[task 2022-07-29T06:29:34.237Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=61900250b780 - ShutDownProcess: Closing channel.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1834
[task 2022-07-29T06:29:34.239Z] 06:29:34 INFO - PID 1330 | [Parent 1330, Main Thread] WARNING: ContentParent: id=61900250b780 - RemoveShutdownBlockers: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3697
[task 2022-07-29T06:29:34.515Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.519Z] 06:29:34 INFO - PID 1330 | Suppressions used:
[task 2022-07-29T06:29:34.520Z] 06:29:34 INFO - PID 1330 | count bytes template
[task 2022-07-29T06:29:34.520Z] 06:29:34 INFO - PID 1330 | 2 288 libfontconfig.so
[task 2022-07-29T06:29:34.520Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.593Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.594Z] 06:29:34 INFO - PID 1330 | Suppressions used:
[task 2022-07-29T06:29:34.594Z] 06:29:34 INFO - PID 1330 | count bytes template
[task 2022-07-29T06:29:34.594Z] 06:29:34 INFO - PID 1330 | 2 288 libfontconfig.so
[task 2022-07-29T06:29:34.594Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.602Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.602Z] 06:29:34 INFO - PID 1330 | Suppressions used:
[task 2022-07-29T06:29:34.602Z] 06:29:34 INFO - PID 1330 | count bytes template
[task 2022-07-29T06:29:34.602Z] 06:29:34 INFO - PID 1330 | 2 288 libfontconfig.so
[task 2022-07-29T06:29:34.602Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.605Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.605Z] 06:29:34 INFO - PID 1330 | Suppressions used:
[task 2022-07-29T06:29:34.605Z] 06:29:34 INFO - PID 1330 | count bytes template
[task 2022-07-29T06:29:34.605Z] 06:29:34 INFO - PID 1330 | 2 288 libfontconfig.so
[task 2022-07-29T06:29:34.605Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.701Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.701Z] 06:29:34 INFO - PID 1330 | Suppressions used:
[task 2022-07-29T06:29:34.701Z] 06:29:34 INFO - PID 1330 | count bytes template
[task 2022-07-29T06:29:34.701Z] 06:29:34 INFO - PID 1330 | 2 288 libfontconfig.so
[task 2022-07-29T06:29:34.701Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.702Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.702Z] 06:29:34 INFO - PID 1330 | Suppressions used:
[task 2022-07-29T06:29:34.702Z] 06:29:34 INFO - PID 1330 | count bytes template
[task 2022-07-29T06:29:34.702Z] 06:29:34 INFO - PID 1330 | 2 288 libfontconfig.so
[task 2022-07-29T06:29:34.702Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.729Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.729Z] 06:29:34 INFO - PID 1330 | Suppressions used:
[task 2022-07-29T06:29:34.729Z] 06:29:34 INFO - PID 1330 | count bytes template
[task 2022-07-29T06:29:34.730Z] 06:29:34 INFO - PID 1330 | 2 288 libfontconfig.so
[task 2022-07-29T06:29:34.730Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.901Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:34.902Z] 06:29:34 INFO - PID 1330 | Suppressions used:
[task 2022-07-29T06:29:34.903Z] 06:29:34 INFO - PID 1330 | count bytes template
[task 2022-07-29T06:29:34.904Z] 06:29:34 INFO - PID 1330 | 2 288 libfontconfig.so
[task 2022-07-29T06:29:34.905Z] 06:29:34 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:37.278Z] 06:29:37 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:37.281Z] 06:29:37 INFO - PID 1330 | Suppressions used:
[task 2022-07-29T06:29:37.281Z] 06:29:37 INFO - PID 1330 | count bytes template
[task 2022-07-29T06:29:37.281Z] 06:29:37 INFO - PID 1330 | 1 32 nsComponentManagerImpl
[task 2022-07-29T06:29:37.282Z] 06:29:37 INFO - PID 1330 | 633 18115 libfontconfig.so
[task 2022-07-29T06:29:37.282Z] 06:29:37 INFO - PID 1330 | 2 16393 libglib-2.0.so
[task 2022-07-29T06:29:37.282Z] 06:29:37 INFO - PID 1330 | 1 32 XPCWrappedNativeJSOps
[task 2022-07-29T06:29:37.282Z] 06:29:37 INFO - PID 1330 | -----------------------------------------------------
[task 2022-07-29T06:29:37.381Z] 06:29:37 INFO - Browser exited with return code 0
[task 2022-07-29T06:29:37.382Z] 06:29:37 INFO - ERROR | LeakSanitizer | SUMMARY: AddressSanitizer: 5000 byte(s) leaked in 8 allocation(s).
[task 2022-07-29T06:29:37.385Z] 06:29:37 INFO - LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2022-07-29T06:29:37.385Z] 06:29:37 INFO - This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2022-07-29T06:29:37.385Z] 06:29:37 INFO - Allowed depth was 4
[task 2022-07-29T06:29:37.386Z] 06:29:37 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at NS_NewPipe2, mozilla::RemoteLazyInputStream::EnsureAsyncRemoteStream, operator, std::_Function_handler
[task 2022-07-29T06:29:37.386Z] 06:29:37 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at PR_NewMonitor, ReentrantMonitor, nsPipe::nsPipe, NS_NewPipe2
[task 2022-07-29T06:29:37.386Z] 06:29:37 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::RemoteLazyInputStreamThread::GetOrCreate, mozilla::BindChildActor, mozilla::RemoteLazyInputStream::IPCRead, IPC::ParamTraits
[task 2022-07-29T06:29:37.386Z] 06:29:37 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at already_AddRefed, NS_NewCancelableRunnableFunction, CallbackHolder::CallbackHolder, nsPipeInputStream::AsyncWait
[task 2022-07-29T06:29:37.386Z] 06:29:37 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at nsSegmentedBuffer::AppendNewSegment, nsPipe::GetWriteSegment, nsPipeOutputStream::WriteSegments, nsStreamCopierOB::DoCopy
[task 2022-07-29T06:29:37.387Z] 06:29:37 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at Malloc, nsTArray_base, nsTArray_Impl, AppendElement
[task 2022-07-29T06:29:37.388Z] 06:29:37 INFO - Closing logging queue
[task 2022-07-29T06:29:37.389Z] 06:29:37 INFO - queue closed
[task 2022-07-29T06:29:37.430Z] 06:29:37 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-07-29T06:29:37.437Z] 06:29:37 INFO - LSan enabled.
[task 2022-07-29T06:29:37.438Z] 06:29:37 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2022-07-29T06:29:37.438Z] 06:29:37 INFO - UBSan enabled.
[task 2022-07-29T06:29:37.439Z] 06:29:37 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmpnbhn8m8u
[task 2022-07-29T06:29:37.448Z] 06:29:37 INFO - PID 1336 | 1659075305965 Marionette INFO Marionette enabled
[task 2022-07-29T06:29:37.449Z] 06:29:37 INFO - PID 1336 | 1659075305974 Marionette INFO Listening on port 44445
[task 2022-07-29T06:29:37.450Z] 06:29:37 INFO - PID 1336 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpeibx5vup/search.json.mozlz4", (void 0)))
[task 2022-07-29T06:29:37.450Z] 06:29:37 INFO - PID 1336 | 1659075695996 addons.xpi ERROR System addon update list error Error: Failed downloading XML, status: 0, reason: error
[task 2022-07-29T06:29:37.451Z] 06:29:37 INFO - Starting runner
[task 2022-07-29T06:29:38.572Z] 06:29:38 INFO - TEST-START | /content-security-policy/media-src/media-src-7_1_2.sub.html
Comment 1•2 years ago
•
|
||
Something within this merge might have triggered it: https://hg.mozilla.org/mozilla-central/pushloghtml?changeset=2d32ee89304872df06dcad6c605447205d816380
Nika, could this and the leaks within this bug, Bug 1782176 and Bug 1782123 be from Bug 1780054 ?
These bugs contain the same leaks but in a different order throughout the log.
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 3•2 years ago
|
||
(In reply to Natalia Csoregi [:nataliaCs] from comment #1)
Nika, could this and the leaks within this bug, Bug 1782176 and Bug 1782123 be from Bug 1780054 ?
These bugs contain the same leaks but in a different order throughout the log.
It's unfortunately definitely possible that this bug could be from bug 1780054, but unfortunately I'm not super confident how it could be related given the set of objects which were apparently leaked. Perhaps there were other leaked objects but they were suppressed or something like that...
Given the current set of leaked objects here, it looks vaguely like the notify dispatch from a nsPipe
is waiting to eventually be delivered to the RemoteLazyInputStreamThread
. It's unclear if the notify was dispatched and leaked due to the thread being dead, or if it was sticking around and waiting to be dispatched at all.
The main way the change could impact things is if there is a buggy nsIAsyncInputStream
which doesn't pass the correct stream to OnInputStreamReady
when it is notified, but I'm pretty sure RemoteLazyInputStream
and nsPipe
aren't broken in that way so it seems unlikely to cause this specific leak. The source stream being copied from could theoretically be a nsMultiplexInputStream
but if that's the case, it shouldn't implement nsIAsyncInputStream
, so the changes won't have any impact.
When scanning for buggy async streams, I only found nsPreloadedStream
https://searchfox.org/mozilla-central/rev/12c2e38fdcc0bcbb9e689560c41ab68f9254413a/netwerk/base/nsPreloadedStream.cpp#111, which will report the wrong stream to the listener. This appears to never be used in a nsMultiplexInputStream
, and is likely also never stored in a RemoteLazyInputStream
(though it also appears to be a legacy stream which could easily be replaced by a nsMultiplexInputStream
, so that might be worth doing to simplify things). I expect it is not the cause of this bug.
I also noticed a potential bug in nsMultiplexInputStream
which could lead to AsyncWait callbacks not properly being cancelled, which is slightly more likely to be the cause of this bug, though it's still somewhat unlikely.
Comment 4•2 years ago
|
||
(Nika, I assume all this means also that "Storage: IndexedDB" is most likely not the right component for this bug?)
Comment 5•2 years ago
|
||
Set release status flags based on info from the regressing bug 1780054
Assignee | ||
Comment 6•2 years ago
|
||
(In reply to Jens Stutte [:jstutte] from comment #4)
(Nika, I assume all this means also that "Storage: IndexedDB" is most likely not the right component for this bug?)
There's a chance that it is, but it's not super clear yet. The issue seems more common when idb is involved, just like the old bug, but it could just be that it exercises stream code the most.
Assignee | ||
Comment 7•2 years ago
|
||
Previously nsMultiplexInputStream would not call AsyncWait
again when the
callback was cleared, meaning that the underlying wait wouldn't actually be
cancelled. This patch changes the behaviour to more consistently forward the
cancelling call to the underlying stream.
There are still some cases where the call will not be cancelled if a read or
other event caused the stream cursor to advance before canceling, however those
should generally be uncommon.
Assignee | ||
Comment 8•2 years ago
|
||
When nsMultiplexInputStream
calls AsyncWait
from within
OnInputStreamReady
, it is possible for those calls to fail. In that case, we
will fail to notify AsyncWait listeners, which could lead to leaks or stream
hangs. This patch changes the error handling in this situation to instead fire
a pending stream callback after an error when re-dispatching AsyncWait
.
Depends on D153628
Assignee | ||
Comment 9•2 years ago
|
||
This is an API requirement of the nsIAsyncInputStream
interface, and is
depended on by some streams such as nsMultiplexInputStream
.
This is unlikely to have any substantial impact as nsPreloadedStream is only
used in very limited situations, but it may be used in more places in the
future.
Depends on D153629
Assignee | ||
Comment 10•2 years ago
|
||
Going to land parts 1 and 2 of this bug, and hope that it fixes the issue. My best bet for the cause right now is the one fixed by part 2.
Comment 11•2 years ago
|
||
Comment on attachment 9288337 [details]
Bug 1782181 - Part 3: Pass the correct stream to OnInputStreamReady in nsPreloadedStream, r=#necko-reviewers
Revision D153630 was moved to bug 1783057. Setting attachment 9288337 [details] to obsolete.
Comment 12•2 years ago
|
||
Comment 13•2 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/40fd3f4eae4c
https://hg.mozilla.org/mozilla-central/rev/2a06e0ff3633
Comment 14•2 years ago
|
||
:nika can you please nominate this one for beta as well since it needs to go with bug 1780054?
Assignee | ||
Comment 15•2 years ago
|
||
Comment on attachment 9288336 [details]
Bug 1782181 - Part 2: Notify nsMultiplexInputStream callbacks if AsyncWait fails, r=asuth!
Beta/Release Uplift Approval Request
- User impact if declined: Memory leaks
- Is this code covered by automated tests?: No
- Has the fix been verified in Nightly?: Yes
- Needs manual test from QE?: No
- If yes, steps to reproduce:
- List of other uplifts needed: Bug 1780054
- Risk to taking this patch: Low
- Why is the change risky/not risky? (and alternatives if risky): Fairly minor improvements to the way that AsyncWait is handled in nsMultiplexInputStream which may help fix memory leaks caused by bug 1780054.
- String changes made/needed: None
- Is Android affected?: Yes
ESR Uplift Approval Request
- If this is not a sec:{high,crit} bug, please state case for ESR consideration: Ride-along for bug 1780054
- User impact if declined: Memory leaks
- Fix Landed on Version: 105
- Risk to taking this patch: Low
- Why is the change risky/not risky? (and alternatives if risky): Fairly minor improvements to the way that AsyncWait is handled in nsMultiplexInputStream which may help fix memory leaks caused by bug 1780054.
Assignee | ||
Updated•2 years ago
|
Comment 16•2 years ago
|
||
Comment on attachment 9288335 [details]
Bug 1782181 - Part 1: Support canceling AsyncWait in nsMultiplexInputStream, r=asuth!
Approved for 104.0b6
Updated•2 years ago
|
Comment 17•2 years ago
|
||
bugherder uplift |
Updated•2 years ago
|
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 19•2 years ago
|
||
Comment on attachment 9288335 [details]
Bug 1782181 - Part 1: Support canceling AsyncWait in nsMultiplexInputStream, r=asuth!
Approved for 102.2esr.
Updated•2 years ago
|
Comment 20•2 years ago
|
||
bugherder uplift |
https://hg.mozilla.org/releases/mozilla-esr102/rev/474e595745e7
https://hg.mozilla.org/releases/mozilla-esr102/rev/bb4ba9e59d36
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 25•2 years ago
|
||
This is still happening on esr102: https://treeherder.mozilla.org/logviewer?job_id=392776072&repo=mozilla-esr102 , if this is the same issue.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Description
•