Closed Bug 1514757 Opened 6 years ago Closed 6 years ago

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

Categories

(Firefox :: Tabbed Browser, defect, P3)

Product:
Firefox
Component:
Tabbed Browser
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
Firefox 67
Tracking Flags:
Tracking Status
firefox67 --- fixed

People

(Reporter: froydnj, Assigned: Felipe)

References

Details

(Whiteboard: [MemShrink:P2][fxperf:p3])

Attachments

(1 file)

Bug 1514757 - Remove InPermitUnload message listener once it has done its job. r=Gijs
(deleted), text/x-phabricator-request
Details
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.
Flags: needinfo?(bgrinstead)
(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.
Flags: needinfo?(bgrinstead) → needinfo?(mconley)
Thanks for the heads up. Added to triage.
Flags: needinfo?(mconley)
Whiteboard: [MemShrink] → [MemShrink][fxperf]
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").
Flags: needinfo?(nfroyd)
I can't really say other than "use the browser". I do have the following addons enabled: Email Tabs 0.1.7582 true email-tabs@mozilla.org Gecko Profiler 0.25 true geckoprofiler@mozilla.com In-Page Pop-up Reporter 1.6 true {feb799e2-29e2-4e35-b862-cc4e1842b6f5} Price Wise 18.0.0 true shopping-testpilot@mozilla.org Side View 0.4.3710 true side-view@mozilla.org Tab Center Redux 0.7.1 true {0ad88674-2b41-4cfb-99e3-e206c74a0076} Tab Stats 0.1.6 true tabstats@glandium.org Test Pilot 3.0.6vffecb95 true @testpilot-addon and it would not surprise me to learn that something like Price Wise was causing leaks...
Flags: needinfo?(nfroyd)
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.
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.
Priority: -- → P3
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?
Flags: needinfo?(gijskruitbosch+bugs)
(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.
Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(shawnjohnjr)
njn is back, I think, so ni? for comment 7.
Flags: needinfo?(n.nethercote)

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?

Flags: needinfo?(nfroyd)

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.

Flags: needinfo?(nfroyd)

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.

Flags: needinfo?(n.nethercote)

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

Flags: needinfo?(nfroyd)
Whiteboard: [MemShrink][fxperf] → [MemShrink:P2][fxperf]

(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?

Whiteboard: [MemShrink:P2][fxperf] → [MemShrink:P2][fxperf:p3]

(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/

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

Component: XUL Widgets → Untriaged
Product: Toolkit → WebExtensions
Priority: P3 → --

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.

Component: Untriaged → Tabbed Browser
Product: WebExtensions → Firefox

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?

Priority: -- → P3

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.

Assignee: nobody → felipc
Status: NEW → ASSIGNED
Pushed by fgomes@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/d650090f08b8 Remove InPermitUnload message listener once it has done its job. r=Gijs

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

Status: ASSIGNED → RESOLVED
Closed: 6 years ago
status-firefox67: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 67
Flags: needinfo?(froydnj+bz)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: