wrapspawner not working, while batchspawner working

[hoba87]

Hi,
I have tried the configuration as described on
https://github.com/jupyterhub/batchspawner/
but it won't work.

The configurations for the LocalProcessSpawner and the TorqueSpawner works. But when trying to use the wrapspawner, the LocalProcessSpawner works, while the TorqueSpawner cannot connect to the started server on a node.

I add some output of the jupyterhub logfile, the first part is from the direct TorqueSpawner, the second from the wrapspawner - TorqueSpawner try.

TorqueSpawner

[D 2019-12-17 16:35:00.359 JupyterHub user:240] Creating <class 'batchspawner.batchspawner.TorqueSpawner'> for user1:test2
[D 2019-12-17 16:35:00.363 JupyterHub pages:165] Triggering spawn with default options for user1:test2
[D 2019-12-17 16:35:00.364 JupyterHub base:780] Initiating spawn for user1:test2
[D 2019-12-17 16:35:00.364 JupyterHub base:787] 0/100 concurrent spawns
[D 2019-12-17 16:35:00.364 JupyterHub base:792] 1/4 active servers
[D 2019-12-17 16:35:00.397 JupyterHub user:542] Calling Spawner.start for user1:test2
[I 2019-12-17 16:35:00.398 JupyterHub batchspawner:188] Spawner submitting job using sudo -E -u user1 qsub
[I 2019-12-17 16:35:00.398 JupyterHub batchspawner:189] Spawner submitted script:
#!/bin/sh
#PBS -q batch@cluster-head
#PBS -l walltime=168:00:00
#PBS -l nodes=1:ppn=20
#PBS -l mem=120gb
#PBS -N jupyterhub
#PBS -v PATH,LD_LIBRARY_PATH,LANG,MKL_NUM_THREADS,JUPYTERHUB_API_TOKEN,JPY_API_TOKEN,JUPYTERHUB_CLIENT_ID,JUPYTERHUB_HOST,JUPYTERHUB_OAUTH_CALLBACK_URL,JUPYTERHUB_USER,JUPYTERHUB_SERVER_NAME,JUPYTERHUB_API_URL,JUPYTERHUB_ACTIVITY_URL,JUPYTERHUB_BASE_URL,JUPYTERHUB_SERVICE_PREFIX
module load python/3.6.4
jupyterhub-singleuser --ip=0.0.0.0 --port=33595

