Proxying requests from api-gateway to jupyterhub service

Description

I have been successful in setting up jupyterhub with k8s locally that exposes a service (i.e. REST API) that contains logic that interacts with jupyterhub’s REST API. I am now working on deploying this service to a production environment and I am experiencing issues routing requests from my api-gateway to the jupyterhub service. If the proxy-api is deployed as a LoadBalancer service it works fine but expose the API publicly which I do not want. When deployed as a ClusterIP service, requests are successfully routed to the service with in the hub but then it returns a 307 response. I see a 307 then a 200 response in the hub, I believe this has to do with my ingress setting but I am not sure where to start.

Deployment Info

k8s

The api-gateway is deployed in the same k8 cluster but is in the public namespace, and jupyterhub is deployed under the ems namespace.

Request from the gateway are routed to the following k8s url.

  • http://proxy-public.ems.svc.cluster.local:80

values.yaml

hub:
  image:
    name: gcr.io/<hub image>
    tag: latest

  service:
    extraPorts:
      - port: 8181
        targetPort: 8181
        name: session
  services:
    session:
      admin: true
      url: http://hub:8181
      command:
        - /home/jovyan/.local/bin/uvicorn
        - src.app:app
        - --port
        - "8181"
        - --host
        - "0.0.0.0"
        - --app-dir
        - /jhub-services/session
  networkPolicy:
    ingress:
      - ports:
          - port: 8181
        from:
          - podSelector:
              matchLabels:
                localhost/network-access-hub: "true"

proxy:
  service:
    type: ClusterIP

singleuser:
  image:
    name: grc.io/<server image>
    tag: latest
  storage:
    type: static
    extraLabels: {}
    static:
      pvcName: jupyter-server-resource-claim
      subPath: 'resource/{username}'
    capacity: 10Gi
    homeMountPath: /home

debug:
  enabled: true

k8s info

$ kubectl get svc -n ems

NAME           TYPE        CLUSTER-IP   EXTERNAL-IP   PORT(S)             AGE
hub            ClusterIP   10.0.8.255   <none>        8081/TCP,8181/TCP   3m28s
proxy-api      ClusterIP   10.0.2.243   <none>        8001/TCP            3m28s
proxy-public   ClusterIP   10.0.13.5    <none>        80/TCP              3m28s

$ kubectl get po -n ems

NAME                              READY   STATUS    RESTARTS   AGE
continuous-image-puller-4vlvg     1/1     Running   0          2m51s
continuous-image-puller-j6stx     1/1     Running   0          2m51s
hub-6c6f6f99c4-h9fg4              1/1     Running   0          2m51s
proxy-6c895b4c9d-86w9s            1/1     Running   0          2m51s
user-scheduler-856bccdc9f-f8b7g   1/1     Running   0          2m51s
user-scheduler-856bccdc9f-rpdd2   1/1     Running   0          2m51s

hub logs

[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 03:32:52 UTC ] - INFO    : 10.36.1.209:36240 - "GET /services/session HTTP/1.1" 307
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 03:33:00 UTC ] - INFO    : 10.36.1.1:59940 - "GET /services/session/ HTTP/1.1" 200

proxy logs

03:21:45.245 [ConfigProxy] info: Adding route / -> http://hub:8081
03:21:45.290 [ConfigProxy] info: Proxying http://*:8000 to http://hub:8081
03:21:45.290 [ConfigProxy] info: Proxy API at http://*:8001/api/routes
03:21:45.292 [ConfigProxy] info: Route added / -> http://hub:8081
03:22:00.025 [ConfigProxy] info: Adding route / -> http://hub:8081
03:22:00.026 [ConfigProxy] info: Route added / -> http://hub:8081
03:22:00.029 [ConfigProxy] info: Adding route /services/session -> http://hub:8181
03:22:00.029 [ConfigProxy] info: Route added /services/session -> http://hub:8181

03:31:26.632 [ConfigProxy] debug: PROXY WEB /services/session to http://hub:8181
03:31:26.744 [ConfigProxy] debug: Not recording activity for status 307 on /services/session

Do you have any detailed logs for your session service?

The session service is running inside of the hub, so the logs provided from the hub are from the service.
In my example I am just send a get request to an endpoint that returns {status: "ok"}.

