search

jupyterhub / zero-to-jupyterhub-k8s

Helm Chart & Documentation for deploying JupyterHub on Kubernetes
https://zero-to-jupyterhub.readthedocs.io
Other
1.54k stars 796 forks source link

500 : Internal Server Error - starting server for new user after deploying jupyterhub on k8s #1446

Closed lapeng closed 4 years ago

lapeng commented 4 years ago

After installing jupyterhub on my k8s cluster running on VMs all pods/services are up and login page available. I try to initiate first user login and I get "500 : Internal Server Error"

image

From pod log:

[D 2019-10-14 14:31:55.894 JupyterHub reflector:263] events watcher timeout [D 2019-10-14 14:31:55.894 JupyterHub reflector:202] Connecting events watcher [D 2019-10-14 14:32:01.405 JupyterHub reflector:263] pods watcher timeout [D 2019-10-14 14:32:01.405 JupyterHub reflector:202] Connecting pods watcher [D 2019-10-14 14:32:02.165 JupyterHub base:357] Setting cookie jupyterhub-session-id: {'httponly': True} [D 2019-10-14 14:32:02.165 JupyterHub base:362] Setting cookie for toto: jupyterhub-hub-login [D 2019-10-14 14:32:02.166 JupyterHub base:357] Setting cookie jupyterhub-hub-login: {'httponly': True, 'path': '/hub/'} [I 2019-10-14 14:32:02.166 JupyterHub base:509] User logged in: toto [I 2019-10-14 14:32:02.167 JupyterHub log:158] 302 POST /hub/login?next= -> /user/toto/ (toto@10.244.5.0) 26.95ms [I 2019-10-14 14:32:02.287 JupyterHub log:158] 302 GET /user/toto/ -> /hub/user/toto/ (@10.244.5.0) 1.49ms [D 2019-10-14 14:32:02.504 JupyterHub user:190] Creating <class 'kubespawner.spawner.KubeSpawner'> for toto: [D 2019-10-14 14:32:02.518 JupyterHub base:613] Initiating spawn for toto [D 2019-10-14 14:32:02.519 JupyterHub base:619] 0/64 concurrent spawns [D 2019-10-14 14:32:02.519 JupyterHub base:622] 0 active servers [E 2019-10-14 14:32:02.558 JupyterHub user:477] Unhandled error starting toto's server: '<' not supported between instances of 'datetime.datetime' and 'NoneType' [D 2019-10-14 14:32:02.563 JupyterHub user:578] Deleting oauth client jupyterhub-user-toto [E 2019-10-14 14:32:02.579 JupyterHub gen:593] Exception in Future <Task finished coro=<BaseHandler.spawn_single_user..finish_user_spawn() done, defined at /usr/local/lib/python3.6/dist-packages/jupyterhub/handlers/base.py:629> exception=TypeError("'<' not supported between instances of 'datetime.datetime' and 'NoneType'",)> after timeout Traceback (most recent call last): File "/usr/local/lib/python3.6/dist-packages/tornado/gen.py", line 589, in error_callback future.result() File "/usr/local/lib/python3.6/dist-packages/jupyterhub/handlers/base.py", line 636, in finish_user_spawn await spawn_future File "/usr/local/lib/python3.6/dist-packages/jupyterhub/user.py", line 489, in spawn raise e File "/usr/local/lib/python3.6/dist-packages/jupyterhub/user.py", line 409, in spawn url = await gen.with_timeout(timedelta(seconds=spawner.start_timeout), f) File "/usr/local/lib/python3.6/dist-packages/kubespawner/spawner.py", line 1636, in _start events = self.events File "/usr/local/lib/python3.6/dist-packages/kubespawner/spawner.py", line 1491, in events for event in self.event_reflector.events: File "/usr/local/lib/python3.6/dist-packages/kubespawner/spawner.py", line 72, in events key=lambda x: x.last_timestamp, TypeError: '<' not supported between instances of 'datetime.datetime' and 'NoneType'

