Open Bug 1488435 Opened 6 years ago Updated 2 years ago

Significant key input delay when typing on large Google Docs

Categories

(Core :: JavaScript Engine, defect, P3)

Product:
Core
Component:
JavaScript Engine
Platform:
x86_64
macOS
Type:
defect

Tracking

()

Project Flags:
Performance Impact medium
Tracking Flags:
Tracking Status
firefox64 --- fix-optional
firefox65 --- fix-optional

People

(Reporter: Dominik, Unassigned)

References

(Depends on 2 open bugs, Blocks 1 open bug)

Details

Attachments

(2 files)

Content process event delays during typing
(deleted), image/png
Details
Content process event delay during reload of the page
(deleted), image/png
Details 
We experience a significant key input delay on both Nightly and Release for Google Docs. This issue is most prominent on large docs.

To reproduce:
Open a big Google Doc. Wait for it to be loaded completely.
Start typing. The problem is more pronounced within the first 60-180sec after loading and will get less severe, but still perceivable afterwards.

Here's a profile recorded to capture the issue on currently Nightly: https://perfht.ml/2NdbaCc
Just wanted to add that I was previously on the 2018-08-18 build of Nightly and it took 20-30s for the input delay to no longer be noticeable. However, on the latest nightly build 2018-09-04 it took around 45s.
Whiteboard: [qf]
Component: DOM → JavaScript Engine
Need some example Google Doc here.

And the performance profile shows this is all JS.
Flags: needinfo?(tcampbell)
(100's of ms of time to process key events, almost all spent in JS/ION/etc).  In some cases near 500ms.  It *seems* to be worse with the gecko profiler enabled -- and vchin indicates it regressed between 8/18 and now (though it wasn't wonderful then).  Note edge and chrome are both very snappy here.

This is a perf profile (with --enable-perf) of that.  lots of JS/ION stuff, lots of JS Helper action
Content Mainthread perf profile: https://perfht.ml/2Q5Iz0g    Random JS Helper (nearly 200ms): https://perfht.ml/2Q5uZtS   mostly in FlagAllOperandsAsHavingRemovedUses (it's compiling..)

This is a Gecko Profiler look at it: https://perfht.ml/2Q5YBHw  with 125-250ms keypress events and 500-1s+ event processing delays

