1482798 - Moving cursor in CodeMirror JsTerm when output is tall causes slow Reflow

Status: RESOLVED FIXED

(DevTools :: Console, defect, P1)

Description

[Nicolas Chevobbe [:nchevobbe]]

**Steps to reproduce**
1. Open the console
2. Evaluate "\n".repeat(9000) 3 times
3. In the input, Hit Shift + Enter to enter new lines
4. Hit Arrow up to move the cursor one line up

**Expected results**

Everything is smooth as it can be

**Actual results**

Moving the cursor looks quite slow

---

Here's a profile I recorded with the STR: https://perfht.ml/2B625WY


The culprit is this code in codeMirror: 
```js
function kn(e){return e.lineSpace.offsetTop}
```

In the profile, we can see a 178ms reflow caused by offsetTop.

Here's another profile when the output contains only 3 one-line logs: https://perfht.ml/2B6cPEN . We can see that there's nothing too costly happening.

Also, if you : 
- clear the console
- evaluate `"\n".repeat(10000)` (this will create a longString)
- go to the top
- click on the arrow before the string
- scroll to the very bottom
- in the input, hit Shift + Enter to have multiple lines
- and hit ArrowUp to navigate the cursor one line up

you'll be able to see that this is not as costly as with the 9000 lines tall evaluation (https://perfht.ml/2B63Fbl).

Comment 1

[Brian Grinstead [:bgrins]]

Looks like it corresponds to this line in the CM source: https://github.com/codemirror/CodeMirror/blob/3eaa89bfdb980a22e903b0a697cbe41bf8bd446a/src/measurement/position_measurement.js#L17

Comment 2

[Nicolas Chevobbe [:nchevobbe]]

Brad, could you have a look at this profile: https://perfht.ml/2B625WY and see why the reflow takes so long ?
I tried to make sense of it but oculdn't really tell what's happening on platform side.

Comment 3

[Brad Werth [:bradwerth]]

Presuming that the reflow is unavoidable, the costly work is in two calls to nsHTMLScrollFrame::ReflowScrolledFrame which appear to be the same element, reflowed twice. I'll see if I can find a way to reduce this to one reflow, which will cut the reflow time in half.

Comment 4

[Brad Werth [:bradwerth]]

Of course, since the profile data is just a sample, it could just be that many similar elements are being reflowed and that makes it look like two large reflows of the same element. I'll learn what I can.

Comment 5

[Brad Werth [:bradwerth]]

In comment 3, I proposed that there was a nsScrolledFrame that is being reflowed twice and I've confirmed that is the case. I haven't yet figured out why it's getting reflowed the second time (other than that a parent is getting reflowed). Anyway, there's still some chance we can find a way to cut this time in half.

But why is it slow in the first place when the very similar longString case from commment 0 is not slow? New theory: the code that calls offsetTop also changes style on some element, and makes some change to a pseudoelement that adds a div into the DOM. That added div causes an expensive reflow. I can't make sense of the JS stack to figure out what restyle is being done.

Comment 6

[Brad Werth [:bradwerth]]

To be clear, the new theory in comment 5 is indicated by the call stacks where reflow is requested. The reflow comes from the addition of a div into the DOM, after some style changes are being processed.

Comment 7

[Nicolas Chevobbe [:nchevobbe]]

Attachment: Bug 1482798 - Use a flex layout for message body; r=bgrins.

It looks like we don't really need a grid layout anymore
for the message body AND it significantly reduces the time
spent on reflow.

Comment 8

[Nicolas Chevobbe [:nchevobbe]]

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #7)
> Created attachment 9002663 [details]
> Bug 1482798 - Use a flex layout for message body; r=bgrins.
> 
> It looks like we don't really need a grid layout anymore
> for the message body AND it significantly reduces the time
> spent on reflow.

This patch seems to improve reflow:

Without patch: https://perfht.ml/2N56U4l (~150ms)
With patch: https://perfht.ml/2N76paa (~80ms)

Comment 9

[Nicolas Chevobbe [:nchevobbe]]

The "Why codeMirror is calling offsetTop (but also scrollTop, getBoundingClientRect, …) causing this reflow" is because it checks if the editor should be scrolled in response to a key stroke. 

This may be something we try to fix in the codeMirror repo at some point.

Comment 10

[Brad Werth [:bradwerth]]

I'm still curious if there is any JS that is setting a style with with a ::before or ::after pseudoelement with content styling. That's one explanation that would explain why the styling is triggering a reflow as evidenced by the call stack. In the meanwhile, switching from grid to flex looks like it avoids the double reflow, which is great. I'll see if I can learn more from the JS stack and find the styling change.

Comment 11