[I 2019-12-17 16:35:00.452 JupyterHub batchspawner:192] Job submitted. cmd: sudo -E -u user1 qsub output: 669540.cluster-head
[D 2019-12-17 16:35:00.453 JupyterHub batchspawner:214] Spawner querying job: sudo -E -u user1 qstat -x 669540.cluster-head
[D 2019-12-17 16:35:00.615 JupyterHub batchspawner:316] Job 669540.cluster-head still pending
[D 2019-12-17 16:35:01.118 JupyterHub batchspawner:214] Spawner querying job: sudo -E -u user1 qstat -x 669540.cluster-head
[I 2019-12-17 16:35:01.165 JupyterHub batchspawner:330] Notebook server job 669540.cluster-head started at cluster-node3:33595
[D 2019-12-17 16:35:01.173 JupyterHub spawner:1084] Polling subprocess every 30s
[I 2019-12-17 16:35:01.365 JupyterHub log:174] 302 GET /hub/spawn/user1/test2 -> /hub/spawn-pending/user1/test2 (user1@::ffff:10.50.10.37) 1016.25ms
[I 2019-12-17 16:35:01.391 JupyterHub pages:303] user1:test2 is pending spawn
[I 2019-12-17 16:35:01.393 JupyterHub log:174] 200 GET /hub/spawn-pending/user1/test2 (user1@::ffff:10.50.10.37) 11.48ms
[I 2019-12-17 16:35:05.053 JupyterHub log:174] 200 GET /hub/api (@192.168.0.3) 2.06ms
[D 2019-12-17 16:35:05.075 JupyterHub users:708] Activity for user user1: 2019-12-17T15:35:03.431151Z
[D 2019-12-17 16:35:05.076 JupyterHub users:729] Activity on server user1/test2: 2019-12-17T15:35:03.431151Z
[I 2019-12-17 16:35:05.081 JupyterHub log:174] 200 POST /hub/api/users/user1/activity (user1@192.168.0.3) 19.08ms
[D 2019-12-17 16:35:08.674 JupyterHub utils:218] Server at http://cluster-node3:33595/user/user1/test2/ responded with 302
[D 2019-12-17 16:35:08.675 JupyterHub _version:60] jupyterhub and jupyterhub-singleuser both on version 1.0.0
[I 2019-12-17 16:35:08.675 JupyterHub base:810] User user1:test2 took 8.311 seconds to start
[I 2019-12-17 16:35:08.675 JupyterHub proxy:261] Adding user user1 to proxy /user/user1/test2/ => http://cluster-node3:33595
[D 2019-12-17 16:35:08.676 JupyterHub proxy:765] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/user/user1/test2
[I 2019-12-17 16:35:08.682 JupyterHub users:606] Server user1:test2 is ready
[I 2019-12-17 16:35:08.683 JupyterHub log:174] 200 GET /hub/api/users/user1/servers/test2/progress (user1@::ffff:10.50.10.37) 7202.35ms
[I 2019-12-17 16:35:08.725 JupyterHub log:174] 302 GET /hub/spawn-pending/user1/test2 -> /user/user1/test2 (user1@::ffff:10.50.10.37) 9.94ms
[D 2019-12-17 16:35:08.801 JupyterHub provider:414] Validating client id jupyterhub-user-user1-test2
[D 2019-12-17 16:35:08.804 JupyterHub provider:492] validate_redirect_uri: client_id=jupyterhub-user-user1-test2, redirect_uri=/user/user1/test2/oauth_callback
[D 2019-12-17 16:35:08.808 JupyterHub auth:222] Skipping oauth confirmation for <User(user1 2/3 running)> accessing Server at /user/user1/test2/
[D 2019-12-17 16:35:08.809 JupyterHub provider:414] Validating client id jupyterhub-user-user1-test2
[D 2019-12-17 16:35:08.811 JupyterHub provider:492] validate_redirect_uri: client_id=jupyterhub-user-user1-test2, redirect_uri=/user/user1/test2/oauth_callback
[D 2019-12-17 16:35:08.814 JupyterHub provider:241] Saving authorization code jupyterhub-user-user1-test2, VVr..., (), {}
[I 2019-12-17 16:35:08.824 JupyterHub log:174] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-user1-test2&redirect_uri=%2Fuser%2Fuser1%2Ftest2%2Foauth_callback&response_type=code&state=[secret] -> /user/user1/test2/oauth_callback?code=[secret]&state=[secret] (user1@::ffff:10.50.10.37) 33.45ms
[D 2019-12-17 16:35:08.856 JupyterHub provider:60] authenticate_client <oauthlib.Request SANITIZED>
[D 2019-12-17 16:35:08.869 JupyterHub provider:119] confirm_redirect_uri: client_id=jupyterhub-user-user1-test2, redirect_uri=/user/user1/test2/oauth_callback
[D 2019-12-17 16:35:08.869 JupyterHub provider:339] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 3600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2019-12-17 16:35:08.877 JupyterHub provider:194] Deleting oauth code VVr... for jupyterhub-user-user1-test2
[I 2019-12-17 16:35:08.885 JupyterHub log:174] 200 POST /hub/api/oauth2/token (user1@192.168.0.3) 37.53ms
[I 2019-12-17 16:35:08.913 JupyterHub log:174] 200 GET /hub/api/authorizations/token/[secret] (user1@192.168.0.3) 22.52ms
[D 2019-12-17 16:35:09.194 JupyterHub log:174] 200 GET /hub/logo (@::ffff:10.50.10.37) 2.20ms
[W 2019-12-17 16:35:10.136 JupyterHub web:1618] 400 POST /hub/api/users/user1/activity (192.168.0.254): No such server 'Head Node' for user user1
[W 2019-12-17 16:35:10.137 JupyterHub log:174] 400 POST /hub/api/users/user1/activity (user1@192.168.0.254) 15.07ms
[W 2019-12-17 16:35:10.860 JupyterHub web:1618] 400 POST /hub/api/users/user1/activity (192.168.0.254): No such server 'Head Node' for user user1
[W 2019-12-17 16:35:10.861 JupyterHub log:174] 400 POST /hub/api/users/user1/activity (user1@192.168.0.254) 14.92ms
[W 2019-12-17 16:35:12.832 JupyterHub web:1618] 400 POST /hub/api/users/user1/activity (192.168.0.254): No such server 'Head Node' for user user1
[W 2019-12-17 16:35:12.833 JupyterHub log:174] 400 POST /hub/api/users/user1/activity (user1@192.168.0.254) 14.32ms
[W 2019-12-17 16:35:15.929 JupyterHub web:1618] 400 POST /hub/api/users/user1/activity (192.168.0.254): No such server 'Head Node' for user user1
[W 2019-12-17 16:35:15.931 JupyterHub log:174] 400 POST /hub/api/users/user1/activity (user1@192.168.0.254) 14.49ms

