Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jupyter for vscode continues to be slow (for large notebooks with mardown cells & large outputs) #14459

Closed
loftusa opened this issue Oct 7, 2023 · 131 comments
Assignees
Labels
bug Issue identified by VS Code Team member as probable bug on-testplan perf Performance issues

Comments

@loftusa
Copy link

loftusa commented Oct 7, 2023

Every few months I try to use vscode for jupyter because I would really love to just use vscode for everything. Every few months, I am disappointed and switch back to the web version.

There are two reasons for this:

1) Jupyter for vscode continues, stubbornly, to essentially always be more slow than traditional jupyter lab on localhost. Look at the run times in this screenshot. It took me a minute to run imports; when I ran the exact same code on the localhost version, it took 7.7 seconds (pictures attached). This is an extremely consistent theme in vscode jupyter. Cells will sometimes randomly take minutes to run, and will sometimes not even run at all until you press 'shift-enter' on them twice. This has been true for me across multiple computers, in many different dev environments.

Screenshot 2023-10-06 at 6 04 32 PM Screenshot 2023-10-06 at 6 13 02 PM

Cells also just randomly take forever to run, for god knows what reason. Here is a screenshot of assigning a string to a variable taking 27.4 seconds:
Screenshot 2023-10-06 at 6 44 34 PM 1

Note that I am not trying to blame the team here, I am just frustrated because this is so close to being a great product, but this one thing holds it back, and it keeps not being fixed for years on end. The very first thing I would do as a product manager if I were in charge of vscode-jupyter is to pause all current tasks and plan, with the team, a multiple-month effort to speed things up, and get cells to run effectively instantly (or as close to the amount of time the python processing of the code takes as possible), every time.

2) Jupyter for vscode sucks at inline documentation, the equivalent of shift+tab in vscode jupyter. I am aware of the existence of the trigger parameter hints and show hover settings in the keyboard shortcuts. These are extremely unreliable, and actually show documentation when I press the button maybe 1/5 of the time. When they do show documentation, there is a 'loading' tag for awhile. Browser jupyter, on the other hand, is immediate with this. Basically every time. Below is an example.

image

The other issue with inline documentation is that, as far as I can tell, hover documentation for methods on instantiated variables simply doesn't work. When I am using pandas, for instance, typing df.unique( and then pressing the show hover hotkey while my typing carat is to the right of the parenthesis pops up a documentation window saying exactly nothing. In contrast, in the web version, typing the same thing produces full documentation, as expected.

I don't understand how these two issues aren't your guys's top priority. Everyone I've spoken to who uses jupyter has had exactly the same experience as I have, and everyone I've spoken to who uses jupyter uses the web version exclusively for exactly these issues. Even Kaggle notebooks are better. I love copilot and it'd be great to bring it into my jupyter notebook experience, but it has just never been viable to switch if I don't want a workflow where I have to wait for 30 seconds every time I press command-enter, or I am frustratingly making a new cell above the current one and typing function? just to see documentation.

These issues have been ongoing since vscode jupyter started. They are the only things holding me and everyone else I've spoken to back from using it. Without fixing these issues, the whole thing is unusable, and no other features you guys put in matter. Why are you guys working on anything besides this when they are the only things anyone I know cares about?

I should note that this is all running in a docker container with access to 7 of my 8 cpus and 10gb of RAM. I am on a 2022 macbook air. I realize that this is a rant, so thank you for reading it. Nothing personal, I just think this product has a bunch of potential and I hate to see it unusable for so long.

@loftusa loftusa added the feature-request Request for new features or functionality label Oct 7, 2023
@DonJayamanne
Copy link
Contributor

Thank you for filling this issue and sorry you are running into these issues

I would like to get to the bottom of these issues and get you unblocked

  • please can you disable all extensions except Python , Jupyter and the Notebook renderers extension
  • If you have the variable viewer open please hide that
  • Run again and check if it’s slow (I if you have the power tools extension that can show things down)
  • finally pear could you provide the logs so I can see what’s slow at your end (instructions below)

Please could you enable logging as follows:

  • Open settings & go into Jupyter->Logging
  • Change the value to verbose
  • Reload VS Code,
  • Attempt to repro the issue & then copy the output from the Jupyter output panel.
  • Use the command ‘Jupyter: Show Output’ to get to the logs

@DonJayamanne DonJayamanne self-assigned this Oct 8, 2023
@DonJayamanne DonJayamanne added the info-needed Issue requires more information from poster label Oct 8, 2023
@dschaub95
Copy link

I have exactly the same issues. The notebooks get especially slow as they get bigger. But many of the problems already exist in an empty notebook.

@jhancibo
Copy link

Same here as @dschaub95 . Could you @DonJayamanne upload a screenshot of Jupyter output panel? I have nothing here. This issue did not present couple of versions of vscode before. It is a recent versions thing.
Screenshot 2023-10-21 at 10 01 52 AM

@jhancibo
Copy link

Okay, I found Jupyter output panel.
Screenshot 2023-10-21 at 10 11 31 AM
Here is the log @DonJayamanne . Any other information needed? I'm not sure how to command ‘Jupyter: Show Output’ to get to the logs, so I copy all of them from the Jupyter output panel.
log.zip

