Code snippet makes the Semantic highlighting very slow

[Goldensteev]

Environment data

• Language Server version: 2022.2.1
• OS and version: win32 x64
• Python version (and distribution if applicable, e.g. Anaconda): 3.9.1
• python.analysis.indexing: null
• python.analysis.typeCheckingMode: off

Expected behaviour

Expect Pylance to hightlight my code in seconds as it's been doing for the past few weeks with even longer code snippets

Actual behaviour

Semantic Highlighting has been very slow or stuck

Logs

Python Language Server Log

[Info  - 16:23:51] (13464) Pylance language server 2022.2.1 (pyright 618f54ed) starting
[Info  - 16:23:51] (13464) Server root directory: c:\Users\StevenFletcher\.vscode\extensions\ms-python.vscode-pylance-2022.2.1\dist
[Info  - 16:23:51] (13464) No configuration file found.
[Info  - 16:23:51] (13464) No pyproject.toml file found.
[Info  - 16:23:51] (13464) Setting pythonPath for service "cartographie-ecosysteme-snds": "c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\base39\Scripts\python.exe"
[Warn  - 16:23:51] (13464) stubPath c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\typings is not a valid directory.
[Info  - 16:23:51] (13464) Assuming Python version 3.9
[Info  - 16:23:51] (13464) Assuming Python platform Windows
[Info  - 16:23:52] (13464) Searching for source files
[Info  - 16:23:52] (13464) Auto-excluding c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\base39
[Info  - 16:23:52] (13464) Found 18 source files
[Info  - 16:23:52] (13464) Background analysis(1) root directory: c:\Users\StevenFletcher\.vscode\extensions\ms-python.vscode-pylance-2022.2.1\dist
[Info  - 16:23:52] (13464) Background analysis(1) started
[Info  - 16:23:53] (13464) Indexer background runner(2) root directory: c:\Users\StevenFletcher\.vscode\extensions\ms-python.vscode-pylance-2022.2.1\dist (index)
[Info  - 16:23:53] (13464) Indexing(2) started
[Info  - 16:24:00] (13464) [IDX(2)] Long operation: index execution environment c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds (5671ms)
[Info  - 16:24:00] (13464) [IDX(2)] Long operation: index libraries c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds (6925ms)
[Info  - 16:24:00] (13464) Indexer done(2). indexed 572 files
[Info  - 16:27:48] (13464) [BG(1)] Long operation: getSemanticTokens full at c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\dashboard.py (235523ms)

Code Snippet / Additional information

slowdown coming from this local import

import dataprep

[juliocepar]

Same issue here. The highlighting is running very slow after I updated Pylance extension in VS Code.

[erictraut]

My, that's quite an expression you have!

Performing type analysis for such a deeply nested expression is computationally expensive. I can look at ways we might be able to speed up this case, but I'll need additional repro steps. This expression is referencing a bunch of symbols whose origin are not clear. For example, I don't know where app or dbc or dash_table come from. Would you be willing to produce a self-contained minimal repro?

If you're looking for a workaround, you can break up the expression into separate expressions that are saved to intermediate variables.

[Goldensteev]

Thanks For the answer!
I was indeed going to break up the expression into smaller pieces so i guess that'll solve this issue like that.
Still i am surprised that it takes that long even with so many nested expressions, but that is because i don't know the ins and outs of pylance !
The repo this file is in should be going open source soon so ill be able to share it with you then. If i have time i'll try and supply you with a minimal working self contained file before.
To answer your questions on the origin of app or dbc and dash_table they come from a library called Dash

from dash import dash, dash_table, dcc, htm
import dash_bootstrap_components as dbc

app = dash.Dash(
    __name__,
    external_stylesheets=[dbc.themes.LUMEN],
)

[Dr-Irv]

I have a large file (almost 3800 lines) where 2022.2.1 took almost 5 minutes to check the file (as reported by the output log)
Version 2022.2.0 took 4 seconds on the same file.

@erictraut - something funky has happened with the 2022.2.1 release

[erictraut]

@Dr-Irv, the issue you're seeing is probably unrelated to this bug report. If you can provide more details (preferably in a separate bug report), that would be appreciated. I have a theory about why you might be seeing this with 2022.2.1, but I'll need additional details to help confirm. I suspect it's this: microsoft/pyright#3008.

