100% CPU usage (macos)

[ssbarnea]

Issue Type: Bug

Since two days ago pylance seems to start a different thead that takes 100% CPU and never finishes.

I updated to daily insiders and it still happens. The thread remains open and taking all the CPU even after I quit vscode (and macos launcher no longer reports the as running). Still, the activity monitor shows Code Helper (Rendered) still running and taking all the cpu it can. I did a spindump of it https://gist.github.com/ssbarnea/28da5f10b5d50a7166ef5c425a7d7135

Even after killing it and starting again, it seems to do hte same. As this takes only on core, it may be harder to observe but it happening and the fan never stops.

Extension version: 2021.3.3-pre.1
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) i7-7700K CPU @ 4.20GHz (8 x 4200)
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)	5, 6, 6
Memory (System)	40.00GB (2.19GB free)
Process Argv	--crash-reporter-id 03ebe87f-b162-449a-862d-238cdfac955f
Screen Reader	no
VM	0%

A/B Experiments

vsliv368:30146709
vsreu685:30147344
python383:30185418
vspor879:30202332
vspor708:30202333
vspor363:30204092
vstry914:30276682
pythonvsdeb440:30248342
pythonvsded773:30248341
pythonvspyt875:30259475
pythontb:30265425
vscoresta800cf:30276762
vspre833:30267464
vsdfh931:30275552
vshan820cf:30276953

I am not sure if that is relevant by the default python interpreter path is configured to be /Users/ssbarnea/.pyenv/shims/python3 -- which happens to be python 3.9.2 installed using pyenv, so it matches the one I use in terminal.

[jakebailey]