Note that it *seems* that Gecko Profiler on makes it worse.  Not 100% confirmed.
Finding the regression range should be always the first step in regression bugs.
Depends on: 1488759
Depends on: 1375631
Flags: needinfo?(tcampbell)
Depends on: 1488768
Depends on: 1488775
I see a few InstanceOf on unboxed objects that cannot attach ICs. We are planning to remove the unboxed object mechanism though.
Depends on: 1488780
(In reply to Olli Pettay [:smaug] from comment #5)
> Finding the regression range should be always the first step in regression
> bugs.

I tried to roll back to a previous build of Nightly and can't reproduce the good behavior anymore. So it may not be a recent regression after all.
I suspect this is a code or build change on their end.
Depends on: 1488786
(In reply to Ted Campbell [:tcampbell] from comment #8)
> I suspect this is a code or build change on their end.

If we have specific questions about this, we can ask Steve Saviano (he's responsive here on Bugzilla).
Whiteboard: [qf] → [qf:p1]
Whiteboard: [qf:p1] → [qf:p1:64]
Whiteboard: [qf:p1:64] → [qf:p1:f64]
(In reply to Ted Campbell [:tcampbell] from comment #8)
> I suspect this is a code or build change on their end.

Steve, are you aware of any changes leading to this input delay? We notice input delays on Chrome as well.
Flags: needinfo?(ssaviano)
Hmm, could be one larger item. Will investigate on Docs-side and report back.
I noticed some long GC slices marking weak references when profiling this, so making bug 1167452 a dependency.
Depends on: 1167452
Is there a sample doc that could be shared? (view only is fine and I can make a copy)
Flags: needinfo?(ssaviano)
External doc with nothing sensitive(first few pages repeated about 50 times - ~147 pages):
https://docs.google.com/document/d/1CBF65WS71QOC4XiUH-KT2ZGDTp5ieSMSqC-d1NfoFCw/edit#
CCing Bruce Dawson because it's possible he'd be interested (though this isn't Windows-specific)
Depends on: 1490798
Thanks Randell for sharing the doc! Agree this feels slow (not just in Firefox btw). We're investigating on our end to see what we can improve.
Whiteboard: [qf:p1:f64] → [qf:p1:f67]
I'm pretty sure this is a dup of bug 1478104.  The patch there fixes the issue for (DRASTICALLY improves the experience).  I don't want to close as dup unilaterally though.
To clarify my comment: bug 1478104 identifies the same issue on the same doc, and the patch fixes the issue.
We have a doc in this bug that's visible to externals, so we should use that as our "example" case to point to if we dup (and move over the dependent bugs we attached to this one). Or perhaps better, rename the other one about JIT tuning, and make it one of the dependencies of this bug.  It doesn't matter much so long as we don't lose track of any of the ideas/bugs here.

I did a quick measurement of this with the patch from bug 1478104.  keypress events that were 125-250+ms (and some near 500ms) are now ~50-90ms (most 55-65 or 70), which is a 2-3x improvement.  We're still maybe 50% slower than Chrome, but we had been 150-400% slower.
Priority: -- → P1
Whiteboard: [qf:p1:f67] → [qf:p1]
Whiteboard: [qf:p1] → [qf:p2]

Using these steps:

  • enable profiler
  • click the link in comment 14
  • click in the table on the first page
  • type for 20 seconds or so
  • capture profile
  • in perf.html, click on the "Web Content" process (only one has significant activity during the profile).

On my machine, we're idle 32% of the time; and 27% of total time is spent under js::jit::IonGetPropertyIC::update (doing actual property lookups), and more than half of that (18% of the total) is on a single stack. This made me wonder if it might be actionable as a JS JIT bug, but:

<djvj> jorendorff: P3. Not pageload, and it only shows up on huge docs. Also, doing further perf improvements on it probably requires a rethink of how we structure objects and sparse arrays.

Leaving P1 for now because it's hard to buy that this is really P3, even if the JS engine side of things is too hard to tackle. There's still the 32% idle time.

Depends on: 1494537

Jason - one thing to look at is how many of the new IC updates are happening due to post-GC re-generation of ICs.

Priority: P1 → P3

@mkaply, maybe this is something that should block one of the enterprise-tracking bugs, since it seems like it could be a deal-breaker for some enterprises?

Flags: needinfo?(mozilla)

Good call. I'm surprised this is still something we haven't fixed.

Blocks: fx-enterprise
Flags: needinfo?(mozilla)

Updated profile (taken with eventDelay data):
https://perfht.ml/2NIS8D5

reload of the page: https://perfht.ml/36Zwims

Mass-removing myself from cc; search for 12b9dfe4-ece3-40dc-8d23-60e179f64ac1 or any reasonable part thereof, to mass-delete these notifications (and sorry!)

This may be a bit better now with Warp. GDocs had a lot of IonBuilder time on the main thread and Warp should have less of that + it runs off-thread.

Just to provide a data point about how chrome is better than us.

Firefox: https://share.firefox.dev/2T5BrH7
Chrome: https://share.firefox.dev/3vagyIR

Input event handlers on this gDoc will execute an a function, it generally took about 80 - 110ms in Firefox, and about 30 - 70ms in Chrome.

This profile is all property lookup. We're spending 20%+ of our time in NativeGetProperty and NativeGetPropertyNoGC. It will be interesting to see if these numbers change once Jan's reshape work lands.

Depends on: ReShape

Worthwhile to reprofile again now that bug 1704430 has been resolved fixed?

It's still pretty bad. https://share.firefox.dev/3t3d3WI

In Firefox, each key event handler takes around 35ms on my fast machine. In Chrome, each key event only takes 16ms.

Now we're spending 10-15% of our time in NativeGetProperty and NativeGetPropertyNoGC, and a similar amount of time in PropMapTable::lookupRaw. The total percentage of time spent looking up properties seems comparable to before, to the extent that it's possible to compare two profiles taken months apart on different machines.

Jan's work on Watchtower might help?

Performance Impact: --- → P2
Whiteboard: [qf:p2]
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: