wakatime / vscode-wakatime

Visual Studio Code plugin for automatic time tracking and metrics generated from your programming activity.
https://wakatime.com/vs-code
BSD 3-Clause "New" or "Revised" License
1.24k stars 137 forks source link

wakatime + source control interaction causes slowness #302

Open davidmwhynot opened 2 years ago

davidmwhynot commented 2 years ago

Hello! Long time wakatime pro user. I love wakatime but I'm going to have to disable it until this issue is resolved. I've been having issues over the past couple of months where my editor starts to slow down significantly, particularly when it comes to saving files. I ran an extension bisect and identified wakatime as the culprit of the saving issues. Importantly, these issues are still present when ALL other extensions are disabled and Wakatime is the only extension that is enabled. This rules out any conflicts with other extensions. Some other symptoms of the problem include the "Source Control" tab showing its loading bar for an extended period of time after saving or making a change to any tracked file. In addition, the source control diff decorations in gutter take a long time to update after modifying/adding new lines to a file. I've also noticed that wakatime adds ~30 seconds to the time it takes for js/ts language features to become available, other extensions to be activated, and the editor to start responding in general. I doubt this issue is widespread as I don't see any other reports, so please let me know if you need any additional info from me.

VSCode Help: About:

Version: 1.71.2 (user setup)
Commit: 74b1f979648cc44d385a2286793c226e611f59e7
Date: 2022-09-14T21:03:37.738Z
Electron: 19.0.12
Chromium: 102.0.5005.167
Node.js: 16.14.2
V8: 10.2.154.15-electron.0
OS: Windows_NT x64 10.0.22000
Sandboxed: No
OnionKiller commented 1 year ago

I also encountered the very same issue, it slowed down savig files so much I learned that VS code has a progress window for saving files. Also it slowed down other extension interactions like Ipython integration, and debug tools, and when I disabled the extension everithing is back to normal. I woud love to debug the issues regardin this one, as I really liked the functionality of Wakatime, but I don't have any experience neither on debuggin nor profiling vs code extensions

alanhamlett commented 1 year ago

What's the size of your repo? Maybe it only happens on large repos because I wasn't able to reproduce any slowness.

OnionKiller commented 1 year ago

It isn't particularly big, but it has a .venv foder (.gitignore ignored) in the repo folder, which is kinda big. The repo contains ~30 tracked files, and a 0.5 Gb .venv untracked, with who knows how many files. ( I can check if necenecessary )

alanhamlett commented 1 year ago

I can check if necenecessary

No need, it's probably not related to repo size.

Do you have debug mode enabled or disabled in the wakatime extension?

You're also using Windows? I tested on Mac, maybe there's something different with VS Code Source Control on Windows.

OnionKiller commented 1 year ago

The debug mode is defaulted, so I would think it's disabled. ( only the api key is setted in the .cfg file ). I also use Windows.

alanhamlett commented 1 year ago

Would you be willing to take a video showing the problem, with debug mode enabled, and showing the vscode dev console? Here's an example video I made with Loom:

https://www.loom.com/share/76be01569b9f464fa50bfd1965c384d5

OnionKiller commented 1 year ago

Yes. I can't reproduce the slow saving issue, but the slowdown on start of debug, and executing a debug, or a simple block from the jupyter notebook takes irrealisticly long, withouth the extension enabled it is almost instant. https://www.loom.com/share/415ca33da38046b0999c745980b94cd2

alanhamlett commented 1 year ago

Can you try v24.0.7 and see if it fixes the slowness?

OnionKiller commented 1 year ago

I tried it, but sadly it is still very slow. I think I found the culprit: the cli tool runs really slow, and the proc calls to the cli tools are blocking, and the extensions share the js process they have, so the vs code extension probably works fine, but the calls hung all the other processes. Also I did a better video of the issue, with comparsion as well. https://www.loom.com/share/b331df1fd8d240af95409a38c5d2a08e

alanhamlett commented 1 year ago

Also I did a better video of the issue, with comparsion as well.

One thing that's strange is at the end of the video you run wakatime-cli-windows-amd64.exe in a cmd prompt but it takes way too long to just output the help contents. Normally that should be instant. For example, if I run time ~/.wakatime/wakatime-cli it finishes running in 0.01s. Is there some kind of antivirus software installed or Windows Defender that could be slowing it down?

