Consistent high cpu load in latest preview (v.2.48.31)

[tverboon]

Type: Bug

Issue Description

While loading projects CPU usage is consistently around and above 100% CPU. That's 1 core on Mac.

Steps to Reproduce

Start VSCode and load our solution with latest C# plugin.

Expected Behavior

After loading projects cpu usage should come down.

Actual Behavior

Keeps opening and closing files causing high cpu usage.

Logs

Latest preview v2.48.31

[LanguageServerHost] No request parameters given, using default language handler
[LanguageServerHost] [05:42:34.763][Start]workspace/buildOnlyDiagnosticIds
[LanguageServerHost] [05:42:34.763][Start]textDocument/didOpen
[LanguageServerHost] didOpen for virtualcsharp-razor:///Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml__virtual.cs
[LanguageServerHost] [05:42:34.763][End]textDocument/didOpen
[LanguageServerHost] [05:42:34.763][End]workspace/buildOnlyDiagnosticIds

Latest release v2.45.25

[LanguageServerHost] No request parameters given, using default language handler
[LanguageServerHost] [05:28:56.201][Start]textDocument/didOpen
[LanguageServerHost] didOpen for virtualcsharp-razor:///Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml__virtual.cs
[LanguageServerHost] [05:28:56.201][End]textDocument/didOpen

I hoped to only paste logs that are relevant, but I can upload everything when this is not enough.

The most obvious difference is, the parent directory file path is duplicated in the latest preview release.

/Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml__virtual.cs

It also seems to be only happening with razor files.

Razor logs:

[Warn  - 7:41:08 AM] [LSP][LanguageServer.GeneratedDocumentPublisher] Skipping publish of Html for /Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml because we've already published version 5, and this request is for 1.
[Warn  - 7:41:08 AM] [LSP][LanguageServer.GeneratedDocumentPublisher] Skipping publish of C# for /Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml because we've already published version 5, and this request is for 1.
[Warn  - 7:41:16 AM] [LSP][LanguageServer.GeneratedDocumentPublisher] Skipping publish of Html for /Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml because we've already published version 5, and this request is for 2.
[Warn  - 7:41:16 AM] [LSP][LanguageServer.GeneratedDocumentPublisher] Skipping publish of C# for /Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml because we've already published version 5, and this request is for 2.
[Warn  - 7:41:16 AM] [LSP][LanguageServer.GeneratedDocumentPublisher] Skipping publish of Html for /Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml because we've already published version 5, and this request is for 1.
[Warn  - 7:41:16 AM] [LSP][LanguageServer.GeneratedDocumentPublisher] Skipping publish of C# for /Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml because we've already published version 5, and this request is for 1.
[Warn  - 7:41:16 AM] [LSP][LanguageServer.GeneratedDocumentPublisher] Skipping publish of Html for /Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml because we've already published version 5, and this request is for 2.
[Warn  - 7:41:16 AM] [LSP][LanguageServer.GeneratedDocumentPublisher] Skipping publish of C# for /Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml because we've already published version 5, and this request is for 2.
[Client - 7:41:16 AM] File '/Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Users/tverboon/Desktop/Code/Midmid/src/Midmid.Shop.Common.Web/Views/Shared/DisplayTemplates/EmailAddress.cshtml' didn't exist in the Razor document list. This is likely because it's from outside the workspace.

The last line is warning that the file didn't exist, I am sure it doesn't because that path also has the duplicate parent folder.

Environment information

VSCode version: 1.93.1
C# Extension: 2.48.31
Using OmniSharp: false

Dotnet Information

.NET SDK: Version: 8.0.104 Commit: 034f91fcc0 Workload version: 8.0.100-manifests.9f663350

Runtime Environment:
OS Name: Mac OS X
OS Version: 14.6
OS Platform: Darwin
RID: osx-arm64
Base Path: /usr/local/share/dotnet/sdk/8.0.104/

.NET workloads installed:
Workload version: 8.0.100-manifests.9f663350
There are no installed workloads to display.

Host:
Version: 8.0.4
Architecture: arm64
Commit: 2d7eea2529

.NET SDKs installed:
6.0.300 [/usr/local/share/dotnet/sdk]
7.0.202 [/usr/local/share/dotnet/sdk]
8.0.104 [/usr/local/share/dotnet/sdk]

.NET runtimes installed:
Microsoft.AspNetCore.App 6.0.5 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
Microsoft.AspNetCore.App 7.0.4 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
Microsoft.AspNetCore.App 8.0.4 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
Microsoft.NETCore.App 6.0.5 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
Microsoft.NETCore.App 7.0.4 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
Microsoft.NETCore.App 8.0.4 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]

Other architectures found:
None

Environment variables:
Not set

global.json file:
Not found

Learn more:
https://aka.ms/dotnet/info

Download .NET:
https://aka.ms/dotnet/download

Visual Studio Code Extensions

Extension	Author	Version	Folder Name
cmake-language-support-vscode	josetr	0.0.9	josetr.cmake-language-support-vscode-0.0.9
cpptools	ms-vscode	1.21.6	ms-vscode.cpptools-1.21.6-darwin-arm64
cpptools-extension-pack	ms-vscode	1.3.0	ms-vscode.cpptools-extension-pack-1.3.0
cpptools-themes	ms-vscode	2.0.0	ms-vscode.cpptools-themes-2.0.0
csdevkit	ms-dotnettools	1.11.9	ms-dotnettools.csdevkit-1.11.9-darwin-arm64
csharp	ms-dotnettools	2.48.31	ms-dotnettools.csharp-2.48.31-darwin-arm64
github-vscode-theme	GitHub	6.3.4	github.github-vscode-theme-6.3.4
kubernetes-yaml-formatter	kennylong	1.1.0	kennylong.kubernetes-yaml-formatter-1.1.0-darwin-arm64
markdown-pdf	yzane	1.5.0	yzane.markdown-pdf-1.5.0
msbuild-project-tools	tintoy	0.6.5	tintoy.msbuild-project-tools-0.6.5
platformio-ide	platformio	3.3.3	platformio.platformio-ide-3.3.3-darwin-arm64
proto	peterj	0.0.4	peterj.proto-0.0.4
swift-lang	sswg	1.11.1	sswg.swift-lang-1.11.1
vscode-commons	redhat	0.0.6	redhat.vscode-commons-0.0.6
vscode-docker	ms-azuretools	1.29.2	ms-azuretools.vscode-docker-1.29.2
vscode-dotnet-runtime	ms-dotnettools	2.1.5	ms-dotnettools.vscode-dotnet-runtime-2.1.5
vscode-edit-csv	janisdd	0.10.0	janisdd.vscode-edit-csv-0.10.0
vscode-github-actions	github	0.26.5	github.vscode-github-actions-0.26.5
vscode-icons	vscode-icons-team	12.9.0	vscode-icons-team.vscode-icons-12.9.0
vscode-lldb	vadimcn	1.10.0	vadimcn.vscode-lldb-1.10.0
vscode-pull-request-github	GitHub	0.96.0	github.vscode-pull-request-github-0.96.0
vscode-sequence-diagrams	AleksandarDev	0.4.7	aleksandardev.vscode-sequence-diagrams-0.4.7
vscode-serial-monitor	ms-vscode	0.13.1	ms-vscode.vscode-serial-monitor-0.13.1
xcode-default-theme	smockle	2.0.24	smockle.xcode-default-theme-2.0.24
xml	DotJoshJohnson	2.5.1	dotjoshjohnson.xml-2.5.1

Extension version: 2.45.25
VS Code version: Code 1.93.1 (38c31bc77e0dd6ae88a4e9cc93428cc27a56ba40, 2024-09-11T17:20:05.685Z)
OS version: Darwin arm64 23.6.0
Modes:

System Info

Item	Value
CPUs	Apple M1 Max (10 x 2400)
GPU Status	2d_canvas: enabled canvas_oop_rasterization: enabled_on direct_rendering_display_compositor: disabled_off_ok gpu_compositing: enabled multiple_raster_threads: enabled_on opengl: enabled_on rasterization: enabled raw_draw: disabled_off_ok skia_graphite: disabled_off video_decode: enabled video_encode: enabled webgl: enabled webgl2: enabled webgpu: enabled webnn: disabled_off
Load (avg)	3, 6, 7
Memory (System)	32.00GB (5.91GB free)
Process Argv	--crash-reporter-id 516dbf53-3b0c-40b9-b808-0b110887c51d
Screen Reader	no
VM	0%

A/B Experiments

vsliv368cf:30146710
vspor879:30202332
vspor708:30202333
vspor363:30204092
vscod805:30301674
binariesv615:30325510
vsaa593cf:30376535
py29gd2263:31024239
c4g48928:30535728
azure-dev_surveyone:30548225
962ge761:30959799
pythongtdpath:30769146
welcomedialogc:30910334
pythonnoceb:30805159
asynctok:30898717
pythonmypyd1:30879173
2e7ec940:31000449
pythontbext0:30879054
accentitlementst:30995554
dsvsc016:30899300
dsvsc017:30899301
dsvsc018:30899302
cppperfnew:31000557
dsvsc020:30976470
pythonait:31006305
dsvsc021:30996838
0ee40948:31013168
a69g1124:31058053
dvdeprecation:31068756
dwnewjupyter:31046869
impr_priority:31102340
nativerepl2:31139839
refactort:31108082
pythonrstrctxt:31112756
flightc:31134773
wkspc-onlycs-t:31132770
wkspc-ranged-t:31125599
ei213698:31121563

