Improve workbench start-up performance
jrieken opened this issue · 43 comments
Startup performance for some users is very bad and we should understand why.
Some ideas:
- add more numbers to our telemetry event for startup times to understand better where time is spend
- also log subsequent window opens as telemetry to see how bad we are with opening a second window when Code is already running (related: #11220)
@bpasero Why is it that you instantiate all services eager during startup and don't let the instantiation service take care of this? The ServiceCollection also accepts ctor's which it will invoke when a service is being requested. While we still have to instantiate them all it might help getting the workbench show up faster
@jrieken so instead of
this.viewletService = this.instantiationService.createInstance(ViewletService, this.sidebarPart);
serviceCollection.set(IViewletService, this.viewletService);
doing
serviceCollection.set(IViewletService, ViewletService);
?
There is no specific reason for instantiating all the services right on startup so we can try with it. Though many services are simply just interfaces for parts that get created on startup anyway (like the viewlet service).
Like so, serviceCollection.set(IMenuService, new SyncDescriptor(MenuService));
I agree, some services are needed right aways or already instantiated but some aren't. My guess is that the lower half there can be lazy, like ConfigurationEditing
it takes about 5 second to load in my machine, latest update 1.8
@shanalikhan Can you do this: Hit F1, type Startup Performance, hit Enter. It will open dev tools and print some startup stats. Can you share them with me please
Is that when reloading (F1 > Reload window) or after a exit/restart?
its when closed code, started code , F1 > Startup Performance
Ok im also posting another one.
1- Computer Started
2- Started Code - F1 - Performance
3- Took about more than 30 seconds to load only
@shanalikhan It would be awesome to get more data about your case. If it's OK with you I'll create you a special built that runs a profiler very early on startup. With that I should be able to understand where the time is spend
sure, no problem go ahead. what information will it send ?
Awesome. The build I just creating will run the v8 profiler on startup - apart from timings and JS function names it will contain fully resolved file names of the VS Code installation directory, like /Users/jrieken/Application/VS Code.app/Resources/file.js. If you don't wanna share that data here you could just send me a mail or run a large find/replace operation on the (text) file.
there we go win32 archive and win32 setup. The former can run after unzipping the latter is the installer. As long as you are profiling, don't react to the update affordance.
Do the following
- unzip/install VS Code which was build from https://github.com/Microsoft/vscode/tree/joh/mainPerf
- start VS Code and wait for it to come up (it might be a little slower because of profiling)
- locate a
main-1234567890.cpuprofilefile in your home directory - zip that file and share it with me
Thanks
ok today i also get first time experience the editor is getting hanging but menus are working.
editor not responding dialog is appearing again nag again from hwn using the LONG json file
will you be able to check this behaviour also form the above build ?
let tackle one thing after the other
@shanalikhan re #15455 (comment) did that work for you, did you get some measurements?
@jrieken do i have to update it, its showing me to update it, to get your work ?
that was of my work computer, following is the image from the home computer- in home code i havent installed your build though, its image from the normal build.
Please install the build as it will provide more detail about where exactly the time is spent.
@jrieken while you now also seem to be looking into workbench time, I noticed quite some time being spend in CharWidthReader when opening the first editor to compute some char widths (actually often 15-20% of overall workbench time). Did you already file a bug for that?
@bpasero Yeah, @alexandrudima and I have a fix which reduces the time to 2/3 but there is still room for improvement. See: #18211
I agree that VSCode takes way to long too open, to make it a feasible alternative to Notepad++ for opening text and code files.
It takes 11+ seconds for a cold startup and 7-8 seconds for Reload Window after that with fast SSD and CPU (Intel® Core™ i7-6700HQ, PCIe® NVMe™ M.2 SSD exclusively, 16GB RAM, Win 10 x64) with all extensions disabled, even with vscode added excluded by Webroot and Anti-Malware.
As a workaround, it would be very helpful if could launch VSCode on Windows startup, minimized to tray, as proposed for #11723
@XeonX1 Can please start VS Code fresh with the --peformance option and then select 'F1 > Start up Performance'? It will open dev tools and print stats to the console. Sharing that with us would be extremely helpful. Thanks.
@jrieken @bpasero
Here is the saved log file contents after starting up with --performance command line option and then printing the results via F1 > Developer: Startup Performance, as requested:
Note: I also posted this, as was also requested, as a comment for related issue #14109
This startup took 11 seconds (before VSCode was usable with empty tab finishing loading), the same time regardless of whether extensions are disabled or whether --performance is used, and is similar to the 7-8 second startup time for just Reload Window.
Is it supposed to be show "OS" as win32 (as seen in the log) as opposed to win64, due to it being a 32-bit process on Windows 10 64-bit?
Is there no 64-bit version available for Windows?
Log File Contents:
Overwriting extension <<.bas>> to now point to mime <<text/x-vba>>
[C:/Users/Dan/.vscode/extensions/abhiagr.livs-1.0.2]: Command extension.launchInVS appears multiple times in the commands section.
Ctrl+Alt+ keybindings should not be used by default under Windows. Offender: 41003 for extension.toggleRegexPreview
Ctrl+Alt+ keybindings should not be used by default under Windows. Offender: 41004 for code-runner.run
Ctrl+Alt+ keybindings should not be used by default under Windows. Offender: 41001 for code-runner.runCustomCommand
Ctrl+Alt+ keybindings should not be used by default under Windows. Offender: 41000 for code-runner.runByLanguage
Ctrl+Alt+ keybindings should not be used by default under Windows. Offender: 41003 for code-runner.stop
Ctrl+Alt+ keybindings should not be used by default under Windows. Offender: 40995 for PowerShell.ExpandAlias
Conflict detected, command extension.toggleRegexPreview cannot be triggered by ctrl+alt+m due to code-runner.stop
[Extension Host] [C:/Users/Dan/.vscode/extensions/abhiagr.livs-1.0.2]: Command extension.launchInVS appears multiple times in the commands section.
Startup Performance Measurement
OS: win32 (10.0.14393)
CPUs: Intel(R) Core(TM) i7-6700HQ CPU @ 2.60GHz (8 x 2592)
Memory (System): 15.96GB (10.59GB free)
Memory (Process): 123.81MB working set (164.63MB peak, 97.02MB private, 36.12MB shared)
Initial Startup: true
Screen Reader Active: false
Empty Workspace: true
Startup Performance Measurement
OS: win32 (10.0.14393)
CPUs: Intel(R) Core(TM) i7-6700HQ CPU @ 2.60GHz (8 x 2592)
Memory (System): 15.96GB (10.59GB free)
Memory (Process): 123.81MB working set (164.63MB peak, 97.02MB private, 36.12MB shared)
Initial Startup: true
Screen Reader Active: false
Empty Workspace: true
(index)TopicTook (ms)
0"[main] start => window.loadUrl()"1907
1"[renderer] window.loadUrl() => begin to require(workbench.main.js)"1594
2"[renderer] require(workbench.main.js)"717
3"[renderer] create extension host => extensions onReady()"3291
4"[renderer] restore viewlet"0
5"[renderer] restore editor view state"1712
6"[renderer] overall workbench load"3109
7"------------------------------------------------------"
8"[main, renderer] start => extensions ready"7576
9"[main, renderer] start => workbench ready"7343
@XeonX1 FYI I have reformatted the last bit of our comment to make the numbers easier to read. Please check that they are still correct
It's interesting, things seems to be slower than usual except for step 2 (loading/defining the main chunk of code) which is fast.
@XeonX1 does it make any difference if you start with code --disable-extensions from the command line to disable extensions loading? Also, please maybe attach a screenshot of the output of the console, would make it easier for us to read. Beginning with todays insider build we also have an action to report these numbers as GH issue (F1 > Report Performance Issue).
Second, do you have any anti virus software running that might scan Code on startup?
Windows 10 with VSCode insiders build. I noticed F-Secure peaked in CPU for quite some time when starting up VSCode.
With F-Secure realtime scanning turned off:
code --performance
Reload window:
That all depends on the size of the project, open tabs, et.c (I guess, corresponding to number of processes). But for the same usercase, here's a measurement for comparison.
It's interesting to see that the app.isReady event takes 500ms (instead of 31ms) when F-Secure is active. Also, other launches (create extension host et al) take very long...
Yup. So that's something to address for all the vanilla users. E.g doesn't happen for Chrome which also spawns lots of processes.
But anyway, with F-Secure disabled and on a SSD, I would have expected faster results. Below 2s for Cold start sounds more reasonable to match MacOS.
As reported initially, it made no difference when running with --disable-extensions, and the reported startup times are after adding VSCode's process and folder as exclusions to both Webroot and Anti-Malware.
I will look into getting you a startup profiling screenshot with the Insider builder.
@XeonX1 we now also have an action to report performance issues (Command Palette > Report Performance Isue).
There is a discussion about virus scanners and bad perf of Electron apps: electron/electron#1487. As it seem VS Code isn't the only app that's affected by this...
Closing this because it has served as an umbrella item to collect general ideas and feedback. Because of the amount of perf work we have added the 'perf' and 'perf-profile' tag which every one should look for.
@jrieken What is considered 'good' startup time and what is considered 'bad'?
On Win10, cold start is >10s. Which to me feels way too long. But perhaps is in the ballpark?
Please see #18514 for additional benchmarking details, as well as pinpointed cause of 10.5 second startup times. I describe a workaround to bring startup time down to 3.3 seconds. I suggest anyone with Malwarebytes make those changes.
However, as pointed out there, any disk access overhead (whether due to anti-virus or potentially just slow disks) seems to have a much greater impact on VS Code.
You can see this in how, whether those anti-virus features were enabled made no difference in Notepad++ and OneNote startup times, which were 0.7 seconds and 1.7 seconds respectively, and how VS Code still takes 3.3 seconds to open, which is nearly 5x Notepad++ (with many plugins enabled) and nearly 2x OneNote (which I would have thought would take longer to open, especially with web hosted/synced/shared Notebooks).
Accordingly, I would suggest deferring extension and feature loading until after the opened document is displayed (similar to what is done with spellcheck underling and content/code language determination being delayed until after that), as discussed further in #18514.
I have provided screenshots, log files, Steps to Reproduce, and manual startup measurements (time until the document contents are displayed - the most important startup metric IMO) all in #18514, for various cases, with and without extensions, and with and without Malwarebytes features which cause slower startup being enabled.
@csholmq A good startup should be in the range of 3 seconds, maybe 5 but everything > 10 is a disaster. Can you run latest insiders from the command line like so: code-insiders --prof-startup. That will create CPU profiles for the main and renderer process which we then can analyse. Happy Coding
@jrieken Seems to be must better now when I tested. <5 seconds which is reasonable.
Doesn't really matter that much if it takes 0.5 or 5 seconds to open the main window.
What feels jarring every single time is the delay between when the VSCode window opens & when a simple text file is finally shown inside!
That's what makes me look for a faster alternative, like I dunno, MS Word?!?
Sorry if I sound bitter, but this seems like the most basic of UX principles...
Slow as f*ck :((
-
VSCode Version:
Code - Insiders 1.18.0-insider (dcd1aa35dfa590b4a528e1ab55e957002f430f17, 2017-10-10T05:26:33.683Z) -
OS Version:
Windows_NT x64 6.1.7601 -
CPUs:
Intel(R) Core(TM) i7-4610M CPU @ 3.00GHz (4 x 2993) -
Memory (System):
7.88GB (4.34GB free) -
Memory (Process):
195.05MB working set (195.25MB peak, 183.58MB private, 36.27MB shared) -
Load (avg):
0, 0, 0
66f9_renderer.cpuprofile.txt -
VM:
0% -
Initial Startup:
yes -
Screen Reader:
no -
Empty Workspace:
yes -
Timings:
| Component | Task | Time (ms) |
|---|---|---|
| main | start => app.isReady | 1060 |
| main | app.isReady => window.loadUrl() | 1741 |
| renderer | window.loadUrl() => begin to require(workbench.main.js) | 3197 |
| renderer | require(workbench.main.js) | 3967 |
| renderer | create extension host => extensions onReady() | 2480 |
| renderer | restore viewlet | 2379 |
| renderer | restore editor view state | 281 |
| renderer | overall workbench load | 3129 |
| main + renderer | start => extensions ready | 13096 |
| main + renderer | start => workbench ready | 13117 |
-66f9_main.cpuprofile.txt
-66f9_renderer.cpuprofile.txt
66f9_main.cpuprofile.txt
66f9_renderer.cpuprofile.txt