Running into 404 error when redirected to /uses/<username>/tree at startup

[casparvl]

Bug description

Initially, I ran into https://github.com/jupyterhub/batchspawner/pull/247 . Since this was merged, and others have reported that PR solved their issue, I tried to run from main (https://github.com/jupyterhub/batchspawner/commit/2a9eda060a875a2b65ca9521368fe052a09c3266 to be exact), at least on the Jupyter Notebook Server side (I don't control the JupyterHub myself, so it's not so easy for me to make changes there).

It resolves the initial issue: my Jupyter Notebook Server starts now. However, where as soon as the spawner redirects me to the page that would normally show the Jupyter Notebook Server (with directory listing etc), I get a 404.

Logs from the JupyterHub:

[JupyterHub] Recording first activity for <APIToken('1fba...', user='casparl', client_id='jupyterhub')>
[JupyterHub] Refreshing auth for casparl
[JupyterHub] 200 POST /2022/hub/api/batchspawner (casparl@172.18.63.173) 6.71ms
[JupyterHub] Notebook server job 3019909 started at srv9:55289
[JupyterHub] Polling subprocess every 30s
[JupyterHub] 200 GET /2022/hub/api (@172.18.63.173) 0.45ms
[JupyterHub] Checking access via scope users:activity
[JupyterHub] Argument-based access to /2022/hub/api/users/casparl/activity via users:activity
[JupyterHub] Activity for user casparl: 2023-07-05T10:05:54.727817Z
[JupyterHub] Activity on server casparl/: 2023-07-05T10:05:54.727817Z
[JupyterHub] 200 POST /2022/hub/api/users/casparl/activity (casparl@172.18.63.173) 4.32ms
[JupyterHub] Server at http://srv9:55289/2022/user/casparl/ responded with 302
[JupyterHub] jupyterhub and jupyterhub-singleuser both on version 3.0.0
[JupyterHub] User casparl took 43.879 seconds to start
[JupyterHub] Adding user casparl to proxy /2022/user/casparl/ => http://srv9:55289
[JupyterHub] Proxy: Fetching POST http://127.0.0.1:8133/api/routes/2022/user/casparl
12:05:56.218 [ConfigProxy] ESC[32minfoESC[39m: Adding route /2022/user/casparl -> http://srv9:55289
12:05:56.218 [ConfigProxy] ESC[32minfoESC[39m: Route added /2022/user/casparl -> http://srv9:55289
12:05:56.218 [ConfigProxy] ESC[32minfoESC[39m: 201 POST /api/routes/2022/user/casparl
[JupyterHub] Server casparl is ready
[JupyterHub] 200 GET /2022/hub/api/users/casparl/server/progress (casparl@127.0.0.1) 43786.98ms
[JupyterHub] Checking access via scope servers
[JupyterHub] Unrestricted access to /2022/hub/spawn-pending/casparl via servers
[JupyterHub] 302 GET /2022/hub/spawn-pending/casparl -> /2022/user/casparl/ (casparl@127.0.0.1) 2.09ms

Logs from the Jupyter Notebook Server

[I 2023-07-05 12:05:54.691 SingleUserNotebookApp mixins:610] Starting jupyterhub single-user server version 3.0.0
[I 2023-07-05 12:05:54.691 SingleUserNotebookApp mixins:624] Extending jupyter_server.serverapp.ServerApp from jupyter_server 1.21.0
[I 2023-07-05 12:05:54.793 SingleUserNotebookApp mixins:671] Starting jupyterhub-singleuser server version 3.0.0
[I 2023-07-05 12:05:54.799 SingleUserNotebookApp serverapp:2726] Serving notebooks from local directory: /gpfs/home4/casparl
[I 2023-07-05 12:05:54.799 SingleUserNotebookApp serverapp:2726] Jupyter Server 1.21.0 is running at:
[I 2023-07-05 12:05:54.799 SingleUserNotebookApp serverapp:2726] http://srv9.local.snellius.surf.nl:55289/2022/user/casparl/tree/
[I 2023-07-05 12:05:54.799 SingleUserNotebookApp serverapp:2726]  or http://127.0.0.1:55289/2022/user/casparl/tree/
[I 2023-07-05 12:05:54.799 SingleUserNotebookApp serverapp:2727] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[I 2023-07-05 12:05:54.807 SingleUserNotebookApp mixins:592] Updating Hub with activity every 300 seconds
[I 2023-07-05 12:05:56.215 SingleUserNotebookApp log:186] 302 GET /2022/user/casparl/ -> /2022/user/casparl/tree/? (@172.18.63.202) 0.26ms
[I 2023-07-05 12:05:56.259 SingleUserNotebookApp log:186] 302 GET /2022/user/casparl/ -> /2022/user/casparl/tree/? (@127.0.0.1) 0.43ms
[I 2023-07-05 12:05:56.275 SingleUserNotebookApp log:186] 302 GET /2022/user/casparl/tree/ -> /2022/user/casparl/tree (@127.0.0.1) 0.42ms
[W 2023-07-05 12:05:56.311 SingleUserNotebookApp log:186] 404 GET /2022/user/casparl/tree (@127.0.0.1) 21.07ms

For comparison: an older JupyterHub (2.X I believe) setup gave me the following logs on the Jupyter Notebook Server side:

[I 2023-07-05 10:31:24.662 SingleUserNotebookApp notebookapp:1593] Authentication of /metrics is OFF, since other authentication is disabled.
[I 2023-07-05 10:31:26.202 SingleUserNotebookApp __init__:26] Loading lmod extension
[I 2023-07-05 10:31:26.206 SingleUserNotebookApp mixins:576] Starting jupyterhub-singleuser server version 1.4.1
[I 2023-07-05 10:31:26.210 SingleUserNotebookApp notebookapp:2302] Serving notebooks from local directory: /gpfs/home4/casparl
[I 2023-07-05 10:31:26.210 SingleUserNotebookApp notebookapp:2302] Jupyter Notebook 6.4.0 is running at:
[I 2023-07-05 10:31:26.210 SingleUserNotebookApp notebookapp:2302] http://srv10.local.snellius.surf.nl:53353/2021/user/casparl/
[I 2023-07-05 10:31:26.210 SingleUserNotebookApp notebookapp:2303] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[I 2023-07-05 10:31:26.213 SingleUserNotebookApp mixins:556] Updating Hub with activity every 300 seconds
[I 2023-07-05 10:31:27.246 SingleUserNotebookApp log:189] 302 GET /2021/user/casparl/ -> /2021/user/casparl/tree? (@172.18.63.202) 0.50ms
[I 2023-07-05 10:31:27.298 SingleUserNotebookApp log:189] 302 GET /2021/user/casparl/ -> /2021/user/casparl/tree? (@127.0.0.1) 0.74ms
[I 2023-07-05 10:31:27.315 SingleUserNotebookApp log:189] 302 GET /2021/user/casparl/tree -> /2021/hub/api/oauth2/authorize?client_id=jupyterhub-user-casparl&redirect_uri=%2F2021%2Fuser%2Fcasparl%2Foauth_callback&response_type=code&state=[secret] (@127.0.0.1) 1.47ms
[I 2023-07-05 10:31:27.401 SingleUserNotebookApp auth:992] Logged-in user {'kind': 'user', 'name': 'casparl', 'admin': True, 'groups': [], 'server': '/2021/user/casparl/', 'pending': None, 'created': '2023-04-19T15:29:34.851789Z', 'last_activity': '2023-07-05T08:31:27.398339Z', 'servers': None}
[I 2023-07-05 10:31:27.401 SingleUserNotebookApp log:189] 302 GET /2021/user/casparl/oauth_callback?code=[secret]&state=[secret] -> /2021/user/casparl/tree (@127.0.0.1) 42.49ms
[I 2023-07-05 10:31:27.498 SingleUserNotebookApp log:189] 200 GET /2021/user/casparl/tree (casparl@127.0.0.1) 82.91ms

The only notable difference I spot is that the redirect is slightly different (going to /2021/user/casparl/tree? instead of to /2021/user/casparl/tree/?), and the fact that I then get redirected to /2021/hub/api/oauth2/authorize?....

I've tried to debug this myself, but I'm at a loss: despite reading the documentation on spawners, I don't understand well enough what steps the spawner should be doing to figure out what could potentially go wrong. If anyone with more expertise on this has some ideas, I'd love to hear them :)

[welcome[bot]]

Thank you for opening your first issue in this project! Engagement like this is essential for open source projects! :hugs:
If you haven't done so already, check out Jupyter's Code of Conduct. Also, please try to follow the issue template as it helps other other community members to contribute more effectively. You can meet the other Jovyans by joining our Discourse forum. There is also an intro thread there where you can stop by and say Hi! :wave:
Welcome to the Jupyter community! :tada:

[mahendrapaipuri]

From your logs, it seems only Jupyter server has started and not notebook server. Maybe that is where that you need to look more?

Could you try to navigate to /2022/user/casparl/lab which should give you a JupyterLab interface? If you can share your JupyterHub config, that would help to find the problem.

[casparvl]

From your logs, it seems only Jupyter server has started and not notebook server. Maybe that is where that you need to look more?

That seems to just be a change in the logging for JupyterHub 3.X, but Jupyter server running essentially means the same thing.

I did experiment (a lot) more. I found out it had to be something in my virtual environment. Note that we have jupyter-server-proxy and jupyterlmod extensions enabled. If I ran from a virtual envrionment that had

source jh_2022_functional/bin/activate
pip install jupyterhub==3.0.0
cd batchspawner/
pip install .
cd ..
pip install jupyter-server-proxy==3.2.2
pip install jupyterlmod==3.0.0

I did not get my 404 error anymore. The batchspawner directory here contains a checkout for the current main branch, so that I get the specific commits for JupyterHub 3.X support.

However, if I did

source jh_2022_non_functional/bin/activate
pip install jupyterhub==3.0.0
cd batchspawner/
pip install .
cd ..
pip install jupyter-server-proxy
pip install jupyterlmod

It failed. Now, my original environment was neither of these two (we use a module environment, as we are on an HPC system). That has a module for jupyter-server-proxy 3.2.2, but the fact that it doesn't work in that environment tells me there is probably some dependency of jupyter-server-proxy that breaks things - and for which the version is different if I do pip install jupyter-server-proxy==3.2.2 compared to the one from the module environment.

Anyway, I'll close this issue here, as it seems to be unrelated to batchspawner. If I figure out more concretely what package/version was the culprit, I'll report back here in case people run into this in the future.

[mahendrapaipuri]

Fair enough! There are no differences in deps of jupyter-server-proxy between 3.2.2 and latest. However, for jupyterlmod the only difference in the dependency between 3.0.0 and latest is that 3.0.0 has notebook as explicit dependency. That opens a question are you sure that notebook is installed in jh_2022_non_functional? If you havent installed any other packages apart from the ones that you showed in the comment, it is due to missing notebook package in the environment.

[casparvl]

Just to report here in case others run into it: the 404 had nothing to do with batchspawner. This issue occurs if you have both jupyterhub and jupyter-server installed. In that case, jupyter-server is used by default to serve the notebook interface, but the classic notebook interface can only be served if the nbclassic package is also present (see here). Installing the nbclassic package resolved my issue.

It is a bit of a strange situation, as one might wonder why nbclassic is not a dependency of something. The problem is, it is only required if the combination of jupyter-server and jupyterhub are present. Which of those two would need to list it as a dependency? Neither, really...

What is really annoying is that there is no clearer error message for this situation (but again, not something that is up to batchspawner to solve ;-)). Anyway, mystery solved :)