Dockerspawner fails. How do I get logs?

JupyterHub
1

The dockerspawner is failing, I think. On the front end, it shows the error:

Spawn failed: Server at http://x.x.x.x:8888/user/xxx/ didn't respond in 30 seconds

That’s cool. It’s not helpful, though. The jupyterhub DEBUG logs show absolutely nothing about what the dockerspawner is doing:

May 14 07:27:01 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [I 2020-05-14 07:27:01.739 JupyterHub app:2631] JupyterHub is now running at http://:8000
May 14 07:27:01 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [D 2020-05-14 07:27:01.739 JupyterHub app:2233] It took 0.285 seconds for the Hub to start
May 14 07:27:13 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [I 2020-05-14 07:27:13.282 JupyterHub log:174] 200 GET /hub/login (@::ffff:10.64.13.67) 24.11ms
May 14 07:27:23 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [I 2020-05-14 07:27:23.018 JupyterHub log:174] 200 GET /hub/login (@::ffff:10.64.14.219) 1.10ms
May 14 07:27:27 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [I 2020-05-14 07:27:27.149 JupyterHub log:174] 302 GET / -> /hub/ (@::ffff:10.64.13.67) 0.80ms
May 14 07:27:27 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [D 2020-05-14 07:27:27.400 JupyterHub base:330] Refreshing auth for xxx
May 14 07:27:27 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [D 2020-05-14 07:27:27.400 JupyterHub user:242] Creating <class 'dockerspawner.dockerspawner.DockerSpawner'> for xxx:
May 14 07:27:27 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [I 2020-05-14 07:27:27.403 JupyterHub log:174] 302 GET /hub/ -> /hub/spawn (xxx@::ffff:x.x.x.x) 11.07ms
May 14 07:27:27 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [D 2020-05-14 07:27:27.672 JupyterHub pages:195] Triggering spawn with default options for xxx
May 14 07:27:27 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [D 2020-05-14 07:27:27.673 JupyterHub base:825] Initiating spawn for xxx
May 14 07:27:27 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [D 2020-05-14 07:27:27.673 JupyterHub base:832] 0/100 concurrent spawns
May 14 07:27:27 ip-x-x-x-x.eu-west-1.compute.internal jupyterhub[20935]: [D 2020-05-14 07:27:27.673 JupyterHub base:837] 0 active servers
May 14 07:27:27 ip-x-x-x-x.eu-west-1.compute.internal python3[20935]: pam_loginuid(login:session): set_loginuid failed

My jupyterhub_config.py looks like this:

import os
c = get_config()
c.JupyterHub.log_level = 'DEBUG'
c.JupyterHub.spawner_class = 'dockerspawner.DockerSpawner'
c.DockerSpawner.image = 'jupyter/base-notebook'
spawn_cmd = "start-singleuser.sh --user={username} --notebook-dir=/home/{username}"
c.DockerSpawner.extra_create_kwargs.update({ 'command': spawn_cmd })
c.DockerSpawner.remove = True
network_name = 'jupyterhub-network'
c.DockerSpawner.use_internal_ip = True
c.DockerSpawner.network_name = network_name
c.DockerSpawner.extra_host_config = { 'network_mode': network_name }
notebook_dir = '/home/{username}'
c.DockerSpawner.notebook_dir = notebook_dir
c.DockerSpawner.volumes = { notebook_dir: notebook_dir }
c.DockerSpawner.remove_containers = True
c.JupyterHub.hub_ip = '0.0.0.0'
c.JupyterHub.hub_port = 8080

I’m guessing that the start-singleuser.sh script is failing to start, but I wouldn’t know why because I can’t see what’s going on. Maybe it doesn’t like the --user and --notebook-dir options? If I don’t specify anything here, the notebooks will be stored in /home/jovyan inside the container, which means that nothing is persisted to notebook_dir.

How can I get a clue what is going on here?

2

Have you tried to manually create a docker container from the image and manually start it using your spawn_cmd?

3

If I do something like this on the jupyterhub machine, it appears to start up just fine:

  sudo docker run \
    -e JUPYTERHUB_API_TOKEN=xxx \
    -e JPY_API_TOKEN=xxx \
    -e JUPYTERHUB_CLIENT_ID=jupyterhub-user-xxx \
    -e JUPYTERHUB_HOST= \
    -e JUPYTERHUB_OAUTH_CALLBACK_URL=/user/xxx/oauth_callback \
    -e JUPYTERHUB_USER=xxx \
    -e JUPYTERHUB_SERVER_NAME= \
    -e JUPYTERHUB_API_URL=http://ip-x-x-x-x.eu-west-1.compute.internal:8080/hub/api \
    -e JUPYTERHUB_ACTIVITY_URL=http://ip-x-x-x-x.eu-west-1.compute.internal:8080/hub/api/users/xxx/activity \
    -e JUPYTERHUB_BASE_URL=/ \
    -e JUPYTERHUB_SERVICE_PREFIX=/user/xxx/ \
    -e PATH=/opt/conda/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin \
    -e DEBIAN_FRONTEND=noninteractive \
    -e CONDA_DIR=/opt/conda \
    -e SHELL=/bin/bash \
    -e LC_ALL=en_US.UTF-8 \
    -e LANG=en_US.UTF-8 \
    -e LANGUAGE=en_US.UTF-8 \
    -e MINICONDA_VERSION=4.8.2 \
    -e MINICONDA_MD5=87e77f097f6ebb5127c77662dfc3165e \
    -e CONDA_VERSION=4.8. \
    -v /home/xxx:/home/xxx \
    -it jupyter/base-notebook \
    tini -g -- start-notebook.sh --user=xxx --notebook-dir=/home/xxx

It doesn’t do what I want it to though, and that is to use /home/xxx as the directory to store the notebooks. It still fails silently (?) when launched by the dockerspawner.

If I add these just for fun:

-e HOME=/home/xxx \
-e NB_USER=xxx \

I will get an error like this:

Traceback (most recent call last):
  File "/opt/conda/lib/python3.7/site-packages/traitlets/traitlets.py", line 528, in get
    value = obj._trait_values[self.name]
KeyError: 'runtime_dir'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/conda/bin/jupyterhub-singleuser", line 10, in <module>
    sys.exit(main())
  File "/opt/conda/lib/python3.7/site-packages/jupyterhub/singleuser.py", line 660, in main
    return SingleUserNotebookApp.launch_instance(argv)
  File "/opt/conda/lib/python3.7/site-packages/jupyter_core/application.py", line 270, in launch_instance
    return super(JupyterApp, cls).launch_instance(argv=argv, **kwargs)
  File "/opt/conda/lib/python3.7/site-packages/traitlets/config/application.py", line 663, in launch_instance
    app.initialize(argv)
  File "/opt/conda/lib/python3.7/site-packages/jupyterhub/singleuser.py", line 558, in initialize
    return super().initialize(argv)
  File "<decorator-gen-7>", line 2, in initialize
  File "/opt/conda/lib/python3.7/site-packages/traitlets/config/application.py", line 87, in catch_config_error
    return method(app, *args, **kwargs)
  File "/opt/conda/lib/python3.7/site-packages/notebook/notebookapp.py", line 1766, in initialize
    self.init_configurables()
  File "/opt/conda/lib/python3.7/site-packages/notebook/notebookapp.py", line 1380, in init_configurables
    connection_dir=self.runtime_dir,
  File "/opt/conda/lib/python3.7/site-packages/traitlets/traitlets.py", line 556, in __get__
    return self.get(obj, cls)
  File "/opt/conda/lib/python3.7/site-packages/traitlets/traitlets.py", line 535, in get
    value = self._validate(obj, dynamic_default())
  File "/opt/conda/lib/python3.7/site-packages/jupyter_core/application.py", line 100, in _runtime_dir_default
    ensure_dir_exists(rd, mode=0o700)
  File "/opt/conda/lib/python3.7/site-packages/jupyter_core/utils/__init__.py", line 13, in ensure_dir_exists
    os.makedirs(path, mode=mode)
  File "/opt/conda/lib/python3.7/os.py", line 211, in makedirs
    makedirs(head, exist_ok=exist_ok)
  File "/opt/conda/lib/python3.7/os.py", line 211, in makedirs
    makedirs(head, exist_ok=exist_ok)
  File "/opt/conda/lib/python3.7/os.py", line 211, in makedirs
    makedirs(head, exist_ok=exist_ok)
  File "/opt/conda/lib/python3.7/os.py", line 221, in makedirs
    mkdir(name, mode)
PermissionError: [Errno 13] Permission denied: '/home/xxx/.local'
1 Like
4

Wait, your previous spawn_cmd and the shell script you provided here differ, you did not start the very same thing. If you replace the command with bash, maybe you can temper around a bit more and also dive into the permission issues.

5

Sorry, I’ve been playing with start-singleuser.sh and start-notebook.sh interchangeably. They both throw the same error when these values and arguments are provided. I am wondering if the jovyan user and home directory are just baked into the dockerspawner and cannot be changed?

6

Well, the user jovyan is part of the docker image you are using. You could develop your own docker image according to your liking.

2 Likes
7

I know this is an old post, but this was the main thread that helped me debug my own DockerSpawner issues.

All the addresses matched, the notebook was reaching out to the hub and just simply not getting a response, producing logs similar to those above.

The problem seemed to be specific to one machine, since Docker notebooks were spawning fine on my Arch server, but seemed to be failing on my Ubuntu server. Docker versions matched, Python versions matched, I swapped my Caddy proxy with an Nginx one. Nothing, no response between Docker and Jupyterhub.

The solution? Check your ufw status. If your docker0 subnet is not listed in the “allow” list, then your firewall is blocking Jupyter from seeing Docker.

Simple, silly solution, that took hours to find. I’m just posting this here in case anyone else sees similar logs and doesn’t know how to proceed.