1490917 - Gmail tab hangs when trying to forward and edit a long Ticketmaster email

Status: NEW

(Core :: JavaScript Engine, defect)

Description

[Chris Peterson [:cpeterson]]

When trying to forward and edit a particular Ticketmaster newsletter email in Gmail, the Gmail tab is unresponsive and hangs for multiple seconds between key press. I can forward the email to anyone that would like to reproduce the hang.

STR:
1. Open the Ticketmaster newsletter email.
2. Click Gmail's Forward button.
3. Try to enter some text in the email edit box of the forwarded email.

RESULT:
The Gmail tab is unresponsive and hangs for multiple seconds between key press. I have tested Firefox 63 Beta, 64 Nightly, and Chrome on Windows 10.

To be fair, Gmail in Chrome is also very slow when trying to forward and edit the same email, but maybe there is something Firefox can improve.

Here is a Gecko profile:

https://perfht.ml/2N5LdVX

Comment 1

[Mike Conley (:mconley) (:⚙️)]

Looking at the profile, we're spending a bunch of time doing regular expression work - "replace"... we're also GC'ing a bunch - weaving in and out of regex code.

Comment 2

[Daniel Holbert [:dholbert]]

Yeah -- drilling down into the profile, I see a lot of time in RegExpGlobalReplaceOpt (~3900ms), but that mostly seems to be GC if I drill down further, e.g. these functions:

js::gc::GCRuntime::gcIfRequested
js::gcstats::Statistics::endPhase

Comment 3

[Mike Conley (:mconley) (:⚙️)]

Hey cpeterson, when you get a chance, do you think you could forward me this email?

Comment 4

[Mike Conley (:mconley) (:⚙️)]

Do you think this is a dupe of bug 1428972, djvj? The GC'ing suggests it might be different, but I think we need someone from the JS team to weigh in on this one. :)

Comment 5

[Chris Peterson [:cpeterson]]

(In reply to Mike Conley (:mconley) (:⚙️) from comment #3)
> Hey cpeterson, when you get a chance, do you think you could forward me this
> email?

Sure. I forwarded the email to you. Ironically, this bug's STR involves forwarding this very email, so I was able to reproduce the problem again. :)

Comment 6

[Kannan Vijayan [:djvj]]

Doesn't seem like a dup of bug 1428972 to me.  >300ms major GCs more than once a second.  You made the right call, this is not regex related.  Steve, can you make sense of why we are hitting major GCs so often here?  Is it just a ton of allocs or are we hitting a pathological case here where we end up triggering major GCs unnecessarily?

Or would jonco/pbone be a better ni? target for this?

Comment 7

[Steve Fink [:sfink] [:s:]]

The longest portion of those pauses is wait_background_thread, which means it may be worthwhile to look at what those threads are doing. But right now, it looks to me like a ton of (individual) allocations -- when you press a key, it exhausts the nursery over and over (the collections are fast, but numerous). Then the incremental GC kicks in. It continues to fill up the nursery repeatedly. Finally, marking finishes, it waits for the background thread, then finishes up in one slice. At that point, it is able to read another key, and the cycle repeats.

We're allocating a ton of *something* for every keypress.

Hm... it might be interesting to capture an about:memory from when it's in the middle of this. The string info in there might be illuminating.

Can I also get a copy of this email?

Comment 8

[Steve Fink [:sfink] [:s:]]

jonco, pbone -- CC'ing because it's an interesting GC case. Even if, or especially, this boils down to the JS doing a ridiculous amount of allocating. Also, this is a case where having some sort of basic count of tenured and/or collected objects would be handy. (AllocKind? clasp->name for objects?)

Hm... when we have counters, it might also be a good idea to track the number of string copies we do because of crossing compartment boundaries. (I wonder if we get degenerate cases where we ping-pong between two compartments, producing many copies of the same string?)

Comment 9

[Chris Peterson [:cpeterson]]

(In reply to Steve Fink [:sfink] [:s:] from comment #7)
> Can I also get a copy of this email?

I sent a copy to you, jonco, and pbone.

Comment 10

[Kannan Vijayan [:djvj]]

This might well be the same issue (or at least contributed to by) as the one in bug 1478104.

Chris, can you repro this behaviour?  If so, can you test with the patch in that bug?

Comment 11

[Mayank Bansal]

see also : bug 1465227 , and its dependencies . Those should also be tested with the patch

Comment 12

[Chris Peterson [:cpeterson]]

(In reply to Kannan Vijayan [:djvj] from comment #10)
> This might well be the same issue (or at least contributed to by) as the one
> in bug 1478104.
> 
> Chris, can you repro this behaviour?  If so, can you test with the patch in
> that bug?

I tried editing the email after applying adjust-inlining-tunings.patch from bug 1478104. It feels like a slight improvement, but it was not a silver bullet.

For comparison, I then tested with javascript.options.ion = false. It was only slightly slower than Ion with the default settings.

Comment 13

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

The profile looks quite different to bug 1478104. regexp is taking crazy lots of time here and so is GC, bug 1478104 is about property lookups (and falling of ion).

Comment 14

[Paul Bone [:pbone]]

(In reply to Steve Fink [:sfink] [:s:] from comment #8)
> jonco, pbone -- CC'ing because it's an interesting GC case. Even if, or
> especially, this boils down to the JS doing a ridiculous amount of
> allocating. Also, this is a case where having some sort of basic count of
> tenured and/or collected objects would be handy. (AllocKind? clasp->name for
> objects?)

We kind-of do have counters, not per AllocKind though.

Looking at this profile I see roughly 2 out of every 50 allocations is a nursery allocation.  And it only takes about 2 allocations before the 1MB nursery is full.

 1. Huge things are being allocated in the nursery
 2. Most allocations are going to the tenured heap (probably not what we want, but don't know yet).

Also, what's with the high numbers of page faults in some of the GC slices.  about:memory really will be interesting.

Comment 15

[Paul Bone [:pbone]]

I've been looking at this today.  It is weird that there are only a few objects being allocated in the nursery between collections.  Nothing's really adding up at this stage, so it's hard to say what I've narrowed it down to.  I'll look again after dinner.

Comment 16

[Paul Bone [:pbone]]

(In reply to Paul Bone [:pbone] from comment #14)
> We kind-of do have counters, not per AllocKind though.

Our counters are broken (Bug 1494278) and what I wrote about is completely incorrect.

> Looking at this profile I see roughly 2 out of every 50 allocations is a
> nursery allocation.  And it only takes about 2 allocations before the 1MB
> nursery is full.

Actually there are thousands of allocations.  The majority seem to be from:

js::CreateRegExpMatchResult, when it calls NewDenseFullyAllocatedArrayWithTemplate

Or from:

js::jit::CreateMatchResultFallbackFunc

These are called from JITed code.

That there are thousands of these allocations, (mostly 80bytes each, and they fill up the nursery again and again) makes me think something in the JITed code is looping...

...so I can reproduce the same behaviour in chrome.  There's just a stupid slow loop in some of the gmail javascript.

Chris, can you reproduce this in gmail also?

Comment 17

[Chris Peterson [:cpeterson]]

(In reply to Paul Bone [:pbone] from comment #16)
> Chris, can you reproduce this in gmail also?

I'm not sure what you mean. My STR in comment 0 uses Gmail.

I can reproduce the problem in Firefox, Chrome, and Edge using Gmail. Firefox performance is the worst; Edge is the least worst.

Comment 18

[Paul Bone [:pbone]]

(In reply to Chris Peterson [:cpeterson] from comment #17)
> (In reply to Paul Bone [:pbone] from comment #16)
> > Chris, can you reproduce this in gmail also?
> 
> I'm not sure what you mean. My STR in comment 0 uses Gmail.
> 
> I can reproduce the problem in Firefox, Chrome, and Edge using Gmail.
> Firefox performance is the worst; Edge is the least worst.

I'm sorry, I meant to say Chrome.

As far as I can tell, there's nothing all that wrong with Firefox here.  But I'd like to let QF triage decide.

If there is anything we can do from a GC perspective it might be to see what's happening with the malloc counter that triggers the major collection.

Bug 1433007 will also improve this case, it'll make minor GCs more frequent but they and the mutator will run much faster by threshing the cache less.

Comment 19

[Daniel Holbert [:dholbert]]

Cool, let's match the qf priority from Bug 1433007 then. (And maybe this will just end up being fixed/improved-by that bug.)

Comment 20

[André Bargull [:anba]]

(In reply to Paul Bone [:pbone] from comment #16)
> Actually there are thousands of allocations.  The majority seem to be from:
> 
> js::CreateRegExpMatchResult, when it calls
> NewDenseFullyAllocatedArrayWithTemplate
> 

Theoretically it should be possible to reuse the result array in RegExpGlobalReplaceOpt, because it's never exposed to user code. Implementing that will just be a bit messy, because it probably involves, more or less, creating a copy of MRegExpMatcher and its recovery, lowering, and codegen code.

In addition to that, the capturing group string allocations could be elided in RegExpGlobalReplaceOpt, because they're never used. But I'm not sure if that's an issue for the performance problem in this bug.