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

nbconvert handler is affected by slow filesystems and blocks event loop #490

Closed
hMED22 opened this issue Apr 22, 2021 · 8 comments · Fixed by #512
Closed

nbconvert handler is affected by slow filesystems and blocks event loop #490

hMED22 opened this issue Apr 22, 2021 · 8 comments · Fixed by #512
Assignees
Labels
Milestone

Comments

@hMED22
Copy link

hMED22 commented Apr 22, 2021

Description

Jupyterlab makes a request to /api/nbconvert while initializing but the handler of that endpoint could be too slow depending on the filesystem and it blocks the event loop which blocks other requests and delays Jupyterlab initialization for too long.

image

To make things worst Jupyterlab makes that request twice.

Reproduce

  1. Mount a remote filesystem like sshfs [user@]hostname:[directory] mountpoint
  2. Start Jupyterlab on that mountpoint or a subdirectory
  3. Wait for Jupyterlab to open on the browser and initialize.

On Devtools notice that all subsequent requests are blocked until we receive responses for both requests to nbconvert exporters endpoint (screenshot above).

Expected behavior

nbconvert requests not block Jupyterlab initialization.

Context

  • Operating System and version: Ubuntu 20.04.2 LTS
  • Browser and version: Mozilla Firefox 87.0
  • Jupyter Server version: 1.6.4
  • Jupyter Lab version: 3.0.14
Troubleshoot Output
$PATH:
	/home/hmed/miniconda3/envs/jupyterlab3.0.14/bin
	/home/hmed/miniconda3/condabin
	/home/hmed/.local/bin
	/usr/local/sbin
	/usr/local/bin
	/usr/sbin
	/usr/bin
	/sbin
	/bin
	/usr/games
	/usr/local/games
	/snap/bin

sys.path:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/bin
/home/hmed/miniconda3/envs/jupyterlab3.0.14/lib/python39.zip
/home/hmed/miniconda3/envs/jupyterlab3.0.14/lib/python3.9
/home/hmed/miniconda3/envs/jupyterlab3.0.14/lib/python3.9/lib-dynload
/home/hmed/miniconda3/envs/jupyterlab3.0.14/lib/python3.9/site-packages

sys.executable:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/bin/python

sys.version:
3.9.2 | packaged by conda-forge | (default, Feb 21 2021, 05:02:46)
[GCC 9.3.0]

platform.platform():
Linux-5.8.0-50-generic-x86_64-with-glibc2.31

which -a jupyter:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/bin/jupyter

pip list:
Package Version
----------------------------- -------------------
anyio 2.2.0
argon2-cffi 20.1.0
arrow 1.0.3
async-generator 1.10
attrs 20.3.0
Babel 2.9.0
backcall 0.2.0
backports.functools-lru-cache 1.6.4
binaryornot 0.4.4
bleach 3.3.0
brotlipy 0.7.0
certifi 2020.12.5
cffi 1.14.5
chardet 4.0.0
click 7.1.2
cookiecutter 1.7.2
cryptography 3.4.7
decorator 5.0.7
defusedxml 0.7.1
deprecation 2.1.0
entrypoints 0.3
idna 2.10
importlib-metadata 4.0.1
ipykernel 5.5.3
ipython 7.22.0
ipython-genutils 0.2.0
jedi 0.18.0
Jinja2 2.11.3
jinja2-time 0.2.0
json5 0.9.5
jsonschema 3.2.0
jupyter-client 6.1.12
jupyter-core 4.7.1
jupyter-packaging 0.9.2
jupyter-server 1.6.4
jupyterlab 3.0.14
jupyterlab-pygments 0.1.2
jupyterlab-server 2.4.0
MarkupSafe 1.1.1
mistune 0.8.4
nbclassic 0.2.7
nbclient 0.5.3
nbconvert 6.0.7
nbformat 5.1.3
nest-asyncio 1.5.1
notebook 6.3.0
packaging 20.9
pandocfilters 1.4.2
parso 0.8.2
pexpect 4.8.0
pickleshare 0.7.5
pip 21.0.1
poyo 0.5.0
prometheus-client 0.10.1
prompt-toolkit 3.0.18
ptyprocess 0.7.0
pycparser 2.20
Pygments 2.8.1
pyOpenSSL 20.0.1
pyparsing 2.4.7
pyrsistent 0.17.3
PySocks 1.7.1
python-dateutil 2.8.1
python-slugify 4.0.1
pytz 2021.1
pyzmq 22.0.3
requests 2.25.1
Send2Trash 1.5.0
setuptools 49.6.0.post20210108
six 1.15.0
sniffio 1.2.0
terminado 0.9.4
testpath 0.4.4
text-unidecode 1.3
tomlkit 0.7.0
tornado 6.1
traitlets 5.0.5
typing-extensions 3.7.4.3
Unidecode 1.2.0
urllib3 1.26.4
wcwidth 0.2.5
webencodings 0.5.1
wheel 0.36.2
whichcraft 0.6.1
zipp 3.4.1

conda list:
# packages in environment at /home/hmed/miniconda3/envs/jupyterlab3.0.14:
#
# Name Version Build Channel
_libgcc_mutex 0.1 conda_forge conda-forge
_openmp_mutex 4.5 1_gnu conda-forge
anyio 2.2.0 py39hf3d152e_0 conda-forge
argon2-cffi 20.1.0 py39h3811e60_2 conda-forge
arrow 1.0.3 py39hf3d152e_0 conda-forge
async_generator 1.10 py_0 conda-forge
attrs 20.3.0 pyhd3deb0d_0 conda-forge
babel 2.9.0 pyhd3deb0d_0 conda-forge
backcall 0.2.0 pyh9f0ad1d_0 conda-forge
backports 1.0 py_2 conda-forge
backports.functools_lru_cache 1.6.4 pyhd8ed1ab_0 conda-forge
binaryornot 0.4.4 py_1 conda-forge
bleach 3.3.0 pyh44b312d_0 conda-forge
brotlipy 0.7.0 py39h3811e60_1001 conda-forge
ca-certificates 2020.12.5 ha878542_0 conda-forge
certifi 2020.12.5 py39hf3d152e_1 conda-forge
cffi 1.14.5 py39he32792d_0 conda-forge
chardet 4.0.0 py39hf3d152e_1 conda-forge
click 7.1.2 pyh9f0ad1d_0 conda-forge
cookiecutter 1.7.2 pyh9f0ad1d_0 conda-forge
cryptography 3.4.7 py39hbca0aa6_0 conda-forge
decorator 5.0.7 pyhd8ed1ab_0 conda-forge
defusedxml 0.7.1 pyhd8ed1ab_0 conda-forge
deprecation 2.1.0 pyh9f0ad1d_0 conda-forge
entrypoints 0.3 pyhd8ed1ab_1003 conda-forge
icu 68.1 h58526e2_0 conda-forge
idna 2.10 pyh9f0ad1d_0 conda-forge
importlib-metadata 4.0.1 py39hf3d152e_0 conda-forge
ipykernel 5.5.3 py39hef51801_0 conda-forge
ipython 7.22.0 py39hef51801_0 conda-forge
ipython_genutils 0.2.0 py_1 conda-forge
jedi 0.18.0 py39hf3d152e_2 conda-forge
jinja2 2.11.3 pyh44b312d_0 conda-forge
jinja2-time 0.2.0 py_2 conda-forge
json5 0.9.5 pyh9f0ad1d_0 conda-forge
jsonschema 3.2.0 pyhd8ed1ab_3 conda-forge
jupyter-packaging 0.9.2 pyhd8ed1ab_0 conda-forge
jupyter_client 6.1.12 pyhd8ed1ab_0 conda-forge
jupyter_core 4.7.1 py39hf3d152e_0 conda-forge
jupyter_server 1.6.4 py39hf3d152e_0 conda-forge
jupyterlab 3.0.14 pyhd8ed1ab_0 conda-forge
jupyterlab_pygments 0.1.2 pyh9f0ad1d_0 conda-forge
jupyterlab_server 2.4.0 pyhd8ed1ab_0 conda-forge
ld_impl_linux-64 2.35.1 hea4e1c9_2 conda-forge
libffi 3.3 h58526e2_2 conda-forge
libgcc-ng 9.3.0 h2828fa1_19 conda-forge
libgomp 9.3.0 h2828fa1_19 conda-forge
libsodium 1.0.18 h36c2ea0_1 conda-forge
libstdcxx-ng 9.3.0 h6de172a_19 conda-forge
libuv 1.41.0 h7f98852_0 conda-forge
markupsafe 1.1.1 py39h3811e60_3 conda-forge
mistune 0.8.4 py39h3811e60_1003 conda-forge
nbclassic 0.2.7 pyhd8ed1ab_0 conda-forge
nbclient 0.5.3 pyhd8ed1ab_0 conda-forge
nbconvert 6.0.7 py39hf3d152e_3 conda-forge
nbformat 5.1.3 pyhd8ed1ab_0 conda-forge
ncurses 6.2 h58526e2_4 conda-forge
nest-asyncio 1.5.1 pyhd8ed1ab_0 conda-forge
nodejs 15.14.0 h92b4a50_0 conda-forge
notebook 6.3.0 pyha770c72_1 conda-forge
openssl 1.1.1k h7f98852_0 conda-forge
packaging 20.9 pyh44b312d_0 conda-forge
pandoc 2.12 h7f98852_0 conda-forge
pandocfilters 1.4.2 py_1 conda-forge
parso 0.8.2 pyhd8ed1ab_0 conda-forge
pexpect 4.8.0 pyh9f0ad1d_2 conda-forge
pickleshare 0.7.5 py_1003 conda-forge
pip 21.0.1 pyhd8ed1ab_0 conda-forge
poyo 0.5.0 py_0 conda-forge
prometheus_client 0.10.1 pyhd8ed1ab_0 conda-forge
prompt-toolkit 3.0.18 pyha770c72_0 conda-forge
ptyprocess 0.7.0 pyhd3deb0d_0 conda-forge
pycparser 2.20 pyh9f0ad1d_2 conda-forge
pygments 2.8.1 pyhd8ed1ab_0 conda-forge
pyopenssl 20.0.1 pyhd8ed1ab_0 conda-forge
pyparsing 2.4.7 pyh9f0ad1d_0 conda-forge
pyrsistent 0.17.3 py39h3811e60_2 conda-forge
pysocks 1.7.1 py39hf3d152e_3 conda-forge
python 3.9.2 hffdb5ce_0_cpython conda-forge
python-dateutil 2.8.1 py_0 conda-forge
python-slugify 4.0.1 pyh9f0ad1d_0 conda-forge
python_abi 3.9 1_cp39 conda-forge
pytz 2021.1 pyhd8ed1ab_0 conda-forge
pyzmq 22.0.3 py39h37b5a0c_1 conda-forge
readline 8.1 h46c0cb4_0 conda-forge
requests 2.25.1 pyhd3deb0d_0 conda-forge
send2trash 1.5.0 py_0 conda-forge
setuptools 49.6.0 py39hf3d152e_3 conda-forge
six 1.15.0 pyh9f0ad1d_0 conda-forge
sniffio 1.2.0 py39hf3d152e_1 conda-forge
sqlite 3.35.4 h74cdb3f_0 conda-forge
terminado 0.9.4 py39hf3d152e_0 conda-forge
testpath 0.4.4 py_0 conda-forge
text-unidecode 1.3 py_0 conda-forge
tk 8.6.10 h21135ba_1 conda-forge
tomlkit 0.7.0 py39hf3d152e_3 conda-forge
tornado 6.1 py39h3811e60_1 conda-forge
traitlets 5.0.5 py_0 conda-forge
typing_extensions 3.7.4.3 py_0 conda-forge
tzdata 2021a he74cb21_0 conda-forge
unidecode 1.2.0 pyhd8ed1ab_0 conda-forge
urllib3 1.26.4 pyhd8ed1ab_0 conda-forge
wcwidth 0.2.5 pyh9f0ad1d_2 conda-forge
webencodings 0.5.1 py_1 conda-forge
wheel 0.36.2 pyhd3deb0d_0 conda-forge
whichcraft 0.6.1 py_0 conda-forge
xz 5.2.5 h516909a_1 conda-forge
zeromq 4.3.4 h9c3ff4c_0 conda-forge
zipp 3.4.1 pyhd8ed1ab_0 conda-forge
zlib 1.2.11 h516909a_1010 conda-forge

