1187180 - MDN Spam Patrol add-on leaks

Status: RESOLVED WONTFIX

(WebExtensions :: General, defect)

Description

[Eric Shepherd [:sheppy]]

Attachment: Sampling taken during random beachball, with garbage box in menu bar

I've been experiencing terrible performance in Firefox for three weeks or so now, in all branches I've tried, including Beta, Dev Edition, and Nightly. I have tried a fresh profile and had no improvement.

I've been collecting OS X samples of Firefox whenever this happens and have a number of them. I will be attaching a few here with some notes about the circumstances that might be interesting.

Overview, though:

Firefox performance starts out pretty good at the outset after launch, with about:performance reporting mostly jank levels in the 0-2 range for most rows, but a couple that run in the 5-7 range (<process> and [System Principal], jar:file:///Applications/FirefoxNightly.app/Contents/Resources/omni.ja!/components/DataReportingService.js).

Over time, the numbers gradually climb, until the numbers are in the 3-8 range, with outliers being in the 10-12 range.

Right now I'm looking at this one for instance:

Jank level	User (%)	System (%)	Cross-Process (%)	Activations	
10	2952	273	0	797205	[System Principal], about:blank

That seems a bit much for about:blank, but I might be missing something.

(I will include an attachment of the entire list).

After Firefox has been running for a while (we're talking 15-30 minutes), it starts to beachball sometimes when opening a tab (even to about:blank), closing a tab, or switching tabs. Before long, the beachball is quite literally every time. For up to 90 seconds each time.

It's about then that random beachballs begin. Just, it's sitting there and suddenly it's beachballed. Or I'll be working in another app and mouse over Firefox, and I get a beachball there, even without clicking.

Once it's at that point, I cannot reasonably restart Firefox without a force-quit, as shutdown of Firefox takes longer than 6-10 minutes (the limit of my willingness to sit and wait for it to quit). In fact, it takes up to 5 minutes for the first of my four open windows to close. The 6-minute test today, only one of the four windows ever got around to closing before I gave up and force-quit.

Interesting added point: this evening, in nightly, it randomly beachballeed and while doing so, there was a little box in the top left corner of my menu bar (on my main screen), about half the height of the menu bar and roughly the same width as the titles of the Apple and Nightly menus, which was flickering garbage content -- mostly black pixels with enough white or grey to make it interesting. That is the first time I've seen this effect though.

Comment 1

[Eric Shepherd [:sheppy]]

I am *not* certain this is a JS bug, for what it's worth. But it seems like it's a good place to start the hunt given the contents of the samples I'm seeing.

Comment 2

[Eric Shepherd [:sheppy]]

Attachment: The contents of about:performance taken from Nightly

Attached: about:performance data from my current Nightly session.

Comment 3

[Eric Shepherd [:sheppy]]

Attachment: Performance tool profile taken during a beachball after switching tabs

Attached: Performance profile output taken while switching tabs for a while. I switched tabs 2-3 times or so here, I think, with the last one beachballing for quite a while.

Comment 4

[Eric Shepherd [:sheppy]]

Seems possibly relevant: I am *not* using e10s.

Comment 5

[Andrew McCreight [:mccr8]]

Could you attach an about:memory report? Severe leaks can have symptoms like that. You can attach an anonymized one if you want.

Comment 6

[Eric Shepherd [:sheppy]]

Attachment: A teaser screenshot offering a little taste of what the profile data previously attached includes

Attached: a PNG screenshot of the performance tool after recording for a while during which I changed tabs a few times, with beachballs of varying length happening each time.

Comment 7

[Eric Shepherd [:sheppy]]

Attachment: Memory report from about:memory

As requested! about:memory report!

Comment 8

[Eric Shepherd [:sheppy]]

Attachment: Sample taken during a beachballed shutdown, about 3 minutes of beachball so far

Attached: Apple Activity Monitor sample taken about three minutes into a beachballed shutdown. At this point, none of my four windows have closed yet.

This is from Developer Edition.

Comment 9

[Eric Shepherd [:sheppy]]

Attachment: Another sample taken during the same shutdown; one window finally closed

Attached: Sample taken after one window finally closed, but still beachballed. Same shutdown as before.

Comment 10

[Eric Shepherd [:sheppy]]

Attachment: Another sample from same shutdown; six minutes beachballed - I give up

Attached: Another sample, taken after six minutes of ongoing beachball during shutdown. Still only one of four windows closed. I gave up after this and force-quit.

That's all I will post tonight -- I have other samples, but I figure this is a good start. Let me know what else I can gather.

Comment 11

[Andrew McCreight [:mccr8]]

How much RAM do you have on your computer? It says Firefox is taking up 10GB. If you have 8GB, the OS might just be thrashing.  Nothing really stands out there, except that you have a lot of tabs open.  I am impressed that the about:memory report took 1.6GB of memory.

Comment 12

[Eric Shepherd [:sheppy]]

(In reply to Andrew McCreight [:mccr8] from comment #11)
> How much RAM do you have on your computer? It says Firefox is taking up
> 10GB. If you have 8GB, the OS might just be thrashing.  Nothing really
> stands out there, except that you have a lot of tabs open.  I am impressed
> that the about:memory report took 1.6GB of memory.

My iMac has 16 GB. I don't think I have that many tabs open. It's, what, 35 across four windows? I counted them the other day and it was around there, and I've been trying to close more than I open since then.

Comment 13

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

The performance profile does show quite a bit of GC'ing. I'm also seeing a lot of time spent firing timers...

How many Google Docs / Drive tabs do you normally have open, our of curiosity?

I also see traffic over what appears to be some SDK APIs hitting content, which suggests to me that an add-on is doing something rather heavy in content.

Can you also post your about:support?

Comment 14

[Eric Shepherd [:sheppy]]

Attachment: Output from about:support

(In reply to Mike Conley (:mconley) - Needinfo me! from comment #13)

> How many Google Docs / Drive tabs do you normally have open, our of
> curiosity?

Not many; I don't normally use Google docs and stuff unless I have to. Right now, I have 32 tabs open (and I *just* force-quit a beachballed Dev Edition).

There are 5 windows:

1: 14 tabs, three of which are Google docs or sheets.
2: 1 tab, a page on MDN.
3: 5 tabs, 3 MDN pages, 2 MXR search result pages
4: 11 tabs, 9 MDN pages, 1 W3C spec page, 1 local page of some sample code
5: 3 tabs, all static web pages with helpful tips about Evernote.

> I also see traffic over what appears to be some SDK APIs hitting content,
> which suggests to me that an add-on is doing something rather heavy in
> content.

Hm, that's possibly true, although I've tried disabling all my add-ons and not seen an appreciable improvement in this situation. But I'm attaching an about:support report.

Comment 15

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

This is all really useful info.

Now it's a matter of trying to figure out what the pattern is. Yoric, do you know what's going on here?

Comment 16

[Eric Shepherd [:sheppy]]

Totally possible it's an addon, but if it is, it's one I have trusted or relied on so much that I re-installed it very soon after starting a clean profile.

Comment 17

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

sheppy:

My hypothesis based on what you've reported is that you have an add-on that is causing Firefox to leak memory. We consume more and more of your system memory until the whole thing grinds to a halt, and you're swapping like crazy.

Since it looks like you're on OS X, can you try to confirm this behaviour by keeping Activity Monitor open, and tracking how much "Real Mem" Firefox will consume? Maybe do this for... an hour or so. Surf normally during that period. Can you give us a sense of how much it grows and how quickly it grows? Does it grow when you switch tabs, or when you follow links?

If so, we've found a leak.

One tactic we can use to diagnose this leak - see if this add-on[1] supplies any useful information about what might be causing such a leak: https://addons.mozilla.org/en-US/firefox/addon/about-addons-memory/?src=search - install it, enable it, and visit about:addons-memory... anything stick out?

Another idea is to install this add-on[1]: https://addons.mozilla.org/en-US/firefox/addon/cycle-collector-analyzer/?src=search

Then, when you're in a slow state, see if you can load up about:ccdump, and save the data to a JSON file with the Save Icon and attach it. That might tell us more about what is leaking.

[1]: Irony

Comment 18

[Eric Shepherd [:sheppy]]

(In reply to Mike Conley (:mconley) - Needinfo me! from comment #17)

I've installed the add-ons you suggested and will be monitoring things today. I'll post once I've collected more information. Thanks!

Comment 19

[David Teller [:Yoric] - still alive but not very active]

Sorry, no useful idea atm.

Comment 20

[Eric Shepherd [:sheppy]]

Interesting new tidbit: I got a Mac application OOM message (where the OS pauses most apps to save memory), and tried to use about:addons-memory to get data, but it beachballed for a while then Nightly crashed.

The crash doesn't seem to be directly related, but it's here: https://crash-stats.mozilla.com/report/index/d1189b7e-9722-44b6-a7e2-fb5262150727

Comment 21

[Eric Shepherd [:sheppy]]

Attachment: Screenshot of about:memory output while lagging is happening

Attached: a screenshot of the output of about:addons-memory taken while I'm getting beachballs switching tabs and the like.

Comment 22

[Eric Shepherd [:sheppy]]

Attachment: about:performance output grabbed between beachballs

Attached: Output from about:performance taken in between beachballs.

Comment 23

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

Huh. According to this, Nightly appears to be using < 500MB of memory, which, in this day and age, is quite reasonable... can you confirm in the Activity Monitor that this is the case, to rule out that this add-ons reporting is busted?

Comment 24

[Eric Shepherd [:sheppy]]

Here's the about:ccdump output: https://www.dropbox.com/s/d4z52s8zyv45fx5/cc-edges-sluggish.log?dl=0

As for your question, according to Activity Monitor, right now:

Memory: 4.79 GB
Compressed Mem: 44.0 MB
Threads: 74
Ports: 432

Comment 25

[Eric Shepherd [:sheppy]]

Also, CPU use is hovering around 50%. It's not spiking at the moment though; I'll try to get this info when it happens next.

Comment 26

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

Ok, I'm going to call about:addons-memory's reporting faulty and untrustworthy. Let's discard it.

Are you able to use https://addons.mozilla.org/en-US/firefox/addon/cycle-collector-analyzer/?src=search to get us a cycle collector dump?

Comment 27

[Eric Shepherd [:sheppy]]

(In reply to Mike Conley (:mconley) - Needinfo me! from comment #26)
> Ok, I'm going to call about:addons-memory's reporting faulty and
> untrustworthy. Let's discard it.
> 
> Are you able to use
> https://addons.mozilla.org/en-US/firefox/addon/cycle-collector-analyzer/
> ?src=search to get us a cycle collector dump?

See comment 24 and the link to the dump I put up earlier: https://www.dropbox.com/s/d4z52s8zyv45fx5/cc-edges-sluggish.log?dl=0 :)

Comment 28

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

Ah, thanks. :)

So, unfortunately, I can't seem to view the tree for this ccdump. I can see that there are over 9 million edges, but that's about it.

mccr8, anything else sheppy can do to help us track down this leak?

Comment 29

[Andrew McCreight [:mccr8]]

Sheppy, in comment 12, you said you had 35 tabs open, but if I open your about:memory report, and then expand "explicit", "window-object" and then "tiny", I see many MDN windows, maybe around 1200 of them. Each one is very small, but there are so many of them it adds up. They all end in $history. Do you have an addon that might be interacting with MDN somehow? "MDN Interface Documentation Generator" is the only addon I see that looks obviously related.

Comment 30

[Eric Shepherd [:sheppy]]

OK -- just saw this info in Activity Monitor while beachballed:

CPU panel:

 Nightly	103.8	1:56:17.86	82	1,095	23215	sheppy	64 bit	4.79 GB	44.0 MB	433		-	No	No	0 bytes	0 bytes	0	0	0 bytes	0 bytes	0 bytes	0 bytes	0 bytes	No	No		0 bytes	

Memory panel:

 Nightly	6.12 GB	922.2 MB	76	440	23215	sheppy	39.1	1:56:58.95	1,116	64 bit		-	No	No	0 bytes	0 bytes	0	0	0 bytes	0 bytes	0 bytes	0 bytes	0 bytes	No	No		0 bytes

Comment 31

[Eric Shepherd [:sheppy]]

(In reply to Andrew McCreight [:mccr8] from comment #29)
> Sheppy, in comment 12, you said you had 35 tabs open, but if I open your
> about:memory report, and then expand "explicit", "window-object" and then
> "tiny", I see many MDN windows, maybe around 1200 of them. Each one is very
> small, but there are so many of them it adds up. They all end in $history.
> Do you have an addon that might be interacting with MDN somehow? "MDN
> Interface Documentation Generator" is the only addon I see that looks
> obviously related.

WTF...?

The generator isn't doing it, definitely; it does nothing until selected, and doesn't know about the new wiki so wouldn't generate a $history URL at all.

But... I have a thought. I'll get back to you.

Comment 32

[Eric Shepherd [:sheppy]]

Yeah, the Spam Patrol add-on one of the MDN team created to help us handle spam added to MDN has broken recently, presumably due to changes in Firefox. Apparently it works fine in Firefox 39. I should try it.

Comment 33

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

Hey - so am I to understand you've narrowed this down to a particular add-on?

Comment 34

[Eric Shepherd [:sheppy]]

Attachment: The Spam Patrol add-on

(In reply to Mike Conley (:mconley) - Needinfo me! from comment #33)
> Hey - so am I to understand you've narrowed this down to a particular add-on?

Yeah -- it appears to be a custom add-on that was designed to help MDN staff monitor our site content for spam. It seems to have broken sometime in the past few weeks (that is, a Firefox change rendered it inoperative and introduced this memory leak at roughly the same time).

I'm attaching the add-on if you want to see it.

Comment 35

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

Who is the maintainer of this add-on? I'd like to verify that this is indeed the add-on misbehaving, and not our SDK somehow leaking something.

Comment 36

[Andrew McCreight [:mccr8]]

Addons should not be able to leak like this.

Comment 37

[Eric Shepherd [:sheppy]]

Attachment: Beachballed on macworld.com article

(In reply to Mike Conley (:mconley) - Needinfo me! from comment #35)
> Who is the maintainer of this add-on? I'd like to verify that this is indeed
> the add-on misbehaving, and not our SDK somehow leaking something.

This add-on was created by Will Bamberg, but I'm not sure if it's actually maintained actively anymore or not -- I thought it was until a couple days ago, but now I'm not sure.

At any rate, I've had another beachball, even without the add-on, but am not sure it's related. Attaching the sample from Activity Monitor. I walked off while waiting on a page on Macworld's site to load, and it went into beachball mode.

There is also an "Unresponsive script" message up, with the URL of the script being: chrome://global/contetn/bindings/browser.xml:401

Comment 38

[Eric Shepherd [:sheppy]]

Adding Will to the cc list so he can offer replies related to the spam patrol add-on. I'm not 100% sure it's the source of the leak,but it does seem to at least exacerbate the problem.

Comment 39

[Jorge Villalobos [:jorgev] (he/him)]

Mass-closing bugs that relate to legacy versions of add-ons or are otherwise no longer worth tracking. Please comment if you think this bug should be reopened.

Sorry for the bugspam. Made you look, though!