Closed Bug 1338894 Opened 5 years ago Closed 5 years ago

Optimize WrapperMap sweeping

Categories

(Core :: JavaScript Engine, defect)

defect
Not set
normal

Tracking

()

RESOLVED WONTFIX
mozilla54

People

(Reporter: jandem, Assigned: jandem)

References

(Blocks 1 open bug)

Details

(Whiteboard: [qf-])

Attachments

(1 file)

The wrapper map is a NurseryAwareHashMap, which uses a HashMap + a Vector of nursery keys. In sweepAfterMinorGC, we iterate over this Vector and lookup each entry in the map, and either remove or rekey it.

Profiles show a lot of our minor GC time on a Google Docs spreadsheet (bug 1338802) is spent in sweepAfterMinorGC. It also looks like many of these wrappers are short-lived and don't survive the nursery collection.

Instead of this HashMap + Vector scheme, I think it would be more efficient to use 2 HashMaps, one containing wrappers for nursery objects, and another one containing wrappers for tenured objects.

Then sweepAfterMinorGC can simply iterate over the nursery map and if the wrapper is still alive we insert it in the non-nursery map, but if the wrapper died (the common case hopefully) we don't have to do any lookups or removes. sweepAfterMinorGC can just clear the whole nursery map at the end.

In getOrCreateWrapper we will have to do an IsInsideNursery check to decide which hash map to use, but that's fast and I think it's worth it.
I'll try to prototype this tomorrow to see if it works and is actually faster.
Flags: needinfo?(jdemooij)
Great idea, I'm interested to see what difference this makes.
Attached patch PatchSplinter Review
This seems to work well. I added some logging and without the patch, when I open the spreadsheet and scroll down a bit, I consistently get a number of minor GCs where the compartment sweeping part takes more than 10 ms. With this patch applied the code always took less than 10 ms.

Below is a shell micro-benchmark that allocates a lot of wrappers and measures two cases: (1) Most wrappers/wrappees *don't* survive the nursery collection (2) Most wrappers/wrappees *do* survive the nursery collection.

I get the following results (best of 5 runs for each of them):

before: 87 ms / 114 ms
after:  70 ms / 107 ms

So especially when we have many short-lived wrappers the new code is faster, but there's also a small improvement when the wrappers are tenured.

I also measured the case where we return the same wrapper all the time and I don't see any performance difference, so the little overhead this adds to the lookup call is negligible.

var g = newGlobal();
function f(keepalive) {
    var arr = [];
    for (var i=0; i<100000; i++) {
        var x = new g.Array();
        if (keepalive)
            arr.push(x);
    }
}
var t = new Date;
f(false);
print(new Date - t);

var t = new Date;
f(true);
print(new Date - t);
Assignee: nobody → jdemooij
Status: NEW → ASSIGNED
Flags: needinfo?(jdemooij)
Attachment #8836697 - Flags: review?(jcoppeard)
Comment on attachment 8836697 [details] [diff] [review]
Patch

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

This looks really good.

::: js/src/jscompartment.h
@@ +589,5 @@
>  
> +    MOZ_MUST_USE bool putNewWrapper(JSContext* cx, const js::CrossCompartmentKey& wrapped,
> +                                    const js::Value& wrapper);
> +    MOZ_MUST_USE bool putWrapperMaybeUpdate(JSContext* cx, const js::CrossCompartmentKey& wrapped,
> +                                            const js::Value& wrapper);

Thanks for splitting these cases.
Attachment #8836697 - Flags: review?(jcoppeard) → review+
I ran your benchmark with JS_PROFILE_NURSERY on and you can see that it really improves things in the case where wrappers are not tenured.

Pre:
 
> Test start
> MinorGC:               Reason  PRate Size   total canIon mkVals mkClls mkSlts mcWCll mkGnrc ckTbls mkRntm mkDbgr clrNOC collct  tenCB swpABO updtIn frSlts  clrSB  sweep resize pretnr
> MinorGC:       OUT_OF_NURSERY   0.2%    1    1025      0      0      0      6      0      0      0     22      0      1      5      0    982      1      0      0      1      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     904      0      0      0      0      0      0      0      8      0      0      0      0    889      1      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     860      0      0      0      0      0      0      0      7      0      0      0      0    847      1      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     821      0      0      0      0      0      0      0      6      0      0      0      0    809      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     789      0      0      0      0      0      0      0      6      0      0      0      0    777      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     732      0      0      0      0      0      0      0      6      0      0      0      0    721      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     704      0      0      0      0      0      0      0      5      0      0      0      0    693      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     680      0      0      0      0      0      0      0      5      0      0      0      0    670      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     683      0      0      0      0      0      0      0      5      0      0      0      0    674      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     658      0      0      0      0      0      0      0      5      0      0      0      0    648      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     636      0      0      0      0      0      0      0      5      0      0      0      0    627      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     619      0      0      0      0      0      0      0      4      0      0      0      0    610      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     597      0      0      0      0      0      0      0      4      0      0      0      0    589      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     582      0      0      0      0      0      0      0      4      0      0      0      0    574      0      0      0      0      0      0
> 181
> MinorGC:       OUT_OF_NURSERY  49.9%    2    1188      0      0      0      0      0      0      0      6      0      0    645      0    527      0      0      0      0      4      0
> MinorGC:       OUT_OF_NURSERY 100.0%    4    3862      0      0      0      1   1057      0      0     10      0      0   1537      0   1242      1      0      0      0      7      0
> MinorGC:       OUT_OF_NURSERY 100.0%    8   10288      0      0      0      2   2004      0      0     12      0      0   3095      0   5137      2      0      0      0     27      0
> 145
> MinorGC:      DESTROY_RUNTIME 100.0%   16   20092      0      0      0      2   4350      0      0      5      0      1   6678      0   9009      0      0      0      1     37      0