Wrapspawner -> TorqueSpawner

[D 2019-12-17 17:32:11.603 JupyterHub user:240] Creating <class 'wrapspawner.wrapspawner.ProfilesSpawner'> for user1:test2
[D 2019-12-17 17:32:11.635 JupyterHub pages:158] Serving options form for user1:test2
[I 2019-12-17 17:32:11.637 JupyterHub log:174] 200 GET /hub/spawn/user1/test2 (user1@::ffff:10.50.10.37) 43.30ms
[D 2019-12-17 17:32:13.678 JupyterHub base:780] Initiating spawn for user1:test2
[D 2019-12-17 17:32:13.679 JupyterHub base:787] 0/100 concurrent spawns
[D 2019-12-17 17:32:13.679 JupyterHub base:792] 0/4 active servers
[D 2019-12-17 17:32:13.715 JupyterHub user:542] Calling Spawner.start for user1:test2
[I 2019-12-17 17:32:13.744 JupyterHub batchspawner:188] Spawner submitting job using sudo -E -u user1 qsub
[I 2019-12-17 17:32:13.744 JupyterHub batchspawner:189] Spawner submitted script:
#!/bin/sh
#PBS -q batch@cluster-head
#PBS -l walltime=168:00:00
#PBS -l nodes=1:ppn=20
#PBS -l mem=120gb
#PBS -N jupyterhub
#PBS -v PATH,LD_LIBRARY_PATH,LANG,MKL_NUM_THREADS,JUPYTERHUB_API_TOKEN,JPY_API_TOKEN,JUPYTERHUB_CLIENT_ID,JUPYTERHUB_HOST,JUPYTERHUB_OAUTH_CALLBACK_URL,JUPYTERHUB_USER,JUPYTERHUB_SERVER_NAME,JUPYTERHUB_API_URL,JUPYTERHUB_ACTIVITY_URL,JUPYTERHUB_BASE_URL,JUPYTERHUB_SERVICE_PREFIX
#PBS -j oe
#PBS -o /dev/null
module load python/3.6.4
jupyterhub-singleuser --port=45951

[I 2019-12-17 17:32:14.126 JupyterHub batchspawner:192] Job submitted. cmd: sudo -E -u user1 qsub output: 669551.cluster-head
[D 2019-12-17 17:32:14.128 JupyterHub batchspawner:214] Spawner querying job: sudo -E -u user1 qstat -x 669551.cluster-head
[D 2019-12-17 17:32:14.266 JupyterHub batchspawner:316] Job 669551.cluster-head still pending
[D 2019-12-17 17:32:14.768 JupyterHub batchspawner:214] Spawner querying job: sudo -E -u user1 qstat -x 669551.cluster-head
[D 2019-12-17 17:32:14.817 JupyterHub batchspawner:316] Job 669551.cluster-head still pending
[D 2019-12-17 17:32:15.319 JupyterHub batchspawner:214] Spawner querying job: sudo -E -u user1 qstat -x 669551.cluster-head
[I 2019-12-17 17:32:15.371 JupyterHub batchspawner:330] Notebook server job 669551.cluster-head started at cluster-node4:45951
[D 2019-12-17 17:32:15.378 JupyterHub spawner:1084] Polling subprocess every 30s
[I 2019-12-17 17:32:18.392 JupyterHub log:174] 200 GET /hub/api (@192.168.0.4) 1.60ms
[D 2019-12-17 17:32:18.415 JupyterHub users:708] Activity for user user1: 2019-12-17T16:32:16.962407Z
[D 2019-12-17 17:32:18.415 JupyterHub users:729] Activity on server user1/test2: 2019-12-17T16:32:16.962407Z
[I 2019-12-17 17:32:18.421 JupyterHub log:174] 200 POST /hub/api/users/user1/activity (user1@192.168.0.4) 20.17ms
[D 2019-12-17 17:32:23.682 JupyterHub batchspawner:214] Spawner querying job: sudo -E -u user1 qstat -x 669551.cluster-head
[W 2019-12-17 17:32:23.730 JupyterHub base:932] User user1:test2 is slow to become responsive (timeout=10)
[D 2019-12-17 17:32:23.730 JupyterHub base:937] Expecting server for user1:test2 at: http://cluster-node4:45951/user/user1/test2/
[I 2019-12-17 17:32:23.741 JupyterHub log:174] 302 POST /hub/spawn/user1/test2 -> /hub/spawn-pending/user1/test2 (user1@::ffff:10.50.10.37) 10071.92ms
[I 2019-12-17 17:32:23.779 JupyterHub pages:303] user1:test2 is pending spawn
[I 2019-12-17 17:32:23.781 JupyterHub log:174] 200 GET /hub/spawn-pending/user1/test2 (user1@::ffff:10.50.10.37) 9.90ms
[D 2019-12-17 17:32:45.381 JupyterHub batchspawner:214] Spawner querying job: sudo -E -u user1 qstat -x 669551.cluster-head
[D 2019-12-17 17:33:15.383 JupyterHub batchspawner:214] Spawner querying job: sudo -E -u user1 qstat -x 669551.cluster-head

[hoba87]

I've updated all packages, however the problem still persists. The log output changes a bit, therefore I append it again:

One error I get multiple times for both but probably thats not the problem here (deleted from the following logs):

jupyterhub: [W JupyterHub log:174] 403 POST /hub/api/users/user1/activity (@192.168.0.254) 3.26ms
jupyterhub: [E SingleUserNotebookApp singleuser:523] Error notifying Hub of activity
jupyterhub: Traceback (most recent call last):
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/singleuser.py", line 521, in notify
jupyterhub: await client.fetch(req)
jupyterhub: tornado.httpclient.HTTPError: HTTP 403: Forbidden

TorqueSpawner:

systemd: Starting Jupyterhub...
jupyterhub: [I JupyterHub app:2120] Using Authenticator: jupyterhub.auth.PAMAuthenticator-1.0.0
jupyterhub: [I JupyterHub app:2120] Using Spawner: batchspawner.batchspawner.TorqueSpawner
jupyterhub: [I JupyterHub app:1257] Loading cookie_secret from /etc/jupyterhub/jupyterhub_cookie_secret
jupyterhub: [I JupyterHub proxy:460] Generating new CONFIGPROXY_AUTH_TOKEN
jupyterhub: [I JupyterHub app:1563] Not using whitelist. Any authenticated user will be allowed.
jupyterhub: [I JupyterHub app:2337] Hub API listening on http://192.168.0.254:8081/hub/
jupyterhub: [I JupyterHub proxy:645] Starting proxy @ http://:8000
jupyterhub: [ConfigProxy] info: Proxying https://*:8000 to (no default)
jupyterhub: [ConfigProxy] info: Proxy API at http://127.0.0.1:8001/api/routes
jupyterhub: [I JupyterHub proxy:319] Checking routes
jupyterhub: [I JupyterHub proxy:399] Adding default route for Hub: / => http://192.168.0.254:8081
jupyterhub: [ConfigProxy] info: 200 GET /api/routes
jupyterhub: [ConfigProxy] info: Adding route / -> http://192.168.0.254:8081
jupyterhub: [ConfigProxy] info: Route added / -> http://192.168.0.254:8081
jupyterhub: [ConfigProxy] info: 201 POST /api/routes/
jupyterhub: [I JupyterHub app:2422] JupyterHub is now running at http://:8000
jupyterhub: [I JupyterHub log:174] 200 GET /hub/spawn-pending/user1 (user1@::ffff:10.50.10.37) 60.55ms
jupyterhub: [I JupyterHub batchspawner:188] Spawner submitting job using sudo -E -u user1 qsub
jupyterhub: [I JupyterHub batchspawner:189] Spawner submitted script:
jupyterhub: #!/bin/sh
jupyterhub: #PBS -q batch@head
jupyterhub: #PBS -l walltime=12:00:00
jupyterhub: #PBS -l nodes=1:ppn=1
jupyterhub: #PBS -l mem=6gb
jupyterhub: #PBS -N jupyterhub
jupyterhub: #PBS -v PATH,LD_LIBRARY_PATH,LANG,MKL_NUM_THREADS,JUPYTERHUB_API_TOKEN,JPY_API_TOKEN,JUPYTERHUB_CLIENT_ID,JUPYTERHUB_HOST,JUPYTERHUB_OAUTH_CALLBACK_URL,JUPYTERHUB_USER,JUPYTERHUB_SERVER_NAME,JUPYTERHUB_API_URL,JUPYTERHUB_ACTIVITY_URL,JUPYTERHUB_BASE_URL,JUPYTERHUB_SERVICE_PREFIX
jupyterhub: #PBS -j oe
jupyterhub: #PBS -o /dev/null
jupyterhub: module load python/3.6.4
jupyterhub: jupyterhub-singleuser --ip=0.0.0.0 --port=49760
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qsub
jupyterhub: [I JupyterHub batchspawner:192] Job submitted. cmd: sudo -E -u user1 qsub output: 669591.head
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669591.head
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669591.head
jupyterhub: [I JupyterHub log:174] 302 GET /hub/spawn/user1 -> /hub/spawn-pending/user1 (user1@::ffff:10.50.10.37) 1010.97ms
jupyterhub: [I JupyterHub pages:303] user1 is pending spawn
jupyterhub: [I JupyterHub log:174] 200 GET /hub/spawn-pending/user1 (user1@::ffff:10.50.10.37) 18.72ms
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669591.head
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669591.head
jupyterhub: [I JupyterHub batchspawner:330] Notebook server job 669591.head started at node4:49760
jupyterhub: [I JupyterHub log:174] 200 GET /hub/api (@192.168.0.4) 1.65ms
jupyterhub: [I JupyterHub log:174] 200 POST /hub/api/users/user1/activity (user1@192.168.0.4) 20.98ms
jupyterhub: [I JupyterHub base:810] User user1 took 4.826 seconds to start
jupyterhub: [I JupyterHub proxy:261] Adding user user1 to proxy /user/user1/ => http://node4:49760
jupyterhub: [ConfigProxy] info: Adding route /user/user1 -> http://node4:49760
jupyterhub: [ConfigProxy] info: Route added /user/user1 -> http://node4:49760
jupyterhub: [ConfigProxy] info: 201 POST /api/routes/user/user1
jupyterhub: [I JupyterHub users:606] Server user1 is ready
jupyterhub: [I JupyterHub log:174] 200 GET /hub/api/users/user1/server/progress (user1@::ffff:10.50.10.37) 3706.19ms
jupyterhub: [I JupyterHub log:174] 302 GET /hub/spawn-pending/user1 -> /user/user1/ (user1@::ffff:10.50.10.37) 9.32ms
jupyterhub: [I JupyterHub log:174] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-user1&redirect_uri=%2Fuser%2Fuser1%2Foauth_callback&response_type=code&state=[secret] -> /user/user1/oauth_callback?code=[secret]&state=[secret] (user1@::ffff:10.50.10.37) 28.73ms
jupyterhub: [I JupyterHub log:174] 200 POST /hub/api/oauth2/token (user1@192.168.0.4) 37.00ms
jupyterhub: [I JupyterHub log:174] 200 GET /hub/api/authorizations/token/[secret] (user1@192.168.0.4) 27.11ms

WrapSpawner:

systemd: Starting Jupyterhub...
jupyterhub: [I JupyterHub app:2120] Using Authenticator: jupyterhub.auth.PAMAuthenticator-1.0.0
jupyterhub: [I JupyterHub app:2120] Using Spawner: wrapspawner.wrapspawner.ProfilesSpawner
jupyterhub: [I JupyterHub app:1257] Loading cookie_secret from /etc/jupyterhub/jupyterhub_cookie_secret
jupyterhub: [I JupyterHub proxy:460] Generating new CONFIGPROXY_AUTH_TOKEN
jupyterhub: [I JupyterHub app:1563] Not using whitelist. Any authenticated user will be allowed.
jupyterhub: [I JupyterHub app:2337] Hub API listening on http://192.168.0.254:8081/hub/
jupyterhub: [I JupyterHub proxy:645] Starting proxy @ http://:8000
jupyterhub: [ConfigProxy] info: Proxying https://*:8000 to (no default)
jupyterhub: [ConfigProxy] info: Proxy API at http://127.0.0.1:8001/api/routes
jupyterhub: [I JupyterHub proxy:319] Checking routes
jupyterhub: [I JupyterHub proxy:399] Adding default route for Hub: / => http://192.168.0.254:8081
jupyterhub: [ConfigProxy] info: 200 GET /api/routes
jupyterhub: [ConfigProxy] info: Adding route / -> http://192.168.0.254:8081
jupyterhub: [ConfigProxy] info: Route added / -> http://192.168.0.254:8081
jupyterhub: [ConfigProxy] info: 201 POST /api/routes/
jupyterhub: [I JupyterHub app:2422] JupyterHub is now running at http://:8000
jupyterhub: [I JupyterHub log:174] 200 GET /hub/spawn-pending/user1?next=%2Fhub%2Fuser%2Fuser1%2Ftree%2Fpython (user1@::ffff:10.50.10.37) 86.45ms
jupyterhub: [I JupyterHub log:174] 200 GET /hub/spawn/user1 (user1@::ffff:10.50.10.37) 19.47ms
jupyterhub: [I JupyterHub batchspawner:188] Spawner submitting job using sudo -E -u user1 qsub
jupyterhub: [I JupyterHub batchspawner:189] Spawner submitted script:
jupyterhub: #!/bin/sh
jupyterhub: #PBS -q batch@head
jupyterhub: #PBS -l walltime=12:00:00
jupyterhub: #PBS -l nodes=1:ppn=1
jupyterhub: #PBS -l mem=6gb
jupyterhub: #PBS -N jupyterhub
jupyterhub: #PBS -v PATH,LD_LIBRARY_PATH,LANG,MKL_NUM_THREADS,JUPYTERHUB_API_TOKEN,JPY_API_TOKEN,JUPYTERHUB_CLIENT_ID,JUPYTERHUB_HOST,JUPYTERHUB_OAUTH_CALLBACK_URL,JUPYTERHUB_USER,JUPYTERHUB_SERVER_NAME,JUPYTERHUB_API_URL,JUPYTERHUB_ACTIVITY_URL,JUPYTERHUB_BASE_URL,JUPYTERHUB_SERVICE_PREFIX
jupyterhub: #PBS -j oe
jupyterhub: #PBS -o /dev/null
jupyterhub: module load python/3.6.4
jupyterhub: jupyterhub-singleuser --port=39969
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qsub
jupyterhub: [I JupyterHub batchspawner:192] Job submitted. cmd: sudo -E -u user1 qsub output: 669590.head
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669590.head
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669590.head
jupyterhub: [I JupyterHub batchspawner:330] Notebook server job 669590.head started at node4:39969
jupyterhub: [I JupyterHub log:174] 200 GET /hub/api (@192.168.0.4) 1.63ms
jupyterhub: [I JupyterHub log:174] 200 POST /hub/api/users/user1/activity (user1@192.168.0.4) 22.22ms
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669590.head
jupyterhub: [W JupyterHub base:932] User user1 is slow to become responsive (timeout=10)
jupyterhub: [I JupyterHub log:174] 302 POST /hub/spawn/user1 -> /hub/spawn-pending/user1 (user1@::ffff:10.50.10.37) 10073.17ms
jupyterhub: [I JupyterHub pages:303] user1 is pending spawn
jupyterhub: [I JupyterHub log:174] 200 GET /hub/spawn-pending/user1 (user1@::ffff:10.50.10.37) 13.32ms
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669590.head
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669590.head
jupyterhub: [E SingleUserNotebookApp singleuser:548] Error notifying Hub of activity
jupyterhub: Traceback (most recent call last):
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/singleuser.py", line 546, in keep_activity_updated
jupyterhub: await self.notify_activity()
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/singleuser.py", line 533, in notify_activity
jupyterhub: timeout=60,
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/utils.py", line 177, in exponential_backoff
jupyterhub: raise TimeoutError(fail_message)
jupyterhub: TimeoutError: Failed to notify Hub of activity
jupyterhub: [W JupyterHub user:678] user1's server never showed up at http://node4:39969/user/user1/ after 120 seconds. Giving up
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669590.head
jupyterhub: [I JupyterHub batchspawner:342] Stopping server job 669590.head
jupyterhub: [I JupyterHub batchspawner:233] Cancelling job 669590.head: sudo -E -u user1 qdel 669590.head
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qdel 669590.head
sudo: root : TTY=unknown ; PWD=/etc/jupyterhub ; USER=user1 ; COMMAND=/bin/qstat -x 669590.head
jupyterhub: [E JupyterHub batchspawner:219] Error querying job 669590.head
jupyterhub: [E JupyterHub gen:599] Exception in Future <Task finished coro=<BaseHandler.spawn_single_user..finish_user_spawn() done, defined at /opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/handlers/base.py:800> exception=TimeoutError("Server at http://node4:39969/user/user1/ didn't respond in 120 seconds",)> after timeout
jupyterhub: Traceback (most recent call last):
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/tornado/gen.py", line 593, in error_callback
jupyterhub: future.result()
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 807, in finish_user_spawn
jupyterhub: await spawn_future
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/user.py", line 654, in spawn
jupyterhub: await self._wait_up(spawner)
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/user.py", line 701, in _wait_up
jupyterhub: raise e
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/user.py", line 669, in _wait_up
jupyterhub: http=True, timeout=spawner.http_timeout, ssl_context=ssl_context
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/utils.py", line 234, in wait_for_http_server
jupyterhub: timeout=timeout,
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/utils.py", line 177, in exponential_backoff
jupyterhub: raise TimeoutError(fail_message)
jupyterhub: TimeoutError: Server at http://node4:39969/user/user1/ didn't respond in 120 seconds
jupyterhub: [I JupyterHub log:174] 200 GET /hub/api/users/user1/server/progress (user1@::ffff:10.50.10.37) 103635.69ms
jupyterhub: [E SingleUserNotebookApp singleuser:548] Error notifying Hub of activity
jupyterhub: Traceback (most recent call last):
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/singleuser.py", line 546, in keep_activity_updated
jupyterhub: await self.notify_activity()
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/singleuser.py", line 533, in notify_activity
jupyterhub: timeout=60,
jupyterhub: File "/opt/python/python-3.6.4/lib/python3.6/site-packages/jupyterhub/utils.py", line 177, in exponential_backoff
jupyterhub: raise TimeoutError(fail_message)
jupyterhub: TimeoutError: Failed to notify Hub of activity

