1369140 - Speedometer Inferno-DeletingItems test spends a lot of time under HTMLElementBinding::focus

Status: RESOLVED FIXED

(Core :: DOM: Core & HTML, defect)

Description

[Jan de Mooij [:jandem]]

STR:

- Open http://speedometer2.benj.me/InteractiveRunner.html?suite=Inferno-TodoMVC
- Click Run
- Look at "DeletingItems : Sync" and notice that it's much slower than the Adding100Items and CompletingAllItems parts.

It turns out that the DeletingItems test spends most of its time doing reflows under the focus() call in componentDidUpdate.

This is also relatively slow in Chrome and Safari but it would be nice if we could optimize this somehow.

Comment 1

[Jan de Mooij [:jandem]]

smaug, any thoughts? I remember you fixed some other focus() issues recently...

Comment 2

[Boris Zbarsky [:bzbarsky]]

Profile at https://perf-html.io/from-addon/calltree/?implementation=cpp&search=focus&thread=3 for what it's worth.

Looks like nsFocusManager::CheckIfFocusable has a FlushType:::Layout flush, with a "ensure frames are up to date" comment.  It used to be a FlushType::Frames flush until bug 612018.

I did look at what's being focused in this case, and it's a bunch of text inputs, one after another.  The relevant call is http://speedometer2.benj.me/resources/todomvc/architecture-examples/inferno/dist/bundle.js line 3237:

            return _this3.editor.focus();

Unfortunately, I expect that focusing a text input does in fact mess with the caret...

That said, I tried backing out the fix for bug 612018 and then trying the testcase from that bug.  I do not get an assert, and the testcase blinks fine.  Maybe something else is flushing layout somewhere.  Maybe we now do not need up-to-date layout for whatever we're doing in that bug.  Ehsan, any thoughts?

Comment 3

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

