Bug description
After updating some libraries my TLJH server won’t spawn user instances anymore. Inside the browser I’m getting an error message.
(Note: the screenshot’s user ID is different from the one in the logs below. The logs were copied during an active session with another user and I got the screenshot idea later after the session from the logs was already terminated)
Expected behaviour
I thought that updating the libraries would go smoothly. A local update went without any trouble.
Actual behaviour
It didn’t go smoothly on the TLJH environment.
How to reproduce
There were so many steps during setup that I don’t know if it’s reproducable for everyone. However, I can reproduce it anytime with any user. I’m using TmpAuthenticator.
I updated like this:
source /opt/tljh/user/bin
sudo -H pip install --upgrade ipycanvas -t /opt/tljh/user/bin
sudo -H pip install --upgrade ipywidgets -t /opt/tljh/user/bin
sudo -H pip install --upgrade import_ipynb -t /opt/tljh/user/bin
Your personal set up
-
OS:
Ubuntu 20.04.1 LTS -
Version(s):
Jupyterhub 1.1.0
Python 3.8.10 -
Full environment
$ pip freeze
WARNING: The directory '/home/domme/.cache/pip' or its parent directory is not owned or is not writable by the current user. The cache has been disabled. Check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag.
alembic==1.4.3
argon2-cffi==20.1.0
async-generator==1.10
attrs==19.3.0
Automat==0.8.0
backcall==0.2.0
bleach==3.3.1
blinker==1.4
certifi==2019.11.28
certipy==0.1.3
cffi==1.14.6
chardet==3.0.4
Click==7.0
cloud-init==21.2
colorama==0.4.3
command-not-found==0.3
configobj==5.0.6
constantly==15.1.0
cryptography==2.8
dbus-python==1.2.16
debugpy==1.4.1
decorator==5.0.9
defusedxml==0.7.1
distro==1.4.0
distro-info===0.23ubuntu1
entrypoints==0.3
httplib2==0.14.0
hyperlink==19.0.0
idna==2.8
importlib-metadata==1.5.0
incremental==16.10.1
ipycanvas==0.9.0
ipykernel==6.0.3
ipython==7.25.0
ipython-genutils==0.2.0
ipywidgets==7.6.3
jedi==0.18.0
Jinja2==2.10.1
jsonpatch==1.22
jsonpointer==2.0
jsonschema==3.2.0
jupyter-client==6.1.12
jupyter-core==4.7.1
jupyter-telemetry==0.1.0
jupyterhub==1.1.0
jupyterhub-tmpauthenticator==0.6
jupyterlab-pygments==0.1.2
jupyterlab-widgets==1.0.0
keyring==18.0.1
language-selector==0.1
launchpadlib==1.10.13
lazr.restfulclient==0.14.2
lazr.uri==1.0.3
Mako==1.1.3
MarkupSafe==1.1.0
matplotlib-inline==0.1.2
mistune==0.8.4
more-itertools==4.2.0
nbclient==0.5.3
nbconvert==6.1.0
nbformat==5.1.3
nest-asyncio==1.5.1
netifaces==0.10.4
notebook==6.4.0
numpy==1.21.1
oauthlib==3.1.0
packaging==21.0
pamela==1.0.0
pandocfilters==1.4.3
parso==0.8.2
pexpect==4.8.0
pickleshare==0.7.5
Pillow==8.3.1
prometheus-client==0.8.0
prompt-toolkit==3.0.19
ptyprocess==0.7.0
pyasn1==0.4.2
pyasn1-modules==0.2.1
pycparser==2.20
Pygments==2.9.0
PyGObject==3.36.0
PyHamcrest==1.9.0
PyJWT==1.7.1
pymacaroons==0.13.0
PyNaCl==1.3.0
pyOpenSSL==19.0.0
pyparsing==2.4.7
pyrsistent==0.15.5
pyserial==3.4
python-apt==2.0.0+ubuntu0.20.4.5
python-dateutil==2.8.1
python-debian===0.1.36ubuntu1
python-editor==1.0.4
python-json-logger==2.0.1
PyYAML==5.3.1
pyzmq==22.1.0
requests==2.22.0
requests-unixsocket==0.2.0
ruamel.yaml==0.16.12
ruamel.yaml.clib==0.2.2
SecretStorage==2.3.1
Send2Trash==1.7.1
service-identity==18.1.0
simplejson==3.16.0
six==1.14.0
SQLAlchemy==1.3.20
ssh-import-id==5.10
systemd-python==234
terminado==0.10.1
testpath==0.5.0
tornado==6.0.4
traitlets==5.0.5
Twisted==18.9.0
ubuntu-advantage-tools==20.3
ufw==0.36
unattended-upgrades==0.1
urllib3==1.25.8
wadllib==1.3.3
wcwidth==0.2.5
webencodings==0.5.1
widgetsnbextension==3.5.1
zipp==1.0.0
zope.interface==4.7.1
$ jupyter-nbextension list
Known nbextensions:
config dir: /home/domme/.jupyter/nbconfig
notebook section
ipycanvas enabled
- Validating: problems found:
- require? X ipycanvas
config dir: /usr/local/etc/jupyter/nbconfig
notebook section
ipycanvas/extension enabled
- Validating: OK
jupyter-js-widgets/extension enabled
- Validating: OK
Initially I had trouble updating the libraries. So I updated into a wrong environment by mistake. This is probably where the Validating problems result from. Unfortunately I don’t know how to fix this and I don’t want to do any more harm to the server.
-
Configuration
# jupyterhub_config.py
"""
JupyterHub config for the littlest jupyterhub.
"""
from glob import glob
import os
from systemdspawner import SystemdSpawner
from tljh import configurer, user
from tljh.config import INSTALL_PREFIX, USER_ENV_PREFIX, CONFIG_DIR
from tljh.normalize import generate_system_username
from tljh.utils import get_plugin_manager
from jupyterhub_traefik_proxy import TraefikTomlProxy
from traitlets import Dict, Unicode, List
class UserCreatingSpawner(SystemdSpawner):
"""
SystemdSpawner with user creation on spawn.
FIXME: Remove this somehow?
"""
user_groups = Dict(key_trait=Unicode(), value_trait=List(Unicode()), config=True)
def start(self):
"""
Perform system user activities before starting server
"""
# FIXME: Move this elsewhere? Into the Authenticator?
system_username = generate_system_username('jupyter-' + self.user.name)
# FIXME: This is a hack. Allow setting username directly instead
self.username_template = system_username
user.ensure_user(system_username)
user.ensure_user_group(system_username, 'jupyterhub-users')
if self.user.admin:
user.ensure_user_group(system_username, 'jupyterhub-admins')
else:
user.remove_user_group(system_username, 'jupyterhub-admins')
if self.user_groups:
for group, users in self.user_groups.items():
if self.user.name in users:
user.ensure_user_group(system_username, group)
return super().start()
c.JupyterHub.spawner_class = UserCreatingSpawner
# leave users running when the Hub restarts
c.JupyterHub.cleanup_servers = False
# Use a high port so users can try this on machines with a JupyterHub already present
c.JupyterHub.hub_port = 15001
c.TraefikTomlProxy.should_start = False
dynamic_conf_file_path = os.path.join(INSTALL_PREFIX, 'state', 'rules', 'rules.toml')
c.TraefikTomlProxy.toml_dynamic_config_file = dynamic_conf_file_path
c.JupyterHub.proxy_class = TraefikTomlProxy
c.SystemdSpawner.extra_paths = [os.path.join(USER_ENV_PREFIX, 'bin')]
c.SystemdSpawner.default_shell = '/bin/bash'
# Drop the '-singleuser' suffix present in the default template
c.SystemdSpawner.unit_name_template = 'jupyter-{USERNAME}'
tljh_config = configurer.load_config()
configurer.apply_config(tljh_config, c)
# Let TLJH hooks modify `c` if they want
# Call our custom configuration plugin
pm = get_plugin_manager()
pm.hook.tljh_custom_jupyterhub_config(c=c)
# Load arbitrary .py config files if they exist.
# This is our escape hatch
extra_configs = sorted(glob(os.path.join(CONFIG_DIR, 'jupyterhub_config.d', '*.py')))
for ec in extra_configs:
load_subconfig(ec)
# Setup temporary user (no auth)
import tmpauthenticator
c.JupyterHub.authenticator_class = tmpauthenticator.TmpAuthenticator
# Port settings
c.JupyterHub.ip = 'X.X.X.X'
c.JupyterHub.port = 8420
c.JupyterHub.bind_url = 'http://X.X.X.X:8420'
c.Spawner.default_url = '/lab/tree/Startseite.ipynb'
c.JupyterHub.shutdown_on_logout = True
#c.JupyterHub.default_url = '/notebooks/Startseite.ipynb'
#c.Spawner.default_url = '/lab/notebooks/Startseite.ipynb'
-
Logs
sudo journalctl -u jupyterhub
Jul 30 10:22:20 tdjupyterhub python3[879]: [I 2021-07-30 10:22:20.746 JupyterHub log:174] 302 GET / -> /hub/ (@X.X.X.X) 2.19ms
Jul 30 10:22:20 tdjupyterhub python3[879]: [I 2021-07-30 10:22:20.801 JupyterHub log:174] 302 GET /hub/ -> /hub/login (@X.X.X.X) 1.30ms
Jul 30 10:22:20 tdjupyterhub python3[879]: [I 2021-07-30 10:22:20.841 JupyterHub log:174] 302 GET /hub/login -> /hub/tmplogin (@X.X.X.X) 1.45ms
Jul 30 10:22:21 tdjupyterhub python3[879]: [I 2021-07-30 10:22:21.010 JupyterHub log:174] 302 GET /hub/tmplogin -> /hub/spawn (@X.X.X.X) 134.70ms
Jul 30 10:22:21 tdjupyterhub useradd[2616]: new group: name=jupyter-42e3bc3a-3551-4a83-823bc, GID=1905
Jul 30 10:22:21 tdjupyterhub useradd[2616]: new user: name=jupyter-42e3bc3a-3551-4a83-823bc, UID=1903, GID=1905, home=/home/jupyter-42e3bc3a-3551-4a83-823bc, shell=/bin/sh, from=none
Jul 30 10:22:21 tdjupyterhub python3[2626]: Adding user jupyter-42e3bc3a-3551-4a83-823bc to group jupyterhub-users
Jul 30 10:22:21 tdjupyterhub gpasswd[2626]: user jupyter-42e3bc3a-3551-4a83-823bc added by root to group jupyterhub-users
Jul 30 10:22:21 tdjupyterhub python3[2636]: Running as unit: jupyter-42e3bc3a-3551-4a83-8034-6e073e1ea3fe.service
Jul 30 10:22:22 tdjupyterhub python3[879]: [I 2021-07-30 10:22:22.094 JupyterHub log:174] 302 GET /hub/spawn -> /hub/spawn-pending/42e3bc3a-3551-4a83-8034-6e073e1ea3fe (42e3bc3a-3551-4a83-8034-6e073e1ea3fe@X.X.X.X) 1046.23ms
Jul 30 10:22:22 tdjupyterhub python3[879]: [I 2021-07-30 10:22:22.130 JupyterHub pages:347] 42e3bc3a-3551-4a83-8034-6e073e1ea3fe is pending spawn
Jul 30 10:22:22 tdjupyterhub python3[879]: [I 2021-07-30 10:22:22.131 JupyterHub log:174] 200 GET /hub/spawn-pending/42e3bc3a-3551-4a83-8034-6e073e1ea3fe (42e3bc3a-3551-4a83-8034-6e073e1ea3fe@X.X.X.X) 6.05ms
Jul 30 10:22:31 tdjupyterhub python3[879]: ERROR:asyncio:Task exception was never retrieved
Jul 30 10:22:31 tdjupyterhub python3[879]: future: <Task finished name='Task-1359' coro=<BaseHandler.spawn_single_user() done, defined at /opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/handlers/base.py:741> exception=HTTPError()>
Jul 30 10:22:31 tdjupyterhub python3[879]: Traceback (most recent call last):
Jul 30 10:22:31 tdjupyterhub python3[879]: File "/opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/handlers/base.py", line 938, in spawn_single_user
Jul 30 10:22:31 tdjupyterhub python3[879]: await gen.with_timeout(
Jul 30 10:22:31 tdjupyterhub python3[879]: tornado.util.TimeoutError: Timeout
Jul 30 10:22:31 tdjupyterhub python3[879]: During handling of the above exception, another exception occurred:
Jul 30 10:22:31 tdjupyterhub python3[879]: Traceback (most recent call last):
Jul 30 10:22:31 tdjupyterhub python3[879]: File "/opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/handlers/base.py", line 969, in spawn_single_user
Jul 30 10:22:31 tdjupyterhub python3[879]: raise web.HTTPError(
Jul 30 10:22:31 tdjupyterhub python3[879]: tornado.web.HTTPError: HTTP 500: Internal Server Error (Spawner failed to start [status=1]. The logs for 42e3bc3a-3551-4a83-8034-6e073e1ea3fe may contain details.)
Jul 30 10:22:50 tdjupyterhub python3[879]: [W 2021-07-30 10:22:50.650 JupyterHub user:687] 42e3bc3a-3551-4a83-8034-6e073e1ea3fe's server never showed up at http://127.0.0.1:39475/user/42e3bc3a-3551-4a83-8034-6e073e1ea3fe/ after 30 seconds. Giving up
Jul 30 10:22:50 tdjupyterhub python3[879]: [E 2021-07-30 10:22:50.792 JupyterHub gen:598] Exception in Future <Task finished name='Task-1360' coro=<BaseHandler.spawn_single_user.<locals>.finish_user_spawn() done, defined at /opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/handlers/base.py:845> exception=TimeoutError("Server at http://127.0.0.1:39475/user/42e3bc3a-3551-4a83-8034-6e073e1ea3fe/ didn't respond in 30 seconds")> after timeout
Jul 30 10:22:50 tdjupyterhub python3[879]: Traceback (most recent call last):
Jul 30 10:22:50 tdjupyterhub python3[879]: File "/opt/tljh/hub/lib/python3.8/site-packages/tornado/gen.py", line 593, in error_callback
Jul 30 10:22:50 tdjupyterhub python3[879]: future.result()
Jul 30 10:22:50 tdjupyterhub python3[879]: File "/opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/handlers/base.py", line 852, in finish_user_spawn
Jul 30 10:22:50 tdjupyterhub python3[879]: await spawn_future
Jul 30 10:22:50 tdjupyterhub python3[879]: File "/opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/user.py", line 668, in spawn
Jul 30 10:22:50 tdjupyterhub python3[879]: await self._wait_up(spawner)
Jul 30 10:22:50 tdjupyterhub python3[879]: File "/opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/user.py", line 715, in _wait_up
Jul 30 10:22:50 tdjupyterhub python3[879]: raise e
Jul 30 10:22:50 tdjupyterhub python3[879]: File "/opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/user.py", line 682, in _wait_up
Jul 30 10:22:50 tdjupyterhub python3[879]: resp = await server.wait_up(
Jul 30 10:22:50 tdjupyterhub python3[879]: File "/opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/utils.py", line 229, in wait_for_http_server
Jul 30 10:22:50 tdjupyterhub python3[879]: re = await exponential_backoff(
Jul 30 10:22:50 tdjupyterhub python3[879]: File "/opt/tljh/hub/lib/python3.8/site-packages/jupyterhub/utils.py", line 177, in exponential_backoff
Jul 30 10:22:50 tdjupyterhub python3[879]: raise TimeoutError(fail_message)
Jul 30 10:22:50 tdjupyterhub python3[879]: TimeoutError: Server at http://127.0.0.1:39475/user/42e3bc3a-3551-4a83-8034-6e073e1ea3fe/ didn't respond in 30 seconds
Jul 30 10:22:50 tdjupyterhub python3[879]:
Jul 30 10:22:50 tdjupyterhub python3[879]: [I 2021-07-30 10:22:50.795 JupyterHub log:174] 200 GET /hub/api/users/42e3bc3a-3551-4a83-8034-6e073e1ea3fe/server/progress (42e3bc3a-3551-4a83-8034-6e073e1ea3fe@X.X.X.X) 28433.62ms
Jul 30 10:23:08 tdjupyterhub python3[879]: [I 2021-07-30 10:23:08.558 JupyterHub log:174] 200 GET /hub/api/users (cull-idle@127.0.0.1) 75.79ms
$ sudo journalctl -u 42e3bc3a-3551-4a83-8034-6e073e1ea3feto (as suggested by one of the error messages)
-- Logs begin at Thu 2021-03-18 16:33:52 UTC, end at Fri 2021-07-30 10:31:22 UTC. --
-- No entries --
Any help would be appreciated. If you need additional details, just ask =)
Kind regards,
Domme