High CPU usage and loose of git function

as-85 commented 3 years ago

Issue Type: Bug

Hi, on my Mac I have the following issue which can be reproduced this way: Open VScode (Workspace loaded) the close VScode (with the x on left upper corner) but not exit it. Then if you open VScode again by open worspace from last opened files all git functions loosing and the process "Code Helper (Rederer)" runs on high cpu usage until you recreate your workspace. So exit VScode, remove your workspace configuration, restart VScode and create a new workspace to resolve the cpu issue and activate git functionallity.

VS Code version: Code 1.54.3 (2b9aebd5354a3629c3aba0a5f5df49f43d6689f8, 2021-03-15T11:57:12.728Z) OS version: Darwin x64 20.3.0

System Info

|Item|Value| |---|---| |CPUs|Intel(R) Core(TM) i9-9980HK CPU @ 2.40GHz (16 x 2400)| |GPU Status|2d_canvas: enabled
gpu_compositing: enabled
metal: disabled_off
multiple_raster_threads: enabled_on
oop_rasterization: enabled
opengl: enabled_on
protected_video_decode: unavailable_off
rasterization: enabled
skia_renderer: disabled_off_ok
video_decode: enabled
webgl: enabled
webgl2: enabled| |Load (avg)|2, 2, 3| |Memory (System)|64.00GB (43.29GB free)| |Process Argv|--crash-reporter-id dd747b07-6cb5-4fa2-b35a-3ad2c04fcb15| |Screen Reader|no| |VM|0%|

Extensions (8)

Extension|Author (truncated)|Version ---|---|--- vscode-intelephense-client|bme|1.6.3 gitlens|eam|11.3.0 php-debug|fel|1.14.12 php-intellisense|fel|2.3.14 php-pack|fel|1.0.2 vscode-docker|ms-|1.11.0 vscode-language-pack-de|MS-|1.54.2 php-docblocker|nei|2.1.0

A/B Experiments

``` vsliv368cf:30146710 vsreu685:30147344 python383cf:30185419 vspor879:30202332 vspor708:30202333 vspor363:30204092 vswsl492:30256859 pythonvsdeb440:30248342 pythonvsded773:30248341 pythonvspyt875:30259475 pythonvsnew554cf:30281909 pythontbcf:30265426 wslfolderdoc:30282074 vspre833cf:30267465 pythonptprofiler:30281270 vshan820cf:30276953 ```

as-85 commented 3 years ago

I have tested other option. You can create new workspace and then, if you have saved the old one, you can copy it over the new and all seems fine.

deepak1556 commented 3 years ago

Can you provide the output of code --status during the high cpu usage.

as-85 commented 3 years ago

For sure:

Version: Code 1.55.0 (c185983a683d14c396952dd432459097bc7f757f, 2021-03-30T16:01:05.981Z) OS Version: Darwin x64 20.3.0 CPUs: Intel(R) Core(TM) i9-9980HK CPU @ 2.40GHz (16 x 2400) Memory (System): 64.00GB (48.92GB free) Load (avg): 3, 2, 1 VM: 0% Screen Reader: no Process Argv: --crash-reporter-id dd747b07-6cb5-4fa2-b35a-3ad2c04fcb15 GPU Status: 2d_canvas: enabled gpu_compositing: enabled metal: disabled_off multiple_raster_threads: enabled_on oop_rasterization: enabled opengl: enabled_on protected_video_decode: unavailable_off rasterization: enabled skia_renderer: disabled_off_ok video_decode: enabled webgl: enabled webgl2: enabled

CPU % Mem MB PID Process 0 131 3668 code main 0 66 3674 gpu-process 0 0 3676 utility 106 262 3677 window (Willkommen — testworkspace (Arbeitsbereich)) 53 131 3687 extensionHost 0 66 3688 watcherService 0 131 3686 shared-process 0 66 3689 ptyHost 0 0 3692 /bin/zsh -l 0 0 3846 bash /usr/local/bin/code --status 3 66 3856 electron_node cli.js

as-85 commented 3 years ago

I think I have found the error.

I can recreate the behavior as follows: If I close VScode without having opened a file, then the error occurs immediately after startup. If I now open a file, close VScode and then restart it, the error is gone.

Errors are also written in the log in the event of an error. Log file is attached.

Maybe this helps further. 1617387806349.log

deepak1556 commented 3 years ago

Can you follow the steps at https://github.com/microsoft/vscode/wiki/Performance-Issues#profiling-the-renderer-process and attach the cpu profile for the window. And follow the steps at https://github.com/microsoft/vscode/wiki/Performance-Issues#profile-the-running-extensions to get the extension host profile.

as-85 commented 3 years ago

I have created the window CPU profile but I can't create the other one because the recording button not working with "active issue". CPU profile attached. CPU-20210402T214539.cpuprofile.zip

deepak1556 commented 3 years ago

Thanks for the profile, there is high volume of serialization failures for messages from extension host. Looping in @alexdima for further investigation.

@as-85 can you do the following next step,

1) Close all instances of the app and launch the app with code --verbose --logExtensionHostCommunication, attach the logs from the terminal when you see the high cpu usage 2) Follow the steps at https://code.visualstudio.com/blogs/2021/02/16/extension-bisect to find the problematic extension.

as-85 commented 3 years ago

Hi deepak1556, I'm not sure how to attache the log. I have created one with aprox. 400MB but with confidential data. I can provide but not public. For step 2, I have disabled all extensions but the issue still occurs.

alexdima commented 3 years ago

@as-85 Thank you for the CPU profile. I confirm that there is some sort of endless ping-pong going on between the renderer process and the extension host. However, it is not clear what exactly is causing this or what the ping pong is about.

You can send me the log you have collected at the email address displayed in my GitHub profile. If you notice repeating patterns, you can send only the repeating patterns. An alternative investigation avenue would be to use extension bisect to track down which of your extensions is causing this:

run F1 > Help: Start Extension Bisect
(this will restart VS Code with half of your extensions disabled)
try to do the steps which reproduce the problem
if the problem reproduces, click "This is bad" (this narrows down the problematic extension to the half which was enabled)
if the problem does not reproduce, click "Good now" (this narrows down the problematic extension to the half which was disabled)
these steps will repeat until the problematic extension is found

initial	step	final

as-85 commented 3 years ago

@alexdima I have send you the logs via download link by email.

I tried two things with the Extension Bisect:

With active error (high CPU usage) I started the extension Bisect and the error remained. So I clicked "This is bad" and the diagnosis was over.

With inactive error I clicked "All Good" every time after waiting a bit and checking the activity indicator. Here I could not reproduce any error.

I have a feeling it's the GIT extension, because as soon as VScode starts without GIT integration (because of the error), the CPU usage is very high. If I open a file and restart VScode (this is how I have always been able to fix it so far) the GIT integration is available again and no problems with the CPU.

alexdima commented 3 years ago

@as-85 Thank you for the logs. The root cause for the high-CPU is the fact that the renderer side is not initializing the extension host communication correctly (pieces of it are not up):

Specifically MainThreadErrors leads to a ping-pong recursion across the two processes. From the log:

Error: Unknown actor MainThreadTerminalService
Error: Unknown actor MainThreadFileSystem
Error: Unknown actor MainThreadWindow
Error: Unknown actor MainThreadSearch
Error: Unknown actor MainThreadTask
Error: Unknown actor MainThreadTask
Error: Unknown actor MainThreadErrors
Error: Unknown actor MainThreadErrors

I don't see any clear reason why those pieces of the extension host would not be up and running on the renderer side, the only error that I see before that is:

