microsoft / pylance-release

Documentation and issues for Pylance
Creative Commons Attribution 4.0 International
1.7k stars 769 forks source link

Pylance Crashing Constantly: `Error: Unhandled method python/isTrustedWorkspace` #5762

Open small-pants opened 5 months ago

small-pants commented 5 months ago

Pylance has been crashing constantly as of late (within the last week or so). Previous problems before the crashing began include high memory usage and unnecessary analysis of unopened files elsewhere in a large monorepo, but I am not yet sure if these things led up to this new issue with the size of the repo increasing each day or if they are unrelated.

Environment data

Expected behavior

Pylance should not crash on this method call

Actual behavior

Pylance crashes on this method call regardless of cursor location or user action at the time of crash

Logs

Error: Unhandled method python/isTrustedWorkspace
    at ce (/home/jp/.vscode-server/extensions/ms-python.vscode-pylance-2024.4.1/dist/vendor.bundle.js:2:1266027)
    at ae (/home/jp/.vscode-server/extensions/ms-python.vscode-pylance-2024.4.1/dist/vendor.bundle.js:2:1264186)
    at Immediate.<anonymous> (/home/jp/.vscode-server/extensions/ms-python.vscode-pylance-2024.4.1/dist/vendor.bundle.js:2:1260472)
    at processImmediate (node:internal/timers:476:21)

2024-04-14 03:41:16.348 [info] [Error - 3:41:16 AM] Server process exited with code 1.
2024-04-14 03:41:16.559 [info] [Error - 3:41:16 AM] Request textDocument/documentSymbol failed.
2024-04-14 03:41:16.559 [info] Error: Connection is disposed.
    at pe (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2308075)
    at Object.sendRequest (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2310379)
    at _.sendRequest (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2351280)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async Arguments.r (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2426736)
    at async d.provideDocumentSymbols (/home/jp/.vscode-server/cli/servers/Stable-5c3e652f63e798a5ac2f31ffd0d863669328dc4c/server/out/vs/workbench/api/node/extensionHostProcess.js:154:90504)
2024-04-14 03:41:16.563 [info] [Error - 3:41:16 AM] Request textDocument/foldingRange failed.
2024-04-14 03:41:16.563 [info] Error: Connection is disposed.
    at pe (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2308075)
    at Object.sendRequest (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2310379)
    at _.sendRequest (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2351280)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async K.provideFoldingRanges (/home/jp/.vscode-server/cli/servers/Stable-5c3e652f63e798a5ac2f31ffd0d863669328dc4c/server/out/vs/workbench/api/node/extensionHostProcess.js:154:114478)
2024-04-14 03:41:16.713 [info] [Error - 3:41:16 AM] Request textDocument/semanticTokens/full failed.
2024-04-14 03:41:16.713 [info] Error: Connection is disposed.
    at pe (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2308075)
    at Object.sendRequest (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2310379)
    at _.sendRequest (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2351280)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async te.provideDocumentSemanticTokens (/home/jp/.vscode-server/cli/servers/Stable-5c3e652f63e798a5ac2f31ffd0d863669328dc4c/server/out/vs/workbench/api/node/extensionHostProcess.js:154:102943)
2024-04-14 03:41:17.260 [info] [Error - 3:41:17 AM] Pylance has crashed 5 times in the last 3 minutes. Pylance will not be restarted. See the output for more information.
debonte commented 4 months ago

I haven't been able to repro this. Can you describe your setup a bit more? Given that .vscode-server is involved, it's some sort of remote scenario. Are you launching VS Code in WSL? Or via SSH? Or something else?

What versions of VS Code are you using on the client and server sides?

small-pants commented 4 months ago

I'm using an Ubuntu 22.04 VM hosted via Parallels on a MacOS host. VS is running via SSH. On the host side, I'm currently on v1.88.1.

debonte commented 4 months ago

What's the version of .vscode-server on the Ubuntu VM? Here's how I determined that on my Ubuntu WSL machine (similar scenario on Windows):

erikd@ERIKD:~/.vscode-server/bin/d037ac076cee195194f93ce6fe2bdfe2969cc82d/bin$ ./code-server --version
1.84.0
d037ac076cee195194f93ce6fe2bdfe2969cc82d
x64
small-pants commented 4 months ago

