排查Python3.10环境下Jupyter Lab单元格执行缓慢问题

问题背景 #

将Python版本从3.9升级到3.10后，Jupyter Lab执行最简单的单元格（如a = 1）有时耗时长达3秒。使用环境为Windows 10企业网络，常规运行日志如下：

NumExpr defaulting to 8 threads.
[I 2022-07-28 08:24:06.341 ServerApp] jupyter_lsp | extension was successfully linked.
[I 2022-07-28 08:24:06.346 ServerApp] jupyter_server_mathjax | extension was successfully linked.
[I 2022-07-28 08:24:06.347 ServerApp] jupyter_server_proxy | extension was successfully linked.
[I 2022-07-28 08:24:06.356 ServerApp] jupyterlab | extension was successfully linked.
[I 2022-07-28 08:24:06.365 ServerApp] nbclassic | extension was successfully linked.
[I 2022-07-28 08:24:06.365 ServerApp] nbdime | extension was successfully linked.
[I 2022-07-28 08:24:08.633 ServerApp] notebook_shim | extension was successfully linked.
[I 2022-07-28 08:24:08.633 ServerApp] panel.io.jupyter_server_extension | extension was successfully linked.
[I 2022-07-28 08:24:08.633 ServerApp] voila.server_extension | extension was successfully linked.
[I 2022-07-28 08:24:08.671 ServerApp] notebook_shim | extension was successfully loaded.
[I 2022-07-28 08:24:09.399 ServerApp] Skipped non-installed server(s): bash-language-server, dockerfile-language-server-nodejs, javascript-typescript-langserver, jedi-language-server, julia-language-server, pyright, python-language-server, r-languageserver, sql-language-server, texlab, typescript-language-server, unified-language-server, vscode-css-languageserver-bin, vscode-html-languageserver-bin, vscode-json-languageserver-bin, yaml-language-server
[I 2022-07-28 08:24:09.593 ServerApp] jupyter_lsp | extension was successfully loaded.
[I 2022-07-28 08:24:09.595 ServerApp] jupyter_server_mathjax | extension was successfully loaded.
[I 2022-07-28 08:24:09.630 ServerApp] jupyter_server_proxy | extension was successfully loaded.
[I 2022-07-28 08:24:09.632 LabApp] JupyterLab extension loaded from C:\\other_software\\Winpython64-3.10.4.0\\WPy64-31040\\python-3.10.4.amd64\\lib\\site-packages\\jupyterlab
[I 2022-07-28 08:24:09.632 LabApp] JupyterLab application directory is C:\\other_software\\Winpython64-3.10.4.0\\WPy64-31040\\python-3.10.4.amd64\\share\\jupyter\\lab
[I 2022-07-28 08:24:09.635 ServerApp] jupyterlab | extension was successfully loaded.
[I 2022-07-28 08:24:09.643 ServerApp] nbclassic | extension was successfully loaded.
[I 2022-07-28 08:24:09.778 ServerApp] nbdime | extension was successfully loaded.
/panel-preview/ /panel-preview
[I 2022-07-28 08:24:09.779 ServerApp] panel.io.jupyter_server_extension | extension was successfully loaded.
[I 2022-07-28 08:24:09.787 ServerApp] voila.server_extension | extension was successfully loaded.
[I 2022-07-28 08:24:09.788 ServerApp] Serving notebooks from local directory: C:\\Users\\user01\\OneDrive\\Documents\\Python\\notebooks
[I 2022-07-28 08:24:09.788 ServerApp] Jupyter Server 1.17.0 is running at:
[I 2022-07-28 08:24:09.789 ServerApp] http://localhost:8888/lab?token=3adeff1d08fbbd087926e7fb006f1ff52813a474dec012be
[I 2022-07-28 08:24:09.789 ServerApp]  or http://127.0.0.1:8888/lab?token=3adeff1d08fbbd087926e7fb006f1ff52813a474dec012be
[I 2022-07-28 08:24:09.789 ServerApp] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[C 2022-07-28 08:24:09.835 ServerApp]

    To access the server, open this file in a browser:
        file:///C:/other_software/Winpython64-3.10.4.0/WPy64-31040/settings/runtime/jpserver-17128-open.html
    Or copy and paste one of these URLs:
        http://localhost:8888/lab?token=3adeff1d08fbbd087926e7fb006f1ff52813a474dec012be
     or http://127.0.0.1:8888/lab?token=3adeff1d08fbbd087926e7fb006f1ff52813a474dec012be
[I 2022-07-28 08:24:14.274 LabApp] Build is up to date
[I 2022-07-28 08:24:15.639 ServerApp] Kernel started: 9b7a709a-1553-44d2-8180-3f8e5686d48a
[W 2022-07-28 08:24:17.343 ServerApp] Got events for closed stream <zmq.eventloop.zmqstream.ZMQStream object at 0x000001C0DFA03910>
[IPKernelApp] ERROR | No such comm target registered: jupyter.widget.control
[IPKernelApp] WARNING | No such comm: 19eec36d-a89b-4c88-ae5e-4a96ec9bb23f
[I 2022-07-28 08:26:14.940 ServerApp] Saving file at /Projects/test/test.ipynb
[I 2022-07-28 08:28:17.394 ServerApp] Saving file at /Projects/test/test.ipynb
[I 2022-07-28 08:39:06.710 ServerApp] Saving file at /Projects/test/test.ipynb
[I 2022-07-28 08:39:09.889 ServerApp] Kernel started: 15c66d7e-8d29-4405-b0b1-bd320ba05a87
C:\\other_software\\Winpython64-3.10.4.0\\WPy64-31040\\python-3.10.4.amd64\\lib\\site-packages\\zmq\\_future.py:591: RuntimeWarning: Proactor event loop does not implement add_reader family of methods required for zmq. Registering an additional selector thread for add_reader support via tornado. Use `asyncio.set_event_loop_policy(WindowsSelectorEventLoopPolicy())` to avoid this warning.
  self._get_loop()
[I 2022-07-28 08:47:54.620 ServerApp] Creating new notebook in /Projects/test
[I 2022-07-28 08:47:57.711 ServerApp] Kernel started: b66e839f-0ccc-49d2-a608-8611b10346f3
[IPKernelApp] ERROR | No such comm target registered: jupyter.widget.control
[IPKernelApp] WARNING | No such comm: 7064f22d-7c01-4966-bdb9-99cd4cc24dcf

排查方法 #

可以通过记录后台流程定位问题，具体步骤如下：

• 启用内核详细日志
  启动Jupyter Lab时添加--debug参数，命令为：

  jupyter lab --debug
  

  该命令会输出内核启动、单元格执行的详细步骤，可直接观察到每一步的耗时节点。也可以修改内核配置文件：先用jupyter --config-dir找到配置目录，编辑kernel.json，在argv数组末尾添加--debug，重启内核后日志会输出到终端。

• 监控系统进程与资源

  • 打开任务管理器，切换到「详细信息」标签，监控python.exe（Jupyter内核进程）的CPU、内存、磁盘、网络占用，执行单元格时观察是否有异常的网络请求（企业环境可能存在代理拦截）或磁盘IO突增。
  • 使用Process Monitor工具追踪内核进程的文件访问、注册表操作、网络连接，筛选单元格执行时段的事件，排查是否存在文件锁、连接超时等阻塞操作。

• 修复ZMQ事件循环警告
  日志中出现的ZMQ事件循环警告是Python 3.10 Windows默认事件循环的兼容性问题，会额外启动线程导致延迟。解决方法：
  在启动Jupyter前执行以下代码：

  import asyncio
  from asyncio import WindowsSelectorEventLoopPolicy
  asyncio.set_event_loop_policy(WindowsSelectorEventLoopPolicy())
  

  或者设置环境变量PYTHONASYNCIODEBUG=1后再启动Jupyter Lab。

• 禁用无关扩展排查
  日志显示加载了多个扩展（panel、voila、nbdime等），部分扩展可能在Python 3.10下存在兼容性问题。先用jupyter lab --no-extensions启动，若速度恢复正常，再逐个启用扩展定位问题源。

• 排除OneDrive同步影响
  笔记本存储在OneDrive目录，执行单元格时可能触发自动同步导致文件IO阻塞。可暂时将笔记本移到本地非OneDrive目录测试，或暂停OneDrive同步后观察执行速度。

内容的提问来源于stack exchange，提问作者Pi.Lilac