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

Workbench takes significantly longer than usual to become ready in Insiders #132086

Closed
joyceerhl opened this issue Sep 1, 2021 · 11 comments · Fixed by #143223
Closed

Workbench takes significantly longer than usual to become ready in Insiders #132086

joyceerhl opened this issue Sep 1, 2021 · 11 comments · Fixed by #143223
Assignees
Labels
chromium Issues and items related to Chromium gpu Issues concerning GPU related items insiders-released Patch has been released in VS Code Insiders perf-startup upstream Issue identified as 'upstream' component related (exists outside of VS Code) windows VS Code on Windows issues
Milestone

Comments

@joyceerhl
Copy link
Collaborator

joyceerhl commented Sep 1, 2021

Looking at the output from running with --prof-startup flag, restoring and resolving open editors in Insiders appears to take 30 seconds. In VS Code Stable the same step takes 5 seconds.

logs.zip

System Info

  • Code - Insiders: 1.60.0-insider (e7d7e9a)
  • OS: win32(10.0.19043)
  • CPUs: Intel(R) Core(TM) i7-1065G7 CPU @ 1.30GHz(8 x 1498)
  • Memory(System): 31.59 GB(17.36GB free)
  • Memory(Process): 204.43 MB working set(164.77MB private, 1.11MB shared)
  • VM(likelihood): 0%
  • Initial Startup: true
  • Has 0 other windows
  • Screen Reader Active: false
  • Empty Workspace: false

Performance Marks

What Duration Process Info
start => app.isReady 190 [main] initial startup: true
nls:start => nls:end 0 [main] initial startup: true
require(main.bundle.js) 208 [main] initial startup: true
start crash reporter 58 [main] initial startup: true
serve main IPC handle 4 [main] initial startup: true
create window 81 [main] initial startup: true, state: 1ms, widget: 75ms, show: 0ms
app.isReady => window.loadUrl() 397 [main] initial startup: true
window.loadUrl() => begin to require(workbench.desktop.main.js) 1005 [main->renderer] NewWindow
require(workbench.desktop.main.js) 3989 [renderer] cached data: NO, node_modules took 0ms
wait for window config 0 [renderer] -
init storage (global & workspace) 71 [renderer] -
init workspace service 117 [renderer] -
register extensions & spawn extension host 24608 [renderer] -
restore viewlet 81 [renderer] workbench.view.explorer
restore panel 53 [renderer] workbench.views.service.panel.7d39cade-d9ad-4447-81d7-dd6c4fe18e14
restore & resolve visible editors 23156 [renderer] 1: workbench.editors.files.fileEditorInput
overall workbench load 23675 [renderer] -
workbench ready 29406 [main->renderer] -
renderer ready 27827 [renderer] -
shared process connection ready 0 [renderer->sharedprocess] -
extensions registered 31049 [renderer] -

Extension Activation Stats

Extension Eager Load Code Call Activate Finish Activate Event By
vscode.debug-auto-launch true 14 0 17 * vscode.debug-auto-launch
vscode.git true 208 13 261 * vscode.github
vscode.github true 38 2 0 * vscode.github
vscode.npm true 86 0 2867 workspaceContains:package.json vscode.npm
vscode.emmet false 83 7 12 onStartupFinished vscode.emmet
vscode.extension-editing false 71 3 115 onLanguage:typescript vscode.extension-editing
vscode.github-authentication false 720 6 0 onAuthenticationRequest:github vscode.github-authentication
vscode.merge-conflict false 15 4 8 onStartupFinished vscode.merge-conflict
vscode.microsoft-authentication false 129 20 5609 onAuthenticationRequest:microsoft vscode.microsoft-authentication
ms-vscode-remote.remote-wsl-recommender false 97 8 5 onStartupFinished ms-vscode-remote.remote-wsl-recommender
ms-vscode.js-debug false 817 31 0 onCommand:extension.js-debug.clearAutoAttachVariables ms-vscode.js-debug
vscode.typescript-language-features false 198 102 17 onLanguage:typescript vscode.typescript-language-features

Raw Perf Marks: main

Name	Timestamp	Delta	Total
code/timeOrigin	1630536465638	0	0
code/didStartMain	1630536465866	228	228
code/willStartCrashReporter	1630536465898	32	260
code/didStartCrashReporter	1630536465956	58	318
code/mainAppReady	1630536466056	100	418
code/willLoadMainBundle	1630536466062	6	424
code/fork/willLoadCode	1630536466094	32	456
code/registerFilesystem/file	1630536466261	167	623
code/didLoadMainBundle	1630536466270	9	632
code/willStartMainServer	1630536466283	13	645
code/didStartMainServer	1630536466287	4	649
code/willCreateCodeWindow	1630536466368	81	730
code/willRestoreCodeWindowState	1630536466369	1	731
code/didRestoreCodeWindowState	1630536466370	1	732
code/willCreateCodeBrowserWindow	1630536466371	1	733
code/didCreateCodeBrowserWindow	1630536466446	75	808
code/didCreateCodeWindow	1630536466449	3	811
code/willOpenNewWindow	1630536466453	4	815

Raw Perf Marks: renderer

Name	Timestamp	Delta	Total
code/timeOrigin	1630536466469	0	0
code/didStartRenderer	1630536467445	976	976
code/willWaitForWindowConfig	1630536467446	1	977
code/didWaitForWindowConfig	1630536467446	0	977
code/willShowPartsSplash	1630536467446	0	977
code/didShowPartsSplash	1630536467447	1	978
code/willLoadWorkbenchMain	1630536467458	11	989
code/didLoadWorkbenchMain	1630536471447	3989	4978
code/registerFilesystem/file	1630536471458	11	4989
code/registerFilesystem/vscode-userdata	1630536471458	0	4989
code/willInitWorkspaceService	1630536471467	9	4998
code/willInitStorage	1630536471469	2	5000
code/didInitStorage	1630536471540	71	5071
code/didInitWorkspaceService	1630536471584	44	5115
code/willStartWorkbench	1630536471597	13	5128
code/LifecyclePhase/Ready	1630536471603	6	5134
code/registerFilesystem/trustedDomains	1630536471748	145	5279
code/willRestoreEditors	1630536472116	368	5647
code/willRestoreViewlet	1630536472131	15	5662
code/willRestorePanel	1630536472159	28	5690
code/didRestoreViewlet	1630536472212	53	5743
code/didRestorePanel	1630536472212	0	5743
code/willResolveExplorer	1630536472246	34	5777
code/willLoadExtensions	1630536472307	61	5838
code/didRestoreEditors	1630536495272	22965	28803
code/LifecyclePhase/Restored	1630536495272	0	28803
code/didStartWorkbench	1630536495272	0	28803
code/didRemovePartsSplash	1630536495272	0	28803
code/willConnectSharedProcess	1630536495322	50	28853
code/didResolveExplorer	1630536496094	772	29625
code/willHandleExtensionPoints	1630536496514	420	30045
code/didHandleExtensionPoints	1630536496879	365	30410
code/didLoadExtensions	1630536496915	36	30446

Raw Perf Marks: workerExtHost

Name	Timestamp	Delta	Total
code/timeOrigin	1630536472659	0	0
code/extHost/willConnectToRenderer	1630536472895	236	236
code/extHost/didWaitForInitData	1630536496955	24060	24296
code/extHost/didCreateServices	1630536496959	4	24300
code/extHost/willWaitForConfig	1630536496970	11	24311
code/extHost/didWaitForConfig	1630536497117	147	24458
code/extHost/didInitAPI	1630536497118	1	24459
code/extHost/ready	1630536497182	64	24523

Raw Perf Marks: localExtHost