[Dr-Irv]

@Dr-Irv, the issue you're seeing is probably unrelated to this bug report. If you can provide more details (preferably in a separate bug report), that would be appreciated. I have a theory about why you might be seeing this with 2022.2.1, but I'll need additional details to help confirm. I suspect it's this: microsoft/pyright#3008.

I can open up a new issue but not sure what to provide. I can't share the code. I just know the performance got significantly worse, and we are seeing this on many files. The output log from the server shows the analysis time grew. Tell me what you need and I can open a new issue.

[erictraut]

Ah, I was hoping you'd be able to provide a repro case that I could look into. If it's not too much to ask, could you see whether the problem started happening between Pyright 1.1.218 and 1.1.219?

[Dr-Irv]

Ah, I was hoping you'd be able to provide a repro case that I could look into. If it's not too much to ask, could you see whether the problem started happening between Pyright 1.1.218 and 1.1.219?

How? I only use it within VS Code. How can I specify the pyright version with VS Code? And if it is command-line, how do I do it so that it uses the VS Code provided type stubs? You have to give me more precise instructions on how to do that test.

[erictraut]

@Dr-Irv, I found a different repro that confirmed my theory. I have a fix in place, and it will be included in the next release. As I mentioned, I don't think your performance slow-down is related to the issue in this particular bug report.

[Dr-Irv]

@Dr-Irv, I found a different repro that confirmed my theory. I have a fix in place, and it will be included in the next release. As I mentioned, I don't think your performance slow-down is related to the issue in this particular bug report.

So we have to wait 5 days to get the release? Should we go back to 2022.2.0 to avoid this? Or is there some other workaround? It's killing our developer productivity right now.

[Goldensteev]

So here is a repo with the original file and a modified file which still has nested expressions. Funnily enough the modified file runs way faster so something i removed is causing a massive slowdown.

test.py

[Info  - 11:53:53] (14316) Pylance language server 2022.2.1 (pyright 618f54ed) starting
[Info  - 11:53:53] (14316) Server root directory: c:\Users\StevenFletcher\.vscode\extensions\ms-python.vscode-pylance-2022.2.1\dist
[Info  - 11:53:53] (14316) No configuration file found.
[Info  - 11:53:53] (14316) No pyproject.toml file found.
[Info  - 11:53:53] (14316) Setting pythonPath for service "cartographie-ecosysteme-snds": "c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\base39\Scripts\python.exe"
[Warn  - 11:53:53] (14316) stubPath c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\typings is not a valid directory.
[Info  - 11:53:53] (14316) Assuming Python version 3.9
[Info  - 11:53:53] (14316) Assuming Python platform Windows
[Info  - 11:53:54] (14316) Searching for source files
[Info  - 11:53:54] (14316) Auto-excluding c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\base39
[Info  - 11:53:54] (14316) Found 10 source files
[Info  - 11:53:54] (14316) Background analysis(1) root directory: c:\Users\StevenFletcher\.vscode\extensions\ms-python.vscode-pylance-2022.2.1\dist
[Info  - 11:53:54] (14316) Background analysis(1) started
[Info  - 11:53:54] (14316) Indexer background runner(2) root directory: c:\Users\StevenFletcher\.vscode\extensions\ms-python.vscode-pylance-2022.2.1\dist (index)
[Info  - 11:53:54] (14316) Indexing(2) started
[Info  - 11:53:58] (14316) [BG(1)] Long operation: checking: c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\test.py (3202ms)
[Info  - 11:53:58] (14316) [BG(1)] Long operation: analyzing: c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\test.py (3599ms)
[Info  - 11:54:06] (14316) [IDX(2)] Long operation: index execution environment c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds (10251ms)
[Info  - 11:54:06] (14316) [IDX(2)] Long operation: index libraries c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds (11408ms)
[Info  - 11:54:06] (14316) Indexer done(2). indexed 572 files

vs dashboard.py

