Internal Server Error HTTP 500

I’m trying to launch a Jupyter notebook on a remote host using the sshspawner. I’m running both JupyterHub and nginx as systemd services. After authenticating to JupyterHub and entering a hostname for the notebook launch, an HTTP 500 error occurs. I’ve looked looked through JupyterHub’s and nginx’s logs and I don’t see anything particularly helpful, although I suspect that I’m missing something simple/obvious. What’s the reason for this error?

Here’s the nginx config file:

#   * Official English Documentation: http://nginx.org/en/docs/
#   * Official Russian Documentation: http://nginx.org/ru/docs/

user nginx;
worker_processes auto;
error_log /var/log/nginx/error.log;
pid /run/nginx.pid;

# Load dynamic modules. See /usr/share/doc/nginx/README.dynamic.
include /usr/share/nginx/modules/*.conf;

events {
    worker_connections 1024;
}

http {
    log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                      '$status $body_bytes_sent "$http_referer" '
                      '"$http_user_agent" "$http_x_forwarded_for"';

    access_log  /var/log/nginx/access.log  main;

    sendfile            on;
    tcp_nopush          on;
    tcp_nodelay         on;
    keepalive_timeout   65;
    types_hash_max_size 2048;

    include             /etc/nginx/mime.types;
    default_type        application/octet-stream;

    # Load modular configuration files from the /etc/nginx/conf.d directory.
    # See http://nginx.org/en/docs/ngx_core_module.html#include
    # for more information.
    include /etc/nginx/conf.d/*.conf;

# I think this "map" is needed for proper proxying:
  map $http_upgrade $connection_upgrade {
	default upgrade;
	''   close;
  }

# HTTP server to redirect all 80 traffic to TLS/HTTPS
    server {
	listen 80;
	server_name protojupy.lanl.gov;
#	server_name jhub.protojupy.lanl.gov;

	return 301 https://$host$request_uri;
    } 

# Settings for a TLS enabled server.
    server {
        listen       443 ssl;
#        listen       443 ssl http2 default_server;
#        listen       [::]:443 ssl http2 default_server;
#        server_name  _;
        server_name  protojupy.lanl.gov;
#        server_name  jhub.protojupy.lanl.gov;
#        root         /usr/share/nginx/html;

#        ssl_certificate     "/etc/pki/tls/certs/protojupy.crt";
#        ssl_certificate_key "/etc/pki/tls/private/protojupy.key";
#        ssl_certificate     "/etc/pki/tls/certs/bleh-crt.pem";
#        ssl_certificate_key "/etc/pki/tls/private/bleh-key.pem";
        ssl_certificate     "/etc/pki/tls/certs/selfsign.cert";
        ssl_certificate_key "/etc/pki/tls/private/selfsign.key";
        ssl_protocols TLSv1.2;
        ssl_session_cache shared:SSL:59m;
        ssl_session_timeout  1d;
#        ssl_ciphers 'AES-256-CBC-HMAC-SHA256'
        ssl_ciphers HIGH:!aNULL:!MD5;
        ssl_prefer_server_ciphers on;
#        ssl_stapling on;
#        ssl_stapling_verify on;
        add_header Strict-Transport-Security max-age=160000;

        # Load configuration files for the default server block.
        include /etc/nginx/default.d/*.conf;

        location / {
           proxy_pass http://localhost:8080/;
	   proxy_set_header X-Real-IP $remote_addr;
           proxy_set_header Host $host;
           proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;

           # websocket headers
           proxy_set_header Upgrade $http_upgrade;
           proxy_set_header Connection $connection_upgrade;
        }

	location ~ /.well-known {
		allow all;
	}


        error_page 404 /404.html;
            location = /40x.html {
        }

        error_page 500 502 503 504 /50x.html;
            location = /50x.html {
        }
    }

}

Here are some of the values set in my Hub config file:


c.PAMAuthenticator.pam_normalize_username=True

#  If set to 0, no limit is enforced.
c.JupyterHub.concurrent_spawn_limit = 4

## The location of jupyterhub data files (e.g. /usr/local/share/jupyterhub)
c.JupyterHub.data_files_path = '/usr/local/share/jupyterhub'

# This is for the SSH spawner
#python
from sshspawner import SSHSpawner
c.JupyterHub.spawner_class = SSHSpawner
c.JupyterHub.bind_url= 'http://localhost:8080' # current way of stating the URL for the JupyterHub service 

snippet of JupyterHub’s log file:

Apr 14 15:06:19 protojupy jupyterhub: [D 2020-04-14 15:06:19.921 JupyterHub log:174] 304 GET /hub/login (@130.55.178.36) 2.20ms
Apr 14 15:06:44 protojupy jupyterhub: [D 2020-04-14 15:06:44.163 JupyterHub base:522] Setting cookie jupyterhub-session-id: {'httponly': True}
Apr 14 15:06:44 protojupy jupyterhub: [D 2020-04-14 15:06:44.163 JupyterHub base:526] Setting cookie for dewallace: jupyterhub-hub-login
Apr 14 15:06:44 protojupy jupyterhub: [D 2020-04-14 15:06:44.163 JupyterHub base:522] Setting cookie jupyterhub-hub-login: {'httponly': True, 'path': '/hub/'}
Apr 14 15:06:44 protojupy jupyterhub: [I 2020-04-14 15:06:44.163 JupyterHub base:707] User logged in: dewallace
Apr 14 15:06:44 protojupy jupyterhub: [I 2020-04-14 15:06:44.164 JupyterHub log:174] 302 POST /hub/login?next= -> /hub/spawn (dewallace@130.55.178.36) 4331.96ms
Apr 14 15:06:44 protojupy jupyterhub: [D 2020-04-14 15:06:44.261 JupyterHub pages:188] Serving options form for dewallace
Apr 14 15:06:44 protojupy jupyterhub: [I 2020-04-14 15:06:44.262 JupyterHub log:174] 200 GET /hub/spawn (dewallace@130.55.178.36) 3.02ms
Apr 14 15:06:47 protojupy jupyterhub: [D 2020-04-14 15:06:47.917 JupyterHub base:825] Initiating spawn for dewallace
Apr 14 15:06:47 protojupy jupyterhub: [D 2020-04-14 15:06:47.917 JupyterHub base:832] 0/4 concurrent spawns
Apr 14 15:06:47 protojupy jupyterhub: [D 2020-04-14 15:06:47.917 JupyterHub base:837] 0 active servers
Apr 14 15:06:47 protojupy jupyterhub: [D 2020-04-14 15:06:47.941 JupyterHub user:556] Calling Spawner.start for dewallace
Apr 14 15:06:48 protojupy jupyterhub: [I 2020-04-14 15:06:48.061 JupyterHub sshspawner:273] Collecting remote environment from 128.165.153.74
Apr 14 15:06:48 protojupy jupyterhub: [D 2020-04-14 15:06:48.063 JupyterHub sshspawner:244] Running: ssh -o ControlMaster=auto -o ControlPath=/tmp/%r@%h -o ControlPersist=180 -o BatchMode=True -o UserKnownHostsFile=/usr/local/etc/jupyterhub/known_hosts 128.165.153.74 env as dewallace
Apr 14 15:06:50 protojupy jupyterhub: [D 2020-04-14 15:06:50.353 JupyterHub sshspawner:244] Running: ssh -o ControlMaster=auto -o ControlPath=/tmp/%r@%h -o ControlPersist=1 -o BatchMode=True -o UserKnownHostsFile=/usr/local/etc/jupyterhub/known_hosts 128.165.153.74 mkdir -p .jupyter/jupyterhub/resources as dewallace
Apr 14 15:06:50 protojupy jupyterhub: [D 2020-04-14 15:06:50.370 JupyterHub sshspawner:244] Running: scp -o ControlMaster=auto -o ControlPath=/tmp/%r@%h -o ControlPersist=1 -o BatchMode=True -o UserKnownHostsFile=/usr/local/etc/jupyterhub/known_hosts /tmp/tmp4hrx5ixm/selfsign.key /tmp/tmp4hrx5ixm/selfsign.cert /tmp/tmp4hrx5ixm/ca-bundle.crt /tmp/tmp4hrx5ixm/start-notebook 128.165.153.74:.jupyter/jupyterhub/resources/ as dewallace
Apr 14 15:06:50 protojupy jupyterhub: [I 2020-04-14 15:06:50.393 JupyterHub sshspawner:480] Copied resources for dewallace to 128.165.153.74
Apr 14 15:06:50 protojupy jupyterhub: [D 2020-04-14 15:06:50.394 JupyterHub sshspawner:244] Running: ssh -o ControlMaster=auto -o ControlPath=/tmp/%r@%h -o ControlPersist=1 -o BatchMode=True -o UserKnownHostsFile=/usr/local/etc/jupyterhub/known_hosts -L 33603:127.0.0.1:33603 128.165.153.74 .jupyter/jupyterhub/resources/start-notebook as dewallace
Apr 14 15:06:50 protojupy jupyterhub: [D 2020-04-14 15:06:50.411 JupyterHub spawner:1113] Polling subprocess every 30s
Apr 14 15:06:57 protojupy jupyterhub: [E 2020-04-14 15:06:57.922 JupyterHub pages:248] Failed to spawn single-user server with form
Apr 14 15:06:57 protojupy jupyterhub: Traceback (most recent call last):
Apr 14 15:06:57 protojupy jupyterhub: File "/usr/local/lib/python3.6/site-packages/jupyterhub/handlers/pages.py", line 245, in post
Apr 14 15:06:57 protojupy jupyterhub: await self.spawn_single_user(user, server_name=server_name, options=options)
Apr 14 15:06:57 protojupy jupyterhub: File "/usr/local/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 972, in spawn_single_user
Apr 14 15:06:57 protojupy jupyterhub: % (status, spawner._log_name),
Apr 14 15:06:57 protojupy jupyterhub: tornado.web.HTTPError: HTTP 500: Internal Server Error (Spawner failed to start [status=127]. The logs for dewallace may contain details.)
Apr 14 15:06:57 protojupy jupyterhub: [I 2020-04-14 15:06:57.924 JupyterHub log:174] 200 POST /hub/spawn (dewallace@130.55.178.36) 10009.30ms
Apr 14 15:07:19 protojupy jupyterhub: [W 2020-04-14 15:07:19.576 JupyterHub user:692] dewallace's server never showed up at http://127.0.0.1:33603/user/dewallace/ after 30 seconds. Giving up
Apr 14 15:07:19 protojupy jupyterhub: [D 2020-04-14 15:07:19.577 JupyterHub user:739] Stopping dewallace
Apr 14 15:07:19 protojupy jupyterhub: [D 2020-04-14 15:07:19.582 JupyterHub user:767] Deleting oauth client jupyterhub-user-dewallace
Apr 14 15:07:19 protojupy jupyterhub: [D 2020-04-14 15:07:19.587 JupyterHub user:770] Finished stopping dewallace
Apr 14 15:07:19 protojupy jupyterhub: [E 2020-04-14 15:07:19.592 JupyterHub gen:599] Exception in Future <Task finished coro=<BaseHandler.spawn_single_user.<locals>.finish_user_spawn() done, defined at /usr/local/lib/python3.6/site-packages/jupyterhub/handlers/base.py:845> exception=TimeoutError("Server at http://127.0.0.1:33603/user/dewallace/ didn't respond in 30 seconds",)> after timeout
Apr 14 15:07:19 protojupy jupyterhub: Traceback (most recent call last):
Apr 14 15:07:19 protojupy jupyterhub: File "/usr/local/lib64/python3.6/site-packages/tornado/gen.py", line 593, in error_callback
Apr 14 15:07:19 protojupy jupyterhub: future.result()
Apr 14 15:07:19 protojupy jupyterhub: File "/usr/local/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 852, in finish_user_spawn
Apr 14 15:07:19 protojupy jupyterhub: await spawn_future
Apr 14 15:07:19 protojupy jupyterhub: File "/usr/local/lib/python3.6/site-packages/jupyterhub/user.py", line 668, in spawn
Apr 14 15:07:19 protojupy jupyterhub: await self._wait_up(spawner)
Apr 14 15:07:19 protojupy jupyterhub: File "/usr/local/lib/python3.6/site-packages/jupyterhub/user.py", line 715, in _wait_up
Apr 14 15:07:19 protojupy jupyterhub: raise e
Apr 14 15:07:19 protojupy jupyterhub: File "/usr/local/lib/python3.6/site-packages/jupyterhub/user.py", line 683, in _wait_up
Apr 14 15:07:19 protojupy jupyterhub: http=True, timeout=spawner.http_timeout, ssl_context=ssl_context
Apr 14 15:07:19 protojupy jupyterhub: File "/usr/local/lib/python3.6/site-packages/jupyterhub/utils.py", line 234, in wait_for_http_server

snippet of nginx log file:

2020/04/14 15:06:19 [error] 4802#0: *1 connect() failed (111: Connection refused) while           connecting to upstream, client: 130.55.178.36, server: protojupy.lanl.gov, request: "GET /hub/    logout HTTP/1.1", upstream: "http://[::1]:8080/hub/logout", host: "protojupy.lanl.gov",           referrer: "https://protojupy.lanl.gov/hub/spawn"  
                                            
2020/04/14 15:06:47 [error] 4802#0: *2 connect() failed (111: Connection refused) while           connecting to upstream, client: 130.55.178.36, server: protojupy.lanl.gov, request: "POST /       hub/spawn HTTP/1.1", upstream: "http://[::1]:8080/hub/spawn", host: "protojupy.lanl.gov",         referrer: "https://protojupy.lanl.gov/hub/spawn"

Thanks. Let me know if I should provide any more information or if anything needs clarification.

The JupyterHub logs indicate that the spawner failed to start your singleuser server. I’m not familiar with SSHspawner but some things you could try are:

  • login to the SSH host and check if anything is running
  • add some additional debug logging to the spawner since you’ve already got your own fork