(In reply to Jan de Mooij [:jandem] from comment #1)
> smaug, any thoughts? I remember you fixed some other focus() issues
> recently...

I fixed the case when we're focusing the already focused element.

I did look at this last week, and here we have elements which don't yet have primary frame, so some flush is needed. Also, I wonder how scrolling should happen. That could happen probably async if needed.

Comment 4

[(no longer active)]

(In reply to Boris Zbarsky [:bz] (if a patch has no decent message, automatic r-) from comment #2)
> Profile at
> https://perf-html.io/from-addon/calltree/
> ?implementation=cpp&search=focus&thread=3 for what it's worth.

You forgot to upload your profile (not that it matters, I've seen this in my own profiles too).

> Looks like nsFocusManager::CheckIfFocusable has a FlushType:::Layout flush,
> with a "ensure frames are up to date" comment.  It used to be a
> FlushType::Frames flush until bug 612018.
> 
> I did look at what's being focused in this case, and it's a bunch of text
> inputs, one after another.  The relevant call is
> http://speedometer2.benj.me/resources/todomvc/architecture-examples/inferno/
> dist/bundle.js line 3237:
> 
>             return _this3.editor.focus();
> 
> Unfortunately, I expect that focusing a text input does in fact mess with
> the caret...

One thing to note is that I rewrote large parts of our caret code after that, and that was 7 years ago, so it's very likely a layout flush isn't needed any more here for the sake of the caret.

> That said, I tried backing out the fix for bug 612018 and then trying the
> testcase from that bug.  I do not get an assert, and the testcase blinks
> fine.  Maybe something else is flushing layout somewhere.  Maybe we now do
> not need up-to-date layout for whatever we're doing in that bug.  Ehsan, any
> thoughts?

I really can't think of why we'd need to flush the layout for the purposes of the caret these days.  These days the caret painting is properly hooked up to the late stages of the refresh cycle when we actually want to paint, if the caret area has been invalidated (i.e., the caret is blinking) and a reflow has been performed at that time, so the caret dimension will be up to date at that time.  I don't remember all of the details about how our code worked before but one crucial difference was that caret drawing could happen from JS (see the assertion stack from that bug in attachment 490422 [details] for example) which I think is no longer possible.

I really think we should try to see if we can go back to flushing frames here...

Comment 5

[(no longer active)]

Let's see what happens: https://treeherder.mozilla.org/#/jobs?repo=try&revision=6cae29338a24f413772804da371330a2c20d5308

Comment 6

[(no longer active)]

I'm calling this qf:p1 because of the impact on the inferno benchmark.  This is what I get on my machine:

Before:

Inferno-TodoMVC : Adding100Items : Sync: 104.84999999999854 ms
Inferno-TodoMVC : Adding100Items : Async: 14.75 ms
Inferno-TodoMVC : CompletingAllItems : Sync: 146.65499999999884 ms
Inferno-TodoMVC : CompletingAllItems : Async: 6.059999999997672 ms
Inferno-TodoMVC : DeletingItems : Sync: 831.9349999999977 ms
Inferno-TodoMVC : DeletingItems : Async: 17.489999999997963 ms
Inferno-TodoMVC : 1121.7399999999907 ms
Total : 1121.7399999999907 ms

Inferno-TodoMVC : Adding100Items : Sync: 95.60499999999593 ms
Inferno-TodoMVC : Adding100Items : Async: 15.724999999998545 ms
Inferno-TodoMVC : CompletingAllItems : Sync: 154.6550000000061 ms
Inferno-TodoMVC : CompletingAllItems : Async: 7.594999999993888 ms
Inferno-TodoMVC : DeletingItems : Sync: 842.1500000000015 ms
Inferno-TodoMVC : DeletingItems : Async: 10.42500000000291 ms
Inferno-TodoMVC : 1126.1549999999988 ms
Total : 1126.1549999999988 ms

Inferno-TodoMVC : Adding100Items : Sync: 96.66500000000087 ms
Inferno-TodoMVC : Adding100Items : Async: 14.784999999996217 ms
Inferno-TodoMVC : CompletingAllItems : Sync: 162.02000000000407 ms
Inferno-TodoMVC : CompletingAllItems : Async: 5.2149999999965075 ms
Inferno-TodoMVC : DeletingItems : Sync: 850.5699999999997 ms
Inferno-TodoMVC : DeletingItems : Async: 6.165000000000873 ms
Inferno-TodoMVC : 1135.4199999999983 ms
Total : 1135.4199999999983 ms

After:

Inferno-TodoMVC : Adding100Items : Sync: 100.56000000000131 ms
Inferno-TodoMVC : Adding100Items : Async: 26.44499999999971 ms
Inferno-TodoMVC : CompletingAllItems : Sync: 145.84499999999753 ms
Inferno-TodoMVC : CompletingAllItems : Async: 9.135000000002037 ms
Inferno-TodoMVC : DeletingItems : Sync: 312.1749999999993 ms
Inferno-TodoMVC : DeletingItems : Async: 5.805000000000291 ms
Inferno-TodoMVC : 599.9650000000001 ms
Total : 599.9650000000001 ms

Inferno-TodoMVC : Adding100Items : Sync: 97.80500000000029 ms
Inferno-TodoMVC : Adding100Items : Async: 15.774999999997817 ms
Inferno-TodoMVC : CompletingAllItems : Sync: 130.02999999999884 ms
Inferno-TodoMVC : CompletingAllItems : Async: 8.099999999998545 ms
Inferno-TodoMVC : DeletingItems : Sync: 305.72499999999854 ms
Inferno-TodoMVC : DeletingItems : Async: 8.805000000000291 ms
Inferno-TodoMVC : 566.2399999999943 ms
Total : 566.2399999999943 ms

Inferno-TodoMVC : Adding100Items : Sync: 93.81999999999971 ms
Inferno-TodoMVC : Adding100Items : Async: 12.375 ms
Inferno-TodoMVC : CompletingAllItems : Sync: 141.5649999999987 ms
Inferno-TodoMVC : CompletingAllItems : Async: 7.299999999999272 ms
Inferno-TodoMVC : DeletingItems : Sync: 311.2000000000007 ms
Inferno-TodoMVC : DeletingItems : Async: 7.989999999997963 ms
Inferno-TodoMVC : 574.2499999999964 ms
Total : 574.2499999999964 ms

Comment 7

[(no longer active)]

Attachment: Part 1: Revert to only flushing styles when checking whether an element is focusable

Bug 612018 made us flush layout for caret painting which isn't triggered
from anything that can call this code any mode, therefore we can revert
the change from that bug.

Comment 8

[(no longer active)]

Attachment: Part 2: Test that tab closing no longer incurs a reflow

Comment 9

[(no longer active)]

Boris, I know you have said no reviews, but do you mind making an exception for part 1 here please?

Comment 10

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 8873276 [details] [diff] [review]
Part 1: Revert to only flushing styles when checking whether an element is focusable

r=me

Comment 11

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 8873277 [details] [diff] [review]
Part 2: Test that tab closing no longer incurs a reflow

This is awesome, by the way!

Comment 12

[(no longer active)]

(In reply to Boris Zbarsky [:bz] (if a patch has no decent message, automatic r-) from comment #11)
> Comment on attachment 8873277 [details] [diff] [review]
> Part 2: Test that tab closing no longer incurs a reflow
> 
> This is awesome, by the way!

Not as awesome as it looks.  For browser.xul, the restyle part is usually the super expensive part in my experience not the reflow part anyway, so this may not save us that much in practice.  I'm hoping the front-end folks will keep measuring tab closing and see the impact of this and evaluate how much more cost is left.

Comment 13

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

Comment on attachment 8873277 [details] [diff] [review]
Part 2: Test that tab closing no longer incurs a reflow

Great! Glad to see these go.

Would you mind adding a comment inside the empty EXPECTED_REFLOWS array making it clear that we should not add anything new there?

I'm doing something similar in https://reviewboard.mozilla.org/r/144732/diff/1#index_header

Comment 14

[(no longer active)]

(In reply to Mike Conley (:mconley) from comment #13)
> Comment on attachment 8873277 [details] [diff] [review]
> Part 2: Test that tab closing no longer incurs a reflow
> 
> Great! Glad to see these go.
> 
> Would you mind adding a comment inside the empty EXPECTED_REFLOWS array
> making it clear that we should not add anything new there?
> 
> I'm doing something similar in
> https://reviewboard.mozilla.org/r/144732/diff/1#index_header

I'll copy your wording.  :-)

Comment 15

[Jan de Mooij [:jandem]]

Thanks for jumping on this, everyone. Great improvement! It will be interesting to see how this affects the various numbers on AWFY.

I'll do some more profiling of the other tests today.

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/d44994c67873
Part 1: Revert to only flushing styles when checking whether an element is focusable; r=bzbarsky
https://hg.mozilla.org/integration/mozilla-inbound/rev/87c1327b918d
Part 2: Test that tab closing no longer incurs a reflow; r=mconley

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/9c0c9ed34b07
Part 3: Test that tab opening no longer incurs a reflow in _adjustFocusAfterTabSwitch

Comment 18

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/127a68011864
Part 4: Test that window opening no longer incurs a reflow in focusAndSelectUrlBar

Comment 19

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/098b03dbc0c2
Part 5: Test that tab opening no longer incurs a reflow in focusAndSelectUrlBar

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3b2d0ff5f9a3
Part 6: Adjust the last few reflow tests to reflect reality. r=bustage-fix on a CLOSED TREE

Comment 21

[(no longer active)]

Not too bad: we're faster than Chrome now on this test.

https://arewefastyet.com/#machine=17&view=single&suite=speedometer-misc&subtest=Inferno-TodoMVC-DeletingItems-sync

Comment 22

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/d44994c67873
https://hg.mozilla.org/mozilla-central/rev/87c1327b918d
https://hg.mozilla.org/mozilla-central/rev/9c0c9ed34b07
https://hg.mozilla.org/mozilla-central/rev/127a68011864
https://hg.mozilla.org/mozilla-central/rev/098b03dbc0c2
https://hg.mozilla.org/mozilla-central/rev/3b2d0ff5f9a3

Comment 23

[Ionuț Goldan [:igoldan]]

== Change summary for alert #6996 (as of June 01 2017 13:20 UTC) ==

Improvements:

 63%  speedometer-misc 2.0 Inferno-TodoMVC-DeletingItems-sync linux64 opt      1,157.80 -> 426.96

For up to date results, see: https://treeherder.mozilla.org/perf.html#/alerts?id=6996

Comment 25

[huangwenjun06]

hi，I test on Linux Platform and build with nightly version, I Found withi this patch, the speedometer2.0 score increase, but could cause test case failed.

./mach marionette-test layout/base/tests/marionette/test_accessiblecaret_selection_mode.py.

Result:
 0:56.51 TEST_START: layout/base/tests/marionette/test_accessiblecaret_selection_mode.py AccessibleCaretSelectionModeTestCase.test_minimum_select_one_character2_content2
 0:57.55 TEST_END: FAIL, expected PASS
AssertionError: u'F' != u'First LineS'
- F
+ First LineS