[Brian Grinstead [:bgrins]]

Comment on attachment 9002663 [details]
Bug 1482798 - Use a flex layout for message body; r=bgrins.

Brian Grinstead [:bgrins] has approved the revision.

Comment 12

[Brian Grinstead [:bgrins]]

(In reply to Brad Werth [:bradwerth] from comment #10)
> I'm still curious if there is any JS that is setting a style with with a
> ::before or ::after pseudoelement with content styling. That's one
> explanation that would explain why the styling is triggering a reflow as
> evidenced by the call stack. In the meanwhile, switching from grid to flex
> looks like it avoids the double reflow, which is great. I'll see if I can
> learn more from the JS stack and find the styling change.

Thanks for looking into this! I'm also curious if there's any particular flexbox perf improvements to be had after this patch lands (it still seems like we should be able to be faster than 80ms for this layout). We've already filed a couple of bugs against the flexbox perf metabug related to the console (Bug 1408190 and Bug 1410464) - I'm assuming one of those will cover it, but we can file a new one if you think this is a distinct issue from than those.

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/038353b1a3c5
Use a flex layout for message body; r=bgrins.

Comment 14

[Nicolas Chevobbe [:nchevobbe]]

Should we add the leave-open bug here so we can land more fixes (if we can) here ?

Comment 15

[Brian Grinstead [:bgrins]]

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #14)
> Should we add the leave-open bug here so we can land more fixes (if we can)
> here ?

I'd say let's do any other fixes in separate bugs so it's easier to track across releases, talos results, etc.

Comment 16

[Brad Werth [:bradwerth]]

Okay, I'll open a new bug. There's definitely more work to do since the key events shouldn't be causing reflow at all (and don't in the alternate longString case noted in comment 0).

Comment 17

[Nicolas Chevobbe [:nchevobbe]]

Attachment: codemirror-de-uglyfy.patch

So here's a profile with saner JS stacktrace in codeMirror (you can apply the patch to have the same thing). This is on top of the grid to flex patch: https://perfht.ml/2wkogTC

You can see the "scrollPosIntoView" function leading to the offsetTop access (and thus reflow).
But this is not the only place a reflow is triggered, If I return a fixed value in `paddingTop` instead of calling offsetTop, then you hit other access to reflow-needed property (scrollTop) or function (getBoundingClientRect).

Comment 18

[Nicolas Chevobbe [:nchevobbe]]