Can you perhaps increase the logging from your service so it shows all requests and responses?

Can you also describe the actual problem, you’ve mentioned there’s a 307 (redirect) but what’s the consequence of that?

@manics I selectively removed some of the logs in my earlier post to highlight the entires I thought were problematic. Here is the entire log entry for the hub and proxy. Im not sure what you mean by see all requests and all responses, so let me know if what I provided is enough. If you need extra info I can update the service to output info in the logs.

Error Clarification

When the api-gateway proxies a request to my services via the proxy-api (via http://proxy-public.ems.svc.cluster.local:80) I get the following error response in postman.

Error: getaddrinfo ENOTFOUND proxy-public.ems.svc.cluster.local

The service endpoint I am interacting with is simple and returns {status: "ok"}. When I look at the hub and proxy logs it looks like the request makes it to the hub/service but then something go wrong (i.e. the 307 error in the hub and the error response from postman). it is a liottle confusing because I see a 200 and a 307 response in the logs for the service so im not sure what is happening.

I have attempted running jupyterhub in the same namespace as the api-gateway and adding the access labels to the gateway (i.e. hub.jupyter.org/network-access-proxy-http=true) but that didnt make any difference.

hub logs

I removed all health check logs because they made the post to large.

[D 2022-11-10 16:28:24.451 JupyterHub application:837] 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
Loading /usr/local/etc/jupyterhub/jupyterhub_config.d config: __init__.py
Loading /usr/local/etc/jupyterhub/jupyterhub_config.d config: custom_services.py
Not working
Loading /usr/local/etc/jupyterhub/jupyterhub_config.d config: custom_spawner.py
[D 2022-11-10 16:28:27.170 JupyterHub application:858] Loaded config file: /usr/local/etc/jupyterhub/jupyterhub_config.py
[I 2022-11-10 16:28:27.178 JupyterHub app:2775] Running JupyterHub version 3.0.0
[I 2022-11-10 16:28:27.179 JupyterHub app:2805] Using Authenticator: jupyterhub.auth.DummyAuthenticator-3.0.0
[I 2022-11-10 16:28:27.179 JupyterHub app:2805] Using Spawner: builtins.CustomSpawner
[I 2022-11-10 16:28:27.179 JupyterHub app:2805] Using Proxy: jupyterhub.proxy.ConfigurableHTTPProxy-3.0.0
[D 2022-11-10 16:28:27.180 JupyterHub app:1783] Connecting to db: sqlite:///jupyterhub.sqlite
[D 2022-11-10 16:28:27.519 JupyterHub orm:967] Stamping empty database with alembic revision 651f5419b74d
[I 2022-11-10 16:28:27.526 alembic.runtime.migration migration:204] Context impl SQLiteImpl.
[I 2022-11-10 16:28:27.526 alembic.runtime.migration migration:207] Will assume non-transactional DDL.
[I 2022-11-10 16:28:27.545 alembic.runtime.migration migration:618] Running stamp_revision  -> 651f5419b74d
[D 2022-11-10 16:28:27.546 alembic.runtime.migration migration:818] new branch insert 651f5419b74d
[D 2022-11-10 16:28:27.563 JupyterHub orm:967] Stamping empty database with alembic revision 651f5419b74d
[I 2022-11-10 16:28:27.565 alembic.runtime.migration migration:204] Context impl SQLiteImpl.
[I 2022-11-10 16:28:27.565 alembic.runtime.migration migration:207] Will assume non-transactional DDL.
[D 2022-11-10 16:28:27.764 JupyterHub app:2035] Loading roles into database
[I 2022-11-10 16:28:27.822 JupyterHub roles:173] Role jupyterhub-idle-culler added to database
[I 2022-11-10 16:28:27.831 JupyterHub app:1934] Not using allowed_users. Any authenticated user will be allowed.
[W 2022-11-10 16:28:27.869 JupyterHub app:2312] Service session sets `admin: True`, which is deprecated in JupyterHub 2.0. You can assign now assign roles via `JupyterHub.load_roles` configuration. If you specify services in the admin role configuration, the Service admin flag will be ignored.
[I 2022-11-10 16:28:27.870 JupyterHub roles:238] Adding role admin for Service: session
[I 2022-11-10 16:28:27.897 JupyterHub provider:651] Creating oauth client service-session
[I 2022-11-10 16:28:27.939 JupyterHub app:2244] Adding API token for service: session
[D 2022-11-10 16:28:27.956 JupyterHub app:2274] Purging expired APITokens
[D 2022-11-10 16:28:27.961 JupyterHub app:2274] Purging expired OAuthCodes
[D 2022-11-10 16:28:27.965 JupyterHub app:2110] Loading role assignments from config
[D 2022-11-10 16:28:28.000 JupyterHub app:2433] Initializing spawners
[D 2022-11-10 16:28:28.006 JupyterHub app:2564] Loaded users:
    
[I 2022-11-10 16:28:28.006 JupyterHub app:2844] Initialized 0 spawners in 0.007 seconds
[I 2022-11-10 16:28:28.010 JupyterHub app:3057] Not starting proxy
[D 2022-11-10 16:28:28.049 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2022-11-10 16:28:28.110 JupyterHub proxy:957] Omitting non-jupyterhub route '/'
[I 2022-11-10 16:28:28.126 JupyterHub app:3093] Hub API listening on http://:8081/hub/
[I 2022-11-10 16:28:28.126 JupyterHub app:3095] Private Hub API connect url http://hub:8081/hub/
[I 2022-11-10 16:28:28.126 JupyterHub app:3104] Starting managed service jupyterhub-idle-culler
[I 2022-11-10 16:28:28.126 JupyterHub service:385] Starting service 'jupyterhub-idle-culler': ['python3', '-m', 'jupyterhub_idle_culler', '--url=http://localhost:8081/hub/api', '--timeout=3600', '--cull-every=600', '--concurrency=10']
[I 2022-11-10 16:28:28.130 JupyterHub service:133] Spawning python3 -m jupyterhub_idle_culler --url=http://localhost:8081/hub/api --timeout=3600 --cull-every=600 --concurrency=10
[D 2022-11-10 16:28:28.141 JupyterHub spawner:1369] Polling subprocess every 30s
[I 2022-11-10 16:28:28.142 JupyterHub app:3104] Starting managed service session at http://hub:8181
[I 2022-11-10 16:28:28.143 JupyterHub service:385] Starting service 'session': ['/home/jovyan/.local/bin/uvicorn', 'src.app:app', '--port', '8181', '--host', '0.0.0.0', '--app-dir', '/jhub-services/session']
[I 2022-11-10 16:28:28.148 JupyterHub service:133] Spawning /home/jovyan/.local/bin/uvicorn src.app:app --port 8181 --host 0.0.0.0 --app-dir /jhub-services/session
[D 2022-11-10 16:28:28.159 JupyterHub spawner:1369] Polling subprocess every 30s
[D 2022-11-10 16:28:28.263 JupyterHub log:186] 200 GET /hub/health (@10.36.1.1) 3.31ms
[D 2022-11-10 16:28:28.453 JupyterHub base:275] Recording first activity for <APIToken('4eeb...', service='jupyterhub-idle-culler', client_id='jupyterhub')>
[I 2022-11-10 16:28:28.468 JupyterHub log:186] 200 GET /hub/api/ (jupyterhub-idle-culler@127.0.0.1) 22.39ms
[D 2022-11-10 16:28:28.475 JupyterHub scopes:796] Checking access via scope list:users
[D 2022-11-10 16:28:28.475 JupyterHub scopes:610] Unrestricted access to /hub/api/users via list:users
[I 2022-11-10 16:28:28.485 JupyterHub log:186] 200 GET /hub/api/users?state=[secret] (jupyterhub-idle-culler@127.0.0.1) 13.05ms
INFO:     Started server process [13]
INFO:     Waiting for application startup.
[ uvicorn.error   | on:startup:61 | 2022-11-10 16:28:28 UTC ] - INFO    : Application startup complete.
[ uvicorn.error   | server:_log_started_message:207 | 2022-11-10 16:28:28 UTC ] - INFO    : Uvicorn running on http://0.0.0.0:8181 (Press CTRL+C to quit)
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:28:35 UTC ] - INFO    : 10.36.1.1:49813 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:28:35.407 JupyterHub proxy:392] Fetching routes to check
[D 2022-11-10 16:28:35.407 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2022-11-10 16:28:35.410 JupyterHub proxy:957] Omitting non-jupyterhub route '/'
[D 2022-11-10 16:28:35.410 JupyterHub proxy:395] Checking routes
[I 2022-11-10 16:28:35.410 JupyterHub proxy:480] Adding route for Hub: / => http://hub:8081
[W 2022-11-10 16:28:35.412 JupyterHub proxy:448] Adding missing route for session (Server(url=http://hub:8181/services/session/, bind_url=http://hub:8181/services/session/))
[D 2022-11-10 16:28:35.412 JupyterHub proxy:884] Proxy: Fetching POST http://proxy-api:8001/api/routes/
[I 2022-11-10 16:28:35.413 JupyterHub proxy:314] Adding service session to proxy /services/session/ => http://hub:8181
[D 2022-11-10 16:28:35.414 JupyterHub proxy:884] Proxy: Fetching POST http://proxy-api:8001/api/routes/services/session
[I 2022-11-10 16:28:35.421 JupyterHub app:3162] JupyterHub is now running, internal Hub API at http://hub:8081/hub/
[D 2022-11-10 16:28:35.421 JupyterHub app:2768] It took 10.979 seconds for the Hub to start
[D 2022-11-10 16:29:35.422 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:29:35 UTC ] - INFO    : 10.36.1.1:36361 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:29:35.428 JupyterHub proxy:395] Checking routes
[D 2022-11-10 16:29:35.430 JupyterHub app:2425] Managed service session running at http://hub:8181
[D 2022-11-10 16:30:35.422 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2022-11-10 16:30:35.427 JupyterHub proxy:395] Checking routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:30:35 UTC ] - INFO    : 10.36.1.1:5260 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:30:35.428 JupyterHub app:2425] Managed service session running at http://hub:8181
[D 2022-11-10 16:31:35.422 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:31:35 UTC ] - INFO    : 10.36.1.1:23132 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:31:35.429 JupyterHub proxy:395] Checking routes
[D 2022-11-10 16:31:35.430 JupyterHub app:2425] Managed service session running at http://hub:8181
[D 2022-11-10 16:32:35.422 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:32:35 UTC ] - INFO    : 10.36.1.1:6893 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:32:35.426 JupyterHub app:2425] Managed service session running at http://hub:8181
[D 2022-11-10 16:32:35.430 JupyterHub proxy:395] Checking routes
[D 2022-11-10 16:33:35.422 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:33:35 UTC ] - INFO    : 10.36.1.1:41126 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:33:35.428 JupyterHub app:2425] Managed service session running at http://hub:8181
[D 2022-11-10 16:33:35.428 JupyterHub proxy:395] Checking routes
[D 2022-11-10 16:34:35.422 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2022-11-10 16:34:35.427 JupyterHub proxy:395] Checking routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:34:35 UTC ] - INFO    : 10.36.1.1:57124 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:34:35.430 JupyterHub app:2425] Managed service session running at http://hub:8181
[D 2022-11-10 16:35:35.423 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2022-11-10 16:35:35.429 JupyterHub proxy:395] Checking routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:35:35 UTC ] - INFO    : 10.36.1.1:13121 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:35:35.431 JupyterHub app:2425] Managed service session running at http://hub:8181
[D 2022-11-10 16:36:35.423 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2022-11-10 16:36:35.428 JupyterHub proxy:395] Checking routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:36:35 UTC ] - INFO    : 10.36.1.1:55602 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:36:35.430 JupyterHub app:2425] Managed service session running at http://hub:8181
[D 2022-11-10 16:37:35.422 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:37:35 UTC ] - INFO    : 10.36.1.1:36895 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:37:35.427 JupyterHub proxy:395] Checking routes
[D 2022-11-10 16:37:35.429 JupyterHub app:2425] Managed service session running at http://hub:8181
[I 2022-11-10 16:38:28.545 JupyterHub log:186] 200 GET /hub/api/ (jupyterhub-idle-culler@127.0.0.1) 40.87ms
[D 2022-11-10 16:38:28.550 JupyterHub scopes:796] Checking access via scope list:users
[D 2022-11-10 16:38:28.550 JupyterHub scopes:610] Unrestricted access to /hub/api/users via list:users
[I 2022-11-10 16:38:28.553 JupyterHub log:186] 200 GET /hub/api/users?state=[secret] (jupyterhub-idle-culler@127.0.0.1) 6.30ms
[D 2022-11-10 16:38:35.423 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:38:35 UTC ] - INFO    : 10.36.1.1:3591 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:38:35.427 JupyterHub app:2425] Managed service session running at http://hub:8181
[D 2022-11-10 16:38:35.429 JupyterHub proxy:395] Checking routes
[D 2022-11-10 16:39:35.423 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:39:35 UTC ] - INFO    : 10.36.1.1:10589 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:39:35.430 JupyterHub proxy:395] Checking routes
[D 2022-11-10 16:39:35.431 JupyterHub app:2425] Managed service session running at http://hub:8181
[I 2022-11-10 16:40:26.284 JupyterHub log:186] 302 GET / -> /hub/ (@::ffff:10.36.1.229) 1.04ms
[D 2022-11-10 16:40:35.422 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2022-11-10 16:40:35.427 JupyterHub proxy:395] Checking routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:40:35 UTC ] - INFO    : 10.36.1.1:21945 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:40:35.429 JupyterHub app:2425] Managed service session running at http://hub:8181
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:40:40 UTC ] - INFO    : 10.36.1.242:47954 - "GET /services/session HTTP/1.1" 307
[D 2022-11-10 16:41:35.422 JupyterHub proxy:884] Proxy: Fetching GET http://proxy-api:8001/api/routes
[D 2022-11-10 16:41:35.428 JupyterHub proxy:395] Checking routes
[ uvicorn.access  | httptools_impl:send:474 | 2022-11-10 16:41:35 UTC ] - INFO    : 10.36.1.1:14914 - "GET /services/session/ HTTP/1.1" 200
[D 2022-11-10 16:41:35.429 JupyterHub app:2425] Managed service session running at http://hub:8181

