Huge amount of heap-unclassified memory for mozilla::TaskQueue::DispatchLocked(nsCOMPtr<nsIRunnable>&, unsigned int, mozilla::AbstractThread::DispatchReason)
Categories
(Core :: Networking, defect)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr78 | --- | unaffected |
firefox82 | --- | unaffected |
firefox83 | --- | unaffected |
firefox84 | --- | fixed |
People
(Reporter: whimboo, Assigned: valentin)
References
(Regression)
Details
(Keywords: memory-footprint, regression)
Attachments
(1 file)
I'm running Firefox Nightly with DMD enabled via the terminal, and after a while the heap-unclassified memory usage increases up to 30%:
1,635.96 MB (100.0%) -- explicit
├────573.15 MB (35.03%) ── heap-unclassified
When running the DMD script on the generated DMD dump the following huge chunk of unreported memory is listed multiple times (342MB, 16MB, 14MB):
Unreported {
83,698 blocks in heap block record 1 of 30,005
342,827,008 bytes (342,827,008 requested / 0 slop)
Individual block sizes: 4,096 x 83,698
22.80% of the heap (22.80% cumulative)
55.48% of unreported (55.48% cumulative)
Allocated at {
#01: mozilla::TaskQueue::DispatchLocked(nsCOMPtr<nsIRunnable>&, unsigned int, mozilla::AbstractThread::DispatchReason) (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x5280a5)
#02: mozilla::TaskQueue::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x53ecd6)
#03: nsSegmentedBuffer::FreeOMT(void*) (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x500e44)
#04: nsPipe::~nsPipe() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x4fcfd3)
#05: nsPipeInputStream::~nsPipeInputStream() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x4ff630)
#06: nsPipeInputStream::Release() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x4fe6aa)
#07: nsInputStreamReadyEvent::~nsInputStreamReadyEvent() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x50551a)
#08: nsInputStreamReadyEvent::~nsInputStreamReadyEvent() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x50466e)
#09: mozilla::CancelableRunnable::Release() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x53ab59)
#10: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x522e2e)
#11: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_4>::Run() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x5273ec)
#12: nsThread::ProcessNextEvent(bool, bool*) (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x53219b)
#13: NS_ProcessPendingEvents(nsIThread*, unsigned int) (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x52f6fc)
#14: nsAppShell::ProcessGeckoEvents(void*) (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x110eca0)
#15: __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ (/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation + 0x83d52)
#16: __CFRunLoopDoSource0 (/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation + 0x83cf1)
#17: __CFRunLoopDoSources0 (/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation + 0x83b0b)
#18: __CFRunLoopRun (/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation + 0x8283a)
#19: CFRunLoopRunSpecific (/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation + 0x81e3e)
#20: RunCurrentEventLoopInMode (/System/Library/Frameworks/Carbon.framework/Versions/A/Frameworks/HIToolbox.framework/Versions/A/HIToolbox + 0x2fabd)
#21: ReceiveNextEventCommon (/System/Library/Frameworks/Carbon.framework/Versions/A/Frameworks/HIToolbox.framework/Versions/A/HIToolbox + 0x2f7d5)
#22: _BlockUntilNextEventMatchingListInModeWithFilter (/System/Library/Frameworks/Carbon.framework/Versions/A/Frameworks/HIToolbox.framework/Versions/A/HIToolbox + 0x2f579)
}
}
Maybe that happens because Firefox pipes the logging output to the terminal window?
I wonder if that is a regression from the recently landed patches on bug 1502355. Waldo, mind having a look?
Comment 1•3 years ago
|
||
Seems doubtful. The piping stuff is in code that is not yet turned on in preferences, so it would be a bit of a feat for it to be producing dark matter just yet.
And whatever output Firefox sends to the console, isn't going to show up as memory within Gecko's conception of a pipe input stream, anyway.
Comment 2•3 years ago
|
||
It looks like some nsInputStreamReadyEvent is getting cancelled. Then maybe we're clearing nsInputStreamReadyEvent::mStream (I think nsPipeInputStream can match the type of that field). This leads us to clear and destroy the nsPipeInputStream::mPipe field. I think we then destroy the nsPipe::mBuffer field, which makes us free all of the segments, but it wants to do it off the main thread, so it creates some new tasks. I guess the tasks aren't running? Or maybe something later is leaking them?
Comment 3•3 years ago
|
||
It looks like FreeOMT changed in bug 1667581, so maybe this is a regression from that? Valentin, could you please take a look? Thanks.
Comment 4•3 years ago
|
||
It looks like a large increase in heap-unclassified was also detected on AWSY, so I'll tentatively mark the regression.
Updated•3 years ago
|
Updated•3 years ago
|
Reporter | ||
Updated•3 years ago
|
Comment 5•3 years ago
|
||
This is coming out of a background task queue. I agree that this is most likely the same issue as bug 1673405, and I expected this to happen by running FreeOMT
sequentially since these frees now happen much slower. We may be able to strike a better balance between the inevitable memory issues and the threadpool bug (bug 1670737) by batching free calls and dispatching them via NS_DispatchBackgroundTask
onto the IO pool.
Reporter | ||
Comment 6•3 years ago
|
||
This is continuously growing over time:
1,952.45 MB (100.0%) -- explicit
├────920.20 MB (47.13%) ── heap-unclassified
And it includes blocks of this trace for 646MB, 27MB, 5MB, 4MB, 3MB, 2 x 2MB, and a couple more with <1MB.
And now also for NS_CreateBackgroundTaskQueue
:
Unreported {
97,025 blocks in heap block record 3 of 29,904
31,048,000 bytes (31,048,000 requested / 0 slop)
Individual block sizes: 320 x 97,025
2.04% of the heap (49.46% cumulative)
3.22% of unreported (77.92% cumulative)
Allocated at {
#01: NS_CreateBackgroundTaskQueue (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x53cdb8)
#02: nsSegmentedBuffer::FreeOMT(void*) (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x500e6d)
#03: nsPipe::~nsPipe() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x4fcfd3)
#04: nsPipeInputStream::~nsPipeInputStream() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x4ff630)
#05: nsPipeInputStream::Release() (/Applications/FirefoxNightly.app/Contents/MacOS/XUL + 0x4fe6aa)
Assignee | ||
Comment 7•3 years ago
|
||
Updated•3 years ago
|
Updated•3 years ago
|
Pushed by valentin.gosu@gmail.com: https://hg.mozilla.org/integration/autoland/rev/e0fa99439c48 Backed out changeset 0bcd9a5ae49f (Bug 1667581) for causing memory usage regressions a=backout
Comment 9•3 years ago
|
||
bugherder |
Assignee | ||
Updated•3 years ago
|
Comment 10•3 years ago
|
||
Thanks for the quick fix!
Comment 11•3 years ago
|
||
== Change summary for alert #27586 (as of Tue, 10 Nov 2020 11:18:18 GMT) ==
Improvements:
Ratio | Suite | Test | Platform | Options | Absolute values (old vs new) |
---|---|---|---|---|---|
9% | Heap Unclassified | linux1804-64-shippable | 76,442,062.98 -> 69,637,726.69 | ||
6% | Heap Unclassified | windows10-64-shippable | 47,783,664.29 -> 44,762,615.82 | ||
6% | Heap Unclassified | windows10-64-shippable | 47,606,708.65 -> 44,762,371.78 |
For up to date results, see: https://treeherder.mozilla.org/perfherder/alerts?id=27586
Updated•3 years ago
|
Description
•