Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

New layout slower? #77856

Closed
jrieken opened this issue Jul 24, 2019 · 15 comments
Closed

New layout slower? #77856

jrieken opened this issue Jul 24, 2019 · 15 comments
Assignees
Labels
bug Issue identified by VS Code Team member as probable bug layout General VS Code workbench layout issues perf verified Verification succeeded
Milestone

Comments

@jrieken
Copy link
Member

jrieken commented Jul 24, 2019

The perf machine showed a ~50ms drop after shipping the new workbench layout. This is something we need to understand and investigate

@joaomoreno
Copy link
Member

From @sbatten:

I investigated the perf of the new gridlayout. I can attribute at least 20ms difference, sometimes near measured 40ms, to the grid layout. There are several steps in the layout where its just 1ms or 2ms slower which can add a bit overall, this will be harder to shrink.

However, a large chunk of the slowdown is due the SerializableGrid.deserialize call. In this call, the grid adds and lays out views multiple times costing a lot of time. ~15ms difference in the analogous legacy version.

I tried an experiment where I deserialize the grid but make their layout functions noops until deserialization is complete and that alone cut 10ms off the time.

@joao do we need to call layout so much in deserialize?

@joaomoreno
Copy link
Member

From @jrieken:

Thanks for investigating!
Yeah, maybe something callback-based would help. The editor does that a lot, e.g. like changeViewZones taking a callback with does all modifications and once the callback is done the editor updates layout etc. Or something explicit, like startRestore matched by stopRestore

@joaomoreno joaomoreno self-assigned this Jul 25, 2019
@joaomoreno joaomoreno added this to the July 2019 milestone Jul 25, 2019
@joaomoreno joaomoreno added bug Issue identified by VS Code Team member as probable bug perf labels Jul 25, 2019
@joaomoreno
Copy link
Member

joaomoreno commented Jul 29, 2019

@sbatten

Upon investigating this, I noticed a SerializableGrid being constructed twice for the workbench... I found I'm always hitting this... which means the grid is never restored from serialization. You can't call getNeighborViews without ever calling layout, there's just no way that could work.

So:

  • I've made getNeighborViews throw if called before layout. c429b41
  • I've deleted that check code and I've changed the way how we can detect where views are in the grid. d0a5544

This was for sure responsible for most of the cost, since the grid would instantiate twice. Always.

I also like the idea of suspending layout calls until deserialization is complete, so I've also pushed this. For example, this reduced the status bar layout calls on startup from 15 to 5. 600c7db

@jrieken How can we get new numbers?

@jrieken
Copy link
Member Author

jrieken commented Jul 29, 2019

@jrieken How can we get new numbers?

You run and measure locally? For the perf bot: it runs twice a day (morning & afternoon) but only when there is new insiders available.

@joaomoreno
Copy link
Member

joaomoreno commented Jul 29, 2019

Yes I mean the perf bot, since the first post mentions an increase on that setup. Let's wait for tomorrow then.

@sbatten
Copy link
Member

sbatten commented Jul 29, 2019

@joaomoreno that code setting undefined was just checked in last night, so it may have been causing a new perf issue but I don't think it was the original issue.

@joaomoreno
Copy link
Member

@sbatten OK. Once I removed it I saw startup duration cut by almost half, so I assumed it was that. Let's wait for da numbas.

@sbatten sbatten added the layout General VS Code workbench layout issues label Jul 29, 2019
@jrieken
Copy link
Member Author

jrieken commented Jul 30, 2019

Perf machine reports ~1780ms which is roughly at the level of the first regression, confirming what @sbatten said here: #77856 (comment)

@joaomoreno joaomoreno modified the milestones: July 2019, August 2019 Jul 31, 2019
@joaomoreno
Copy link
Member

Moving to August since it's not impacting endgame.

joaomoreno added a commit that referenced this issue Aug 13, 2019
@joaomoreno
Copy link
Member

joaomoreno commented Aug 28, 2019

@sbatten Great job! I can see, using breakpoints, that the editor is only called layout once. I think algorithmically, we're in a great spot. We can now start looking into bad decisions in terms of code patterns and DOM usage.

I found something. On my beefy machine, given a specific workbench size and layout, I can measure the CPU profile of these two calls taking roughly 50ms: bad.cpuprofile.txt

There's a lengthy layout call which is very suspicious. It turns out that there's a forced DOM reflow due to a417a06 which introduced changes to scrollTop and scrollLeft during layout! When I comment out those changes, I get that number down to 15ms instead: good.cpuprofile.txt

Since #78167 was pushed out to September, I'll just revert that fix, since it isn't super important anyway.

joaomoreno added a commit that referenced this issue Aug 28, 2019
Revert "fix #78768"

This reverts commit b6a4220.

Related to #77856 and #78167

Revert "fixes #78167"

This reverts commit a417a06.

Related to #77856 and #78167
@joaomoreno
Copy link
Member

joaomoreno commented Aug 28, 2019

Yep, by reverting the changes from #78167, I can bring the average of workbench ready down by another ~30ms on my machine. Pushing it! 💪

Run Before After
1 1954 1785
2 1863 1873
3 1900 1892
4 1901 1806
5 1862 1809
6 1873 1845
7 1843 1830
8 1826 1908
9 1868 1858
10 1869 1815
Average 1875.9 1842.1

@joaomoreno
Copy link
Member

@jrieken Closing this for now, let me know what the bot says tomorrow!

hunghw pushed a commit to hunghw/vscode that referenced this issue Aug 28, 2019
Revert "fix microsoft#78768"

This reverts commit b6a4220.

Related to microsoft#77856 and microsoft#78167

Revert "fixes microsoft#78167"

This reverts commit a417a06.

Related to microsoft#77856 and microsoft#78167
@octref octref added the verification-steps-needed Steps to verify are needed for verification label Aug 29, 2019
@octref
Copy link
Contributor

octref commented Aug 29, 2019

Not sure how to verify this. Startup was slow compared to old runs but @jrieken attributed that to Windows bloat.

💩Summary: BEST `1774ms`, VERSION `bffbe2ea304a6a4cff23388703b0963f1dadec36`, APP `Code - Insiders.exe`

SLOW 2136    Code - Insiders    bffbe2ea30    52dd11ff-31cc-447b-9249-ed2b032caef11567069843821    standard_start 
SLOW 1809    Code - Insiders    bffbe2ea30    c0e9031c-91d7-40a0-ad6d-837137f285e21567069890756    standard_start 
SLOW 1810    Code - Insiders    bffbe2ea30    af9ed370-7b31-4e46-abbc-5ecdfe2931fa1567069921039    standard_start 
SLOW 1813    Code - Insiders    bffbe2ea30    fc327391-064d-4c08-9cb7-b58359e51ab31567069977230    standard_start 
SLOW 1816    Code - Insiders    bffbe2ea30    8bcfb10e-9cc5-4cd8-919c-339affbc3eee1567070027415    standard_start 
SLOW 1788    Code - Insiders    bffbe2ea30    49bd75d6-c2a6-4531-95eb-c12c2e2f71721567070059584    standard_start 
SLOW 1830    Code - Insiders    bffbe2ea30    14aa9329-50f9-4d88-90db-940deb6253dc1567070089797    standard_start 
SLOW 1812    Code - Insiders    bffbe2ea30    4fd698e9-e468-40fe-b04c-f72cf534dc261567070123982    standard_start 
SLOW 1774    Code - Insiders    bffbe2ea30    dd43781a-f9ea-43a9-91bf-baab5bd51c781567070173151    standard_start 
SLOW 1808    Code - Insiders    bffbe2ea30    3f7fef8c-edf4-4a5f-b485-9915490ad28e1567070210408    standard_start

@sbatten
Copy link
Member

sbatten commented Aug 29, 2019

To verify, preferably with a clean install or with extensions disabled, use the grid layout setting to try both configurations for several runs. Compare startup perf using the command Developer: Startup Performance and look at overall workbench load and workbench ready times. Testing todays insiders averaged over 5 runs, I actually see us better than with grid disabled:

Grid Load Grid Ready Legacy Load Legacy Ready
140.2 751.4 141.8 753.4

@sbatten sbatten removed the verification-steps-needed Steps to verify are needed for verification label Aug 29, 2019
@octref
Copy link
Contributor

octref commented Aug 29, 2019

Here are my numbers, seems overall good:

grid

453 941
453 937
455 939
475 965
473 958

legacy 

441 930
478 966
438 928
440 924
441 930

@octref octref added the verified Verification succeeded label Aug 29, 2019
@vscodebot vscodebot bot locked and limited conversation to collaborators Oct 12, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Issue identified by VS Code Team member as probable bug layout General VS Code workbench layout issues perf verified Verification succeeded
Projects
None yet
Development

No branches or pull requests

4 participants