conda env:
name: jupyterlab3.0.14
channels:
- conda-forge
- defaults
dependencies:
- _libgcc_mutex=0.1=conda_forge
- _openmp_mutex=4.5=1_gnu
- anyio=2.2.0=py39hf3d152e_0
- argon2-cffi=20.1.0=py39h3811e60_2
- arrow=1.0.3=py39hf3d152e_0
- async_generator=1.10=py_0
- attrs=20.3.0=pyhd3deb0d_0
- babel=2.9.0=pyhd3deb0d_0
- backcall=0.2.0=pyh9f0ad1d_0
- backports=1.0=py_2
- backports.functools_lru_cache=1.6.4=pyhd8ed1ab_0
- binaryornot=0.4.4=py_1
- bleach=3.3.0=pyh44b312d_0
- brotlipy=0.7.0=py39h3811e60_1001
- ca-certificates=2020.12.5=ha878542_0
- certifi=2020.12.5=py39hf3d152e_1
- cffi=1.14.5=py39he32792d_0
- chardet=4.0.0=py39hf3d152e_1
- click=7.1.2=pyh9f0ad1d_0
- cookiecutter=1.7.2=pyh9f0ad1d_0
- cryptography=3.4.7=py39hbca0aa6_0
- decorator=5.0.7=pyhd8ed1ab_0
- defusedxml=0.7.1=pyhd8ed1ab_0
- deprecation=2.1.0=pyh9f0ad1d_0
- entrypoints=0.3=pyhd8ed1ab_1003
- icu=68.1=h58526e2_0
- idna=2.10=pyh9f0ad1d_0
- importlib-metadata=4.0.1=py39hf3d152e_0
- ipykernel=5.5.3=py39hef51801_0
- ipython=7.22.0=py39hef51801_0
- ipython_genutils=0.2.0=py_1
- jedi=0.18.0=py39hf3d152e_2
- jinja2=2.11.3=pyh44b312d_0
- jinja2-time=0.2.0=py_2
- json5=0.9.5=pyh9f0ad1d_0
- jsonschema=3.2.0=pyhd8ed1ab_3
- jupyter-packaging=0.9.2=pyhd8ed1ab_0
- jupyter_client=6.1.12=pyhd8ed1ab_0
- jupyter_core=4.7.1=py39hf3d152e_0
- jupyter_server=1.6.4=py39hf3d152e_0
- jupyterlab=3.0.14=pyhd8ed1ab_0
- jupyterlab_pygments=0.1.2=pyh9f0ad1d_0
- jupyterlab_server=2.4.0=pyhd8ed1ab_0
- ld_impl_linux-64=2.35.1=hea4e1c9_2
- libffi=3.3=h58526e2_2
- libgcc-ng=9.3.0=h2828fa1_19
- libgomp=9.3.0=h2828fa1_19
- libsodium=1.0.18=h36c2ea0_1
- libstdcxx-ng=9.3.0=h6de172a_19
- libuv=1.41.0=h7f98852_0
- markupsafe=1.1.1=py39h3811e60_3
- mistune=0.8.4=py39h3811e60_1003
- nbclassic=0.2.7=pyhd8ed1ab_0
- nbclient=0.5.3=pyhd8ed1ab_0
- nbconvert=6.0.7=py39hf3d152e_3
- nbformat=5.1.3=pyhd8ed1ab_0
- ncurses=6.2=h58526e2_4
- nest-asyncio=1.5.1=pyhd8ed1ab_0
- nodejs=15.14.0=h92b4a50_0
- notebook=6.3.0=pyha770c72_1
- openssl=1.1.1k=h7f98852_0
- packaging=20.9=pyh44b312d_0
- pandoc=2.12=h7f98852_0
- pandocfilters=1.4.2=py_1
- parso=0.8.2=pyhd8ed1ab_0
- pexpect=4.8.0=pyh9f0ad1d_2
- pickleshare=0.7.5=py_1003
- pip=21.0.1=pyhd8ed1ab_0
- poyo=0.5.0=py_0
- prometheus_client=0.10.1=pyhd8ed1ab_0
- prompt-toolkit=3.0.18=pyha770c72_0
- ptyprocess=0.7.0=pyhd3deb0d_0
- pycparser=2.20=pyh9f0ad1d_2
- pygments=2.8.1=pyhd8ed1ab_0
- pyopenssl=20.0.1=pyhd8ed1ab_0
- pyparsing=2.4.7=pyh9f0ad1d_0
- pyrsistent=0.17.3=py39h3811e60_2
- pysocks=1.7.1=py39hf3d152e_3
- python=3.9.2=hffdb5ce_0_cpython
- python-dateutil=2.8.1=py_0
- python-slugify=4.0.1=pyh9f0ad1d_0
- python_abi=3.9=1_cp39
- pytz=2021.1=pyhd8ed1ab_0
- pyzmq=22.0.3=py39h37b5a0c_1
- readline=8.1=h46c0cb4_0
- requests=2.25.1=pyhd3deb0d_0
- send2trash=1.5.0=py_0
- setuptools=49.6.0=py39hf3d152e_3
- six=1.15.0=pyh9f0ad1d_0
- sniffio=1.2.0=py39hf3d152e_1
- sqlite=3.35.4=h74cdb3f_0
- terminado=0.9.4=py39hf3d152e_0
- testpath=0.4.4=py_0
- text-unidecode=1.3=py_0
- tk=8.6.10=h21135ba_1
- tomlkit=0.7.0=py39hf3d152e_3
- tornado=6.1=py39h3811e60_1
- traitlets=5.0.5=py_0
- typing_extensions=3.7.4.3=py_0
- tzdata=2021a=he74cb21_0
- unidecode=1.2.0=pyhd8ed1ab_0
- urllib3=1.26.4=pyhd8ed1ab_0
- wcwidth=0.2.5=pyh9f0ad1d_2
- webencodings=0.5.1=py_1
- wheel=0.36.2=pyhd3deb0d_0
- whichcraft=0.6.1=py_0
- xz=5.2.5=h516909a_1
- zeromq=4.3.4=h9c3ff4c_0
- zipp=3.4.1=pyhd8ed1ab_0
- zlib=1.2.11=h516909a_1010
prefix: /home/hmed/miniconda3/envs/jupyterlab3.0.14

