1303754 - Reconsider lazy source code options

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Jan de Mooij [:jandem]]

We have some flags (per compilation or per compartment) to discard source code completely or to call a callback whenever we need the source code (for Function.prototype.toString etc). This was added to save memory, but these flags inhibit lazy parsing so they can actually make us use more memory.

After removing the options.setSourceIsLazy call in mozJSComponentLoader::ObjectForLocation, I get the following results:

GC heap, parent process:

-2,076,640 B (92.69%) -- gc-things
  -1,303,832 B (58.19%) ── scripts
     557,376 B (-24.88%) ── lazy-scripts
    -530,368 B (23.67%) ── scopes
    -331,984 B (14.82%) ── objects
    -280,352 B (12.51%) ── shapes
    -211,864 B (09.46%) ── strings
     ─33,888 B (-1.51%) ── object-groups
      -9,504 B (00.42%) ── base-shapes

GC heap, 3 content processes combined:

-1,096,520 B (113.43%) -- gc-things
  -735,216 B (76.06%) ── scripts [3]
   346,560 B (-35.85%) ── lazy-scripts [3]
  -294,368 B (30.45%) ── scopes [3]
  -171,440 B (17.74%) ── strings [3]
  -109,384 B (11.32%) ── shapes [3]
   -90,832 B (09.40%) ── objects [3]
   -41,904 B (04.33%) ── object-groups [3]

Note that we have a lot more lazy scripts now and fewer scripts, scopes, strings, etc.

The actual win is a bit bigger because these numbers are only for the GC heap.

Comment 1

[Jan de Mooij [:jandem]]

Attachment: Patch

Not sure if there's a better reviewer for this..

There's still the uncompressed-source-cache issue we talked about, but this patch is definitely a win locally and shrinks the GC heap a lot.

Comment 2

[Eric Rahm [:erahm]]

Can you try throwing this at AWSY? I'm curious to see the behavior on a larger test set.

You can spin up a test with the following try syntax:

> try: -b o -p linux64 -u none -t none -awsy jandem_bug_1303754

I'd suggest doing two runs, one with just a baseline (no patch) and one with your changes.

Comment 3

[Jan de Mooij [:jandem]]

(In reply to Eric Rahm [:erahm] from comment #2)
> You can spin up a test with the following try syntax:

I actually did just that earlier today: https://treeherder.mozilla.org/#/jobs?repo=try&author=[e-mail]&group_state=expanded

But it's not showing up here: https://areweslimyet.com/?series=jandem_lazyparsing - do I have to wait a bit longer?

Comment 4

[Jan de Mooij [:jandem]]

And thanks for the reminder, I wanted to ping you about AWSY but forgot :)

Comment 5

[Eric Rahm [:erahm]]