(In reply to Brad Werth [:bradwerth] from comment #10)
> I'm still curious if there is any JS that is setting a style with with a
> ::before or ::after pseudoelement with content styling. That's one
> explanation that would explain why the styling is triggering a reflow as
> evidenced by the call stack. In the meanwhile, switching from grid to flex
> looks like it avoids the double reflow, which is great. I'll see if I can
> learn more from the JS stack and find the styling change.

Is this when only moving the cursor or when typing a letter ?
If it's when typing, it may be the "completionText" feature, where we use an ::after to display that.
The JS call is here https://searchfox.org/mozilla-central/rev/71ef4447db179639be9eff4471f32a95423962d7/devtools/client/sourceeditor/editor.js#1289-1303 and the CSS for it: https://searchfox.org/mozilla-central/rev/71ef4447db179639be9eff4471f32a95423962d7/devtools/client/themes/webconsole.css#351-354

Comment 19

[Brad Werth [:bradwerth]]

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #18)
> (In reply to Brad Werth [:bradwerth] from comment #10)
> > I'm still curious if there is any JS that is setting a style with with a
> > ::before or ::after pseudoelement with content styling. That's one
> > explanation that would explain why the styling is triggering a reflow as
> > evidenced by the call stack. In the meanwhile, switching from grid to flex
> > looks like it avoids the double reflow, which is great. I'll see if I can
> > learn more from the JS stack and find the styling change.
> 
> Is this when only moving the cursor or when typing a letter ?

For me, it's occurring from cursor movement AND typing of letters. With your de-uglified codemirror JS, I should be able to learn more.

Comment 20

[Nicolas Chevobbe [:nchevobbe]]

So, I was looking at the differences between the longString example and the regular one.
The longString is contained in an object-inspector node, which display is inline-block.
So I added a display:inline-block to the .objectBox.objectBox-string element like below: 

> <div class="cm-s-mozilla message javascript result log" aria-live="polite">
>   <span data-indent="0" class="indent" style="width: 0px;"></span>
>   <span class="icon" title="Log" aria-live="off"></span>
>   <span class="message-body-wrapper">
>     <span class="message-flex-body">
>       <span class="message-body devtools-monospace">
>         <span class="objectBox objectBox-string" style="display: inline-block;">""</span>
>       </span>
>       <span class="message-location devtools-monospace"></span>
>     </span>
>   </span>
>  </div>

And then, voila, no more costly reflows on keyboard move !
So, I'm not sure this is the thing to do right now (not sure what the impact on the UI is), but I hope this will help you Brad.

Comment 21

[Brad Werth [:bradwerth]]

Well done! That's a surprising result. I propose you add this fix to the other, and land this bug. I will open a new issue to investigate why the reflow is happening at all, and assign myself to that bug. Since I'm not contributing any patches to this bug, I'm taking myself off it.

Comment 22

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/mozilla-central/rev/038353b1a3c5

Comment 23

[Nicolas Chevobbe [:nchevobbe]]

So, the display: inline-block things only works for the case described in Comment 0 (i.e. 1 tall message).
Evaluating 
```js
for (i = 0; i < 200; i++) {
  console.log(i)
}
```

And then moving the cursor will still be slow.

Comment 24

[Nicolas Chevobbe [:nchevobbe]]

I tried to use `inputStyle: "contenteditable"` on the editor config, which make it use a contenteditable div. The idea was that since it's native, it doesn't need custom code to check if the ceontainer should be scrolled when moving the cursor.
And it works, no more reflow in the case of this specific bug (i.e. moving cursor).
_But_, they're still there when typing, which is the primary interaction in the input, so I'm not sure it's worth investigating on that side (it may causes some small issue we need to take care of).

Comment 25

[Brian Grinstead [:bgrins]]

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #24)
> I tried to use `inputStyle: "contenteditable"` on the editor config, which
> make it use a contenteditable div. The idea was that since it's native, it
> doesn't need custom code to check if the ceontainer should be scrolled when
> moving the cursor.
> And it works, no more reflow in the case of this specific bug (i.e. moving
> cursor).
> _But_, they're still there when typing, which is the primary interaction in
> the input, so I'm not sure it's worth investigating on that side (it may
> causes some small issue we need to take care of).

Yeah, sounds like it's not a fix for this particular issue. Although we have talked about switching to it for accessibility sake (at least for reading the contents of the input field). But I'd like to know if/how it relates to the in-development version of CM that is supposed to have better accessibility before we spend too much time testing it.

Comment 26

[Brad Werth [:bradwerth]]

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #24)
> I tried to use `inputStyle: "contenteditable"` on the editor config, which
> make it use a contenteditable div. The idea was that since it's native, it
> doesn't need custom code to check if the ceontainer should be scrolled when
> moving the cursor.
> And it works, no more reflow in the case of this specific bug (i.e. moving
> cursor).
> _But_, they're still there when typing, which is the primary interaction in
> the input, so I'm not sure it's worth investigating on that side (it may
> causes some small issue we need to take care of).

I think this bug should stay open until we have a general solution. Here are the sources of slowness:

1) Slowness in flex container unnecessary sibling reflows. Bug 1377253 is tracking this and I'm told we'll have a solution there soon. Alternatively, landing Bug 1150081 will provide a solution too.
2) If vertical scrollbars are shown when content overflows, it forces a second layout of this slow flex container (discussed in Bug 1486996). There's probably nothing we can do about that since the console output area should show a vertical scrollbar in this situation. I'll play around with the overflow property values and see if that can help.

Comment 27

[Brad Werth [:bradwerth]]

(In reply to Brad Werth [:bradwerth] from comment #26)
> 2) If vertical scrollbars are shown when content overflows, it forces a
> second layout of this slow flex container (discussed in Bug 1486996).
> There's probably nothing we can do about that since the console output area
> should show a vertical scrollbar in this situation. I'll play around with
> the overflow property values and see if that can help.

As expected, adding .webconsole-output { overflow-y: scroll; } cuts the reflow time in half, at the expense of always showing the scrollbar.

Comment 28

[Brian Grinstead [:bgrins]]

(In reply to Brad Werth [:bradwerth] from comment #27)
> (In reply to Brad Werth [:bradwerth] from comment #26)
> > 2) If vertical scrollbars are shown when content overflows, it forces a
> > second layout of this slow flex container (discussed in Bug 1486996).
> > There's probably nothing we can do about that since the console output area
> > should show a vertical scrollbar in this situation. I'll play around with
> > the overflow property values and see if that can help.
> 
> As expected, adding .webconsole-output { overflow-y: scroll; } cuts the
> reflow time in half, at the expense of always showing the scrollbar.

By the way, the patch in Bug 1487457 does some markup simplification and overflow changes to speed up reflow.

Comment 29

[Nicolas Chevobbe [:nchevobbe]]

This is definitely fixed by Bug 1490890. We'll watch typing performance with a damp test in the future (See Bug 1487359).