Command Line Output
[D 2021-04-22 18:33:13.831 ServerApp] Searching ['/mnt/remote-home/tmp', '/home/hmed/.jupyter', '/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2021-04-22 18:33:13.831 ServerApp] Looking for jupyter_config in /etc/jupyter
[D 2021-04-22 18:33:13.831 ServerApp] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2021-04-22 18:33:13.831 ServerApp] Looking for jupyter_config in /home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter
[D 2021-04-22 18:33:13.832 ServerApp] Looking for jupyter_config in /home/hmed/.jupyter
[D 2021-04-22 18:33:13.832 ServerApp] Looking for jupyter_config in /mnt/remote-home/tmp
[D 2021-04-22 18:33:14.269 ServerApp] Looking for jupyter_server_config in /etc/jupyter
[D 2021-04-22 18:33:14.270 ServerApp] Looking for jupyter_server_config in /usr/local/etc/jupyter
[D 2021-04-22 18:33:14.270 ServerApp] Looking for jupyter_server_config in /home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter
[D 2021-04-22 18:33:14.271 ServerApp] Looking for jupyter_server_config in /home/hmed/.jupyter
[D 2021-04-22 18:33:14.271 ServerApp] Looking for jupyter_server_config in /mnt/remote-home/tmp
[D 2021-04-22 18:33:14.731 ServerApp] Paths used for configuration of jupyter_server_config: 
    	/etc/jupyter/jupyter_server_config.json
[D 2021-04-22 18:33:14.733 ServerApp] Paths used for configuration of jupyter_server_config: 
    	/usr/local/etc/jupyter/jupyter_server_config.json
[D 2021-04-22 18:33:14.734 ServerApp] Paths used for configuration of jupyter_server_config: 
    	/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/jupyter_server_config.d/jupyterlab.json
    	/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/jupyter_server_config.d/nbclassic.json
    	/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/jupyter_server_config.json
[D 2021-04-22 18:33:14.736 ServerApp] Paths used for configuration of jupyter_server_config: 
    	/home/hmed/.jupyter/jupyter_server_config.json
[D 2021-04-22 18:33:15.619 LabApp] Config changed: {'NotebookApp': {}, 'ServerApp': {'log_level': 'DEBUG', 'jpserver_extensions': }, 'ExtensionApp': {'log_level': 'DEBUG'}}
[I 2021-04-22 18:33:15.621 ServerApp] jupyterlab | extension was successfully linked.
[D 2021-04-22 18:33:16.516 NotebookApp] Config changed: {'NotebookApp': {}, 'ServerApp': {'log_level': 'DEBUG', 'jpserver_extensions': }, 'ExtensionApp': {'log_level': 'DEBUG'}}
[D 2021-04-22 18:33:16.651 ServerApp] Paths used for configuration of jupyter_notebook_config: 
    	/home/hmed/.jupyter/jupyter_notebook_config.json
[D 2021-04-22 18:33:16.651 ServerApp] Paths used for configuration of jupyter_notebook_config: 
    	/etc/jupyter/jupyter_notebook_config.json
[D 2021-04-22 18:33:16.651 ServerApp] Paths used for configuration of jupyter_notebook_config: 
    	/usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2021-04-22 18:33:16.652 ServerApp] Paths used for configuration of jupyter_notebook_config: 
    	/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/jupyter_notebook_config.d/jupyterlab.json
    	/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/jupyter_notebook_config.json
[D 2021-04-22 18:33:16.652 ServerApp] Paths used for configuration of jupyter_notebook_config: 
    	/home/hmed/.jupyter/jupyter_notebook_config.json
[I 2021-04-22 18:33:16.652 ServerApp] nbclassic | extension was successfully linked.
[D 2021-04-22 18:33:16.653 ServerApp] Config changed: {'ExtensionApp': {'log_level': 'DEBUG'}, 'NotebookApp': {}, 'ServerApp': {'log_level': 'DEBUG', 'jpserver_extensions': }}
[D 2021-04-22 18:33:16.653 ServerApp] Raising open file limit: soft 1024->4096; hard 1048576->1048576
[I 2021-04-22 18:33:16.668 LabApp] JupyterLab extension loaded from /home/hmed/miniconda3/envs/jupyterlab3.0.14/lib/python3.9/site-packages/jupyterlab
[I 2021-04-22 18:33:16.668 LabApp] JupyterLab application directory is /home/hmed/miniconda3/envs/jupyterlab3.0.14/share/jupyter/lab
[I 2021-04-22 18:33:16.670 ServerApp] jupyterlab | extension was successfully loaded.
[I 2021-04-22 18:33:16.673 ServerApp] nbclassic | extension was successfully loaded.
[I 2021-04-22 18:33:16.675 ServerApp] Serving notebooks from local directory: /mnt/remote-home/tmp
[I 2021-04-22 18:33:16.675 ServerApp] Jupyter Server 1.6.4 is running at:
[I 2021-04-22 18:33:16.675 ServerApp] http://localhost:8888/lab?token=c3d722e6194b419623766447e66c380133711461ef3d181a
[I 2021-04-22 18:33:16.675 ServerApp]     http://127.0.0.1:8888/lab?token=c3d722e6194b419623766447e66c380133711461ef3d181a
[I 2021-04-22 18:33:16.675 ServerApp] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[C 2021-04-22 18:33:16.708 ServerApp] 
To access the server, open this file in a browser:
    file:///home/hmed/.local/share/jupyter/runtime/jpserver-54812-open.html
Or copy and paste one of these URLs:
    http://localhost:8888/lab?token=c3d722e6194b419623766447e66c380133711461ef3d181a
    http://127.0.0.1:8888/lab?token=c3d722e6194b419623766447e66c380133711461ef3d181a

[D 2021-04-22 18:33:19.448 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:19.454 ServerApp] Paths used for configuration of page_config:
/etc/jupyter/labconfig/page_config.json
[D 2021-04-22 18:33:19.455 ServerApp] Paths used for configuration of page_config:
/usr/local/etc/jupyter/labconfig/page_config.json
[D 2021-04-22 18:33:19.456 ServerApp] Paths used for configuration of page_config:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/labconfig/page_config.json
[D 2021-04-22 18:33:19.457 ServerApp] Paths used for configuration of page_config:
/home/hmed/.jupyter/labconfig/page_config.json
[D 2021-04-22 18:33:19.459 LabApp] Using contents: services/contents
[D 2021-04-22 18:33:19.464 LabApp] 200 GET /lab?token=c3d722e6194b419623766447e66c380133711461ef3d181a (127.0.0.1) 18.61ms
[D 2021-04-22 18:33:19.533 ServerApp] Path main.52329a42239bdb62d87e.js served from /home/hmed/miniconda3/envs/jupyterlab3.0.14/share/jupyter/lab/static/main.52329a42239bdb62d87e.js
[D 2021-04-22 18:33:19.534 ServerApp] 200 GET /static/lab/main.52329a42239bdb62d87e.js?v=52329a42239bdb62d87e (127.0.0.1) 1.65ms
[D 2021-04-22 18:33:19.560 ServerApp] Path 8173.b3cdc88dcb401955d50e.js served from /home/hmed/miniconda3/envs/jupyterlab3.0.14/share/jupyter/lab/static/8173.b3cdc88dcb401955d50e.js
[D 2021-04-22 18:33:19.561 ServerApp] 200 GET /static/lab/8173.b3cdc88dcb401955d50e.js?v=b3cdc88dcb401955d50e (127.0.0.1) 1.52ms
[D 2021-04-22 18:33:19.939 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:19.940 ServerApp] Found kernel python3 in /home/hmed/miniconda3/envs/jupyterlab3.0.14/share/jupyter/kernels
[D 2021-04-22 18:33:19.942 ServerApp] 200 GET /api/kernelspecs?1619112799938 (127.0.0.1) 3.29ms
[D 2021-04-22 18:33:19.946 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:19.947 ServerApp] Paths used for configuration of default_setting_overrides:
/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:33:19.947 ServerApp] Paths used for configuration of default_setting_overrides:
/usr/local/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:33:19.948 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:33:19.948 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/.jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:33:19.975 LabApp] 200 GET /lab/api/settings?1619112799945 (127.0.0.1) 29.39ms
[D 2021-04-22 18:33:19.976 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:19.977 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:19.977 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:19.978 ServerApp] 200 GET /api/kernels?1619112799951 (127.0.0.1) 2.08ms
[D 2021-04-22 18:33:19.979 ServerApp] 200 GET /api/sessions?1619112799952 (127.0.0.1) 2.83ms
[D 2021-04-22 18:33:19.980 ServerApp] 200 GET /api/terminals?1619112799954 (127.0.0.1) 2.92ms
[D 2021-04-22 18:33:19.987 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:19.988 ServerApp] Found kernel python3 in /home/hmed/miniconda3/envs/jupyterlab3.0.14/share/jupyter/kernels
[D 2021-04-22 18:33:19.989 ServerApp] 200 GET /api/kernelspecs?1619112799972 (127.0.0.1) 2.00ms
[D 2021-04-22 18:33:21.060 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:21.321 ServerApp] 200 GET /lab/api/translations/en?1619112801051 (127.0.0.1) 262.70ms
[D 2021-04-22 18:33:21.339 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:21.346 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:21.348 ServerApp] Paths used for configuration of default_setting_overrides:
/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:33:21.350 ServerApp] Paths used for configuration of default_setting_overrides:
/usr/local/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:33:21.351 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:33:21.351 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/.jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:33:21.475 LabApp] Node v15.14.0

