1503961 - 100ms of bytecode encoding during pageload on eventbrite.ca

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect, P1)

Description

[Markus Stange [:mstange]]

I experienced this while loading https://www.eventbrite.ca/e/starcon-2019-tickets-51364393283 but can't reproduce it.

Profile: https://perfht.ml/2PBWv4w

This profile shows us spending 100ms inside ScriptLoader::EncodeBytecode, mostly in clearing and copying memory.

Comment 1

[Jean Gong :jgong]

Steven, from the QF triage, please follow-up with the JS team. Thanks!

Comment 2

[Steven DeTar [:sdetar]]

Kannan, can you help QF Triage this bug

Comment 3

[Nicolas B. Pierron [:nbp]]

The use case never appeared before, if needed this work might be moved to an off-thread task.
The only thing I do not know about is how to handle the 30ms of AltDataOutputStreamChild::Write.

I will also note that this is supposed to be a one time event per page. Thus if this issue keeps happenning then we should focus more on why this issue keeps happening than why do we spend time encoding.

Comment 4

[Kannan Vijayan [:djvj]]

It seems like the time sink here is at least a large number of copies due to doublings as the a vector is filled up and needs to be enlarged repeatedly.

Looking at XDRIncrementalLoader::linearize here: https://searchfox.org/mozilla-central/source/js/src/vm/Xdr.cpp#367

I notice that the `buffer.append` call at https://searchfox.org/mozilla-central/source/js/src/vm/Xdr.cpp#416 appends each slice independently.

We should be able to cut down drastically on the reallocations by ensuring the appropriate capacity is available in the Vector prior - by summing up the size of the copied in to be added prior to actually copying it.

Comment 5

[Nathan Froyd [:froydnj]]

Attachment: part 1 - factor out a slice iterator for XDRIncrementalEncoder

We're going to do two passes over the tree, so we might as well have
some common code to do the iteration.

Comment 6

[Nathan Froyd [:froydnj]]

Attachment: part 2 - do a single allocation for the linearized buffer

This change should eliminate the repeated copying we see on some testcases.

I think the profile in comment 0 also suggests that we are doing too much
allocation in ScriptLoader::EncodeBytecode, or something downstream of it.
This patch doesn't solve that, AFAIK.

I'm not sure whether the accumulation into `totalLength` can legimately be
unchecked, or whether `totalLength` should be a `CheckedInt<size_t>`.  Comments
from somebody who knows XDR better than me welcome!

Comment 7

[Nicolas B. Pierron [:nbp]]

Comment on attachment 9024245 [details] [diff] [review]
part 1 - factor out a slice iterator for XDRIncrementalEncoder

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

::: js/src/vm/Xdr.h
@@ +604,5 @@
>      SlicesTree tree_;
>      JS::TranscodeBuffer slices_;
>      bool oom_;
>  
> +    class DepthFirstSliceIterator {

nit: This iterator is only used and should only be used within Xdr.cpp, just keep a predeclaration and move this iterator definition to Xdr.cpp.

Comment 8

[Nicolas B. Pierron [:nbp]]

Comment on attachment 9024246 [details] [diff] [review]
part 2 - do a single allocation for the linearized buffer

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

Thanks for working on this issue.

Another idea, would be to use the size of the temporary TranscodeBuffer and use it as an over approximation, or maybe even subtract from it the size of the overridden content:
  https://searchfox.org/mozilla-central/source/js/src/vm/Xdr.cpp#320-321

Comment 9

[Nicolas B. Pierron [:nbp]]

(In reply to Nathan Froyd [:froydnj] from comment #6)
> I'm not sure whether the accumulation into `totalLength` can legimately be
> unchecked, or whether `totalLength` should be a `CheckedInt<size_t>`. 
> Comments
> from somebody who knows XDR better than me welcome!

It can because for 2 reasons:
 - A node is not supposed to be visited more than once in a depth-first visit.
 - Any of the data which is being copied is a subset of the slices_ buffer.
 - Any failure from the encoding act as a kill-switch[1] before calling the linearize function.

Therefore, the totalLength must be less or equal to slices_.length().

[1] https://searchfox.org/mozilla-central/source/js/src/vm/JSScript.cpp#2231,2235

Comment 10

[Nicolas B. Pierron [:nbp]]

(In reply to Nicolas B. Pierron [:nbp] from comment #3)
> I will also note that this is supposed to be a one time event per page. Thus
> if this issue keeps happenning then we should focus more on why this issue
> keeps happening than why do we spend time encoding.

Markus, is this a one time event, or you keep seeing it after multiple reload?

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/9718b942ff55
part 1 - factor out a slice iterator for XDRIncrementalEncoder; r=nbp
https://hg.mozilla.org/integration/mozilla-inbound/rev/f949c4870f02
part 2 - do a single allocation for the linearized buffer; r=nbp

Comment 12

[Markus Stange [:mstange]]

(In reply to Nicolas B. Pierron [:nbp] from comment #10)
> (In reply to Nicolas B. Pierron [:nbp] from comment #3)
> > I will also note that this is supposed to be a one time event per page. Thus
> > if this issue keeps happenning then we should focus more on why this issue
> > keeps happening than why do we spend time encoding.
> 
> Markus, is this a one time event, or you keep seeing it after multiple
> reload?

I've only seen it once. It didn't happen on subsequent page reloads. I haven't tried with a fresh profile.

Comment 13

[Razvan Maries]

https://hg.mozilla.org/mozilla-central/rev/9718b942ff55
https://hg.mozilla.org/mozilla-central/rev/f949c4870f02