@DonJayamanne
Copy link
Contributor

@jhancibo @dschaub95 @loftusa
Does this repro when you close the variable view
Please ensure you always hide the variable view completely
Let me know of the issue persists even after that

@dschaub95
Copy link

In my experience, it is entirely independent of the variable view.

@DonJayamanne
Copy link
Contributor

If you have the Jupyter powertoys extension
Please disable that as well

@dschaub95
Copy link

I don't use the powertoys extension at all. Maybe it's also important to mention that the problems with jupyter notebooks are even more severe when developing on a remote server (via ssh or Kubernetes). However, they still persist when developing locally.

@DonJayamanne
Copy link
Contributor

@dschaub95
Please could you enable logging as follows:

  • Open settings & go into Jupyter->Logging
  • Change the value to verbose
  • Reload VS Code,
  • Attempt to repro the issue & then copy the output from the Jupyter output panel.

please share these logs when you run into perf issues

@dschaub95
Copy link

The output is attached. As far as I could see, the output only changed when the cell started executing. The time between me trying to execute and the actual execution seems not to be logged.
logs.txt

@jhancibo
Copy link

In my experience, it is entirely independent of the variable view.

Same here. And I didn't install powertoys extension.

@jhancibo
Copy link

@DonJayamanne The issue persists after close the variable view completely.

@DonJayamanne
Copy link
Contributor

@dschaub95 @jhancibo
I’m being sorry this is still unresolved
Please can you try the following

  • disable all extensions except Python, Jupyter and notebook renders extension
  • from the command palette select.Developer: Set log level
  • Select extension host and select info
  • When you run into this issue
  • Please go into the output panel and select Extension host
  • Clear the logs
  • click the run cell button
  • Capture the logs and let me know what you get
  • Also let me know how long it took for you to see the output ‘NotebookController[..] EXECUTE Cell’ in the output panel
  • Basically was there a delay between you clicking the button and the message getting logged
  • Please do sure the logs from extension host when you replicate this issue
  • And please do disable all but the about 3 extensions

Once again thank you for your continued patience ands support

@jhancibo
Copy link

@DonJayamanne Could you recording a video to do those instruction above? I tried and it is abstract to follow each step. For example, when I type Developer: Set log level in command palette, I see nothing pop up.
If you have time to recording the video, I would be very happy to test it. Thanks.

@DonJayamanne
Copy link
Contributor

The time between me trying to execute and the actual execution seems not to be logged.
Recording 2023-11-01 at 14 00 50

Please send the logs from Extension Host and Jupyter
From the ExtenisonHost logs I'm only interested in the lines that have the text [trace] NotebookController[...] EXECUTE cells

@dschaub95 @jhancibo
Please could you send these two logs
From what I understand

  • Jupyter extension logs do not get updated for a while, meaning Jupyter extension does not recieve messages for execution for while

Please let me know

  • How long it takes to see output in the ExtensionHost logs from the time you try to run a cell.
    @dschaub95 You have already confirmed that Jupyter logs do not get updated, please check the ExtensionHost logs as well.

Here are the instructions again (please clear the both ExtensionHost and Jupyter logs before you start executing cells)

Please can you try the following

  • disable all extensions except Python, Jupyter and notebook renders extension
  • from the command palette select.Developer: Set log level
  • Select extension host and select info
  • When you run into this issue
  • Please go into the output panel and select Extension host
  • Clear the logs
  • click the run cell button
  • Capture the logs and let me know what you get
  • Also let me know how long it took for you to see the output ‘NotebookController[..] EXECUTE Cell’ in the output panel
  • Basically was there a delay between you clicking the button and the message getting logged
  • Please do sure the logs from extension host when you replicate this issue
  • And please do disable all but the about 3 extensions

Once again thank you for your continued patience ands support

@DonJayamanne
Copy link
Contributor

Closing this issue as its been over 4 weeks, since the information was requested.
We'll be happy to reopen the issue when the requested information has been provided.

@yuuuxt
Copy link

yuuuxt commented Dec 22, 2023

got one example and the logs are in microsoft/pylance-release#5301 (Note that I'm not disabling all other extensions).

image

UPDATE: having the same issue again, but nothing in Extension Host (in info level). the pending lasted for about one minutes. I tried it again with debug level for Extension Host, the only logs (from middle of pending to after execution) are as follows. (seems unrelated?)

meanwhile, the time shown below is incorrect - the waiting time is more than one minute.
image

2023-12-22 14:30:10.159 [debug] ExtHostNotebook#$acceptEditorPropertiesChanged 47805538-ec73-4099-90db-736613202be8 {"selections":{"selections":[{"start":34,"end":35}]}}
2023-12-22 14:30:27.062 [debug] ExtHostNotebook#$acceptEditorPropertiesChanged 47805538-ec73-4099-90db-736613202be8 {"selections":{"selections":[{"start":35,"end":36}]}}
2023-12-22 14:30:33.206 [debug] ExtHostNotebook#$acceptEditorPropertiesChanged 47805538-ec73-4099-90db-736613202be8 {"selections":{"selections":[{"start":35,"end":36}]}}
2023-12-22 14:30:48.061 [debug] ExtHostNotebook#$acceptEditorPropertiesChanged 47805538-ec73-4099-90db-736613202be8 {"visibleRanges":{"ranges":[{"start":33,"end":36}]}}
2023-12-22 14:30:51.428 [debug] ExtHostNotebook#$acceptEditorPropertiesChanged 47805538-ec73-4099-90db-736613202be8 {"visibleRanges":{"ranges":[{"start":33,"end":37}]}}
2023-12-22 14:30:52.066 [debug] ExtHostNotebook#$acceptEditorPropertiesChanged 47805538-ec73-4099-90db-736613202be8 {"selections":{"selections":[{"start":35,"end":36}]}}
2023-12-22 14:31:30.497 [debug] ExtHostNotebook#$acceptEditorPropertiesChanged 47805538-ec73-4099-90db-736613202be8 {"selections":{"selections":[{"start":35,"end":36}]}}
2023-12-22 14:32:34.055 [debug] ExtHostNotebook#$acceptEditorPropertiesChanged 47805538-ec73-4099-90db-736613202be8 {"visibleRanges":{"ranges":[{"start":33,"end":36}]}}

and again, pls note that I'm not disabling other extensions during work, which is not consistent with your instruction above.

@suiluj
Copy link

suiluj commented Jan 9, 2024

Hi, i think this issue should not be closed because it is not solved.

Or does someone have a solution?

When I run notebooks in jupyter lab in the browser everything is instant but in vscode everything runs delayed.

@DonJayamanne DonJayamanne reopened this Jan 9, 2024
@FlorinAndrei
Copy link

Not sure if this is what you're seeing, but I've noticed a regression of an old bug. I have a code cell that should run in a fraction of a second. I run it. It's stuck for about 1 minute. Then all of a sudden it runs.

Very annoying. Because of this and other, numerous bugs, I'm thinking to go back to Jupyter Notebook in a browser.

@suiluj
Copy link

suiluj commented Jan 13, 2024

I don't know if Windows interferes the "vscode ipykernel" differently than the "kernel type" that is started by running jupyter lab.
But I noticed that on my macbook air m2 vscode restarts kernels and runs cells fast.

Perhaps there are some Windows processes like Windows Defender and proxy and vpn settings that interfere with the ipykernel when starting a kernel from vscode.

Here is an issue that describes some of these things:
jupyter/notebook#1415

@FayzulSaimun
Copy link

I am experiencing the same issue. A few days ago, everything was working fine but after updating to the latest version, Visual Studio Code is using almost 90% of my CPU and the Jupyter Notebook is also running slow. Previously, I could use 3-4 notebooks at a time with my current setup but now running even one notebook is not possible. On the other hand, everything is smooth in Jupyter Lab.

"I have attached the cell loading data. It has been stuck for 5 minutes now and is not running."

image

@JasonGross
Copy link

In my experience, jupyter notebooks performance degrades very quickly in the size of the notebook. This is especially true for plotly.express plots, and is independent of whether I am using a .ipynb file or the interactive cell views for a .py file.

Describing the experience for a .py file: when there are no plots and no LaTeX in the interactive window, everything is snappy. But if I have even just a handful of plots (or many lines of rendered LaTeX from Markdown cells), then it takes multiple seconds between when I press Shift+Enter and when the interactive window starts running the command. If I click "clear all", everything is quick again. This seems to largely depend on how many plots are in the interactive window, not how many are currently visible.

Some other observations:

  • Making fancy interactive .js plots slows vscode way more than making png plots
  • When my notebooks contain many interactive plotly.express plots, the .ipynb files saved from vscode can be ~10x larger (100+MB rather than 10MB) than equivalent notebooks saved from Google Colab

@FlorinAndrei
Copy link

@JasonGross All that is true, but the bug where it gets stuck on a cell does not depend on notebook size or plot complexity.

@JasonGross
Copy link

It used to be the case that clearing the interactive window would restore performance, but now it seems like slowness accumulates over time even when the interactive window has been cleared --- this is so much worse than the non-pre-release/non-insider-preview state!

2024-04-25-slow-ctrl-enter-vscode

Clicking "Clear all" should be instantaneous, it should not take multiple seconds after clicking "run cell" to have the text show up in the interactive window, and it should not take 5+ seconds to start running the code.

Profiling the clear all -> shift+enter -> wait for running to complete:
CPU-20240426T060412.680Z.cpuprofile.txt

am I reading this right that most of the time is not spent in extensions?

image

