I am having an issue where the hub pod is unable to spawn user pods, and failing within 30 seconds with a timeout error, even though the singleuser.startTimeout is set to 30000. While trying to create the pod, I see the logs saying Attempting to create pod jupyter-user3, with timeout 3, and then eventually fails after 30 seconds with user3's server failed to start in 30000 seconds, giving up., even though it hasn’t been 30000 seconds in total.
Is there a way to increase the timeout 3 which it uses while “attempting to create the pod” ?
My cluster has a lot of resources, so pod creation, etc. takes up to a minute or two on times.
I see the following in the hub logs
[D 2023-04-25 17:28:31.789 JupyterHub user:430] Creating <class 'kubespawner.spawner.KubeSpawner'> for user3:
[D 2023-04-25 17:28:31.792 JupyterHub pages:213] Triggering spawn with default options for user3
[D 2023-04-25 17:28:31.792 JupyterHub base:934] Initiating spawn for user3
[D 2023-04-25 17:28:31.792 JupyterHub base:938] 0/64 concurrent spawns
[D 2023-04-25 17:28:31.792 JupyterHub base:943] 0 active servers
[I 2023-04-25 17:28:31.803 JupyterHub provider:651] Creating oauth client jupyterhub-user-user3
[D 2023-04-25 17:28:31.821 JupyterHub user:743] Calling Spawner.start for user3
[I 2023-04-25 17:28:31.822 JupyterHub spawner:2509] Attempting to create pvc claim-user3, with timeout 3
[I 2023-04-25 17:28:31.823 JupyterHub log:186] 302 GET /hub/spawn/user3 -> /hub/spawn-pending/user3 (user3@100.64.31.165) 36.76ms
[D 2023-04-25 17:28:31.844 JupyterHub scopes:796] Checking access via scope servers
[D 2023-04-25 17:28:31.844 JupyterHub scopes:623] Argument-based access to /hub/spawn-pending/user3 via servers
[I 2023-04-25 17:28:31.844 JupyterHub pages:394] user3 is pending spawn
[D 2023-04-25 17:28:31.845 JupyterHub log:186] 304 GET /hub/spawn-pending/user3 (user3@100.64.31.165) 3.24ms
[I 2023-04-25 17:28:31.846 JupyterHub spawner:2525] PVC claim-user3 already exists, so did not create new pvc.
[I 2023-04-25 17:28:31.851 JupyterHub spawner:2469] Attempting to create pod jupyter-user3, with timeout 3
[D 2023-04-25 17:28:31.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.55ms
[D 2023-04-25 17:28:31.928 JupyterHub scopes:796] Checking access via scope read:servers
[D 2023-04-25 17:28:31.928 JupyterHub scopes:623] Argument-based access to /hub/api/users/user3/server/progress via read:servers
[D 2023-04-25 17:28:31.929 JupyterHub spawner:2308] progress generator: jupyter-user3
[D 2023-04-25 17:28:32.901 JupyterHub reflector:362] pods watcher timeout
[D 2023-04-25 17:28:32.902 JupyterHub reflector:281] Connecting pods watcher
[D 2023-04-25 17:28:33.541 JupyterHub reflector:362] events watcher timeout
[D 2023-04-25 17:28:33.541 JupyterHub reflector:281] Connecting events watcher
[D 2023-04-25 17:28:33.859 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.94ms
[D 2023-04-25 17:28:33.859 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.92ms
[I 2023-04-25 17:28:34.983 JupyterHub spawner:2469] Attempting to create pod jupyter-user3, with timeout 3
[D 2023-04-25 17:28:35.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.65ms
[D 2023-04-25 17:28:37.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.61ms
[I 2023-04-25 17:28:38.181 JupyterHub spawner:2469] Attempting to create pod jupyter-user3, with timeout 3
[D 2023-04-25 17:28:39.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.72ms
[I 2023-04-25 17:28:41.730 JupyterHub spawner:2469] Attempting to create pod jupyter-user3, with timeout 3
[D 2023-04-25 17:28:41.859 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.69ms
[D 2023-04-25 17:28:42.913 JupyterHub reflector:362] pods watcher timeout
[D 2023-04-25 17:28:42.913 JupyterHub reflector:281] Connecting pods watcher
[D 2023-04-25 17:28:43.566 JupyterHub reflector:362] events watcher timeout
[D 2023-04-25 17:28:43.566 JupyterHub reflector:281] Connecting events watcher
[D 2023-04-25 17:28:43.859 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.92ms
[D 2023-04-25 17:28:43.859 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.81ms
[D 2023-04-25 17:28:45.859 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.66ms
[I 2023-04-25 17:28:46.027 JupyterHub spawner:2469] Attempting to create pod jupyter-user3, with timeout 3
[D 2023-04-25 17:28:47.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.70ms
[D 2023-04-25 17:28:49.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.63ms
[I 2023-04-25 17:28:51.422 JupyterHub spawner:2469] Attempting to create pod jupyter-user3, with timeout 3
[D 2023-04-25 17:28:51.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.67ms
[D 2023-04-25 17:28:52.922 JupyterHub reflector:362] pods watcher timeout
[D 2023-04-25 17:28:52.923 JupyterHub reflector:281] Connecting pods watcher
[D 2023-04-25 17:28:53.587 JupyterHub reflector:362] events watcher timeout
[D 2023-04-25 17:28:53.588 JupyterHub reflector:281] Connecting events watcher
[D 2023-04-25 17:28:53.859 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.94ms
[D 2023-04-25 17:28:53.859 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.89ms
[D 2023-04-25 17:28:55.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.69ms
[D 2023-04-25 17:28:57.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.63ms
[I 2023-04-25 17:28:57.899 JupyterHub spawner:2469] Attempting to create pod jupyter-user3, with timeout 3
[D 2023-04-25 17:28:59.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.63ms
[D 2023-04-25 17:29:01.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.67ms
[I 2023-04-25 17:29:02.208 JupyterHub spawner:2469] Attempting to create pod jupyter-user3, with timeout 3
[D 2023-04-25 17:29:02.934 JupyterHub reflector:362] pods watcher timeout
[D 2023-04-25 17:29:02.934 JupyterHub reflector:281] Connecting pods watcher
[D 2023-04-25 17:29:03.613 JupyterHub reflector:362] events watcher timeout
[D 2023-04-25 17:29:03.614 JupyterHub reflector:281] Connecting events watcher
[D 2023-04-25 17:29:03.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.81ms
[D 2023-04-25 17:29:03.858 JupyterHub log:186] 200 GET /hub/health (@100.64.24.192) 0.82ms
[W 2023-04-25 17:29:05.211 JupyterHub user:824] user3's server failed to start in 30000 seconds, giving up.
Common causes of this timeout, and debugging tips:
1. Everything is working, but it took too long.
To fix: increase `Spawner.start_timeout` configuration
to a number of seconds that is enough for spawners to finish starting.
2. The server didn't finish starting,
or it crashed due to a configuration issue.
Check the single-user server's logs for hints at what needs fixing.
[D 2023-04-25 17:29:05.211 JupyterHub user:930] Stopping user3
[D 2023-04-25 17:29:05.216 JupyterHub user:950] Deleting oauth client jupyterhub-user-user3
[D 2023-04-25 17:29:05.224 JupyterHub user:953] Finished stopping user3
[W 2023-04-25 17:29:05.233 JupyterHub base:1030] 3 consecutive spawns failed. Hub will exit if failure count reaches 5 before succeeding
[E 2023-04-25 17:29:05.233 JupyterHub gen:630] Exception in Future <Task finished name='Task-1601' coro=<BaseHandler.spawn_single_user.<locals>.finish_user_spawn() done, defined at /usr/local/lib/python3.9/site-packages/jupyterhub/handlers/base.py:954> exception=TimeoutError('Could not create pod dev-jupyterhub/jupyter-user3')> after timeout
Traceback (most recent call last):
File "/usr/local/lib/python3.9/site-packages/tornado/gen.py", line 625, in error_callback
future.result()
File "/usr/local/lib/python3.9/site-packages/jupyterhub/handlers/base.py", line 961, in finish_user_spawn
await spawn_future
File "/usr/local/lib/python3.9/site-packages/jupyterhub/user.py", line 850, in spawn
raise e
File "/usr/local/lib/python3.9/site-packages/jupyterhub/user.py", line 747, in spawn
url = await gen.with_timeout(timedelta(seconds=spawner.start_timeout), f)
File "/usr/local/lib/python3.9/site-packages/kubespawner/spawner.py", line 2663, in _start
await exponential_backoff(
File "/usr/local/lib/python3.9/site-packages/jupyterhub/utils.py", line 236, in exponential_backoff
raise asyncio.TimeoutError(fail_message)
asyncio.exceptions.TimeoutError: Could not create pod dev-jupyterhub/jupyter-user3
https://discourse.jupyter.org/t/jupyterhub-deployed-on-kubernetes-cannot-spawn-users/17511
[I 2023-04-25 17:29:05.234 JupyterHub log:186] 200 GET /hub/api/users/user3/server/progress (user3@100.64.31.165) 33307.70ms
[D 2023-04-25 17:29:05.325 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2023-04-25 17:29:05.327 JupyterHub proxy:395] Checking routes
[I 2023-04-25 17:29:05.495 JupyterHub log:186] 200 GET /hub/api/ (jupyterhub-idle-culler@127.0.0.1) 7.92ms
[D 2023-04-25 17:29:05.498 JupyterHub scopes:796] Checking access via scope list:users
Kubernetes Version: 1.23
Helm Chart Version: 2.0.0