proxy logs

16:28:12.461 [ConfigProxy] info: Adding route / -> http://hub:8081
16:28:12.528 [ConfigProxy] info: Proxying http://*:8000 to http://hub:8081
16:28:12.528 [ConfigProxy] info: Proxy API at http://*:8001/api/routes
16:28:12.530 [ConfigProxy] info: Route added / -> http://hub:8081
16:28:28.110 [ConfigProxy] info: 200 GET /api/routes 
16:28:35.409 [ConfigProxy] info: 200 GET /api/routes 
16:28:35.416 [ConfigProxy] info: Adding route / -> http://hub:8081
16:28:35.417 [ConfigProxy] info: Route added / -> http://hub:8081
16:28:35.418 [ConfigProxy] info: 201 POST /api/routes/ 
16:28:35.419 [ConfigProxy] info: Adding route /services/session -> http://hub:8181
16:28:35.419 [ConfigProxy] info: Route added /services/session -> http://hub:8181
16:28:35.422 [ConfigProxy] info: 201 POST /api/routes/services/session 
16:29:35.427 [ConfigProxy] info: 200 GET /api/routes 
16:30:35.426 [ConfigProxy] info: 200 GET /api/routes 
16:31:35.428 [ConfigProxy] info: 200 GET /api/routes 
16:32:35.427 [ConfigProxy] info: 200 GET /api/routes 
16:33:35.426 [ConfigProxy] info: 200 GET /api/routes 
16:34:35.426 [ConfigProxy] info: 200 GET /api/routes 
16:35:35.428 [ConfigProxy] info: 200 GET /api/routes 
16:36:35.427 [ConfigProxy] info: 200 GET /api/routes 
16:37:35.426 [ConfigProxy] info: 200 GET /api/routes 
16:38:35.428 [ConfigProxy] info: 200 GET /api/routes 
16:39:35.430 [ConfigProxy] info: 200 GET /api/routes 
16:40:35.426 [ConfigProxy] info: 200 GET /api/routes 
16:40:40.197 [ConfigProxy] debug: PROXY WEB /services/session to http://hub:8181
16:40:40.203 [ConfigProxy] debug: Not recording activity for status 307 on /services/session

@manics any idea based on the logs?

The issue was in the request. I was missing the / at the end.