Post:

> Test start
> MinorGC:               Reason  PRate Size   total canIon mkVals mkClls mkSlts mcWCll mkGnrc ckTbls mkRntm mkDbgr clrNOC collct  tenCB swpABO updtIn frSlts  clrSB  sweep resize pretnr
> MinorGC:       OUT_OF_NURSERY   0.2%    1     360      0      0      0      5      0      0      0     14      6      0      5      0    320      1      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     297      0      0      0      0      0      0      0      6      0      0      0      0    285      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     280      0      0      0      0      0      0      0      5      0      0      0      0    270      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     257      0      0      0      0      0      0      0      5      0      0      0      0    248      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     247      0      0      0      0      0      0      0      4      0      0      0      0    238      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     238      0      0      0      0      0      0      0      4      0      0      0      0    229      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     229      0      0      0      0      0      0      0      4      0      0      0      0    221      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     221      0      0      0      0      0      0      0      4      0      0      0      0    213      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     214      0      0      0      0      0      0      0      4      0      0      0      0    206      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     207      0      0      0      0      0      0      0      4      0      0      0      0    200      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     201      0      0      0      0      0      0      0      3      0      0      0      0    194      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     200      0      0      0      0      0      0      0      3      0      0      0      0    193      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     194      0      0      0      0      0      0      0      3      0      0      0      0    187      0      0      0      0      0      0
> MinorGC:       OUT_OF_NURSERY   0.0%    1     188      0      0      0      0      0      0      0      3      0      0      0      0    182      0      0      0      0      0      0
> 183
> MinorGC:       OUT_OF_NURSERY  49.9%    2    1131      0      0      0      0      0      0      0      5      0      0    634      0    479      1      0      0      0      5      0
> MinorGC:       OUT_OF_NURSERY 100.0%    4    4013      0      0      0      1    950      0      0      8      0      0   1515      0   1520      2      0      0      0      9      0
> MinorGC:       OUT_OF_NURSERY 100.0%    8    8993      0      0      0      2   1883      0      0     13      0      1   3120      0   3939      2      0      0      0     24      0
> 149
> MinorGC:      DESTROY_RUNTIME 100.0%   16   21992      0      0      0     10   3992      0      0      6      0      1   6615      0  11324      0      0      0      1     33      0
Nice, I didn't know about JS_PROFILE_NURSERY.

(I think the patch in bug 1338834 improves the micro-benchmark a lot. My results are with that patch applied, but it shouldn't make much of a difference as the improvement from that is the same in both cases.)
Pushed by jandemooij@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/76c26eaf4f18
Rewrite NurseryAwareHashMap to speed up WrapperMap sweeping. r=jonco
https://hg.mozilla.org/mozilla-central/rev/76c26eaf4f18
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla54
I backed this out to see if it's responsible for the GC_MINOR_US Telemetry regression.

Pretty weird because this patch should be a clear win.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Keywords: leave-open
The backout seems to have fixed the regression.

I'm wondering if the patch accidentally caused all CCWs to be tenured, but I can't see how that might happen.
(In reply to Jon Coppeard (:jonco) from comment #11)
> I'm wondering if the patch accidentally caused all CCWs to be tenured, but I
> can't see how that might happen.

In that case we wouldn't have seen improvements on all these (micro)benchmarks, I think. Maybe we have some slow realloc since we move tenured wrappers from one HashSet to the other now..
Whiteboard: [qf-]
I'll WONTFIX this. It's not clear what caused the Telemetry regression and hopefully Jason's work will eliminate this issue for the most part.
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → WONTFIX
Removing leave-open keyword from resolved bugs, per :sylvestre.
Keywords: leave-open
You need to log in before you can comment on or make changes to this bug.