Jupyterhub can not download large file(>100MB) with download button

JupyterHub
1

My JupyterHub Service is runnung on RHEL 8.6 and some informations about my JupyterHub is follows:

jupyter-client==7.1.2
jupyter-core==4.9.2
jupyter-server==1.13.1
jupyter-telemetry==0.1.0
jupyterhub==2.3.1
jupyterhub-ldapauthenticator==1.3.2
jupyterlab==2.2.8
jupyterlab-pygments==0.1.2
jupyterlab-server==1.2.0
jupyterlab-wedgets==1.1.1

In my case, I generate 2 files with linux dd command(one 100MB, the other 101MB).
situation 1 download 100 MB file: successfully downloaded and logs info
situation 2 download 101 MB file: It fails immediately after clicking the download button, and I got the logs (like the screenshot below)

image
image1501Ă—76 8.52 KB

How can I solve this problem?

2

Can you turn on debug logging for JupyterHub (--debug) and configurable-http-proxy (Proxies — JupyterHub 3.0.0 documentation), and show us the logs?

3

There are likely some things at various levels that would improve this.

jupyter_server has a bespoke implementation of chunked large file handling, but whiole both notebook and lab appear to implement it on the frontend for uploading, neither do so for downloading.

Presumably, a client-only implementation could be added to jupyterlab 3.4 (and by extension retrolab) as an extension, today, and then migrated to a jupyterlab 4 extension would work with the forthcoming notebook 7, as well.

However, the high road would be to support the HTTP standard Range and Accept-Range headers in the ContentsManager API handlers (and underlying API), which JupyterHub’s proxies (certainly traefik) would be able to handle transparently.

This is already implemented at the tornado level for StaticFileHandler, so it’s at least possible, but might require further changes to the ContentsManager that would be considered breaking.

The win here is that almost all clients, like most browsers, curl, and aria2c, would not only support this, but could potentially handle it in parallel, which would not only make the download finish, but might allow it to finish faster, provided the various chunked requests don’t stomp on each other.

As jupyter_server is currently v2.0.0rc4, it’s possible such a change by a motivated contributor could be landed before the final, but seems semi-unlikely at this point.

1 Like
4

Hi @manics
I turn on debug logging and got the logs

image
image1495Ă—64 11.5 KB

and I have a questions about how should I enable the debug mode of configurable-http-proxy

5

I linked to it above, set c.ConfigurableHTTPProxy.debug = False.

Would you mind sharing the logs for a successful and unsuccessful download? Please share the full context for the logs, not just the four lines, as there may be clues in the surrounding logs. Please could you include them as plain text instead of a screenshot? If you’re not familiar with Markdown Creating and highlighting code blocks - GitHub Docs has instructions for including a code block which you can use to include the logs.

6

Hi manics,
sorry, I took a while to deal with organization’s internal process issues,the log of download is as follows

==================== download 100 MB ====================