[Info  - 11:18:37] (32228) Pylance language server 2022.2.1 (pyright 618f54ed) starting
[Info  - 11:18:37] (32228) Server root directory: c:\Users\StevenFletcher\.vscode\extensions\ms-python.vscode-pylance-2022.2.1\dist
[Info  - 11:18:37] (32228) No configuration file found.
[Info  - 11:18:37] (32228) No pyproject.toml file found.
[Info  - 11:18:37] (32228) Setting pythonPath for service "cartographie-ecosysteme-snds": "c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\base39\Scripts\python.exe"
[Warn  - 11:18:37] (32228) stubPath c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\typings is not a valid directory.
[Info  - 11:18:37] (32228) Assuming Python version 3.9
[Info  - 11:18:37] (32228) Assuming Python platform Windows
[Info  - 11:18:37] (32228) Searching for source files
[Info  - 11:18:37] (32228) Auto-excluding c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\base39
[Info  - 11:18:37] (32228) Found 10 source files
[Info  - 11:18:37] (32228) Background analysis(1) root directory: c:\Users\StevenFletcher\.vscode\extensions\ms-python.vscode-pylance-2022.2.1\dist
[Info  - 11:18:37] (32228) Background analysis(1) started
[Info  - 11:18:38] (32228) Indexer background runner(2) root directory: c:\Users\StevenFletcher\.vscode\extensions\ms-python.vscode-pylance-2022.2.1\dist (index)
[Info  - 11:18:38] (32228) Indexing(2) started
[Info  - 11:18:44] (32228) [IDX(2)] Long operation: index execution environment c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds (4639ms)
[Info  - 11:18:44] (32228) [IDX(2)] Long operation: index libraries c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds (6109ms)
[Info  - 11:18:44] (32228) Indexer done(2). indexed 572 files
[Info  - 11:49:20] (32228) [BG(1)] Long operation: checking: c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\dashboard.py (1841617ms)
[Info  - 11:49:20] (32228) [BG(1)] Long operation: analyzing: c:\Users\StevenFletcher\Documents\workspace\cartographie-ecosysteme-snds\dashboard.py (1842110ms)

[erictraut]

@Goldensteev, thanks for preparing the repro. Unfortunately, I'm not able to reproduce the problem you're seeing. The performance looks fine to me (nearly instantaneous semantic highlighting) when using the latest version of pylance. So there must be some additional context I need.

I was able to figure out all of the sources of imports except for the package called scripts. That import could be contributing to the slowdown. Could you tell me where scripts comes from? I didn't see any obvious candidate packages called scripts in the pypi directory. Perhaps it's a local source file that you didn't include in your repro?

Do you have any other non-default "python.analyzer" settings configured in your workspace?

[ssssshong]

Same issue here! Semantic highlighting, code completion, parameter suggestions, etc., get super-slowed with 100% cpu usage in Pylance version 2022.2.1. I downgrade to 2022.2.0 and it seems to work fine.

[Goldensteev]

@erictraut So I have been doing a bit of investigation on my own after what you said and I have discovered what is making the semantic highlighting super slow and it's the local import import dataprep
If i comment this line, the highlighting is done very quickly.
What's even more interesting is if i add the code bellow to test.py it still is very fast.

import dataprep
all_data = dataprep.DashboardData("query_results/new_query.pkl")

So this import combined with something in the dashboard.py file is missing is making the highlighting very slow

scripts is a local package and dataprep is a local file. I don't have any value overwriting any default python.analyzer config in my workspace

I have updated the repo and added dataprep

[erictraut]

I'm still not able to repro the slow behavior with the code you provided in your repo. The import dataprep statement was commented out, so I uncommented it. Is there anything else I need to do to repro the problem? What I see is about a 3 second lag for semantic tokens the first time I open the file. That's reasonable given the complexity of that file and the files it imports. After it is opened the first time, semantic tokens appear immediately when I open the file subsequent times in the same session. It sounds like you're seeing something different?

[Goldensteev]

Okay so i have pushed on the repo my .vscode folder which hopefully should make you be able to replicate the Issue i am having as i can replicate it in the repro.
Yes i am seeing something different indeed. When i first load the file with the commented import, i get a fast Highlighting process as per the image

but as soon as i uncomment the import, i get what seems to be an infinite analysis as per image


5 mins and file is still not highlighted properly and all subsequent files will not be highlighted as it's stuck on this one