[W 2019-10-14 14:32:02.579 JupyterHub base:699] 3 consecutive spawns failed. Hub will exit if failure count reaches 5 before succeeding [W 2019-10-14 14:32:02.579 JupyterHub web:1782] 500 GET /hub/user/toto/ (10.244.5.0): Spawner failed to start [status=1]. The logs for toto may contain details. [D 2019-10-14 14:32:02.579 JupyterHub base:890] No template for 500 [E 2019-10-14 14:32:02.580 JupyterHub log:150] { "X-Forwarded-Host": "10.44.255.106:30371", "X-Forwarded-Proto": "http", "X-Forwarded-Port": "30371", "X-Forwarded-For": "10.244.5.0", "Cookie": "jupyterhub-hub-login=\"2|1:0|10:1571063522|20:jupyterhub-hub-login|44:MjAzMmNjZGM2M2MxNGRjODhiZWVlY2EwZmRlY2M0NTY=|6e0a2bb26ff78b928ecb00e784fa8e689c17f62142c669110eea96cf18f9683c\"; jupyterhub-session-id=98d1ff228f364f58a49aa3e286badfd4", "Accept-Language": "en-CA,en-GB;q=0.9,en-US;q=0.8,en;q=0.7,fr;q=0.6", "Accept-Encoding": "gzip, deflate", "Referer": "http://10.44.255.106:30371/hub/login", "Accept": "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,/;q=0.8,application/signed-exchange;v=b3", "User-Agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/77.0.3865.90 Safari/537.36", "Upgrade-Insecure-Requests": "1", "Cache-Control": "max-age=0", "Connection": "close", "Host": "10.44.255.106:30371" } [E 2019-10-14 14:32:02.580 JupyterHub log:158] 500 GET /hub/user/toto/ (toto@10.244.5.0) 89.50ms [D 2019-10-14 14:32:05.949 JupyterHub reflector:263] events watcher timeout [D 2019-10-14 14:32:05.950 JupyterHub reflector:202] Connecting events watcher [D 2019-10-14 14:32:11.417 JupyterHub reflector:263] pods watcher timeout [D 2019-10-14 14:32:11.418 JupyterHub reflector:202] Connecting pods watcher [D 2019-10-14 14:32:16.005 JupyterHub reflector:263] events watcher timeout [D 2019-10-14 14:32:16.006 JupyterHub reflector:202] Connecting events watcher [D 2019-10-14 14:32:21.429 JupyterHub reflector:263] pods watcher timeout [D 2019-10-14 14:32:21.430 JupyterHub reflector:202] Connecting pods watcher [D 2019-10-14 14:32:26.060 JupyterHub reflector:263] events watcher timeout [D 2019-10-14 14:32:26.061 JupyterHub reflector:202] Connecting events watcher [D 2019-10-14 14:32:30.337 JupyterHub proxy:686] Proxy: Fetching GET http://10.105.19.121:8001/api/routes

Deployed using the following chart: jupyterhub-0.8.2

Config.yaml:

Proxy token

proxy: secretToken: "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"

Storage

singleuser: storage: type: none dynamic: storageClass: standard

After reading a few posts I updated my config.yaml to the following:

Current config.yaml

Proxy token

proxy: secretToken: "abbd4efc9051cac30fa5369f5e5d51c05f0d12392ebc0bfb294bd83a91a5d4"

hub: uid: 0 fsGid: 0 extraConfig: myConfig.py: | c.KubeSpawner.uid = 0 c.JupyterHub.allow_named_servers=True

    c.Spawner.cmd = ['jupyter-labhub']
    c.Spawner.args = ['--allow-root']
    c.Spawner.uid = 0
    c.Spawner.gid = 0
    c.Spawner.delete_stopped_pods = False
    c.Spawner.debug = True
    c.JupyterHub.log_level = 'DEBUG'
    c.LocalProcessSpawner.debug = True

Storage

singleuser: storage: type: none dynamic: storageClass: standard uid: 0

Even after update above error persists, not sure why I am unable to spawn notebooks with default configuration.

[root@jhub]# kubectl get all --namespace=jhub NAME READY STATUS RESTARTS AGE pod/hub-7c49c9dbff-prkc6 1/1 Running 0 72m pod/proxy-585dddc8dc-vtr29 1/1 Running 0 6h11m

NAME TYPE CLUSTER-IP EXTERNAL-IP PORT(S) AGE service/hub ClusterIP 10.96.184.212 8081/TCP 3d5h service/proxy-api ClusterIP 10.105.19.121 8001/TCP 3d5h service/proxy-public LoadBalancer 10.102.100.111 80:30371/TCP,443:32171/TCP 3d5h

NAME READY UP-TO-DATE AVAILABLE AGE deployment.apps/hub 1/1 1 1 3d5h deployment.apps/proxy 1/1 1 1 3d5h

NAME DESIRED CURRENT READY AGE replicaset.apps/hub-569477764 0 0 0 3d5h replicaset.apps/hub-599fb78d59 0 0 0 4h18m replicaset.apps/hub-6967945dfb 0 0 0 4h27m replicaset.apps/hub-7b7cdf886c 0 0 0 74m replicaset.apps/hub-7c49c9dbff 1 1 1 72m replicaset.apps/hub-98cc6cb64 0 0 0 3d replicaset.apps/hub-98d9dccdf 0 0 0 3d5h replicaset.apps/hub-c89dcb8b9 0 0 0 4h34m replicaset.apps/proxy-585dddc8dc 1 1 1 3d5h

