Jupyterhub failing to spawn after successful login

Currently trying to upgrade the helm version to Version 4.1.0 & App version 5.2.1.
After successfully logging in I get the error

[E 2025-01-30 10:58:32.156 JupyterHub pages:312] Error starting server <redacted user id>: 'NoneType' object is not subscriptable
    Traceback (most recent call last):
    NoneType: None

The source of the error is coming from jupyterhub/handlers/page.py

async def _wrap_spawn_single_user(
        self, user, server_name, spawner, pending_url, options=None
    ):
        # Explicit spawn request: clear _spawn_future
        # which may have been saved to prevent implicit spawns
        # after a failure.
        if spawner._spawn_future and spawner._spawn_future.done():
            spawner._spawn_future = None
        # not running, no form. Trigger spawn and redirect back to /user/:name
        f = asyncio.ensure_future(
            self.spawn_single_user(user, server_name, options=options)
        )
        done, pending = await asyncio.wait([f], timeout=1)
        # If spawn_single_user throws an exception, raise a 500 error
        # otherwise it may cause a redirect loop
        if f.done() and f.exception():
            exc = f.exception()
            self.log.exception(f"Error starting server {spawner._log_name}: {exc}")
            if isinstance(exc, web.HTTPError):
                # allow custom HTTPErrors to pass through
                raise exc
            raise web.HTTPError(
                500,
                f"Unhandled error starting server {spawner._log_name}",
            )
        return self.redirect(pending_url)

Not sure if its related but I also cannot get _xsrf token to work since upgrading from version 2.0.0 & app version 3.0.0.

Any help would be greatly appreciated

Is this really the entire traceback reported?

If so, that’s not much to go on, unfortunately. I would expect more of an error to be logged, though. If there is a traceback somewhere, please do include the whole thing.

Hi thanks replying so I managed to fix this above error by overriding refresh_user in OAuthenticator. It believe its caused by the auth_state being refreshed but then failing. These are the logs extra logs I get.

[JupyterHub _xsrf_utils:125] Setting new xsrf cookie for 4' {'path': '/jupyter/hub/'}
[JupyterHub log:192] 302 GET /jupyter/hub/login -> /jupyter/hub/spawn (my client id @ ip address)
[D JupyterHub scopes:1010] Checking access to /jupyter/hub/spawn via scope servers!server=my client id/
Hitting auth_state_hook
[D JupyterHub pages:216] Triggering spawn with default options for my-client-id
[D 2025-02-03 10:49:37.240 JupyterHub base:411] Refreshing auth for my-client-id

I’m not sure what the root cause of this is.
What extra info do you need to help resolve this issue?

In terms of the xsrf issue these are the logs I get from k8s. I know there were some breaking changes but I’m unsure what I need to make for this work. Any insight would be really appreciated. I got round the xsrf issue by again overriding the check_xsrf_cookie in the callback handler

[D 2025-02-03 11:04:21.187 JupyterHub log:192] 200 GET /jupyter/hub/health (@ip address) 0.93ms
[W 2025-02-03 11:04:21.701 JupyterHub web:1873] 403 POST /jupyter/hub/oauth_callback (ip address): '_xsrf' argument missing from POST
[D 2025-02-03 11:04:21.702 JupyterHub base:1519] Using default error template for 403
[W 2025-02-03 11:04:21.703 JupyterHub log:192] 403 POST /jupyter/hub/oauth_callback (@ip address) 2.49ms
[I 2025-02-03 11:04:21.763 JupyterHub log:192] 200 GET /jupyter/hub/metrics (@ip address) 13.98ms

Something’s definitely weird in the configuration, because /jupyter/hub/oauth_callback is not a POST handler at all, which makes me think something is wonky. Can you share your JupyterHub configuration (with any sensitive fields redacted)?

The refresh auth state does make sense. It would be helpful to share the complete traceback of the error and surrounding log context to get to the bottom of it. It might also help to enable debug logging with --debug to get more detail.

Hey, thanks for getting back I managed to resolve the xsrf issue. I had to override check_xsrf_cookie
So the xsrf token was being sent in the field cookie.

This is the original code in jupyterhub

def check_xsrf_cookie(handler):
    """Check that xsrf cookie matches xsrf token in request"""
    # overrides tornado's implementation
    # because we changed what a correct value should be in xsrf_token
    if not _needs_check_xsrf(handler):
        # don't require XSRF for regular page views
        return

    token = (
        handler.get_argument("_xsrf", None)
        or handler.request.headers.get("X-Xsrftoken")
        or handler.request.headers.get("X-Csrftoken")
    )

    if not token:
        # Would fail here
        raise web.HTTPError(
            403, f"'_xsrf' argument missing from {handler.request.method}" 
        )

    try:
        token = token.encode("utf8")
    except UnicodeEncodeError:
        raise web.HTTPError(403, "'_xsrf' argument invalid")

    if token != handler.xsrf_token:
        raise web.HTTPError(
            403, f"XSRF cookie does not match {handler.request.method.upper()} argument"
        )

This is the solution that resolved it for me

def check_xsrf_cookie(self):
        self.log.debug('Custom xsrf cookie')
        token = self.request.headers.get("cookie") # The actual _xsrf cookie is embedded in a string separated by ;
        
        if token is None:
            raise Exception("_xsrf cookie is missing from header")
        parts = [part for part in token.split("; ") if part.startswith("_xsrf=")]

        # Only one xsrf token should be present
        xsrf_token = parts[0].split("=", 1)[1] if parts else None

        if not xsrf_token:
            raise HTTPError(403, "'_xsrf' argument missing from POST")
        _, xsrf_token, _ = self._decode_xsrf_token(xsrf_token)
        _, expected_token, _ = self._get_raw_xsrf_token()
        if not xsrf_token:
            raise HTTPError(403, "'_xsrf' argument has invalid format")
        if not hmac.compare_digest(utf8(xsrf_token), utf8(expected_token)):
            raise HTTPError(403, "XSRF cookie does not match POST argument")

That change is disabling the xsrf check entirely. The xsrf argument must come from a request-controlled argument (url parameter or dedicated non-cookie header), and compared with the value stored in the cookie. That change is comparing the cookie with itself, which is always True.

But there should be no POST requests to /hub/oauth_callback, which is the real issue.

More information about configuration and logs would help understand what’s going on.

Oh right I didn’t realise, thanks here is the config and logs

extraConfig:
    client_code_pod_annotation.py: |
      def auth_state_hook(spawner, auth_state):
          client_code = auth_state.get('redacted client id', None)

          if client_code:
              spawner.extra_annotations.update({'client_code': client_code})
      c.Spawner.auth_state_hook = auth_state_hook
    use_okta_authenticator.py: |
      '''
      The `jupyterhub_config.py` file that runs this is located at /usr/local/etc/jupyterhub/jupyterhub_config.py. It
      is configured (https://github.com/jupyterhub/zero-to-jupyterhub-k8s/blob/ca859aafb41d4081388ea5790c26e69b106e91e3/jupyterhub/files/hub/jupyterhub_config.py#L12-L13)
      such that any files in the same directory can be easily imported. Hence no need for a '.' to preceed the import.
      '''
      from OktaOAuthenticator import OktaOAuthenticator
      c.JupyterHub.authenticator_class = OktaOAuthenticator
      c.OAuthenticator.allow_all = True # Allows all authenicated users to login, resolves issue where users will get 403s
      c.JupyterHub.tornado_settings = {
       "xsrf_cookies": True,
      }
    use_lusid_logo.py: |
      c.JupyterHub.logo_file = '/usr/local/share/jupyterhub/static/lusid.png'
config:
    Application:
      log_level: DEBUG
    Authenticator:
      allow_all: true
    JupyterHub:
      auth_state_enabled: true
      authenticator_class: OktaOAuthenticator
      tornado_settings:
        xsrf_cookies: true
      authenticate_prometheus: false

Logs

Loading /usr/local/etc/jupyterhub/secret/values.yaml
No config at /usr/local/etc/jupyterhub/existing-secret/values.yaml
Loading extra config: client_code_pod_annotation.py
Loading extra config: use_lusid_logo.py
Loading extra config: use_okta_authenticator.py
[W 2025-02-06 10:20:46.893 JupyterHub configurable:214] Config option `auth_state_enabled` not recognized by `JupyterHub`.
[I 2025-02-06 10:20:46.894 JupyterHub app:3346] Running JupyterHub version 5.2.1
[I 2025-02-06 10:20:46.894 JupyterHub app:3376] Using Authenticator: OktaOAuthenticator.OktaOAuthenticator
[I 2025-02-06 10:20:46.894 JupyterHub app:3376] Using Spawner: kubespawner.spawner.KubeSpawner-7.0.0
[I 2025-02-06 10:20:46.894 JupyterHub app:3376] Using Proxy: jupyterhub.proxy.ConfigurableHTTPProxy-5.2.1
/usr/local/lib/python3.12/site-packages/jupyter_events/schema.py:68: JupyterEventsVersionWarning: The `version` property of an event schema must be a string. It has been type coerced, but in a future version of this library, it will fail to validate. Please update schema: https://schema.jupyter.org/jupyterhub/events/server-action
  validate_schema(_schema)
[D 2025-02-06 10:20:46.897 JupyterHub app:1998] Connecting to db: sqlite:///jupyterhub.sqlite
[D 2025-02-06 10:20:46.924 JupyterHub orm:1509] database schema version found: 4621fec11365
[D 2025-02-06 10:20:46.933 JupyterHub orm:1509] database schema version found: 4621fec11365
[D 2025-02-06 10:20:47.017 JupyterHub app:2338] Loading roles into database
[D 2025-02-06 10:20:47.017 JupyterHub app:2347] Loading role jupyterhub-idle-culler
[I 2025-02-06 10:20:47.160 JupyterHub app:2919] Creating service jupyterhub-idle-culler without oauth.
[D 2025-02-06 10:20:47.166 JupyterHub app:2685] Purging expired APITokens
[D 2025-02-06 10:20:47.169 JupyterHub app:2685] Purging expired OAuthCodes
[D 2025-02-06 10:20:47.171 JupyterHub app:2685] Purging expired Shares
[D 2025-02-06 10:20:47.173 JupyterHub app:2685] Purging expired ShareCodes
[D 2025-02-06 10:20:47.175 JupyterHub app:2459] Loading role assignments from config
[D 2025-02-06 10:20:47.204 JupyterHub app:2970] Initializing spawners
[D 2025-02-06 10:20:47.224 JupyterHub user:496] Creating <class 'kubespawner.spawner.KubeSpawner'> for <REDACTED_USER_ID>:
[D 2025-02-06 10:20:47.228 JupyterHub app:3100] Loading state for <REDACTED_USER_ID> from db
[D 2025-02-06 10:20:47.243 JupyterHub app:3039] Verifying that <REDACTED_USER_ID> is running at <REDACTED_URL>
[D 2025-02-06 10:20:47.243 JupyterHub utils:292] Waiting 30s for server at <REDACTED_URL>
[I 2025-02-06 10:20:47.244 JupyterHub reflector:297] watching for pods with label selector='component=singleuser-server' in namespace jupyterhub
[D 2025-02-06 10:20:47.244 JupyterHub reflector:304] Connecting pods watcher
[D 2025-02-06 10:20:47.249 JupyterHub utils:328] Server at <REDACTED_URL> responded in 0.01s
[W 2025-02-06 10:20:47.250 JupyterHub _version:67] jupyterhub version 5.2.1 != jupyterhub-singleuser version 4.0.2. This could cause failure to authenticate and result in redirect loops!
[I 2025-02-06 10:20:47.250 JupyterHub app:3053] <REDACTED_USER_ID> still running
[D 2025-02-06 10:20:47.250 JupyterHub spawner:1475] Polling subprocess every 30s
[D 2025-02-06 10:20:47.250 JupyterHub app:3120] Loaded users:
    <REDACTED_USER_ID> admin <REDACTED_USER_ID>: running at <REDACTED_SERVER>
[I 2025-02-06 10:20:47.250 JupyterHub app:3416] Initialized 1 spawners in 0.047 seconds
[I 2025-02-06 10:20:47.259 JupyterHub metrics:373] Found X active users in the last ActiveUserPeriods.twenty_four_hours
[I 2025-02-06 10:20:47.259 JupyterHub metrics:373] Found X active users in the last ActiveUserPeriods.seven_days
[I 2025-02-06 10:20:47.260 JupyterHub metrics:373] Found X active users in the last ActiveUserPeriods.thirty_days
[I 2025-02-06 10:20:47.260 JupyterHub app:3703] Not starting proxy
[D 2025-02-06 10:20:47.269 JupyterHub proxy:392] Checking routes
[I 2025-02-06 10:20:47.269 JupyterHub app:3772] JupyterHub is now running, internal Hub API at <REDACTED_URL>
[D 2025-02-06 10:20:47.270 JupyterHub app:3339] It took 1.015 seconds for the Hub to start
[I 2025-02-06 10:20:57.286 JupyterHub log:192] 302 GET /jupyter/hub/oauth_login?next= -> <REDACTED_OAUTH_URL>
[W 2025-02-06 10:20:58.410 JupyterHub web:1873] 403 POST /jupyter/hub/oauth_callback: '_xsrf' argument missing from POST
[D 2025-02-06 10:20:58.410 JupyterHub base:1519] Using default error template for 403
[W 2025-02-06 10:20:58.440 JupyterHub log:192] 403 POST /jupyter/hub/oauth_callback 30.94ms