Skip to content

Instantly share code, notes, and snippets.

@loganasherjones
Created September 6, 2022 23:41
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save loganasherjones/a7debfdb74ac6e2ec8770e4f9a6b12a8 to your computer and use it in GitHub Desktop.
Save loganasherjones/a7debfdb74ac6e2ec8770e4f9a6b12a8 to your computer and use it in GitHub Desktop.
Jupyter Hub Logs
[D 2022-09-06 00:41:58.338 JupyterHub application:730] Looking for /usr/local/etc/jupyterhub/jupyterhub_config in /srv/jupyterhub
Loading /usr/local/etc/jupyterhub/secret/values.yaml
No config at /usr/local/etc/jupyterhub/existing-secret/values.yaml
[D 2022-09-06 00:41:58.689 JupyterHub application:752] Loaded config file: /usr/local/etc/jupyterhub/jupyterhub_config.py
[I 2022-09-06 00:41:58.729 JupyterHub app:2479] Running JupyterHub version 1.5.0
[I 2022-09-06 00:41:58.730 JupyterHub app:2509] Using Authenticator: jupyterhub.auth.DummyAuthenticator-1.5.0
[I 2022-09-06 00:41:58.730 JupyterHub app:2509] Using Spawner: kubespawner.spawner.KubeSpawner-1.1.0
[I 2022-09-06 00:41:58.730 JupyterHub app:2509] Using Proxy: jupyterhub.proxy.ConfigurableHTTPProxy-1.5.0
[D 2022-09-06 00:41:58.731 JupyterHub app:1721] Connecting to db: sqlite:///jupyterhub.sqlite
[D 2022-09-06 00:41:58.745 JupyterHub orm:784] Stamping empty database with alembic revision 4dc2d5a8c53c
[I 2022-09-06 00:41:58.750 alembic.runtime.migration migration:164] Context impl SQLiteImpl.
[I 2022-09-06 00:41:58.750 alembic.runtime.migration migration:167] Will assume non-transactional DDL.
[I 2022-09-06 00:41:58.763 alembic.runtime.migration migration:556] Running stamp_revision -> 4dc2d5a8c53c
[D 2022-09-06 00:41:58.764 alembic.runtime.migration migration:752] new branch insert 4dc2d5a8c53c
[D 2022-09-06 00:41:58.778 JupyterHub orm:784] Stamping empty database with alembic revision 4dc2d5a8c53c
[I 2022-09-06 00:41:58.779 alembic.runtime.migration migration:164] Context impl SQLiteImpl.
[I 2022-09-06 00:41:58.779 alembic.runtime.migration migration:167] Will assume non-transactional DDL.
[W 2022-09-06 00:41:58.872 JupyterHub app:1828] No admin users, admin interface will be unavailable.
[W 2022-09-06 00:41:58.872 JupyterHub app:1829] Add any administrative users to `c.Authenticator.admin_users` in config.
[I 2022-09-06 00:41:58.872 JupyterHub app:1858] Not using allowed_users. Any authenticated user will be allowed.
[D 2022-09-06 00:41:58.911 JupyterHub app:2010] Purging expired APITokens
[D 2022-09-06 00:41:58.914 JupyterHub app:2010] Purging expired OAuthAccessTokens
[D 2022-09-06 00:41:58.916 JupyterHub app:2010] Purging expired OAuthCodes
[D 2022-09-06 00:41:58.933 JupyterHub app:2133] Initializing spawners
[D 2022-09-06 00:41:58.935 JupyterHub app:2266] Loaded users:
[I 2022-09-06 00:41:58.936 JupyterHub app:2546] Initialized 0 spawners in 0.002 seconds
[I 2022-09-06 00:41:58.938 JupyterHub app:2758] Not starting proxy
[D 2022-09-06 00:41:58.938 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[W 2022-09-06 00:41:58.941 JupyterHub proxy:851] api_request to the proxy failed with status code 599, retrying...
[D 2022-09-06 00:41:59.086 JupyterHub proxy:905] Omitting non-jupyterhub route '/'
[I 2022-09-06 00:41:59.087 JupyterHub app:2794] Hub API listening on http://:8081/hub/
[I 2022-09-06 00:41:59.087 JupyterHub app:2796] Private Hub API connect url http://hub:8081/hub/
[D 2022-09-06 00:41:59.087 JupyterHub proxy:342] Fetching routes to check
[D 2022-09-06 00:41:59.087 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2022-09-06 00:41:59.089 JupyterHub proxy:905] Omitting non-jupyterhub route '/'
[I 2022-09-06 00:41:59.089 JupyterHub proxy:347] Checking routes
[I 2022-09-06 00:41:59.089 JupyterHub proxy:432] Adding route for Hub: / => http://hub:8081
[D 2022-09-06 00:41:59.089 JupyterHub proxy:832] Proxy: Fetching POST http://proxy-api:8001/api/routes/
[I 2022-09-06 00:41:59.092 JupyterHub app:2869] JupyterHub is now running at http://:8000
[D 2022-09-06 00:41:59.093 JupyterHub app:2472] It took 0.761 seconds for the Hub to start
[D 2022-09-06 00:42:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:42:59.098 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:43:59.094 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:43:59.099 JupyterHub proxy:347] Checking routes
[I 2022-09-06 00:44:35.177 JupyterHub log:189] 302 GET / -> /hub/ (@::ffff:10.42.0.1) 0.97ms
[W 2022-09-06 00:44:35.187 JupyterHub base:390] Invalid or expired cookie token
[I 2022-09-06 00:44:35.188 JupyterHub log:189] 302 GET /hub/ -> /hub/login?next=%2Fhub%2F (@::ffff:10.42.0.1) 1.23ms
[I 2022-09-06 00:44:35.235 JupyterHub log:189] 200 GET /hub/login?next=%2Fhub%2F (@::ffff:10.42.0.1) 38.29ms
[D 2022-09-06 00:44:35.277 JupyterHub log:189] 200 GET /hub/static/css/style.min.css?v=bff49b4a161afb17ee3b71927ce7d6c4e5b0e4b9ef6f18ca3e356a05f29e69776d3a76aee167060dd2ae2ee62d3cfdcf203b4b0090b1423f7d629ea7daa3f9da (@::ffff:10.42.0.1) 1.34ms
[D 2022-09-06 00:44:35.291 JupyterHub log:189] 200 GET /hub/static/components/requirejs/require.js?v=bd1aa102bdb0b27fbf712b32cfcd29b016c272acf3d864ee8469376eaddd032cadcf827ff17c05a8c8e20061418fe58cf79947049f5c0dff3b4f73fcc8cad8ec (@::ffff:10.42.0.1) 2.20ms
[D 2022-09-06 00:44:35.292 JupyterHub log:189] 200 GET /hub/static/components/jquery/dist/jquery.min.js?v=f3de1813a4160f9239f4781938645e1589b876759cd50b7936dbd849a35c38ffaed53f6a61dbdd8a1cf43cf4a28aa9fffbfddeec9a3811a1bb4ee6df58652b31 (@::ffff:10.42.0.1) 2.75ms
[D 2022-09-06 00:44:35.293 JupyterHub log:189] 200 GET /hub/static/components/bootstrap/dist/js/bootstrap.min.js?v=a014e9acc78d10a0a7a9fbaa29deac6ef17398542d9574b77b40bf446155d210fa43384757e3837da41b025998ebfab4b9b6f094033f9c226392b800df068bce (@::ffff:10.42.0.1) 3.24ms
[D 2022-09-06 00:44:35.372 JupyterHub log:189] 200 GET /hub/logo (@::ffff:10.42.0.1) 1.39ms
[D 2022-09-06 00:44:35.660 JupyterHub log:189] 200 GET /hub/static/favicon.ico?v=fde5757cd3892b979919d3b1faa88a410f28829feb5ba22b6cf069f2c6c98675fceef90f932e49b510e74d65c681d5846b943e7f7cc1b41867422f0481085c1f (@::ffff:10.42.0.1) 0.78ms
[D 2022-09-06 00:44:41.415 JupyterHub log:189] 200 GET /hub/static/components/font-awesome/fonts/fontawesome-webfont.woff2?v=4.7.0 (@::ffff:10.42.0.1) 1.76ms
[D 2022-09-06 00:44:41.451 JupyterHub base:530] Setting cookie for test_user: jupyterhub-hub-login
[D 2022-09-06 00:44:41.452 JupyterHub base:526] Setting cookie jupyterhub-hub-login: {'httponly': True, 'path': '/hub/'}
[I 2022-09-06 00:44:41.452 JupyterHub base:762] User logged in: test_user
[I 2022-09-06 00:44:41.453 JupyterHub log:189] 302 POST /hub/login?next=%2Fhub%2F -> /hub/ (test_user@::ffff:10.42.0.1) 40.64ms
[D 2022-09-06 00:44:41.467 JupyterHub base:283] Recording first activity for <User(test_user 0/1 running)>
[D 2022-09-06 00:44:41.474 JupyterHub user:317] Creating <class 'kubespawner.spawner.KubeSpawner'> for test_user:
[D 2022-09-06 00:44:41.481 JupyterHub spawner:194] Starting executor thread pool with 40 workers
[I 2022-09-06 00:44:41.495 JupyterHub reflector:275] watching for pods with label selector='component=singleuser-server' in namespace jupyter
[D 2022-09-06 00:44:41.496 JupyterHub reflector:282] Connecting pods watcher
[I 2022-09-06 00:44:41.519 JupyterHub reflector:275] watching for events with field selector='involvedObject.kind=Pod' in namespace jupyter
[D 2022-09-06 00:44:41.520 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:44:41.522 JupyterHub log:189] 302 GET /hub/ -> /hub/spawn (test_user@::ffff:10.42.0.1) 57.97ms
[D 2022-09-06 00:44:41.535 JupyterHub pages:217] Triggering spawn with default options for test_user
[D 2022-09-06 00:44:41.536 JupyterHub base:880] Initiating spawn for test_user
[D 2022-09-06 00:44:41.536 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:44:41.536 JupyterHub base:889] 0 active servers
[I 2022-09-06 00:44:41.556 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user
[D 2022-09-06 00:44:41.574 JupyterHub user:631] Calling Spawner.start for test_user
[I 2022-09-06 00:44:41.576 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fuser, with timeout 3
[I 2022-09-06 00:44:41.578 JupyterHub log:189] 302 GET /hub/spawn -> /hub/spawn-pending/test_user (test_user@::ffff:10.42.0.1) 46.21ms
[I 2022-09-06 00:44:41.590 JupyterHub pages:402] test_user is pending spawn
[I 2022-09-06 00:44:41.596 JupyterHub log:189] 200 GET /hub/spawn-pending/test_user (test_user@::ffff:10.42.0.1) 8.88ms
[I 2022-09-06 00:44:41.606 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser, with timeout 3
[D 2022-09-06 00:44:41.892 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser
[D 2022-09-06 00:44:50.039 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser events before launch: 2022-09-06T00:44:46.633419Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser to logan-dev
2022-09-06T00:44:47Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:44:47Z [Normal] Created container block-cloud-metadata
2022-09-06T00:44:47Z [Normal] Started container block-cloud-metadata
2022-09-06T00:44:48Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:44:48Z [Normal] Created container notebook
2022-09-06T00:44:48Z [Normal] Started container notebook
[D 2022-09-06 00:44:50.048 JupyterHub spawner:1179] Polling subprocess every 30s
[I 2022-09-06 00:44:50.767 JupyterHub log:189] 200 GET /hub/api (@10.42.0.164) 1.31ms
[D 2022-09-06 00:44:50.780 JupyterHub base:283] Recording first activity for <APIToken('ce21...', user='test_user')>
[D 2022-09-06 00:44:50.792 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:44:49.159129Z
[D 2022-09-06 00:44:50.792 JupyterHub users:796] Activity on server test_user/: 2022-09-06T00:44:49.159129Z
[I 2022-09-06 00:44:50.802 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.164) 26.35ms
[D 2022-09-06 00:44:51.507 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:44:51.507 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:44:51.545 JupyterHub utils:225] Server at http://10.42.0.164:8888/user/test_user/ responded with 302
[W 2022-09-06 00:44:51.545 JupyterHub _version:70] jupyterhub version 1.5.0 != jupyterhub-singleuser version 1.4.2. This could cause failure to authenticate and result in redirect loops!
[I 2022-09-06 00:44:51.545 JupyterHub base:909] User test_user took 10.009 seconds to start
[I 2022-09-06 00:44:51.546 JupyterHub proxy:285] Adding user test_user to proxy /user/test_user/ => http://10.42.0.164:8888
[D 2022-09-06 00:44:51.546 JupyterHub proxy:832] Proxy: Fetching POST http://proxy-api:8001/api/routes/user/test_user
[I 2022-09-06 00:44:51.550 JupyterHub users:677] Server test_user is ready
[I 2022-09-06 00:44:51.551 JupyterHub log:189] 200 GET /hub/api/users/test_user/server/progress (test_user@::ffff:10.42.0.1) 9663.21ms
[D 2022-09-06 00:44:51.551 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:44:51.552 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:44:51.566 JupyterHub log:189] 302 GET /hub/spawn-pending/test_user -> /user/test_user/ (test_user@::ffff:10.42.0.1) 3.19ms
[D 2022-09-06 00:44:51.594 JupyterHub provider:409] Validating client id jupyterhub-user-test_user
[D 2022-09-06 00:44:51.595 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user, redirect_uri=/user/test_user/oauth_callback
[D 2022-09-06 00:44:51.596 JupyterHub auth:252] Skipping oauth confirmation for <User(test_user 1/1 running)> accessing Server at /user/test_user/
[D 2022-09-06 00:44:51.597 JupyterHub provider:409] Validating client id jupyterhub-user-test_user
[D 2022-09-06 00:44:51.597 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user, redirect_uri=/user/test_user/oauth_callback
[D 2022-09-06 00:44:51.598 JupyterHub provider:231] Saving authorization code jupyterhub-user-test_user, BsV..., (), {}
[I 2022-09-06 00:44:51.609 JupyterHub log:189] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user&redirect_uri=%2Fuser%2Ftest_user%2Foauth_callback&response_type=code&state=[secret] -> /user/test_user/oauth_callback?code=[secret]&state=[secret] (test_user@::ffff:10.42.0.1) 16.82ms
[D 2022-09-06 00:44:51.630 JupyterHub provider:55] authenticate_client <oauthlib.Request SANITIZED>
[D 2022-09-06 00:44:51.639 JupyterHub provider:111] confirm_redirect_uri: client_id=jupyterhub-user-test_user, redirect_uri=/user/test_user/oauth_callback
[D 2022-09-06 00:44:51.640 JupyterHub provider:334] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 1209600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2022-09-06 00:44:51.655 JupyterHub provider:189] Deleting oauth code BsV... for jupyterhub-user-test_user
[I 2022-09-06 00:44:51.674 JupyterHub log:189] 200 POST /hub/api/oauth2/token (test_user@10.42.0.164) 47.80ms
[I 2022-09-06 00:44:51.704 JupyterHub log:189] 200 GET /hub/api/authorizations/token/[secret] (test_user@10.42.0.164) 23.64ms
[I 2022-09-06 00:44:56.690 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 17.29ms
[D 2022-09-06 00:44:56.909 JupyterHub log:189] 200 GET /hub/static/js/home.js?v=20220906004158 (@::ffff:10.42.0.1) 1.41ms
[D 2022-09-06 00:44:56.935 JupyterHub log:189] 200 GET /hub/static/components/moment/moment.js?v=20220906004158 (@::ffff:10.42.0.1) 2.45ms
[D 2022-09-06 00:44:56.936 JupyterHub log:189] 200 GET /hub/static/js/jhapi.js?v=20220906004158 (@::ffff:10.42.0.1) 2.93ms
[D 2022-09-06 00:44:56.954 JupyterHub log:189] 200 GET /hub/static/js/utils.js?v=20220906004158 (@::ffff:10.42.0.1) 1.24ms
[D 2022-09-06 00:44:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:44:59.110 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:45:01.524 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:45:01.525 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:45:01.589 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:45:01.589 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:45:11.541 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:45:11.541 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:45:11.625 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:45:11.625 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:45:21.560 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:45:21.560 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:45:21.666 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:45:21.666 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:45:24.045 JupyterHub log:189] 304 GET /hub/home (test_user@::ffff:10.42.0.1) 5.17ms
[D 2022-09-06 00:45:31.578 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:45:31.578 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:45:31.706 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:45:31.706 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:45:41.588 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:45:41.588 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:45:41.805 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:45:41.805 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:45:51.603 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:45:51.604 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:45:51.843 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:45:51.844 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:45:56.062 JupyterHub user:317] Creating <class 'kubespawner.spawner.KubeSpawner'> for test_user:test1
[D 2022-09-06 00:45:56.074 JupyterHub pages:217] Triggering spawn with default options for test_user:test1
[D 2022-09-06 00:45:56.074 JupyterHub base:880] Initiating spawn for test_user:test1
[D 2022-09-06 00:45:56.074 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:45:56.074 JupyterHub base:889] 1 active servers
[I 2022-09-06 00:45:56.091 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user-test1
[D 2022-09-06 00:45:56.110 JupyterHub user:631] Calling Spawner.start for test_user:test1
[I 2022-09-06 00:45:56.111 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fusertest1, with timeout 3
[I 2022-09-06 00:45:56.113 JupyterHub log:189] 302 GET /hub/spawn/test_user/test1 -> /hub/spawn-pending/test_user/test1 (test_user@::ffff:10.42.0.1) 61.17ms
[I 2022-09-06 00:45:56.124 JupyterHub pages:402] test_user:test1 is pending spawn
[I 2022-09-06 00:45:56.125 JupyterHub log:189] 200 GET /hub/spawn-pending/test_user/test1 (test_user@::ffff:10.42.0.1) 5.11ms
[I 2022-09-06 00:45:56.133 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser--test1, with timeout 3
[D 2022-09-06 00:45:56.344 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser--test1
[D 2022-09-06 00:45:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:45:59.109 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:46:01.618 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:46:01.618 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:46:01.885 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:46:01.885 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:46:03.924 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser--test1 events before launch: 2022-09-06T00:46:01.163467Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser--test1 to logan-dev
2022-09-06T00:46:01Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:46:01Z [Normal] Created container block-cloud-metadata
2022-09-06T00:46:01Z [Normal] Started container block-cloud-metadata
2022-09-06T00:46:02Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:46:02Z [Normal] Created container notebook
2022-09-06T00:46:02Z [Normal] Started container notebook
[D 2022-09-06 00:46:03.934 JupyterHub spawner:1179] Polling subprocess every 30s
[I 2022-09-06 00:46:05.048 JupyterHub log:189] 200 GET /hub/api (@10.42.0.166) 1.27ms
[D 2022-09-06 00:46:05.058 JupyterHub base:283] Recording first activity for <APIToken('3e64...', user='test_user')>
[D 2022-09-06 00:46:05.069 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:46:03.442865Z
[D 2022-09-06 00:46:05.069 JupyterHub users:796] Activity on server test_user/test1: 2022-09-06T00:46:03.442865Z
[I 2022-09-06 00:46:05.076 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.166) 20.66ms
[D 2022-09-06 00:46:11.631 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:46:11.631 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:46:11.931 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:46:11.931 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:46:21.645 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:46:21.645 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:46:21.974 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:46:21.974 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:46:31.659 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:46:31.660 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:46:32.002 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:46:32.002 JupyterHub reflector:282] Connecting events watcher
[W 2022-09-06 00:46:35.665 JupyterHub user:767] test_user's server never showed up at http://10.42.0.166:8888/user/test_user/test1/ after 30 seconds. Giving up
[D 2022-09-06 00:46:35.666 JupyterHub user:819] Stopping test_user:test1
[I 2022-09-06 00:46:35.667 JupyterHub spawner:2620] Deleting pod jupyter/jupyter-test-5fuser--test1
[D 2022-09-06 00:46:37.709 JupyterHub user:845] Deleting oauth client jupyterhub-user-test_user-test1
[D 2022-09-06 00:46:37.720 JupyterHub user:848] Finished stopping test_user:test1
[E 2022-09-06 00:46:37.730 JupyterHub gen:623] Exception in Future <Task finished name='Task-334' coro=<BaseHandler.spawn_single_user.<locals>.finish_user_spawn() done, defined at /usr/local/lib/python3.8/dist-packages/jupyterhub/handlers/base.py:900> exception=TimeoutError("Server at http://10.42.0.166:8888/user/test_user/test1/ didn't respond in 30 seconds")> after timeout
Traceback (most recent call last):
File "/usr/local/lib/python3.8/dist-packages/tornado/gen.py", line 618, in error_callback
future.result()
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/handlers/base.py", line 907, in finish_user_spawn
await spawn_future
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/user.py", line 748, in spawn
await self._wait_up(spawner)
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/user.py", line 795, in _wait_up
raise e
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/user.py", line 762, in _wait_up
resp = await server.wait_up(
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/utils.py", line 236, in wait_for_http_server
re = await exponential_backoff(
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/utils.py", line 184, in exponential_backoff
raise TimeoutError(fail_message)
TimeoutError: Server at http://10.42.0.166:8888/user/test_user/test1/ didn't respond in 30 seconds
[I 2022-09-06 00:46:37.732 JupyterHub log:189] 200 GET /hub/api/users/test_user/servers/test1/progress (test_user@::ffff:10.42.0.1) 41392.54ms
[D 2022-09-06 00:46:41.675 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:46:41.675 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:46:42.045 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:46:42.045 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:46:45.378 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 6.40ms
[I 2022-09-06 00:46:47.531 JupyterHub users:492] Deleting spawner test_user:test1
[I 2022-09-06 00:46:47.532 JupyterHub spawner:2653] Deleting pvc claim-test-5fusertest1
[I 2022-09-06 00:46:47.558 JupyterHub log:189] 204 DELETE /hub/api/users/test_user/servers/test1 (test_user@::ffff:10.42.0.1) 30.55ms
[D 2022-09-06 00:46:51.687 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:46:51.687 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:46:52.081 JupyterHub user:317] Creating <class 'kubespawner.spawner.KubeSpawner'> for test_user:test1
[D 2022-09-06 00:46:52.090 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:46:52.090 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:46:52.097 JupyterHub pages:217] Triggering spawn with default options for test_user:test1
[D 2022-09-06 00:46:52.098 JupyterHub base:880] Initiating spawn for test_user:test1
[D 2022-09-06 00:46:52.098 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:46:52.098 JupyterHub base:889] 1 active servers
[I 2022-09-06 00:46:52.112 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user-test1
[D 2022-09-06 00:46:52.137 JupyterHub user:631] Calling Spawner.start for test_user:test1
[I 2022-09-06 00:46:52.139 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fusertest1, with timeout 3
[I 2022-09-06 00:46:52.141 JupyterHub log:189] 302 GET /hub/spawn/test_user/test1 -> /hub/spawn-pending/test_user/test1 (test_user@::ffff:10.42.0.1) 63.93ms
[I 2022-09-06 00:46:52.155 JupyterHub pages:402] test_user:test1 is pending spawn
[D 2022-09-06 00:46:52.156 JupyterHub log:189] 304 GET /hub/spawn-pending/test_user/test1 (test_user@::ffff:10.42.0.1) 4.03ms
[I 2022-09-06 00:46:52.161 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser--test1, with timeout 3
[D 2022-09-06 00:46:52.375 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser--test1
[D 2022-09-06 00:46:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:46:59.102 JupyterHub proxy:347] Checking routes
[I 2022-09-06 00:47:01.299 JupyterHub log:189] 200 GET /hub/api (@10.42.0.169) 1.29ms
[D 2022-09-06 00:47:01.309 JupyterHub base:283] Recording first activity for <APIToken('f1ad...', user='test_user')>
[D 2022-09-06 00:47:01.321 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:46:59.699249Z
[D 2022-09-06 00:47:01.321 JupyterHub users:796] Activity on server test_user/test1: 2022-09-06T00:46:59.699249Z
[I 2022-09-06 00:47:01.328 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.169) 21.33ms
[D 2022-09-06 00:47:01.631 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser--test1 events before launch: 2022-09-06T00:46:57.191537Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser--test1 to logan-dev
2022-09-06T00:46:57Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:46:57Z [Normal] Created container block-cloud-metadata
2022-09-06T00:46:57Z [Normal] Started container block-cloud-metadata
2022-09-06T00:46:58Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:46:58Z [Normal] Created container notebook
2022-09-06T00:46:58Z [Normal] Started container notebook
[D 2022-09-06 00:47:01.642 JupyterHub spawner:1179] Polling subprocess every 30s
[D 2022-09-06 00:47:01.652 JupyterHub utils:225] Server at http://10.42.0.169:8888/user/test_user/test1/ responded with 302
[I 2022-09-06 00:47:01.652 JupyterHub base:909] User test_user:test1 took 9.554 seconds to start
[I 2022-09-06 00:47:01.652 JupyterHub proxy:285] Adding user test_user to proxy /user/test_user/test1/ => http://10.42.0.169:8888
[D 2022-09-06 00:47:01.653 JupyterHub proxy:832] Proxy: Fetching POST http://proxy-api:8001/api/routes/user/test_user/test1
[I 2022-09-06 00:47:01.655 JupyterHub users:677] Server test_user:test1 is ready
[I 2022-09-06 00:47:01.656 JupyterHub log:189] 200 GET /hub/api/users/test_user/servers/test1/progress (test_user@::ffff:10.42.0.1) 9285.77ms
[I 2022-09-06 00:47:01.671 JupyterHub log:189] 302 GET /hub/spawn-pending/test_user/test1 -> /user/test_user/test1 (test_user@::ffff:10.42.0.1) 3.10ms
[D 2022-09-06 00:47:01.696 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:47:01.696 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:47:01.702 JupyterHub provider:409] Validating client id jupyterhub-user-test_user-test1
[D 2022-09-06 00:47:01.703 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user-test1, redirect_uri=/user/test_user/test1/oauth_callback
[D 2022-09-06 00:47:01.707 JupyterHub auth:252] Skipping oauth confirmation for <User(test_user 2/2 running)> accessing Server at /user/test_user/test1/
[D 2022-09-06 00:47:01.708 JupyterHub provider:409] Validating client id jupyterhub-user-test_user-test1
[D 2022-09-06 00:47:01.709 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user-test1, redirect_uri=/user/test_user/test1/oauth_callback
[D 2022-09-06 00:47:01.710 JupyterHub provider:231] Saving authorization code jupyterhub-user-test_user-test1, KLQ..., (), {}
[I 2022-09-06 00:47:01.718 JupyterHub log:189] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user-test1&redirect_uri=%2Fuser%2Ftest_user%2Ftest1%2Foauth_callback&response_type=code&state=[secret] -> /user/test_user/test1/oauth_callback?code=[secret]&state=[secret] (test_user@::ffff:10.42.0.1) 17.93ms
[D 2022-09-06 00:47:01.736 JupyterHub provider:55] authenticate_client <oauthlib.Request SANITIZED>
[D 2022-09-06 00:47:01.741 JupyterHub provider:111] confirm_redirect_uri: client_id=jupyterhub-user-test_user-test1, redirect_uri=/user/test_user/test1/oauth_callback
[D 2022-09-06 00:47:01.742 JupyterHub provider:334] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 1209600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2022-09-06 00:47:01.750 JupyterHub provider:189] Deleting oauth code KLQ... for jupyterhub-user-test_user-test1
[I 2022-09-06 00:47:01.761 JupyterHub log:189] 200 POST /hub/api/oauth2/token (test_user@10.42.0.169) 28.13ms
[I 2022-09-06 00:47:01.778 JupyterHub log:189] 200 GET /hub/api/authorizations/token/[secret] (test_user@10.42.0.169) 10.94ms
[D 2022-09-06 00:47:02.128 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:47:02.128 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:47:11.682 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 5.01ms
[D 2022-09-06 00:47:11.707 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:47:11.707 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:47:12.161 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:47:12.161 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:47:13.946 JupyterHub pages:652] No template for 503
[I 2022-09-06 00:47:13.954 JupyterHub log:189] 200 GET /hub/error/503?url=%2Fuser%2Ftest_user (@10.42.0.158) 9.17ms
[D 2022-09-06 00:47:21.722 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:47:21.722 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:47:22.203 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:47:22.203 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:47:31.734 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:47:31.735 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:47:32.247 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:47:32.248 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:47:41.753 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:47:41.753 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:47:42.293 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:47:42.293 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:47:51.766 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:47:51.766 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:47:52.327 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:47:52.327 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:47:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:47:59.116 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:48:01.784 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:48:01.784 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:48:02.379 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:48:02.379 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:48:11.799 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:48:11.799 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:48:12.421 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:48:12.421 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:48:16.072 JupyterHub pages:652] No template for 503
[I 2022-09-06 00:48:16.073 JupyterHub log:189] 200 GET /hub/error/503?url=%2Fuser%2Ftest_user (@10.42.0.158) 2.20ms
[D 2022-09-06 00:48:21.822 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:48:21.822 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:48:22.464 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:48:22.464 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:48:31.844 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:48:31.845 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:48:32.508 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:48:32.508 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:48:41.856 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:48:41.856 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:48:42.540 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:48:42.540 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:48:51.867 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:48:51.867 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:48:52.578 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:48:52.578 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:48:59.094 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:48:59.105 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:49:01.882 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:49:01.883 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:49:02.611 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:49:02.611 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:49:11.904 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:49:11.904 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:49:12.641 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:49:12.642 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:49:21.914 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:49:21.915 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:49:22.680 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:49:22.680 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:49:28.293 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 15.96ms
[D 2022-09-06 00:49:31.934 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:49:31.934 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:49:32.707 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:49:32.707 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:49:41.951 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:49:41.951 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:49:42.794 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:49:42.794 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:49:51.972 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:49:51.972 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:49:52.840 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:49:52.840 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:49:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:49:59.116 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:50:00.519 JupyterHub base:328] Refreshing auth for test_user
[D 2022-09-06 00:50:00.522 JupyterHub users:783] Not updating activity for <User(test_user 2/2 running)>: 2022-09-06T00:45:22.836602Z < 2022-09-06T00:49:32.551000Z
[D 2022-09-06 00:50:00.523 JupyterHub users:804] Not updating server activity on test_user/: 2022-09-06T00:45:22.836602Z < 2022-09-06T00:49:32.551000Z
[I 2022-09-06 00:50:00.523 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.164) 16.13ms
[D 2022-09-06 00:50:01.991 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:50:01.991 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:50:02.886 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:50:02.886 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:50:12.007 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:50:12.007 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:50:12.917 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:50:12.917 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:50:22.024 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:50:22.024 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:50:22.961 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:50:22.961 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:50:25.998 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 13.09ms
[I 2022-09-06 00:50:27.371 JupyterHub proxy:309] Removing user test_user from proxy (/user/test_user/test1/)
[D 2022-09-06 00:50:27.371 JupyterHub proxy:832] Proxy: Fetching DELETE http://proxy-api:8001/api/routes/user/test_user/test1
[D 2022-09-06 00:50:27.374 JupyterHub user:819] Stopping test_user:test1
[I 2022-09-06 00:50:27.374 JupyterHub spawner:2620] Deleting pod jupyter/jupyter-test-5fuser--test1
[D 2022-09-06 00:50:29.157 JupyterHub user:845] Deleting oauth client jupyterhub-user-test_user-test1
[D 2022-09-06 00:50:29.178 JupyterHub user:848] Finished stopping test_user:test1
[I 2022-09-06 00:50:29.187 JupyterHub base:1115] User test_user server took 1.816 seconds to stop
[I 2022-09-06 00:50:29.188 JupyterHub log:189] 204 DELETE /hub/api/users/test_user/servers/test1 (test_user@::ffff:10.42.0.1) 1822.04ms
[I 2022-09-06 00:50:30.487 JupyterHub log:189] 200 GET /hub/api/authorizations/token/[secret] (test_user@10.42.0.164) 17.13ms
[D 2022-09-06 00:50:32.041 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:50:32.041 JupyterHub reflector:282] Connecting pods watcher
[I 2022-09-06 00:50:32.605 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 4.93ms
[D 2022-09-06 00:50:33.005 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:50:33.005 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:50:35.606 JupyterHub user:317] Creating <class 'kubespawner.spawner.KubeSpawner'> for test_user:test1
[D 2022-09-06 00:50:35.611 JupyterHub pages:217] Triggering spawn with default options for test_user:test1
[D 2022-09-06 00:50:35.611 JupyterHub base:880] Initiating spawn for test_user:test1
[D 2022-09-06 00:50:35.611 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:50:35.611 JupyterHub base:889] 1 active servers
[I 2022-09-06 00:50:35.625 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user-test1
[D 2022-09-06 00:50:35.643 JupyterHub user:631] Calling Spawner.start for test_user:test1
[I 2022-09-06 00:50:35.644 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fusertest1, with timeout 3
[I 2022-09-06 00:50:35.646 JupyterHub log:189] 302 GET /hub/spawn/test_user/test1 -> /hub/spawn-pending/test_user/test1 (test_user@::ffff:10.42.0.1) 42.02ms
[I 2022-09-06 00:50:35.657 JupyterHub pages:402] test_user:test1 is pending spawn
[I 2022-09-06 00:50:35.660 JupyterHub log:189] 200 GET /hub/spawn-pending/test_user/test1 (test_user@::ffff:10.42.0.1) 6.17ms
[I 2022-09-06 00:50:35.662 JupyterHub spawner:2361] PVC claim-test-5fusertest1 already exists, so did not create new pvc.
[I 2022-09-06 00:50:35.667 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser--test1, with timeout 3
[D 2022-09-06 00:50:35.863 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser--test1
[D 2022-09-06 00:50:38.277 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser--test1 events before launch: 2022-09-06T00:50:35.681072Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser--test1 to logan-dev
2022-09-06T00:50:36Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:50:36Z [Normal] Created container block-cloud-metadata
2022-09-06T00:50:36Z [Normal] Started container block-cloud-metadata
2022-09-06T00:50:36Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:50:36Z [Normal] Created container notebook
2022-09-06T00:50:36Z [Normal] Started container notebook
[D 2022-09-06 00:50:38.286 JupyterHub spawner:1179] Polling subprocess every 30s
[I 2022-09-06 00:50:39.110 JupyterHub log:189] 200 GET /hub/api (@10.42.0.170) 1.30ms
[D 2022-09-06 00:50:39.123 JupyterHub base:283] Recording first activity for <APIToken('c22c...', user='test_user')>
[D 2022-09-06 00:50:39.135 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:50:37.597937Z
[D 2022-09-06 00:50:39.135 JupyterHub users:796] Activity on server test_user/test1: 2022-09-06T00:50:37.597937Z
[I 2022-09-06 00:50:39.142 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.170) 23.08ms
[D 2022-09-06 00:50:39.699 JupyterHub utils:225] Server at http://10.42.0.170:8888/user/test_user/test1/ responded with 302
[I 2022-09-06 00:50:39.699 JupyterHub base:909] User test_user:test1 took 4.088 seconds to start
[I 2022-09-06 00:50:39.700 JupyterHub proxy:285] Adding user test_user to proxy /user/test_user/test1/ => http://10.42.0.170:8888
[D 2022-09-06 00:50:39.700 JupyterHub proxy:832] Proxy: Fetching POST http://proxy-api:8001/api/routes/user/test_user/test1
[I 2022-09-06 00:50:39.703 JupyterHub users:677] Server test_user:test1 is ready
[I 2022-09-06 00:50:39.704 JupyterHub log:189] 200 GET /hub/api/users/test_user/servers/test1/progress (test_user@::ffff:10.42.0.1) 3845.39ms
[I 2022-09-06 00:50:39.720 JupyterHub log:189] 302 GET /hub/spawn-pending/test_user/test1 -> /user/test_user/test1 (test_user@::ffff:10.42.0.1) 4.33ms
[D 2022-09-06 00:50:39.754 JupyterHub provider:409] Validating client id jupyterhub-user-test_user-test1
[D 2022-09-06 00:50:39.755 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user-test1, redirect_uri=/user/test_user/test1/oauth_callback
[D 2022-09-06 00:50:39.756 JupyterHub auth:252] Skipping oauth confirmation for <User(test_user 2/2 running)> accessing Server at /user/test_user/test1/
[D 2022-09-06 00:50:39.756 JupyterHub provider:409] Validating client id jupyterhub-user-test_user-test1
[D 2022-09-06 00:50:39.757 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user-test1, redirect_uri=/user/test_user/test1/oauth_callback
[D 2022-09-06 00:50:39.758 JupyterHub provider:231] Saving authorization code jupyterhub-user-test_user-test1, ilh..., (), {}
[I 2022-09-06 00:50:39.768 JupyterHub log:189] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user-test1&redirect_uri=%2Fuser%2Ftest_user%2Ftest1%2Foauth_callback&response_type=code&state=[secret] -> /user/test_user/test1/oauth_callback?code=[secret]&state=[secret] (test_user@::ffff:10.42.0.1) 16.30ms
[D 2022-09-06 00:50:39.789 JupyterHub provider:55] authenticate_client <oauthlib.Request SANITIZED>
[D 2022-09-06 00:50:39.801 JupyterHub provider:111] confirm_redirect_uri: client_id=jupyterhub-user-test_user-test1, redirect_uri=/user/test_user/test1/oauth_callback
[D 2022-09-06 00:50:39.801 JupyterHub provider:334] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 1209600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2022-09-06 00:50:39.810 JupyterHub provider:189] Deleting oauth code ilh... for jupyterhub-user-test_user-test1
[I 2022-09-06 00:50:39.818 JupyterHub log:189] 200 POST /hub/api/oauth2/token (test_user@10.42.0.170) 32.82ms
[I 2022-09-06 00:50:39.833 JupyterHub log:189] 200 GET /hub/api/authorizations/token/[secret] (test_user@10.42.0.170) 10.61ms
[D 2022-09-06 00:50:42.054 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:50:42.055 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:50:43.045 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:50:43.046 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:50:52.071 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:50:52.071 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:50:53.097 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:50:53.097 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:50:55.460 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 7.44ms
[D 2022-09-06 00:50:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:50:59.115 JupyterHub proxy:347] Checking routes
[I 2022-09-06 00:51:01.951 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 5.39ms
[D 2022-09-06 00:51:02.086 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:51:02.087 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:51:02.613 JupyterHub pages:652] No template for 503
[I 2022-09-06 00:51:02.615 JupyterHub log:189] 200 GET /hub/error/503?url=%2Fuser%2Ftest_user (@10.42.0.158) 2.18ms
[D 2022-09-06 00:51:03.141 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:51:03.141 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:51:04.107 JupyterHub log:189] 304 GET /hub/home (test_user@::ffff:10.42.0.1) 4.52ms
[D 2022-09-06 00:51:12.096 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:51:12.096 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:51:13.188 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:51:13.188 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:51:13.661 JupyterHub user:317] Creating <class 'kubespawner.spawner.KubeSpawner'> for test_user:test2
[D 2022-09-06 00:51:13.679 JupyterHub pages:217] Triggering spawn with default options for test_user:test2
[D 2022-09-06 00:51:13.679 JupyterHub base:880] Initiating spawn for test_user:test2
[D 2022-09-06 00:51:13.679 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:51:13.679 JupyterHub base:889] 2 active servers
[I 2022-09-06 00:51:13.693 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user-test2
[D 2022-09-06 00:51:13.709 JupyterHub user:631] Calling Spawner.start for test_user:test2
[I 2022-09-06 00:51:13.711 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fusertest2, with timeout 3
[I 2022-09-06 00:51:13.713 JupyterHub log:189] 302 GET /hub/spawn/test_user/test2 -> /hub/spawn-pending/test_user/test2 (test_user@::ffff:10.42.0.1) 53.83ms
[I 2022-09-06 00:51:13.725 JupyterHub pages:402] test_user:test2 is pending spawn
[I 2022-09-06 00:51:13.727 JupyterHub log:189] 200 GET /hub/spawn-pending/test_user/test2 (test_user@::ffff:10.42.0.1) 4.83ms
[I 2022-09-06 00:51:13.735 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser--test2, with timeout 3
[D 2022-09-06 00:51:13.927 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser--test2
[D 2022-09-06 00:51:22.107 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:51:22.107 JupyterHub reflector:282] Connecting pods watcher
[I 2022-09-06 00:51:22.375 JupyterHub log:189] 200 GET /hub/api (@10.42.0.172) 1.23ms
[D 2022-09-06 00:51:22.386 JupyterHub base:283] Recording first activity for <APIToken('5482...', user='test_user')>
[D 2022-09-06 00:51:22.397 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:51:20.769964Z
[D 2022-09-06 00:51:22.398 JupyterHub users:796] Activity on server test_user/test2: 2022-09-06T00:51:20.769964Z
[I 2022-09-06 00:51:22.406 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.172) 21.85ms
[D 2022-09-06 00:51:22.814 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser--test2 events before launch: 2022-09-06T00:51:18.759385Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser--test2 to logan-dev
2022-09-06T00:51:19Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:51:19Z [Normal] Created container block-cloud-metadata
2022-09-06T00:51:19Z [Normal] Started container block-cloud-metadata
2022-09-06T00:51:19Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:51:19Z [Normal] Created container notebook
2022-09-06T00:51:19Z [Normal] Started container notebook
[D 2022-09-06 00:51:22.823 JupyterHub spawner:1179] Polling subprocess every 30s
[D 2022-09-06 00:51:22.835 JupyterHub utils:225] Server at http://10.42.0.172:8888/user/test_user/test2/ responded with 302
[I 2022-09-06 00:51:22.835 JupyterHub base:909] User test_user:test2 took 9.156 seconds to start
[I 2022-09-06 00:51:22.836 JupyterHub proxy:285] Adding user test_user to proxy /user/test_user/test2/ => http://10.42.0.172:8888
[D 2022-09-06 00:51:22.836 JupyterHub proxy:832] Proxy: Fetching POST http://proxy-api:8001/api/routes/user/test_user/test2
[I 2022-09-06 00:51:22.839 JupyterHub users:677] Server test_user:test2 is ready
[I 2022-09-06 00:51:22.840 JupyterHub log:189] 200 GET /hub/api/users/test_user/servers/test2/progress (test_user@::ffff:10.42.0.1) 8916.63ms
[I 2022-09-06 00:51:22.854 JupyterHub log:189] 302 GET /hub/spawn-pending/test_user/test2 -> /user/test_user/test2 (test_user@::ffff:10.42.0.1) 2.88ms
[D 2022-09-06 00:51:22.883 JupyterHub provider:409] Validating client id jupyterhub-user-test_user-test2
[D 2022-09-06 00:51:22.884 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user-test2, redirect_uri=/user/test_user/test2/oauth_callback
[D 2022-09-06 00:51:22.885 JupyterHub auth:252] Skipping oauth confirmation for <User(test_user 3/3 running)> accessing Server at /user/test_user/test2/
[D 2022-09-06 00:51:22.886 JupyterHub provider:409] Validating client id jupyterhub-user-test_user-test2
[D 2022-09-06 00:51:22.887 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user-test2, redirect_uri=/user/test_user/test2/oauth_callback
[D 2022-09-06 00:51:22.888 JupyterHub provider:231] Saving authorization code jupyterhub-user-test_user-test2, qIu..., (), {}
[I 2022-09-06 00:51:22.899 JupyterHub log:189] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user-test2&redirect_uri=%2Fuser%2Ftest_user%2Ftest2%2Foauth_callback&response_type=code&state=[secret] -> /user/test_user/test2/oauth_callback?code=[secret]&state=[secret] (test_user@::ffff:10.42.0.1) 19.17ms
[D 2022-09-06 00:51:22.920 JupyterHub provider:55] authenticate_client <oauthlib.Request SANITIZED>
[D 2022-09-06 00:51:22.926 JupyterHub provider:111] confirm_redirect_uri: client_id=jupyterhub-user-test_user-test2, redirect_uri=/user/test_user/test2/oauth_callback
[D 2022-09-06 00:51:22.926 JupyterHub provider:334] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 1209600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2022-09-06 00:51:22.936 JupyterHub provider:189] Deleting oauth code qIu... for jupyterhub-user-test_user-test2
[I 2022-09-06 00:51:22.946 JupyterHub log:189] 200 POST /hub/api/oauth2/token (test_user@10.42.0.172) 29.21ms
[I 2022-09-06 00:51:22.968 JupyterHub log:189] 200 GET /hub/api/authorizations/token/[secret] (test_user@10.42.0.172) 14.65ms
[D 2022-09-06 00:51:23.231 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:51:23.231 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:51:26.921 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 4.80ms
[D 2022-09-06 00:51:32.116 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:51:32.117 JupyterHub reflector:282] Connecting pods watcher
[I 2022-09-06 00:51:32.139 JupyterHub proxy:309] Removing user test_user from proxy (/user/test_user/)
[D 2022-09-06 00:51:32.139 JupyterHub proxy:832] Proxy: Fetching DELETE http://proxy-api:8001/api/routes/user/test_user
[D 2022-09-06 00:51:32.141 JupyterHub user:819] Stopping test_user
[I 2022-09-06 00:51:32.142 JupyterHub spawner:2620] Deleting pod jupyter/jupyter-test-5fuser
[D 2022-09-06 00:51:33.272 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:51:33.272 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:51:33.487 JupyterHub user:845] Deleting oauth client jupyterhub-user-test_user
[D 2022-09-06 00:51:33.501 JupyterHub user:848] Finished stopping test_user
[I 2022-09-06 00:51:33.513 JupyterHub base:1115] User test_user server took 1.374 seconds to stop
[I 2022-09-06 00:51:33.514 JupyterHub log:189] 204 DELETE /hub/api/users/test_user/server (test_user@::ffff:10.42.0.1) 1379.60ms
[D 2022-09-06 00:51:34.690 JupyterHub pages:652] No template for 503
[I 2022-09-06 00:51:34.691 JupyterHub log:189] 200 GET /hub/error/503?url=%2Fuser%2Ftest_user%2Ftest1 (@10.42.0.158) 2.26ms
[D 2022-09-06 00:51:42.132 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:51:42.132 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:51:43.313 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:51:43.313 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:51:50.505 JupyterHub user:317] Creating <class 'kubespawner.spawner.KubeSpawner'> for test_user:
[I 2022-09-06 00:51:50.513 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 10.77ms
[D 2022-09-06 00:51:52.146 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:51:52.147 JupyterHub reflector:282] Connecting pods watcher
[I 2022-09-06 00:51:52.844 JupyterHub log:189] 301 GET /user/test_user -> /user/test_user/ (@::ffff:10.42.0.1) 0.75ms
[I 2022-09-06 00:51:52.856 JupyterHub log:189] 302 GET /user/test_user/ -> /hub/user/test_user/ (@::ffff:10.42.0.1) 1.07ms
[E 2022-09-06 00:51:52.872 JupyterHub log:189] 503 GET /hub/user/test_user/ (test_user@::ffff:10.42.0.1) 10.35ms
[D 2022-09-06 00:51:53.028 JupyterHub log:189] 200 GET /hub/static/js/not_running.js?v=20220906004158 (@::ffff:10.42.0.1) 1.12ms
[D 2022-09-06 00:51:53.353 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:51:53.353 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:51:54.630 JupyterHub pages:217] Triggering spawn with default options for test_user
[D 2022-09-06 00:51:54.630 JupyterHub base:880] Initiating spawn for test_user
[D 2022-09-06 00:51:54.630 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:51:54.630 JupyterHub base:889] 2 active servers
[I 2022-09-06 00:51:54.645 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user
[D 2022-09-06 00:51:54.666 JupyterHub user:631] Calling Spawner.start for test_user
[I 2022-09-06 00:51:54.668 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fuser, with timeout 3
[I 2022-09-06 00:51:54.670 JupyterHub log:189] 302 GET /hub/spawn/test_user?next=%2Fhub%2Fuser%2Ftest_user%2F -> /hub/spawn-pending/test_user?next=%2Fhub%2Fuser%2Ftest_user%2F (test_user@::ffff:10.42.0.1) 43.38ms
[I 2022-09-06 00:51:54.681 JupyterHub pages:402] test_user is pending spawn
[I 2022-09-06 00:51:54.683 JupyterHub log:189] 200 GET /hub/spawn-pending/test_user?next=%2Fhub%2Fuser%2Ftest_user%2F (test_user@::ffff:10.42.0.1) 5.11ms
[I 2022-09-06 00:51:54.688 JupyterHub spawner:2361] PVC claim-test-5fuser already exists, so did not create new pvc.
[I 2022-09-06 00:51:54.693 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser, with timeout 3
[D 2022-09-06 00:51:54.859 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser
[D 2022-09-06 00:51:57.621 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser events before launch: 2022-09-06T00:51:54.707700Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser to logan-dev
2022-09-06T00:51:55Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:51:55Z [Normal] Created container block-cloud-metadata
2022-09-06T00:51:55Z [Normal] Started container block-cloud-metadata
2022-09-06T00:51:55Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:51:55Z [Normal] Created container notebook
2022-09-06T00:51:56Z [Normal] Started container notebook
[D 2022-09-06 00:51:57.630 JupyterHub spawner:1179] Polling subprocess every 30s
[I 2022-09-06 00:51:58.348 JupyterHub log:189] 200 GET /hub/api (@10.42.0.173) 0.99ms
[D 2022-09-06 00:51:58.359 JupyterHub base:283] Recording first activity for <APIToken('c1f3...', user='test_user')>
[D 2022-09-06 00:51:58.370 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:51:56.812693Z
[D 2022-09-06 00:51:58.371 JupyterHub users:796] Activity on server test_user/: 2022-09-06T00:51:56.812693Z
[I 2022-09-06 00:51:58.379 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.173) 22.20ms
[D 2022-09-06 00:51:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:51:59.112 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:52:02.161 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:52:02.161 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:52:03.389 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:52:03.389 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:52:12.180 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:52:12.180 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:52:13.430 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:52:13.430 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:52:22.202 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:52:22.202 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:52:23.471 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:52:23.471 JupyterHub reflector:282] Connecting events watcher
[W 2022-09-06 00:52:27.120 JupyterHub user:767] test_user's server never showed up at http://10.42.0.173:8888/user/test_user/ after 30 seconds. Giving up
[D 2022-09-06 00:52:27.120 JupyterHub user:819] Stopping test_user
[I 2022-09-06 00:52:27.121 JupyterHub spawner:2620] Deleting pod jupyter/jupyter-test-5fuser
[D 2022-09-06 00:52:28.161 JupyterHub user:845] Deleting oauth client jupyterhub-user-test_user
[D 2022-09-06 00:52:28.170 JupyterHub user:848] Finished stopping test_user
[E 2022-09-06 00:52:28.181 JupyterHub gen:623] Exception in Future <Task finished name='Task-988' coro=<BaseHandler.spawn_single_user.<locals>.finish_user_spawn() done, defined at /usr/local/lib/python3.8/dist-packages/jupyterhub/handlers/base.py:900> exception=TimeoutError("Server at http://10.42.0.173:8888/user/test_user/ didn't respond in 30 seconds")> after timeout
Traceback (most recent call last):
File "/usr/local/lib/python3.8/dist-packages/tornado/gen.py", line 618, in error_callback
future.result()
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/handlers/base.py", line 907, in finish_user_spawn
await spawn_future
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/user.py", line 748, in spawn
await self._wait_up(spawner)
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/user.py", line 795, in _wait_up
raise e
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/user.py", line 762, in _wait_up
resp = await server.wait_up(
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/utils.py", line 236, in wait_for_http_server
re = await exponential_backoff(
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/utils.py", line 184, in exponential_backoff
raise TimeoutError(fail_message)
TimeoutError: Server at http://10.42.0.173:8888/user/test_user/ didn't respond in 30 seconds
[I 2022-09-06 00:52:28.183 JupyterHub log:189] 200 GET /hub/api/users/test_user/server/progress (test_user@::ffff:10.42.0.1) 33326.51ms
[I 2022-09-06 00:52:31.850 JupyterHub log:189] 302 GET /hub/ -> /hub/spawn (test_user@::ffff:10.42.0.1) 4.15ms
[D 2022-09-06 00:52:31.859 JupyterHub pages:217] Triggering spawn with default options for test_user
[D 2022-09-06 00:52:31.859 JupyterHub base:880] Initiating spawn for test_user
[D 2022-09-06 00:52:31.859 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:52:31.859 JupyterHub base:889] 2 active servers
[I 2022-09-06 00:52:31.871 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user
[D 2022-09-06 00:52:31.908 JupyterHub user:631] Calling Spawner.start for test_user
[I 2022-09-06 00:52:31.910 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fuser, with timeout 3
[I 2022-09-06 00:52:31.912 JupyterHub log:189] 302 GET /hub/spawn -> /hub/spawn-pending/test_user (test_user@::ffff:10.42.0.1) 53.94ms
[I 2022-09-06 00:52:31.921 JupyterHub pages:402] test_user is pending spawn
[I 2022-09-06 00:52:31.923 JupyterHub log:189] 200 GET /hub/spawn-pending/test_user (test_user@::ffff:10.42.0.1) 3.84ms
[I 2022-09-06 00:52:31.927 JupyterHub spawner:2361] PVC claim-test-5fuser already exists, so did not create new pvc.
[I 2022-09-06 00:52:31.932 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser, with timeout 3
[D 2022-09-06 00:52:32.140 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser
[D 2022-09-06 00:52:32.215 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:52:32.215 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:52:33.516 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:52:33.516 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:52:34.517 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser events before launch: 2022-09-06T00:52:31.946986Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser to logan-dev
2022-09-06T00:52:32Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:52:32Z [Normal] Created container block-cloud-metadata
2022-09-06T00:52:32Z [Normal] Started container block-cloud-metadata
2022-09-06T00:52:33Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:52:33Z [Normal] Created container notebook
2022-09-06T00:52:33Z [Normal] Started container notebook
[D 2022-09-06 00:52:34.523 JupyterHub spawner:1179] Polling subprocess every 30s
[I 2022-09-06 00:52:35.443 JupyterHub log:189] 200 GET /hub/api (@10.42.0.174) 1.42ms
[D 2022-09-06 00:52:35.453 JupyterHub base:283] Recording first activity for <APIToken('fdd7...', user='test_user')>
[D 2022-09-06 00:52:35.467 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:52:33.977710Z
[D 2022-09-06 00:52:35.468 JupyterHub users:796] Activity on server test_user/: 2022-09-06T00:52:33.977710Z
[I 2022-09-06 00:52:35.476 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.174) 25.71ms
[D 2022-09-06 00:52:42.230 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:52:42.230 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:52:43.554 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:52:43.555 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:52:52.255 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:52:52.255 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:52:53.651 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:52:53.651 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:52:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:52:59.103 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:53:02.279 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:53:02.280 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:53:03.689 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:53:03.689 JupyterHub reflector:282] Connecting events watcher
[W 2022-09-06 00:53:07.307 JupyterHub user:767] test_user's server never showed up at http://10.42.0.174:8888/user/test_user/ after 30 seconds. Giving up
[D 2022-09-06 00:53:07.307 JupyterHub user:819] Stopping test_user
[I 2022-09-06 00:53:07.308 JupyterHub spawner:2620] Deleting pod jupyter/jupyter-test-5fuser
[D 2022-09-06 00:53:08.897 JupyterHub user:845] Deleting oauth client jupyterhub-user-test_user
[D 2022-09-06 00:53:08.910 JupyterHub user:848] Finished stopping test_user
[W 2022-09-06 00:53:08.922 JupyterHub base:976] 2 consecutive spawns failed. Hub will exit if failure count reaches 5 before succeeding
[E 2022-09-06 00:53:08.922 JupyterHub gen:623] Exception in Future <Task finished name='Task-1078' coro=<BaseHandler.spawn_single_user.<locals>.finish_user_spawn() done, defined at /usr/local/lib/python3.8/dist-packages/jupyterhub/handlers/base.py:900> exception=TimeoutError("Server at http://10.42.0.174:8888/user/test_user/ didn't respond in 30 seconds")> after timeout
Traceback (most recent call last):
File "/usr/local/lib/python3.8/dist-packages/tornado/gen.py", line 618, in error_callback
future.result()
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/handlers/base.py", line 907, in finish_user_spawn
await spawn_future
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/user.py", line 748, in spawn
await self._wait_up(spawner)
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/user.py", line 795, in _wait_up
raise e
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/user.py", line 762, in _wait_up
resp = await server.wait_up(
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/utils.py", line 236, in wait_for_http_server
re = await exponential_backoff(
File "/usr/local/lib/python3.8/dist-packages/jupyterhub/utils.py", line 184, in exponential_backoff
raise TimeoutError(fail_message)
TimeoutError: Server at http://10.42.0.174:8888/user/test_user/ didn't respond in 30 seconds
[I 2022-09-06 00:53:08.923 JupyterHub log:189] 200 GET /hub/api/users/test_user/server/progress (test_user@::ffff:10.42.0.1) 36786.42ms
[D 2022-09-06 00:53:12.304 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:53:12.304 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:53:13.732 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:53:13.733 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:53:15.888 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 4.99ms
[I 2022-09-06 00:53:18.490 JupyterHub proxy:309] Removing user test_user from proxy (/user/test_user/test1/)
[D 2022-09-06 00:53:18.491 JupyterHub proxy:832] Proxy: Fetching DELETE http://proxy-api:8001/api/routes/user/test_user/test1
[D 2022-09-06 00:53:18.493 JupyterHub user:819] Stopping test_user:test1
[I 2022-09-06 00:53:18.493 JupyterHub spawner:2620] Deleting pod jupyter/jupyter-test-5fuser--test1
[D 2022-09-06 00:53:19.490 JupyterHub user:845] Deleting oauth client jupyterhub-user-test_user-test1
[D 2022-09-06 00:53:19.502 JupyterHub user:848] Finished stopping test_user:test1
[I 2022-09-06 00:53:19.509 JupyterHub base:1115] User test_user server took 1.019 seconds to stop
[I 2022-09-06 00:53:19.510 JupyterHub log:189] 204 DELETE /hub/api/users/test_user/servers/test1 (test_user@::ffff:10.42.0.1) 1023.71ms
[I 2022-09-06 00:53:20.508 JupyterHub proxy:309] Removing user test_user from proxy (/user/test_user/test2/)
[D 2022-09-06 00:53:20.508 JupyterHub proxy:832] Proxy: Fetching DELETE http://proxy-api:8001/api/routes/user/test_user/test2
[D 2022-09-06 00:53:20.509 JupyterHub user:819] Stopping test_user:test2
[I 2022-09-06 00:53:20.510 JupyterHub spawner:2620] Deleting pod jupyter/jupyter-test-5fuser--test2
[D 2022-09-06 00:53:21.411 JupyterHub user:845] Deleting oauth client jupyterhub-user-test_user-test2
[D 2022-09-06 00:53:21.425 JupyterHub user:848] Finished stopping test_user:test2
[I 2022-09-06 00:53:21.435 JupyterHub base:1115] User test_user server took 0.928 seconds to stop
[I 2022-09-06 00:53:21.437 JupyterHub log:189] 204 DELETE /hub/api/users/test_user/servers/test2 (test_user@::ffff:10.42.0.1) 933.53ms
[D 2022-09-06 00:53:22.324 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:53:22.325 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:53:23.786 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:53:23.786 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:53:26.528 JupyterHub log:189] 302 GET /user/test_user/ -> /hub/user/test_user/ (@::ffff:10.42.0.1) 0.71ms
[I 2022-09-06 00:53:26.539 JupyterHub log:189] 303 GET /hub/user/test_user/ (test_user@::ffff:10.42.0.1) 3.51ms
[E 2022-09-06 00:53:26.551 JupyterHub pages:380] Previous spawn for test_user failed: Server at http://10.42.0.174:8888/user/test_user/ didn't respond in 30 seconds
[E 2022-09-06 00:53:26.553 JupyterHub log:181] {
"X-Forwarded-Host": "localhost:31558",
"X-Forwarded-Proto": "http",
"X-Forwarded-Port": "31558",
"X-Forwarded-For": "::ffff:10.42.0.1",
"If-None-Match": "\"44b6a3128c4bdc1cc5482db71798d1c263486f0b\"",
"Cookie": "jupyterhub-hub-login=[secret]; jupyterhub-session-id=[secret]; _xsrf=[secret]",
"Accept-Language": "en-US,en;q=0.9",
"Accept-Encoding": "gzip, deflate, br",
"Referer": "http://localhost:31558/hub/home",
"Sec-Ch-Ua-Platform": "\"Linux\"",
"Sec-Ch-Ua-Mobile": "?0",
"Sec-Ch-Ua": "\"Chromium\";v=\"104\", \" Not A;Brand\";v=\"99\", \"Google Chrome\";v=\"104\"",
"Sec-Fetch-Dest": "document",
"Sec-Fetch-User": "?1",
"Sec-Fetch-Mode": "navigate",
"Sec-Fetch-Site": "same-origin",
"Accept": "text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9",
"User-Agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/104.0.0.0 Safari/537.36",
"Upgrade-Insecure-Requests": "1",
"Connection": "close",
"Host": "localhost:31558"
}
[E 2022-09-06 00:53:26.553 JupyterHub log:189] 500 GET /hub/spawn-pending/test_user?next=%2Fhub%2Fuser%2Ftest_user%2F (test_user@::ffff:10.42.0.1) 3.52ms
[D 2022-09-06 00:53:32.210 JupyterHub pages:217] Triggering spawn with default options for test_user
[D 2022-09-06 00:53:32.210 JupyterHub base:880] Initiating spawn for test_user
[D 2022-09-06 00:53:32.210 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:53:32.210 JupyterHub base:889] 0 active servers
[I 2022-09-06 00:53:32.225 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user
[D 2022-09-06 00:53:32.241 JupyterHub user:631] Calling Spawner.start for test_user
[I 2022-09-06 00:53:32.242 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fuser, with timeout 3
[I 2022-09-06 00:53:32.244 JupyterHub log:189] 302 GET /hub/spawn/test_user -> /hub/spawn-pending/test_user (test_user@::ffff:10.42.0.1) 36.23ms
[I 2022-09-06 00:53:32.254 JupyterHub pages:402] test_user is pending spawn
[D 2022-09-06 00:53:32.256 JupyterHub log:189] 304 GET /hub/spawn-pending/test_user (test_user@::ffff:10.42.0.1) 4.97ms
[I 2022-09-06 00:53:32.261 JupyterHub spawner:2361] PVC claim-test-5fuser already exists, so did not create new pvc.
[I 2022-09-06 00:53:32.266 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser, with timeout 3
[D 2022-09-06 00:53:32.341 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:53:32.342 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:53:32.446 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser
[D 2022-09-06 00:53:33.835 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:53:33.835 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:53:35.300 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser events before launch: 2022-09-06T00:53:32.281896Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser to logan-dev
2022-09-06T00:53:32Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:53:32Z [Normal] Created container block-cloud-metadata
2022-09-06T00:53:32Z [Normal] Started container block-cloud-metadata
2022-09-06T00:53:33Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:53:33Z [Normal] Created container notebook
2022-09-06T00:53:33Z [Normal] Started container notebook
[D 2022-09-06 00:53:35.309 JupyterHub spawner:1179] Polling subprocess every 30s
[I 2022-09-06 00:53:35.743 JupyterHub log:189] 200 GET /hub/api (@10.42.0.175) 0.86ms
[D 2022-09-06 00:53:35.753 JupyterHub base:283] Recording first activity for <APIToken('79a2...', user='test_user')>
[D 2022-09-06 00:53:35.765 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:53:34.249519Z
[D 2022-09-06 00:53:35.765 JupyterHub users:796] Activity on server test_user/: 2022-09-06T00:53:34.249519Z
[I 2022-09-06 00:53:35.774 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.175) 23.05ms
[D 2022-09-06 00:53:35.902 JupyterHub utils:225] Server at http://10.42.0.175:8888/user/test_user/ responded with 302
[I 2022-09-06 00:53:35.903 JupyterHub base:909] User test_user took 3.692 seconds to start
[I 2022-09-06 00:53:35.903 JupyterHub proxy:285] Adding user test_user to proxy /user/test_user/ => http://10.42.0.175:8888
[D 2022-09-06 00:53:35.903 JupyterHub proxy:832] Proxy: Fetching POST http://proxy-api:8001/api/routes/user/test_user
[I 2022-09-06 00:53:35.907 JupyterHub users:677] Server test_user is ready
[I 2022-09-06 00:53:35.908 JupyterHub log:189] 200 GET /hub/api/users/test_user/server/progress (test_user@::ffff:10.42.0.1) 3465.63ms
[I 2022-09-06 00:53:35.924 JupyterHub log:189] 302 GET /hub/spawn-pending/test_user -> /user/test_user/ (test_user@::ffff:10.42.0.1) 4.28ms
[D 2022-09-06 00:53:35.954 JupyterHub provider:409] Validating client id jupyterhub-user-test_user
[D 2022-09-06 00:53:35.955 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user, redirect_uri=/user/test_user/oauth_callback
[D 2022-09-06 00:53:35.956 JupyterHub auth:252] Skipping oauth confirmation for <User(test_user 1/3 running)> accessing Server at /user/test_user/
[D 2022-09-06 00:53:35.957 JupyterHub provider:409] Validating client id jupyterhub-user-test_user
[D 2022-09-06 00:53:35.958 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user, redirect_uri=/user/test_user/oauth_callback
[D 2022-09-06 00:53:35.959 JupyterHub provider:231] Saving authorization code jupyterhub-user-test_user, zmD..., (), {}
[I 2022-09-06 00:53:35.970 JupyterHub log:189] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user&redirect_uri=%2Fuser%2Ftest_user%2Foauth_callback&response_type=code&state=[secret] -> /user/test_user/oauth_callback?code=[secret]&state=[secret] (test_user@::ffff:10.42.0.1) 20.33ms
[D 2022-09-06 00:53:35.988 JupyterHub provider:55] authenticate_client <oauthlib.Request SANITIZED>
[D 2022-09-06 00:53:35.995 JupyterHub provider:111] confirm_redirect_uri: client_id=jupyterhub-user-test_user, redirect_uri=/user/test_user/oauth_callback
[D 2022-09-06 00:53:35.995 JupyterHub provider:334] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 1209600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2022-09-06 00:53:36.013 JupyterHub provider:189] Deleting oauth code zmD... for jupyterhub-user-test_user
[I 2022-09-06 00:53:36.036 JupyterHub log:189] 200 POST /hub/api/oauth2/token (test_user@10.42.0.175) 50.42ms
[I 2022-09-06 00:53:36.054 JupyterHub log:189] 200 GET /hub/api/authorizations/token/[secret] (test_user@10.42.0.175) 13.41ms
[I 2022-09-06 00:53:38.153 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 6.50ms
[I 2022-09-06 00:53:39.682 JupyterHub proxy:309] Removing user test_user from proxy (/user/test_user/)
[D 2022-09-06 00:53:39.682 JupyterHub proxy:832] Proxy: Fetching DELETE http://proxy-api:8001/api/routes/user/test_user
[D 2022-09-06 00:53:39.685 JupyterHub user:819] Stopping test_user
[I 2022-09-06 00:53:39.685 JupyterHub spawner:2620] Deleting pod jupyter/jupyter-test-5fuser
[D 2022-09-06 00:53:41.262 JupyterHub user:845] Deleting oauth client jupyterhub-user-test_user
[D 2022-09-06 00:53:41.277 JupyterHub user:848] Finished stopping test_user
[I 2022-09-06 00:53:41.287 JupyterHub base:1115] User test_user server took 1.605 seconds to stop
[I 2022-09-06 00:53:41.287 JupyterHub log:189] 204 DELETE /hub/api/users/test_user/server (test_user@::ffff:10.42.0.1) 1610.27ms
[D 2022-09-06 00:53:42.350 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:53:42.350 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:53:42.748 JupyterHub user:317] Creating <class 'kubespawner.spawner.KubeSpawner'> for test_user:test1
[D 2022-09-06 00:53:42.753 JupyterHub pages:217] Triggering spawn with default options for test_user:test1
[D 2022-09-06 00:53:42.754 JupyterHub base:880] Initiating spawn for test_user:test1
[D 2022-09-06 00:53:42.754 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:53:42.754 JupyterHub base:889] 0 active servers
[I 2022-09-06 00:53:42.773 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user-test1
[D 2022-09-06 00:53:42.792 JupyterHub user:631] Calling Spawner.start for test_user:test1
[I 2022-09-06 00:53:42.793 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fusertest1, with timeout 3
[I 2022-09-06 00:53:42.794 JupyterHub log:189] 302 GET /hub/spawn/test_user/test1 -> /hub/spawn-pending/test_user/test1 (test_user@::ffff:10.42.0.1) 49.80ms
[I 2022-09-06 00:53:42.805 JupyterHub pages:402] test_user:test1 is pending spawn
[D 2022-09-06 00:53:42.806 JupyterHub user:317] Creating <class 'kubespawner.spawner.KubeSpawner'> for test_user:
[I 2022-09-06 00:53:42.811 JupyterHub log:189] 200 GET /hub/spawn-pending/test_user/test1 (test_user@::ffff:10.42.0.1) 9.40ms
[I 2022-09-06 00:53:42.811 JupyterHub spawner:2361] PVC claim-test-5fusertest1 already exists, so did not create new pvc.
[I 2022-09-06 00:53:42.816 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser--test1, with timeout 3
[D 2022-09-06 00:53:43.004 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser--test1
[D 2022-09-06 00:53:43.878 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:53:43.878 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:53:46.813 JupyterHub log:189] 200 GET /hub/api (@10.42.0.176) 1.27ms
[D 2022-09-06 00:53:46.825 JupyterHub base:283] Recording first activity for <APIToken('73af...', user='test_user')>
[D 2022-09-06 00:53:46.837 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:53:45.320667Z
[D 2022-09-06 00:53:46.837 JupyterHub users:796] Activity on server test_user/test1: 2022-09-06T00:53:45.320667Z
[I 2022-09-06 00:53:46.846 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.176) 22.39ms
[D 2022-09-06 00:53:47.028 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser--test1 events before launch: 2022-09-06T00:53:42.830057Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser--test1 to logan-dev
2022-09-06T00:53:43Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:53:43Z [Normal] Created container block-cloud-metadata
2022-09-06T00:53:43Z [Normal] Started container block-cloud-metadata
2022-09-06T00:53:44Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:53:44Z [Normal] Created container notebook
2022-09-06T00:53:44Z [Normal] Started container notebook
[D 2022-09-06 00:53:47.039 JupyterHub spawner:1179] Polling subprocess every 30s
[D 2022-09-06 00:53:47.044 JupyterHub utils:225] Server at http://10.42.0.176:8888/user/test_user/test1/ responded with 302
[I 2022-09-06 00:53:47.045 JupyterHub base:909] User test_user:test1 took 4.291 seconds to start
[I 2022-09-06 00:53:47.045 JupyterHub proxy:285] Adding user test_user to proxy /user/test_user/test1/ => http://10.42.0.176:8888
[D 2022-09-06 00:53:47.045 JupyterHub proxy:832] Proxy: Fetching POST http://proxy-api:8001/api/routes/user/test_user/test1
[I 2022-09-06 00:53:47.048 JupyterHub users:677] Server test_user:test1 is ready
[I 2022-09-06 00:53:47.049 JupyterHub log:189] 200 GET /hub/api/users/test_user/servers/test1/progress (test_user@::ffff:10.42.0.1) 4049.44ms
[I 2022-09-06 00:53:47.063 JupyterHub log:189] 302 GET /hub/spawn-pending/test_user/test1 -> /user/test_user/test1 (test_user@::ffff:10.42.0.1) 3.45ms
[D 2022-09-06 00:53:47.092 JupyterHub provider:409] Validating client id jupyterhub-user-test_user-test1
[D 2022-09-06 00:53:47.093 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user-test1, redirect_uri=/user/test_user/test1/oauth_callback
[D 2022-09-06 00:53:47.094 JupyterHub auth:252] Skipping oauth confirmation for <User(test_user 1/3 running)> accessing Server at /user/test_user/test1/
[D 2022-09-06 00:53:47.095 JupyterHub provider:409] Validating client id jupyterhub-user-test_user-test1
[D 2022-09-06 00:53:47.096 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user-test1, redirect_uri=/user/test_user/test1/oauth_callback
[D 2022-09-06 00:53:47.097 JupyterHub provider:231] Saving authorization code jupyterhub-user-test_user-test1, 8Yh..., (), {}
[I 2022-09-06 00:53:47.109 JupyterHub log:189] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user-test1&redirect_uri=%2Fuser%2Ftest_user%2Ftest1%2Foauth_callback&response_type=code&state=[secret] -> /user/test_user/test1/oauth_callback?code=[secret]&state=[secret] (test_user@::ffff:10.42.0.1) 19.14ms
[D 2022-09-06 00:53:47.129 JupyterHub provider:55] authenticate_client <oauthlib.Request SANITIZED>
[D 2022-09-06 00:53:47.136 JupyterHub provider:111] confirm_redirect_uri: client_id=jupyterhub-user-test_user-test1, redirect_uri=/user/test_user/test1/oauth_callback
[D 2022-09-06 00:53:47.136 JupyterHub provider:334] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 1209600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2022-09-06 00:53:47.146 JupyterHub provider:189] Deleting oauth code 8Yh... for jupyterhub-user-test_user-test1
[I 2022-09-06 00:53:47.158 JupyterHub log:189] 200 POST /hub/api/oauth2/token (test_user@10.42.0.176) 33.36ms
[I 2022-09-06 00:53:47.181 JupyterHub log:189] 200 GET /hub/api/authorizations/token/[secret] (test_user@10.42.0.176) 16.88ms
[D 2022-09-06 00:53:52.372 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:53:52.372 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:53:53.917 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:53:53.918 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:53:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:53:59.106 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:54:02.389 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:54:02.389 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:54:03.966 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:54:03.966 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:54:12.404 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:54:12.405 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:54:14.008 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:54:14.009 JupyterHub reflector:282] Connecting events watcher
[I 2022-09-06 00:54:21.368 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 13.42ms
[D 2022-09-06 00:54:22.417 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:54:22.418 JupyterHub reflector:282] Connecting pods watcher
[I 2022-09-06 00:54:23.660 JupyterHub log:189] 302 GET /user/test_user/ -> /hub/user/test_user/ (@::ffff:10.42.0.1) 0.79ms
[E 2022-09-06 00:54:23.672 JupyterHub log:189] 503 GET /hub/user/test_user/ (test_user@::ffff:10.42.0.1) 3.92ms
[D 2022-09-06 00:54:24.052 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:54:24.052 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:54:25.542 JupyterHub pages:217] Triggering spawn with default options for test_user
[D 2022-09-06 00:54:25.543 JupyterHub base:880] Initiating spawn for test_user
[D 2022-09-06 00:54:25.543 JupyterHub base:884] 0/64 concurrent spawns
[D 2022-09-06 00:54:25.543 JupyterHub base:889] 1 active servers
[I 2022-09-06 00:54:25.560 JupyterHub provider:574] Creating oauth client jupyterhub-user-test_user
[D 2022-09-06 00:54:25.581 JupyterHub user:631] Calling Spawner.start for test_user
[I 2022-09-06 00:54:25.583 JupyterHub spawner:2344] Attempting to create pvc claim-test-5fuser, with timeout 3
[I 2022-09-06 00:54:25.585 JupyterHub log:189] 302 GET /hub/spawn/test_user?next=%2Fhub%2Fuser%2Ftest_user%2F -> /hub/spawn-pending/test_user?next=%2Fhub%2Fuser%2Ftest_user%2F (test_user@::ffff:10.42.0.1) 45.67ms
[I 2022-09-06 00:54:25.595 JupyterHub pages:402] test_user is pending spawn
[I 2022-09-06 00:54:25.597 JupyterHub log:189] 200 GET /hub/spawn-pending/test_user?next=%2Fhub%2Fuser%2Ftest_user%2F (test_user@::ffff:10.42.0.1) 4.65ms
[I 2022-09-06 00:54:25.599 JupyterHub spawner:2361] PVC claim-test-5fuser already exists, so did not create new pvc.
[I 2022-09-06 00:54:25.604 JupyterHub spawner:2302] Attempting to create pod jupyter-test-5fuser, with timeout 3
[D 2022-09-06 00:54:25.798 JupyterHub spawner:2157] progress generator: jupyter-test-5fuser
[D 2022-09-06 00:54:27.640 JupyterHub spawner:2592] pod jupyter/jupyter-test-5fuser events before launch: 2022-09-06T00:54:25.618633Z [Normal] Successfully assigned jupyter/jupyter-test-5fuser to logan-dev
2022-09-06T00:54:26Z [Normal] Container image "jupyterhub/k8s-network-tools:1.2.0" already present on machine
2022-09-06T00:54:26Z [Normal] Created container block-cloud-metadata
2022-09-06T00:54:26Z [Normal] Started container block-cloud-metadata
2022-09-06T00:54:26Z [Normal] Container image "jupyterhub/k8s-singleuser-sample:1.2.0" already present on machine
2022-09-06T00:54:26Z [Normal] Created container notebook
2022-09-06T00:54:26Z [Normal] Started container notebook
[D 2022-09-06 00:54:27.648 JupyterHub spawner:1179] Polling subprocess every 30s
[I 2022-09-06 00:54:28.999 JupyterHub log:189] 200 GET /hub/api (@10.42.0.177) 1.97ms
[D 2022-09-06 00:54:29.013 JupyterHub base:283] Recording first activity for <APIToken('ff5a...', user='test_user')>
[D 2022-09-06 00:54:29.025 JupyterHub users:778] Activity for user test_user: 2022-09-06T00:54:27.460916Z
[D 2022-09-06 00:54:29.025 JupyterHub users:796] Activity on server test_user/: 2022-09-06T00:54:27.460916Z
[I 2022-09-06 00:54:29.034 JupyterHub log:189] 200 POST /hub/api/users/test_user/activity (test_user@10.42.0.177) 23.97ms
[D 2022-09-06 00:54:30.051 JupyterHub utils:225] Server at http://10.42.0.177:8888/user/test_user/ responded with 302
[I 2022-09-06 00:54:30.051 JupyterHub base:909] User test_user took 4.508 seconds to start
[I 2022-09-06 00:54:30.051 JupyterHub proxy:285] Adding user test_user to proxy /user/test_user/ => http://10.42.0.177:8888
[D 2022-09-06 00:54:30.052 JupyterHub proxy:832] Proxy: Fetching POST http://proxy-api:8001/api/routes/user/test_user
[I 2022-09-06 00:54:30.056 JupyterHub users:677] Server test_user is ready
[I 2022-09-06 00:54:30.057 JupyterHub log:189] 200 GET /hub/api/users/test_user/server/progress (test_user@::ffff:10.42.0.1) 4263.91ms
[I 2022-09-06 00:54:30.071 JupyterHub log:189] 302 GET /hub/spawn-pending/test_user?next=%2Fhub%2Fuser%2Ftest_user%2F -> /hub/user/test_user/ (test_user@::ffff:10.42.0.1) 3.49ms
[I 2022-09-06 00:54:30.080 JupyterHub log:189] 302 GET /hub/user/test_user/ -> /user/test_user/?redirects=1 (test_user@::ffff:10.42.0.1) 2.63ms
[D 2022-09-06 00:54:30.115 JupyterHub provider:409] Validating client id jupyterhub-user-test_user
[D 2022-09-06 00:54:30.117 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user, redirect_uri=/user/test_user/oauth_callback
[D 2022-09-06 00:54:30.119 JupyterHub auth:252] Skipping oauth confirmation for <User(test_user 2/3 running)> accessing Server at /user/test_user/
[D 2022-09-06 00:54:30.119 JupyterHub provider:409] Validating client id jupyterhub-user-test_user
[D 2022-09-06 00:54:30.120 JupyterHub provider:484] validate_redirect_uri: client_id=jupyterhub-user-test_user, redirect_uri=/user/test_user/oauth_callback
[D 2022-09-06 00:54:30.121 JupyterHub provider:231] Saving authorization code jupyterhub-user-test_user, Wut..., (), {}
[I 2022-09-06 00:54:30.133 JupyterHub log:189] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user&redirect_uri=%2Fuser%2Ftest_user%2Foauth_callback&response_type=code&state=[secret] -> /user/test_user/oauth_callback?code=[secret]&state=[secret] (test_user@::ffff:10.42.0.1) 20.01ms
[D 2022-09-06 00:54:30.153 JupyterHub provider:55] authenticate_client <oauthlib.Request SANITIZED>
[D 2022-09-06 00:54:30.160 JupyterHub provider:111] confirm_redirect_uri: client_id=jupyterhub-user-test_user, redirect_uri=/user/test_user/oauth_callback
[D 2022-09-06 00:54:30.161 JupyterHub provider:334] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 1209600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2022-09-06 00:54:30.171 JupyterHub provider:189] Deleting oauth code Wut... for jupyterhub-user-test_user
[I 2022-09-06 00:54:30.181 JupyterHub log:189] 200 POST /hub/api/oauth2/token (test_user@10.42.0.177) 31.61ms
[I 2022-09-06 00:54:30.203 JupyterHub log:189] 200 GET /hub/api/authorizations/token/[secret] (test_user@10.42.0.177) 15.12ms
[I 2022-09-06 00:54:32.036 JupyterHub log:189] 200 GET /hub/home (test_user@::ffff:10.42.0.1) 6.50ms
[D 2022-09-06 00:54:32.433 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:54:32.433 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:54:33.062 JupyterHub pages:652] No template for 503
[I 2022-09-06 00:54:33.063 JupyterHub log:189] 200 GET /hub/error/503?url=%2Fuser%2Ftest_user%2Ftest1 (@10.42.0.158) 1.76ms
[D 2022-09-06 00:54:34.097 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:54:34.097 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:54:42.452 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:54:42.452 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:54:44.140 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:54:44.140 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:54:52.468 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:54:52.468 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:54:54.185 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:54:54.185 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:54:59.093 JupyterHub proxy:832] Proxy: Fetching GET http://proxy-api:8001/api/routes
[I 2022-09-06 00:54:59.111 JupyterHub proxy:347] Checking routes
[D 2022-09-06 00:55:02.478 JupyterHub reflector:357] pods watcher timeout
[D 2022-09-06 00:55:02.478 JupyterHub reflector:282] Connecting pods watcher
[D 2022-09-06 00:55:04.245 JupyterHub reflector:357] events watcher timeout
[D 2022-09-06 00:55:04.246 JupyterHub reflector:282] Connecting events watcher
[D 2022-09-06 00:53:45.288 SingleUserNotebookApp application:174] Searching ['/home/jovyan', '/home/jovyan/.jupyter', '/home/jovyan/.local/etc/jupyter', '/opt/conda/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2022-09-06 00:53:45.288 SingleUserNotebookApp application:731] Looking for jupyter_config in /etc/jupyter
[D 2022-09-06 00:53:45.289 SingleUserNotebookApp application:731] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2022-09-06 00:53:45.289 SingleUserNotebookApp application:731] Looking for jupyter_config in /opt/conda/etc/jupyter
[D 2022-09-06 00:53:45.289 SingleUserNotebookApp application:731] Looking for jupyter_config in /home/jovyan/.local/etc/jupyter
[D 2022-09-06 00:53:45.289 SingleUserNotebookApp application:731] Looking for jupyter_config in /home/jovyan/.jupyter
[D 2022-09-06 00:53:45.290 SingleUserNotebookApp application:731] Looking for jupyter_config in /home/jovyan
[D 2022-09-06 00:53:45.292 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /etc/jupyter
[D 2022-09-06 00:53:45.293 SingleUserNotebookApp application:753] Loaded config file: /etc/jupyter/jupyter_notebook_config.py
[D 2022-09-06 00:53:45.293 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2022-09-06 00:53:45.293 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /opt/conda/etc/jupyter
[D 2022-09-06 00:53:45.294 SingleUserNotebookApp application:753] Loaded config file: /opt/conda/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:53:45.294 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /home/jovyan/.local/etc/jupyter
[D 2022-09-06 00:53:45.294 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /home/jovyan/.jupyter
[D 2022-09-06 00:53:45.294 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /home/jovyan
[W 2022-09-06 00:53:45.296 SingleUserNotebookApp configurable:193] Config option `open_browser` not recognized by `SingleUserNotebookApp`. Did you mean `browser`?
[D 2022-09-06 00:53:45.308 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:53:45.309 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:53:45.310 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/opt/conda/etc/jupyter/jupyter_notebook_config.d/jupyterlab.json
/opt/conda/etc/jupyter/jupyter_notebook_config.d/nbgitpuller.json
/opt/conda/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:53:45.311 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/home/jovyan/.local/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:53:45.312 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/home/jovyan/.jupyter/jupyter_notebook_config.json
[I 2022-09-06 00:53:45.321 SingleUserNotebookApp notebookapp:1593] Authentication of /metrics is OFF, since other authentication is disabled.
[W 2022-09-06 00:53:46.774 LabApp] 'ip' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[W 2022-09-06 00:53:46.774 LabApp] 'port' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[W 2022-09-06 00:53:46.774 LabApp] 'port' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[W 2022-09-06 00:53:46.774 LabApp] 'port' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[D 2022-09-06 00:53:46.781 LabApp] Config changed: {'NotebookApp': {'open_browser': False, 'nbserver_extensions': <LazyConfigValue {'update': {'jupyterlab': True, 'nbgitpuller': True}}>}, 'ServerApp': {'ip': '0.0.0.0', 'port': 8888}, 'FileContentsManager': {'delete_to_trash': False}, 'SingleUserNotebookApp': {'ip': '0.0.0.0', 'port': 8888}, 'Application': {'log_level': 10}}
[I 2022-09-06 00:53:46.783 LabApp] JupyterLab extension loaded from /opt/conda/lib/python3.9/site-packages/jupyterlab
[I 2022-09-06 00:53:46.783 LabApp] JupyterLab application directory is /opt/conda/share/jupyter/lab
Patching auth into jupyter_server.base.handlers.JupyterHandler(jupyter_server.base.handlers.AuthenticatedHandler) -> JupyterHandler(jupyterhub.singleuser.mixins.HubAuthenticatedHandler, jupyter_server.base.handlers.AuthenticatedHandler)
[I 2022-09-06 00:53:46.803 SingleUserNotebookApp mixins:576] Starting jupyterhub-singleuser server version 1.4.2
[W 2022-09-06 00:53:46.814 SingleUserNotebookApp _version:70] jupyterhub version 1.5.0 != jupyterhub-singleuser version 1.4.2. This could cause failure to authenticate and result in redirect loops!
[I 2022-09-06 00:53:46.815 SingleUserNotebookApp notebookapp:2302] Serving notebooks from local directory: /home/jovyan
[I 2022-09-06 00:53:46.815 SingleUserNotebookApp notebookapp:2302] Jupyter Notebook 6.4.5 is running at:
[I 2022-09-06 00:53:46.815 SingleUserNotebookApp notebookapp:2302] http://jupyter-test-5fuser--test1:8888/user/test_user/test1/
[I 2022-09-06 00:53:46.815 SingleUserNotebookApp notebookapp:2303] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[I 2022-09-06 00:53:46.821 SingleUserNotebookApp mixins:556] Updating Hub with activity every 300 seconds
[D 2022-09-06 00:53:46.821 SingleUserNotebookApp mixins:518] Notifying Hub of activity 2022-09-06T00:53:45.320667Z
[I 2022-09-06 00:53:47.044 SingleUserNotebookApp log:189] 302 GET /user/test_user/test1/ -> /user/test_user/test1/tree? (@10.42.0.162) 1.19ms
[I 2022-09-06 00:53:47.070 SingleUserNotebookApp log:189] 302 GET /user/test_user/test1 -> /user/test_user/test1/tree? (@::ffff:10.42.0.1) 0.84ms
[D 2022-09-06 00:53:47.078 SingleUserNotebookApp auth:505] No user identified
[D 2022-09-06 00:53:47.081 SingleUserNotebookApp auth:844] Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user-test1&redirect_uri=%2Fuser%2Ftest_user%2Ftest1%2Foauth_callback&response_type=code&state=eyJ1dWlkIjogIjIzYzAxMDViMjk2NjRmMjg5ZTI5NjY1Yjc0NDkxNmQzIiwgIm5leHRfdXJsIjogIi91c2VyL3Rlc3RfdXNlci90ZXN0MS90cmVlPyJ9
[I 2022-09-06 00:53:47.081 SingleUserNotebookApp log:189] 302 GET /user/test_user/test1/tree? -> /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user-test1&redirect_uri=%2Fuser%2Ftest_user%2Ftest1%2Foauth_callback&response_type=code&state=[secret] (@::ffff:10.42.0.1) 3.73ms
[D 2022-09-06 00:53:47.118 SingleUserNotebookApp auth:505] No user identified
[D 2022-09-06 00:53:47.160 SingleUserNotebookApp auth:310] HubAuth cache miss: token:2f790d1fbd5a4735821fe63ac5858882:krorJRs3UMGOS6cF9ngqBsRRdWmXpR
[D 2022-09-06 00:53:47.182 SingleUserNotebookApp auth:316] Received request from Hub user {'kind': 'user', 'name': 'test_user', 'admin': False, 'groups': [], 'server': None, 'pending': None, 'created': '2022-09-06T00:44:41.422381Z', 'last_activity': '2022-09-06T00:53:47.171922Z', 'servers': None}
[I 2022-09-06 00:53:47.182 SingleUserNotebookApp auth:992] Logged-in user {'kind': 'user', 'name': 'test_user', 'admin': False, 'groups': [], 'server': None, 'pending': None, 'created': '2022-09-06T00:44:41.422381Z', 'last_activity': '2022-09-06T00:53:47.171922Z', 'servers': None}
[D 2022-09-06 00:53:47.183 SingleUserNotebookApp auth:748] Setting oauth cookie for ::ffff:10.42.0.1: jupyterhub-user-test_user-test1, {'path': '/user/test_user/test1/', 'httponly': True}
[I 2022-09-06 00:53:47.184 SingleUserNotebookApp log:189] 302 GET /user/test_user/test1/oauth_callback?code=[secret]&state=[secret] -> /user/test_user/test1/tree? (@::ffff:10.42.0.1) 65.95ms
[D 2022-09-06 00:53:47.193 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:53:47.194 SingleUserNotebookApp handlers:251] Using contents: services/contents
[D 2022-09-06 00:53:47.261 SingleUserNotebookApp handlers:836] Path base/images/favicon.ico served from /opt/conda/lib/python3.9/site-packages/notebook/static/base/images/favicon.ico
[D 2022-09-06 00:53:47.261 SingleUserNotebookApp handlers:836] Path components/jquery-ui/themes/smoothness/jquery-ui.min.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css
[D 2022-09-06 00:53:47.262 SingleUserNotebookApp handlers:836] Path components/jquery-typeahead/dist/jquery.typeahead.min.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/jquery-typeahead/dist/jquery.typeahead.min.css
[D 2022-09-06 00:53:47.262 SingleUserNotebookApp handlers:836] Path style/style.min.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/style/style.min.css
[D 2022-09-06 00:53:47.263 SingleUserNotebookApp handlers:836] Path components/es6-promise/promise.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/es6-promise/promise.min.js
[D 2022-09-06 00:53:47.263 SingleUserNotebookApp handlers:836] Path components/react/react.production.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/react/react.production.min.js
[D 2022-09-06 00:53:47.263 SingleUserNotebookApp handlers:836] Path components/react/react-dom.production.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/react/react-dom.production.min.js
[D 2022-09-06 00:53:47.264 SingleUserNotebookApp handlers:836] Path components/create-react-class/index.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/create-react-class/index.js
[D 2022-09-06 00:53:47.264 SingleUserNotebookApp handlers:836] Path components/requirejs/require.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/requirejs/require.js
[D 2022-09-06 00:53:47.267 SingleUserNotebookApp handlers:836] Path tree/js/main.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/tree/js/main.min.js
[I 2022-09-06 00:53:47.277 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/tree? (test_user@::ffff:10.42.0.1) 84.91ms
[D 2022-09-06 00:53:47.324 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:53:47.325 SingleUserNotebookApp handlers:836] Path custom.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/custom/custom.css
[D 2022-09-06 00:53:47.326 SingleUserNotebookApp log:189] 304 GET /user/test_user/test1/custom/custom.css (test_user@::ffff:10.42.0.1) 2.19ms
[D 2022-09-06 00:53:47.446 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:53:47.446 SingleUserNotebookApp handlers:836] Path services/contents.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/services/contents.js
[D 2022-09-06 00:53:47.447 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/static/services/contents.js?v=20220906005345 (test_user@::ffff:10.42.0.1) 1.42ms
[D 2022-09-06 00:53:47.556 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:53:47.557 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 00:53:47.558 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/usr/local/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 00:53:47.559 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/opt/conda/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 00:53:47.559 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/home/jovyan/.local/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 00:53:47.560 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/home/jovyan/.jupyter/nbconfig/tree.json
[I 2022-09-06 00:53:47.561 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/api/config/tree?_=1662425627429 (test_user@::ffff:10.42.0.1) 5.01ms
[D 2022-09-06 00:53:47.562 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:53:47.562 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/etc/jupyter/nbconfig/common.json
[D 2022-09-06 00:53:47.563 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/usr/local/etc/jupyter/nbconfig/common.json
[D 2022-09-06 00:53:47.564 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/opt/conda/etc/jupyter/nbconfig/common.json
[D 2022-09-06 00:53:47.564 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/home/jovyan/.local/etc/jupyter/nbconfig/common.json
[D 2022-09-06 00:53:47.565 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/home/jovyan/.jupyter/nbconfig/common.json
[I 2022-09-06 00:53:47.566 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/api/config/common?_=1662425627430 (test_user@::ffff:10.42.0.1) 4.32ms
[D 2022-09-06 00:53:47.574 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 00:53:47.575 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/api/terminals?_=1662425627431 (test_user@::ffff:10.42.0.1) 1.65ms
[D 2022-09-06 00:53:47.576 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 00:53:47.578 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/api/sessions?_=1662425627432 (test_user@::ffff:10.42.0.1) 2.50ms
[D 2022-09-06 00:53:47.579 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:53:47.580 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 00:53:47.581 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/api/terminals?_=1662425627433 (test_user@::ffff:10.42.0.1) 2.40ms
[D 2022-09-06 00:53:47.582 SingleUserNotebookApp kernelspec:218] Found kernel python3 in /opt/conda/share/jupyter/kernels
[D 2022-09-06 00:53:47.806 SingleUserNotebookApp log:189] 304 GET /user/test_user/test1/api/kernelspecs (test_user@::ffff:10.42.0.1) 226.15ms
[D 2022-09-06 00:53:47.810 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:53:47.812 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:53:47.812 SingleUserNotebookApp handlers:836] Path custom.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/custom/custom.js
[D 2022-09-06 00:53:47.814 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/custom/custom.js?v=20220906005345 (test_user@::ffff:10.42.0.1) 5.33ms
[I 2022-09-06 00:53:47.817 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/api/contents?type=directory&_=1662425627434 (test_user@::ffff:10.42.0.1) 6.27ms
[D 2022-09-06 00:54:20.595 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 00:54:20.596 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/api/sessions?_=1662425627435 (test_user@::ffff:10.42.0.1) 1.17ms
[D 2022-09-06 00:54:20.597 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 00:54:20.598 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/api/terminals?_=1662425627436 (test_user@::ffff:10.42.0.1) 1.12ms
[D 2022-09-06 00:54:20.611 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 00:54:20.612 SingleUserNotebookApp log:189] 200 GET /user/test_user/test1/api/contents?type=directory&_=1662425627437 (test_user@::ffff:10.42.0.1) 1.58ms
[D 2022-09-06 00:58:45.218 SingleUserNotebookApp mixins:518] Notifying Hub of activity 2022-09-06T00:54:20.612519Z
[D 2022-09-06 01:03:11.426 SingleUserNotebookApp application:174] Searching ['/home/jovyan', '/home/jovyan/.jupyter', '/home/jovyan/.local/etc/jupyter', '/opt/conda/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2022-09-06 01:03:11.426 SingleUserNotebookApp application:731] Looking for jupyter_config in /etc/jupyter
[D 2022-09-06 01:03:11.427 SingleUserNotebookApp application:731] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2022-09-06 01:03:11.427 SingleUserNotebookApp application:731] Looking for jupyter_config in /opt/conda/etc/jupyter
[D 2022-09-06 01:03:11.427 SingleUserNotebookApp application:731] Looking for jupyter_config in /home/jovyan/.local/etc/jupyter
[D 2022-09-06 01:03:11.427 SingleUserNotebookApp application:731] Looking for jupyter_config in /home/jovyan/.jupyter
[D 2022-09-06 01:03:11.427 SingleUserNotebookApp application:731] Looking for jupyter_config in /home/jovyan
[D 2022-09-06 01:03:11.428 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /etc/jupyter
[D 2022-09-06 01:03:11.428 SingleUserNotebookApp application:753] Loaded config file: /etc/jupyter/jupyter_notebook_config.py
[D 2022-09-06 01:03:11.428 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2022-09-06 01:03:11.429 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /opt/conda/etc/jupyter
[D 2022-09-06 01:03:11.429 SingleUserNotebookApp application:753] Loaded config file: /opt/conda/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 01:03:11.429 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /home/jovyan/.local/etc/jupyter
[D 2022-09-06 01:03:11.429 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /home/jovyan/.jupyter
[D 2022-09-06 01:03:11.429 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /home/jovyan
[W 2022-09-06 01:03:11.430 SingleUserNotebookApp configurable:193] Config option `open_browser` not recognized by `SingleUserNotebookApp`. Did you mean `browser`?
[D 2022-09-06 01:03:11.448 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 01:03:11.449 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 01:03:11.450 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/opt/conda/etc/jupyter/jupyter_notebook_config.d/jupyterlab.json
/opt/conda/etc/jupyter/jupyter_notebook_config.d/nbgitpuller.json
/opt/conda/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 01:03:11.452 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/home/jovyan/.local/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 01:03:11.453 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/home/jovyan/.jupyter/jupyter_notebook_config.json
[I 2022-09-06 01:03:11.464 SingleUserNotebookApp notebookapp:1593] Authentication of /metrics is OFF, since other authentication is disabled.
[W 2022-09-06 01:03:12.952 LabApp] 'ip' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[W 2022-09-06 01:03:12.952 LabApp] 'port' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[W 2022-09-06 01:03:12.952 LabApp] 'port' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[W 2022-09-06 01:03:12.952 LabApp] 'port' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[D 2022-09-06 01:03:12.960 LabApp] Config changed: {'NotebookApp': {'open_browser': False, 'nbserver_extensions': <LazyConfigValue {'update': {'jupyterlab': True, 'nbgitpuller': True}}>}, 'ServerApp': {'ip': '0.0.0.0', 'port': 8888}, 'FileContentsManager': {'delete_to_trash': False}, 'SingleUserNotebookApp': {'ip': '0.0.0.0', 'port': 8888}, 'Application': {'log_level': 10}}
[I 2022-09-06 01:03:12.961 LabApp] JupyterLab extension loaded from /opt/conda/lib/python3.9/site-packages/jupyterlab
[I 2022-09-06 01:03:12.961 LabApp] JupyterLab application directory is /opt/conda/share/jupyter/lab
Patching auth into jupyter_server.base.handlers.JupyterHandler(jupyter_server.base.handlers.AuthenticatedHandler) -> JupyterHandler(jupyterhub.singleuser.mixins.HubAuthenticatedHandler, jupyter_server.base.handlers.AuthenticatedHandler)
[I 2022-09-06 01:03:12.970 SingleUserNotebookApp mixins:576] Starting jupyterhub-singleuser server version 1.4.2
[W 2022-09-06 01:03:12.977 SingleUserNotebookApp _version:70] jupyterhub version 1.5.0 != jupyterhub-singleuser version 1.4.2. This could cause failure to authenticate and result in redirect loops!
[I 2022-09-06 01:03:12.977 SingleUserNotebookApp notebookapp:2302] Serving notebooks from local directory: /home/jovyan
[I 2022-09-06 01:03:12.977 SingleUserNotebookApp notebookapp:2302] Jupyter Notebook 6.4.5 is running at:
[I 2022-09-06 01:03:12.977 SingleUserNotebookApp notebookapp:2302] http://jupyter-test-5fuser--test2:8888/user/test_user/test2/
[I 2022-09-06 01:03:12.977 SingleUserNotebookApp notebookapp:2303] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[I 2022-09-06 01:03:12.981 SingleUserNotebookApp mixins:556] Updating Hub with activity every 300 seconds
[D 2022-09-06 01:03:12.982 SingleUserNotebookApp mixins:518] Notifying Hub of activity 2022-09-06T01:03:11.464045Z
[I 2022-09-06 01:03:13.037 SingleUserNotebookApp log:189] 302 GET /user/test_user/test2/ -> /user/test_user/test2/tree? (@10.42.0.162) 1.67ms
[I 2022-09-06 01:03:13.068 SingleUserNotebookApp log:189] 302 GET /user/test_user/test2 -> /user/test_user/test2/tree? (@::ffff:10.42.0.1) 1.12ms
[D 2022-09-06 01:03:13.076 SingleUserNotebookApp auth:505] No user identified
[D 2022-09-06 01:03:13.077 SingleUserNotebookApp auth:844] Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user-test2&redirect_uri=%2Fuser%2Ftest_user%2Ftest2%2Foauth_callback&response_type=code&state=eyJ1dWlkIjogIjI0NWJiOTE3MjE1MjQ1ZTg4NmIzMjlhMjZhNmIwYzM1IiwgIm5leHRfdXJsIjogIi91c2VyL3Rlc3RfdXNlci90ZXN0Mi90cmVlPyJ9
[I 2022-09-06 01:03:13.078 SingleUserNotebookApp log:189] 302 GET /user/test_user/test2/tree? -> /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user-test2&redirect_uri=%2Fuser%2Ftest_user%2Ftest2%2Foauth_callback&response_type=code&state=[secret] (@::ffff:10.42.0.1) 2.76ms
[D 2022-09-06 01:03:13.114 SingleUserNotebookApp auth:505] No user identified
[D 2022-09-06 01:03:13.156 SingleUserNotebookApp auth:310] HubAuth cache miss: token:2f790d1fbd5a4735821fe63ac5858882:PHpLvIjCGAbqM5TzoJu41SlKaf2C2D
[D 2022-09-06 01:03:13.179 SingleUserNotebookApp auth:316] Received request from Hub user {'kind': 'user', 'name': 'test_user', 'admin': False, 'groups': [], 'server': '/user/test_user/', 'pending': None, 'created': '2022-09-06T00:44:41.422381Z', 'last_activity': '2022-09-06T01:03:13.170179Z', 'servers': None}
[I 2022-09-06 01:03:13.180 SingleUserNotebookApp auth:992] Logged-in user {'kind': 'user', 'name': 'test_user', 'admin': False, 'groups': [], 'server': '/user/test_user/', 'pending': None, 'created': '2022-09-06T00:44:41.422381Z', 'last_activity': '2022-09-06T01:03:13.170179Z', 'servers': None}
[D 2022-09-06 01:03:13.180 SingleUserNotebookApp auth:748] Setting oauth cookie for ::ffff:10.42.0.1: jupyterhub-user-test_user-test2, {'path': '/user/test_user/test2/', 'httponly': True}
[I 2022-09-06 01:03:13.181 SingleUserNotebookApp log:189] 302 GET /user/test_user/test2/oauth_callback?code=[secret]&state=[secret] -> /user/test_user/test2/tree? (@::ffff:10.42.0.1) 67.25ms
[D 2022-09-06 01:03:13.191 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 01:03:13.192 SingleUserNotebookApp handlers:251] Using contents: services/contents
[D 2022-09-06 01:03:13.278 SingleUserNotebookApp handlers:836] Path base/images/favicon.ico served from /opt/conda/lib/python3.9/site-packages/notebook/static/base/images/favicon.ico
[D 2022-09-06 01:03:13.279 SingleUserNotebookApp handlers:836] Path components/jquery-ui/themes/smoothness/jquery-ui.min.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css
[D 2022-09-06 01:03:13.280 SingleUserNotebookApp handlers:836] Path components/jquery-typeahead/dist/jquery.typeahead.min.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/jquery-typeahead/dist/jquery.typeahead.min.css
[D 2022-09-06 01:03:13.280 SingleUserNotebookApp handlers:836] Path style/style.min.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/style/style.min.css
[D 2022-09-06 01:03:13.282 SingleUserNotebookApp handlers:836] Path components/es6-promise/promise.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/es6-promise/promise.min.js
[D 2022-09-06 01:03:13.283 SingleUserNotebookApp handlers:836] Path components/react/react.production.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/react/react.production.min.js
[D 2022-09-06 01:03:13.283 SingleUserNotebookApp handlers:836] Path components/react/react-dom.production.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/react/react-dom.production.min.js
[D 2022-09-06 01:03:13.284 SingleUserNotebookApp handlers:836] Path components/create-react-class/index.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/create-react-class/index.js
[D 2022-09-06 01:03:13.285 SingleUserNotebookApp handlers:836] Path components/requirejs/require.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/requirejs/require.js
[D 2022-09-06 01:03:13.289 SingleUserNotebookApp handlers:836] Path tree/js/main.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/tree/js/main.min.js
[I 2022-09-06 01:03:13.298 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/tree? (test_user@::ffff:10.42.0.1) 107.22ms
[D 2022-09-06 01:03:13.340 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 01:03:13.341 SingleUserNotebookApp handlers:836] Path custom.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/custom/custom.css
[D 2022-09-06 01:03:13.342 SingleUserNotebookApp log:189] 304 GET /user/test_user/test2/custom/custom.css (test_user@::ffff:10.42.0.1) 1.83ms
[D 2022-09-06 01:03:13.531 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 01:03:13.532 SingleUserNotebookApp handlers:836] Path services/contents.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/services/contents.js
[D 2022-09-06 01:03:13.532 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/static/services/contents.js?v=20220906010311 (test_user@::ffff:10.42.0.1) 1.47ms
[D 2022-09-06 01:03:13.561 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 01:03:13.562 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 01:03:13.563 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/usr/local/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 01:03:13.564 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/opt/conda/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 01:03:13.565 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/home/jovyan/.local/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 01:03:13.566 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/home/jovyan/.jupyter/nbconfig/tree.json
[I 2022-09-06 01:03:13.567 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/api/config/tree?_=1662426193452 (test_user@::ffff:10.42.0.1) 6.71ms
[D 2022-09-06 01:03:13.568 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 01:03:13.569 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/etc/jupyter/nbconfig/common.json
[D 2022-09-06 01:03:13.569 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/usr/local/etc/jupyter/nbconfig/common.json
[D 2022-09-06 01:03:13.570 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/opt/conda/etc/jupyter/nbconfig/common.json
[D 2022-09-06 01:03:13.570 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/home/jovyan/.local/etc/jupyter/nbconfig/common.json
[D 2022-09-06 01:03:13.571 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/home/jovyan/.jupyter/nbconfig/common.json
[I 2022-09-06 01:03:13.572 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/api/config/common?_=1662426193453 (test_user@::ffff:10.42.0.1) 4.66ms
[D 2022-09-06 01:03:13.573 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 01:03:13.574 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 01:03:13.575 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 01:03:13.576 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 01:03:13.577 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/api/terminals?_=1662426193454 (test_user@::ffff:10.42.0.1) 4.40ms
[D 2022-09-06 01:03:13.578 SingleUserNotebookApp kernelspec:218] Found kernel python3 in /opt/conda/share/jupyter/kernels
[D 2022-09-06 01:03:13.792 SingleUserNotebookApp log:189] 304 GET /user/test_user/test2/api/kernelspecs (test_user@::ffff:10.42.0.1) 218.47ms
[I 2022-09-06 01:03:13.793 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/api/sessions?_=1662426193455 (test_user@::ffff:10.42.0.1) 218.66ms
[I 2022-09-06 01:03:13.794 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/api/terminals?_=1662426193456 (test_user@::ffff:10.42.0.1) 218.32ms
[D 2022-09-06 01:03:13.796 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 01:03:13.797 SingleUserNotebookApp handlers:836] Path custom.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/custom/custom.js
[D 2022-09-06 01:03:13.798 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/custom/custom.js?v=20220906010311 (test_user@::ffff:10.42.0.1) 2.20ms
[D 2022-09-06 01:03:13.810 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 01:03:13.813 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/api/contents?type=directory&_=1662426193457 (test_user@::ffff:10.42.0.1) 3.62ms
[D 2022-09-06 01:08:13.627 SingleUserNotebookApp mixins:518] Notifying Hub of activity 2022-09-06T01:03:13.812692Z
[D 2022-09-06 01:11:08.995 SingleUserNotebookApp auth:310] HubAuth cache miss: token:2f790d1fbd5a4735821fe63ac5858882:PHpLvIjCGAbqM5TzoJu41SlKaf2C2D
[D 2022-09-06 01:11:09.019 SingleUserNotebookApp auth:316] Received request from Hub user {'kind': 'user', 'name': 'test_user', 'admin': False, 'groups': [], 'server': '/user/test_user/', 'pending': None, 'created': '2022-09-06T00:44:41.422381Z', 'last_activity': '2022-09-06T01:11:09.013069Z', 'servers': None}
[D 2022-09-06 01:11:09.020 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 01:11:09.020 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/api/sessions?_=1662426193458 (test_user@::ffff:10.42.0.1) 26.43ms
[D 2022-09-06 01:11:09.021 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 01:11:09.022 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/api/terminals?_=1662426193459 (test_user@::ffff:10.42.0.1) 1.12ms
[D 2022-09-06 01:11:09.042 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 01:11:09.043 SingleUserNotebookApp log:189] 200 GET /user/test_user/test2/api/contents?type=directory&_=1662426193460 (test_user@::ffff:10.42.0.1) 1.59ms
[D 2022-09-06 01:13:19.371 SingleUserNotebookApp mixins:518] Notifying Hub of activity 2022-09-06T01:11:09.042796Z
00:41:51.230 [ConfigProxy] info: Adding route / -> http://hub:8081
00:41:51.239 [ConfigProxy] info: Proxying http://*:8000 to http://hub:8081
00:41:51.239 [ConfigProxy] info: Proxy API at http://*:8001/api/routes
00:41:51.244 [ConfigProxy] info: Route added / -> http://hub:8081
00:41:59.086 [ConfigProxy] info: 200 GET /api/routes
00:41:59.089 [ConfigProxy] info: 200 GET /api/routes
00:41:59.091 [ConfigProxy] info: Adding route / -> http://hub:8081
00:41:59.091 [ConfigProxy] info: Route added / -> http://hub:8081
00:41:59.092 [ConfigProxy] info: 201 POST /api/routes/
00:42:59.098 [ConfigProxy] info: 200 GET /api/routes
00:43:59.099 [ConfigProxy] info: 200 GET /api/routes
00:44:35.165 [ConfigProxy] debug: PROXY WEB / to http://hub:8081
00:44:35.179 [ConfigProxy] debug: Not recording activity for status 302 on /
00:44:35.184 [ConfigProxy] debug: PROXY WEB /hub/ to http://hub:8081
00:44:35.189 [ConfigProxy] debug: Not recording activity for status 302 on /
00:44:35.195 [ConfigProxy] debug: PROXY WEB /hub/login to http://hub:8081
00:44:35.273 [ConfigProxy] debug: PROXY WEB /hub/static/css/style.min.css to http://hub:8081
00:44:35.283 [ConfigProxy] debug: PROXY WEB /hub/static/components/requirejs/require.js to http://hub:8081
00:44:35.285 [ConfigProxy] debug: PROXY WEB /hub/static/components/jquery/dist/jquery.min.js to http://hub:8081
00:44:35.286 [ConfigProxy] debug: PROXY WEB /hub/static/components/bootstrap/dist/js/bootstrap.min.js to http://hub:8081
00:44:35.368 [ConfigProxy] debug: PROXY WEB /hub/logo to http://hub:8081
00:44:35.657 [ConfigProxy] debug: PROXY WEB /hub/static/favicon.ico to http://hub:8081
00:44:41.409 [ConfigProxy] debug: PROXY WEB /hub/login to http://hub:8081
00:44:41.410 [ConfigProxy] debug: PROXY WEB /hub/static/components/font-awesome/fonts/fontawesome-webfont.woff2 to http://hub:8081
00:44:41.453 [ConfigProxy] debug: Not recording activity for status 302 on /
00:44:41.462 [ConfigProxy] debug: PROXY WEB /hub/ to http://hub:8081
00:44:41.523 [ConfigProxy] debug: Not recording activity for status 302 on /
00:44:41.530 [ConfigProxy] debug: PROXY WEB /hub/spawn to http://hub:8081
00:44:41.579 [ConfigProxy] debug: Not recording activity for status 302 on /
00:44:41.585 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user to http://hub:8081
00:44:41.885 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/server/progress to http://hub:8081
00:44:51.548 [ConfigProxy] info: Adding route /user/test_user -> http://10.42.0.164:8888
00:44:51.548 [ConfigProxy] info: Route added /user/test_user -> http://10.42.0.164:8888
00:44:51.549 [ConfigProxy] info: 201 POST /api/routes/user/test_user
00:44:51.560 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user to http://hub:8081
00:44:51.566 [ConfigProxy] debug: Not recording activity for status 302 on /
00:44:51.571 [ConfigProxy] debug: PROXY WEB /user/test_user/ to http://10.42.0.164:8888
00:44:51.575 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:44:51.579 [ConfigProxy] debug: PROXY WEB /user/test_user/tree to http://10.42.0.164:8888
00:44:51.584 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:44:51.590 [ConfigProxy] debug: PROXY WEB /hub/api/oauth2/authorize to http://hub:8081
00:44:51.610 [ConfigProxy] debug: Not recording activity for status 302 on /
00:44:51.618 [ConfigProxy] debug: PROXY WEB /user/test_user/oauth_callback to http://10.42.0.164:8888
00:44:51.706 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:44:51.731 [ConfigProxy] debug: PROXY WEB /user/test_user/tree to http://10.42.0.164:8888
00:44:51.853 [ConfigProxy] debug: PROXY WEB /user/test_user/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css to http://10.42.0.164:8888
00:44:51.865 [ConfigProxy] debug: PROXY WEB /user/test_user/static/components/jquery-typeahead/dist/jquery.typeahead.min.css to http://10.42.0.164:8888
00:44:51.866 [ConfigProxy] debug: PROXY WEB /user/test_user/static/style/style.min.css to http://10.42.0.164:8888
00:44:51.867 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.css to http://10.42.0.164:8888
00:44:51.868 [ConfigProxy] debug: PROXY WEB /user/test_user/static/components/es6-promise/promise.min.js to http://10.42.0.164:8888
00:44:51.870 [ConfigProxy] debug: PROXY WEB /user/test_user/static/components/react/react.production.min.js to http://10.42.0.164:8888
00:44:51.871 [ConfigProxy] debug: PROXY WEB /user/test_user/static/components/react/react-dom.production.min.js to http://10.42.0.164:8888
00:44:51.890 [ConfigProxy] debug: PROXY WEB /user/test_user/static/components/create-react-class/index.js to http://10.42.0.164:8888
00:44:51.895 [ConfigProxy] debug: PROXY WEB /user/test_user/static/components/requirejs/require.js to http://10.42.0.164:8888
00:44:51.921 [ConfigProxy] debug: PROXY WEB /user/test_user/static/tree/js/main.min.js to http://10.42.0.164:8888
00:44:52.090 [ConfigProxy] debug: PROXY WEB /user/test_user/static/services/contents.js to http://10.42.0.164:8888
00:44:52.131 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/tree to http://10.42.0.164:8888
00:44:52.133 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/common to http://10.42.0.164:8888
00:44:52.141 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.164:8888
00:44:52.144 [ConfigProxy] debug: PROXY WEB /user/test_user/api/kernelspecs to http://10.42.0.164:8888
00:44:52.146 [ConfigProxy] debug: PROXY WEB /user/test_user/api/sessions to http://10.42.0.164:8888
00:44:52.152 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.164:8888
00:44:52.205 [ConfigProxy] debug: PROXY WEB /user/test_user/static/components/font-awesome/fonts/fontawesome-webfont.woff2 to http://10.42.0.164:8888
00:44:52.209 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.js to http://10.42.0.164:8888
00:44:52.361 [ConfigProxy] debug: PROXY WEB /user/test_user/api/contents to http://10.42.0.164:8888
00:44:52.393 [ConfigProxy] debug: PROXY WEB /user/test_user/static/base/images/favicon.ico to http://10.42.0.164:8888
00:44:56.671 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:44:56.905 [ConfigProxy] debug: PROXY WEB /hub/static/js/home.js to http://hub:8081
00:44:56.929 [ConfigProxy] debug: PROXY WEB /hub/static/components/moment/moment.js to http://hub:8081
00:44:56.930 [ConfigProxy] debug: PROXY WEB /hub/static/js/jhapi.js to http://hub:8081
00:44:56.951 [ConfigProxy] debug: PROXY WEB /hub/static/js/utils.js to http://hub:8081
00:44:58.263 [ConfigProxy] debug: PROXY WEB /user/test_user to http://10.42.0.164:8888
00:44:58.267 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:44:58.272 [ConfigProxy] debug: PROXY WEB /user/test_user/tree to http://10.42.0.164:8888
00:44:58.278 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:44:58.313 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.css to http://10.42.0.164:8888
00:44:58.317 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:44:58.511 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/tree to http://10.42.0.164:8888
00:44:58.512 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/common to http://10.42.0.164:8888
00:44:58.516 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.164:8888
00:44:58.520 [ConfigProxy] debug: PROXY WEB /user/test_user/api/kernelspecs to http://10.42.0.164:8888
00:44:58.521 [ConfigProxy] debug: PROXY WEB /user/test_user/api/sessions to http://10.42.0.164:8888
00:44:58.523 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.164:8888
00:44:58.531 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:44:58.539 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.js to http://10.42.0.164:8888
00:44:58.543 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:44:58.551 [ConfigProxy] debug: PROXY WEB /user/test_user/api/contents to http://10.42.0.164:8888
00:44:59.098 [ConfigProxy] info: 200 GET /api/routes
00:45:22.818 [ConfigProxy] debug: PROXY WEB /user/test_user/api/sessions to http://10.42.0.164:8888
00:45:22.819 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.164:8888
00:45:22.834 [ConfigProxy] debug: PROXY WEB /user/test_user/api/contents to http://10.42.0.164:8888
00:45:24.037 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:45:24.045 [ConfigProxy] debug: Not recording activity for status 304 on /
00:45:56.049 [ConfigProxy] debug: PROXY WEB /hub/spawn/test_user/test1 to http://hub:8081
00:45:56.112 [ConfigProxy] debug: Not recording activity for status 302 on /
00:45:56.118 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user/test1 to http://hub:8081
00:45:56.338 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/servers/test1/progress to http://hub:8081
00:45:59.098 [ConfigProxy] info: 200 GET /api/routes
00:46:45.369 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:46:47.525 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/servers/test1 to http://hub:8081
00:46:52.075 [ConfigProxy] debug: PROXY WEB /hub/spawn/test_user/test1 to http://hub:8081
00:46:52.140 [ConfigProxy] debug: Not recording activity for status 302 on /
00:46:52.148 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user/test1 to http://hub:8081
00:46:52.157 [ConfigProxy] debug: Not recording activity for status 304 on /
00:46:52.368 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/servers/test1/progress to http://hub:8081
00:46:59.098 [ConfigProxy] info: 200 GET /api/routes
00:47:01.654 [ConfigProxy] info: Adding route /user/test_user/test1 -> http://10.42.0.169:8888
00:47:01.654 [ConfigProxy] info: Route added /user/test_user/test1 -> http://10.42.0.169:8888
00:47:01.654 [ConfigProxy] info: 201 POST /api/routes/user/test_user/test1
00:47:01.666 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user/test1 to http://hub:8081
00:47:01.671 [ConfigProxy] debug: Not recording activity for status 302 on /
00:47:01.676 [ConfigProxy] debug: PROXY WEB /user/test_user/test1 to http://10.42.0.169:8888
00:47:01.679 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:47:01.685 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/tree to http://10.42.0.169:8888
00:47:01.691 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:47:01.697 [ConfigProxy] debug: PROXY WEB /hub/api/oauth2/authorize to http://hub:8081
00:47:01.719 [ConfigProxy] debug: Not recording activity for status 302 on /
00:47:01.725 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/oauth_callback to http://10.42.0.169:8888
00:47:01.780 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:47:01.786 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/tree to http://10.42.0.169:8888
00:47:01.898 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css to http://10.42.0.169:8888
00:47:01.899 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/components/jquery-typeahead/dist/jquery.typeahead.min.css to http://10.42.0.169:8888
00:47:01.900 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/style/style.min.css to http://10.42.0.169:8888
00:47:01.903 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.css to http://10.42.0.169:8888
00:47:01.904 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/components/es6-promise/promise.min.js to http://10.42.0.169:8888
00:47:01.906 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/components/react/react.production.min.js to http://10.42.0.169:8888
00:47:01.912 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/components/react/react-dom.production.min.js to http://10.42.0.169:8888
00:47:01.926 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/components/create-react-class/index.js to http://10.42.0.169:8888
00:47:01.928 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/components/requirejs/require.js to http://10.42.0.169:8888
00:47:01.964 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/tree/js/main.min.js to http://10.42.0.169:8888
00:47:02.139 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/services/contents.js to http://10.42.0.169:8888
00:47:02.177 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/tree to http://10.42.0.169:8888
00:47:02.178 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/common to http://10.42.0.169:8888
00:47:02.189 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.169:8888
00:47:02.190 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/kernelspecs to http://10.42.0.169:8888
00:47:02.192 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/sessions to http://10.42.0.169:8888
00:47:02.193 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.169:8888
00:47:02.206 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.js to http://10.42.0.169:8888
00:47:02.214 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/components/font-awesome/fonts/fontawesome-webfont.woff2 to http://10.42.0.169:8888
00:47:02.390 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/contents to http://10.42.0.169:8888
00:47:02.418 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/base/images/favicon.ico to http://10.42.0.169:8888
00:47:11.675 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:47:13.939 [ConfigProxy] debug: PROXY WEB /user/test_user to http://10.42.0.164:8888
00:47:13.942 [ConfigProxy] error: 503 GET /user/test_user connect ECONNREFUSED 10.42.0.164:8888
00:47:13.943 [ConfigProxy] debug: Requesting custom error page: http://hub:8081/hub/error/503?url=%2Fuser%2Ftest_user
00:47:13.956 [ConfigProxy] debug: Not recording activity for status 503 on /user/test_user
00:47:59.096 [ConfigProxy] info: 200 GET /api/routes
00:48:16.067 [ConfigProxy] debug: PROXY WEB /user/test_user to http://10.42.0.164:8888
00:48:16.068 [ConfigProxy] error: 503 GET /user/test_user connect ECONNREFUSED 10.42.0.164:8888
00:48:16.069 [ConfigProxy] debug: Requesting custom error page: http://hub:8081/hub/error/503?url=%2Fuser%2Ftest_user
00:48:16.074 [ConfigProxy] debug: Not recording activity for status 503 on /user/test_user
00:48:59.098 [ConfigProxy] info: 200 GET /api/routes
00:49:28.275 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:49:32.138 [ConfigProxy] debug: PROXY WEB /user/test_user/test1 to http://10.42.0.169:8888
00:49:32.142 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:49:32.146 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/tree to http://10.42.0.169:8888
00:49:32.152 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:49:32.225 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.css to http://10.42.0.169:8888
00:49:32.228 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:49:32.480 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/tree to http://10.42.0.169:8888
00:49:32.481 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/common to http://10.42.0.169:8888
00:49:32.488 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.169:8888
00:49:32.491 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/kernelspecs to http://10.42.0.169:8888
00:49:32.492 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/sessions to http://10.42.0.169:8888
00:49:32.495 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.169:8888
00:49:32.502 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:49:32.531 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.js to http://10.42.0.169:8888
00:49:32.536 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:49:32.546 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/contents to http://10.42.0.169:8888
00:49:59.097 [ConfigProxy] info: 200 GET /api/routes
00:50:24.630 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/sessions to http://10.42.0.169:8888
00:50:24.632 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.169:8888
00:50:24.645 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/contents to http://10.42.0.169:8888
00:50:25.983 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:50:27.363 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/servers/test1 to http://hub:8081
00:50:27.373 [ConfigProxy] info: Removing route /user/test_user/test1
00:50:27.374 [ConfigProxy] info: 204 DELETE /api/routes/user/test_user/test1
00:50:30.456 [ConfigProxy] debug: PROXY WEB /user/test_user to http://10.42.0.164:8888
00:50:30.459 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:50:30.463 [ConfigProxy] debug: PROXY WEB /user/test_user/tree to http://10.42.0.164:8888
00:50:30.491 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:50:30.540 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.css to http://10.42.0.164:8888
00:50:30.544 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:50:30.813 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/tree to http://10.42.0.164:8888
00:50:30.814 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/common to http://10.42.0.164:8888
00:50:30.818 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.164:8888
00:50:30.820 [ConfigProxy] debug: PROXY WEB /user/test_user/api/kernelspecs to http://10.42.0.164:8888
00:50:30.831 [ConfigProxy] debug: PROXY WEB /user/test_user/api/sessions to http://10.42.0.164:8888
00:50:30.832 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.164:8888
00:50:30.835 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:50:30.844 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.js to http://10.42.0.164:8888
00:50:30.848 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:50:30.859 [ConfigProxy] debug: PROXY WEB /user/test_user/api/contents to http://10.42.0.164:8888
00:50:32.597 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:50:35.601 [ConfigProxy] debug: PROXY WEB /hub/spawn/test_user/test1 to http://hub:8081
00:50:35.645 [ConfigProxy] debug: Not recording activity for status 302 on /
00:50:35.651 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user/test1 to http://hub:8081
00:50:35.856 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/servers/test1/progress to http://hub:8081
00:50:39.702 [ConfigProxy] info: Adding route /user/test_user/test1 -> http://10.42.0.170:8888
00:50:39.702 [ConfigProxy] info: Route added /user/test_user/test1 -> http://10.42.0.170:8888
00:50:39.702 [ConfigProxy] info: 201 POST /api/routes/user/test_user/test1
00:50:39.713 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user/test1 to http://hub:8081
00:50:39.720 [ConfigProxy] debug: Not recording activity for status 302 on /
00:50:39.724 [ConfigProxy] debug: PROXY WEB /user/test_user/test1 to http://10.42.0.170:8888
00:50:39.726 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:50:39.732 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/tree to http://10.42.0.170:8888
00:50:39.743 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:50:39.750 [ConfigProxy] debug: PROXY WEB /hub/api/oauth2/authorize to http://hub:8081
00:50:39.769 [ConfigProxy] debug: Not recording activity for status 302 on /
00:50:39.775 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/oauth_callback to http://10.42.0.170:8888
00:50:39.835 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:50:39.841 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/tree to http://10.42.0.170:8888
00:50:39.956 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.css to http://10.42.0.170:8888
00:50:39.961 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:50:40.075 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/services/contents.js to http://10.42.0.170:8888
00:50:40.161 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/tree to http://10.42.0.170:8888
00:50:40.162 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/common to http://10.42.0.170:8888
00:50:40.168 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.170:8888
00:50:40.169 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/kernelspecs to http://10.42.0.170:8888
00:50:40.174 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/sessions to http://10.42.0.170:8888
00:50:40.175 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.170:8888
00:50:40.194 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.js to http://10.42.0.170:8888
00:50:40.390 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:50:40.408 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/contents to http://10.42.0.170:8888
00:50:54.491 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/sessions to http://10.42.0.170:8888
00:50:54.492 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.170:8888
00:50:54.505 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/contents to http://10.42.0.170:8888
00:50:55.450 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:50:59.098 [ConfigProxy] info: 200 GET /api/routes
00:51:00.302 [ConfigProxy] debug: PROXY WEB /user/test_user/test1 to http://10.42.0.170:8888
00:51:00.304 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:51:00.308 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/tree to http://10.42.0.170:8888
00:51:00.314 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:51:00.357 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.css to http://10.42.0.170:8888
00:51:00.361 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:51:00.562 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/tree to http://10.42.0.170:8888
00:51:00.563 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/common to http://10.42.0.170:8888
00:51:00.570 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.170:8888
00:51:00.572 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/kernelspecs to http://10.42.0.170:8888
00:51:00.573 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/sessions to http://10.42.0.170:8888
00:51:00.574 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.170:8888
00:51:00.582 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:51:00.590 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.js to http://10.42.0.170:8888
00:51:00.593 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:51:00.598 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/contents to http://10.42.0.170:8888
00:51:01.943 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:51:02.610 [ConfigProxy] debug: PROXY WEB /user/test_user to http://10.42.0.164:8888
00:51:02.611 [ConfigProxy] error: 503 GET /user/test_user connect ECONNREFUSED 10.42.0.164:8888
00:51:02.611 [ConfigProxy] debug: Requesting custom error page: http://hub:8081/hub/error/503?url=%2Fuser%2Ftest_user
00:51:02.615 [ConfigProxy] debug: Not recording activity for status 503 on /user/test_user
00:51:04.100 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:51:04.108 [ConfigProxy] debug: Not recording activity for status 304 on /
00:51:13.657 [ConfigProxy] debug: PROXY WEB /hub/spawn/test_user/test2 to http://hub:8081
00:51:13.712 [ConfigProxy] debug: Not recording activity for status 302 on /
00:51:13.720 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user/test2 to http://hub:8081
00:51:13.921 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/servers/test2/progress to http://hub:8081
00:51:22.837 [ConfigProxy] info: Adding route /user/test_user/test2 -> http://10.42.0.172:8888
00:51:22.838 [ConfigProxy] info: Route added /user/test_user/test2 -> http://10.42.0.172:8888
00:51:22.838 [ConfigProxy] info: 201 POST /api/routes/user/test_user/test2
00:51:22.849 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user/test2 to http://hub:8081
00:51:22.854 [ConfigProxy] debug: Not recording activity for status 302 on /
00:51:22.859 [ConfigProxy] debug: PROXY WEB /user/test_user/test2 to http://10.42.0.172:8888
00:51:22.862 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test2
00:51:22.866 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/tree to http://10.42.0.172:8888
00:51:22.871 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test2
00:51:22.877 [ConfigProxy] debug: PROXY WEB /hub/api/oauth2/authorize to http://hub:8081
00:51:22.900 [ConfigProxy] debug: Not recording activity for status 302 on /
00:51:22.906 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/oauth_callback to http://10.42.0.172:8888
00:51:22.971 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test2
00:51:22.977 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/tree to http://10.42.0.172:8888
00:51:23.106 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css to http://10.42.0.172:8888
00:51:23.108 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/components/jquery-typeahead/dist/jquery.typeahead.min.css to http://10.42.0.172:8888
00:51:23.109 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/style/style.min.css to http://10.42.0.172:8888
00:51:23.110 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/custom/custom.css to http://10.42.0.172:8888
00:51:23.110 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/components/es6-promise/promise.min.js to http://10.42.0.172:8888
00:51:23.112 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/components/react/react.production.min.js to http://10.42.0.172:8888
00:51:23.124 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/components/react/react-dom.production.min.js to http://10.42.0.172:8888
00:51:23.126 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/components/create-react-class/index.js to http://10.42.0.172:8888
00:51:23.136 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/components/requirejs/require.js to http://10.42.0.172:8888
00:51:23.181 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/tree/js/main.min.js to http://10.42.0.172:8888
00:51:23.366 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/services/contents.js to http://10.42.0.172:8888
00:51:23.402 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/config/tree to http://10.42.0.172:8888
00:51:23.403 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/config/common to http://10.42.0.172:8888
00:51:23.408 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/terminals to http://10.42.0.172:8888
00:51:23.410 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/kernelspecs to http://10.42.0.172:8888
00:51:23.415 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/sessions to http://10.42.0.172:8888
00:51:23.416 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/terminals to http://10.42.0.172:8888
00:51:23.436 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/components/font-awesome/fonts/fontawesome-webfont.woff2 to http://10.42.0.172:8888
00:51:23.437 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/custom/custom.js to http://10.42.0.172:8888
00:51:23.647 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/contents to http://10.42.0.172:8888
00:51:23.670 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/static/base/images/favicon.ico to http://10.42.0.172:8888
00:51:26.914 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:51:32.132 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/server to http://hub:8081
00:51:32.141 [ConfigProxy] info: Removing route /user/test_user
00:51:32.141 [ConfigProxy] info: 204 DELETE /api/routes/user/test_user
00:51:34.686 [ConfigProxy] debug: PROXY WEB /user/test_user/test1 to http://10.42.0.170:8888
00:51:34.687 [ConfigProxy] error: 503 GET /user/test_user/test1 connect ECONNREFUSED 10.42.0.170:8888
00:51:34.687 [ConfigProxy] debug: Requesting custom error page: http://hub:8081/hub/error/503?url=%2Fuser%2Ftest_user%2Ftest1
00:51:34.692 [ConfigProxy] debug: Not recording activity for status 503 on /user/test_user/test1
00:51:37.392 [ConfigProxy] debug: PROXY WEB /user/test_user/test2 to http://10.42.0.172:8888
00:51:37.395 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test2
00:51:37.402 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/tree to http://10.42.0.172:8888
00:51:37.408 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test2
00:51:37.440 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/custom/custom.css to http://10.42.0.172:8888
00:51:37.444 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test2
00:51:37.669 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/config/tree to http://10.42.0.172:8888
00:51:37.670 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/config/common to http://10.42.0.172:8888
00:51:37.673 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/terminals to http://10.42.0.172:8888
00:51:37.676 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/kernelspecs to http://10.42.0.172:8888
00:51:37.681 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/sessions to http://10.42.0.172:8888
00:51:37.682 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/terminals to http://10.42.0.172:8888
00:51:37.690 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test2
00:51:37.706 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/custom/custom.js to http://10.42.0.172:8888
00:51:37.710 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test2
00:51:37.718 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/contents to http://10.42.0.172:8888
00:51:49.686 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/sessions to http://10.42.0.172:8888
00:51:49.687 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/terminals to http://10.42.0.172:8888
00:51:49.706 [ConfigProxy] debug: PROXY WEB /user/test_user/test2/api/contents to http://10.42.0.172:8888
00:51:50.499 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:51:52.840 [ConfigProxy] debug: PROXY WEB /user/test_user to http://hub:8081
00:51:52.844 [ConfigProxy] debug: Not recording activity for status 301 on /
00:51:52.853 [ConfigProxy] debug: PROXY WEB /user/test_user/ to http://hub:8081
00:51:52.856 [ConfigProxy] debug: Not recording activity for status 302 on /
00:51:52.860 [ConfigProxy] debug: PROXY WEB /hub/user/test_user/ to http://hub:8081
00:51:52.872 [ConfigProxy] debug: Not recording activity for status 503 on /
00:51:53.025 [ConfigProxy] debug: PROXY WEB /hub/static/js/not_running.js to http://hub:8081
00:51:54.624 [ConfigProxy] debug: PROXY WEB /hub/spawn/test_user to http://hub:8081
00:51:54.669 [ConfigProxy] debug: Not recording activity for status 302 on /
00:51:54.676 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user to http://hub:8081
00:51:54.854 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/server/progress to http://hub:8081
00:51:59.097 [ConfigProxy] info: 200 GET /api/routes
00:52:31.844 [ConfigProxy] debug: PROXY WEB /hub/ to http://hub:8081
00:52:31.851 [ConfigProxy] debug: Not recording activity for status 302 on /
00:52:31.856 [ConfigProxy] debug: PROXY WEB /hub/spawn to http://hub:8081
00:52:31.911 [ConfigProxy] debug: Not recording activity for status 302 on /
00:52:31.917 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user to http://hub:8081
00:52:32.135 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/server/progress to http://hub:8081
00:52:59.096 [ConfigProxy] info: 200 GET /api/routes
00:53:15.880 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:53:18.484 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/servers/test1 to http://hub:8081
00:53:18.492 [ConfigProxy] info: Removing route /user/test_user/test1
00:53:18.492 [ConfigProxy] info: 204 DELETE /api/routes/user/test_user/test1
00:53:20.501 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/servers/test2 to http://hub:8081
00:53:20.509 [ConfigProxy] info: Removing route /user/test_user/test2
00:53:20.509 [ConfigProxy] info: 204 DELETE /api/routes/user/test_user/test2
00:53:26.524 [ConfigProxy] debug: PROXY WEB /user/test_user/ to http://hub:8081
00:53:26.528 [ConfigProxy] debug: Not recording activity for status 302 on /
00:53:26.534 [ConfigProxy] debug: PROXY WEB /hub/user/test_user/ to http://hub:8081
00:53:26.541 [ConfigProxy] debug: Not recording activity for status 303 on /
00:53:26.547 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user to http://hub:8081
00:53:26.553 [ConfigProxy] debug: Not recording activity for status 500 on /
00:53:32.206 [ConfigProxy] debug: PROXY WEB /hub/spawn/test_user to http://hub:8081
00:53:32.244 [ConfigProxy] debug: Not recording activity for status 302 on /
00:53:32.249 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user to http://hub:8081
00:53:32.257 [ConfigProxy] debug: Not recording activity for status 304 on /
00:53:32.439 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/server/progress to http://hub:8081
00:53:35.905 [ConfigProxy] info: Adding route /user/test_user -> http://10.42.0.175:8888
00:53:35.906 [ConfigProxy] info: Route added /user/test_user -> http://10.42.0.175:8888
00:53:35.906 [ConfigProxy] info: 201 POST /api/routes/user/test_user
00:53:35.918 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user to http://hub:8081
00:53:35.925 [ConfigProxy] debug: Not recording activity for status 302 on /
00:53:35.929 [ConfigProxy] debug: PROXY WEB /user/test_user/ to http://10.42.0.175:8888
00:53:35.931 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:53:35.936 [ConfigProxy] debug: PROXY WEB /user/test_user/tree to http://10.42.0.175:8888
00:53:35.942 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:53:35.947 [ConfigProxy] debug: PROXY WEB /hub/api/oauth2/authorize to http://hub:8081
00:53:35.970 [ConfigProxy] debug: Not recording activity for status 302 on /
00:53:35.976 [ConfigProxy] debug: PROXY WEB /user/test_user/oauth_callback to http://10.42.0.175:8888
00:53:36.057 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:53:36.064 [ConfigProxy] debug: PROXY WEB /user/test_user/tree to http://10.42.0.175:8888
00:53:36.178 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.css to http://10.42.0.175:8888
00:53:36.182 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:53:36.346 [ConfigProxy] debug: PROXY WEB /user/test_user/static/services/contents.js to http://10.42.0.175:8888
00:53:36.376 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/tree to http://10.42.0.175:8888
00:53:36.377 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/common to http://10.42.0.175:8888
00:53:36.381 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.175:8888
00:53:36.383 [ConfigProxy] debug: PROXY WEB /user/test_user/api/kernelspecs to http://10.42.0.175:8888
00:53:36.385 [ConfigProxy] debug: PROXY WEB /user/test_user/api/sessions to http://10.42.0.175:8888
00:53:36.387 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.175:8888
00:53:36.404 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.js to http://10.42.0.175:8888
00:53:36.582 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:53:36.597 [ConfigProxy] debug: PROXY WEB /user/test_user/api/contents to http://10.42.0.175:8888
00:53:38.144 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:53:39.675 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/server to http://hub:8081
00:53:39.684 [ConfigProxy] info: Removing route /user/test_user
00:53:39.684 [ConfigProxy] info: 204 DELETE /api/routes/user/test_user
00:53:42.742 [ConfigProxy] debug: PROXY WEB /hub/spawn/test_user/test1 to http://hub:8081
00:53:42.794 [ConfigProxy] debug: Not recording activity for status 302 on /
00:53:42.799 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user/test1 to http://hub:8081
00:53:42.997 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/servers/test1/progress to http://hub:8081
00:53:47.047 [ConfigProxy] info: Adding route /user/test_user/test1 -> http://10.42.0.176:8888
00:53:47.047 [ConfigProxy] info: Route added /user/test_user/test1 -> http://10.42.0.176:8888
00:53:47.047 [ConfigProxy] info: 201 POST /api/routes/user/test_user/test1
00:53:47.057 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user/test1 to http://hub:8081
00:53:47.063 [ConfigProxy] debug: Not recording activity for status 302 on /
00:53:47.068 [ConfigProxy] debug: PROXY WEB /user/test_user/test1 to http://10.42.0.176:8888
00:53:47.070 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:53:47.075 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/tree to http://10.42.0.176:8888
00:53:47.082 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:53:47.087 [ConfigProxy] debug: PROXY WEB /hub/api/oauth2/authorize to http://hub:8081
00:53:47.109 [ConfigProxy] debug: Not recording activity for status 302 on /
00:53:47.116 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/oauth_callback to http://10.42.0.176:8888
00:53:47.184 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user/test1
00:53:47.191 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/tree to http://10.42.0.176:8888
00:53:47.321 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.css to http://10.42.0.176:8888
00:53:47.327 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:53:47.444 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/static/services/contents.js to http://10.42.0.176:8888
00:53:47.553 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/tree to http://10.42.0.176:8888
00:53:47.554 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/config/common to http://10.42.0.176:8888
00:53:47.566 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.176:8888
00:53:47.569 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/sessions to http://10.42.0.176:8888
00:53:47.571 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.176:8888
00:53:47.572 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/kernelspecs to http://10.42.0.176:8888
00:53:47.592 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/custom/custom.js to http://10.42.0.176:8888
00:53:47.605 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/contents to http://10.42.0.176:8888
00:53:47.806 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user/test1
00:53:59.095 [ConfigProxy] info: 200 GET /api/routes
00:54:20.592 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/sessions to http://10.42.0.176:8888
00:54:20.593 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/terminals to http://10.42.0.176:8888
00:54:20.609 [ConfigProxy] debug: PROXY WEB /user/test_user/test1/api/contents to http://10.42.0.176:8888
00:54:21.353 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:54:23.657 [ConfigProxy] debug: PROXY WEB /user/test_user/ to http://hub:8081
00:54:23.661 [ConfigProxy] debug: Not recording activity for status 302 on /
00:54:23.666 [ConfigProxy] debug: PROXY WEB /hub/user/test_user/ to http://hub:8081
00:54:23.672 [ConfigProxy] debug: Not recording activity for status 503 on /
00:54:25.537 [ConfigProxy] debug: PROXY WEB /hub/spawn/test_user to http://hub:8081
00:54:25.584 [ConfigProxy] debug: Not recording activity for status 302 on /
00:54:25.590 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user to http://hub:8081
00:54:25.791 [ConfigProxy] debug: PROXY WEB /hub/api/users/test_user/server/progress to http://hub:8081
00:54:30.054 [ConfigProxy] info: Adding route /user/test_user -> http://10.42.0.177:8888
00:54:30.055 [ConfigProxy] info: Route added /user/test_user -> http://10.42.0.177:8888
00:54:30.056 [ConfigProxy] info: 201 POST /api/routes/user/test_user
00:54:30.066 [ConfigProxy] debug: PROXY WEB /hub/spawn-pending/test_user to http://hub:8081
00:54:30.072 [ConfigProxy] debug: Not recording activity for status 302 on /
00:54:30.076 [ConfigProxy] debug: PROXY WEB /hub/user/test_user/ to http://hub:8081
00:54:30.081 [ConfigProxy] debug: Not recording activity for status 302 on /
00:54:30.087 [ConfigProxy] debug: PROXY WEB /user/test_user/ to http://10.42.0.177:8888
00:54:30.089 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:54:30.095 [ConfigProxy] debug: PROXY WEB /user/test_user/tree to http://10.42.0.177:8888
00:54:30.104 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:54:30.110 [ConfigProxy] debug: PROXY WEB /hub/api/oauth2/authorize to http://hub:8081
00:54:30.133 [ConfigProxy] debug: Not recording activity for status 302 on /
00:54:30.140 [ConfigProxy] debug: PROXY WEB /user/test_user/oauth_callback to http://10.42.0.177:8888
00:54:30.205 [ConfigProxy] debug: Not recording activity for status 302 on /user/test_user
00:54:30.213 [ConfigProxy] debug: PROXY WEB /user/test_user/tree to http://10.42.0.177:8888
00:54:30.327 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.css to http://10.42.0.177:8888
00:54:30.331 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:54:30.501 [ConfigProxy] debug: PROXY WEB /user/test_user/static/services/contents.js to http://10.42.0.177:8888
00:54:30.548 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/tree to http://10.42.0.177:8888
00:54:30.550 [ConfigProxy] debug: PROXY WEB /user/test_user/api/config/common to http://10.42.0.177:8888
00:54:30.556 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.177:8888
00:54:30.562 [ConfigProxy] debug: PROXY WEB /user/test_user/api/kernelspecs to http://10.42.0.177:8888
00:54:30.571 [ConfigProxy] debug: PROXY WEB /user/test_user/api/sessions to http://10.42.0.177:8888
00:54:30.572 [ConfigProxy] debug: PROXY WEB /user/test_user/api/terminals to http://10.42.0.177:8888
00:54:30.583 [ConfigProxy] debug: PROXY WEB /user/test_user/custom/custom.js to http://10.42.0.177:8888
00:54:30.761 [ConfigProxy] debug: Not recording activity for status 304 on /user/test_user
00:54:30.779 [ConfigProxy] debug: PROXY WEB /user/test_user/api/contents to http://10.42.0.177:8888
00:54:32.028 [ConfigProxy] debug: PROXY WEB /hub/home to http://hub:8081
00:54:33.058 [ConfigProxy] debug: PROXY WEB /user/test_user/test1 to http://10.42.0.176:8888
00:54:33.059 [ConfigProxy] error: 503 GET /user/test_user/test1 connect ECONNREFUSED 10.42.0.176:8888
00:54:33.060 [ConfigProxy] debug: Requesting custom error page: http://hub:8081/hub/error/503?url=%2Fuser%2Ftest_user%2Ftest1
00:54:33.064 [ConfigProxy] debug: Not recording activity for status 503 on /user/test_user/test1
00:54:59.097 [ConfigProxy] info: 200 GET /api/routes
00:55:59.098 [ConfigProxy] info: 200 GET /api/routes
00:56:59.098 [ConfigProxy] info: 200 GET /api/routes
00:57:59.097 [ConfigProxy] info: 200 GET /api/routes
00:58:59.096 [ConfigProxy] info: 200 GET /api/routes
00:59:59.098 [ConfigProxy] info: 200 GET /api/routes
01:00:59.104 [ConfigProxy] info: 200 GET /api/routes
[D 2022-09-06 00:54:27.437 SingleUserNotebookApp application:174] Searching ['/home/jovyan', '/home/jovyan/.jupyter', '/home/jovyan/.local/etc/jupyter', '/opt/conda/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2022-09-06 00:54:27.437 SingleUserNotebookApp application:731] Looking for jupyter_config in /etc/jupyter
[D 2022-09-06 00:54:27.437 SingleUserNotebookApp application:731] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2022-09-06 00:54:27.438 SingleUserNotebookApp application:731] Looking for jupyter_config in /opt/conda/etc/jupyter
[D 2022-09-06 00:54:27.438 SingleUserNotebookApp application:731] Looking for jupyter_config in /home/jovyan/.local/etc/jupyter
[D 2022-09-06 00:54:27.438 SingleUserNotebookApp application:731] Looking for jupyter_config in /home/jovyan/.jupyter
[D 2022-09-06 00:54:27.438 SingleUserNotebookApp application:731] Looking for jupyter_config in /home/jovyan
[D 2022-09-06 00:54:27.439 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /etc/jupyter
[D 2022-09-06 00:54:27.439 SingleUserNotebookApp application:753] Loaded config file: /etc/jupyter/jupyter_notebook_config.py
[D 2022-09-06 00:54:27.439 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2022-09-06 00:54:27.439 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /opt/conda/etc/jupyter
[D 2022-09-06 00:54:27.440 SingleUserNotebookApp application:753] Loaded config file: /opt/conda/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:54:27.440 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /home/jovyan/.local/etc/jupyter
[D 2022-09-06 00:54:27.440 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /home/jovyan/.jupyter
[D 2022-09-06 00:54:27.440 SingleUserNotebookApp application:731] Looking for jupyter_notebook_config in /home/jovyan
[W 2022-09-06 00:54:27.441 SingleUserNotebookApp configurable:193] Config option `open_browser` not recognized by `SingleUserNotebookApp`. Did you mean `browser`?
[D 2022-09-06 00:54:27.450 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:54:27.450 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:54:27.450 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/opt/conda/etc/jupyter/jupyter_notebook_config.d/jupyterlab.json
/opt/conda/etc/jupyter/jupyter_notebook_config.d/nbgitpuller.json
/opt/conda/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:54:27.451 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/home/jovyan/.local/etc/jupyter/jupyter_notebook_config.json
[D 2022-09-06 00:54:27.451 SingleUserNotebookApp config_manager:96] Paths used for configuration of jupyter_notebook_config:
/home/jovyan/.jupyter/jupyter_notebook_config.json
[I 2022-09-06 00:54:27.461 SingleUserNotebookApp notebookapp:1593] Authentication of /metrics is OFF, since other authentication is disabled.
[W 2022-09-06 00:54:28.966 LabApp] 'ip' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[W 2022-09-06 00:54:28.966 LabApp] 'port' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[W 2022-09-06 00:54:28.966 LabApp] 'port' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[W 2022-09-06 00:54:28.967 LabApp] 'port' has moved from NotebookApp to ServerApp. This config will be passed to ServerApp. Be sure to update your config before our next release.
[D 2022-09-06 00:54:28.979 LabApp] Config changed: {'NotebookApp': {'open_browser': False, 'nbserver_extensions': <LazyConfigValue {'update': {'jupyterlab': True, 'nbgitpuller': True}}>}, 'ServerApp': {'ip': '0.0.0.0', 'port': 8888}, 'FileContentsManager': {'delete_to_trash': False}, 'SingleUserNotebookApp': {'ip': '0.0.0.0', 'port': 8888}, 'Application': {'log_level': 10}}
[I 2022-09-06 00:54:28.981 LabApp] JupyterLab extension loaded from /opt/conda/lib/python3.9/site-packages/jupyterlab
[I 2022-09-06 00:54:28.981 LabApp] JupyterLab application directory is /opt/conda/share/jupyter/lab
Patching auth into jupyter_server.base.handlers.JupyterHandler(jupyter_server.base.handlers.AuthenticatedHandler) -> JupyterHandler(jupyterhub.singleuser.mixins.HubAuthenticatedHandler, jupyter_server.base.handlers.AuthenticatedHandler)
[I 2022-09-06 00:54:28.991 SingleUserNotebookApp mixins:576] Starting jupyterhub-singleuser server version 1.4.2
[W 2022-09-06 00:54:28.999 SingleUserNotebookApp _version:70] jupyterhub version 1.5.0 != jupyterhub-singleuser version 1.4.2. This could cause failure to authenticate and result in redirect loops!
[I 2022-09-06 00:54:28.999 SingleUserNotebookApp notebookapp:2302] Serving notebooks from local directory: /home/jovyan
[I 2022-09-06 00:54:28.999 SingleUserNotebookApp notebookapp:2302] Jupyter Notebook 6.4.5 is running at:
[I 2022-09-06 00:54:29.000 SingleUserNotebookApp notebookapp:2302] http://jupyter-test-5fuser:8888/user/test_user/
[I 2022-09-06 00:54:29.000 SingleUserNotebookApp notebookapp:2303] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[I 2022-09-06 00:54:29.007 SingleUserNotebookApp mixins:556] Updating Hub with activity every 300 seconds
[D 2022-09-06 00:54:29.008 SingleUserNotebookApp mixins:518] Notifying Hub of activity 2022-09-06T00:54:27.460916Z
[I 2022-09-06 00:54:30.050 SingleUserNotebookApp log:189] 302 GET /user/test_user/ -> /user/test_user/tree? (@10.42.0.162) 1.45ms
[I 2022-09-06 00:54:30.089 SingleUserNotebookApp log:189] 302 GET /user/test_user/?redirects=1 -> /user/test_user/tree?redirects=1 (@::ffff:10.42.0.1) 0.76ms
[D 2022-09-06 00:54:30.097 SingleUserNotebookApp auth:505] No user identified
[D 2022-09-06 00:54:30.098 SingleUserNotebookApp auth:844] Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user&redirect_uri=%2Fuser%2Ftest_user%2Foauth_callback&response_type=code&state=eyJ1dWlkIjogImIwMzA3Y2NmNjg2ZjRjMzhiMjI4ZGE1MWU0NTZmZTAxIiwgIm5leHRfdXJsIjogIi91c2VyL3Rlc3RfdXNlci90cmVlP3JlZGlyZWN0cz0xIn0
[I 2022-09-06 00:54:30.099 SingleUserNotebookApp log:189] 302 GET /user/test_user/tree?redirects=1 -> /hub/api/oauth2/authorize?client_id=jupyterhub-user-test_user&redirect_uri=%2Fuser%2Ftest_user%2Foauth_callback&response_type=code&state=[secret] (@::ffff:10.42.0.1) 2.54ms
[D 2022-09-06 00:54:30.142 SingleUserNotebookApp auth:505] No user identified
[D 2022-09-06 00:54:30.182 SingleUserNotebookApp auth:310] HubAuth cache miss: token:2f790d1fbd5a4735821fe63ac5858882:aXny1VE6e0sC84QWsMJOLpU1sKlEZm
[D 2022-09-06 00:54:30.203 SingleUserNotebookApp auth:316] Received request from Hub user {'kind': 'user', 'name': 'test_user', 'admin': False, 'groups': [], 'server': '/user/test_user/', 'pending': None, 'created': '2022-09-06T00:44:41.422381Z', 'last_activity': '2022-09-06T00:54:30.194235Z', 'servers': None}
[I 2022-09-06 00:54:30.204 SingleUserNotebookApp auth:992] Logged-in user {'kind': 'user', 'name': 'test_user', 'admin': False, 'groups': [], 'server': '/user/test_user/', 'pending': None, 'created': '2022-09-06T00:44:41.422381Z', 'last_activity': '2022-09-06T00:54:30.194235Z', 'servers': None}
[D 2022-09-06 00:54:30.204 SingleUserNotebookApp auth:748] Setting oauth cookie for ::ffff:10.42.0.1: jupyterhub-user-test_user, {'path': '/user/test_user/', 'httponly': True}
[I 2022-09-06 00:54:30.205 SingleUserNotebookApp log:189] 302 GET /user/test_user/oauth_callback?code=[secret]&state=[secret] -> /user/test_user/tree?redirects=1 (@::ffff:10.42.0.1) 63.11ms
[D 2022-09-06 00:54:30.216 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:54:30.217 SingleUserNotebookApp handlers:251] Using contents: services/contents
[D 2022-09-06 00:54:30.280 SingleUserNotebookApp handlers:836] Path base/images/favicon.ico served from /opt/conda/lib/python3.9/site-packages/notebook/static/base/images/favicon.ico
[D 2022-09-06 00:54:30.280 SingleUserNotebookApp handlers:836] Path components/jquery-ui/themes/smoothness/jquery-ui.min.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css
[D 2022-09-06 00:54:30.281 SingleUserNotebookApp handlers:836] Path components/jquery-typeahead/dist/jquery.typeahead.min.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/jquery-typeahead/dist/jquery.typeahead.min.css
[D 2022-09-06 00:54:30.281 SingleUserNotebookApp handlers:836] Path style/style.min.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/style/style.min.css
[D 2022-09-06 00:54:30.282 SingleUserNotebookApp handlers:836] Path components/es6-promise/promise.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/es6-promise/promise.min.js
[D 2022-09-06 00:54:30.282 SingleUserNotebookApp handlers:836] Path components/react/react.production.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/react/react.production.min.js
[D 2022-09-06 00:54:30.282 SingleUserNotebookApp handlers:836] Path components/react/react-dom.production.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/react/react-dom.production.min.js
[D 2022-09-06 00:54:30.282 SingleUserNotebookApp handlers:836] Path components/create-react-class/index.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/create-react-class/index.js
[D 2022-09-06 00:54:30.283 SingleUserNotebookApp handlers:836] Path components/requirejs/require.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/components/requirejs/require.js
[D 2022-09-06 00:54:30.284 SingleUserNotebookApp handlers:836] Path tree/js/main.min.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/tree/js/main.min.js
[I 2022-09-06 00:54:30.288 SingleUserNotebookApp log:189] 200 GET /user/test_user/tree?redirects=1 (test_user@::ffff:10.42.0.1) 72.94ms
[D 2022-09-06 00:54:30.330 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:54:30.330 SingleUserNotebookApp handlers:836] Path custom.css served from /opt/conda/lib/python3.9/site-packages/notebook/static/custom/custom.css
[D 2022-09-06 00:54:30.331 SingleUserNotebookApp log:189] 304 GET /user/test_user/custom/custom.css (test_user@::ffff:10.42.0.1) 2.06ms
[D 2022-09-06 00:54:30.503 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:54:30.503 SingleUserNotebookApp handlers:836] Path services/contents.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/services/contents.js
[D 2022-09-06 00:54:30.504 SingleUserNotebookApp log:189] 200 GET /user/test_user/static/services/contents.js?v=20220906005427 (test_user@::ffff:10.42.0.1) 1.44ms
[D 2022-09-06 00:54:30.552 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:54:30.553 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 00:54:30.553 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/usr/local/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 00:54:30.554 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/opt/conda/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 00:54:30.554 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/home/jovyan/.local/etc/jupyter/nbconfig/tree.json
[D 2022-09-06 00:54:30.555 SingleUserNotebookApp config_manager:96] Paths used for configuration of tree:
/home/jovyan/.jupyter/nbconfig/tree.json
[I 2022-09-06 00:54:30.556 SingleUserNotebookApp log:189] 200 GET /user/test_user/api/config/tree?_=1662425670424 (test_user@::ffff:10.42.0.1) 4.56ms
[D 2022-09-06 00:54:30.557 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:54:30.558 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/etc/jupyter/nbconfig/common.json
[D 2022-09-06 00:54:30.558 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/usr/local/etc/jupyter/nbconfig/common.json
[D 2022-09-06 00:54:30.559 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/opt/conda/etc/jupyter/nbconfig/common.json
[D 2022-09-06 00:54:30.560 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/home/jovyan/.local/etc/jupyter/nbconfig/common.json
[D 2022-09-06 00:54:30.560 SingleUserNotebookApp config_manager:96] Paths used for configuration of common:
/home/jovyan/.jupyter/nbconfig/common.json
[I 2022-09-06 00:54:30.561 SingleUserNotebookApp log:189] 200 GET /user/test_user/api/config/common?_=1662425670425 (test_user@::ffff:10.42.0.1) 5.11ms
[D 2022-09-06 00:54:30.563 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 00:54:30.564 SingleUserNotebookApp log:189] 200 GET /user/test_user/api/terminals?_=1662425670426 (test_user@::ffff:10.42.0.1) 1.54ms
[D 2022-09-06 00:54:30.566 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:54:30.567 SingleUserNotebookApp kernelspec:218] Found kernel python3 in /opt/conda/share/jupyter/kernels
[D 2022-09-06 00:54:30.760 SingleUserNotebookApp log:189] 304 GET /user/test_user/api/kernelspecs (test_user@::ffff:10.42.0.1) 194.05ms
[D 2022-09-06 00:54:30.762 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:54:30.763 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[D 2022-09-06 00:54:30.765 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 00:54:30.767 SingleUserNotebookApp log:189] 200 GET /user/test_user/api/sessions?_=1662425670427 (test_user@::ffff:10.42.0.1) 5.96ms
[I 2022-09-06 00:54:30.768 SingleUserNotebookApp log:189] 200 GET /user/test_user/api/terminals?_=1662425670428 (test_user@::ffff:10.42.0.1) 5.67ms
[D 2022-09-06 00:54:30.769 SingleUserNotebookApp handlers:836] Path custom.js served from /opt/conda/lib/python3.9/site-packages/notebook/static/custom/custom.js
[D 2022-09-06 00:54:30.770 SingleUserNotebookApp log:189] 200 GET /user/test_user/custom/custom.js?v=20220906005427 (test_user@::ffff:10.42.0.1) 5.81ms
[D 2022-09-06 00:54:30.782 SingleUserNotebookApp auth:883] Allowing Hub user test_user
[I 2022-09-06 00:54:30.785 SingleUserNotebookApp log:189] 200 GET /user/test_user/api/contents?type=directory&_=1662425670429 (test_user@::ffff:10.42.0.1) 3.45ms
[D 2022-09-06 00:59:31.339 SingleUserNotebookApp mixins:518] Notifying Hub of activity 2022-09-06T00:54:30.784572Z
[D 2022-09-06 01:04:36.961 SingleUserNotebookApp mixins:518] Notifying Hub of activity 2022-09-06T00:54:30.784572Z
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment