JupyterHub in K8s, Profile None Type on First Login Only

I’m experiencing abug that isn’t throwing any errors or warnings in the logs. When a user logs into JupyterHub (hosted in Kubernetes), after the user has been authenticated (via third party, so there is a redirect happening), if the JH database has existing tables, the profile selection screen (which we’re using to allow users to select a pod size) is skipped and a pod is automatically starts with the default profile that is configured on the JH server. This only happens at the time of login. If the user stops their running pod, they are able to return to the profile selection screen and select a desired profile as intended.

While trying to replicate the issue on a feature branch, when the database is empty and a user is logging in for the first time (i.e. when the feature branch is first created and deployed, making this the very first time someone logs into JH on this feature branch), the profile selection screen loads as intended. Similarly on the main branch, if I drop the DB tables and relaunch the server, the profile selection screen shows up.

So from what I’m seeing, it’s only when the database has existing tables and the user is logging in that the issue occurs. The database exists outside of the namespace as a DBaaS provided by others. This issue was not being experienced with the DB was hosted within the cluster in a Postgres container. Access to the DB doesn’t appear to be the issue as we have verified the admin account is usable and we are able to create tables within the DB.

The only hint I am getting from the logs during the time of login when the pre_spawn_hook is called, the profile type that is being load is None. So my thought is that as the server is progressing through start up, it’s not getting a response from the DB when it tries to load the profiles, but this only occurs in this one specific situation (at first login). We know that JH is able to communicate with the DB because the subsequent attempt is able to get to the profile selection screen after the user pod was started was successful.

Relevant logs (at start up, after being authenticated and redirected back to JH):

[D 2023-04-28 17:12:07.856 JupyterHub roles:454] Assigning default role to User redacted-user
[D 2023-04-28 17:12:07.888 JupyterHub base:934] Initiating spawn for redacted-user
[D 2023-04-28 17:12:07.888 JupyterHub base:938] 0/100 concurrent spawns
[D 2023-04-28 17:12:07.888 JupyterHub base:943] 0 active servers
[D 2023-04-28 17:12:07.919 JupyterHub roles:477] Checking token permissions against requested role server
[I 2023-04-28 17:12:07.921 JupyterHub roles:482] Adding role server to token: <APIToken('.....', user='redacted-user', client_id='secret-id')>
[I 2023-04-28 17:12:07.992 JupyterHub provider:607] Creating oauth client jupyterhub-user-redacted-user
@ pre_spawn_start
pre_spawn_hook initiated. Assigning username and profile...
username: redacted-user
profile: None
_find_default_profile: None
user_profile: Jupyter Notebook Server (1 CPU Core, 1GB Memory)

I’m a bit stumped, curious if anyone has any suggestions?

Additional Info:

-$ jupyter --version
Selected Jupyter core packages...
IPython          : 8.10.0
ipykernel        : 6.22.0
ipywidgets       : 7.6.3
jupyter_client   : 6.2.0
jupyter_core     : 5.3.0
jupyter_server   : 1.23.6
jupyterlab       : 3.2.8
nbclient         : 0.5.13
nbconvert        : not installed
nbformat         : 5.8.0
notebook         : 6.4.12
qtconsole        : not installed
traitlets        : 5.9.0

We got a bit deeper into the logs and troubleshooting, it looks like a race condition is happening with OAuth. When the login works as expected and I see the profile selection screen, I see this sequence in the logs:

[D 2023-05-11 14:54:53.612 JupyterHub roles:454] Assigning default role to User 265616052
[D 2023-05-11 14:54:53.617 JupyterHub log:189] 200 GET /hub/health (@::ffff:10.190.17.2) 1.30ms
[D 2023-05-11 14:54:53.627 JupyterHub base:565] Setting cookie jupyterhub-session-id: {'httponly': True, 'path': '/'}
[D 2023-05-11 14:54:53.627 JupyterHub base:569] Setting cookie for 265616052: jupyterhub-hub-login
[D 2023-05-11 14:54:53.628 JupyterHub base:565] Setting cookie jupyterhub-hub-login: {'httponly': True, 'path': '/hub/'}
[I 2023-05-11 14:54:53.628 JupyterHub base:816] User logged in: 265616052
[I 2023-05-11 14:54:53.629 JupyterHub log:189] 302 GET /hub/oauth_callback?code=[secret]&state=[secret] -> /hub/ (@::ffff:10.190.29.2) 610.39ms
[D 2023-05-11 14:54:54.064 JupyterHub user:399] Creating <class 'kubespawner.spawner.KubeSpawner'> for 265616052:
[D 2023-05-11 14:54:54.065 JupyterHub spawner:195] Starting executor thread pool with 80 workers

Noting the 302 that occurs before the creation of KubeSpawner.

When the profile selection screen is skipped, we’re seeing the KubeSpawner being created before the 302:

[D 2023-05-11 17:33:25.902 JupyterHub roles:454] Assigning default role to User 265616052
[D 2023-05-11 17:33:25.926 JupyterHub base:565] Setting cookie jupyterhub-session-id: {'httponly': True, 'path': '/'}
[D 2023-05-11 17:33:25.926 JupyterHub base:569] Setting cookie for 265616052: jupyterhub-hub-login
[D 2023-05-11 17:33:25.927 JupyterHub base:565] Setting cookie jupyterhub-hub-login: {'httponly': True, 'path': '/hub/'}
[I 2023-05-11 17:33:25.927 JupyterHub base:816] User logged in: 265616052
[D 2023-05-11 17:33:25.927 JupyterHub user:399] Creating <class 'kubespawner.spawner.KubeSpawner'> for 265616052:
[I 2023-05-11 17:33:25.930 JupyterHub log:189] 302 GET /hub/oauth_callback?code=[secret]&state=[secret] -> /hub/spawn?code=[secret]&state=[secret] (@::ffff:10.190.67.2) 1440.77ms
[D 2023-05-11 17:33:26.050 JupyterHub scopes:491] Checking access via scope servers
[D 2023-05-11 17:33:26.050 JupyterHub scopes:402] Argument-based access to /hub/spawn via servers
[D 2023-05-11 17:33:26.051 JupyterHub pages:189] Triggering spawn with supplied query arguments for 265616052
[D 2023-05-11 17:33:26.051 JupyterHub base:326] Refreshing auth for 265616052

Is there a way to make the KubeSpawner wait for the OAuth callback to finish before it starts spawning?