Running notebook cells uses all available memory

[jjnurminen]

Hi,

since about 1-2 months ago, I cannot run many of my notebooks inside VS Code any more. When running certain cells, memory usage increases massively, eventually causing Windows to hang or terminate VS Code when all available RAM is taken.

Unfortunately I cannot share code due to IP issues and haven't yet came up with a minimal reproducible example. However, the issue seems to be quite often triggered by code that generates a bunch of matplotlib or plotly plots. I've seen it happen with other kinds of code too.

The issue occurs in both Insiders and regular VS Code. From Jupyter Lab the same code runs fine, no memory issues.

Running Windows 10 and latest VS Code releases.

[rchiodo]

Thanks for the issue.

Can you include the contents of the output 'Jupyter' tab.

Additionally can you tell us your settings?

This setting here might cause this problem:

"jupyter.generateSVGPlots": true

[jjnurminen]

@rchiodo I checked the SVG plots setting, it’s not on.

The Jupyter output tab doesn’t show much when this happens. Just the "Adding hash for..." message when the cell is executed, and then it hangs.

[rchiodo]

And the memory usage of the kernel is really large?

The full output of the jupyter tab may indicate something before you started running the cell. The output doesn't have your code in it, just your user name folder, so it shouldn't include any of your IP in it.

[jjnurminen]

@rchiodo full output of Jupyter tab is below. Here I executed two cells which set up some necessary stuff, and they ran fine. The output was captured before running the third one, which caused a hang.

I see that I'm in some Jupyter 'experiment groups', maybe I should try disabling the experiments?

Visual Studio Code (1.66.0, undefined, desktop)
Jupyter Extension Version: 2022.3.1000901801.
Python Extension Version: 2022.4.0.
Workspace folder c:\Users\vicon123\llinna
Info 17:55:09: ZMQ install verified.
User belongs to experiment group 'jupyterTest'
User belongs to experiment group 'jupyterEnhancedDataViewer'
Info 17:55:10: Old kernelspecs (created by Jupyter extension) stored in directory C:\Users\vicon123\AppData\Roaming\jupyter\kernels\__old_vscode_kernelspecs
Info 17:55:10: Experiment status for python is {"enabled":true,"optInto":[],"optOutFrom":[]}
Info 17:55:12: Got activated conda env vars ourselves for ~\.conda\envs\gaitutils_mar22\python.exe in 1268
Info 17:55:12: Process Execution: > ~\.conda\envs\gaitutils_mar22\python.exe -m pip list
> ~\.conda\envs\gaitutils_mar22\python.exe -m pip list
Info 17:56:42: Creating controller for interactive with interpreter ~\.conda\envs\gaitutils_mar22\python.exe
Info 17:56:42: Starting interactive window with controller ID ms-toolsai.jupyter/.jvsc74a57bd088bed4b7b7f109b29755200fbbde2b4e7e2aa8bf9b83ed9d11b5fd1c5bac4d26.C:\Users\vicon123\.conda\envs\gaitutils_mar22\python.exe.C:\Users\vicon123\.conda\envs\gaitutils_mar22\python.exe.-m#ipykernel_launcher (Interactive)
Info 17:56:42: Setting setActiveController for vscode-interactive:Interactive-1.interactive
Info 17:56:42: Starting Notebook in kernel.ts id = .jvsc74a57bd088bed4b7b7f109b29755200fbbde2b4e7e2aa8bf9b83ed9d11b5fd1c5bac4d26.C:\Users\vicon123\.conda\envs\gaitutils_mar22\python.exe.C:\Users\vicon123\.conda\envs\gaitutils_mar22\python.exe.-m#ipykernel_launcher for vscode-interactive:Interactive-1.interactive
Info 17:56:42: Creating raw notebook for vscode-interactive:Interactive-1.interactive
Info 17:56:42: Getting preferred kernel for vscode-interactive:Interactive-1.interactive
Info 17:56:42: Computing working directory vscode-interactive:Interactive-1.interactive
Info 17:56:42: Starting raw kernel gaitutils_mar22 (Python 3.10.2) for interpreter ~\.conda\envs\gaitutils_mar22\python.exe
Info 17:56:42: Kernel launching with ports 9000,9001,9002,9003,9004. Start port is 9000
Info 17:56:42: Process Execution: > ~\.conda\envs\gaitutils_mar22\python.exe -c "import ipykernel; print(ipykernel.__version__); print("5dc3a68c-e34e-4080-9c3e-2a532b2ccb4d"); print(ipykernel.__file__)"
> ~\.conda\envs\gaitutils_mar22\python.exe -c "import ipykernel; print(ipykernel.__version__); print("5dc3a68c-e34e-4080-9c3e-2a532b2ccb4d"); print(ipykernel.__file__)"
Info 17:56:42: Adding env Variable PYTHONNOUSERSITE to ~\.conda\envs\gaitutils_mar22\python.exe
Info 17:56:42: Creating controller for interactive with interpreter ~\.conda\envs\gaitutils_mar22\python.exe
Info 17:56:42: TargetController found ID: .jvsc74a57bd088bed4b7b7f109b29755200fbbde2b4e7e2aa8bf9b83ed9d11b5fd1c5bac4d26.C:\Users\vicon123\.conda\envs\gaitutils_mar22\python.exe.C:\Users\vicon123\.conda\envs\gaitutils_mar22\python.exe.-m#ipykernel_launcher (Interactive) for document vscode-interactive:Interactive-1.interactive
Info 17:56:42: Setting controller affinity for vscode-interactive:Interactive-1.interactive .jvsc74a57bd088bed4b7b7f109b29755200fbbde2b4e7e2aa8bf9b83ed9d11b5fd1c5bac4d26.C:\Users\vicon123\.conda\envs\gaitutils_mar22\python.exe.C:\Users\vicon123\.conda\envs\gaitutils_mar22\python.exe.-m#ipykernel_launcher (Interactive)
Info 17:56:42: Creating daemon process for ~\.conda\envs\gaitutils_mar22\python.exe with env variables count 75
Info 17:56:42: Process Execution: > ~\.conda\envs\gaitutils_mar22\python.exe -m vscode_datascience_helpers.daemon --daemon-module=vscode_datascience_helpers.kernel_interrupt_daemon -v --ppid 7576
> ~\.conda\envs\gaitutils_mar22\python.exe -m vscode_datascience_helpers.daemon --daemon-module=vscode_datascience_helpers.kernel_interrupt_daemon -v --ppid 7576
Info 17:56:43: Registering dummy command feature
Info 17:56:43: ipykernel version 6.9.1 for ~\.conda\envs\gaitutils_mar22\python.exe
Info 17:56:43: ipykernel location ~\.conda\envs\gaitutils_mar22\lib\site-packages\ipykernel\__init__.py for ~\.conda\envs\gaitutils_mar22\python.exe
Info 17:56:44: get interrupthandle daemon
Info 17:56:44: Process Execution: > ~\.conda\envs\gaitutils_mar22\python.exe -m ipykernel_launcher --ip=127.0.0.1 --stdin=9003 --control=9001 --hb=9000 --Session.signature_scheme="hmac-sha256" --Session.key=b"0f24d12e-42b9-40cb-9cd0-cf94e3593daa" --shell=9002 --transport="tcp" --iopub=9004 --f=C:\Users\vicon123\AppData\Local\Temp\tmp-7576VLgFjZIEH0Dy.json
> ~\.conda\envs\gaitutils_mar22\python.exe -m ipykernel_launcher --ip=127.0.0.1 --stdin=9003 --control=9001 --hb=9000 --Session.signature_scheme="hmac-sha256" --Session.key=b"0f24d12e-42b9-40cb-9cd0-cf94e3593daa" --shell=9002 --transport="tcp" --iopub=9004 --f=C:\Users\vicon123\AppData\Local\Temp\tmp-7576VLgFjZIEH0Dy.json
Info 17:56:44: Process Execution: cwd: c:\Users\vicon123\llinna\misc_gait
cwd: c:\Users\vicon123\llinna\misc_gait
Warn 17:56:46: StdErr from Kernel Process C:\Users\vicon123\.conda\envs\gaitutils_mar22\lib\site-packages\traitlets\traitlets.py:2202: FutureWarning: Supporting extra quotes around strings is deprecated in traitlets 5.0. You can use 'hmac-sha256' instead of '"hmac-sha256"' if you require traitlets >=5.
  warn(

Warn 17:56:46: StdErr from Kernel Process C:\Users\vicon123\.conda\envs\gaitutils_mar22\lib\site-packages\traitlets\traitlets.py:2157: FutureWarning: Supporting extra quotes around Bytes is deprecated in traitlets 5.0. Use '0f24d12e-42b9-40cb-9cd0-cf94e3593daa' instead of 'b"0f24d12e-42b9-40cb-9cd0-cf94e3593daa"'.
  warn(

Info 17:56:46: Kernel Output: NOTE: When using the `ipython kernel` entry point, Ctrl-C will not work.

To exit, you will have to explicitly quit this process, by either sending
"quit" from a client, or using Ctrl-\ in UNIX-like environments.

To read more about this, see https://github.com/ipython/ipython/issues/2049


To connect another client to this kernel, use:
    --existing C:\Users\vicon123\AppData\Local\Temp\tmp-7576VLgFjZIEH0Dy.json

Info 17:56:46: Raw session started and connected
Started kernel gaitutils_mar22 (Python 3.10.2)
Info 17:56:46: Finished connecting c239451f-158f-417f-b7b8-59ca61623bb9
Info 17:56:46: UpdateWorkingDirectoryAndPath in Kernel
Info 17:56:46: Executing silently Code (idle) = import types as _VSCODE_types\nimport os\nimport hashlib as _VSCODE_hashlib\nfrom IPython import get_ip
Info 17:56:46: Executing silently Code (completed) = import types as _VSCODE_types\nimport os\nimport hashlib as _VSCODE_hashlib\nfrom IPython import get_ip
Info 17:56:46: Executing silently Code (idle) = %load-ext autoreload\n%autoreload 2\n%gui qt5
Info 17:56:46: Executing silently Code (completed) = %load-ext autoreload\n%autoreload 2\n%gui qt5
Info 17:56:46: Waiting for idle on (kernel): 79de23a3-e9ac-410c-97ea-d6f3236bab0c -> idle
Info 17:56:46: Finished waiting for idle on (kernel): 79de23a3-e9ac-410c-97ea-d6f3236bab0c -> idle
Info 17:56:46: Executing silently Code (idle) = __file__ = 'c:\\Users\\vicon123\\llinna\\misc_gait\\autotag.py'
Info 17:56:46: Executing silently Code (completed) = __file__ = 'c:\\Users\\vicon123\\llinna\\misc_gait\\autotag.py'
Info 17:56:46: Adding hash for 1 = 9895009945e2 with 121 lines
Info 17:56:49: Cell 1 executed with state Success
Info 17:57:06: Adding hash for 2 = 6dfce1350279 with 35 lines
Info 17:57:06: Cell 2 executed with state Success

[rchiodo]

Unfortunately all that tells me is that it worked and that you're running code through the interactive window. I thought it might be related to jedi (what jupyter uses for auto completion) in the jupyter process but your extension version is new enough that we automatically disable jedi now.

Hmm, I think we'd need to generate a custom jupyter extension to debug this. Or if you can give us a repro that you can share then we could investigate here.

My only guess is that our startup code is somehow affecting your kernel. That should be the only difference between running our code and running this in jupyter.

[rchiodo]

Does the problem repro if you run the code inside of a notebook instead of the interactive window?

It might be our debug hook that's causing the problem (only used for interactive window):
https://github.com/microsoft/vscode-jupyter/blob/6e161e7deca31aab96acbd1d70af5ca48aa9f1f2/src/kernels/kernel.node.ts#L689

[rchiodo]

Debug hook looks like this:
https://github.com/microsoft/vscode-jupyter/blob/8b309169fdc69fb177bd67ded7a8c633f992264a/pythonFiles/vscode_datascience_helpers/kernel/addRunCellHook.py#L1

Essentially it creates a SHA1 hash of your code so we can name the cell for debugging. Naming the cell sets an environment variable.

I don't think this could cause a problem, but maybe the sha1 algorithm is really slow? And we did change this a couple of months ago (corresponds to when you said the problem started happening).

[jjnurminen]

@rchiodo I just ran the code inside of a VS Code notebook, and yes it still does crash.

I'm trying to come up with a minimal repro. It's not really a matter of code-related IP to be honest. It's more that the code reads some 3D imaging data using external libraries. Setting up the whole environment and test files on another system would be somewhat involved.

[rchiodo]

Hmm, just noticed that you said VS code crashed, not the kernel.

This might be a memory leak in VS code core that was just fixed yesterday.

Would you be able to try the insiders build of VS code to see it works there?

[jjnurminen]

Thanks for the suggestion @rchiodo. I updated Insiders to the latest version and ran the code there. Unfortunately the crash still persists.

However I did make some progress. My code generates plenty of debug messages via the logging module. After disabling the logging output, the issue went away! So it seems to be triggered by lot of output into the interactive window.

[jjnurminen]

Confirmed that I can crash VS Code by just running the following cell:

# %% let's crash
import logging

for k in range(10_000):
    logging.warning(k)

The first time it hung after printing 1438 warnings. The second time it hung without printing anything at all. However I can't seem to crash it by e.g. printing a lot of numbers using print().

[rchiodo]

Thanks for the repro. I can repro with the latest bits.

It chews up all the memory for one of the renderer processes.

[roblourens]

This is the classic issue of the jupyter extension concatenating all streaming output and calling replaceOutputItems with the result, which gets larger and larger. The EH messages get way ahead of the renderer process.

And we can't use 'append' just because the jupyter extension has to process possible terminal ansi codes, is that right? https://github.com/microsoft/vscode-jupyter/blob/d4aa4ea7855a8c148e91f10805da2a8402466694/src/kernels/execution/cellExecutionMessageHandler.ts#L849

There has to be a better way to do this

[DonJayamanne]

ut and calling replaceOutputItems with

@roblourens can you let me know what's the perf impact of calling this too many times. I.e. what's the underlying issue that blows up the memory usage.

[roblourens]

That method is called 10000 times with a payload that gets very large. vscode has to do a bunch of work to render an output from scratch on each iteration. It can't keep up and messages are written much faster than they are read by the renderer process. I was thinking this is basically the use-case that appendOutputItems was invented for.

[DonJayamanne]

was thinking this is basically the use-case that appendOutputItems was invented for.

let's sync up tomorrow or debt week.
part time we worked on this together, i didn't use the weekends items, as we need to process the data, and need to delete lines from a previous output.

i guess we can use a mix of both to optimize this scenario.
also, silly question, what about throttling the update.

let's sync during debt week

[DonJayamanne]

Should be fixed with #161023

[DonJayamanne]

Steps to validate

• Run the following python code

# %% let's crash
import logging

for k in range(10_000):
    logging.warning(k)

#146768 (comment)

[AndrewRocky]

Was this fixed?
On my machine #146768 (comment) still causes VSCode to go unresponsive and eventually almost freezes the whole machine (by consuming all RAM and loading system SSD on 100% (because it's a swap disk)).

Windows 10 21H2
VSCode 1.73.1

[DonJayamanne]

the fix will be in there next release, some time this week