Name	Timestamp	Delta	Total
code/timeOrigin	1630536472501	0	0
code/fork/start	1630536472853	352	352
code/fork/willLoadCode	1630536472926	73	425
code/extHost/willConnectToRenderer	1630536473763	837	1262
code/extHost/didConnectToRenderer	1630536473764	1	1263
code/extHost/didWaitForInitData	1630536497060	23296	24559
code/extHost/didCreateServices	1630536497077	17	24576
code/extHost/willWaitForConfig	1630536497084	7	24583
code/extHost/didWaitForConfig	1630536497510	426	25009
code/extHost/didInitAPI	1630536497510	0	25009
code/extHost/didInitProxyResolver	1630536497519	9	25018
code/extHost/ready	1630536497519	0	25018
code/extHost/willLoadExtensionCode/vscode.microsoft-authentication	1630536497714	195	25213
code/extHost/didLoadExtensionCode/vscode.microsoft-authentication	1630536497843	129	25342
code/extHost/willLoadExtensionCode/vscode.extension-editing	1630536497844	1	25343
code/extHost/didLoadExtensionCode/vscode.extension-editing	1630536497915	71	25414
code/extHost/willLoadExtensionCode/vscode.typescript-language-features	1630536497916	1	25415
code/extHost/didLoadExtensionCode/vscode.typescript-language-features	1630536498114	198	25613
code/extHost/willLoadExtensionCode/vscode.debug-auto-launch	1630536498114	0	25613
code/extHost/didLoadExtensionCode/vscode.debug-auto-launch	1630536498128	14	25627
code/extHost/willLoadExtensionCode/vscode.git	1630536498129	1	25628
code/extHost/didLoadExtensionCode/vscode.git	1630536498337	208	25836
code/extHost/willLoadExtensionCode/vscode.npm	1630536498338	1	25837
code/extHost/didLoadExtensionCode/vscode.npm	1630536498424	86	25923

Node Cached Data Stats

cached data used

cached data missed

cached data rejected

cached data created (lazy, might need refreshes)

@joyceerhl
Copy link
Collaborator Author

Data from running --prof-startup in 1.59.1:

System Info

  • Code: 1.59.1 (3866c35)
  • OS: win32(10.0.19043)
  • CPUs: Intel(R) Core(TM) i7-1065G7 CPU @ 1.30GHz(8 x 1498)
  • Memory(System): 31.59 GB(18.63GB free)
  • Memory(Process): 212.76 MB working set(175.43MB private, 0.87MB shared)
  • VM(likelihood): 0%
  • Initial Startup: true
  • Has 0 other windows
  • Screen Reader Active: false
  • Empty Workspace: false

Performance Marks

What Duration Process Info
start => app.isReady 184 [main] initial startup: true
nls:start => nls:end 0 [main] initial startup: true
require(main.bundle.js) 231 [main] initial startup: true
start crash reporter 56 [main] initial startup: true
serve main IPC handle 5 [main] initial startup: true
create window 91 [main] initial startup: true, state: 1ms, widget: 40ms, show: 39ms
app.isReady => window.loadUrl() 458 [main] initial startup: true
window.loadUrl() => begin to require(workbench.desktop.main.js) 533 [main->renderer] NewWindow
require(workbench.desktop.main.js) 1261 [renderer] cached data: NO, node_modules took 0ms
wait for window config 0 [renderer] -
init storage (global & workspace) 28 [renderer] -
init workspace service 94 [renderer] -
register extensions & spawn extension host 2448 [renderer] -
restore viewlet 81 [renderer] workbench.view.explorer
restore panel 51 [renderer] terminal
restore & resolve visible editors 1029 [renderer] 1: workbench.editors.files.fileEditorInput
overall workbench load 1579 [renderer] -
workbench ready 4129 [main->renderer] -
renderer ready 2970 [renderer] -
shared process connection ready 933 [renderer->sharedprocess] -
extensions registered 5871 [renderer] -

Extension Activation Stats

Extension Eager Load Code Call Activate Finish Activate Event By
vscode.debug-auto-launch true 13 0 14 * vscode.debug-auto-launch
vscode.git true 199 11 278 * vscode.github
vscode.github true 64 2 0 * vscode.github
vscode.npm true 106 0 7548 workspaceContains:package.json vscode.npm
vscode.emmet false 114 20 24 onStartupFinished vscode.emmet
vscode.extension-editing false 73 1 83 onLanguage:typescript vscode.extension-editing
vscode.github-authentication false 898 9 1 onAuthenticationRequest:github vscode.github-authentication
vscode.merge-conflict false 44 8 15 onStartupFinished vscode.merge-conflict
vscode.microsoft-authentication false 143 15 8338 onAuthenticationRequest:microsoft vscode.microsoft-authentication
ms-vscode-remote.remote-wsl-recommender false 121 15 8 onStartupFinished ms-vscode-remote.remote-wsl-recommender
ms-vscode.js-debug false 1302 82 0 onCommand:extension.js-debug.clearAutoAttachVariables ms-vscode.js-debug
vscode.typescript-language-features false 168 72 14 onLanguage:typescript vscode.typescript-language-features

Raw Perf Marks: main

Name	Timestamp	Delta	Total
code/timeOrigin	1630536781577	0	0
code/didStartMain	1630536781771	194	194
code/willStartCrashReporter	1630536781824	53	247
code/didStartCrashReporter	1630536781880	56	303
code/mainAppReady	1630536781955	75	378
code/willLoadMainBundle	1630536781963	8	386
code/fork/willLoadCode	1630536782013	50	436
code/registerFilesystem/file	1630536782183	170	606
code/didLoadMainBundle	1630536782194	11	617
code/willStartMainServer	1630536782209	15	632
code/didStartMainServer	1630536782214	5	637
code/willCreateCodeWindow	1630536782319	105	742
code/willRestoreCodeWindowState	1630536782321	2	744
code/didRestoreCodeWindowState	1630536782322	1	745
code/willCreateCodeBrowserWindow	1630536782328	6	751
code/didCreateCodeBrowserWindow	1630536782368	40	791
code/willMaximizeCodeWindow	1630536782368	0	791
code/didMaximizeCodeWindow	1630536782407	39	830
code/didCreateCodeWindow	1630536782410	3	833
code/willOpenNewWindow	1630536782413	3	836

Raw Perf Marks: renderer

Name	Timestamp	Delta	Total
code/timeOrigin	1630536782416	0	0
code/didStartRenderer	1630536782930	514	514
code/willWaitForWindowConfig	1630536782931	1	515
code/didWaitForWindowConfig	1630536782931	0	515
code/willShowPartsSplash	1630536782932	1	516
code/didShowPartsSplash	1630536782934	2	518
code/willLoadWorkbenchMain	1630536782946	12	530
code/didLoadWorkbenchMain	1630536784207	1261	1791
code/registerFilesystem/file	1630536784214	7	1798
code/registerFilesystem/vscode-userdata	1630536784215	1	1799
code/willInitWorkspaceService	1630536784221	6	1805
code/willInitStorage	1630536784223	2	1807
code/didInitStorage	1630536784251	28	1835
code/didInitWorkspaceService	1630536784315	64	1899
code/willStartWorkbench	1630536784321	6	1905
code/LifecyclePhase/Ready	1630536784325	4	1909
code/registerFilesystem/trustedDomains	1630536784467	142	2051
code/willRestoreEditors	1630536784871	404	2455
code/willRestoreViewlet	1630536784886	15	2470
code/willRestorePanel	1630536784916	30	2500
code/didRestoreViewlet	1630536784967	51	2551
code/didRestorePanel	1630536784967	0	2551
code/willResolveExplorer	1630536785003	36	2587
code/willLoadExtensions	1630536785194	191	2778
code/didRestoreEditors	1630536785900	706	3484
code/LifecyclePhase/Restored	1630536785900	0	3484
code/didStartWorkbench	1630536785900	0	3484
code/didRemovePartsSplash	1630536785900	0	3484
code/willConnectSharedProcess	1630536785969	69	3553
code/didResolveExplorer	1630536786479	510	4063
code/didConnectSharedProcess	1630536786902	423	4486
code/willHandleExtensionPoints	1630536787187	285	4771
code/didHandleExtensionPoints	1630536787620	433	5204
code/didLoadExtensions	1630536787642	22	5226

Raw Perf Marks: localExtHost