Conveniently there are five folders here:

drwxrwxr-x 6 jp jp 4096 Mar 13 15:04 019f4d1419fbc8219a181fab7892ebccf7ee29a2/
drwxrwxr-x 6 jp jp 4096 Feb 22 04:39 31c37ee8f63491495ac49e43b8544550fbae4533/
drwxrwxr-x 6 jp jp 4096 Apr  9 18:04 5c3e652f63e798a5ac2f31ffd0d863669328dc4c/
drwxrwxr-x 6 jp jp 4096 Apr  9 18:03 863d2581ecda6849923a2118d93a088b0745d9d6/
drwxrwxr-x 6 jp jp 4096 Mar  5 16:43 903b1e9d8990623e3d7da1df3d33db3e42d80eda/

And each of them has a different version:

jp@deltacomplex:~/.vscode-server/bin/019f4d1419fbc8219a181fab7892ebccf7ee29a2/bin$ ./code-server --version
1.87.0
019f4d1419fbc8219a181fab7892ebccf7ee29a2
x64

jp@deltacomplex:~/.vscode-server/bin/31c37ee8f63491495ac49e43b8544550fbae4533/bin$ ./code-server --version
1.86.1
31c37ee8f63491495ac49e43b8544550fbae4533
x64

jp@deltacomplex:~/.vscode-server/bin/5c3e652f63e798a5ac2f31ffd0d863669328dc4c/bin$ ./code-server --version
1.88.0
5c3e652f63e798a5ac2f31ffd0d863669328dc4c
x64

jp@deltacomplex:~/.vscode-server/bin/863d2581ecda6849923a2118d93a088b0745d9d6/bin$ ./code-server --version
1.87.2
863d2581ecda6849923a2118d93a088b0745d9d6
x64

jp@deltacomplex:~/.vscode-server/bin/903b1e9d8990623e3d7da1df3d33db3e42d80eda/bin$ ./code-server --version
1.86.2
903b1e9d8990623e3d7da1df3d33db3e42d80eda
x64

But the most recently modified folder appears to be the latest version, matching the host's vs version.

small-pants commented 4 months ago

I should also add that performance has degraded from bad to worse lately. It used to get stuck analyzing a file on occasion but now it's all the time. The only way to fix this is to wait a long time for the server to crash, then run the restart command, or just reload the entire window. Even files <500 lines will take >1s to analyze according to the log output.

heejaechang commented 4 months ago

it might be a dupe of this - https://github.com/microsoft/pylance-release/issues/5798

does it only repro with remote/WSL? can you provide us a live repro steps? if not possible, at least https://github.com/microsoft/pylance-release/wiki/Collecting-data-for-an-investigation.#collecting-cpuprofiles ? so we can take a look?

small-pants commented 4 months ago

Before I go profile this, I'm adding the logs for the most recent crash from a few minutes ago.


[33085:0x5b88a00]   234575 ms: Mark-sweep 4051.9 (4137.4) -> 4042.3 (4143.4) MB, 2280.3 / 0.0 ms  (average mu = 0.739, current mu = 0.031) allocation failure; scavenge might not succeed
[33085:0x5b88a00]   238144 ms: Mark-sweep 4058.2 (4143.4) -> 4048.6 (4149.6) MB, 3490.3 / 0.0 ms  (average mu = 0.499, current mu = 0.022) allocation failure; scavenge might not succeed

<--- JS stacktrace --->

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory

2024-04-29 20:03:52.789 [info]  1: 0xb85bc0 node::Abort() [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.790 [info]  2: 0xa94834  [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.792 [info]  3: 0xd66d10 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.793 [info]  4: 0xd670b7 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.794 [info]  5: 0xf447c5  [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.795 [info]  6: 0xf56cad v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.797 [info]  7: 0xf313ae v8::internal::HeapAllocator::AllocateRawWithLightRetrySlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.797 [info]  8: 0xf32777 v8::internal::HeapAllocator::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.799 [info]  9: 0xf1394a v8::internal::Factory::NewFillerObject(int, v8::internal::AllocationAlignment, v8::internal::AllocationType, v8::internal::AllocationOrigin) [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.800 [info] 10: 0x12d8caf v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:52.801 [info] 11: 0x1705b39  [/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/node]

2024-04-29 20:03:53.366 [info] [Error - 8:03:53 PM] Server process exited with signal SIGABRT.
2024-04-29 20:03:53.857 [info] [Error - 8:03:53 PM] Request textDocument/semanticTokens/full failed.
2024-04-29 20:03:53.858 [info] Error: Connection is disposed.
    at pe (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2308075)
    at Object.sendRequest (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2310379)
    at _.sendRequest (/home/jp/.vscode-server/extensions/ms-python.python-2024.4.1/out/client/extension.js:2:2351280)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async te.provideDocumentSemanticTokens (/home/jp/.vscode-server/cli/servers/Stable-e170252f762678dec6ca2cc69aba1570769a5d39/server/out/vs/workbench/api/node/extensionHostProcess.js:154:102943)
2024-04-29 20:04:18.176 [info] [Info  - 8:04:18 PM] Connection to server got closed. Server will restart.

I researched in the past about allocating additional memory but learned that it was not actually possible.

heejaechang commented 4 months ago

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory

so, it is OOM issue. we now provide a way to assign more memory - https://github.com/microsoft/pylance-release/blob/main/TROUBLESHOOTING.md#pylance-is-crashing

that said, not 100% sure whether it will work with WSL. I think it will but probably need to try first. you probably need to provide node path in WSL.

small-pants commented 4 months ago

Okay so few things.

  1. The OOM error is just one of the types of crashes that I get. The other and more unusual is the one I pasted in the OP.
  2. I'm not using WSL. I stated I'm hosting a headless Ubuntu VM through Parallels on MacOS and connecting VS with SSH.
  3. The suggested node executable setting only works if VS is in a local session.
image
rchiodo commented 4 months ago

Is there another tab in the settings dialog? I don't have a remote SSH connection, but in WSL we have this:

image

Which I believe translates to this settings.json for me:

image

small-pants commented 4 months ago

No I don't have that setting available. Whenever Pylance crashes, I get a notification message that asks me if I want to change the node executable. If I click "Yes" it takes me to the settings menu and attempts to search for the setting shown in your screenshot, but there are no results. It doesn't exist in this style of remote connection.

rchiodo commented 4 months ago

I tried SSH. I have that setting available on this separate tab:

image

What's the version of the Remote SSH extension? Maybe that's what provides this. Alternatively you can just edit this file:

image

If you add something like this:

{
    "python.analysis.nodeExecutable": "/home/azureuser/.nvm/versions/node/v18.20.2/bin/node"
}

That should fix the OOM issue. I installed node using nvm

small-pants commented 4 months ago

I recreated my remote workspace and suddenly the setting is available under that tab (which is fun in itself). I've added the node-options=--max_old_space_size=4096 option to my .npmrc and I'm hoping for the best in terms of the OOM error. I should ask though, if it is expected for Pylance to take 4,000ms to analyze a pytest file with ~800 lines. This seems to be about average, almost regardless of file size.

As for the error I originally posted about, I am waiting for it to show up again but it seems like something to be investigated.

rchiodo commented 4 months ago

The original error you reported was something we used to get when things were out of sync. I believe it shouldn't happen anymore if your python extension and pylance extension are the latest versions.

As far as analysis time, analysis is almost always dependent upon the import tree. So the contents of the file are not likely the root issue but rather the list of dependencies that are pulled in.

I believe @heejaechang added new settings in this PR that should allow us to figure out what imports are causing your slowdown.

You'd put these three settings in your workspace or remote settings.json:

   "python.analysis.logLevel": "Trace",
  "python.analysis.logTypeEvaluationTime": true,
  "python.analysis.typeEvaluationTimeThreshold": 1000,

That would generate a log that shows what methods we went through that are taking so long. Or if you can share your repository we can try debugging it on our side.

kohtala commented 1 month ago

I was having pylance crashing after code upgrade on Windows and ssh remote Linux upgrade. I have several windows open and a few with the same remote ssh-host with different projects.

The crashing seems to have cleared with closing code and checking what code related processes are left running on the remote with pstree. killall -1 node and killall -1 code-b1c0a14de1 processes to clean these leftover processes, restart code and it came up fine.