Error: Handler already set!
    at c.setHandler (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1558:5176)
    at l.registerListeners (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1564:3223)
    at new l (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1564:3099)
    at C._createInstance (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:15342)
    at C.createInstance (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:14761)
    at new G (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2100:27062)
    at C._createInstance (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:15342)
    at file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:17522
    at B._executor (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:68:18723)
    at B.get value [as value] (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:68:18920)
    at Object.get (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:17623)
    at new x (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2069:5448)
    at C._createInstance (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:15342)
    at C.createInstance (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:14761)
    at L.createView (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2425:35407)
    at L.createView (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2789:131705)
    at L.onDidAddViewDescriptors (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2425:36831)
    at file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2425:32740
    at c.fire (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:60:1836)
    at d.triggerOnDidAddVisibleViewDescriptors (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2145:10020)
    at d.onDidChangeContext (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2145:14207)
    at file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2145:6878
    at c.fire (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:60:1836)
    at file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:58:58790
    at g.fire (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:60:1836)
    at g.resume (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:60:2476)
    at n.bufferChangeEvents (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:633:89598)
    at Jt.onDidChangeActiveViews (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2789:80952)
    at Jt.<anonymous> (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2789:79529)
    at c.fire (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:60:1856)
    at d.onDidChangeContext (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2145:14040)
    at file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2145:6878
    at c.fire (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:60:1836)
    at file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:58:58790
    at g.fire (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:60:1836)
    at g.resume (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:60:2476)
    at n.bufferChangeEvents (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:633:89598)
    at new G (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2100:27331)
    at C._createInstance (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:15342)
    at file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:17522
    at B._executor (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:68:18723)
    at B.get value [as value] (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:68:18920)
    at Object.get (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:17623)
    at k.registerListeners (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2100:49682)
    at new k (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:2100:49597)
    at C._createInstance (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:15342)
    at C.createInstance (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:624:14761)
    at v.safeCreateInstance (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1608:58965)
    at v.doInstantiateByPhase (file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1608:58744)
    at file:///Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1608:58586

And this error is also very weird. The call site of this exception is https://github.com/microsoft/vscode/blob/3986914a04049303af8552e7c51da3076a2497f2/src/vs/workbench/contrib/debug/browser/debugAdapterManager.ts#L55 since that is the only .setHandler caller that is in a method called registerListeners . That one is instantiated only once, so it does not appear possible that the code could have executed before. cc @isidorn

@as-85 Does this still reproduce for you on our latest stable 1.55?

isidorn commented 3 years ago

Yes, that code should execute only once, since we have only one instance of the debugAdapterManager overall.

as-85 commented 3 years ago

@alexdima Yes, I can reproduce the error with this Version: Version: 1.55.2 Commit: 3c4e3df9e89829dce27b7b5c24508306b151f30d Datum: 2021-04-13T09:36:32.643Z Electron: 11.3.0 Chrome: 87.0.4280.141 Node.js: 12.18.3 V8: 8.7.220.31-electron.0 Betriebssystem: Darwin x64 20.3.0

alexdima commented 3 years ago

@jrieken This stack that we see could only happen if a service is instantiated twice. Do you think that would ever be possible?

@as-85 Perhaps there is some kind of problem with code caching or some other weird, exotic thing causing this. Could I please ask that you try our Insiders which has a separate user data dir and which will execute fresh on your system?

jrieken commented 3 years ago

@jrieken This stack that we see could only happen if a service is instantiated twice. Do you think that would ever be possible?

The only possibility would be if a child instantiation service is created and inside that the service is refined, but in normal usage this shouldn't never happen

as-85 commented 3 years ago

@as-85 Perhaps there is some kind of problem with code caching or some other weird, exotic thing causing this. Could I please ask that you try our Insiders which has a separate user data dir and which will execute fresh on your system?

It looks like the issue does not occur with the Insiders version. I will use it for a while and come back to you, if I get in error again.

microsoft / vscode

High CPU usage and loose of git function #120132