Pylance's analysis does not run in the VS Code renderer. Can you check something like top/htop to see what the CLI args are for that process? That dump unfortunately doesn't list them (and I don't see pylance mentioned).

This could be similar to #1035 and may be the interpreter detection code in the core Python extension.

[ssbarnea]

It is Pylance and I tried to use vscode-insiders and even the pythonDiscoveryModule and I was not able to prevent it from happening, only workable solution was to switch to Jedi so far.

[jakebailey]

Thanks. Unfortunate that we show as "renderer" 🙁.

Do you have trace logs or an example project that may help us reproduce it?

If you set "python.analysis.indexing": false, does the issue go away?

[Timmmm]

I have exactly the same problem. Setting python.analysis.indexing to false does not solve it. VSCode also says that that is an unknown option, so maybe that's not the right setting?

Also, even when you quit VSCode entirely the pylance process keeps running, consuming 100% CPU.

Here's the output from the Python Language Server logs:

[Info  - 9:17:10 PM] Pylance language server 2021.3.2 (pyright 85309906) starting
[Info  - 9:17:10 PM] Server root directory: /Users/timh/.vscode/extensions/ms-python.vscode-pylance-2021.3.2/dist
[Info  - 9:17:10 PM] Background analysis(8) root directory: /Users/timh/.vscode/extensions/ms-python.vscode-pylance-2021.3.2/dist
[Info  - 9:17:10 PM] Background analysis(8) started
[Info  - 9:17:10 PM] Background analysis(4) root directory: /Users/timh/.vscode/extensions/ms-python.vscode-pylance-2021.3.2/dist
[Info  - 9:17:10 PM] Background analysis(2) root directory: /Users/timh/.vscode/extensions/ms-python.vscode-pylance-2021.3.2/dist
[Info  - 9:17:10 PM] Background analysis(4) started
[Info  - 9:17:10 PM] Background analysis(1) root directory: /Users/timh/.vscode/extensions/ms-python.vscode-pylance-2021.3.2/dist
[Info  - 9:17:10 PM] Background analysis(2) started
[Info  - 9:17:10 PM] Background analysis(6) root directory: /Users/timh/.vscode/extensions/ms-python.vscode-pylance-2021.3.2/dist
[Info  - 9:17:10 PM] Background analysis(1) started
[Info  - 9:17:10 PM] Background analysis(6) started
[Error - 9:17:10 PM] stubPath /Users/timh/workspace/the_project/subproject_a/typings is not a valid directory.
[Error - 9:17:11 PM] stubPath /Users/timh/workspace/the_project/subproject_b/typings is not a valid directory.

I can reproduce it for now, but unfortunately the code is all private. Is there something simple I can do to debug it? I tried sampling the process but it's just V8 stuff.

Wild guess - this is in a workspace with the_project and the_project/subproject_a both added as folders, so the files are available in two places, if you see what I mean. Is it possible you have some kind of infinite loop in that case?

[jakebailey]

VSCode also says that that is an unknown option, so maybe that's not the right setting?

It's a hidden setting; the graying out is expected.

Wild guess - this is in a workspace with the_project and the_project/subproject_a both added as folders, so the files are available in two places, if you see what I mean. Is it possible you have some kind of infinite loop in that case?

Do these folders by chance contain recursive symlinks? There's a known bug (fixed in the next release) that does lead to some infinite behavior, but it may not actually fix this.

Do you have many multi-root workspaces or many pyright execution environments?

It's a bit scary that we aren't quitting when the parent process ends... but that's something that VS Code or the init system is supposed to be handling. Unless I'm mistaken, I'd think that all UNIX-alikes will kill off processes which haven't been explicitly unparented if the parent process has exited. Back in MPLS, we watched for parent process exit to ensure that the process exits, but this doesn't solve the high CPU usage when it's actually supposed to be running.

One thing that may be interesting are the (even more) verbose logs, which you can enable with a pyrightconfig.json file:

{
	"verboseOutput": true
}

I understand your code is private, so I would not attach these at all, but it'd be interesting to see what (after a while) it's doing.

[ssbarnea]

For sure most of our projects do use symlinks, usually something like .cache/roles/foo -> ../../roles/foo is one such example and obviously the expected symlinks created by pip when installing packages as editable (pip install -e .).

Yes, most of the time I do have 4-5 and up to 10 python projects/folders open inside an Untitled workspace. All of them are using the same python version. I wonder if I should try to switch python version to use brew installed one instead of pyenv, just to rule out a bug specific to pyenv (I am not sure if the shimming is confusing pylance).

One of the very weird things around this bug is that the parent process appears to be null, and this explains why it was not killed when the app was killed. I am not sure what kind of tricks were used when starting this process that made it believe it has no parent.

I am going to try to other things during the day and update my answer, with bit of luck we will narrow it down.

[Timmmm]

which you can enable with a pyrightconfig.json file:

I tried putting that file in a few places but it didn't seem to have any effect. I get the exact same logs from the language server. :-/

But I managed to figure it out anyway! I thought I didn't have any symlinks in my code, but it turns out a recursive one was added by a Rust crate (cxx). Debugging this was a bit of a pain - here's what I went through:

I profiled the process with Instruments and it shows about 5k fstats in 4 seconds, which seemed supicious!

I tried the System Call Trace instrument and while it does capture the fstats unfortunately it isn't clever enough to show the actual paths (fstatfs64 just gets a file descriptor). I tried using the file descriptor and lsof to get the file paths, but I guess they are just opened for a split second and then closed again so I never saw the path.

Finally I tried using dtruss to trace the fopen() system calls. That didn't work, but I realised it is actually the access() syscall that I needed to trace, like this:

sudo dtruss -p 44665 -t access

At last, paths! But they are truncated at 255 characters. This is a dtrace option but unfortunately isn't exposed by dtruss, so what you have to do is:

cp /usr/bin/dtruss .
micro dtruss

# Add this line at the top of the script string (where it says "Define D Script":

#pragma D option strsize=1024

sudo ./dtruss -p 44665 -t access

That finally gives full paths and shows it is accessing recursive symlinks. So when's the next release? :-)

[jakebailey]

That finally gives full paths and shows it is accessing recursive symlinks. So when's the next release? :-)

Tomorrow. Hopefully this fixes all of the problems you both have been having. I really appreciate the debugging efforts you've done to trace this out. It's a bit difficult to tease this info out over a GitHub issue. 🙂

#1070 is the issue, for reference, but it's possible that there's another code path we've still missed for this (so I'll leave this open and not close it as a dupe for now).

One way to confirm is to downgrade to 2021.3.0 or 2021.3.1; the former didn't have symlink support and the later almost had it, so you should be able to see a difference.

[jakebailey]

We've just release 2021.3.3; if you could retest and see if the issue is fixed, that'd be appreciated.

[Timmmm]

Fixed for me, thanks!

[ssbarnea]

I got 2021.3.4-pre.1 and apparently it does seem fixed. I will know for sure before the end of the day.

[jakebailey]

At this point, I'm convinced this is fixed. We can reopen this if it's persisting. 2021.3.4 contains another symlink fix (handling broken links), but you would have seen crashes if that were in play.

[ArgoHA]

Hey there! I see similar behaviour now
100% utilisation of a core. In activity monitor it's called Electron, but I've checked pid and got this:

3990 100,0 1,8 451822000 294176 ?? R 9:59 1:19.95 /Applications/Visual Studio Code.app/Contents/MacOS/Electron --ms-enable-electron-run-as-node /Users/argosaakan/.vscode/extensions/ms-python.vscode-pylance-2022.2.1/dist/server.bundle.js --cancellationReceive=file:4e53a31ae5f1c51980edd9c6f67427bacbeed900c0 --node-ipc --clientProcessId=3908 argosaakan 4057 0,0 0,0 408637584 1760 s000 S+ 10:00 0:00.00 grep 3990

I tried to turn off pylance, vscode needed a restart after which that pid was gone. Then I turned on pylance again and in couple of seconds got that process back with 100% core utilisation

I am using m1 pro macbook, monterey 12.2, VSCode 1.64.2 (Universal)

[bschnurr]

Stay tuned for next release this Wednesday

[kavehv]

This is still happening to me on the latest VSCode 1.66.2 with what looks like pylance 2022.4.1.

[spmacdonald]

This is also happening to me on pylance v2022.10.30 and VSCode

Version: 1.72.2
Commit: d045a5eda657f4d7b676dedbfa7aab8207f8a075
Date: 2022-10-12T22:15:55.763Z (1 wk ago)
Electron: 19.0.17
Chromium: 102.0.5005.167
Node.js: 16.14.2
V8: 10.2.154.15-electron.0
OS: Darwin arm64 21.6.0
Sandboxed: No

It seems to be triggered when I have more than 1 VSCode window open (cmd-shift-N), I did not notice with previous versions of pylance/vscode...

I also see the pylance process continue to run after quitting vscode.

[MaskdDev]

Finding the same issue occurring on pylance 2022.10.40. Process continues to run even after VSCode is closed, and is using close to 100% of my CPU. Issue occurring on an intel-based mac.

[desprit]

Confirm it's happening on mac os m1.

Process is showing the following:

/Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper.app/Contents/Frameworks/Code Helper.app/Contents/MacOS/Code Helper --ms-enable-electron-run-as-node /Users/desprit/.vscode/extensions/ms-python.vscode-pylance-2022.10.40/dist/server.bundle.js --cancellationReceive=file:a35b792cbab96ad12f3a8e1e9b4604f57b29b7cf3e --node-ipc --clientProcessId=67127

[spmacdonald]

Hoping someone can triage this as high priority. VSCode is unusable for me right now with this bug.

[rchiodo]

See this issue here: #3554. The prerelease version should have the fix.