[hoba87]

That is my configuration:

import batchspawner
c.Spawner.http_timeout = 120

c.BatchSpawnerBase.req_nprocs = '1'
c.BatchSpawnerBase.req_queue = 'batch'
c.BatchSpawnerBase.req_host = 'head'
c.BatchSpawnerBase.req_runtime = '12:00:00'
c.BatchSpawnerBase.req_memory = '6gb'

c.TorqueSpawner.batch_script = '''#!/bin/sh
#PBS -q {queue}@{host}
#PBS -l walltime={runtime}
#PBS -l nodes=1:ppn={nprocs}
#PBS -l mem={memory}
#PBS -N jupyterhub
#PBS -v {keepvars}
#PBS -j oe
#PBS -o /dev/null
module load python/3.6.4
{cmd}
'''

c.JupyterHub.spawner_class = 'wrapspawner.ProfilesSpawner'
c.ProfilesSpawner.profiles = [
( "Head Node", 'local', 'jupyterhub.spawner.LocalProcessSpawner', {'ip':'0.0.0.0'}),
( "Compute Node, 1core, 6GB, 12 hours", 'compute-c1r6t0.5', 'batchspawner.TorqueSpawner', {}),
( "Compute Node, 1core, 6GB, 7 days", 'compute-c1r6t7', 'batchspawner.TorqueSpawner', dict(req_runtime='168:00:00')),
( "Compute Node, 20cores, 120GB, 7 days", 'compute-c20r120t7', 'batchspawner.TorqueSpawner', dict(req_nprocs='20', req_memory='120gb', req_runtime='168:00:00')),
]

[hoba87]

with adding
c.ProfilesSpawner.ip = '0.0.0.0'
to the configuration, I was able to workaround it. Then the logs also tells for the wrapspawner:

jupyterhub: jupyterhub-singleuser --ip=0.0.0.0 --port=49760

This was not able to be solved by setting the ip in the profiles, like is done for the LocalProcessSpawner in the examples given by https://github.com/jupyterhub/batchspawner/

[gmfricke]

Thank you that worked :)