Closed Bug 1675203 Opened 3 years ago Closed 3 years ago

Huge amount of heap-unclassified memory for mozilla::TaskQueue::DispatchLocked(nsCOMPtr<nsIRunnable>&, unsigned int, mozilla::AbstractThread::DispatchReason)

Categories

(Core :: Networking, defect)

defect

Tracking

()

RESOLVED FIXED
84 Branch
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?

Flags: needinfo?(jwalden)

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.

Flags: needinfo?(jwalden)

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?

Component: General → XPCOM

It looks like FreeOMT changed in bug 1667581, so maybe this is a regression from that? Valentin, could you please take a look? Thanks.

Flags: needinfo?(valentin.gosu)

It looks like a large increase in heap-unclassified was also detected on AWSY, so I'll tentatively mark the regression.

Keywords: regression
Regressed by: 1667581
See Also: → 1673405
Has Regression Range: --- → yes
Component: XPCOM → Networking

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.

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: nobody → valentin.gosu
Status: NEW → ASSIGNED
Attachment #9185951 - Attachment description: Bug 1675203 - Backed out changeset 0bcd9a5ae49f (Bug 1667581) for causing memory usage regressions r=Gijs → Bug 1675203 - Backed out changeset 0bcd9a5ae49f (Bug 1667581) for causing memory usage regressions a=backout
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
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → 84 Branch
Flags: needinfo?(valentin.gosu)

Thanks for the quick fix!

== 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

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: