[Slow performance] Pylance goes crazy after switching git branch

[sam-val]

Environment data

• Language Server version: v2024.6.1
• OS and version: macOS 14.4.1, Ubuntu 22.04 LTS
• Python version: 3.7.17

GIF

Repro Steps

1. Open a large repo (thousands of files) with Vscode, pylance takes 5-10 seconds to fully analyze but works normally
2. Git checkout/switch to another branch
3. Pylance takes a crazy long time to analyze. The bigger the difference between the branches, the longer it takes.

Expected behavior

After git checkout/switching, pylance should finish analyzing after a much shorter time

Actual behavior

taking a long time to analyze

Logs

2024-06-21 22:36:23.631 [info] [Info  - 10:36:23 PM] (46004)   /Users/sam/.pyenv/versions/3.7.17/lib/python3.7
2024-06-21 22:36:23.631 [info] [Info  - 10:36:23 PM] (46004)   /Users/sam/.pyenv/versions/3.7.17/lib/python3.7/lib-dynload
2024-06-21 22:36:23.631 [info] [Info  - 10:36:23 PM] (46004)   /Users/sam/.pyenv/versions/3.7.17/envs/julo-mvp/lib/python3.7/site-packages
2024-06-21 22:36:23.631 [info] [Info  - 10:36:23 PM] (46004) Adding fs watcher for library directories:
 file:///Users/sam/.pyenv/versions/3.7.17/lib/python3.7
file:///Users/sam/.pyenv/versions/3.7.17/lib/python3.7/lib-dynload
file:///Users/sam/.pyenv/versions/3.7.17/envs/julo-mvp/lib/python3.7/site-packages
2024-06-21 22:36:23.631 [info] [Info  - 10:36:23 PM] (46004) Adding fs watcher for directories:
 file:///Users/sam/code/julo/mvp/src/juloserver
2024-06-21 22:36:23.631 [info] (46004) Searching for source files
2024-06-21 22:36:23.907 [info] (46004) Found module argparse : 1.4.0
2024-06-21 22:36:23.908 [info] (46004) Found module cfgv : 3.3.1
2024-06-21 22:36:23.910 [info] (46004) Found module decorator : 5.1.1
(keeps going like gif)
...

[heejaechang]

why are you have logLevel: Trace on? that logging will slow you down. it should be only on when you are investigating something or okay with perf hit, otherwise, you should not have that mode on.

that said, if you want us to take a look what is going on, give the full log of logLevel: Trace of git switch without any modification even if it is more than a 10+MB. that will help us to find out what pylance is doing.

[sam-val]

I turned on Trace loglevel to demonstate the GIF, because otherwise not much was shown. Here is a larger log when i do git switch: output_vscode.txt

[heejaechang]

are you saying what you shared is all you got? or some part of it?

Can you provide the log as described in the troubleshooting guide?

basically,

1. use the command to turn on the log (you can leave logLevel as Information),
2. do the git switch command,
3. wait until vscode goes into idle and then
4. use the command to stop the log
5. share the log file it generated to us

that should contain full log we need. not some part of it.

• PS. make sure pylance is loaded (by like opening a file), make sure vscode is idle before turning on the log. that will make the log to contains only relevant information.

[sam-val]

Sure, here is the full log file with said approach. (not sure how long it took, maybe 5-10 minutes for it to completely finish analyzing)

pylance_2024.6.1_id_0.txt.zip

[heejaechang]

so, everything there seems expected. would it be possible for me to get this data (profiling data) as well? (https://github.com/microsoft/pylance-release/wiki/Collecting-data-for-an-investigation.#collecting-cpuprofiles)

so, we can take a look what we can optimize to make things faster for your case?

[rajputa-deshaw]

I am facing this issue as well. I can reproduce it in the django repo by checking out an old commit for eg: git checkout a506b6981bc48caec30bca3de94d2ac3e6fc1660. After running this command, python code intelligence stops working and in the logs it can be seen that pylance is scanning the modules in the venv multiple times. There are several statements like

2024-06-25 19:40:10.956 [info] [Info  - 7:40:10 PM] (3808089) SourceFile: Received fs event 'change' for path '/codemill/rajputa/django/tests/commands_sql'

And after each such statement, pylance scans all the modules in the venv. For the standard python installation, pylance starts working again after 5-10 minutes but for our custom venv which has a lot more modules, pylance only works again after reloading the VSCode window. Is there room for improving how pylance handles file system events here? pylance_log.txt

[sam-val]

so, everything there seems expected. would it be possible for me to get this data (profiling data) as well? (https://github.com/microsoft/pylance-release/wiki/Collecting-data-for-an-investigation.#collecting-cpuprofiles)

so, we can take a look what we can optimize to make things faster for your case?

Huhm, taking 5-10 minutes to load i don't think it should be the way even if it's expected. The thing is if I start VScode the first time, it's normal and takes 10 seconds or so only happens when changing branches. As @rajputa-deshaw said, I think pylance keeps scanning for all modules again for each file changed.

But anyhow, I managed to improve the performance a bit by using python.analysis.exclude and python.analysis.include to only the folders/files that I frequently use.

From about ~8000 source files

to about ~300

This reduces the analysis to under 1 minute when I change branches.

[heejaechang]

After running this command, python code intelligence stops working and in the logs it can be seen that pylance is scanning the modules in the venv multiple times.

I am working on to optimize some of it. but providing us the profile data I mentioned above will help us greatly. since we have concrete data rather than optimizing speculatively.

[rajputa-deshaw]

Sure, attaching the logs and profile data for the reproducer. pylance_2024.6.1_bg_1_id_0.cpuprofile.txt pylance_2024.6.1_bg_2_id_0.cpuprofile.txt pylance_2024.6.1_fg_id_0.cpuprofile.txt pylance_2024.6.1_id_0.txt

[heejaechang]

thank you. the profile data showed what the issue is.

[rchiodo]

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