[dibarbet]

@tverboon which process is causing the high CPU usage? You may need to post the process command line string to differentiate (on Mac the C# extension processes are usually all dotnet).

Once you've identified the process, could you collect a trace of it via dotnet-trace? You can email it to me ([email protected]) if you don't want to upload here.
Should be something like dotnet-trace collect -p <PID>

Thanks!

[tverboon]

It's actually Code Helper Plugin that is longer on 100%. This is not a dotnet process, so I couldn't trace it. The issue title isn't right. CPU comes down after 5 minutes. It's way slower. It seems project loading is just slower and dotnet processes seem to take longer before really start doing serious work. I am sorry, this is a horrible way to do problem solving. I created 2 video's.

Release

Release.mp4

Preview

Preview.mp4

Trace

Last part of loading trace of preview. I don't think this process is a problem at this point.

dotnet_20240925_074526.nettrace.zip

Summary

Consistent high CPU load is not the issue. Code Helper Plugin is using 100% cpu for 42 seconds in release. After this the code lense reference count is working. With the Preview release this take a little longer than 3 minutes.

[dibarbet]

@tverboon thanks, I will take a look at the trace to see if anything stands out. The Code Helper processes I believe are related to VSCode itself - however the high CPU usage in that process could be caused by an extension. I would try the following to help pinpoint if its VSCode or an extension causing the high CPU usage.

1. Disable all extensions, see if you can reproduce the issue - if so it is likely related to VSCode itself.
2. Enable just the C# extension, and see if you can reproduce the issue
3. Enable just C# + C# Dev Kit and see if you can reproduce the issue
4. If neither of those do it, keep re-enabling other extensions 1 by 1

[tverboon]

@dibarbet thanks. I will investigate the extensions tomorrow.

What do you think about the multiple attempts to load the razor files, because part of the directory path is duplicate causing files not being found? Could that be the issue why loading the projects takes much longer?

[dibarbet]

To confirm - loading projects w/ C# extension prerelease takes 3 minutes, but 42 seconds in release? And it is the same version of C# Dev Kit both times?

I wouldn't think that the Razor file loading attempts would slow down project loading, but tagging @ryzngard in case he's seen anything there. I'll need to dig into the trace to figure out more.

[tverboon]

To confirm - loading projects w/ C# extension prerelease takes 3 minutes, but 42 seconds in release? And it is the same version of C# Dev Kit both times?

Confirmed. Everything else is the same. I only switch between release and prerelease of the C# extension. Then I quit and start VSCode to start fresh.

[ryzngard]

File paths being wrong could be a bug, but I wouldn't expect it to fix over time. For the razor logs it would be a bit more helpful to enable trace logging with this config

"razor.server.trace": "Trace"

if you don't feel comfortable posting the logs on GH feel free to e-mail them to my MS address directly but please zip :)

[dibarbet]

Additionally, if you wouldn't mind collecting one more trace, but with a couple different parameters (for the slow preview version)

1. Make sure dotnet.server.trace is set to Trace
2. As soon as possible open the 'C#' output window logs to find the processId (should be near the top, and run dotnet-trace collect -p <PID> --providers Microsoft-DotNETCore-SampleProfiler - we need to capture the project loading steps to figure out what is causing it to take so long
   

And record until the 'Projects' spinner in the bottom left of VSCode stops spinning.

If you're having a hard time capturing it at the beginning, you can optionally set the dotnet.server.waitForDebugger setting which will wait 2 minutes after launching the process so you have time to start collecting the trace.

[tverboon]

@dibarbet
I ran trace collection twice. One for preview and one for release. The time before spinning stops is less than 3 minutes. It's ~1:20 for preview and ~0:40 for release. Big difference though is that release version quickly shows Codelense, but preview doesn't.

Preview

dotnet_20240926_081730.nettrace.zip

Release

dotnet_20240926_082134.nettrace.zip

[tverboon]

@ryzngard From the logging it seems that the right paths are loaded also. See attached.

5-Razor Log.1.log.zip

[dibarbet]

Thanks! Will take a look at these today.