1260475 - Poor GC throughput due to refresh-triggered slices

Status: RESOLVED FIXED

(Core :: JavaScript: GC, defect)

Description

[The 8472]

Attachment: refresh-triggered GCs.png

See attached profiler screenshot. It's spending 28.7% of time in GC slices triggered by the refresh driver and an additional 11.2% in slices triggered by other things.

In the past I've turned off project silk vsync settings and that seemed to lessen the impact, but that option has been gone for a while (february?).

Anyway, in my case the GC is going to miss the 60fps pause goals anyway, since I've also increased javascript.options.mem.gc_incremental_slice_ms to 40ms, so it would be nice if I could at least improve throughput by turning off refresh-triggered GC slices.

Comment 1

[Emanuel Hoogeveen [:ehoogeveen]]

I made a quick patch to add a preference to disable these slice triggers. Could you try the build from this try run that matches your platform (once they're done), and see if it performs any better?

https://treeherder.mozilla.org/#/jobs?repo=try&revision=cc88ce7e1de4&selectedJob=18761739

Once the build for a platform is done, the B next to that platform will turn green. If you then click on that B, a panel will pop up, with a link to the build directory next to "Build:" on the lower left.

The new preference is called javascript.options.mem.gc_refresh_frame_slices_enabled and can be set to false from about:config. It might need a browser restart to take effect, though I'm not sure.

Comment 2

[Emanuel Hoogeveen [:ehoogeveen]]

Attachment: Add an option to disable GC slices triggered by painting.

I won't ask for review on this until we know it helps :)

Comment 3

[The 8472]

The GC logs don't show refresh timer slices, so that part works.

I can't compare profiler numbers since it can't resolve symbols for this build.

But subjectively the browser does seem to be less sluggish.

Comment 4

[Emanuel Hoogeveen [:ehoogeveen]]

Comment on attachment 8736014 [details] [diff] [review]
Add an option to disable GC slices triggered by painting.

Great, I'll ask for review on this then.

Terrence, this was pretty straightforward, though it's obviously just a mitigation for a situation that I think is hard to fix in general.

I wasn't sure if the preference should be exposed to workers - I don't know if those receive NotifyDidPaint at all. If they do, though, it should work just the same as for the main thread GCRuntime, so I propagated the preference for completeness. This is all off by default, so it shouldn't affect behavior normally.

Comment 5

[The 8472]

The pref also has a positive impact on startup performance:

gc_refresh_frame_slices_enabled = false -> 1m11s
gc_refresh_frame_slices_enabled =  true -> 1m40s

Comment 6

[Terrence Cole [:terrence]]

Comment on attachment 8736014 [details] [diff] [review]
Add an option to disable GC slices triggered by painting.

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

It would be nice to have this happen automatically in the case where the refresh driver is overloading us. In the meantime, let's take this.

Comment 7

[Emanuel Hoogeveen [:ehoogeveen]]

(In reply to Terrence Cole [:terrence] from comment #6)
> It would be nice to have this happen automatically in the case where the
> refresh driver is overloading us. In the meantime, let's take this.

Yeah, in general it would be nice to let the mutator run at least a certain percentage of the time, unless it's allocating so quickly that we're falling behind. But this should provide a nicer middle ground at least.

Comment 8

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/aeb9cc61c8ad

Comment 9

[Carsten Book [:Tomcat]]

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

Comment 10

[Emanuel Hoogeveen [:ehoogeveen]]

Looks like this made it today's Nightly :) Automatic updates seem to be disabled at the moment, but you can download the latest from http://archive.mozilla.org/pub/firefox/nightly/latest-mozilla-central/

Comment 11

[The 8472]

Works on nightly and improves responsiveness after a restart.

Sadly performance - ratio of GC time to application time - still is getting worse with uptime. I'll file a separate bug for that once I have some decent profiler output showing the issue.

The problem is getting the corresponding GC logs. Is there a way to print them to a file instead of the browser console?

Comment 12

[Emanuel Hoogeveen [:ehoogeveen]]

I believe the output can be redirected by setting the MOZ_GCTIMER environment variable to a filename before opening the browser. See also [1] and [2].

[1] https://developer.mozilla.org/en-US/docs/Mozilla/Performance/GC_and_CC_logs
[2] https://developer.mozilla.org/en-US/docs/Mozilla/Projects/SpiderMonkey/Internals/GC/Statistics_API

Comment 13

[The 8472]

Ok, that variable was crashing the content process for me, but I figured it out, it needs security.sandbox.content.level = 0 to work.

Comment 14

[Andrew McCreight [:mccr8]]

(In reply to The 8472 from comment #13)
> Ok, that variable was crashing the content process for me, but I figured it
> out, it needs security.sandbox.content.level = 0 to work.

That sounds like a bug in the patch. What is the crash report for the crash that you got?

Comment 15

[The 8472]

I meant the MOZ_GCTIMER environment variable, that one crashes the content process.

crash report is bp-c5ae5232-1dfd-4b52-bd24-ab6fa2160402

Comment 16

[Andrew McCreight [:mccr8]]

Thanks, I filed bug 1261850 about that issue.

Comment 17

[The 8472]

Filed bug 1262321 about the remaining throughput problems.