microsoft / vscode-jupyter

VS Code Jupyter extension
https://marketplace.visualstudio.com/items?itemName=ms-toolsai.jupyter
MIT License
1.3k stars 294 forks source link

vs code freeze when rendering papermill notebook output #11636

Open ghylander opened 2 years ago

ghylander commented 2 years ago

Environment data

Description

VSC is instantly freezing when opening scrolling down to a papermill notebook cell with output Even before the the cell is actually shown (i assume it's pre-rendering it)

When this happens, the system slows down significantly

I tried downgrading the pylance extension to version 2022.4.3 (as I saw in other issues) but it had no effect

Perhaps may be caused by notebooks executed by papermill (https://github.com/nteract/papermill)?

Logs

Nothing weird here. There's no output when VSC freezes: ``` Visual Studio Code - Insiders (1.73.0-insider, undefined, desktop) Jupyter Extension Version: 2022.10.1102862059. Python Extension Version: 2022.17.12851050. No workspace folder opened. info 11:44:40.577: ZMQ install verified. User belongs to experiment group 'jupyterTestcf' User belongs to experiment group 'jupyterEnhancedDataViewer' info 11:44:41.523: LSP Notebooks experiment is disabled -- Pylance does not support experiment info 11:44:43.923: Preferred Remote kernel for c:\Users\gus_h\Desktop\test.ipynb is undefined info 11:44:44.425: Preferred Remote kernel for c:\Users\gus_h\Desktop\test.ipynb is undefined info 11:44:44.427: Find preferred kernel for c:\Users\gus_h\Desktop\test.ipynb with metadata {"kernelspec":{"display_name":"Python 3","language":"python","name":"python3"},"language_info":{"codemirror_mode":{"name":"ipython","version":3},"file_extension":".py","mimetype":"text/x-python","name":"python","nbconvert_exporter":"python","pygments_lexer":"ipython3","version":"3.10.7 (tags/v3.10.7:6cc6b13, Sep 5 2022, 14:08:36) [MSC v.1933 64 bit (AMD64)]"},"papermill":{"default_parameters":{},"duration":18908.864335,"end_time":"2022-10-10T18:02:11.861578","environment_variables":{},"exception":null,"input_path":"S2.1_3C_json.ipynb","output_path":"test.ipynb","parameters":{},"start_time":"2022-10-10T12:47:02.997243","version":"2.4.0"},"vscode":{"interpreter":{"hash":"461bf450c9324df63eb3bd695cb24b9b1bf30d4b8b02a43f08c1fd0902af10f4"}}} & preferred interpreter c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe info 11:44:44.467: Starting Jupyter Session startUsingPythonInterpreter, .jvsc74a57bd0461bf450c9324df63eb3bd695cb24b9b1bf30d4b8b02a43f08c1fd0902af10f4.c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe.c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe.-m#ipykernel_launcher (Python Path: c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe, EnvType: Unknown, EnvName: 'undefined', Version: 3.10.7 (tags/v3.10.7:6cc6b13, Sep 5 2022, 14:08:36) [MSC v.1933 64 bit (AMD64)]) for 'c:\Users\gus_h\Desktop\test.ipynb' (disableUI=true) info 11:44:44.470: Computing working directory for resource 'c:\Users\gus_h\Desktop\test.ipynb' info 11:44:44.478: Preferred Remote kernel for c:\Users\gus_h\Desktop\test.ipynb is undefined info 11:44:44.479: Preferred kernel .jvsc74a57bd0461bf450c9324df63eb3bd695cb24b9b1bf30d4b8b02a43f08c1fd0902af10f4.c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe.c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe.-m#ipykernel_launcher is exact match or top match for non python kernels, (false, [object Object], true, false) info 11:44:44.482: PreferredConnection: .jvsc74a57bd0461bf450c9324df63eb3bd695cb24b9b1bf30d4b8b02a43f08c1fd0902af10f4.c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe.c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe.-m#ipykernel_launcher found for NotebookDocument: c:\Users\gus_h\Desktop\test.ipynb info 11:44:46.191: Registering dummy command feature info 11:44:46.430: Got empty env vars with python c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe in 1995ms info 11:44:46.547: Process Execution: > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe -m pip list > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe -m pip list info 11:44:46.556: Got env vars ourselves faster c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe with env var count 75 in 1865ms info 11:44:46.756: Process Execution: > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe -c "import ipykernel; print(ipykernel.__version__); print("5dc3a68c-e34e-4080-9c3e-2a532b2ccb4d"); print(ipykernel.__file__)" > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe -c "import ipykernel; print(ipykernel.__version__); print("5dc3a68c-e34e-4080-9c3e-2a532b2ccb4d"); print(ipykernel.__file__)" info 11:44:46.768: Got empty env vars with python c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe in 2077ms info 11:44:47.006: Got env vars ourselves faster c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe with env var count 75 in 13ms info 11:44:47.006: Got env vars ourselves faster c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe with env var count 75 in 12ms info 11:44:47.026: Got env vars ourselves faster c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe with env var count 75 in 1ms info 11:44:47.386: Process Execution: > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe ~\.vscode-insiders\extensions\ms-toolsai.jupyter-2022.10.1102862059\pythonFiles\vscode_datascience_helpers\kernel_interrupt_daemon.py --ppid 5536 > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe ~\.vscode-insiders\extensions\ms-toolsai.jupyter-2022.10.1102862059\pythonFiles\vscode_datascience_helpers\kernel_interrupt_daemon.py --ppid 5536 info 11:44:47.386: Process Execution: cwd: ~\.vscode-insiders\extensions\ms-toolsai.jupyter-2022.10.1102862059\pythonFiles\vscode_datascience_helpers cwd: ~\.vscode-insiders\extensions\ms-toolsai.jupyter-2022.10.1102862059\pythonFiles\vscode_datascience_helpers info 11:44:47.585: Got empty env vars with python c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe in 592ms info 11:44:47.591: Got empty env vars with python c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe in 597ms info 11:44:47.595: Got empty env vars with python c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe in 570ms info 11:44:49.166: Process Execution: > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe -m ipykernel_launcher --ip=127.0.0.1 --stdin=9013 --control=9011 --hb=9010 --Session.signature_scheme="hmac-sha256" --Session.key=b"3b9d88b1-1310-450a-8b7d-5dc80f2261d3" --shell=9012 --transport="tcp" --iopub=9014 --f=c:\Users\gus_h\AppData\Roaming\jupyter\runtime\kernel-v2-5536Av1H5t07Wm0q.json > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe -m ipykernel_launcher --ip=127.0.0.1 --stdin=9013 --control=9011 --hb=9010 --Session.signature_scheme="hmac-sha256" --Session.key=b"3b9d88b1-1310-450a-8b7d-5dc80f2261d3" --shell=9012 --transport="tcp" --iopub=9014 --f=c:\Users\gus_h\AppData\Roaming\jupyter\runtime\kernel-v2-5536Av1H5t07Wm0q.json info 11:44:49.166: Process Execution: cwd: ~\Desktop cwd: ~\Desktop info 11:44:49.211: ipykernel version & path 6.0.3, ~\AppData\Local\Packages\PythonSoftwareFoundation.Python.3.10_qbz5n2kfra8p0\LocalCache\local-packages\Python310\site-packages\ipykernel\__init__.py for c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe warn 11:44:54.227: StdErr from Kernel Process C:\Users\gus_h\AppData\Local\Packages\PythonSoftwareFoundation.Python.3.10_qbz5n2kfra8p0\LocalCache\local-packages\Python310\site-packages\traitlets\traitlets.py:2196: FutureWarning: Supporting extra quotes around Unicode is deprecated in traitlets 5.0. Use 'hmac-sha256' instead of '"hmac-sha256"' – or use CUnicode. warn( C:\Users\gus_h\AppData\Local\Packages\PythonSoftwareFoundation.Python.3.10_qbz5n2kfra8p0\LocalCache\local-packages\Python310\site-packages\traitlets\traitlets.py:2151: FutureWarning: Supporting extra quotes around Bytes is deprecated in traitlets 5.0. Use '3b9d88b1-1310-450a-8b7d-5dc80f2261d3' instead of 'b"3b9d88b1-1310-450a-8b7d-5dc80f2261d3"'. warn( info 11:44:54.831: Kernel Output: To connect another client to this kernel, use: --existing c:\Users\gus_h\AppData\Roaming\jupyter\runtime\kernel-v2-5536Av1H5t07Wm0q.json info 11:44:55.036: Started Kernel Python 3 (pid: 17532) info 11:44:55.043: UpdateWorkingDirectoryAndPath in Kernel info 11:44:58.054: Got env vars ourselves faster c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe with env var count 75 in 2ms info 11:44:58.145: Process Execution: > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe ~\.vscode-insiders\extensions\ms-toolsai.jupyter-2022.10.1102862059\pythonFiles\printJupyterDataDir.py > ~\AppData\Local\Microsoft\WindowsApps\python3.10.exe ~\.vscode-insiders\extensions\ms-toolsai.jupyter-2022.10.1102862059\pythonFiles\printJupyterDataDir.py info 11:44:58.246: Got empty env vars with python c:\Users\gus_h\AppData\Local\Microsoft\WindowsApps\python3.10.exe in 194ms ```
ghylander commented 2 years ago

This is the "source" for a regular notebook cell:

{
   "cell_type": "code",
   "execution_count": 16,
   "metadata": {
    "execution": {
     "iopub.execute_input": "2021-07-05T10:42:52.838788Z",
     "iopub.status.busy": "2021-07-05T10:42:52.838238Z",
     "iopub.status.idle": "2021-07-05T10:42:55.231015Z",
     "shell.execute_reply": "2021-07-05T10:42:55.231372Z"
    }
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Test1\n",
      "Test2\n"
     ]
    }
   ],
   "source": [
    "[...]"
   ]
  },