(In reply to Jan de Mooij [:jandem] from comment #3)
> (In reply to Eric Rahm [:erahm] from comment #2)
> > You can spin up a test with the following try syntax:
> 
> I actually did just that earlier today:
> https://treeherder.mozilla.org/#/jobs?repo=try&author=jandemooij@gmail.
> com&group_state=expanded
> 
> But it's not showing up here:
> https://areweslimyet.com/?series=jandem_lazyparsing - do I have to wait a
> bit longer?

It looks like the try watcher was notified the build finished before the archives were uploaded, I'll reschedule the runs now. Should take about 1.5 hours.

Comment 6

[Jan de Mooij [:jandem]]

(In reply to Eric Rahm [:erahm] from comment #5)
> It looks like the try watcher was notified the build finished before the
> archives were uploaded, I'll reschedule the runs now. Should take about 1.5
> hours.

Thanks!

Comment 7

[Jan de Mooij [:jandem]]

So most of the lines on AWSY show an improvement: https://areweslimyet.com/?series=jandem_lazyparsing

But I'm a bit worried about "JS: After TP5 [+30s]" in the last graph. Not sure why that shows a 9.61 MB regression. I'll investigate, maybe we're double counting stuff or does about:memory detect that?

Comment 8

[Jan de Mooij [:jandem]]

(In reply to Jan de Mooij [:jandem] from comment #7)
> But I'm a bit worried about "JS: After TP5 [+30s]" in the last graph. Not
> sure why that shows a 9.61 MB regression. I'll investigate, maybe we're
> double counting stuff or does about:memory detect that?

Looking at the 5 iterations before/after, most of them show a clear win if we look at js-main-runtime:

Before: 132.92, 121.13, 132.53, 134.42, 120.78
After:  118.74, 118.36, 118.03, 128.08, 130.39

AWSY shows us the 5th iteration (120.78 -> 130.39), but that's unfortunate here as it seems to be an outlier and the 4 other iterations show a win.

If we look at that 130.39 number, we see 12.72 MB for "gc-heap" with 10.48 MB unused-arenas and 1 MB unused-chunks. Some of the other iterations I looked at have 0 for unused-areneas - I wonder if this is because of a race somewhere where we're not deallocating them fast enough?

Comment 9

[Jan de Mooij [:jandem]]

See comment 8. Could a race explain the large values we (occasionally) see for unused-arenas? I think I've noticed this before and fixing it should make about:memory and AWSY less noisy.

Comment 10

[Andrew McCreight [:mccr8]]

(In reply to Jan de Mooij [:jandem] from comment #7)
> But I'm a bit worried about "JS: After TP5 [+30s]" in the last graph. Not
> sure why that shows a 9.61 MB regression. I'll investigate, maybe we're
> double counting stuff or does about:memory detect that?

DMD will detect double counting, but about:memory will not.

Comment 11

[Eric Rahm [:erahm]]

(In reply to Jan de Mooij [:jandem] from comment #9)
> See comment 8. Could a race explain the large values we (occasionally) see
> for unused-arenas? I think I've noticed this before and fixing it should
> make about:memory and AWSY less noisy.

Fixing this (or understanding it and updating AWSY to avoid it) would be great. As-is we have a pretty noisy pseudo-bi-modal distribution [1]. 9-10MiB drift seems within our current threshold and I agree that overall it looks like a win here.

[1] https://treeherder.mozilla.org/perf.html#/graphs?series=%5Bmozilla-inbound,0c9fbb47d39eaeca9628dafa82aecffb7659459b,1,4%5D

Comment 12

[Luke Wagner [:luke]]

Comment on attachment 8792597 [details] [diff] [review]
Patch

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

Forwarding to bholley, since he wrote the code and is actually a peer in this module :)

Comment 13

[Bobby Holley (:bholley)]

Comment on attachment 8792597 [details] [diff] [review]
Patch

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

I didn't write this code (just shuffled it around), but happy to rubberstamp given that smart people have measured this.

Comment 14

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/aad183efb09a
Don't use the lazySource option for JSMs, so we can benefit from syntax parsing. r=bholley

Comment 15

[Jon Coppeard (:jonco)]

(In reply to Jan de Mooij [:jandem] from comment #9)
The reported value itself is calculated by subtracting all the other measurements from the total.  The total comes from an atomic variable which is modified by both the main thread and the background sweep thread.  However GC would have to be active for there to be a possibility of getting this wrong and I assume we wait for GC to finish before measuring.

It might be because we skip decommitting unused arenas if we are in high-frequency GC mode.  It's possible that the last GC happened in this mode and so we didn't decommit and this left a lot of unused arenas committed.

Comment 16

[Emanuel Hoogeveen [:ehoogeveen]]

To make memory reporting more accurate, we already call a function [1] called jemalloc_purge_freed_pages() on OSX which simply protects and unprotects all chunks with madvise(MADV_FREE)d pages to force the OS to page them out. We should probably add something similar for the GC, but maybe we could also run the decommit phase before that on all OSes.

[1] https://dxr.mozilla.org/mozilla-central/source/xpcom/base/nsMemoryReporterManager.cpp#445
[2] https://dxr.mozilla.org/mozilla-central/source/memory/mozjemalloc/jemalloc.c#6735

Comment 17

[Emanuel Hoogeveen [:ehoogeveen]]

Er, I meant to link [2] after the description of the implementation.

Comment 18

[Jan de Mooij [:jandem]]

Unfortunately, this regressed the (desktop) installer size by a few MB (bug 1304719). The problem is that omni.ja is *smaller* now, but it's harder to compress (it contains more compressed source code instead of bytecode).

Talos also reports various regressions in ts_paint, tpaint, sessionrestore, etc.

I think I'll just back this out for now. Content processes don't use the startup cache, so maybe we could make this change only there. I'll do some measurements with that.

Comment 19

[Jan de Mooij [:jandem]]

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

Comment 20

[Jan de Mooij [:jandem]]

Attachment: Patch

Here's a patch to disable lazy source code *if the startup cache is disabled* (i.e. content processes).

This way it should not affect the parent process, the startup cache, and installer size, but we still avoid full parsing all modules in content processes.

Comment 21

[Bobby Holley (:bholley)]

Comment on attachment 8799741 [details] [diff] [review]
Patch

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

::: js/xpconnect/loader/mozJSComponentLoader.cpp
@@ +716,5 @@
>          LOG(("Slow loading %s\n", nativePath.get()));
>  
> +        // Use lazy source if both of these conditions hold:
> +        //
> +        // (1) mReuseLoaderGlobal is false. If mReuseLoaderGlobal is true, we

FWIW, we could rip mReuseLoaderGlobal out at this point, since b2g is gone.

Comment 22

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/9c89fbb659a8
Don't use lazy source code if the startup cache is not available (i.e. content processes). r=bholley

Comment 23

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

https://hg.mozilla.org/mozilla-central/rev/9c89fbb659a8

Comment 24

[Guilherme Lima]

Should this get marked as fixed?