KeyError: 'port'

Nick_Cote · November 8, 2023, 4:51pm

We are doing an initial zero2binderhub deployment on top of a local kubernetes cluster with Harbor as a private registry. We have gotten to the point where Binder builds an image, pushes it to the repository, and goes to start but fails. I can provide more information and logs but was hoping this is something obvious like a missing port definition in a yaml file or something.
In the Binder UI logs we see :

Found built image, launching…
Launching server…
Server requested
Spawn failed: ‘port’
Launch attempt 1 failed, retrying…
Spawn failed: ‘port’
Launch attempt 2 failed, retrying…
Spawn failed: ‘port’
Launch attempt 3 failed, retrying…
Spawn failed: ‘port’

In the pod logs the related error message is :

Exception in Future <Task finished name=‘Task-409’ coro=<BaseHandler.spawn_single_user..finish_user_spawn() done, defined at /usr/local/lib/python3.11/site-packages/jupyterhub/handlers/base.py:981> exception=KeyError(‘port’)> after timeout
Traceback (most recent call last):
File “/usr/local/lib/python3.11/site-packages/tornado/gen.py”, line 625, in error_callback
future.result()
File “/usr/local/lib/python3.11/site-packages/jupyterhub/handlers/base.py”, line 988, in finish_user_spawn
await spawn_future
File “/usr/local/lib/python3.11/site-packages/jupyterhub/user.py”, line 902, in spawn
raise e
File “/usr/local/lib/python3.11/site-packages/jupyterhub/user.py”, line 798, in spawn
url = await gen.with_timeout(timedelta(seconds=spawner.start_timeout), f)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 2697, in _start
pod = await self.get_pod_manifest()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 2003, in get_pod_manifest
env=self.get_env(), # Expansion is handled by get_env
^^^^^^^^^^^^^^
File “”, line 104, in get_env
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 2161, in get_env
env.update(self._expand_all(self.environment))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1836, in _expand_all
return {k: self._expand_all(v) for k, v in src.items()}
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1836, in
return {k: self._expand_all(v) for k, v in src.items()}
^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1838, in _expand_all
return self._expand_user_properties(src)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1816, in _expand_user_properties
rendered = template.format(
^^^^^^^^^^^^^^^^
KeyError: ‘port’

manics · November 8, 2023, 7:41pm

Can you show us your full configuration?

Nick_Cote · November 8, 2023, 8:12pm

Someone else on my team is performing the actual install and I’ve been helping to try and figure out the issue. We are just using a Helm install and the config.yaml file is fairly basic:

config:
BinderHub:
use_registry: true
image_prefix: hub.k8s.xxx.yyy/binder-dev-
hub_url: http://jhub-test.k8s.hub.k8s.xxx.yyy
DockerRegistry:
url: https://hub.k8s.xxx.yyy
token_url: https://hub.k8s.xxx.yyy/service/token?service=harbor-registry

service:
type: ClusterIP
ingress:
enabled: true
hosts:
- binder.k8s.xxx.yyy
annotations:
kubernetes.io/ingress.class: nginx
kubernetes.io/tls-acme: “true”
cert-manager.io/cluster-issuer: incommon
tls:
- secretName: binder-k8s–tls
hosts:
- binder.k8s.xxx.yyy
#Added dind and imagecleaner to mitigate build issues with BH
imageBuilderType: dind

manics · November 9, 2023, 5:57pm

Can you turn on debug logging and show us your BinderHub and JupyterHub logs? Which version of the BinderHub helm chart are you using?

barkathali · November 18, 2023, 1:08am

@manics We are utilizing the latest version (version=1.0.0-0.dev.git.3350.he7995d6) of BinderHub helm chart.

As suggested, debug logging is enabled on JupyterHub.
For BinderHub, in technical reference (app — BinderHub documentation), there is an option to enable debug logging, can you help how it can utilized in helm chart. I tested with following config, but helm upgrade is failing.

extraConfig:
c.BinderHub.debug = True

Below are the logs from hub pod when we try to build - binder-examples/conda.git

[D 2023-11-17 23:27:56.390 JupyterHub reflector:374] pods watcher timeout
[D 2023-11-17 23:27:56.391 JupyterHub reflector:289] Connecting pods watcher
[D 2023-11-17 23:27:57.087 JupyterHub scopes:877] Checking access to /hub/api/users/binder-examples-conda-eajqhpde via scope admin:users
[D 2023-11-17 23:27:57.088 JupyterHub scopes:677] Unrestricted access to /hub/api/users/binder-examples-conda-eajqhpde via admin:users
[D 2023-11-17 23:27:57.088 JupyterHub roles:281] Assigning default role to User binder-examples-conda-eajqhpde
[I 2023-11-17 23:27:57.090 JupyterHub roles:238] Adding role user for User: binder-examples-conda-eajqhpde
[I 2023-11-17 23:27:57.099 JupyterHub log:191] 201 POST /hub/api/users/binder-examples-conda-eajqhpde (binder@xx.xx.xx) 15.64ms
[D 2023-11-17 23:27:57.104 JupyterHub scopes:877] Checking access to /hub/api/users/binder-examples-conda-eajqhpde/servers/ via scope servers
[D 2023-11-17 23:27:57.104 JupyterHub scopes:677] Unrestricted access to /hub/api/users/binder-examples-conda-eajqhpde/servers/ via servers
[D 2023-11-17 23:27:57.105 JupyterHub user:431] Creating <class ‘BinderSpawner’> for binder-examples-conda-eajqhpde:
[D 2023-11-17 23:27:57.106 JupyterHub base:961] Initiating spawn for binder-examples-conda-eajqhpde
[D 2023-11-17 23:27:57.106 JupyterHub base:965] 0/64 concurrent spawns
[D 2023-11-17 23:27:57.106 JupyterHub base:970] 0 active servers
[I 2023-11-17 23:27:57.119 JupyterHub provider:659] Creating oauth client jupyterhub-user-binder-examples-conda-eajqhpde
[D 2023-11-17 23:27:57.132 JupyterHub user:794] Calling Spawner.start for binder-examples-conda-eajqhpde
[D 2023-11-17 23:27:57.132 JupyterHub spawner:3199] Applying KubeSpawner override for profile ‘Test Notebook’
[D 2023-11-17 23:27:57.132 JupyterHub spawner:3177] … overriding KubeSpawner value cpu_limit=None
[D 2023-11-17 23:27:57.132 JupyterHub spawner:3177] … overriding KubeSpawner value mem_limit=None
[D 2023-11-17 23:27:57.132 JupyterHub spawner:3177] … overriding KubeSpawner value cpu_guarantee=0.013
[D 2023-11-17 23:27:57.132 JupyterHub spawner:3177] … overriding KubeSpawner value mem_guarantee=0.904G
[I 2023-11-17 23:27:57.132 JupyterHub log:191] 202 POST /hub/api/users/binder-examples-conda-eajqhpde/servers/ (binder@xx.xx.xx.xx) 31.34ms
[E 2023-11-17 23:27:57.133 JupyterHub user:884] Unhandled error starting binder-examples-conda-eajqhpde’s server: ‘port’
Traceback (most recent call last):
File “/usr/local/lib/python3.11/site-packages/jupyterhub/user.py”, line 798, in spawn
url = await gen.with_timeout(timedelta(seconds=spawner.start_timeout), f)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 2697, in _start
pod = await self.get_pod_manifest()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 2003, in get_pod_manifest
env=self.get_env(), # Expansion is handled by get_env
^^^^^^^^^^^^^^
File “”, line 104, in get_env
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 2161, in get_env
env.update(self._expand_all(self.environment))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1836, in _expand_all
return {k: self._expand_all(v) for k, v in src.items()}
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1836, in
return {k: self._expand_all(v) for k, v in src.items()}
^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1838, in _expand_all
return self._expand_user_properties(src)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1816, in _expand_user_properties
rendered = template.format(
^^^^^^^^^^^^^^^^
KeyError: ‘port’

[D 2023-11-17 23:27:57.133 JupyterHub user:982] Stopping binder-examples-conda-eajqhpde
[D 2023-11-17 23:27:57.136 JupyterHub user:1002] Deleting oauth client jupyterhub-user-binder-examples-conda-eajqhpde
[D 2023-11-17 23:27:57.140 JupyterHub user:1005] Finished stopping binder-examples-conda-eajqhpde
[C 2023-11-17 23:27:57.149 JupyterHub base:1064] Aborting due to 5 consecutive spawn failures
[E 2023-11-17 23:27:57.149 JupyterHub gen:630] Exception in Future <Task finished name=‘Task-2745’ coro=<BaseHandler.spawn_single_user..finish_user_spawn() done, defined at /usr/local/lib/python3.11/site-packages/jupyterhub/handlers/base.py:981> exception=KeyError(‘port’)> after timeout
Traceback (most recent call last):
File “/usr/local/lib/python3.11/site-packages/tornado/gen.py”, line 625, in error_callback
future.result()
File “/usr/local/lib/python3.11/site-packages/jupyterhub/handlers/base.py”, line 988, in finish_user_spawn
await spawn_future
File “/usr/local/lib/python3.11/site-packages/jupyterhub/user.py”, line 902, in spawn
raise e
File “/usr/local/lib/python3.11/site-packages/jupyterhub/user.py”, line 798, in spawn
url = await gen.with_timeout(timedelta(seconds=spawner.start_timeout), f)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 2697, in _start
pod = await self.get_pod_manifest()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 2003, in get_pod_manifest
env=self.get_env(), # Expansion is handled by get_env
^^^^^^^^^^^^^^
File “”, line 104, in get_env
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 2161, in get_env
env.update(self._expand_all(self.environment))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1836, in _expand_all
return {k: self._expand_all(v) for k, v in src.items()}
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1836, in
return {k: self._expand_all(v) for k, v in src.items()}
^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1838, in _expand_all
return self._expand_user_properties(src)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/local/lib/python3.11/site-packages/kubespawner/spawner.py”, line 1816, in _expand_user_properties
rendered = template.format(
^^^^^^^^^^^^^^^^
KeyError: ‘port’

[D 2023-11-17 23:27:57.153 JupyterHub scopes:877] Checking access to /hub/api/users/binder-examples-conda-eajqhpde/server/progress via scope read:servers
[D 2023-11-17 23:27:57.153 JupyterHub scopes:677] Unrestricted access to /hub/api/users/binder-examples-conda-eajqhpde/server/progress via read:servers
[I 2023-11-17 23:27:57.154 JupyterHub log:191] 200 GET /hub/api/users/binder-examples-conda-eajqhpde/server/progress (binder@xx.xx.xx.xx) 4.14ms
[D 2023-11-17 23:27:57.183 JupyterHub reflector:374] events watcher timeout
[D 2023-11-17 23:27:57.183 JupyterHub reflector:289] Connecting events watcher
[D 2023-11-17 23:27:58.262 JupyterHub log:191] 200 GET /hub/health (@xx.xx.xx.xx) 0.40ms
Task was destroyed but it is pending!
task: <Task pending name=‘Task-1437’ coro=<shared_client..close_client_task() running at /usr/local/lib/python3.11/site-packages/kubespawner/clients.py:58> wait_for=>
Exception ignored in: <coroutine object shared_client..close_client_task at 0x7fc4ca125300>
RuntimeError: coroutine ignored GeneratorExit

Below are the logs from binder pod and UI respectively:

[I 231117 23:27:57 launcher:197] Creating user binder-examples-conda-eajqhpde for image redacted/binderhub/binder-dev-binder-2dexamples-2dconda-8677da:f00a783146e9c6a2ed9726f01fc09fbfbad2f89e
[I 231117 23:27:57 launcher:257] Starting server for user binder-examples-conda-eajqhpde with image redacted/binderhub/binder-dev-binder-2dexamples-2dconda-8677da:f00a783146e9c6a2ed9726f01fc09fbfbad2f89e
[W 231117 23:27:57 web:1869] 500 GET /build/gh/binder-examples/conda.git/HEAD (10.42.2.0): Spawn failed: ‘port’
===

Found built image, launching…
Launching server…
Server requested
Spawn failed: ‘port’
Launch attempt 1 failed, retrying…
Spawn failed: ‘port’
Launch attempt 2 failed, retrying…
Spawn failed: ‘port’
Launch attempt 3 failed, retrying…
Spawn failed: ‘port’
Spawn failed: ‘port’

manics · November 23, 2023, 12:07am

Are you sure KeyError: 'port' - #3 by Nick_Cote is your full configuration?
Your logs contain

barkathali:

[D 2023-11-17 23:27:57.132 JupyterHub spawner:3199] Applying KubeSpawner override for profile ‘Test Notebook’
[D 2023-11-17 23:27:57.132 JupyterHub spawner:3177] … overriding KubeSpawner value cpu_limit=None
[D 2023-11-17 23:27:57.132 JupyterHub spawner:3177] … overriding KubeSpawner value mem_limit=None
[D 2023-11-17 23:27:57.132 JupyterHub spawner:3177] … overriding KubeSpawner value cpu_guarantee=0.013
[D 2023-11-17 23:27:57.132 JupyterHub spawner:3177] … overriding KubeSpawner value mem_guarantee=0.904G

which isn’t part of the default config.

barkathali · November 27, 2023, 5:54pm

@manics Below is the full configuration:

config:
  BinderHub:
    hub_url: https://jhub-**.k8s.***
    image_prefix: hub.***.***/binderhub/binder-dev-
    use_registry: true
  DockerRegistry:
    token_url: https://hub.***.***/service/token?service=harbor-registry
    url: https://hub.***.***
extraPodSpec:
  dnsPolicy: ClusterFirstWithHostNet
  hostNetwork: true
imageBuilderType: dind
ingress:
  annotations:
    cert-manager**/cluster-issuer: incommon
    kubernetes**/ingress.class: nginx
    kubernetes**/tls-acme: "true"
  enabled: true
  hosts:
  - binder.***.***
  tls:
  - hosts:
    - binder.***.***
    secretName: binder-***
jupyterhub:
  debug:
    enabled: true
  hub:
    config:
      Authenticator:
        admin_users:
        - XXXXXX
        - XXXXXX
      BinderSpawner:
        auth_enabled: true
      GitHubOAuthenticator:
        allowed_organizations:
        - XXXXX
        client_id: <Redacted>
        client_secret: <Redacted>
        oauth_callback_url: https://jhub-***.k8s.***/hub/oauth_callback
        scope:
        - read:org
      JupyterHub:
        authenticator_class: github
      proxy.token: <Redacted>
    services:
      binder:
        apiToken: <Redacted>
  ingress:
    annotations:
      cert-manager**/cluster-issuer: incommon
      nginx.ingress.kubernetes**/proxy-body-size: 600m
      nginx.ingress.kubernetes**/proxy-read-timeout: "1800"
      nginx.ingress.kubernetes**/proxy-send-timeout: "1800"
      nginx.ingress.kubernetes**/rewrite-target: /
      nginx.ingress.kubernetes**/secure-backends: "true"
      nginx.ingress.kubernetes**/ssl-redirect: "true"
      nginx.ingress.kubernetes**/websocket-services: proxy-public
      nginx.org/client-max-body-size: 10m
      nginx.org/websocket-services: proxy-public
    enabled: true
    hosts:
    - jhub-***.k8s.***
    ingressClassName: nginx
    tls:
    - hosts:
      - jhub-***.k8s.***
      secretName: https-auto-incommon
  proxy:
    secretToken: <Redacted>
    service:
      type: ClusterIP
  singleuser:
    cmd: jupyterhub-singleuser
    extraEnv:
      DASK_DISTRIBUTED__DASHBOARD__LINK: $(JUPYTERHUB_SERVICE_PREFIX)proxy/{port}/status
      DASK_GATEWAY__CLUSTER__OPTIONS__IMAGE: $(JUPYTER_IMAGE_SPEC)
    image:
      name: pangeo/pangeo-notebook
      tag: xxxx.xx.xx
    profileList:
    - default: true
      description: Start a container with the chosen specifications on a node of this
        type
      display_name: Pangeo Notebook
      kubespawner_override:
        cpu_limit: null
        mem_limit: null
      profile_options:
        requests:
          choices:
            mem_1:
              default: true
              display_name: ~1 GB, ~0.125 CPU
              kubespawner_override:
                cpu_guarantee: 0.013
                mem_guarantee: 0.904G
            mem_4:
              display_name: ~4 GB, ~0.5 CPU
              kubespawner_override:
                cpu_guarantee: 0.025
                mem_guarantee: 1.809G
            mem_16:
              display_name: ~16 GB, ~2.0 CPU
              kubespawner_override:
                cpu_guarantee: 0.5
                mem_guarantee: 14.469G
          display_name: Container Selection
      slug: pangeo
    - description: Start a container on a dedicated node with a GPU
      display_name: NVIDIA Tensor A10
      kubespawner_override:
        environment:
          NVIDIA_DRIVER_CAPABILITIES: compute,utility
        extra_pod_config:
          runtimeClassName: nvidia
        extra_resource_limits:
          nvidia.com/gpu: "1"
        mem_guarantee: 14G
        mem_limit: null
      profile_options:
        image:
          choices:
            pytorch:
              default: true
              display_name: Pangeo PyTorch ML Notebook
              kubespawner_override:
                image: pangeo/pytorch-notebook:2023.05.18
              slug: pytorch
            tensorflow:
              display_name: Pangeo Tensorflow ML Notebook
              kubespawner_override:
                image: pangeo/ml-notebook:2023.05.18
              slug: tensorflow
          display_name: Image
      slug: gpu
    - description: 6 GB of memory; up to 4 vCPUS
      display_name: Test Custom
      kubespawner_override:
        cpu_guarantee: 1
        cpu_limit: 4
        mem_guarantee: 2G
        mem_limit: 6G
      profile_options:
        image:
          choices:
            tensorflow:
              display_name: <Redacted>
              kubespawner_override:
                image: <Redacted>
              slug: <redacted>
          display_name: Latest
    storage:
      extraVolumeMounts:
      - mountPath: /home/**/**
        name: nfs-volume
        readOnly: true
      - mountPath: /**/collections
        name: **-collections
        readOnly: true
      - mountPath: /**/campaign
        name: campaign
        readOnly: true
      extraVolumes:
      - name: nfs-volume
        nfs:
          path: /mnt/**/jupyter/shared
          server: <Redacted>
      - name: **-collections
        nfs:
          path: /gpfs/fs1/collections
          server: <Redacted>
      - name: campaign
        nfs:
          path: /gpfs/csfs1
          server: <Redacted>
registry:
  password: <Redacted>
  url: https://hub.k8s.***.***
  username: <Redacted>
service:
  type: ClusterIP

manics · December 1, 2023, 3:33pm

I think this is the cause of

Try using {{port}} instead

github.com/jupyterhub/kubespawner

Expand environment variables

jupyterhub:main ← dolfinus:expand_environment

opened 12:29PM - 30 Sep 22 UTC

dolfinus

+47 -14

### Updated PR summary Like for other of KubeSpawner's config options, `KubeS…pawner.environment` now supports variable expansion. This means that `{` and `}` gets reserved for use by variable expansion. To retain existing behavior, replace `{` and `}` with `{{` and `}}` respectively in this `KubeSpawner.environment`. `{username}`, `{userid}`, `{servername}`, `{hubnamespace}`, `{unescaped_username}`, and `{unescaped_servername}` will now be expanded if found within strings of the `KubeSpawner.environment` config. `username` and `servername` comes escaped to follow the [DNS label standard](https://kubernetes.io/docs/concepts/overview/working-with-objects/names/#dns-label-names) This feature is released as part of KubeSpawner 5.0.0. ### Original PR description In #644 spawner can add extra services after pod creation. To pass created service name, I've tried to set up notebook environment like this: ```python c.KubeSpawner.environment = {"SPARK_DRIVER_HOST": "jupyter-{username}-spark-driver--{servername}"} ``` But unfortunately, environment variables does not support substitutions. Now they are

barkathali · December 1, 2023, 4:19pm

thank you @manics !
Will give it a try and let you know the outcome.

barkathali · December 1, 2023, 5:07pm

it worked, thank you @manics !

Topic		Replies	Views
Binderhub container init error/crashloopbackoff after upgrading Binder	1	512	May 2, 2022
Custom docker image, spawn fails on mybinder.org repo help jupyterhub , help-wanted	6	989	October 21, 2022
Debugging BinderHub: Immediately fails to build a binder BinderHub	6	1556	March 20, 2019
Containers created, but spawn fails on mybinder.org mybinder.org ops	1	1078	October 19, 2021
Binderhub install gives 400 error (bad request) BinderHub	10	1567	February 20, 2019

KeyError: 'port'

Related Topics