the proc calls to the cli tools are blocking

They aren't blocking, we use child_process.execFile which forks a new process and calls our callback after the process exits so the JS extension thread can continue doing things without waiting on wakatime-cli. If we had used child_process.execFileSync then it would be blocking, but we don't use that in the wakatime plugin. I think the confusion here is because we only log to the dev console when the wakatime-cli process exits, but that doesn't mean we're blocking other JS code from running.

OnionKiller commented 1 year ago

So I made some experiments to figure out why the cli tool is so slow, and it was indeed my antivirus software with process analitics that slowed things down significantly.

#Safe Mode on
#(Ms Win10 19041)
Measure-Command {node -e 0} | Select-Object TotalSeconds
TotalSeconds
------------
   0,0389806

Measure-Command {C:\Users\tomi\.wakatime\wakatime-cli-windows-amd64.exe} | Select-Object TotalSeconds
TotalSeconds
------------
   0,0256833

Measure-Command {npm --version} | Select-Object TotalSeconds
TotalSeconds
------------
   0,9990728

#Safemode Off:

Measure-Command {node -e 0} | Select-Object TotalSeconds
TotalSeconds
------------
   0,2135716

Measure-Command {C:\Users\tomi\.wakatime\wakatime-cli-windows-amd64.exe} | Select-Object TotalSeconds
TotalSeconds
------------
  29,1718734

Measure-Command {npm --version} | Select-Object TotalSeconds
TotalSeconds
------------
    4,751656

# After setting an exception in the AV:
Measure-Command {C:\Users\tomi\.wakatime\wakatime-cli-windows-amd64.exe} | Select-Object TotalSeconds
TotalSeconds
------------
   0,1185601

It seems like there is some overhead still with the powesshell, but it is significantly better. After I fixed the CLI speed, now the performance of the extension is significantly better, it feels normal rigth now.

I think it was blocking, because initialisation was taking a really long time, and from the status line, and the debug message I can see, when it started, and when it finished. During that time it was impossible to use other extensions, like debugging didn't worked at al, it only started after the initialisation was done. The reason why I wait so long beofre demonstrating the slowdown is because I wait for the initialisation to finish. If I tried to debug while initialisation it actually would've broke the debugger. I have a feeling that somewhere Nodejs did an indirect syncronisation, but I can't really figure out where, or why. (My guess goes to that even if you spawn new processes the context is blocking, and it has to wait for the process to finish, before letting other parts to execute. Maybe the ChildProcess classes destructor waits for the processes to finish? I'm just guessing, I don't use js to much, I'm not really familiar with the internal structure of js/Nodejs nor how extensions work inside VS Code.)

It seems likely, that the issue is closely related to slow cli performance, maybe you can reproduce it with a modified cli, where you just add a ~10s delay on any kind of cli response.

Edit; I was thinking and I think it is also a possibility, that the antivirus blocks the process while analysing it, so the whole extension process hangs, while the AV figures all their magic out.

davidmwhynot commented 1 year ago

I uninstalled bitdefender last week because I thought it may have been causing some issues I was experiencing while working on an application that communicates via websockets.

After reading this, I turned wakatime back on and things have been working well so far. I will report back here if I run into the same issues again.

I looked into when this issue was opened and my wakatime logs and found that the time I started experiencing issues roughly correlated with the date I last visited the bitdefender download page (from chrome history).

I'm curios what antivirus software you're using @OnionKiller. If you're also using bitdefender, then I think we can say with a fair degree of certainty that it's the problem.

My question then would be: why does bitdefender cause problems specifically with wakatime and not with any of my other extensions? It's possible the answer here is that it's the only extension that I have that calls any outside executables during operation (not just initialization). That being said, my knowledge of the extension ecosystem is cursory and this might be common practice.

alanhamlett commented 1 year ago

It's possible the answer here is that it's the only extension that I have that calls any outside executables during operation

Yes, most likely that's why.

OnionKiller commented 1 year ago

Yes, I also use bitdefender, there is an Advanced Threat Defence system and I added the exception for that exclusively. I think it actually effects quite a lot of cli tools on Windows.