Also as mentioned, the test file which is a modified dashboard file does work, so it's something specific to the dashboard file and that import.

Hopefully with all this you are able to pinpoint the Issue and replicate it locally!

[Dr-Irv]

Here's another sample. Just pull the pandas repo at https://github.com/pandas-dev/pandas . Open up pandas/core/series.py. I see the following in the log:

[Info  - 8:08:09 AM] (18468) [BG(1)] Long operation: getSemanticTokens full at c:\Code\pandas_dev\mypytest\pandas\core\series.py (16631ms)
[Info  - 8:08:09 AM] (18468) Emptying type cache to avoid heap overflow. Heap size used: 1604MB
[Info  - 8:08:26 AM] (18468) [BG(1)] Long operation: checking: c:\Code\pandas_dev\mypytest\pandas\core\series.py (16387ms)
[Info  - 8:08:26 AM] (18468) [BG(1)] Long operation: analyzing: c:\Code\pandas_dev\mypytest\pandas\core\series.py (16387ms)
[Info  - 8:08:33 AM] (18468) Emptying type cache to avoid heap overflow. Heap size used: 2055MB
[Info  - 8:08:43 AM] (18468) Emptying type cache to avoid heap overflow. Heap size used: 2422MB
[Warn  - 8:08:46 AM] (18468) Workspace indexing has hit its upper limit: 2000 files

With pylance 2022.2.0, it's 3 times faster:

[Info  - 8:11:17 AM] (29416) [BG(1)] Long operation: checking: c:\Code\pandas_dev\mypytest\pandas\core\series.py (5955ms)
[Info  - 8:11:17 AM] (29416) [BG(1)] Long operation: analyzing: c:\Code\pandas_dev\mypytest\pandas\core\series.py (6367ms)

Not as dramatic a difference on my private code, but still significant.

Or for pandas/core/generic.py:
pylance 2022.2.1:

[Info  - 8:17:21 AM] (12860) [BG(1)] Long operation: checking: c:\Code\pandas_dev\mypytest\pandas\core\generic.py (19488ms)
[Info  - 8:17:21 AM] (12860) [BG(1)] Long operation: analyzing: c:\Code\pandas_dev\mypytest\pandas\core\generic.py (19488ms)

pylance 2022.2.0:

[Info  - 8:16:04 AM] (29416) [BG(1)] Long operation: checking: c:\Code\pandas_dev\mypytest\pandas\core\generic.py (2219ms)
[Info  - 8:16:04 AM] (29416) [BG(1)] Long operation: analyzing: c:\Code\pandas_dev\mypytest\pandas\core\generic.py (2449ms)

Almost 10 times slower.

[erictraut]

@Dr-Irv, we understand the issue you're seeing, and it should be addressed in this week's Pylance release.

@Goldensteev, I'm still not seeing the same behavior you're reporting. Here are the steps I'm using to try to reproduce the issue. Please let me know if I have these correct.

1. Clone the repo here.
2. Make sure Pylance v2022.2.1 is installed.
3. Open the root directory from the cloned repo and open the file dashboard.py
4. Uncomment the line # import dataprep

Here's what I see prior to uncommenting the import:

[Info  - 8:25:46 AM] (45055) [BG(1)] Long operation: getSemanticTokens full at /xxx/Issue2366-pylance/dashboard.py (2565ms)

Here's what I see after uncommenting the import:

[Info  - 8:27:01 AM] (45197) [BG(1)] Long operation: getSemanticTokens full at /xxx/Issue2366-pylance/dashboard.py (5100ms)

Both of these times are long, but I'm not seeing anything approaching 5 minutes. Is there anything in the above steps that I missed? Or anything else about your configuration that might be relevant? For example, are you editing remotely over ssh?

Perhaps another member of the Pylance team could try to repro following these steps (@debonte, @heejaechang)?

[Goldensteev]

Yes those steps are indeed correct!
Well that's a stumper... I have added all the remaining uncommitted files, even the ignored ones, so there are no differences from the local repo and the one on the git! I have also committed the list of my extensions just in case its one of them causing the issue. If you think of anything else i could give you don't hesitate.
Also yeah no i'm not doing anything fancy just local editing...

[Goldensteev]

this new patch did not fix my issue unfortunately

[Dr-Irv]

this new patch did not fix my issue unfortunately

The new patch did fix both the issues I reported above #2366 (comment) and #2366 (comment)

[ssssshong]

Same issue here! Semantic highlighting, code completion, parameter suggestions, etc., get super-slowed with 100% cpu usage in Pylance version 2022.2.1. I downgrade to 2022.2.0 and it seems to work fine.

The issues are fixed in the new version, 2022.2.3. Thank you!

[radu-ion]

Same thing with me. Pylance 2022.2.0 does semantic highlighting instantly on import sys, Pylance 2022.2.3 gets stuck (it does not work for me). I don't have logs but I will stick with 2022.2.0 for a bit longer.
It's not just about semantic highlighting, plain syntax checking fails, e.g. 'a =' followed by a newline does not yield a red squiggle. If I switch to Jedi, it works fine.

Running Windows 10, 64 bit, Python 3.9.9, default settings for all extensions.

[erictraut]

@radu-ion, could you post a minimal, self-contained piece of code that reproduces the problem? We won't be able to debug an issue like this from partial screen shots. Thanks!

[radu-ion]

@erictraut Unfortunately, I am not able to reproduce the bug with simple, random Python code. But I will attach the Python file I am currently working on that is producing the bug with Pylance 2022.2.3. It works fine with Pylance 2022.2.0.

Steps to reproduce on Windows 10, 64 bit (latest updates installed), Python 3.9.9, VS Code:
Version: 1.64.2 (system setup)
Commit: f80445acd5a3dadef24aa209168452a3d97cc326
Date: 2022-02-09T22:02:28.252Z
Electron: 13.5.2
Chromium: 91.0.4472.164
Node.js: 14.16.0
V8: 9.1.269.39-electron.0
OS: Windows_NT x64 10.0.19043

Install the following with standard pip install commands:
transformers 4.15.0
numpy 1.22.0
scikit-learn 1.0.2
yake 0.4.8

Create a test folder, copy the kcats.py (unzip it first) to the test folder and open the test folder with VS Code. You are not expected to run the code, just make sure Pylance is working as expected.
kcats.zip

[erictraut]

@radu-ion, thanks for the repro steps. I was able to find and fix the underlying cause. This will be addressed in the next release of pylance. I'll note that this issue was unrelated to the issue that was initially reported in this bug report even though the symptoms were superficially similar.

[bschnurr]

This issue has been fixed in version 2022.3.0, which we've just released. You can find the changelog here: CHANGELOG.md

[Goldensteev]

So I was hoping to come here this morning and comment "Hallelujah" but unfortunately it seems the issue is not fixed for me.
I have of course updated to the last version and it is still extremely slow in that one file.
The full project has gone open source so i will share with you the full git which hopefully will help pinpoint the root cause of this issue.

https://gitlab.com/healthdatahub/cartographie-ecosysteme-snds/-/tree/cd33b0be55e9d5304d040255cee1bd635a1d3c66

As stated above, it seems there where 2 separate issues perhaps, the nested expressions, and that import.

in the dashboard.py file, commenting import lib.data as data will make the semantic highlighting act normally, but uncommenting it will make the highlight very very slow, and with the new version still.

first time being with commented lib import and then without.

if there is any additionnal info that can be shared please ask i will give it.

Thanks

[erictraut]

@Goldensteev, thanks for posting — and for the repro steps.

Would you mind opening a new issue? This one has already been fixed and closed. While the symptoms you're seeing are similar, it's clearly a different issue, and I don't want it to get lost.

[erictraut]

Never mind, I just realized that this is probably the same issue that you reported at the start of this thread, which was obscured by several other unrelated bug reports. I'll re-open this issue.

If other pylance users experience performance problems with seemingly-similar symptoms, please open a new issue rather than adding to this one.

[erictraut]

Since this is a core type checking issue, I've created a tracking bug in the pyright repo: microsoft/pyright#3145

[erictraut]

@Goldensteev, I was able to repro the perf issue. I found the underlying cause. It will be fixed in the next release. Thanks again for reporting the problem.

[bschnurr]

This issue has been fixed in version 2022.3.1, which we've just released. You can find the changelog here: CHANGELOG.md