And this is the same cell after the notebook is executed through papermill:

{
   "cell_type": "code",
   "execution_count": 16,
   "id": "38fa880c",
   "metadata": {
    "execution": {
     "iopub.execute_input": "2022-10-10T12:47:06.086042Z",
     "iopub.status.busy": "2022-10-10T12:47:06.085877Z",
     "iopub.status.idle": "2022-10-10T12:47:07.302541Z",
     "shell.execute_reply": "2022-10-10T12:47:07.302091Z"
    },
    "papermill": {
     "duration": 1.226089,
     "end_time": "2022-10-10T12:47:07.303689",
     "exception": false,
     "start_time": "2022-10-10T12:47:06.077600",
     "status": "completed"
    },
    "tags": []
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Test1\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Test2\n"
     ]
    }
   ],
   "source": [
    "[...]
  }
ghylander commented 2 years ago

There's 2 main differences (at least in this case):

The output is divided into sub-elements:

"outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Test1\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Test2\n"
     ]
    }
   ],
rebornix commented 2 years ago

@ghylander do you have the notebook document open all the time when this happened? Does it still happen when you close the same notebook and open again?

ghylander commented 2 years ago

Hi,

Yes, this happens if when I start VSC I don't have the notebook open, then open it. I can open the notebook, as long as I don't scroll down to a cell with output

I think I may have found a cause. When rendering a regular notebook in VSC, the output of cells is trimmed to the size limit, with an option to open the full output in a text editor

This does not happen with the papermill notebooks, the full output of the cell is shown. I think this might be caused because in papermill, the 'output' element is subdivided into individual output elements, instead of grouping all output in a single element (therefore, VSC instead of trimming one single large output, detects that each output is small in size and does not trim them individually).

The output of some of the cells in the notebook is very large (hundreds of lines of text per cell). As they are divided by element instead of grouped together, every single sub-element is rendered. Perhaps VSC is freezing when trying to render the full output of hundreds of lines inside the notebook

If this turns out to be what's happening, I can't tell if it would be something fixable from the jupyter extension or directly on VSC side

amunger commented 11 months ago

That makes it sound like what I was experiencing when running the repro example for https://github.com/microsoft/vscode/issues/141022 - vscode just becomes unresponsive. I think there is some limit for how many outputs we will display, but maybe that's just for images. either way, a configureable limit for output items to display would help here, aside from looking into what specifically goes wrong when it's overloaded like that. (it doesn't look like typical memory pressure)