$ code-insiders --status
Version:          Code - Insiders 1.89.0-insider (6d23b7f11a3d7292b9458f0de7160048089398f9, 2024-04-24T05:49:19.433Z)
OS Version:       Windows_NT x64 10.0.19045
CPUs:             Intel(R) Core(TM) i7-10510U CPU @ 1.80GHz (8 x 2304)
Memory (System):  15.79GB (0.92GB free)
VM:               40%
Screen Reader:    no
Process Argv:     --crash-reporter-id 711c8cd8-5f5f-4f4c-aa89-e07b93812ffc
GPU Status:       2d_canvas:                              enabled
                  canvas_oop_rasterization:               enabled_on
                  direct_rendering_display_compositor:    disabled_off_ok
                  gpu_compositing:                        enabled
                  multiple_raster_threads:                enabled_on
                  opengl:                                 enabled_on
                  rasterization:                          enabled
                  raw_draw:                               disabled_off_ok
                  skia_graphite:                          disabled_off
                  video_decode:                           enabled
                  video_encode:                           enabled
                  vulkan:                                 disabled_off
                  webgl:                                  enabled
                  webgl2:                                 enabled
                  webgpu:                                 enabled

CPU %   Mem MB     PID  Process
    0      108    9868  code-insiders main
    0       57     460     window
    0      312    1736  window [1] (max_of_4.py - guarantees-based-mechanistic-interpretability [SSH: jason-stream] - Visual Studio Code - Insiders)
    0       12    3384     utility-network-service
    0        7    5160  fileWatcher [1]
    0        4   13488     crashpad-handler
    0      237   13920     window
    0      101   14296     gpu-process
    0       25   15624  extensionHost [1]
    0       60   18544  shared-process
    0       13   21732  ptyHost
    0        0   25228       C:\Windows\System32\cmd.exe /c (type "C:\Users\jason\AppData\Local\Temp\vscode-linux-multi-line-command-jason-stream-725305142.sh" | "C:\Windows\System32\OpenSSH\ssh.exe" -T -D 53588 "jason-stream" bash) & exit /b 0
    0        2   27640         "C:\Windows\System32\OpenSSH\ssh.exe"  -T -D 53588 "jason-stream" bash
    0        1   28332       conpty-agent



Remote:           SSH: jason-stream
OS Version:       Linux x64 5.4.0-172-generic
CPUs:             AMD EPYC 7B13 64-Core Processor (128 x 1499)
Memory (System):  188.54GB (128.51GB free)
VM:               0%
CPU %   Mem MB     PID  Process
    0        0  1269563 remote agent
    0        0  1269790    ptyHost
    0        0  1280505      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1280808      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1469438      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1469750      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1501927      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1508764      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1526211        git diff
    0        0  1526212          /bin/sh -c less -SFRX less -SFRX
    0        0  1526213            less -SFRX
    0        0  1509326      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1509614      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1527477      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1270610    fileWatcher
    0        0  1280173    fileWatcher
    0        0  1469137    fileWatcher
    0        0  1508686    extension-host
    0        0  1508747      /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/node /home/jason/.vscode-server-insiders/extensions/visualstudioexptteam.intellicode-api-usage-examples-0.2.8/dist/server/server.js --node-ipc --clientProcessId=1508686
    0        0  1509094      /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/node /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/extensions/json-language-features/server/dist/node/jsonServerMain --node-ipc --clientProcessId=1508686
    0        0  1509239      /home/jason/guarantees-based-mechanistic-interpretability/.venv/bin/python /home/jason/.vscode-server-insiders/extensions/ms-python.black-formatter-2024.2.0/bundled/tool/lsp_server.py --stdio
    0        0  1509585      /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/node /home/jason/.vscode-server-insiders/extensions/ms-python.vscode-pylance-2024.4.1/dist/server.bundle.js --cancellationReceive=file:a74ce2e62c5ebe9922b6d7c924535799138bc385cc --node-ipc --clientProcessId=1508686
    0        0  1510337      electron-nodejs (KNk.js )
    0        0  1510689        luatex --luaonly /home/jason/guarantees-based-mechanistic-interpretability/.venv/lib/python3.10/site-packages/matplotlib/mpl-data/kpsewhich.lua
    0        0  1510690        electron-nodejs (min.js MathJax.js )
    0        0  1510694          electron-nodejs (min.js MathJax.js )
    0        0  1510696            zygote
    0        0  1510710              gpu-process
    0        0  1510697            zygote
    0        0  1510712              window
    0        0  1510711            utility-network-service
    0        0  1510338      /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/node /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/extensions/markdown-language-features/server/dist/node/workerMain --node-ipc --clientProcessId=1508686
    0        0  1526151      electron-nodejs (CNzp.js )
    0        0  1508697    fileWatcher
    0        0  1531766    /bin/sh -c /usr/bin/ps -ax -o pid=,ppid=,pcpu=,pmem=,command=
    0        0  1531767      /usr/bin/ps -ax -o pid=,ppid=,pcpu=,pmem=,command=
Folder (guarantees-based-mechanistic-interpretability): more than 61608 files
|      File types: json(8418) pyc(2899) py(2892) pyi(1830) dat(1014) txt(105)
|                  so(60) typed(47) npy(20) testcase(18)

Here is the performance monitor of the relevant time slice, but how do I save it?

image
image

I was not able to capture any additional profiles, yet, since reloading the window reset the performance. Is there something else I should be profiling though?

@DonJayamanne
Copy link
Contributor

DonJayamanne commented Apr 26, 2024

@JasonGross

it should not take multiple seconds after clicking "run cell" to have the text show up in the interactive window, and it should not take 5+ seconds to start running the code.
this is so much worse than the non-pre-release/non-insider-preview state!

Are you saying that this is fast in VS Code insiders, and slow in VS Code Stable?
If you have tested this in VS Code insiders and have disabled all extensions except for Jupyter + Python and Notebook renderers, then we know the issue has either been resolved or its with another extension.
If its in another extension , please use extension bisect to determine the extension thats causing this issue (unlikely thought).

am I reading this right that most of the time is not spent in extensions?

Yes, it looks like the extensions are fine, at least from the logs
Please confirm you captured the lots while you were running the test scenario.

to capture any additional profiles, yet, since reloading the window reset the performance. Is there something else I should be profiling though?

Please try the following:

  • Open dev tools (as you have done)
  • Go into the Performance tab (the tabs are on the top, Elements, Console, Sources, Network, Perforamnce
  • On in Performance, ensure you un-tick the Screenshots item
  • Then start the Record button on the far left
  • Replicate the issue in VS Code (i.e. ensure you perform the actions that repros the perf issues you run into)
  • Finally go back into the Performance tab and stop recording
  • Now you go go to the Summary tab and next to that you will see Bottom-Up, click that tab
    This tab is around 1/2 way down the screen
    Sort the Self Time in ascending order and share a screenshot of the table.
    I'd like to see the items in the table in asc order.
  • Next sort the Total Time column in asc order and share a screenshot of the sorted table again
    Please snure the activity column along with the file names and paths are included.
  • Please ensure you screen down the table to show the data, i'd like to see items that take over 100ms (this could be a fairly large list of items, hence you might have to scroll a lot and capture screenshots).
    Optionally, you can take a screen recording (e.g. using gifcap.dev or other).

Unfortunately saving the logs is broken in VS Code, hence we will have to resort to capturing screenshots.
Thank you very much for your help, I'm sure we can get to the bottom of this.

Below is a screenshot (for reference) of the Performance tab (see towards the top) and the Bottom-Up tab towards the middle.
This shows the getOutlineEntries being one of the slower parts of the code path, and this has been resolved, in the latest version of VS Code insiders.

Screenshot 2024-04-26 at 16 57 12

@JasonGross
Copy link

JasonGross commented Apr 26, 2024

Slightly different issue, shift+enter on some code in the interactive window takes a second or two before it starts running the code. (This time if I clear the interactive window first, it becomes instantaneous; there are a bunch of plots hidden above where I'm scrolled to.)
2024-04-25-slow-ctrl-enter-vscode2

CPU-20240426T065336.682Z.cpuprofile.txt

here too is seems that not much happens in extensions

image

$ code-insiders --status
Version:          Code - Insiders 1.89.0-insider (6d23b7f11a3d7292b9458f0de7160048089398f9, 2024-04-24T05:49:19.433Z)
OS Version:       Windows_NT x64 10.0.19045
CPUs:             Intel(R) Core(TM) i7-10510U CPU @ 1.80GHz (8 x 2304)
Memory (System):  15.79GB (2.63GB free)
VM:               40%
Screen Reader:    no
Process Argv:     --crash-reporter-id 711c8cd8-5f5f-4f4c-aa89-e07b93812ffc
GPU Status:       2d_canvas:                              enabled
                  canvas_oop_rasterization:               enabled_on
                  direct_rendering_display_compositor:    disabled_off_ok
                  gpu_compositing:                        enabled
                  multiple_raster_threads:                enabled_on
                  opengl:                                 enabled_on
                  rasterization:                          enabled
                  raw_draw:                               disabled_off_ok
                  skia_graphite:                          disabled_off
                  video_decode:                           enabled
                  video_encode:                           enabled
                  vulkan:                                 disabled_off
                  webgl:                                  enabled
                  webgl2:                                 enabled
                  webgpu:                                 enabled

CPU %   Mem MB     PID  Process
    0      140    9868  code-insiders main
    0      284    1736  window [1] (Interactive - max_of_4.py - guarantees-based-mechanistic-interpretability [SSH: jason-stream] - Visual Studio Code - Insiders)
    0       12    3384     utility-network-service
    0        3   13488     crashpad-handler
    6      591   13920     window
   10      165   14296     gpu-process
    0       74   18544  shared-process
    0       20   21732  ptyHost
    0        1    8716       C:\Windows\System32\cmd.exe /c (type "C:\Users\jason\AppData\Local\Temp\vscode-linux-multi-line-command-jason-stream-631440849.sh" | "C:\Windows\System32\OpenSSH\ssh.exe" -T -D 54821 "jason-stream" bash) & exit /b 0
    0        3   27352         "C:\Windows\System32\OpenSSH\ssh.exe"  -T -D 54821 "jason-stream" bash
    0        2   11372       C:\Windows\System32\cmd.exe /c (type "C:\Users\jason\AppData\Local\Temp\vscode-linux-multi-line-command-jason-stream-405813590.sh" | "C:\Windows\System32\OpenSSH\ssh.exe" -T -D 54986 "jason-stream" bash) & exit /b 0
    0        6    1260         "C:\Windows\System32\OpenSSH\ssh.exe"  -T -D 54986 "jason-stream" bash
    0        2   15728       conpty-agent
    0        2   24872       conpty-agent
    0        0   25228       C:\Windows\System32\cmd.exe /c (type "C:\Users\jason\AppData\Local\Temp\vscode-linux-multi-line-command-jason-stream-725305142.sh" | "C:\Windows\System32\OpenSSH\ssh.exe" -T -D 53588 "jason-stream" bash) & exit /b 0
    0        1   27640         "C:\Windows\System32\OpenSSH\ssh.exe"  -T -D 53588 "jason-stream" bash
    0        1   28332       conpty-agent
    0        4   28808       conpty-agent
    0        1   28944       C:\Windows\System32\cmd.exe /c (type "C:\Users\jason\AppData\Local\Temp\vscode-linux-multi-line-command-jason-stream-544157236.sh" | "C:\Windows\System32\OpenSSH\ssh.exe" -T -D 54878 "jason-stream" bash) & exit /b 0
    0        3   26036         "C:\Windows\System32\OpenSSH\ssh.exe"  -T -D 54878 "jason-stream" bash
    3       71   24980  extensionHost [1]
    0        6   28236     utility-process
    0      111   28564     window
    0       10   30856  fileWatcher [1]
    0        7   30900  fileWatcher [1]



Remote:           SSH: jason-stream
OS Version:       Linux x64 5.4.0-172-generic
CPUs:             AMD EPYC 7B13 64-Core Processor (128 x 2421)
Memory (System):  188.54GB (131.21GB free)
VM:               0%
CPU %   Mem MB     PID  Process
    0        0  1269563 remote agent
    0        0  1269790    ptyHost
    0        0  1280505      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1280808      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1469438      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1469750      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1501927      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1508764      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1526211        git diff
    0        0  1526212          /bin/sh -c less -SFRX less -SFRX
    0        0  1526213            less -SFRX
    0        0  1509326      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1509614      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1527477      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1532423      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1532688      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1532949      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1534065      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1534363      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1536144      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1536418      /usr/bin/bash --init-file /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/out/vs/workbench/contrib/terminal/browser/media/shellIntegration-bash.sh
    0        0  1270610    fileWatcher
    0        0  1280173    fileWatcher
    0        0  1469137    fileWatcher
    0        0  1508697    fileWatcher
    0        0  1531984    fileWatcher
    0        0  1533629    fileWatcher
    0        0  1535706    extension-host
    0        0  1535767      /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/node /home/jason/.vscode-server-insiders/extensions/visualstudioexptteam.intellicode-api-usage-examples-0.2.8/dist/server/server.js --node-ipc --clientProcessId=1535706
    0        0  1535931      /home/jason/guarantees-based-mechanistic-interpretability/.venv/bin/python /home/jason/.vscode-server-insiders/extensions/ms-python.black-formatter-2024.2.0/bundled/tool/lsp_server.py --stdio
    0        0  1536244      /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/node /home/jason/.vscode-server-insiders/extensions/ms-python.vscode-pylance-2024.4.1/dist/server.bundle.js --cancellationReceive=file:241b4cd17d6259d56ccbf421f618c057cbd4f3e690 --node-ipc --clientProcessId=1535706
    0        0  1536964      /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/node /home/jason/.vscode-server-insiders/cli/servers/Insiders-6d23b7f11a3d7292b9458f0de7160048089398f9/server/extensions/markdown-language-features/server/dist/node/workerMain --node-ipc --clientProcessId=1535706
    0        0  1535717    fileWatcher
    0        0  1540006    /bin/sh -c /usr/bin/ps -ax -o pid=,ppid=,pcpu=,pmem=,command=
    0        0  1540007      /usr/bin/ps -ax -o pid=,ppid=,pcpu=,pmem=,command=
Folder (guarantees-based-mechanistic-interpretability): more than 61608 files
|      File types: json(8418) pyc(2899) py(2892) pyi(1830) dat(1014) txt(105)
|                  so(60) typed(47) npy(20) testcase(18)

Here is the performance recording from this one: the bad (slow) behavior starts at just over 2 seconds in, and persists until just before the end.

misc images

image
image
image

self time over 100 ms

image
image
image

total time over 100ms

image
image

total time over 100ms subitems expanded

image

(image captured with PicPick as suggested by google)

I'm a bit confused why even for leaves the self time does not equal total time?

@JasonGross
Copy link

Are you saying that this is fast in VS Code insiders, and slow in VS Code Stable?

No, it is slow in VS Code Insiders, fast in VS Code Stable.

If you have tested this in VS Code insiders and have disabled all extensions except for Jupyter + Python and Notebook renderers, then we know the issue has either been resolved or its with another extension.

I did not disable extensions, but it should be fine because the extension profile says that no time is spent in extensions other than ssh, right?

Please confirm you captured the lots while you were running the test scenario.

Yes, captures were performed while recreating the events shown in the gif.

@JasonGross
Copy link

I have captured a profile from repeating the test in #14459 (comment) a handful of times, over the course of 60 seconds. However, the performance capture seems to be broken, there are no details provided
image

@DonJayamanne
Copy link
Contributor

DonJayamanne commented Apr 26, 2024

No, it is slow in VS Code Insiders, fast in VS Code Stable.

What is slow, editing, executing notebooks?
Have you disabled all extensions and tried again.
We found esline, copilot, eslint and a few other extensions can slow things down.

Please can you try this with the following extension

  • Install this extension using Install from VSIX
  • Disable all extensions except this extension
  • Open your notebook
  • Select the kernel Dummy Execution
  • Select the command Dummy Execution: run all (text output)
  • Open the output panel and select Dummy execution
  • Once execution completes, copy all of the output from the output panel and paste that here.

vscode-notebook-dummy-execution-0.0.1.vsix.zip

@JasonGross
Copy link

JasonGross commented Apr 26, 2024

I have captured a profile from repeating the test in #14459 (comment) a handful of times, over the course of 60 seconds. However, the performance capture seems to be broken, there are no details provided

Okay, I did it for only 40s instead of 60s, here's more captures:
image

total time over 100ms

image

expanded

image

I hope you find this more informative than I do. But I can't help but think that this profile doesn't contain the relevant information---I'm waiting 40 seconds for an operation that should only take 4 seconds (or less), and yet this profile only claims to capture 1256ms/.266 = 4.7 seconds. Where are the other 35s spent?

@JasonGross
Copy link

What is slow, editing, executing notebooks?

Executing.

I have given up on using .ipynb notebooks because they are too slow and the performance is too hard to localize. Here I am reporting on the performance issues only for clicking "run cell" in .py files treated as jupyter notebooks (with # %%) and for entering code in the Interactive - ***.py bar and evaluating that.

The problem is that while text is dumped into the interactive window immediately, VS Code spends an excessive amount of time (sometimes upwards of 5 seconds for one-liners like [k for k in latex_figures.keys() if "SVD" in k]) with cells in the image state.
image

You can see the behavior in the gifs I've uploaded.

Have you disabled all extensions and tried again.

No, I haven't done this. I'll do this next. But why does the CPU profile show that no time is spent in extensions?

@JasonGross
Copy link

I've disabled all extensions except jupyter, python, remote ssh, and wsl

extensions

image
image
image

I've established that the problem persists even when I've disabled all extensions except for the ones shown above.

@DonJayamanne
Copy link
Contributor

Oh no, I'm so sorry, please can you sort the table is descending order,
How could I maker they mistake

@JasonGross
Copy link

Luckily I still have it open, I can resort. I don't suppose there's a quick way to automatically expand everything above 100ms?

Also, I think there must be a bug in the profiling code, there's an instance where the total time of a parent node is less than half the total time of it's only child. What might cause this?
image

@DonJayamanne
Copy link
Contributor

Pleaser can you take a screen recording.
Use gifcap.dev

@DonJayamanne
Copy link
Contributor

I will try to find a way to get the logs from you
I will get back next week with some instructions

@JasonGross
Copy link

JasonGross commented Apr 26, 2024

Sorry it took so long, the autoscrolling screen capture kept crashing. Apparently it's too much for a single image.

resorted expanded profile

image
image
image
image

high self time

image

@JasonGross
Copy link

Hm, it seems to have the performance issue occasionally even with all extensions disabled, but has the performance issue way more reliably with copilot enabled. Is it possible that copilot is blocking cell execution on sending relevant data to ChatGPT or something, but this somehow doesn't show up in any profile because the time is spent in low-level system calls or something? Is there a way to debug this?

@JasonGross
Copy link

Highlighting this in case it got lost:

But I can't help but think that this profile doesn't contain the relevant information---I'm waiting 40 seconds for an operation that should only take 4 seconds (or less), and yet this profile only claims to capture 1256ms/.266 = 4.7 seconds. Where are the other 35s spent?

@DonJayamanne do you have any idea what would cause almost 90% of the time to not show up in the profile at all?

@tlkaufmann
Copy link

@DonJayamanne
So disabling Copilot and changing to the newest version of VSCode Insiders has removed the issues for me.
So it seems that Copilot was the main culprit. However, I do remember having the same issues even without Copilot last week (also using Insiders). I will upload another performance report if the problem comes back.

For now, thanks a ton for all the help and work!

@Liam3851
Copy link

I've had the same issues as others. I'm working with a particularly large dataset (50 GB in RAM). Turning on Github Copilot completions makes it take >60 seconds to start to run a cell; if I turn off completions, there is no delay at all. I'm running VS Code stable (not insiders) with pylance installed and running. Definitely seems like a Copilot issue (for me at least).

@DonJayamanne
Copy link
Contributor

@tlkaufmann @Liam3851
That's great news, great because we've been able to identify the cause and there's a work around.
We will work with copilot to get this resolved

@JasonGross
Copy link

Is the issue that Jupyter (or VSCode) is exposing some sort of blocking hook on cell execution / send text to the interactive window, Copilot takes advantage of this hook to process the entirety of the notebook / interactive window with an LLM, and blocks the execution of the code until it gets a response?

(Also, did "Clear All" become less destructive in the insider's preview / pre-release version of Jupyter? Is Copilot somehow getting access to all the cells that have been executed, even the cleared ones?)

@matrix303
Copy link

matrix303 commented Apr 27, 2024

@tlkaufmann @Liam3851 That's great news, great because we've been able to identify the cause and there's a work around. We will work with copilot to get this resolved

Can also confirm, disabling Copilot entirely (autocompletion setting didnt make faster on its own) was the answer to much faster performance including shift-enter, decreased lag when entering text, and much faster built-in autocompletions. When/How will we know when the copilot workaround has been resolved?

Remote Configuration: MacOS - remotessh - Linux machine

vscode details Version: 1.88.1 Commit: e170252f762678dec6ca2cc69aba1570769a5d39 Date: 2024-04-10T17:42:52.765Z Electron: 28.2.8 ElectronBuildId: 27744544 Chromium: 120.0.6099.291 Node.js: 18.18.2 V8: 12.0.267.19-electron.0 OS: Darwin x64 23.4.0
Extension Author (truncated) Version
strike-vscode art 3.0.0
path-intellisense chr 2.8.5
python-environment-manager don 1.2.4
python-extension-pack don 1.7.0
gitlens eam 14.9.1
comment-anchors Exo 1.10.4
workspace Foo 1.3.0
gc-excelviewer Gra 4.2.59
beautify Hoo 1.5.0
rainbow-csv mec 3.11.0
python-path mge 0.0.14
vscode-dotnet-runtime ms- 2.0.3
black-formatter ms- 2024.2.0
debugpy ms- 2024.4.0
isort ms- 2023.10.1
python ms- 2024.4.1
vscode-pylance ms- 2024.4.1
datawrangler ms- 1.0.0
jupyter ms- 2024.3.1
jupyter-renderers ms- 1.0.17
vscode-jupyter-cell-tags ms- 0.1.9
vscode-jupyter-slideshow ms- 0.1.6
autodocstring njp 0.6.1
indent-rainbow ode 8.3.1
vscode-yaml red 1.14.0
unique-window-colors stu 1.0.51
python tht 0.2.3
intellicode-api-usage-examples Vis 0.2.8
vscodeintellicode Vis 1.3.1
vscode-wakatime Wak 24.5.0
markdown-all-in-one yzh 3.6.2
vsc-material-theme Equ 34.3.1
vsc-material-theme-icons equ 3.6.0
auto-close-tag for 0.5.15
output-colorizer IBM 0.1.2
vsc-python-indent Kev 1.18.0
jupyter-keymap ms- 1.1.2
remote-ssh ms- 0.110.1
remote-ssh-edit ms- 0.86.0
remote-wsl ms- 0.88.0
vscode-remote-extensionpack ms- 0.25.0
remote-explorer ms- 0.4.3
remote-server ms- 1.5.1
python-extended-snippets tus 0.0.1
vscode-icons vsc 12.7.0
jinja who 0.0.8

(2 theme extensions excluded)

@SoshyHayami
Copy link

SoshyHayami commented Apr 29, 2024

I'm facing the same issue and I don't even use copilot (haven't installed it).
it usually happens when I have a bunch of audio files playing inside the notebook (I train TTS).

@DonJayamanne
Copy link
Contributor

@SoshyHayami Please can you file a separate issue for that, and please can you provide a sample notebook with all of the necessary dependencies to repro the issue (perhaps a requirements.txt or conda yml file to setup the python envirolnment).
Also if there are any audio or other files, please do attach those as well.

@JasonGross
Copy link

This issue also seems to occur with Microsoft's IntelliCode, so it seems like it might be common to LLM-based code completion extensions

@jorenham
Copy link

I'm using neither IntelliCode nor copilot, but I do use codeium, so perhaps @JasonGross is on the right track here

@DonJayamanne
Copy link
Contributor

This issue also seems to occur with Microsoft's IntelliCode, so it seems like it might be common to LLM-based code completion extensions

@JasonGross Do you mean that performance is back to normal when IntelliCode is disabled?

@rebornix
Copy link
Member

For the copilot relevant issues, we are working with Copilot team for a fix and will keep you posted.

@amunger
Copy link
Contributor

amunger commented Apr 30, 2024

I'm going to close this issue since we've taken care of two of the major causes of poor performance and this thread has gotten really long and difficult to navigate. Please use a more specific issue for any other performance issues or file a separate issue with the specific poor performance patterns that you are experiencing.

CPU profiles are usually very helpful if it is something new:
https://github.com/microsoft/vscode/wiki/Performance-Issues#profile-the-running-extensions
https://github.com/microsoft/vscode/wiki/Performance-Issues#profiling-the-renderer-process

We'll use microsoft/vscode#211154 to track the issue with copilot from our end.
microsoft/vscode#211730 is tracking improving the save performance for large files.

A big thanks to everyone that helped gather diagnostics and help narrow down the issues!

@amunger amunger closed this as completed Apr 30, 2024
@microsoft microsoft locked as resolved and limited conversation to collaborators Apr 30, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Issue identified by VS Code Team member as probable bug on-testplan perf Performance issues
Projects
None yet
Development

No branches or pull requests