NAME READY AGE statefulset.apps/user-placeholder 0/0 3d5h

Statefulset Description:

[root@jhub]# kubectl describe statefulset.apps/user-placeholder -n jhub Name: user-placeholder Namespace: jhub CreationTimestamp: Fri, 11 Oct 2019 09:08:57 +0000 Selector: app=jupyterhub,component=user-placeholder,release=jhub Labels: app=jupyterhub chart=jupyterhub-0.8.2 component=user-placeholder heritage=Tiller release=jhub Annotations: Replicas: 0 desired | 0 total Update Strategy: RollingUpdate Partition: 824639700632 Pods Status: 0 Running / 0 Waiting / 0 Succeeded / 0 Failed Pod Template: Labels: app=jupyterhub component=user-placeholder release=jhub Containers: pause: Image: gcr.io/google_containers/pause:3.0 Port: Host Port: Requests: memory: 1G Environment: Mounts: Volumes: Volume Claims: Events:

Pod Decription:

[root@esemlc94dev110 jhub]# kubectl describe po hub-7c49c9dbff-prkc6 -n jhub Name: hub-7c49c9dbff-prkc6 Namespace: jhub Priority: 0 Node: esemlc94dev106/10.44.255.106 Start Time: Mon, 14 Oct 2019 13:34:27 +0000 Labels: app=jupyterhub component=hub hub.jupyter.org/network-access-proxy-api=true hub.jupyter.org/network-access-proxy-http=true hub.jupyter.org/network-access-singleuser=true pod-template-hash=7c49c9dbff release=jhub Annotations: checksum/config-map: 5e97626d8ef29a9c1710debe50e64c657f3fe1cf9ae8b4a971bbbc6285b154b5 checksum/secret: 6371812f8091ab5c53500c9f26e3828f0d3a13cabe9ec4c6a7a072712a1c491c Status: Running IP: 10.244.5.55 IPs: IP: 10.244.5.55 Controlled By: ReplicaSet/hub-7c49c9dbff Containers: hub: Container ID: docker://22d5fb94520e5f5d53e6577eaf1322ad502cb6abbe025b8c18cc95449b2648c7 Image: jupyterhub/k8s-hub:0.8.2 Image ID: docker-pullable://jupyterhub/k8s-hub@sha256:0492ebf6917e3da9a8c8ce35d4e014769f469271b724a58b0823cba7bee066ce Port: 8081/TCP Host Port: 0/TCP Command: jupyterhub --config /srv/jupyterhub_config.py --upgrade-db State: Running Started: Mon, 14 Oct 2019 13:34:29 +0000 Ready: True Restart Count: 0 Requests: cpu: 500m memory: 2Gi Environment: PYTHONUNBUFFERED: 1 HELM_RELEASE_NAME: jhub POD_NAMESPACE: jhub (v1:metadata.namespace) CONFIGPROXY_AUTH_TOKEN: <set to the key 'proxy.token' in secret 'hub-secret'> Optional: false Mounts: /data/jupyterhub from hub-db-dir (rw) /etc/jupyterhub/config/ from config (rw) /etc/jupyterhub/secret/ from secret (rw) /var/run/secrets/kubernetes.io/serviceaccount from hub-token-fzcgd (ro) Conditions: Type Status Initialized True Ready True ContainersReady True PodScheduled True Volumes: config: Type: ConfigMap (a volume populated by a ConfigMap) Name: hub-config Optional: false secret: Type: Secret (a volume populated by a Secret) SecretName: hub-secret Optional: false hub-db-dir: Type: PersistentVolumeClaim (a reference to a PersistentVolumeClaim in the same namespace) ClaimName: hub-db-dir ReadOnly: false hub-token-fzcgd: Type: Secret (a volume populated by a Secret) SecretName: hub-token-fzcgd Optional: false QoS Class: Burstable Node-Selectors: Tolerations: node.kubernetes.io/not-ready:NoExecute for 300s node.kubernetes.io/unreachable:NoExecute for 300s Events:

Please let me know if more information is needed

manics commented 4 years ago

@lapeng Are you using K8s 1.16? There's at least known known bug when running Z2JH on it: https://github.com/jupyterhub/zero-to-jupyterhub-k8s/issues/1444 In particular it looks like you're seeing https://github.com/jupyterhub/kubespawner/issues/354

lapeng commented 4 years ago

Thank you, yes I am using K8s 1.16. Do you know if the scripts will be updated with patch described in jupyterhub/kubespawner#354 or this is only a temporary fix. If not what version of k8s would you recommend for jhub?