Name	Timestamp	Delta	Total
code/timeOrigin	1630536785452	0	0
code/fork/start	1630536785784	332	332
code/fork/willLoadCode	1630536785869	85	417
code/extHost/willConnectToRenderer	1630536786946	1077	1494
code/extHost/didConnectToRenderer	1630536786948	2	1496
code/extHost/didWaitForInitData	1630536787782	834	2330
code/extHost/didCreateServices	1630536787828	46	2376
code/extHost/willWaitForConfig	1630536787841	13	2389
code/extHost/didWaitForConfig	1630536788665	824	3213
code/extHost/didInitAPI	1630536788665	0	3213
code/extHost/didInitProxyResolver	1630536788672	7	3220
code/extHost/ready	1630536788673	1	3221
code/extHost/willLoadExtensionCode/vscode.microsoft-authentication	1630536789213	540	3761
code/extHost/didLoadExtensionCode/vscode.microsoft-authentication	1630536789355	142	3903
code/extHost/willLoadExtensionCode/vscode.extension-editing	1630536789367	12	3915
code/extHost/didLoadExtensionCode/vscode.extension-editing	1630536789440	73	3988
code/extHost/willLoadExtensionCode/vscode.typescript-language-features	1630536789441	1	3989
code/extHost/didLoadExtensionCode/vscode.typescript-language-features	1630536789609	168	4157
code/extHost/willLoadExtensionCode/vscode.debug-auto-launch	1630536789610	1	4158
code/extHost/didLoadExtensionCode/vscode.debug-auto-launch	1630536789623	13	4171
code/extHost/willLoadExtensionCode/vscode.git	1630536789624	1	4172
code/extHost/didLoadExtensionCode/vscode.git	1630536789822	198	4370
code/extHost/willLoadExtensionCode/vscode.npm	1630536789823	1	4371
code/extHost/didLoadExtensionCode/vscode.npm	1630536789929	106	4477
code/extHost/willActivateExtension/vscode.microsoft-authentication	1630536790755	826	5303
code/extHost/willActivateExtension/vscode.extension-editing	1630536790770	15	5318
code/extHost/willActivateExtension/vscode.typescript-language-features	1630536790771	1	5319
code/extHost/willActivateExtension/vscode.debug-auto-launch	1630536790843	72	5391
code/extHost/willActivateExtension/vscode.git	1630536790843	0	5391
code/extHost/willActivateExtension/vscode.npm	1630536790854	11	5402
code/extHost/didActivateExtension/vscode.extension-editing	1630536790875	21	5423
code/extHost/didActivateExtension/vscode.typescript-language-features	1630536790875	0	5423
code/extHost/didActivateExtension/vscode.debug-auto-launch	1630536790875	0	5423
code/extHost/didActivateExtension/vscode.git	1630536791132	257	5680
code/extHost/willLoadExtensionCode/vscode.github	1630536798334	7202	12882
code/extHost/didLoadExtensionCode/vscode.github	1630536798398	64	12946
code/extHost/didActivateExtension/vscode.npm	1630536798402	4	12950

Node Cached Data Stats

cached data used

cached data missed

cached data rejected

cached data created (lazy, might need refreshes)

@deepak1556
Copy link
Collaborator

Time is mostly spent on the rendering

Screen Shot 2021-09-02 at 7 58 43 AM

@deepak1556
Copy link
Collaborator

Is there a particular file you see this issue with or opening any workspace ?

@deepak1556 deepak1556 added info-needed Issue requires more information from poster perf-startup windows VS Code on Windows issues labels Sep 1, 2021
@deepak1556 deepak1556 assigned deepak1556 and alexdima and unassigned bpasero and lramos15 Sep 1, 2021
@joyceerhl
Copy link
Collaborator Author

I had a file in the vscode-jupyter repo open, but it seems that any file will do. E.g. here's the --prof-startup output when starting Insiders with the vscode repo open to this file: https://github.com/microsoft/vscode/blob/main/src/vs/workbench/browser/parts/editor/editor.ts

System Info

  • Code - Insiders: 1.60.0-insider (e7d7e9a)
  • OS: win32(10.0.19043)
  • CPUs: Intel(R) Core(TM) i7-1065G7 CPU @ 1.30GHz(8 x 1498)
  • Memory(System): 31.59 GB(18.06GB free)
  • Memory(Process): 244.14 MB working set(197.15MB private, 1.46MB shared)
  • VM(likelihood): 0%
  • Initial Startup: true
  • Has 0 other windows
  • Screen Reader Active: false
  • Empty Workspace: false

Performance Marks

What Duration Process Info
start => app.isReady 180 [main] initial startup: true
nls:start => nls:end 0 [main] initial startup: true
require(main.bundle.js) 208 [main] initial startup: true
start crash reporter 61 [main] initial startup: true
serve main IPC handle 3 [main] initial startup: true
create window 83 [main] initial startup: true, state: 1ms, widget: 40ms, show: 38ms
app.isReady => window.loadUrl() 436 [main] initial startup: true
window.loadUrl() => begin to require(workbench.desktop.main.js) 937 [main->renderer] NewWindow
require(workbench.desktop.main.js) 3900 [renderer] cached data: NO, node_modules took 0ms
wait for window config 0 [renderer] -
init storage (global & workspace) 54 [renderer] -
init workspace service 119 [renderer] -
register extensions & spawn extension host 23580 [renderer] -
restore viewlet 92 [renderer] workbench.view.explorer
restore panel 68 [renderer] workbench.panel.markers
restore & resolve visible editors 23269 [renderer] 1: workbench.editors.files.fileEditorInput
overall workbench load 23759 [renderer] -
workbench ready 29354 [main->renderer] -
renderer ready 27820 [renderer] -
shared process connection ready 0 [renderer->sharedprocess] -
extensions registered 29852 [renderer] -

Extension Activation Stats

Extension Eager Load Code Call Activate Finish Activate Event By
vscode.debug-auto-launch true 14 3 15 * vscode.debug-auto-launch
vscode.git true 213 12 445 * vscode.github
vscode.github true 32 1 0 * vscode.github
vscode.npm true 99 0 3857 workspaceContains:package.json vscode.npm
vscode.emmet false 91 6 11 onStartupFinished vscode.emmet
vscode.extension-editing false 74 4 151 onLanguage:typescript vscode.extension-editing
vscode.github-authentication false 139 4 17 onAuthenticationRequest:github vscode.github-authentication
vscode.merge-conflict false 17 3 8 onStartupFinished vscode.merge-conflict
vscode.microsoft-authentication false 135 26 1218 onAuthenticationRequest:microsoft vscode.microsoft-authentication
ms-vscode-remote.remote-wsl-recommender false 76 8 3 onStartupFinished ms-vscode-remote.remote-wsl-recommender
ms-vscode.js-debug false 2249 20 0 onCommand:extension.js-debug.clearAutoAttachVariables ms-vscode.js-debug
vscode.typescript-language-features false 214 132 21 onLanguage:typescript vscode.typescript-language-features

Raw Perf Marks: main

Name	Timestamp	Delta	Total
code/timeOrigin	1630541523540	0	0
code/didStartMain	1630541523706	166	166
code/willStartCrashReporter	1630541523737	31	197
code/didStartCrashReporter	1630541523798	61	258
code/mainAppReady	1630541523886	88	346
code/willLoadMainBundle	1630541523890	4	350
code/fork/willLoadCode	1630541523926	36	386
code/registerFilesystem/file	1630541524087	161	547
code/didLoadMainBundle	1630541524098	11	558
code/willStartMainServer	1630541524117	19	577
code/didStartMainServer	1630541524120	3	580
code/willCreateCodeWindow	1630541524220	100	680
code/willRestoreCodeWindowState	1630541524221	1	681
code/didRestoreCodeWindowState	1630541524222	1	682
code/willCreateCodeBrowserWindow	1630541524222	0	682
code/didCreateCodeBrowserWindow	1630541524262	40	722
code/willMaximizeCodeWindow	1630541524262	0	722
code/didMaximizeCodeWindow	1630541524300	38	760
code/didCreateCodeWindow	1630541524303	3	763
code/willOpenNewWindow	1630541524322	19	782

Raw Perf Marks: renderer

Name	Timestamp	Delta	Total
code/timeOrigin	1630541524324	0	0
code/didStartRenderer	1630541525240	916	916
code/willWaitForWindowConfig	1630541525242	2	918
code/didWaitForWindowConfig	1630541525242	0	918
code/willShowPartsSplash	1630541525242	0	918
code/didShowPartsSplash	1630541525243	1	919
code/willLoadWorkbenchMain	1630541525259	16	935
code/didLoadWorkbenchMain	1630541529159	3900	4835
code/registerFilesystem/file	1630541529167	8	4843
code/registerFilesystem/vscode-userdata	1630541529167	0	4843
code/willInitWorkspaceService	1630541529173	6	4849
code/willInitStorage	1630541529174	1	4850
code/didInitStorage	1630541529228	54	4904
code/didInitWorkspaceService	1630541529292	64	4968
code/willStartWorkbench	1630541529301	9	4977
code/LifecyclePhase/Ready	1630541529305	4	4981
code/registerFilesystem/trustedDomains	1630541529454	149	5130
code/willRestoreEditors	1630541529791	337	5467
code/willRestoreViewlet	1630541529803	12	5479
code/willRestorePanel	1630541529827	24	5503
code/didRestoreViewlet	1630541529895	68	5571
code/didRestorePanel	1630541529895	0	5571
code/willResolveExplorer	1630541529935	40	5611
code/willLoadExtensions	1630541529978	43	5654
code/didRestoreEditors	1630541553060	23082	28736
code/LifecyclePhase/Restored	1630541553060	0	28736
code/didStartWorkbench	1630541553060	0	28736
code/didRemovePartsSplash	1630541553061	1	28737
code/willConnectSharedProcess	1630541553109	48	28785
code/willHandleExtensionPoints	1630541553255	146	28931
code/didHandleExtensionPoints	1630541553547	292	29223
code/didLoadExtensions	1630541553558	11	29234

Raw Perf Marks: workerExtHost

Name	Timestamp	Delta	Total
code/timeOrigin	1630541553167	0	0
code/extHost/willConnectToRenderer	1630541553946	779	779
code/extHost/didWaitForInitData	1630541554201	255	1034
code/extHost/didCreateServices	1630541554205	4	1038
code/extHost/willWaitForConfig	1630541554218	13	1051
code/extHost/didWaitForConfig	1630541554290	72	1123
code/extHost/didInitAPI	1630541554290	0	1123
code/extHost/ready	1630541554330	40	1163

Raw Perf Marks: localExtHost

Name	Timestamp	Delta	Total
code/timeOrigin	1630541530173	0	0
code/fork/start	1630541530493	320	320
code/fork/willLoadCode	1630541530554	61	381
code/extHost/willConnectToRenderer	1630541531345	791	1172
code/extHost/didConnectToRenderer	1630541531347	2	1174
code/extHost/didWaitForInitData	1630541554067	22720	23894
code/extHost/didCreateServices	1630541554087	20	23914
code/extHost/willWaitForConfig	1630541554094	7	23921
code/extHost/didWaitForConfig	1630541554389	295	24216
code/extHost/didInitAPI	1630541554390	1	24217
code/extHost/didInitProxyResolver	1630541554401	11	24228
code/extHost/ready	1630541554401	0	24228
code/extHost/willLoadExtensionCode/vscode.microsoft-authentication	1630541554554	153	24381
code/extHost/didLoadExtensionCode/vscode.microsoft-authentication	1630541554678	124	24505
code/extHost/willLoadExtensionCode/vscode.extension-editing	1630541554679	1	24506
code/extHost/didLoadExtensionCode/vscode.extension-editing	1630541554753	74	24580
code/extHost/willLoadExtensionCode/vscode.typescript-language-features	1630541554753	0	24580
code/extHost/didLoadExtensionCode/vscode.typescript-language-features	1630541554967	214	24794
code/extHost/willLoadExtensionCode/vscode.debug-auto-launch	1630541554968	1	24795
code/extHost/didLoadExtensionCode/vscode.debug-auto-launch	1630541554981	13	24808
code/extHost/willLoadExtensionCode/vscode.git	1630541554982	1	24809
code/extHost/didLoadExtensionCode/vscode.git	1630541555195	213	25022
code/extHost/willLoadExtensionCode/vscode.npm	1630541555195	0	25022
code/extHost/didLoadExtensionCode/vscode.npm	1630541555294	99	25121
code/extHost/willActivateExtension/vscode.microsoft-authentication	1630541555649	355	25476
code/extHost/willActivateExtension/vscode.extension-editing	1630541555676	27	25503
code/extHost/willActivateExtension/vscode.typescript-language-features	1630541555680	4	25507
code/extHost/willActivateExtension/vscode.debug-auto-launch	1630541555812	132	25639
code/extHost/willActivateExtension/vscode.git	1630541555818	6	25645
code/extHost/willActivateExtension/vscode.npm	1630541555830	12	25657
code/extHost/didActivateExtension/vscode.extension-editing	1630541555856	26	25683
code/extHost/didActivateExtension/vscode.typescript-language-features	1630541555856	0	25683
code/extHost/didActivateExtension/vscode.debug-auto-launch	1630541555856	0	25683
code/extHost/didActivateExtension/vscode.git	1630541556275	419	26102
code/extHost/willLoadExtensionCode/vscode.github	1630541556714	439	26541
code/extHost/didLoadExtensionCode/vscode.github	1630541556746	32	26573
code/extHost/willActivateExtension/vscode.github	1630541556865	119	26692
code/extHost/didActivateExtension/vscode.github	1630541556866	1	26693
code/extHost/didActivateExtension/vscode.microsoft-authentication	1630541556894	28	26721
code/extHost/willLoadExtensionCode/ms-vscode.js-debug	1630541556911	17	26738
code/extHost/didLoadExtensionCode/ms-vscode.js-debug	1630541559160	2249	28987
code/extHost/willActivateExtension/ms-vscode.js-debug	1630541559666	506	29493
code/extHost/didActivateExtension/ms-vscode.js-debug	1630541559686	20	29513
code/extHost/didActivateExtension/vscode.npm	1630541559687	1	29514

Node Cached Data Stats

cached data used

cached data missed

cached data rejected

cached data created (lazy, might need refreshes)

@alexdima alexdima added the candidate Issue identified as probable candidate for fixing in the next release label Sep 2, 2021
@alexdima alexdima added this to the August 2021 milestone Sep 2, 2021
@alexdima
Copy link
Member

alexdima commented Sep 2, 2021

@joyceerhl Do you have by any chance the minimap enabled? Does this reproduce when closing all instances and launching with code --disable-gpu?

I noticed that a method called renderLines takes a very long time (I think it might be the renderLines from the minimap code, not the renderLines from the editor's text), but also does a piece of code in xterm:

image

So my immediate reaction is that something is very very wrong on your computer around using <canvas> elements.

@deepak1556 I think we did an Electron update in Insiders, maybe some change came in around GPUs?

@sandy081
Copy link
Member

sandy081 commented Sep 2, 2021

After discussions in stand up we decided to defer it to September as it is not yet clear.

@sandy081 sandy081 modified the milestones: August 2021, September 2021 Sep 2, 2021
@sandy081 sandy081 removed the candidate Issue identified as probable candidate for fixing in the next release label Sep 2, 2021
@deepak1556
Copy link
Collaborator

deepak1556 commented Sep 2, 2021

@joyceerhl can you follow the steps below to get a trace from the runtime,

1) Start the app like

code-insiders --enable-gpu-service-tracing --enable-tracing="blink,cc,gpu,renderer.scheduler,sequence_manager,v8,toplevel,viz,disabled-by-default-viz.overdraw" --trace-startup-file="<fill-some-absolute-path-to-trace-filename.log>"

2) Once the window is loaded, quit the app
3) Log file will be generated at the path you have provided for --trace-startup-file
4) Repeat the above steps 1-3 for the stable build
5) Attach the logs from both runs

Can you also confirm what is your display resolution and scaling.

@joyceerhl
Copy link
Collaborator Author

If I start Insiders with --disable-gpu, the problem goes away.

@deepak1556 deepak1556 added chromium Issues and items related to Chromium upstream Issue identified as 'upstream' component related (exists outside of VS Code) gpu Issues concerning GPU related items labels Sep 2, 2021
@deepak1556
Copy link
Collaborator

@joyceerhl can you please provide the data for #132086 (comment), otherwise this issue will eventually be closed with no action. Thanks!

@joyceerhl
Copy link
Collaborator Author

Apologies for the delay, here are the log files:

gpu-startup-logs.zip

Display resolution: 3240 x 2160 (recommended setting)
Scale: 200% (recommended setting)

@deepak1556 deepak1556 removed the info-needed Issue requires more information from poster label Sep 8, 2021
@alexdima alexdima removed their assignment Sep 13, 2021
@deepak1556
Copy link
Collaborator

Minor update, I don't have the root cause yet but all the GL driver calls are slow in the insiders version even the initialization one (100ms vs 1s) on your device. Once the main branch is open again, I will publish newer runtime builds that has GL tracing enabled to get better insight via --enable-gpu-service-logging

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
chromium Issues and items related to Chromium gpu Issues concerning GPU related items insiders-released Patch has been released in VS Code Insiders perf-startup upstream Issue identified as 'upstream' component related (exists outside of VS Code) windows VS Code on Windows issues
Projects
None yet
Development

Successfully merging a pull request may close this issue.

7 participants
@bpasero @deepak1556 @lramos15 @alexdima @sandy081 @joyceerhl and others