[D 2022-11-18 18:01:07,654 configurable_http_proxy] PROXY WEB /user/USER/files/home/USER/test_file_100 to http://127.0.0.1:56259
[D 2022-11-18 18:01:08,602 configurable_http_proxy] PROXY WEB /user/USER/api/terminals to http://127.0.0.1:56259
[I 2022-11-18 18:01:08.604 SingleUserLabApp log:189] 200 GET /user/USER/api/terminals?1668765668486 (USER@IP) 0.94ms
[D 2022-11-18 18:01:10,326 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER to http://127.0.0.1:56259
[I 2022-11-18 18:01:10.330 SingleUserLabApp log:189] 200 GET /user/USER/api/contents/home/USER?content=1&1668765670234 (USER@IP) 2.02ms
[D 2022-11-18 18:01:10,601 configurable_http_proxy] PROXY WEB /user/USER/api/sessions to http://127.0.0.1:56259
[D 2022-11-18 18:01:10,603 configurable_http_proxy] PROXY WEB /user/USER/api/kernels to http://127.0.0.1:56259
[I 2022-11-18 18:01:10.605 SingleUserLabApp log:189] 200 GET /user/USER/api/sessions?1668765670510 (USER@IP) 1.06ms
[I 2022-11-18 18:01:10.606 SingleUserLabApp log:189] 200 GET /user/USER/api/kernels?1668765670510 (USER@IP) 0.74ms
[D 2022-11-18 18:01:15,140 configurable_http_proxy] PROXY WEB /user/USER/metrics to http://127.0.0.1:56259
[I 2022-11-18 18:01:15.148 SingleUserLabApp log:189] 200 GET /user/USER/metrics?1668765675047 (USER@IP) 7.12ms

==================== download 101 MB ====================

[D 2022-11-18 18:01:16,337 configurable_http_proxy] PROXY WEB /user/USER/files/home/USER/test_file_101 to http://127.0.0.1:56259
[E 2022-11-18 18:01:16,340 configurable_http_proxy] 503 GET /user/USER/files/home/USER/test_file_101 Connection closed
[D 2022-11-18 18:01:16,340 configurable_http_proxy] Requesting custom error page: http://server-host:49007/hub/error/503?url=/user/USER/files/home/USER/test_file_101
[D 2022-11-18 18:01:16.342 JupyterHub pages:586] No template for 503
[I 2022-11-18 18:01:16.347 JupyterHub log:189] 200 GET /hub/error/503?url=/user/USER/files/home/USER/test_file_101 (@127.0.0.1) 5.32ms
[E 2022-11-18 18:01:16,347 tornado.access] 503 GET /user/USER/files/home/USER/test_file_101?_xsrf=2%7C50cacde2%7Ce0b1586dc793ff6b41f08ffa43027661%7C1667292494 (127.0.0.1) 10.13ms
[D 2022-11-18 18:01:16,347 configurable_http_proxy] Not recording activity for status 503 on /user/USER
[D 2022-11-18 18:01:18,663 configurable_http_proxy] PROXY WEB /user/USER/api/terminals to http://127.0.0.1:56259
[I 2022-11-18 18:01:18.665 SingleUserLabApp log:189] 200 GET /user/USER/api/terminals?1668765678570 (USER@IP) 0.86ms
7

Because of the word limit, add some startup logs here:

[I 2022-11-18 18:00:32.894 JupyterHub app:2802] Using Spawner: jupyterhub.spawner.LocalProcessSpawner-2.3.1
[I 2022-11-18 18:00:32.894 JupyterHub app:2802] Using Proxy: jupyterhub.proxy.ConfigurableHTTPProxy-2.3.1
[D 2022-11-18 18:00:32.895 JupyterHub app:2734] Could not load pycurl: No module named 'pycurl'
    pycurl is recommended if you have a large number of users.
[I 2022-11-18 18:00:32.896 JupyterHub app:1606] Loading cookie_secret from /root/jupyterhub_cookie_secret
[D 2022-11-18 18:00:32.896 JupyterHub app:1775] Connecting to db: sqlite:///jupyterhub.sqlite
[D 2022-11-18 18:00:32.911 JupyterHub orm:953] database schema version found: 833da8570507
[I 2022-11-18 18:00:32.949 JupyterHub proxy:496] Generating new CONFIGPROXY_AUTH_TOKEN
[D 2022-11-18 18:00:32.949 JupyterHub app:2024] Loading roles into database
[W 2022-11-18 18:00:32.958 JupyterHub configurable:168] Config option `debug` not recognized by `LDAPAuthenticator`.
[D 2022-11-18 18:00:32.966 JupyterHub app:2283] Purging expired APITokens
[D 2022-11-18 18:00:32.968 JupyterHub app:2283] Purging expired OAuthCodes
[D 2022-11-18 18:00:32.970 JupyterHub app:2116] Loading role assignments from config
[D 2022-11-18 18:00:32.970 JupyterHub app:2188] Assigning 4 allowed_users to the user role
[D 2022-11-18 18:00:32.985 JupyterHub app:2429] Initializing spawners
[D 2022-11-18 18:00:32.987 JupyterHub app:2560] Loaded users:

[I 2022-11-18 18:00:32.987 JupyterHub app:2843] Initialized 0 spawners in 0.002 seconds
[W 2022-11-18 18:00:32.989 JupyterHub proxy:688] Running JupyterHub without SSL.  I hope there is SSL termination happening somewhere else...
[I 2022-11-18 18:00:32.989 JupyterHub proxy:691] Starting proxy @ http://0.0.0.0:49008/
[D 2022-11-18 18:00:32.989 JupyterHub proxy:692] Proxy cmd: ['configurable-http-proxy', '--ip', '0.0.0.0', '--port', '49008', '--api-ip', '127.0.0.1', '--api-port', '8001', '--error-target', 'http://server-host:49007/hub/error', '--log-level', 'debug']
[D 2022-11-18 18:00:32.993 JupyterHub proxy:610] Writing proxy pid file: jupyterhub-proxy.pid
[I 2022-11-18 18:00:33,244 configurable_http_proxy] Proxying http://0.0.0.0:49008 to (no default)
[I 2022-11-18 18:00:33,244 configurable_http_proxy] Proxy API at http://127.0.0.1:8001/api/routes
[D 2022-11-18 18:00:33.470 JupyterHub proxy:728] Proxy started and appears to be up
[D 2022-11-18 18:00:33.474 JupyterHub proxy:821] Proxy: Fetching GET http://127.0.0.1:8001/api/routes
[I 2022-11-18 18:00:33,477 configurable_http_proxy] 200 GET /api/routes
[I 2022-11-18 18:00:33.478 JupyterHub app:3089] Hub API listening on http://0.0.0.0:49007/hub/
[I 2022-11-18 18:00:33.478 JupyterHub app:3091] Private Hub API connect url http://server-host:49007/hub/
[D 2022-11-18 18:00:33.478 JupyterHub proxy:343] Fetching routes to check
[D 2022-11-18 18:00:33.478 JupyterHub proxy:821] Proxy: Fetching GET http://127.0.0.1:8001/api/routes
[I 2022-11-18 18:00:33,480 configurable_http_proxy] 200 GET /api/routes
[D 2022-11-18 18:00:33.480 JupyterHub proxy:346] Checking routes
[I 2022-11-18 18:00:33.480 JupyterHub proxy:431] Adding route for Hub: / => http://server-host:49007
[D 2022-11-18 18:00:33.480 JupyterHub proxy:821] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/
[I 2022-11-18 18:00:33,482 configurable_http_proxy] Adding route / -> http://server-host:49007
[I 2022-11-18 18:00:33,482 configurable_http_proxy] Route added / -> http://server-host:49007
[I 2022-11-18 18:00:33,482 configurable_http_proxy] 201 POST /api/routes/
[I 2022-11-18 18:00:33.482 JupyterHub app:3156] JupyterHub is now running at http://0.0.0.0:49008/
[D 2022-11-18 18:00:33.483 JupyterHub app:2764] It took 0.679 seconds for the Hub to start
[D 2022-11-18 18:00:44,369 configurable_http_proxy] PROXY WEB /user/USER/lab to http://server-host:49007
[I 2022-11-18 18:00:44.373 JupyterHub log:189] 302 GET /user/USER/lab?redirects=3 -> /hub/user/USER/lab?redirects=3 (@IP) 1.29ms
[D 2022-11-18 18:00:44,373 configurable_http_proxy] Not recording activity for status 302 on /
[D 2022-11-18 18:00:44,377 configurable_http_proxy] PROXY WEB /hub/user/USER/lab to http://server-host:49007
[D 2022-11-18 18:00:44.386 JupyterHub base:326] Refreshing auth for USER
[D 2022-11-18 18:00:44.388 JupyterHub scopes:491] Checking access via scope access:servers
[D 2022-11-18 18:00:44.389 JupyterHub scopes:389] Unrestricted access to /hub/user/USER/lab via access:servers
[D 2022-11-18 18:00:44.389 JupyterHub user:399] Creating <class 'jupyterhub.spawner.LocalProcessSpawner'> for USER:
[W 2022-11-18 18:00:44.415 JupyterHub log:189] 424 GET /hub/user/USER/lab?redirects=3 (USER@IP) 36.63ms
[W 2022-11-18 18:00:44,415 tornado.access] 424 GET /hub/user/USER/lab?redirects=3 (127.0.0.1) 38.62ms
[D 2022-11-18 18:00:44,415 configurable_http_proxy] Not recording activity for status 424 on /
[D 2022-11-18 18:00:44,467 configurable_http_proxy] PROXY WEB /hub/static/js/not_running.js to http://server-host:49007
[D 2022-11-18 18:00:44.470 JupyterHub log:189] 200 GET /hub/static/js/not_running.js?v=20221118180032 (@IP) 1.11ms
[D 2022-11-18 18:00:44,479 configurable_http_proxy] PROXY WEB /hub/static/js/utils.js to http://server-host:49007
[D 2022-11-18 18:00:44.481 JupyterHub log:189] 200 GET /hub/static/js/utils.js?v=20221118180032 (@IP) 0.69ms
[D 2022-11-18 18:00:46,092 configurable_http_proxy] PROXY WEB /hub/spawn/USER to http://server-host:49007
[D 2022-11-18 18:00:46.096 JupyterHub scopes:491] Checking access via scope servers
[D 2022-11-18 18:00:46.096 JupyterHub scopes:389] Unrestricted access to /hub/spawn/USER via servers
[D 2022-11-18 18:00:46.096 JupyterHub pages:216] Triggering spawn with default options for USER
[D 2022-11-18 18:00:46.096 JupyterHub base:934] Initiating spawn for USER
[D 2022-11-18 18:00:46.097 JupyterHub base:941] 0/100 concurrent spawns
[D 2022-11-18 18:00:46.097 JupyterHub base:946] 0 active servers
[D 2022-11-18 18:00:46.102 JupyterHub roles:478] Checking token permissions against requested role server
[I 2022-11-18 18:00:46.104 JupyterHub roles:482] Adding role server to token: <APIToken('ce55...', user='USER', client_id='jupyterhub')>
[I 2022-11-18 18:00:46.112 JupyterHub provider:607] Creating oauth client jupyterhub-user-USER
[D 2022-11-18 18:00:46.124 JupyterHub user:728] Calling Spawner.start for USER
[I 2022-11-18 18:00:46.126 JupyterHub spawner:1563] Spawning jupyter-labhub --allow-root
[D 2022-11-18 18:00:46.139 JupyterHub spawner:1258] Polling subprocess every 30s
[I 2022-11-18 18:00:47.098 JupyterHub log:189] 302 GET /hub/spawn/USER?next=%2Fhub%2Fuser%2FUSER%2Flab%3Fredirects%3D3 -> /hub/spawn-pending/USER?next=%2Fhub%2Fuser%2FUSER%2Flab%3Fredirects%3D3 (USER@IP) 1004.11ms
[D 2022-11-18 18:00:47,098 configurable_http_proxy] Not recording activity for status 302 on /
[D 2022-11-18 18:00:47,103 configurable_http_proxy] PROXY WEB /hub/spawn-pending/USER to http://server-host:49007
[D 2022-11-18 18:00:47.108 JupyterHub scopes:491] Checking access via scope servers
[D 2022-11-18 18:00:47.108 JupyterHub scopes:389] Unrestricted access to /hub/spawn-pending/USER via servers
[I 2022-11-18 18:00:47.108 JupyterHub pages:401] USER is pending spawn
[I 2022-11-18 18:00:47.112 JupyterHub log:189] 200 GET /hub/spawn-pending/USER?next=%2Fhub%2Fuser%2FUSER%2Flab%3Fredirects%3D3 (USER@IP) 7.29ms
Patching auth into jupyter_server.base.handlers.JupyterHandler(jupyter_server.base.handlers.AuthenticatedHandler) -> JupyterHandler(jupyterhub.singleuser.mixins.HubAuthenticatedHandler, jupyter_server.base.handlers.AuthenticatedHandler)
Patching auth into notebook.base.handlers.IPythonHandler(notebook.base.handlers.AuthenticatedHandler) -> IPythonHandler(jupyterhub.singleuser.mixins.HubAuthenticatedHandler, notebook.base.handlers.AuthenticatedHandler)
[I 2022-11-18 18:00:47.147 SingleUserLabApp mixins:615] Starting jupyterhub single-user server version 2.3.1
[I 2022-11-18 18:00:47.147 SingleUserLabApp mixins:630] Extending jupyterlab.labhubapp.SingleUserLabApp from jupyterlab 2.2.8
[I 2022-11-18 18:00:47.147 SingleUserLabApp mixins:630] Extending notebook.notebookapp.NotebookApp from notebook 6.2.0
[D 2022-11-18 18:00:47,155 configurable_http_proxy] PROXY WEB /hub/api/users/USER/server/progress to http://server-host:49007
[D 2022-11-18 18:00:47.159 JupyterHub scopes:491] Checking access via scope read:servers
[D 2022-11-18 18:00:47.159 JupyterHub scopes:389] Unrestricted access to /hub/api/users/USER/server/progress via read:servers
[I 2022-11-18 18:00:47.689 SingleUserLabApp extension:162] JupyterLab extension loaded from /usr/local/lib/python3.6/site-packages/jupyterlab
[I 2022-11-18 18:00:47.689 SingleUserLabApp extension:163] JupyterLab application directory is /usr/local/share/jupyter/lab
[I 2022-11-18 18:00:47.692 SingleUserLabApp mixins:648] Starting jupyterhub-singleuser server version 2.3.1
[I 2022-11-18 18:00:47.698 SingleUserLabApp notebookapp:2257] Serving notebooks from local directory: /
[I 2022-11-18 18:00:47.698 SingleUserLabApp notebookapp:2257] Jupyter Notebook 6.2.0 is running at:
[I 2022-11-18 18:00:47.698 SingleUserLabApp notebookapp:2257] http://127.0.0.1:56259/user/USER/
[I 2022-11-18 18:00:47.698 SingleUserLabApp notebookapp:2258] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[I 2022-11-18 18:00:47.702 SingleUserLabApp mixins:598] Updating Hub with activity every 300 seconds
[D 2022-11-18 18:00:47.706 JupyterHub base:281] Recording first activity for <APIToken('ce55...', user='USER', client_id='jupyterhub')>
[D 2022-11-18 18:00:47.710 JupyterHub scopes:301] Authenticated with token <APIToken('ce55...', user='USER', client_id='jupyterhub')>
[D 2022-11-18 18:00:47.712 JupyterHub scopes:491] Checking access via scope users:activity
[D 2022-11-18 18:00:47.712 JupyterHub scopes:402] Argument-based access to /hub/api/users/USER/activity via users:activity
[D 2022-11-18 18:00:47.714 JupyterHub users:860] Activity for user USER: 2022-11-18T18:00:47.161476Z
[D 2022-11-18 18:00:47.714 JupyterHub users:881] Activity on server USER/: 2022-11-18T18:00:47.161476Z
[I 2022-11-18 18:00:47.717 JupyterHub log:189] 200 POST /hub/api/users/USER/activity (USER@127.0.0.1) 12.75ms
[I 2022-11-18 18:00:49.932 SingleUserLabApp log:189] 302 GET /user/USER/ -> /user/USER/lab? (@127.0.0.1) 0.89ms
[D 2022-11-18 18:00:49.932 JupyterHub utils:230] Server at http://127.0.0.1:56259/user/USER/ responded with 302
[D 2022-11-18 18:00:49.933 JupyterHub _version:75] jupyterhub and jupyterhub-singleuser both on version 2.3.1
[I 2022-11-18 18:00:49.933 JupyterHub base:964] User USER took 3.836 seconds to start
[I 2022-11-18 18:00:49.933 JupyterHub proxy:290] Adding user USER to proxy /user/USER/ => http://127.0.0.1:56259
[D 2022-11-18 18:00:49.933 JupyterHub proxy:821] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/user/USER
[I 2022-11-18 18:00:49,935 configurable_http_proxy] Adding route /user/USER -> http://127.0.0.1:56259
[I 2022-11-18 18:00:49,935 configurable_http_proxy] Route added /user/USER -> http://127.0.0.1:56259
[I 2022-11-18 18:00:49,935 configurable_http_proxy] 201 POST /api/routes/user/USER
[I 2022-11-18 18:00:49.936 JupyterHub users:753] Server USER is ready
[I 2022-11-18 18:00:49.936 JupyterHub log:189] 200 GET /hub/api/users/USER/server/progress (USER@IP) 2779.50ms
[D 2022-11-18 18:00:49,949 configurable_http_proxy] PROXY WEB /hub/spawn-pending/USER to http://server-host:49007
[D 2022-11-18 18:00:49.953 JupyterHub scopes:491] Checking access via scope servers
[D 2022-11-18 18:00:49.953 JupyterHub scopes:389] Unrestricted access to /hub/spawn-pending/USER via servers
[I 2022-11-18 18:00:49.954 JupyterHub log:189] 302 GET /hub/spawn-pending/USER?next=%2Fhub%2Fuser%2FUSER%2Flab%3Fredirects%3D3 -> /hub/user/USER/lab?redirects=3 (USER@IP) 3.01ms
[D 2022-11-18 18:00:49,954 configurable_http_proxy] Not recording activity for status 302 on /
[D 2022-11-18 18:00:49,958 configurable_http_proxy] PROXY WEB /hub/user/USER/lab to http://server-host:49007
[D 2022-11-18 18:00:49.960 JupyterHub scopes:491] Checking access via scope access:servers
[D 2022-11-18 18:00:49.960 JupyterHub scopes:389] Unrestricted access to /hub/user/USER/lab via access:servers
[W 2022-11-18 18:00:49.961 JupyterHub base:1615] Redirect loop detected on /hub/user/USER/lab?redirects=3
[I 2022-11-18 18:00:57.967 JupyterHub log:189] 302 GET /hub/user/USER/lab?redirects=3 -> /user/USER/lab?redirects=4 (USER@IP) 8008.24ms
[D 2022-11-18 18:00:57,968 configurable_http_proxy] Not recording activity for status 302 on /
[D 2022-11-18 18:00:57,972 configurable_http_proxy] PROXY WEB /user/USER/lab to http://127.0.0.1:56259
[I 2022-11-18 18:00:57.976 SingleUserLabApp log:189] 302 GET /user/USER/lab?redirects=4 -> /hub/api/oauth2/authorize?client_id=jupyterhub-user-USER&redirect_uri=%2Fuser%2FUSER%2Foauth_callback&response_type=code&state=[secret] (@IP) 2.36ms
[D 2022-11-18 18:00:57,976 configurable_http_proxy] Not recording activity for status 302 on /user/USER
[D 2022-11-18 18:00:57,981 configurable_http_proxy] PROXY WEB /hub/api/oauth2/authorize to http://server-host:49007
[D 2022-11-18 18:00:57.984 JupyterHub provider:411] Validating client id jupyterhub-user-USER
[D 2022-11-18 18:00:57.986 oauthlib.oauth2.rfc6749.grant_types.authorization_code authorization_code:364] Validating redirection uri /user/USER/oauth_callback for client jupyterhub-user-USER.
[D 2022-11-18 18:00:57.986 oauthlib.oauth2.rfc6749.grant_types.base base:230] Using provided redirect_uri /user/USER/oauth_callback
[D 2022-11-18 18:00:57.986 JupyterHub provider:489] validate_redirect_uri: client_id=jupyterhub-user-USER, redirect_uri=/user/USER/oauth_callback
[D 2022-11-18 18:00:57.987 oauthlib.oauth2.rfc6749.grant_types.base base:172] Validating access to scopes [] for client 'jupyterhub-user-USER' (<OAuthClient(identifier='jupyterhub-user-USER')>).
[D 2022-11-18 18:00:57.988 JupyterHub provider:571] Allowing request for role(s) for jupyterhub-user-USER:  []
[D 2022-11-18 18:00:57.989 JupyterHub auth:290] Skipping oauth confirmation for <User(USER 1/1 running)> accessing Server at /user/USER/
[D 2022-11-18 18:00:57.989 oauthlib.oauth2.rfc6749.endpoints.authorization authorization:99] Dispatching response_type code request to <oauthlib.oauth2.rfc6749.grant_types.authorization_code.AuthorizationCodeGrant object at 0x7fc348ba49b0>.
[D 2022-11-18 18:00:57.989 JupyterHub provider:411] Validating client id jupyterhub-user-USER
[D 2022-11-18 18:00:57.990 oauthlib.oauth2.rfc6749.grant_types.authorization_code authorization_code:364] Validating redirection uri /user/USER/oauth_callback for client jupyterhub-user-USER.
[D 2022-11-18 18:00:57.990 oauthlib.oauth2.rfc6749.grant_types.base base:230] Using provided redirect_uri /user/USER/oauth_callback
[D 2022-11-18 18:00:57.990 JupyterHub provider:489] validate_redirect_uri: client_id=jupyterhub-user-USER, redirect_uri=/user/USER/oauth_callback
[D 2022-11-18 18:00:57.991 oauthlib.oauth2.rfc6749.grant_types.base base:172] Validating access to scopes [] for client 'jupyterhub-user-USER' (<OAuthClient(identifier='jupyterhub-user-USER')>).
[D 2022-11-18 18:00:57.992 JupyterHub provider:571] Allowing request for role(s) for jupyterhub-user-USER:  []
[D 2022-11-18 18:00:57.992 oauthlib.oauth2.rfc6749.grant_types.authorization_code authorization_code:247] Pre resource owner authorization validation ok for <oauthlib.Request SANITIZED>.
[D 2022-11-18 18:00:57.993 oauthlib.oauth2.rfc6749.grant_types.authorization_code authorization_code:172] Created authorization code grant {'code': 'rPXTjRr2syzzNZYkQocZthrX9RxLFQ', 'state': 'eyJ1dWlkIjogIjI5NTNhZjQ4Y2JlODRiNzA4YmNiYTJkNTlkMTQ3MzU1IiwgIm5leHRfdXJsIjogIi91c2VyL2VzYjE0MjQzL2xhYj9yZWRpcmVjdHM9NCJ9'} for request <oauthlib.Request SANITIZED>.
[D 2022-11-18 18:00:57.993 oauthlib.oauth2.rfc6749.grant_types.authorization_code authorization_code:278] Saving grant {'code': 'rPXTjRr2syzzNZYkQocZthrX9RxLFQ', 'state': 'eyJ1dWlkIjogIjI5NTNhZjQ4Y2JlODRiNzA4YmNiYTJkNTlkMTQ3MzU1IiwgIm5leHRfdXJsIjogIi91c2VyL2VzYjE0MjQzL2xhYj9yZWRpcmVjdHM9NCJ9'} for <oauthlib.Request SANITIZED>.
[D 2022-11-18 18:00:57.993 JupyterHub provider:242] Saving authorization code jupyterhub-user-USER, rPX..., (), {}
[I 2022-11-18 18:00:57.999 JupyterHub log:189] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-USER&redirect_uri=%2Fuser%2FUSER%2Foauth_callback&response_type=code&state=[secret] -> /user/USER/oauth_callback?code=[secret]&state=[secret] (USER@IP) 16.41ms
[D 2022-11-18 18:00:57,999 configurable_http_proxy] Not recording activity for status 302 on /
[D 2022-11-18 18:00:58,003 configurable_http_proxy] PROXY WEB /user/USER/oauth_callback to http://127.0.0.1:56259
[D 2022-11-18 18:00:58.010 JupyterHub scopes:301] Authenticated with token <APIToken('ce55...', user='USER', client_id='jupyterhub')>
[D 2022-11-18 18:00:58.011 oauthlib.oauth2.rfc6749.endpoints.token token:113] Dispatching grant_type authorization_code request to <oauthlib.oauth2.rfc6749.grant_types.authorization_code.AuthorizationCodeGrant object at 0x7fc348ba49b0>.
[D 2022-11-18 18:00:58.011 JupyterHub provider:53] authenticate_client <oauthlib.Request SANITIZED>
[D 2022-11-18 18:00:58.017 oauthlib.oauth2.rfc6749.grant_types.authorization_code authorization_code:534] Using provided redirect_uri /user/USER/oauth_callback
[D 2022-11-18 18:00:58.017 JupyterHub provider:115] confirm_redirect_uri: client_id=jupyterhub-user-USER, redirect_uri=/user/USER/oauth_callback
[D 2022-11-18 18:00:58.017 oauthlib.oauth2.rfc6749.grant_types.authorization_code authorization_code:302] Token request validation ok for <oauthlib.Request SANITIZED>.
[D 2022-11-18 18:00:58.017 JupyterHub provider:335] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 1209600, 'token_type': 'Bearer', 'scope': '', 'refresh_token': 'REDACTED'}
[D 2022-11-18 18:00:58.022 JupyterHub provider:195] Deleting oauth code rPX... for jupyterhub-user-USER
[I 2022-11-18 18:00:58.028 JupyterHub log:189] 200 POST /hub/api/oauth2/token (USER@127.0.0.1) 19.78ms
[D 2022-11-18 18:00:58.031 JupyterHub base:281] Recording first activity for <APIToken('n9v7...', user='USER', client_id='jupyterhub-user-USER')>
[D 2022-11-18 18:00:58.033 JupyterHub scopes:301] Authenticated with token <APIToken('n9v7...', user='USER', client_id='jupyterhub-user-USER')>
[I 2022-11-18 18:00:58.036 JupyterHub log:189] 200 GET /hub/api/user (USER@127.0.0.1) 6.04ms
[I 2022-11-18 18:00:58.036 SingleUserLabApp auth:1132] Logged-in user {'kind': 'user', 'groups': [], 'name': 'USER', 'admin': True, 'session_id': '08a6908c5a8a461c815a177dbc38bb16', 'scopes': ['access:servers!server=USER/']}
[I 2022-11-18 18:00:58.037 SingleUserLabApp log:189] 302 GET /user/USER/oauth_callback?code=[secret]&state=[secret] -> /user/USER/lab?redirects=4 (@IP) 33.02ms
[D 2022-11-18 18:00:58,038 configurable_http_proxy] Not recording activity for status 302 on /user/USER
[D 2022-11-18 18:00:58,042 configurable_http_proxy] PROXY WEB /user/USER/lab to http://127.0.0.1:56259
[I 2022-11-18 18:00:58.049 SingleUserLabApp log:189] 200 GET /user/USER/lab?redirects=4 (USER@IP) 6.40ms
[D 2022-11-18 18:00:58,060 configurable_http_proxy] PROXY WEB /user/USER/static/lab/main.96d5afda0af51b39975b.js to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,061 configurable_http_proxy] PROXY WEB /user/USER/static/lab/vendors~main.4d038cf945edd868eb6a.js to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,064 configurable_http_proxy] Not recording activity for status 304 on /user/USER
[D 2022-11-18 18:00:58,077 configurable_http_proxy] Not recording activity for status 304 on /user/USER
[D 2022-11-18 18:00:58,409 configurable_http_proxy] PROXY WEB /user/USER/api/kernelspecs to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,413 configurable_http_proxy] PROXY WEB /user/USER/lab/api/settings/ to http://127.0.0.1:56259
[D 2022-11-18 18:00:58.414 JupyterHub scopes:301] Authenticated with token <APIToken('ce55...', user='USER', client_id='jupyterhub')>
[I 2022-11-18 18:00:58.415 JupyterHub log:189] 200 GET /hub/api/user (USER@127.0.0.1) 2.38ms
[D 2022-11-18 18:00:58,432 configurable_http_proxy] PROXY WEB /user/USER/api/kernels to http://127.0.0.1:56259
[I 2022-11-18 18:00:58.432 SingleUserLabApp log:189] 200 GET /user/USER/api/kernelspecs?1668765658317 (USER@IP) 20.91ms
[D 2022-11-18 18:00:58,434 configurable_http_proxy] PROXY WEB /user/USER/api/sessions to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,434 configurable_http_proxy] PROXY WEB /user/USER/api/terminals to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,436 configurable_http_proxy] PROXY WEB /user/USER/static/base/images/favicon.ico to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,451 configurable_http_proxy] PROXY WEB /user/USER/api/kernelspecs to http://127.0.0.1:56259
[I 2022-11-18 18:00:58.467 SingleUserLabApp log:189] 200 GET /user/USER/lab/api/settings/?1668765658322 (USER@IP) 34.14ms
[I 2022-11-18 18:00:58.471 SingleUserLabApp log:189] 200 GET /user/USER/api/kernels?1668765658341 (USER@IP) 3.09ms
[I 2022-11-18 18:00:58.472 SingleUserLabApp log:189] 200 GET /user/USER/api/sessions?1668765658341 (USER@IP) 3.57ms
[I 2022-11-18 18:00:58.472 SingleUserLabApp log:189] 200 GET /user/USER/api/terminals?1668765658342 (USER@IP) 3.52ms
[D 2022-11-18 18:00:58,473 configurable_http_proxy] Not recording activity for status 304 on /user/USER
[I 2022-11-18 18:00:58.474 SingleUserLabApp log:189] 200 GET /user/USER/api/kernelspecs?1668765658360 (USER@IP) 4.13ms
[D 2022-11-18 18:00:58,569 configurable_http_proxy] PROXY WEB /user/USER/metrics to http://127.0.0.1:56259
[I 2022-11-18 18:00:58.576 SingleUserLabApp log:189] 200 GET /user/USER/metrics?1668765658477 (USER@IP) 5.48ms
[D 2022-11-18 18:00:58,777 configurable_http_proxy] PROXY WEB /user/USER/lab/api/themes/@jupyterlab/theme-dark-extension/index.css to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,780 configurable_http_proxy] Not recording activity for status 304 on /user/USER
[D 2022-11-18 18:00:58,782 configurable_http_proxy] PROXY WEB /user/USER/lab/api/settings/@jupyterlab/docmanager-extension:plugin to http://127.0.0.1:56259
[I 2022-11-18 18:00:58.785 SingleUserLabApp log:189] 200 GET /user/USER/lab/api/settings/%40jupyterlab/docmanager-extension%3Aplugin?1668765658690 (USER@IP) 1.87ms
[D 2022-11-18 18:00:58,849 configurable_http_proxy] PROXY WEB /user/USER/lab/api/build to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,857 configurable_http_proxy] PROXY WEB /user/USER/lab/api/listings/@jupyterlab/extensionmanager-extension/listings.json to http://127.0.0.1:56259
[I 2022-11-18 18:00:58.861 SingleUserLabApp log:189] 200 GET /user/USER/lab/api/listings/%40jupyterlab/extensionmanager-extension/listings.json?1668765658766 (USER@IP) 1.80ms
[D 2022-11-18 18:00:58,864 configurable_http_proxy] PROXY WEB /user/USER/api/nbconvert to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,884 configurable_http_proxy] PROXY WEB /user/USER/api/nbconvert to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,904 configurable_http_proxy] PROXY WEB /user/USER/lab/api/workspaces/lab to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,942 configurable_http_proxy] PROXY WEB /user/USER/lab/api/settings/@jupyterlab/docmanager-extension:plugin to http://127.0.0.1:56259
[D 2022-11-18 18:00:58,996 configurable_http_proxy] PROXY WEB /user/USER/lab/api/extensions to http://127.0.0.1:56259
[I 2022-11-18 18:00:59.139 SingleUserLabApp log:189] 200 GET /user/USER/api/nbconvert?1668765658772 (USER@IP) 274.28ms
[I 2022-11-18 18:00:59.371 SingleUserLabApp log:189] 200 GET /user/USER/api/nbconvert?1668765658793 (USER@IP) 229.77ms
[I 2022-11-18 18:00:59.372 SingleUserLabApp log:189] 200 GET /user/USER/lab/api/workspaces/lab?1668765658813 (USER@IP) 229.50ms
[I 2022-11-18 18:00:59.374 SingleUserLabApp log:189] 200 GET /user/USER/lab/api/settings/%40jupyterlab/docmanager-extension%3Aplugin?1668765658851 (USER@IP) 230.90ms
[D 2022-11-18 18:00:59,381 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/Untitled.ipynb to http://127.0.0.1:56259
[D 2022-11-18 18:00:59,383 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/requirements.txt to http://127.0.0.1:56259
[I 2022-11-18 18:00:59.682 SingleUserLabApp log:189] 200 GET /user/USER/lab/api/extensions?1668765658900 (USER@IP) 538.05ms
[I 2022-11-18 18:00:59.683 SingleUserLabApp build_handler:47] Build is up to date
[I 2022-11-18 18:00:59.686 SingleUserLabApp log:189] 200 GET /user/USER/lab/api/build?1668765658757 (USER@IP) 835.54ms
/usr/lib64/python3.6/json/encoder.py:257: UserWarning: date_default is deprecated since jupyter_client 7.0.0. Use jupyter_client.jsonutil.json_default.
  return _iterencode(o, 0)
[I 2022-11-18 18:00:59.687 SingleUserLabApp log:189] 200 GET /user/USER/api/contents/home/USER/Untitled.ipynb?content=0&1668765659290 (USER@IP) 3.22ms
[I 2022-11-18 18:00:59.688 SingleUserLabApp log:189] 200 GET /user/USER/api/contents/home/USER/requirements.txt?content=0&1668765659291 (USER@IP) 2.73ms
[D 2022-11-18 18:00:59,758 configurable_http_proxy] PROXY WEB /user/USER/lab/api/settings/ to http://127.0.0.1:56259
[D 2022-11-18 18:00:59,761 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/Untitled.ipynb to http://127.0.0.1:56259
[D 2022-11-18 18:00:59,762 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/requirements.txt to http://127.0.0.1:56259
[I 2022-11-18 18:00:59.791 SingleUserLabApp log:189] 200 GET /user/USER/lab/api/settings/?1668765659667 (USER@IP) 31.06ms
[I 2022-11-18 18:00:59.817 SingleUserLabApp log:189] 200 GET /user/USER/api/contents/home/USER/Untitled.ipynb?type=notebook&content=1&1668765659670 (USER@IP) 25.63ms
[I 2022-11-18 18:00:59.818 SingleUserLabApp log:189] 200 GET /user/USER/api/contents/home/USER/requirements.txt?format=text&type=file&content=1&1668765659671 (USER@IP) 25.81ms
[D 2022-11-18 18:00:59,889 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/Untitled.ipynb/checkpoints to http://127.0.0.1:56259
[D 2022-11-18 18:00:59,891 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/Untitled.ipynb/checkpoints to http://127.0.0.1:56259
[I 2022-11-18 18:00:59.894 SingleUserLabApp log:189] 200 GET /user/USER/api/contents/home/USER/Untitled.ipynb/checkpoints?1668765659797 (USER@IP) 1.69ms
[I 2022-11-18 18:00:59.895 SingleUserLabApp log:189] 200 GET /user/USER/api/contents/home/USER/Untitled.ipynb/checkpoints?1668765659798 (USER@IP) 0.88ms
[D 2022-11-18 18:00:59,915 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/Untitled.ipynb/checkpoints to http://127.0.0.1:56259
[D 2022-11-18 18:00:59,917 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/requirements.txt/checkpoints to http://127.0.0.1:56259
[I 2022-11-18 18:00:59.917 SingleUserLabApp log:189] 200 GET /user/USER/api/contents/home/USER/Untitled.ipynb/checkpoints?1668765659824 (USER@IP) 0.80ms
[D 2022-11-18 18:00:59,919 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/requirements.txt/checkpoints to http://127.0.0.1:56259
[D 2022-11-18 18:00:59,920 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER/requirements.txt/checkpoints to http://127.0.0.1:56259
[D 2022-11-18 18:00:59,969 configurable_http_proxy] PROXY WEB /user/USER/api/sessions to http://127.0.0.1:56259
[I 2022-11-18 18:00:59.971 SingleUserLabApp log:189] 200 GET /user/USER/api/sessions?1668765659877 (USER@IP) 0.76ms
[D 2022-11-18 18:00:59,976 configurable_http_proxy] PROXY WEB /user/USER/api/sessions to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,000 configurable_http_proxy] PROXY WEB /user/USER/lab/api/extensions to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.005 SingleUserLabApp log:189] 200 GET /user/USER/lab/api/extensions?1668765659908 (USER@IP) 3.30ms
[I 2022-11-18 18:01:00.007 SingleUserLabApp kernelmanager:179] Kernel started: 159cb1e5-2c05-41df-b73d-0334b5b93fb9, name: python3
[I 2022-11-18 18:01:00.009 SingleUserLabApp log:189] 201 POST /user/USER/api/sessions?1668765659885 (USER@IP) 31.55ms
[D 2022-11-18 18:01:00,014 configurable_http_proxy] PROXY WEB /user/USER/api/sessions to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.016 SingleUserLabApp log:189] 200 GET /user/USER/api/sessions?1668765659923 (USER@IP) 1.09ms
[D 2022-11-18 18:01:00,024 configurable_http_proxy] PROXY WEB /user/USER/api/sessions/8a970ebf-f71e-409f-93d7-786d24ba8731 to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,026 configurable_http_proxy] PROXY WEB /user/USER/api/kernels/159cb1e5-2c05-41df-b73d-0334b5b93fb9/channels to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,026 configurable_http_proxy] PROXY WEB /user/USER/api/kernels/159cb1e5-2c05-41df-b73d-0334b5b93fb9/channels to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.029 SingleUserLabApp log:189] 200 PATCH /user/USER/api/sessions/8a970ebf-f71e-409f-93d7-786d24ba8731?1668765659933 (USER@IP) 1.49ms
[D 2022-11-18 18:01:00,032 configurable_http_proxy] PROXY WEB /user/USER/api/kernels to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.034 SingleUserLabApp log:189] 200 GET /user/USER/api/kernels?1668765659941 (USER@IP) 0.88ms
[D 2022-11-18 18:01:00,041 configurable_http_proxy] PROXY WEB /user/USER/api/sessions/8a970ebf-f71e-409f-93d7-786d24ba8731 to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.044 SingleUserLabApp log:189] 200 PATCH /user/USER/api/sessions/8a970ebf-f71e-409f-93d7-786d24ba8731?1668765659950 (USER@IP) 1.32ms
[D 2022-11-18 18:01:00,045 configurable_http_proxy] PROXY WEB /user/USER/api/sessions to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.047 SingleUserLabApp log:189] 200 GET /user/USER/api/sessions?1668765659954 (USER@IP) 0.87ms
[D 2022-11-18 18:01:00,048 configurable_http_proxy] PROXY WEB /user/USER/api/kernelspecs to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.050 SingleUserLabApp log:189] 200 GET /user/USER/api/kernelspecs?1668765659957 (USER@IP) 1.38ms
[D 2022-11-18 18:01:00,277 configurable_http_proxy] PROXY WEB /user/USER/lab/api/workspaces/lab to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.280 SingleUserLabApp log:189] 204 PUT /user/USER/lab/api/workspaces/lab?1668765660186 (USER@IP) 1.35ms
[D 2022-11-18 18:01:00,285 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,294 configurable_http_proxy] PROXY WEB /user/USER/api/contents/home/USER to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.518 SingleUserLabApp log:189] 101 GET /user/USER/api/kernels/159cb1e5-2c05-41df-b73d-0334b5b93fb9/channels?session_id=d17ec096-9ee2-4ccd-ab16-7133460410f2 (USER@IP) 488.54ms
[D 2022-11-18 18:01:00,538 configurable_http_proxy] PROXY WEB /user/USER/api/kernels/159cb1e5-2c05-41df-b73d-0334b5b93fb9/channels to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,538 configurable_http_proxy] PROXY WEB /user/USER/api/kernels/159cb1e5-2c05-41df-b73d-0334b5b93fb9/channels to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.542 SingleUserLabApp log:189] 101 GET /user/USER/api/kernels/159cb1e5-2c05-41df-b73d-0334b5b93fb9/channels?session_id=9eea96a5-81d3-4ace-b528-55c9ea319a17 (USER@IP) 2.45ms
[D 2022-11-18 18:01:00,558 configurable_http_proxy] PROXY WEB /user/USER/api/kernels/159cb1e5-2c05-41df-b73d-0334b5b93fb9/channels to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,558 configurable_http_proxy] PROXY WEB /user/USER/api/kernels/159cb1e5-2c05-41df-b73d-0334b5b93fb9/channels to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.563 SingleUserLabApp log:189] 101 GET /user/USER/api/kernels/159cb1e5-2c05-41df-b73d-0334b5b93fb9/channels?session_id=f5a0234c-77d1-4955-b5ad-bfdbd6bfe143 (USER@IP) 3.09ms
[D 2022-11-18 18:01:00,582 configurable_http_proxy] PROXY WEB /user/USER/api/sessions to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,583 configurable_http_proxy] PROXY WEB /user/USER/api/kernels to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,595 configurable_http_proxy] PROXY WEB /user/USER/static/base/images/favicon-busy-1.ico to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,597 configurable_http_proxy] Not recording activity for status 304 on /user/USER
[D 2022-11-18 18:01:00,600 configurable_http_proxy] PROXY WEB /user/USER/static/base/images/favicon-busy-1.ico to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,602 configurable_http_proxy] Not recording activity for status 304 on /user/USER
[D 2022-11-18 18:01:00,604 configurable_http_proxy] PROXY WEB /user/USER/static/base/images/favicon-busy-1.ico to http://127.0.0.1:56259
[D 2022-11-18 18:01:00,606 configurable_http_proxy] Not recording activity for status 304 on /user/USER
[D 2022-11-18 18:01:00,813 configurable_http_proxy] PROXY WEB /user/USER/lab/api/workspaces/lab to http://127.0.0.1:56259
[I 2022-11-18 18:01:00.816 SingleUserLabApp log:189] 204 PUT /user/USER/lab/api/workspaces/lab?1668765660720 (USER@IP) 1.27ms
8

It looks like the error may come from your singleuser server. Do you see the same error JupyterLab on it’s own, but on the same system as the same user? Are there any configuration files in the user’s home directory? Do you see the error on a freshly installed system?

What versions of nodejs and configurable-http-proxy are you using? Your JupyterLab version is very old, can you try the latest?

9

Hi,
Any update?
Same issue here after upgrading Jupyter version:
image

We are using jupyter over a docker container.
Thanks