1341484 - Chris Lord is experiencing really slow CCs in the parent process

Status: RESOLVED WORKSFORME

(Core :: XPCOM, defect)

Description

[(no longer active)]

See this profile: <https://perfht.ml/2l5z3KR>.

Olli, can you please take a look?  I'm CCing Chris in case you have any questions about his setup.

Comment 1

[(no longer active)]

This query may expose the extent of the problem better: https://perfht.ml/2l5NWMY

Comment 2

[Andrew McCreight [:mccr8]]

What does the browser console show for the CC when javascript.options.mem.log is set to true?

Generally horrible CC times are caused by ghost windows. Does about:memory show any ghost windows?

Though it does seem bad that all of this CC work is happening under NotifyDidPaint.

Comment 3

[Chris Lord [:cwiiis]]

I'll do this tonight (probably) - I assume that's a pref, should I set it only when this happens, or before? Does it have impact on normal running? Should I capture another profile when it happens? And while we're at it, is there any other information you'd like that I can easily gather?

Comment 4

[Olli Pettay [:smaug][[e-mail]]]

Well, all the work happens under NotifyDidPaint if there is any painting happening.

The pref doesn't affect really normal running, but keeping browser console open of course itself
creates some more garbage to collect.

When the issue happens, creating CC/GG logs using about:memory could be useful.
I or mccr8 could then take a look at the one related to parent process.
Concise and verbose could both be useful.

Does the verbose memory report from about:memory show detached or ghost windows?

Comment 5

[Olli Pettay [:smaug][[e-mail]]]

The profile seems to tell that there is a leak.

Do you use any addons?

Comment 6

[Chris Lord [:cwiiis]]

(In reply to Olli Pettay [:smaug] (pto-ish for couple of days) from comment #5)
> The profile seems to tell that there is a leak.
> 
> Do you use any addons?

Currently using:
- DuckDuckGo Plus 1.1.1
- Gecko Profiler 2.0.31
- LastPass 4.1.35a
- Open Tabs Next to Current 1.1.5
- Page Shot 5.2.201701261751
- Test Pilot 1.1.1-dev-8b67799
- uBlock Origin 1.11.0

Note that in this profile, the browser was left basically unused for the day. It had 5 tabs open, Facebook (active tab), TweetDeck, GMail, GoDaddy Mail and a Medium post.

I use the same add-ons with success in Linux, though that machine is a lot more powerful than this laptop.

Comment 7

[Andrew McCreight [:mccr8]]

(In reply to Chris Lord [:cwiiis] from comment #3)
> I'll do this tonight (probably) - I assume that's a pref, should I set it
> only when this happens, or before? Does it have impact on normal running?

It just generates some strings, so you should be able to leave it on all the time without much perf impact. Just don't leave the console open, because that can leak windows. (bug 1084605)

Like Olli said, save an about:memory report (anonymized if you would like, though if you do keep around a non-anonymized copy yourself so we can figure out which page is actually leaking, if that's the case). That will show us what is leaking, which is the most likely cause for slow CCs.

I did recently fix a leak that impacted AdBlockPlus (bug 1336811) so it is possible that it also impacts uBlock Origin.

Comment 8

[Chris Lord [:cwiiis]]

Attachment: memory-report.json.gz

Here's a memory report with Nightly in the state of using a load of CPU while doing nothing. I left it running all day, and didn't really interact with it at all.

I wasn't seeing the huge pauses that I was in the original profile that spawned this bug, just abnormal, constant CPU usage. Unfortunately, when I went to capture a profile, Firefox crashed :(

It's pretty easy to get into this state though (STR: Open Firefox, wait a few hours), so let me know what other information I've missed that would be useful.

Comment 9

[(no longer active)]

No ghost windows, some detached ones...

It would be helpful if you could bisect your add-ons, by which I mean, disable half of them, and see if the issue occurs.  If it does, repeat this process in the set of currently enabled ones recursively, otherwise in the set of currently disabled ones.  Of course, before doing that it's worth verifying that it doesn't happen without any add-ons, which you can test by running in safe mode.

Comment 10

[Chris Lord [:cwiiis]]

Here are the memory reports for the bug occurring in safe mode. Unfortunately I can't get a profile like this, but I'll disable all the add-ons bar the Gecko profiler and do that next. Turns out you don't really have to wait that long :(

https://www.dropbox.com/sh/f1vzxfb1onuvy14/AADkX3QvGRHtBkepc2WmUg29a?dl=0

Comment 11

[Olli Pettay [:smaug][[e-mail]]]

Hmm, the gc-cc logs contains lots of random files.
Could you just include the files about:memory tells about, and perhaps two different zips, one for concise and one for verbose logs.
(concise logs are often way easier to analyze, but may miss information which is available in verbose)

Comment 12

[Chris Lord [:cwiiis]]

I'll have to come back to this as I want to use this machine a bit and having something sitting in the background eating CPU makes things a bit painful.

I can confirm the issue happens both in safe mode and with only one add-on (the profiler) enabled. I would have had a profile, but Firefox crashed getting the profile, again (here's the crash report: https://crash-stats.mozilla.com/report/index/851ce8c4-8938-4ae0-8574-6d2422170223).

I'll get a concise memory report soon, I assume the attached profiles are good enough seeing as it appears that add-ons are not causing the problem.

Comment 13

[Markus Stange [:mstange]]

You can stop the crash by setting your thread filter back to the default "GeckoMain,Compositor". The crash is bug 1224595. Profiler crashiness is being worked on at the moment.

Comment 14

[Daniel Holbert [:dholbert]]

Hi Chris - are you still able to circle back to this?  Looks like this was blocked on getting a memory report, per comment 12.

(For now, I'm removing [qf:investigate] since there's nothing the QF team can do in terms of investigation at this point, IIUC. Once we've got something that's independently actionable/investigatable here, feel free to add [qf] back to nominate for qf triage!)

Comment 15

[Chris Lord [:cwiiis]]

I'm not sure I see this anymore - I had my laptop on for multiple days with Nightly open recently (the same machine with a similar workload and similar add-ons) and it hadn't gotten itself into the state that this bug was filed about. That said, I also don't use Tweetdeck anymore, so that may be related. I think most, if not all, the performance issues I was hitting have been filed and are being addressed, so going to close this.