1514757 - tens of thousands of references in message-manager-suspect for multiple messages

Status: RESOLVED FIXED

(Firefox :: Tabbed Browser, defect, P3)

Description

[Nathan Froyd [:froydnj]]

I opened up about:memory today on a whim and found:

1,033,365 (100.0%) -- message-manager-suspect
└──1,033,365 (100.0%) -- global-manager
   ├────537,829 (52.05%) ── referent(message=InPermitUnload) [289]
   ├─────28,050 (02.71%) ── referent(message=Browser:Init) [75]
   ├─────24,522 (02.37%) ── referent(message=DOMTitleChanged) [67]
   ├─────21,960 (02.13%) ── referent(message=AudibleAutoplayMediaOccurred) [61]
   ├─────21,960 (02.13%) ── referent(message=AudioPlayback:ActiveMediaBlockStart) [61]
   ├─────21,960 (02.13%) ── referent(message=AudioPlayback:ActiveMediaBlockStop) [61]
   ├─────21,960 (02.13%) ── referent(message=AudioPlayback:Start) [61]
   ├─────21,960 (02.13%) ── referent(message=AudioPlayback:Stop) [61]
   ├─────21,960 (02.13%) ── referent(message=Autoscroll:Cancel) [61]
   ├─────21,960 (02.13%) ── referent(message=Autoscroll:Start) [61]
   ├─────21,960 (02.13%) ── referent(message=PopupBlocking:UpdateBlockedPopups) [61]
   ├─────21,960 (02.13%) ── referent(message=UnselectedTabHover:Toggle) [61]
   ├─────21,122 (02.04%) ── referent(message=Content:LoadURIResult) [59]
   ├─────21,122 (02.04%) ── referent(message=Content:LocationChange) [59]
   ├─────21,122 (02.04%) ── referent(message=Content:ProgressChange) [59]
   ├─────21,122 (02.04%) ── referent(message=Content:SecurityChange) [59]
   ├─────21,122 (02.04%) ── referent(message=Content:StateChange) [59]
   ├─────21,122 (02.04%) ── referent(message=Content:StatusChange) [59]
   ├─────21,122 (02.04%) ── referent(message=FullZoomChange) [59]
   ├─────21,122 (02.04%) ── referent(message=ImageDocumentLoaded) [59]
   ├─────21,122 (02.04%) ── referent(message=TextZoomChange) [59]
   ├─────21,122 (02.04%) ── referent(message=ZoomChangeUsingMouseWheel) [59]
   ├─────17,052 (01.65%) ── referent(message=Forms:HideDropDown) [49]
   └─────17,052 (01.65%) ── referent(message=Forms:ShowDropDown) [49]

I will say up front that I have many tabs (~3k), but half a million things hanging off a single message in the message manager seems like a bit much.  I don't know very much about browser.xul, but it seems bad that InPermitUnload is added and then never removed:

https://hg.mozilla.org/mozilla-central/rev/95d82d6b1751#l5.810

and similar for things like Browser:Init and DOMTitleChanged:

https://hg.mozilla.org/mozilla-central/rev/95d82d6b1751#l5.810

It's not completely clear to me that the changeset for bug 1492967 is responsible, as it looks like various bits of addMessageListener calls were just moved around.  So this might have been a pre-existing problem.  There are also various other listeners that might be at fault here; I see tabbrowser.js registers listeners as well.

Brian, can you look into these or find somebody else to?  Thanks.

Comment 1

[Brian Grinstead [:bgrins]]

(In reply to Nathan Froyd [:froydnj] from comment #0)
> I will say up front that I have many tabs (~3k), but half a million things
> hanging off a single message in the message manager seems like a bit much. 
> I don't know very much about browser.xul, but it seems bad that
> InPermitUnload is added and then never removed:
> 
> https://hg.mozilla.org/mozilla-central/rev/95d82d6b1751#l5.810
> 
> and similar for things like Browser:Init and DOMTitleChanged:
> 
> https://hg.mozilla.org/mozilla-central/rev/95d82d6b1751#l5.810
> 
> It's not completely clear to me that the changeset for bug 1492967 is
> responsible, as it looks like various bits of addMessageListener calls were
> just moved around.  So this might have been a pre-existing problem.  There
> are also various other listeners that might be at fault here; I see
> tabbrowser.js registers listeners as well.

I was attempting to make no functional changes in Bug 1492967, although given how complex the construction / destruction is it's possible that something did change. It's worth noting that I'm now working on making <browser> a Custom Element in Bug 1441935, although I don't expect that would fix this particular issue, if it's a matter of removing the listener. It would at least make refactoring the code easier.

I'm focused on the Custom Element change right now so won't be able to take this at the moment, but perhaps Mike would be able to find someone to investigate this further given the perf implications.

Comment 2

[Mike Conley (:mconley) (:⚙️)]

Thanks for the heads up. Added to triage.

Comment 3

[:Gijs (he/him)]

Any idea how you get into this state? Just starting or restoring a bunch of tabs, or opening and closing a bundle of them, doesn't seem to do it for me (or at least, about:memory has no find-in-page hits for "message-manager-suspect").

Comment 4

[Nathan Froyd [:froydnj]]

I can't really say other than "use the browser".  I do have the following addons enabled:

Email Tabs	0.1.7582	true	[e-mail]
Gecko Profiler	0.25	true	[e-mail]
In-Page Pop-up Reporter	1.6	true	{feb799e2-29e2-4e35-b862-cc4e1842b6f5}
Price Wise	18.0.0	true	[e-mail]
Side View	0.4.3710	true	[e-mail]
Tab Center Redux	0.7.1	true	{0ad88674-2b41-4cfb-99e3-e206c74a0076}
Tab Stats	0.1.6	true	[e-mail]
Test Pilot	3.0.6vffecb95	true	@testpilot-addon

and it would not surprise me to learn that something like Price Wise was causing leaks...

Comment 5

[Mike Conley (:mconley) (:⚙️)]

I have Email Tabs, Gecko Profiler, Price Wise, Side View and Test Pilot also installed, and I don't see this in about:memory with a few hundred tabs open.

I've got my money on Tab Stats or Tab Center Redux.

Comment 6

[:Gijs (he/him)]

So, AFAICT, the `suspect` bit here just means "there are a lot of references" (specifically, more than 300).

This is all pretty strange because :froydnj is seeing us adding lots (like ~1300) references for the InPermitUnload case when adding a new tab. But setting a breakpoint in the browser.xml case which is the only place where we have InPermitUnload listeners, only gets hit once:

getInPermitUnload (browser.xml#1797)
updateCurrentBrowser (tabbrowser.js#1050)
_setupEventListeners (tabbrowser.js#4548)
selectedIndex (tabbox.js#201)
selectedPanel (tabbox.js#215)
set_selectedIndex (tabbox.xml#172)
set_selectedItem (tabbox.xml#197)
selectedTab (tabbox.js#80)
selectedTab (tabbrowser.js#271)
loadOneTab (tabbrowser.js#1462)
openLinkIn (utilityOverlay.js#536)
openUILinkIn (utilityOverlay.js#261)
openTrustedLinkIn (utilityOverlay.js#191)
wrappedJSObject (browser.js#2364)
BrowserOpenTab (browser.js#2363)
oncommand (browser.xul#1)

This doesn't make much sense - if we're adding only 1 listener, why are we incrementing the refcount by so many?

The code here is not great in that it should definitely remove itself when it gets the "right" message - otherwise we'll just accumulate listeners that keep getting called if we keep querying this method. But we don't actually, AFAICT, call into it all that much, and so I don't understand where the inflated reference counts are coming from.

The "side view" and "price wise" add-ons I assume are the only mozilla-signed ones and therefore the only ones with experiments, and I don't see them manipulating anything here either.

Comment 7

[Nathan Froyd [:froydnj]]

Still running into this with a relatively fresh session:

4,737 (100.0%) -- message-manager
└──4,737 (100.0%) -- referent
   ├──4,669 (98.56%) -- global-manager
   │  ├──4,669 (98.56%) ── strong
   │  └──────0 (00.00%) ++ weak
   ├─────57 (01.20%) -- parent-process-manager
   │     ├──57 (01.20%) ── strong
   │     └───0 (00.00%) ++ weak
   └─────11 (00.23%) ++ child-process-manager

38,760 (100.0%) -- message-manager-suspect
└──38,760 (100.0%) ── global-manager/referent(message=InPermitUnload) [60]

But I'm starting to suspect that we're not counting things correctly in about:memory.  The function that does the counting is here:

https://searchfox.org/mozilla-central/rev/0ee0b63732d35d16ba22d5a1120622e2e8d58c29/dom/base/nsFrameMessageManager.cpp#1020-1064

And notice that we're recursively traversing child managers:

https://searchfox.org/mozilla-central/rev/0ee0b63732d35d16ba22d5a1120622e2e8d58c29/dom/base/nsFrameMessageManager.cpp#1058-1063

But we're adding suspect messages during the recursive calls, as it were:

https://searchfox.org/mozilla-central/rev/0ee0b63732d35d16ba22d5a1120622e2e8d58c29/dom/base/nsFrameMessageManager.cpp#1036-1040

So if we have, say, 1000 child message managers and our limit is 300, we're actually going to add ~700 entries to mSuspectMessages, right, all for the same message?  And then we're going to repeatedly re-count the total number of referents for each of those ~700 entries:

https://searchfox.org/mozilla-central/rev/0ee0b63732d35d16ba22d5a1120622e2e8d58c29/dom/base/nsFrameMessageManager.cpp#1093-1105

I think?  So we'd wind up with several thousand (tens of thousand?) "referents", because we've double-counted things.  Does that sound plausible?

Comment 8

[:Gijs (he/him)]

(In reply to Nathan Froyd [:froydnj] from comment #7)
> So if we have, say, 1000 child message managers and our limit is 300, we're
> actually going to add ~700 entries to mSuspectMessages, right, all for the
> same message?  And then we're going to repeatedly re-count the total number
> of referents for each of those ~700 entries:
> 
> https://searchfox.org/mozilla-central/rev/
> 0ee0b63732d35d16ba22d5a1120622e2e8d58c29/dom/base/nsFrameMessageManager.
> cpp#1093-1105
> 
> I think?  So we'd wind up with several thousand (tens of thousand?)
> "referents", because we've double-counted things.  Does that sound plausible?

From how you explain it, yes, but I'm totally not familiar with this code. Maybe Shawn or :njn (needinfos blocked) can help check.

Comment 9

[Nathan Froyd [:froydnj]]

njn is back, I think, so ni? for comment 7.

Comment 10

[:Felipe Gomes (needinfo for replies!)]

Regardless of the double counting, adding the listener and never removing it in this case seems clearly incorrect, and we should fix it. It's different from the other examples brought up (e.g. DOMTitleChanged) because the listener is added only once on those cases, and the listener object is the <browser> element itself, so they all go away together.

The getInPermitUnload function appears to be called on every tab switch, so that explains why usage will ramp up.. But it doesn't explain why others can't reproduce the issue (I just tried too). It could be that something else is leaking browsers and then you're seeing this count for every tab that ever existed in your current session.. Could be some add-on or other non-standard pref behavior. Do you have the pref dom.disable_beforeunload set to true?

Comment 11

[Nathan Froyd [:froydnj]]

I do not have dom.disable_beforeunload set. I will twiddle some of the addons I have (Email Tabs, In-Page Pop-up Reporter, and the Gecko Profiler) and see if that makes a difference.

Comment 12

[Nicholas Nethercote [inactive]]

I have zero expertise with how the message manager works so I can't say one way or the other if double counting is occurring.

Comment 13

[Eric Rahm [:erahm]]

Nathan can you split off the double-counting issue and we can use this bug for the 'not removing a listener' part?

Comment 14

[Mike Conley (:mconley) (:⚙️)]

(In reply to Nathan Froyd [:froydnj] from comment #11)

I do not have dom.disable_beforeunload set. I will twiddle some of the addons I have (Email Tabs, In-Page Pop-up Reporter, and the Gecko Profiler) and see if that makes a difference.

Did fiddling with your add-ons make any difference here?

Comment 15

[Nathan Froyd [:froydnj]]

(In reply to Mike Conley (:mconley) (:⚙️) from comment #14)

(In reply to Nathan Froyd [:froydnj] from comment #11)

I do not have dom.disable_beforeunload set. I will twiddle some of the addons I have (Email Tabs, In-Page Pop-up Reporter, and the Gecko Profiler) and see if that makes a difference.

Did fiddling with your add-ons make any difference here?

Disabling the in-page pop-up reporter appears to make this problem go away. \o/

Comment 16

[Mike Conley (:mconley) (:⚙️)]

Alrighty, moving to the WebExtension component for now then, as this is probably something we should try to prevent within the WebExtension APIs.

Here's the source code for the WebExtension in question: https://github.com/ehsan/popup-reporter

Comment 17

[Kris Maglione [:kmag]]

I can't see any reason this would be related to that extension. It looks pretty trivial, and doesn't really do anything that looks relevant.

The getInPermitUnload function is definitely buggy, though, and is clearly the cause of this problem, and will clearly cause it with or without extensions.

Comment 18

[Kris Maglione [:kmag]]

Also, can I mention how much I hate that we have so much code uses buggy ad-hoc strategies for sending messages that need responses like this?

Comment 19

[:Felipe Gomes (needinfo for replies!)]

Attachment: Bug 1514757 - Remove InPermitUnload message listener once it has done its job. r=Gijs

Comment 20

[:Felipe Gomes (needinfo for replies!)]

I'm fixing the obvious flaw here and will file a separate bug to improve the InPermitUnload handling so that it shouldn't require a round-trip message for this.

I'll leave following up on the possible double-counting of listeners up to Nathan.

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d650090f08b8
Remove InPermitUnload message listener once it has done its job. r=Gijs

Comment 22

[Razvan Maries]

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