[D 2021-04-22 18:33:21.528 ServerApp] 200 GET /lab/api/translations/?1619112801343 (127.0.0.1) 183.11ms
[D 2021-04-22 18:33:21.530 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:21.530 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:21.531 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:33:21.533 ServerApp] 200 GET /lab/api/listings/@jupyterlab/extensionmanager-extension/listings.json?1619112801366 (127.0.0.1) 4.21ms
[D 2021-04-22 18:33:21.812 LabApp] Yarn configuration loaded.
[D 2021-04-22 18:34:05.058 ServerApp] 200 GET /api/nbconvert?1619112801396 (127.0.0.1) 43527.82ms
[D 2021-04-22 18:34:54.626 ServerApp] 200 GET /api/nbconvert?1619112801434 (127.0.0.1) 93095.37ms
[D 2021-04-22 18:34:54.630 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:54.637 ServerApp] Paths used for configuration of default_setting_overrides:
/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:54.639 ServerApp] Paths used for configuration of default_setting_overrides:
/usr/local/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:54.643 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:54.645 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/.jupyter/labconfig/default_setting_overrides.json
[I 2021-04-22 18:34:54.646 LabApp] Build is up to date
[D 2021-04-22 18:34:54.652 LabApp] 200 GET /lab/api/settings/@jupyterlab/shortcuts-extension:shortcuts?1619112801593 (127.0.0.1) 23.01ms
[D 2021-04-22 18:34:54.653 LabApp] 200 GET /lab/api/build?1619112801336 (127.0.0.1) 93315.18ms
[D 2021-04-22 18:34:54.654 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:54.656 ServerApp] Paths used for configuration of default_setting_overrides:
/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:54.657 ServerApp] Paths used for configuration of default_setting_overrides:
/usr/local/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:54.658 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:54.659 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/.jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:54.662 LabApp] 200 GET /lab/api/settings/@jupyterlab/docmanager-extension:plugin?1619112801594 (127.0.0.1) 7.84ms
[D 2021-04-22 18:34:54.663 ServerApp] Path @jupyterlab/theme-light-extension/index.css served from /home/hmed/miniconda3/envs/jupyterlab3.0.14/share/jupyter/lab/themes/@jupyterlab/theme-light-extension/index.css
[D 2021-04-22 18:34:54.663 ServerApp] 304 GET /lab/api/themes/@jupyterlab/theme-light-extension/index.css (127.0.0.1) 3.70ms
[D 2021-04-22 18:34:54.664 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:54.665 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:54.991 LabApp] Yarn configuration loaded.
[D 2021-04-22 18:34:54.993 ServerApp] Paths used for configuration of page_config:
/etc/jupyter/labconfig/page_config.json
[D 2021-04-22 18:34:54.993 ServerApp] Paths used for configuration of page_config:
/usr/local/etc/jupyter/labconfig/page_config.json
[D 2021-04-22 18:34:54.993 ServerApp] Paths used for configuration of page_config:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/labconfig/page_config.json
[D 2021-04-22 18:34:54.993 ServerApp] Paths used for configuration of page_config:
/home/hmed/.jupyter/labconfig/page_config.json
[D 2021-04-22 18:34:54.995 LabApp] 200 GET /lab/api/extensions?1619112801631 (127.0.0.1) 331.08ms
[D 2021-04-22 18:34:54.996 ServerApp] 200 GET /api/sessions?1619112810110 (127.0.0.1) 330.69ms
[D 2021-04-22 18:34:54.997 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:54.998 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:54.999 ServerApp] Found kernel python3 in /home/hmed/miniconda3/envs/jupyterlab3.0.14/share/jupyter/kernels
[D 2021-04-22 18:34:55.000 ServerApp] 200 GET /api/kernelspecs?1619112861108 (127.0.0.1) 3.05ms
[D 2021-04-22 18:34:55.001 LabApp] 200 GET /lab/api/workspaces/default?1619112894756 (127.0.0.1) 2.97ms
[D 2021-04-22 18:34:55.001 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:55.002 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:55.003 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:55.005 ServerApp] Paths used for configuration of default_setting_overrides:
/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:55.005 ServerApp] Paths used for configuration of default_setting_overrides:
/usr/local/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:55.006 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:55.006 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/.jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:55.007 ServerApp] 200 GET /api/terminals?1619112810115 (127.0.0.1) 6.06ms
[D 2021-04-22 18:34:55.008 ServerApp] 200 GET /api/kernels?1619112810105 (127.0.0.1) 5.95ms
[D 2021-04-22 18:34:55.010 LabApp] 200 GET /lab/api/settings/@jupyterlab/shortcuts-extension:shortcuts?1619112894851 (127.0.0.1) 7.17ms
[D 2021-04-22 18:34:55.308 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:55.309 ServerApp] Paths used for configuration of default_setting_overrides:
/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:55.309 ServerApp] Paths used for configuration of default_setting_overrides:
/usr/local/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:55.310 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/miniconda3/envs/jupyterlab3.0.14/etc/jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:55.310 ServerApp] Paths used for configuration of default_setting_overrides:
/home/hmed/.jupyter/labconfig/default_setting_overrides.json
[D 2021-04-22 18:34:55.337 LabApp] 200 GET /lab/api/settings?1619112895270 (127.0.0.1) 29.24ms
[D 2021-04-22 18:34:56.081 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:56.082 LabApp] 204 PUT /lab/api/workspaces/default?1619112895784 (127.0.0.1) 1.27ms
[D 2021-04-22 18:34:56.099 ServerApp] Serving kernel resource from: /home/hmed/miniconda3/envs/jupyterlab3.0.14/share/jupyter/kernels/python3
[D 2021-04-22 18:34:56.099 ServerApp] 200 GET /kernelspecs/python3/logo-64x64.png (127.0.0.1) 1.82ms
[D 2021-04-22 18:34:56.127 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:56.568 ServerApp] 200 GET /api/contents?content=1&1619112896125 (127.0.0.1) 441.41ms
[D 2021-04-22 18:34:56.645 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:34:56.646 LabApp] 204 PUT /lab/api/workspaces/default?1619112896643 (127.0.0.1) 1.09ms
[D 2021-04-22 18:35:05.023 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:35:05.025 ServerApp] 200 GET /api/sessions?1619112905013 (127.0.0.1) 2.91ms
[D 2021-04-22 18:35:05.369 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:35:05.372 ServerApp] 200 GET /api/terminals?1619112905360 (127.0.0.1) 3.19ms
[D 2021-04-22 18:35:05.393 ServerApp] Accepting token-authenticated connection from 127.0.0.1
[D 2021-04-22 18:35:05.395 ServerApp] 200 GET /api/kernels?1619112905364 (127.0.0.1) 3.43ms

Browser Output

@hMED22 hMED22 added the bug label Apr 22, 2021
@welcome
Copy link

welcome bot commented Apr 22, 2021

Thank you for opening your first issue in this project! Engagement like this is essential for open source projects! 🤗

If you haven't done so already, check out Jupyter's Code of Conduct. Also, please try to follow the issue template as it helps other other community members to contribute more effectively.
welcome
You can meet the other Jovyans by joining our Discourse forum. There is also an intro thread there where you can stop by and say Hi! 👋

Welcome to the Jupyter community! 🎉

@hMED22
Copy link
Author

hMED22 commented Apr 22, 2021

The responsible handler is jupyter_server.services.nbconvert.handlers.NbconvertRootHandler I was able to make a quick fix for this by using anyio like you have already done with AsyncFileContentsManager.

With this JupyterLab loads in seconds.

exporters = await anyio.run_sync_in_worker_thread(base.get_export_names)
...
exporter_class = await anyio.run_sync_in_worker_thread(base.get_exporter, exporter_name)

image

@kevin-bates
Copy link
Member

Hi @hMED22 - thank you for opening this issue. Your analysis looks sound.

Regarding the use of anyio.run_sync_in_worker_thread, we're finding that anyio version 3 is encountering issues with that method (see #487) which forced us to cap anyio. Were you running with v3 in your test above? If so, that would be an interesting data point for #487.

Also, I'd recommend we switch the calls to anyio.to_thread.run_sync() sincerun_sync_in_worker_thread() produces a deprecation warning in v3 - suggesting run_sync() instead. Unfortunately, that switch doesn't appear to resolve the v3 issue, but, should we take this approach, we'd want to avoid the warning.

@hMED22
Copy link
Author

hMED22 commented Apr 25, 2021

Thanks for the heads up.

I'm running on anyio==2.2.0 and anyio.to_thread.run_sync() doesn't exist before v3, but I see the v3 bug is fixed and upgrade is coming in #492.

Furthermore I found out that file operations are made by exporters based on TemplateExporter while instantiating by base.get_exporter() which is called in 2 loops one in the base.get_export_names and the other by the handler itself here I could optimize that by suggesting get_exporters() in nbconvert so we don't have to loop a second time but still I think making the handler async is the best approach.

So would it be ok to use anyio.to_thread.run_sync() here and not just in AsyncFileContentsManager?

@kevin-bates
Copy link
Member

Good point about run_sync() only existing in anyio >= 3. Are you okay submitting a PR for this that uses run_sync() and waiting until the anyio release is out? If not, we could go ahead with using run_sync_in_worker_thread() and make a note to backtrack to replace at that time (as we'll get the deprecation warnings otherwise)?

@hMED22
Copy link
Author

hMED22 commented Apr 27, 2021

I'll open a PR using run_sync() after #492 is merged.
Thank you.

@kevin-bates kevin-bates mentioned this issue May 1, 2021
1 task
@blink1073
Copy link
Contributor

Hi @hMED22, do you want me to assign this issue to you now that #492 is merged?

@blink1073 blink1073 added this to the 1.7 milestone May 6, 2021
@hMED22
Copy link
Author

hMED22 commented May 6, 2021

Yes I'll handle this, I didn't notice 492 was merged before.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants