773755 - don't force a cycle collection with 0 suspected objects

Status: RESOLVED FIXED

(Core :: XPCOM, defect)

Description

[Andrew McCreight [:mccr8]]

Gregor noticed this when he left B2G running overnight:

E/GeckoConsole(  116): CC(T+47536.5) duration: 71ms, suspected: 0, visited: 1089 RCed and 1016 GCed, collected: 0 RCed and 0 GCed (0 waiting for GC)
E/GeckoConsole(  116): ForgetSkippable 1 times before CC, min: 3 ms, max: 3 ms, avg: 3 ms, total: 3 ms, removed: 0
E/GeckoConsole(  116): CC(T+47662.6) duration: 61ms, suspected: 0, visited: 1089 RCed and 1016 GCed, collected: 0 RCed and 0 GCed (0 waiting for GC)

We're triggering a forced CC, even though there are 0 suspected objects and no GC has run since the last time.  In that case, the CC shouldn't find any garbage, so we shouldn't run the CC.  We can probably ignore the GC condition, (because the GC will force a CC) as long as we are careful about how and when we bail out.

Comment 1

[Andrew McCreight [:mccr8]]

In Gregor's log, there are 427 CCs with 0 suspected objects, 78 with 1, and 25 with 2 or more (mostly 2-4, with a few in the low teens).  Smaug points out that ForgetSkippable is only running once in between, so maybe fixing that would reduce the number of suspected objects further.  So about 80% have 0 suspected objects.

Comment 2

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

Attachment: patch?

Maybe like this.
Could you Gregor test this on b2g.

The changes to TimerFireForgetSkippable are just about better logging, so that
we get right min/max/count of forgetSkippables

Comment 3

[Andrew McCreight [:mccr8]]

Comment on attachment 642157 [details] [diff] [review]
patch?

Review of attachment 642157 [details] [diff] [review]:
-----------------------------------------------------------------

Nice!

Comment 4

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

Hmm, I think I need to change MaybePokeCC too

Comment 5

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

And I think I've found another problem.
If there are 100 < suspected < 250 objects, we won't do CC until after 120s.
Before that forgetSkippable timer may run all the time because the limit to start forgetSkippable
is lower than limit to run CC.
And especially, MaybePokeCC() is called after each event in main event loop.
So when forgetSkippable timer is called last time, sCCTimer is deleted and then MaybePokeCC()
starts a new cycle.

New patch coming.

Comment 6

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

Attachment: v2

Make sure we don't re-trigger forgetSkippable timer right after deleting it.

Comment 7

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

200 is somewhat random, but wanted to lower it a bit so that cc timer does get
triggered quite easily.

Comment 8

[Andrew McCreight [:mccr8]]

Comment on attachment 642250 [details] [diff] [review]
v2

Hmm. I'm not sure if it is a good idea to make the thresholds the same, but I guess realistically a CC and a forgetSkippable can take similar amounts of time.  You could also add a suspected threshold argument to ShouldTriggerCC, with a default of NS_CC_PURPLE_LIMIT.  But this is okay too I guess.

Comment 9

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

Well, the point is that the threshold must be the same, otherwise we may end up firing the
timer all the time if there are more than 100 suspected objects but less than 250

Comment 10

[Andrew McCreight [:mccr8]]

Ah, right.

Comment 11

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

https://hg.mozilla.org/mozilla-central/rev/5ff43f5c593e

Let's see what telemetry will say about this.

Comment 12

[Gregor Wagner [:gwagner]]

The log file on my B2G phone looks more empty with this patch :)
On my netbook I still see a CC every 15 sec even when I don't touch it:

CC(T+4866.2) duration: 10ms, suspected: 277, visited: 1173 RCed and 635 GCed, collected: 0 RCed and 0 GCed (0 waiting for GC)
ForgetSkippable 2 times before CC, min: 0 ms, max: 0 ms, avg: 0 ms, total: 0 ms, removed: 44

CC(T+4881.2) duration: 10ms, suspected: 277, visited: 1173 RCed and 635 GCed, collected: 0 RCed and 0 GCed (0 waiting for GC)
ForgetSkippable 2 times before CC, min: 0 ms, max: 0 ms, avg: 0 ms, total: 0 ms, removed: 44

Here we have a constant set of suspected objects that trigger a CC every 15 sec for quite a while now.

Comment 13

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

Well, on Netbook you use normal Firefox which does plenty of stuff all the time causing
possible garbage. (And even just moving mouse over the UI puts objects to the CC graph.)

But every 15s is odd. I'm certainly not getting that behavior. When I now look at
memchaser, last CC happened 62s ago.