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

Editor model is set very late #37541

Closed
jrieken opened this issue Nov 2, 2017 · 19 comments
Closed

Editor model is set very late #37541

jrieken opened this issue Nov 2, 2017 · 19 comments
Assignees
Labels
important Issue identified as high-priority perf perf-startup
Milestone

Comments

@jrieken
Copy link
Member

jrieken commented Nov 2, 2017

I used to Timeline/Performance and console.timeStamp. Turns out that we instantiate the editor widget ~400ms after startup. However, setting the model only happens 2seconds later... In-between we do all kinds of things (extension parsing, tree updating etc, etc). We should look at all of them and justify why they are more important than setModel...

screen shot 2017-11-02 at 17 48 17

The patch to get the performance marks: timeStamp.patch.txt

@vscodebot vscodebot bot added the workbench label Nov 2, 2017
@jrieken jrieken added important Issue identified as high-priority perf perf-startup and removed important Issue identified as high-priority workbench labels Nov 2, 2017
@jrieken jrieken added this to the November 2017 milestone Nov 2, 2017
@jrieken
Copy link
Member Author

jrieken commented Nov 3, 2017

So, the rough order of things is like this:

  1. create workbench and widgets (sidebar, editor-container, editor-widget, etc)
  2. explorer: resolve files & folders, then update the tree
  3. extensions: start extension host, parse package.json-files, fill registries, send events
  4. editor: load file from disk, set model, render model

I believe the order should be 1, 4, 2, 3. With some delaying in the extension service you can easily get to 1, 2, 4, 3 which makes the editor render roughly a second sooner.

@bpasero
Copy link
Member

bpasero commented Nov 3, 2017

@jrieken viewlet and editor resolve in parallel if I remember correctly, the editor should never wait on the explorer to be loaed.

I agree on pushing out the extension host loading to a later point would make sense.

@jrieken
Copy link
Member Author

jrieken commented Nov 3, 2017

in parallel if I remember correctly, the editor should never wait on the explorer to be loaed.

Wishful thinking... Nothing happens in parallel here. Yes, both use promises and both run async operations but because the viewlet is being asked first, it always wins

@bpasero
Copy link
Member

bpasero commented Nov 3, 2017

@jrieken well "in parallel" meaning that both components go to disk and load files and the first one that gets back control will win to do the drawing. I am not sure how reordering the editor to be called first before the explorer would change anything because in the end it highly depends on what disk IO is being done from both components.

@jrieken
Copy link
Member Author

jrieken commented Nov 3, 2017

I understand the theory but in practice I never measured a run where the editor won. Maybe that's because the explorer loads it's files very eagerly when being constructed whereas the editor widget needs to get the model set.

Despite all parallelism, I believe the perceived performance depends a lot more on how soon you see text and a blinking cursor and not on how fast the tree populates and because of that we shouldn't even allow that "race" but start with the editor.

@bpasero
Copy link
Member

bpasero commented Nov 3, 2017

Yeah, let's make sure the editor wins and see why that is not the case.

@jrieken
Copy link
Member Author

jrieken commented Nov 3, 2017

Let's swap 1 and 2, Call me artist.

screen shot 2017-11-03 at 10 45 24

jrieken added a commit that referenced this issue Nov 6, 2017
@jrieken
Copy link
Member Author

jrieken commented Nov 6, 2017

I have pushed ff82f1a which makes sure extension-host-startup and package.json-scanning is done after the editor is populated. This improves the perceived performance but it also causes flicker, e.g. the text is rendered without colors first, then the grammers/tokenizers are loaded, and then the text is re-rendered with colors.

@bpasero I have also played with createTextEditorModel and when removing the 50ms timeout the editor loads more parallel and finishes before the tree is being populated. I'd suggestion to skip the timeout while the LifecyclePhase is not Running

@bpasero
Copy link
Member

bpasero commented Nov 6, 2017

@jrieken sounds good, I will look into that part

@jrieken
Copy link
Member Author

jrieken commented Nov 7, 2017

I have disabled my late-ext-host-launch-change because of #37751

@jrieken
Copy link
Member Author

jrieken commented Nov 7, 2017

I have pushed ab17bb7 which adds a new lifecycle event Restoring, it also removes the 50ms wait time when setting an editor input as the mode depends (once) on the extensions being read. Looks now like this

screen shot 2017-11-07 at 12 31 03

bpasero added a commit that referenced this issue Nov 7, 2017
@bpasero
Copy link
Member

bpasero commented Nov 7, 2017

I pushed a change to restore the editor first before sidebar and panel (c1bfc05). I still see the explorer showing data first before the editor shows any data.

Next I will first get rid of IPartService.joinCreation() in favour of LifeCycleService.

@sandy081
Copy link
Member

sandy081 commented Nov 7, 2017

@jrieken @bpasero Let me know if there is any action to be taken by me here?

@jrieken
Copy link
Member Author

jrieken commented Nov 8, 2017

Three things happen at the same time: (1) populating the editor, (2) populating the explorer, (3) scanning for extensions. And the reason for the editor being set so late is a big waterfall... This is what happens when calling TextFileEditorModel#load (this comes first, before loading the explorer or scanning for extensions)

 -1- // backupmodel, init
    -2- // fileservice, resolve
       -3- // mime, fs.open
          -4- // mime, fs.read
             -5- // mime, fs.end
                -6- // fileservice, createReadStream
|----------------|
0               1sec
  1. The load-function checks with the backup-service which is still initialising.
  2. The load-function ends up calling IFileService#resolveStreamContent which begins with calling resolve which is doing a stat-call
  3. Then it calls detectMime which does the following: It calls fs.open,
  4. it calls fs.read (potentially n-times),
  5. it calls fs.end
  6. After doing that the resolveFileStreamContent-function runs. It opens the file again and streams it around.
  7. We have read the file and call setModel

Lots of waiting and delaying.... (around 1 second) Questions:

  • @Tyriar Can the backup and the actual model be resolved in parallel instead of todays blocking waterfall way of things?
  • @bpasero Why do we stat a file that we want to read? Won't we get an error when trying to read a non-file?
  • @bpasero Why do we read/open the file twice. I believe we should read the file in chunks (as stream or not) and detect the mime/encoding while we are doing that

@sandy081 sandy081 removed their assignment Nov 8, 2017
@Tyriar
Copy link
Member

Tyriar commented Nov 8, 2017

@Tyriar Can the backup and the actual model be resolved in parallel instead of todays blocking waterfall way of things?

@jrieken it's been a while since I touched this, I think the editor model needs the backup model to be initialized in order to get the content. If a particular file has a backup it needs to be loaded from the backup file in user data, not the regular file.

Here's where the loading happens:

https://github.com/Microsoft/vscode/blob/284779f5c10c5676821b2a4e7fe6e5973fe11e51/src/vs/workbench/services/textfile/common/textFileEditorModel.ts#L286

A TextFileEditorModel cannot load until:

  1. The BackupMainService has initialized and identified the backup root path (done on Electron main process side)
  2. The BackupFileService has been initialized with the backup root path such that it can identify which paths have backups available

Not sure if I answered your question.

@bpasero
Copy link
Member

bpasero commented Nov 9, 2017

@jrieken we need the stat to resolve some metadata around the file (e.g. the modification time) in order to prevent dirty writes and do proper conditional get if the file has not changed. Unfortunately we do not get this info from just reading the file.

I guess we could experiment with detecting the encoding and leaving the stream open to do the actual read of the file. We would need to be able to push back bytes to the stream though so that we can give the entire stream to iconv-lite.

As for the backups: I am not sure how we could load the backup and the model in parallel because we need to know if there is a backup to resolve the file properly. Are you suggesting to load both in parallel and then see if we actually have a backup and then pick that one over the file we resolved?

@bpasero
Copy link
Member

bpasero commented Nov 9, 2017

@jrieken now that we have the startup phases in lifecycle service, should we change registerWorkbenchContribution to accept an optional phase argument and then when we instantiate the contributions respect that event to delay the instantiation? This would need to be wired into the setInstantiationService call of the BaseRegistry I guess.

@jrieken
Copy link
Member Author

jrieken commented Nov 9, 2017

Unfortunately we do not get this info from just reading the file.

Well, fortunately not every file read does that. Question is why reading needs to wait for stating? Why doesn't the editor call resolveFile and at the some times reads the file? Most callers of resolveContent only want the content anyways and it wouldn't cause the waterfall.

We would need to be able to push back bytes to the stream though so that we can give the entire stream to iconv-lite

Not sure I understand that? We only give it 512 or 4096 bytes anyways. We could just start reading, buffer so many bytes require to detect encoding, guess the encoding via detectMimeAndEncodingFromBuffer and than bail out or surface the bytes to the reader

As for the backups: I am not sure how we could load the backup and the model in parallel because we need to know if there is a backup to resolve the file properly.

I believe that the blocking call is just to build the index of of backup files not loading. We could also optimistically do it in parallel and drop the "real" file once we know a back exists.

@bpasero
Copy link
Member

bpasero commented Nov 10, 2017

Well, fortunately not every file read does that. Question is why reading needs to wait for stating? Why doesn't the editor call resolveFile and at the some times reads the file? Most callers of resolveContent only want the content anyways and it wouldn't cause the waterfall.

@jrieken we first do the stat to prevent unneeded disk IO for reading the file in case the file has not changed. Every time you click on a tab we do this call, even if the tab has already been opened before (because the file could have changed on disk and we do not trust the file events). If we would start to always read the file from disk in that case I think we would too much unnecessary work.

We could however think about doing this either only on startup or just create a new resolveContentSync method which is sync and which is only used during startup.

Not sure I understand that? We only give it 512 or 4096 bytes anyways. We could just start reading, buffer so many bytes require to detect encoding, guess the encoding via detectMimeAndEncodingFromBuffer and than bail out or surface the bytes to the reader

Yeah, I guess the challenge is with iconv-lite stream handling as you already found out.

I believe that the blocking call is just to build the index of of backup files not loading. We could also optimistically do it in parallel and drop the "real" file once we know a back exists.

Yes, that could work.

@bpasero bpasero closed this as completed Nov 14, 2017
bpasero added a commit that referenced this issue Nov 14, 2017
mjbvz added a commit that referenced this issue Nov 14, 2017
@vscodebot vscodebot bot locked and limited conversation to collaborators Dec 29, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
important Issue identified as high-priority perf perf-startup
Projects
None yet
Development

No branches or pull requests

5 participants