Error 431 (headers too big) during singleuser oauth

gfg4 · October 10, 2023, 11:57am

Hey,

I’m using jupyterhub with kubespawner to create servers for my users. Sometimes we get complains about hitting a 431 error (Request header fields too large). Upon further investigation, looks like the -oauth-state cookie is created at least 11 times and they are never deleted, making the request headers too big. Our current fix consists in asking the users to delete their cookies.

Does anyone know what could be the issue?

How to reproduce

It happens randomly and I’m unable to reproduce it

Expected behaviour

I’m expecting to have in the worst case only one oauth-state cookie, not as many as possible until headers get too long.

Actual behaviour

I’m getting several oauth-state cookies with different ids:

jupyterhub-user-[username]-oauth-state=[cookie]
jupyterhub-user-[username]-oauth-state-UvZREBjB=[cookie]
jupyterhub-user-[username]-oauth-state-NBNVBKOg=[cookie]
jupyterhub-user-[username]-oauth-state-TNmHVRmd=[cookie]
... (at least 11 times, first cookie does not have an id after oauth-state)
jupyterhub-user-carlos-dominguez=[cookie]

Your personal set up

OS:
ubuntu 20.04

Full environment

#
# This file is autogenerated by pip-compile with Python 3.9
# by the following command:
#
#    pip-compile requirements.in
#
aiofiles==23.2.1
    # via jupyterhub-announcement
aiohttp==3.8.6
    # via kubernetes-asyncio
aiosignal==1.3.1
    # via aiohttp
alembic==1.12.0
    # via jupyterhub
async-generator==1.10
    # via jupyterhub
async-timeout==4.0.3
    # via aiohttp
attrs==23.1.0
    # via
    #   aiohttp
    #   jsonschema
    #   referencing
beautifulsoup4==4.12.2
    # via html-sanitizer
cachetools==5.3.1
    # via google-auth
certifi==2023.7.22
    # via
    #   kubernetes
    #   kubernetes-asyncio
    #   requests
certipy==0.1.3
    # via jupyterhub
cffi==1.16.0
    # via cryptography
charset-normalizer==3.3.0
    # via
    #   aiohttp
    #   requests
cryptography==41.0.4
    # via pyopenssl
escapism==1.0.1
    # via jupyterhub-kubespawner
frozenlist==1.4.0
    # via
    #   aiohttp
    #   aiosignal
google-auth==2.23.3
    # via kubernetes
html-sanitizer==2.2.0
    # via jupyterhub-announcement
hvac==1.2.1
    # via -r requirements.in
idna==3.4
    # via
    #   requests
    #   yarl
importlib-metadata==6.8.0
    # via jupyterhub
jinja2==3.1.2
    # via
    #   jupyterhub
    #   jupyterhub-kubespawner
json-log-formatter==0.5.2
    # via -r requirements.in
jsonschema==4.19.1
    # via jupyter-telemetry
jsonschema-specifications==2023.7.1
    # via jsonschema
jupyter-telemetry==0.1.0
    # via jupyterhub
jupyterhub==4.0.2
    # via
    #   -r requirements.in
    #   jupyterhub-announcement
    #   jupyterhub-kubespawner
jupyterhub-announcement==0.9.1
    # via -r requirements.in
jupyterhub-idle-culler==1.2.1
    # via -r requirements.in
jupyterhub-kubespawner==4.3.0
    # via -r requirements.in
kubernetes==28.1.0
    # via -r requirements.in
kubernetes-asyncio==28.2.0
    # via jupyterhub-kubespawner
lxml==4.9.3
    # via html-sanitizer
mako==1.2.4
    # via alembic
markupsafe==2.1.3
    # via
    #   jinja2
    #   mako
multidict==6.0.4
    # via
    #   aiohttp
    #   yarl
oauthlib==3.2.2
    # via
    #   jupyterhub
    #   kubernetes
    #   requests-oauthlib
packaging==23.2
    # via jupyterhub
pamela==1.1.0
    # via jupyterhub
prometheus-client==0.17.1
    # via jupyterhub
pyasn1==0.5.0
    # via
    #   pyasn1-modules
    #   rsa
pyasn1-modules==0.3.0
    # via google-auth
pycparser==2.21
    # via cffi
pycurl==7.45.2
    # via -r requirements.in
pyhcl==0.4.5
    # via hvac
pyopenssl==23.2.0
    # via certipy
python-dateutil==2.8.2
    # via
    #   jupyterhub
    #   jupyterhub-idle-culler
    #   kubernetes
    #   kubernetes-asyncio
python-json-logger==2.0.7
    # via jupyter-telemetry
python-slugify==8.0.1
    # via jupyterhub-kubespawner
pyyaml==6.0.1
    # via
    #   jupyterhub-kubespawner
    #   kubernetes
    #   kubernetes-asyncio
referencing==0.30.2
    # via
    #   jsonschema
    #   jsonschema-specifications
requests==2.31.0
    # via
    #   hvac
    #   jupyterhub
    #   kubernetes
    #   requests-oauthlib
requests-oauthlib==1.3.1
    # via kubernetes
rpds-py==0.10.4
    # via
    #   jsonschema
    #   referencing
rsa==4.9
    # via google-auth
ruamel-yaml==0.17.35
    # via jupyter-telemetry
ruamel-yaml-clib==0.2.8
    # via ruamel-yaml
six==1.16.0
    # via
    #   kubernetes
    #   kubernetes-asyncio
    #   python-dateutil
soupsieve==2.5
    # via beautifulsoup4
sqlalchemy==2.0.21
    # via
    #   alembic
    #   jupyterhub
text-unidecode==1.3
    # via python-slugify
tornado==6.3.3
    # via
    #   jupyterhub
    #   jupyterhub-idle-culler
traitlets==5.11.2
    # via
    #   jupyter-telemetry
    #   jupyterhub
typing-extensions==4.8.0
    # via
    #   alembic
    #   sqlalchemy
urllib3==1.26.17
    # via
    #   jupyterhub-kubespawner
    #   kubernetes
    #   kubernetes-asyncio
    #   requests
websocket-client==1.6.4
    # via kubernetes
yarl==1.9.2
    # via aiohttp
zipp==3.17.0
    # via importlib-metadata

# The following packages are considered to be unsafe in a requirements file:
# setuptools

minrk · October 18, 2023, 2:10pm

What is the expiration on the cookie(s) and what browser are you using? JupyterHub oauth state cookies are set to expire after 10 minutes, and should be cleared when consumed.

Here’s how it’s supposed to work:

only jupyterhub-user-username-oauth-state is set
on successful completion of oauth, cookie is cleared
if oauth doesn’t complete within 10 minutes, cookie is cleared, having been set with max-age: 600

And where it gets complicated:

if oauth begins and jupyterhub-user-username-oauth-state is already set (i.e. another oauth flow is still outstanding), use a random cookie suffix to avoid mixing state between two oauths happening in the same browser.

So the underlying issue is that oauth state cookies aren’t getting cleared (or at least not promptly). My guess is the root is in cookie_options, and the Max-Age: 600 not having any effect, so every failed oauth is taking up space for longer than it should. Do you perhaps have any cookie_options set? What is $JUPYTERHUB_COOKIE_OPTIONS in the user server environment?

gfg4 · October 18, 2023, 4:55pm

Hey, thanks for replying

The JUPYTERHUB_COOKIE_OPTIONS environment variable is empty and I’m not setting up any cookie_options.

I was thinking on creating a patch to change the expiration time from 600 seconds to 10 seconds so that cookies are cleared earlier.

What do you think about this change? or Is there any specific reason to be 600 seconds?

Thanks

minrk · October 19, 2023, 9:46am

Can you see the expiration on the cookies you have that are lingering?

The time needs to account not just for the no-confirmation roundtrip oauth with JupyterHub if you’re already authenticated, but also the actual login with the upstream authentication provider, which can include entering passwords, 2fa codes, etc. and reading oauth confirmation pages (potentially at two levels - the upstream authenticator and jupyterhub itself), etc.

Something definitely seems wrong in the cookie expiration if any browser has more than 2 of these cookies for any period of time.

gfg4 · October 19, 2023, 6:26pm

Cookies expiration date look right, 10 minutes exactly.

I’m sometimes able to reproduce this by clicking reload (multiple times) during the creation of the server (not always work). By doing this I can get first, the oauth-state and if I do this again I can get the oauth-state-<id>

In my case, our users only need to login before the server creation and they need to be connected to the VPN.

minrk · October 27, 2023, 8:39am

It does make sense that refreshing pages in the middle of oauth redirects would start multiple oauth redirects before they finish.

move service oauth state fields to in-memory by minrk · Pull Request #4608 · jupyterhub/jupyterhub · GitHub changes things a bit to:

reduce the size of the oauth state cookie to a single uid instead of a larger blob, and
clear all oauth state cookies on any successful login, rather than only the consumed one

This should both greatly increase the number of simultaneous oauths required to trigger 431, and improve the behavior in the most common case where background or aborted requests are responsible for the additional oauth flows, and only one is ever likely to complete

It would be useful to get the logs from the single-user server to see the redirects which are prompting the multiple oauth flows, if possible.

gfg4 · October 27, 2023, 9:12am

Awesome! thanks for your help!

Do you know what kind of logs are you looking for? We use datadog for storing them, but because this is so random is really difficult to find them.

I tried with:
431
request header fields too large
but nothing comes

minrk · October 27, 2023, 9:29am

The 431 is the symptom after it’s gone wrong. The source will be logs from the single-user server with 302 GET, e.g.

[I 2023-10-27 11:25:42.717 minrk] 302 GET /user/test/lab -> /hub/api/oauth2/authorize?client_id=jupyterhub-user-test&redirect_uri=%2Fuser%2Ftest%2Foauth_callback&response_type=code&state=[secret] (@::1) 1.13ms

It will also be helpful to share the startup logs of the single-user server, which include versions of everything and some configuration info.

-Min

minrk · October 27, 2023, 9:32am

In fact, any log line with ‘oauth’ would be good, since that will capture both the start and completion of oauth.

gfg4 · October 27, 2023, 2:59pm

Not sure if these logs are going to be helpful, but I can’t get exactly the ones were I get the 431 error. These are the most common ones that I found in the last month using jupyterhub==4.0.2

Warning logs:

Detected unused OAuth state cookies (over ~13k logs)

403 GET /user/[username]/oauth_callback?=[code] [IP]: oauth state does not match. Try logging in again. (<1k logs)

oauth state '[state value]' != '[some other state value]' (<1k logs)

oauth state '[state value]' != None (<1k logs)

Debug logs

Setting oauth cookie for [IP]: *, {'path': '/user/[username]/[path] 'httponly': True, 'secure': True} (<1k logs)

Allowing Hub user [username] based on oauth scopes {'access:servers!server=[username]/'} (<1k logs)

minrk · November 2, 2023, 7:13pm

Thanks, that definitely means that too many oauth redirects are being started.

An actual contiguous log segment with the oauth redirects would be the biggest help (only lines with oauth would be fine, but in order for one server will help a ton), so I can see the oauth events starting and finishing in sequence.

I think the most useful will be the redirects (i.e. what URL is being redirected to /hub/api/oauth2/authorize). Because I’m almost certain it’s a background

And for this, an export of the single-user environment (especially jupyterhub, jupyterlab, and jupyter-server version, but ideally everything) would be a big help. As would the startup blob where jupyter-server logs the versions of packages and extensions it’s using.

gfg4 · November 8, 2023, 12:42pm

Sorry for the delay, here are the contiguous logs of a redirect. I will try to have an export of the user env by EOD or tomorrow

Date	                    Service	            Message
2023-11-08T12:14:24.881Z	"nbt-singleuser"	302 GET /user/[user]-> /user/[user]/lab? (@[IP]) 0.80ms
2023-11-08T12:14:24.881Z	"nbt-singleuser"	HubAuth cache miss: token:[token]
2023-11-08T12:14:24.881Z	"nbt-singleuser"	No Hub user identified for request
2023-11-08T12:14:24.881Z	"nbt-singleuser"	Token stored in cookie may have expired
2023-11-08T12:14:24.881Z	"nbt-singleuser"	No user identified
2023-11-08T12:14:24.881Z	"nbt-singleuser"	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T12:14:24.881Z	"nbt-singleuser"	302 GET /user/[user]/lab? -> /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[secret] (@[IP]) 29.77ms
2023-11-08T12:14:25.882Z	"nbt-singleuser"	HubAuth cache miss: token:[token]
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Received request from Hub user {'kind': 'user', 'admin': False, 'name': ‘[user]’, 'groups': [[… list of groups …], 'session_id': ‘[session_id]’, 'scopes': [‘access:servers!server=[user]/‘, ‘read:users:groups!user=[user]’, ‘read:users:name!user=[user]’]}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Logged-in user {'kind': 'user', 'admin': False, 'name': '[user]', 'groups': [ [..list of groups…]], 'session_id': ‘[session_id]’, 'scopes': ['access:servers!server=[user]/', 'read:users:groups!user=[user]', 'read:users:name!user=[user]']}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Setting oauth cookie for [IP]: jupyterhub-user-[user], {'path': ‘/user/[user]/‘, 'httponly': True, 'secure': True}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Token stored in cookie may have expired
2023-11-08T12:14:25.882Z	"nbt-singleuser"	No user identified
2023-11-08T12:14:25.882Z	"nbt-singleuser"	302 GET /user/[user]/oauth_callback?code=[secret]&state=[secret] -> /user/[user]/lab? (@[IP]) 46.77ms
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Checking user [user] with scopes [‘access:servers!server=[user]/‘, 'read:users:groups!user=[user]', 'read:users:name!user=[user]'] against {'access:servers!server=[user]/', 'access:servers!user=[user]'}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Allowing user [user] with scopes {'access:servers!server=[user]/'}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Paths used for configuration of page_config: 	/etc/jupyter/labconfig/page_config.json
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Paths used for configuration of page_config: 	/usr/local/etc/jupyter/labconfig/page_config.json
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Paths used for configuration of page_config: 	/opt/nbt/venvs/jupyter-server/etc/jupyter/labconfig/page_config.json
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Paths used for configuration of page_config: 	/home/jovyan/.jupyter/labconfig/page_config.json
2023-11-08T12:14:25.882Z	"nbt-singleuser"	200 GET /user/[user]/lab? ([user]@[IP]) 10.63ms
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Checking user [user] with scopes ['access:servers!server=[user]/', 'read:users:groups!user=[user]', 'read:users:name!user=[user]'] against {'access:servers!server=[user]/', 'access:servers!user=[user]'}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Allowing user [user] with scopes {'access:servers!server=[user]/'}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Path main.df4a154f94063e34ef18.js served from /opt/nbt/venvs/jupyter-server/share/jupyter/lab/static/main.df4a154f94063e34ef18.js
2023-11-08T12:14:25.882Z	"nbt-singleuser"	200 GET /user/[user]/static/lab/main.df4a154f94063e34ef18.js?v=df4a154f94063e34ef18 ([user]@[IP])1.56ms
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Checking user [user] with scopes ['access:servers!server=[user]/', 'read:users:groups!user=[user]', 'read:users:name!user=[user]'] against {'access:servers!server=[user]/', 'access:servers!user=[user]'}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Allowing user [user] with scopes {'access:servers!server=[user]/'}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Path nbt_lab/static/remoteEntry.e69c5fb866fe2d47ad3b.js served from /opt/nbt/venvs/jupyter-server/share/jupyter/labextensions/nbt_lab/static/remoteEntry.e69c5fb866fe2d47ad3b.js
2023-11-08T12:14:25.882Z	"nbt-singleuser"	304 GET /user/[user]/lab/extensions/nbt_lab/static/remoteEntry.e69c5fb866fe2d47ad3b.js ([user]@[IP])1.32ms
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Checking user [user] with scopes ['access:servers!server=[user]/', 'read:users:groups!user=[user]', 'read:users:name!user=[user]'] against {'access:servers!server=[user]/', 'access:servers!user=[user]'}
2023-11-08T12:14:25.882Z	"nbt-singleuser"	Allowing user [user] with scopes {'access:servers!server=[user]/'}

gfg4 · November 8, 2023, 1:48pm

Here you have the remaining things

Single user environment

Single-user environment (We have extra dependencies for the kernels). At the end of the list there are some custom extensions that we have created and are not publicly available.


alembic==1.12.0

anyio==4.0.0

appnope==0.1.3

argon2-cffi==23.1.0

argon2-cffi-bindings==21.2.0

arrow==1.2.3

asttokens==2.4.0

async-generator==1.10

async-lru==2.0.4

attrs==23.1.0

azure-core==1.29.5

azure-identity==1.15.0

azure-storage-blob==12.19.0

Babel==2.12.1

backcall==0.2.0

beautifulsoup4==4.12.2

black==23.10.1

bleach==6.0.0

boto3==1.28.80

botocore==1.31.80

cachetools==5.3.2

cattrs==23.1.2

certifi==2023.7.22

certipy==0.1.3

cffi==1.15.1

charset-normalizer==3.2.0

click==8.1.7

colorama==0.4.6

comm==0.1.4

contourpy==1.1.1

cryptography==41.0.4

cycler==0.11.0

datadog==0.47.0

debugpy==1.8.0

decorator==5.1.1

defusedxml==0.7.1

docstring-to-markdown==0.13

exceptiongroup==1.1.3

executing==1.2.0

fastjsonschema==2.18.0

fonttools==4.42.1

fqdn==1.5.1

gitdb==4.0.11

GitPython==3.1.40

google-api-core==2.13.0

google-auth==2.23.4

google-cloud-core==2.3.3

google-cloud-storage==2.13.0

google-crc32c==1.5.0

google-resumable-media==2.6.0

googleapis-common-protos==1.61.0

greenlet==3.0.1

gssapi==1.8.3

hdijupyterutils==0.21.0

idna==3.4

importlib-metadata==6.8.0

importlib-resources==6.1.0

ipykernel==6.25.2

ipympl==0.9.3

ipython==8.15.0

ipython-genutils==0.2.0

ipywidgets==8.1.1

isodate==0.6.1

isoduration==20.11.0

isort==5.12.0

jedi==0.19.0

jedi-language-server==0.41.1

Jinja2==3.1.2

jmespath==1.0.1

JSON-log-formatter==0.5.2

json5==0.9.14

jsonpointer==2.4

jsonschema==4.19.1

jsonschema-specifications==2023.7.1

jupyter==1.0.0

jupyter-archive==3.4.0

jupyter-console==6.6.3

jupyter-contrib-core==0.4.2

jupyter-events==0.7.0

jupyter-lsp==2.2.0

jupyter-nbextensions-configurator==0.6.3

jupyter-server-mathjax==0.2.6

jupyter-telemetry==0.1.0

jupyter_client==8.3.1

jupyter_core==5.3.1

jupyter_server==2.7.3

jupyter_server_terminals==0.4.4

jupyterhub==4.0.2

jupyterlab==4.0.6

jupyterlab-execute-time==3.0.1

jupyterlab-lsp==5.0.0

jupyterlab-pygments==0.2.2

jupyterlab-spellchecker==0.8.4

jupyterlab-unfold==0.3.0

jupyterlab-widgets==3.0.9

jupyterlab_code_formatter==2.2.1

jupyterlab_favorites==3.2.0

jupyterlab_git==0.50.0a0

jupyterlab_search_replace==1.1.0

jupyterlab_server==2.25.0

jupyterlab_templates==0.5.0

kiwisolver==1.4.5

krb5==0.5.1

lsprotocol==2023.0.0b1

Mako==1.2.4

MarkupSafe==2.1.3

matplotlib==3.8.0

matplotlib-inline==0.1.6

mistune==3.0.1

msal==1.25.0

msal-extensions==1.0.0

mypy-extensions==1.0.0

nbclient==0.8.0

nbconvert==7.8.0

nbdime==4.0.0a1

nbformat==5.9.2

nest-asyncio==1.5.5

notebook==7.0.4

notebook_shim==0.2.3

numpy==1.26.0

oauthlib==3.2.2

overrides==7.4.0

packaging==23.1

pamela==1.1.0

pandas==2.1.0

pandocfilters==1.5.0

parso==0.8.3

pathspec==0.11.2

pexpect==4.8.0

pickleshare==0.7.5

Pillow==10.0.1

platformdirs==3.10.0

plotly==5.18.0

portalocker==2.8.2

prometheus-client==0.17.1

prompt-toolkit==3.0.39

protobuf==4.25.0

psutil==5.9.5

ptyprocess==0.7.0

pure-eval==0.2.2

pyasn1==0.5.0

pyasn1-modules==0.3.0

pycparser==2.21

pygls==1.1.2

Pygments==2.16.1

PyJWT==2.8.0

pyOpenSSL==23.2.0

pyparsing==3.1.1

pyspnego==0.10.2

python-dateutil==2.8.2

python-json-logger==2.0.7

pytz==2023.3.post1

PyYAML==6.0.1

pyzmq==25.1.1

qtconsole==5.5.0

QtPy==2.4.1

referencing==0.30.2

requests==2.31.0

requests-kerberos==0.14.0

rfc3339-validator==0.1.4

rfc3986-validator==0.1.1

rpds-py==0.10.3

rsa==4.9

ruamel.yaml==0.17.32

ruamel.yaml.clib==0.2.7

s3transfer==0.7.0

Send2Trash==1.8.2

six==1.16.0

smmap==5.0.1

sniffio==1.3.0

soupsieve==2.5

sparkmagic==0.20.5

SQLAlchemy==2.0.21

stack-data==0.6.2

tenacity==8.2.3

terminado==0.17.1

tinycss2==1.2.1

tomli==2.0.1

tornado==6.3.3

traitlets==5.10.0

typeguard==4.1.5

types-python-dateutil==2.8.19.14

typing_extensions==4.8.0

tzdata==2023.3

uri-template==1.3.0

urllib3==2.0.5

wcwidth==0.2.6

webcolors==1.13

webencodings==0.5.1

websocket-client==1.6.3

widgetsnbextension==4.0.9

zipp==3.17.0

# Extra extensions (I can’t provide the source code of these for installation)

# nbt-lib

# nbt_lab @ file:///opt/nbt_lab

# ddmetrics_lab @ file:///opt/ddmetrics_lab

# hub_share @ file:///opt/hub-share

Logs for server startup


2023-11-08T13:09:55.799Z waiting for an initial pod process

2023-11-08T13:09:55.799Z server starting

2023-11-08T13:09:55.799Z starting

2023-11-08T13:09:55.799Z logging in

2023-11-08T13:09:56.105Z logged in

2023-11-08T13:09:56.105Z waiting until next renew time

2023-11-08T13:09:56.106Z server starting

2023-11-08T13:09:56.107Z starting

2023-11-08T13:12:02.120Z detected initial pod process

2023-11-08T13:12:02.120Z finished minimum wait

2023-11-08T13:12:02.120Z waiting for all pod processes to complete

2023-11-08T13:12:04.818Z Loaded config file: /etc/jupyter/jupyter_server_config.py

2023-11-08T13:12:04.819Z Looking for jupyter_server_config in /usr/local/etc/jupyter

2023-11-08T13:12:04.819Z Looking for jupyter_server_config in /opt/nbt/venvs/jupyter-server/etc/jupyter

2023-11-08T13:12:04.819Z Looking for jupyter_server_config in /home/jovyan/.jupyter

2023-11-08T13:12:04.819Z ServerApp.iopub_msg_rate_limit config is deprecated in 2.0. Use ZMQChannelsWebsocketConnection.iopub_msg_rate_limit.

2023-11-08T13:12:04.820Z ServerApp.iopub_data_rate_limit config is deprecated in 2.0. Use ZMQChannelsWebsocketConnection.iopub_data_rate_limit.

2023-11-08T13:12:04.822Z Paths used for configuration of jupyter_server_config: /etc/jupyter/jupyter_server_config.json

2023-11-08T13:12:04.823Z Paths used for configuration of jupyter_server_config: /usr/local/etc/jupyter/jupyter_server_config.json

2023-11-08T13:12:04.823Z Paths used for configuration of jupyter_server_config: /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/ddmetrics_lab.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/hub_share.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyter-archive.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyter-lsp-jupyter-server.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyter_server_mathjax.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyter_server_terminals.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab-spellchecker.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab_code_formatter.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab_git.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab_search_replace.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab_templates.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/nbdime.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/nbt_lab.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/notebook.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/notebook_shim.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.json

2023-11-08T13:12:04.824Z Paths used for configuration of jupyter_server_config: /home/jovyan/.jupyter/jupyter_server_config.json

2023-11-08T13:12:04.830Z Package jupyterhub took 0.0000s to import

2023-11-08T13:12:04.888Z Package ddmetrics_lab took 0.0573s to import

2023-11-08T13:12:04.888Z Package hub_share took 0.0002s to import

2023-11-08T13:12:04.888Z A `_jupyter_server_extension_points` function was not found in hub_share, so Jupyter Server will look for extension points in the extension pacakge's root.

2023-11-08T13:12:04.894Z Package jupyter_archive took 0.0056s to import

2023-11-08T13:12:04.908Z Package jupyter_lsp took 0.0133s to import

2023-11-08T13:12:04.908Z A `_jupyter_server_extension_points` function was not found in jupyter_lsp. Instead, a `_jupyter_server_extension_paths` function was found and will be used for now. This function name will be deprecated in future releases of Jupyter Server.

2023-11-08T13:12:04.910Z Package jupyter_server_mathjax took 0.0014s to import

2023-11-08T13:12:04.916Z Package jupyter_server_terminals took 0.0055s to import

2023-11-08T13:12:04.938Z Package jupyterlab took 0.0211s to import

2023-11-08T13:12:05.737Z Package jupyterlab_code_formatter took 0.0024s to import

2023-11-08T13:12:05.752Z Package jupyterlab_git took 0.0139s to import

2023-11-08T13:12:05.754Z Package jupyterlab_search_replace took 0.0014s to import

2023-11-08T13:12:05.755Z Package jupyterlab_spellchecker took 0.0008s to import

2023-11-08T13:12:05.756Z Package jupyterlab_templates took 0.0006s to import

2023-11-08T13:12:05.756Z A `_jupyter_server_extension_points` function was not found in jupyterlab_templates. Instead, a `_jupyter_server_extension_paths` function was found and will be used for now. This function name will be deprecated in future releases of Jupyter Server.

2023-11-08T13:12:05.756Z Package nbdime took 0.0000s to import

2023-11-08T13:12:06.288Z configured nbt logger

2023-11-08T13:12:06.289Z Package nbt_lab took 0.5322s to import

2023-11-08T13:12:06.289Z Package notebook took 0.0000s to import

2023-11-08T13:12:06.292Z Package notebook_shim took 0.0000s to import

2023-11-08T13:12:06.292Z A `_jupyter_server_extension_points` function was not found in notebook_shim. Instead, a `_jupyter_server_extension_paths` function was found and will be used for now. This function name will be deprecated in future releases of Jupyter Server.

2023-11-08T13:12:06.294Z ddmetrics_lab | extension was successfully linked.

2023-11-08T13:12:06.295Z hub_share | extension was successfully linked.

2023-11-08T13:12:06.296Z jupyter_archive | extension was successfully linked.

2023-11-08T13:12:06.297Z jupyter_lsp | extension was successfully linked.

2023-11-08T13:12:06.306Z Config changed: {'ServerApp': {'ip': '0.0.0.0', 'disable_check_xsrf': True, 'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0, 'tornado_settings': {'headers': {‘Content-Security-Policy': [CONTENT SECURITY POLICY]}, 'jpserver_extensions': <LazyConfigValue value={'jupyterhub': True, 'ddmetrics_lab': True, 'hub_share': True, 'jupyter_archive': True, 'jupyter_lsp': True, 'jupyter_server_mathjax': True, 'jupyter_server_terminals': True, 'jupyterlab': True, 'jupyterlab_code_formatter': True, 'jupyterlab_git': True, 'jupyterlab_search_replace': True, 'jupyterlab_spellchecker': True, 'jupyterlab_templates': True, 'nbdime': True, 'nbt_lab': True, 'notebook': True, 'notebook_shim': True}>}, 'ZMQChannelsWebsocketConnection': {'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0}, 'FileContentsManager': {'post_save_hook': <function notebook_post_save at 0x7f154b653e20>}, 'ContentsManager': {'allow_hidden': True}, 'MultiKernelManager': {'default_kernel_name': 'ipykernel-default'}, 'KernelSpecManager': {'ensure_native_kernel': False}, 'JupyterLabTemplates': {'allowed_extensions': ['*.ipynb'], 'template_dirs': ['/opt/nbt/templates/'], 'include_default': False, 'include_core_paths': False}}

2023-11-08T13:12:06.307Z jupyter_server_mathjax | extension was successfully linked.

2023-11-08T13:12:06.312Z Config changed: {'ServerApp': {'ip': '0.0.0.0', 'disable_check_xsrf': True, 'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0, 'tornado_settings': {'headers': {'Content-Security-Policy': [CONTENT SECURITY POLICY]}, 'jpserver_extensions': <LazyConfigValue value={'jupyterhub': True, 'ddmetrics_lab': True, 'hub_share': True, 'jupyter_archive': True, 'jupyter_lsp': True, 'jupyter_server_mathjax': True, 'jupyter_server_terminals': True, 'jupyterlab': True, 'jupyterlab_code_formatter': True, 'jupyterlab_git': True, 'jupyterlab_search_replace': True, 'jupyterlab_spellchecker': True, 'jupyterlab_templates': True, 'nbdime': True, 'nbt_lab': True, 'notebook': True, 'notebook_shim': True}>}, 'ZMQChannelsWebsocketConnection': {'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0}, 'FileContentsManager': {'post_save_hook': <function notebook_post_save at 0x7f154b653e20>}, 'ContentsManager': {'allow_hidden': True}, 'MultiKernelManager': {'default_kernel_name': 'ipykernel-default'}, 'KernelSpecManager': {'ensure_native_kernel': False}, 'JupyterLabTemplates': {'allowed_extensions': ['*.ipynb'], 'template_dirs': ['/opt/nbt/templates/'], 'include_default': False, 'include_core_paths': False}}

2023-11-08T13:12:06.312Z jupyter_server_terminals | extension was successfully linked.

2023-11-08T13:12:06.314Z Config changed: {'ServerApp': {'ip': '0.0.0.0', 'disable_check_xsrf': True, 'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0, 'tornado_settings': {'headers': {'Content-Security-Policy': [CONTENT SECURITY POLICY]}, 'jpserver_extensions': <LazyConfigValue value={'jupyterhub': True, 'ddmetrics_lab': True, 'hub_share': True, 'jupyter_archive': True, 'jupyter_lsp': True, 'jupyter_server_mathjax': True, 'jupyter_server_terminals': True, 'jupyterlab': True, 'jupyterlab_code_formatter': True, 'jupyterlab_git': True, 'jupyterlab_search_replace': True, 'jupyterlab_spellchecker': True, 'jupyterlab_templates': True, 'nbdime': True, 'nbt_lab': True, 'notebook': True, 'notebook_shim': True}>}, 'ZMQChannelsWebsocketConnection': {'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0}, 'FileContentsManager': {'post_save_hook': <function notebook_post_save at 0x7f154b653e20>}, 'ContentsManager': {'allow_hidden': True}, 'MultiKernelManager': {'default_kernel_name': 'ipykernel-default'}, 'KernelSpecManager': {'ensure_native_kernel': False}, 'JupyterLabTemplates': {'allowed_extensions': ['*.ipynb'], 'template_dirs': ['/opt/nbt/templates/'], 'include_default': False, 'include_core_paths': False}}

2023-11-08T13:12:06.318Z Config changed: {'ServerApp': {'ip': '0.0.0.0', 'disable_check_xsrf': True, 'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0, 'tornado_settings': {'headers': {'Content-Security-Policy': [CONTENT SECURITY POLICY]}, 'jpserver_extensions': <LazyConfigValue value={'jupyterhub': True, 'ddmetrics_lab': True, 'hub_share': True, 'jupyter_archive': True, 'jupyter_lsp': True, 'jupyter_server_mathjax': True, 'jupyter_server_terminals': True, 'jupyterlab': True, 'jupyterlab_code_formatter': True, 'jupyterlab_git': True, 'jupyterlab_search_replace': True, 'jupyterlab_spellchecker': True, 'jupyterlab_templates': True, 'nbdime': True, 'nbt_lab': True, 'notebook': True, 'notebook_shim': True}>, 'identity_provider_class': <class 'jupyterhub.singleuser.extension.JupyterHubIdentityProvider'>, 'allow_remote_access': True, 'open_browser': False, 'trust_xheaders': True, 'quit_button': False, 'port_retries': 0, 'answer_yes': True, 'port': 8888, 'base_url': '/user/[user]/', 'default_url': '/lab', 'keyfile': '', 'certfile': '', 'client_ca': ''}, 'ZMQChannelsWebsocketConnection': {'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0}, 'FileContentsManager': {'post_save_hook': <function notebook_post_save at 0x7f154b653e20>, 'delete_to_trash': False}, 'ContentsManager': {'allow_hidden': True}, 'MultiKernelManager': {'default_kernel_name': 'ipykernel-default'}, 'KernelSpecManager': {'ensure_native_kernel': False}, 'JupyterLabTemplates': {'allowed_extensions': ['*.ipynb'], 'template_dirs': ['/opt/nbt/templates/'], 'include_default': False, 'include_core_paths': False}}

2023-11-08T13:12:06.319Z jupyterhub | extension was successfully linked.

2023-11-08T13:12:06.325Z jupyterlab | extension was successfully linked.

2023-11-08T13:12:06.326Z jupyterlab_code_formatter | extension was successfully linked.

2023-11-08T13:12:06.326Z jupyterlab_git | extension was successfully linked.

2023-11-08T13:12:06.326Z jupyterlab_search_replace | extension was successfully linked.

2023-11-08T13:12:06.326Z jupyterlab_spellchecker | extension was successfully linked.

2023-11-08T13:12:06.326Z jupyterlab_templates | extension was successfully linked.

2023-11-08T13:12:06.326Z nbdime | extension was successfully linked.

2023-11-08T13:12:06.326Z nbt_lab | extension was successfully linked.

2023-11-08T13:12:06.333Z notebook | extension was successfully linked.

2023-11-08T13:12:06.644Z Paths used for configuration of jupyter_notebook_config: /home/jovyan/.jupyter/jupyter_notebook_config.json

2023-11-08T13:12:06.644Z Paths used for configuration of jupyter_notebook_config: /etc/jupyter/jupyter_notebook_config.json

2023-11-08T13:12:06.645Z Paths used for configuration of jupyter_notebook_config: /usr/local/etc/jupyter/jupyter_notebook_config.json

2023-11-08T13:12:06.645Z Paths used for configuration of jupyter_notebook_config: /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/hub_share.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyter-lsp-notebook.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyter_nbextensions_configurator.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyterlab-spellchecker.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyterlab.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyterlab_code_formatter.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/nbdime.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.json

2023-11-08T13:12:06.646Z Paths used for configuration of jupyter_notebook_config: /home/jovyan/.jupyter/jupyter_notebook_config.json

2023-11-08T13:12:06.647Z jupyter_nbextensions_configurator | error adding extension (enabled: True): The module 'jupyter_nbextensions_configurator' could not be found (No module named 'notebook.base'). Are you sure the extension is installed?

2023-11-08T13:12:06.647Z nbt | error adding extension (enabled: True): The module 'nbt' could not be found (No module named 'nbt'). Are you sure the extension is installed?

2023-11-08T13:12:06.648Z ddmetrics | error adding extension (enabled: True): The module 'ddmetrics' could not be found (No module named 'ddmetrics'). Are you sure the extension is installed?

2023-11-08T13:12:06.648Z Package sparkmagic took 0.0002s to import

2023-11-08T13:12:06.649Z A `_jupyter_server_extension_points` function was not found in sparkmagic, so Jupyter Server will look for extension points in the extension pacakge's root.

2023-11-08T13:12:06.649Z sparkmagic | extension was found and enabled by notebook_shim. Consider moving the extension to Jupyter Server's extension paths.

2023-11-08T13:12:06.649Z sparkmagic | extension was successfully linked.

2023-11-08T13:12:06.649Z notebook_shim | extension was successfully linked.

2023-11-08T13:12:06.650Z Config changed: {'ZMQChannelsWebsocketConnection': {'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0}, 'FileContentsManager': {'post_save_hook': <function notebook_post_save at 0x7f154b653e20>, 'delete_to_trash': False}, 'ContentsManager': {'allow_hidden': True}, 'MultiKernelManager': {'default_kernel_name': 'ipykernel-default'}, 'KernelSpecManager': {'ensure_native_kernel': False}, 'JupyterLabTemplates': {'allowed_extensions': ['*.ipynb'], 'template_dirs': ['/opt/nbt/templates/'], 'include_default': False, 'include_core_paths': False}, 'NotebookApp': {'nbserver_extensions': {'jupyter_nbextensions_configurator': True, 'nbt': True, 'ddmetrics': True, 'sparkmagic': True}, 'extra_template_paths': <LazyConfigValue {'extend': ['/opt/nbt/venvs/jupyter-server/lib/python3.10/site-packages/jupyterhub/singleuser/templates']}>}, 'ServerApp': {'ip': '0.0.0.0', 'disable_check_xsrf': True, 'iopub_msg_rate_limit': 100000000.0, 'iopub_data_rate_limit': 100000000.0, 'tornado_settings': {'headers': {'Content-Security-Policy': [CONTENT SECURITY POLICY]}, 'jpserver_extensions': <LazyConfigValue value={'jupyterhub': True, 'ddmetrics_lab': True, 'hub_share': True, 'jupyter_archive': True, 'jupyter_lsp': True, 'jupyter_server_mathjax': True, 'jupyter_server_terminals': True, 'jupyterlab': True, 'jupyterlab_code_formatter': True, 'jupyterlab_git': True, 'jupyterlab_search_replace': True, 'jupyterlab_spellchecker': True, 'jupyterlab_templates': True, 'nbdime': True, 'nbt_lab': True, 'notebook': True, 'notebook_shim': True}>, 'identity_provider_class': <class 'jupyterhub.singleuser.extension.JupyterHubIdentityProvider'>, 'allow_remote_access': True, 'open_browser': False, 'trust_xheaders': True, 'quit_button': False, 'port_retries': 0, 'answer_yes': True, 'port': 8888, 'base_url': '/user/[user]/', 'default_url': '/lab', 'keyfile': '', 'certfile': '', 'client_ca': ''}}

2023-11-08T13:12:06.672Z notebook_shim | extension was successfully loaded.

2023-11-08T13:12:06.673Z Registered ddmetrics_lab server extension

2023-11-08T13:12:06.673Z ddmetrics_lab | extension was successfully loaded.

2023-11-08T13:12:06.673Z hub_share | extension failed loading with message: ExtensionLoadingError('_load_jupyter_server_extension function was not found.')

2023-11-08T13:12:06.674Z jupyter_archive | extension was successfully loaded.

2023-11-08T13:12:06.677Z [lsp] rootUri will be file:///home/jovyan

2023-11-08T13:12:06.677Z [lsp] virtualDocumentsUri will be file:///home/jovyan/.virtual_documents

2023-11-08T13:12:06.677Z jupyter_lsp | extension was successfully loaded.

2023-11-08T13:12:06.678Z jupyter_server_mathjax | extension was successfully loaded.

2023-11-08T13:12:06.680Z jupyter_server_terminals | extension was successfully loaded.

2023-11-08T13:12:06.683Z Paths used for configuration of jupyter_config: /etc/jupyter/jupyter_config.json

2023-11-08T13:12:06.683Z Paths used for configuration of jupyter_config: /usr/local/etc/jupyter/jupyter_config.json

2023-11-08T13:12:06.683Z Paths used for configuration of jupyter_config: /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_config.json

2023-11-08T13:12:06.683Z Paths used for configuration of jupyter_config: /home/jovyan/.jupyter/jupyter_config.json

2023-11-08T13:12:06.684Z Paths used for configuration of jupyter_notebook_config: /etc/jupyter/jupyter_notebook_config.json

2023-11-08T13:12:06.684Z Paths used for configuration of jupyter_notebook_config: /usr/local/etc/jupyter/jupyter_notebook_config.json

2023-11-08T13:12:06.684Z Paths used for configuration of jupyter_notebook_config: /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/hub_share.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyter-lsp-notebook.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyter_nbextensions_configurator.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyterlab-spellchecker.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyterlab.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/jupyterlab_code_formatter.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.d/nbdime.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_notebook_config.json

2023-11-08T13:12:06.685Z Paths used for configuration of jupyter_notebook_config: /home/jovyan/.jupyter/jupyter_notebook_config.json

2023-11-08T13:12:06.685Z Paths used for configuration of jupyter_server_config: /etc/jupyter/jupyter_server_config.json

2023-11-08T13:12:06.685Z Paths used for configuration of jupyter_server_config: /usr/local/etc/jupyter/jupyter_server_config.json

2023-11-08T13:12:06.686Z Paths used for configuration of jupyter_server_config: /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/ddmetrics_lab.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/hub_share.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyter-archive.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyter-lsp-jupyter-server.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyter_server_mathjax.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyter_server_terminals.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab-spellchecker.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab_code_formatter.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab_git.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab_search_replace.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/jupyterlab_templates.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/nbdime.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/nbt_lab.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/notebook.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.d/notebook_shim.json /opt/nbt/venvs/jupyter-server/etc/jupyter/jupyter_server_config.json

2023-11-08T13:12:06.687Z Paths used for configuration of jupyter_server_config: /home/jovyan/.jupyter/jupyter_server_config.json

2023-11-08T13:12:06.709Z jupyterhub | extension was successfully loaded.

2023-11-08T13:12:06.718Z jupyterlab | extension was successfully loaded.

2023-11-08T13:12:06.718Z Registered jupyterlab_code_formatter server extension

2023-11-08T13:12:06.718Z jupyterlab_code_formatter | extension was successfully loaded.

2023-11-08T13:12:06.726Z jupyterlab_git | extension was successfully loaded.

2023-11-08T13:12:06.726Z Registered search-replace extension

2023-11-08T13:12:06.726Z jupyterlab_search_replace | extension was successfully loaded.

2023-11-08T13:12:06.727Z Looking for hunspell dictionaries for spellchecker in ['/home/jovyan/.local/share/jupyter/dictionaries', '/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries', '/usr/local/share/jupyter/dictionaries', '/usr/share/jupyter/dictionaries', '/usr/share/hunspell', '/usr/share/myspell', '/usr/share/myspell/dicts']

2023-11-08T13:12:06.812Z Located hunspell dictionaries for spellchecker: [{'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'en_US', 'id': 'en_US', 'dic': 'en_US.dic', 'aff': 'en_US.aff', 'name': 'English (United States)'}, {'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'en_CA', 'id': 'en_CA', 'dic': 'en_CA.dic', 'aff': 'en_CA.aff', 'name': 'English (Canada)'}, {'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'de_CH_frami', 'id': 'de_CH_frami', 'dic': 'de_CH_frami.dic', 'aff': 'de_CH_frami.aff', 'name': 'Deutsch (Schweiz)'}, {'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'pt_PT', 'id': 'pt_PT', 'dic': 'pt_PT.dic', 'aff': 'pt_PT.aff', 'name': 'português (Portugal)'}, {'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'de_DE_frami', 'id': 'de_DE_frami', 'dic': 'de_DE_frami.dic', 'aff': 'de_DE_frami.aff', 'name': 'Deutsch (Deutschland)'}, {'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'en_GB', 'id': 'en_GB-ise', 'dic': 'en_GB-ise.dic', 'aff': 'en_GB-ise.aff', 'name': 'English (United Kingdom)'}, {'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'es_ES', 'id': 'es_ES', 'dic': 'es_ES.dic', 'aff': 'es_ES.aff', 'name': 'español (España)'}, {'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'en_AU', 'id': 'en_AU', 'dic': 'en_AU.dic', 'aff': 'en_AU.aff', 'name': 'English (Australia)'}, {'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'de_AT_frami', 'id': 'de_AT_frami', 'dic': 'de_AT_frami.dic', 'aff': 'de_AT_frami.aff', 'name': 'Deutsch (Österreich)'}, {'path': PosixPath('/opt/nbt/venvs/jupyter-server/share/jupyter/dictionaries'), 'code': 'fr', 'id': 'fr', 'dic': 'fr.dic', 'aff': 'fr.aff', 'name': 'français'}]

2023-11-08T13:12:06.815Z Registered jupyterlab_spellchecker extension at URL path /spellchecker

2023-11-08T13:12:06.815Z jupyterlab_spellchecker | extension was successfully loaded.

2023-11-08T13:12:06.815Z Installing jupyterlab_templates handler on path /user/[user]/templates

2023-11-08T13:12:06.816Z Search paths: /opt/nbt/templates/

2023-11-08T13:12:06.816Z Available templates:

2023-11-08T13:12:06.816Z jupyterlab_templates | extension was successfully loaded.

2023-11-08T13:12:06.891Z Using default logger

2023-11-08T13:12:06.891Z Using default logger

2023-11-08T13:12:06.891Z Using default logger

2023-11-08T13:12:06.891Z Using default logger

2023-11-08T13:12:06.891Z Using default logger

2023-11-08T13:12:06.892Z nbdime | extension was successfully loaded.

2023-11-08T13:12:06.893Z nbt_lab extension enabled!

2023-11-08T13:12:06.894Z Registered nbt_lab server extension

2023-11-08T13:12:06.894Z nbt_lab | extension was successfully loaded.

2023-11-08T13:12:06.904Z notebook | extension was successfully loaded.

2023-11-08T13:12:06.904Z sparkmagic | extension failed loading with message: ExtensionLoadingError('_load_jupyter_server_extension function was not found.')

2023-11-08T13:12:06.905Z Serving notebooks from local directory: /home/jovyan

2023-11-08T13:12:06.905Z Jupyter Server 2.7.3 is running at:

2023-11-08T13:12:06.905Z http://[URL]:8888/user/[user]/lab?token=...

2023-11-08T13:12:06.905Z http://127.0.0.1:8888/user/[user]/lab?token=...

2023-11-08T13:12:06.905Z Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).

gfg4 · November 8, 2023, 2:22pm

Just today we had the issue and I was able to capture and save the logs.

This is a small part of it:

Date	Message
2023-11-08T13:28:16.477Z	Checking user [user] with scopes [‘access:servers!server=[user]/’, ‘read:users:groups!user=[user]’, ‘read:users:name!user=[user]’] against {‘access:servers!server=[user]/’, ‘access:servers!user=[user]’}
2023-11-08T13:28:16.477Z	Allowing user [user] with scopes {‘access:servers!server=[user]/’}
2023-11-08T13:28:16.477Z	204 PUT /user/[user]/lab/api/workspaces/default?1699450095656 ([user]@10.49.241.58) 1.73ms
2023-11-08T13:28:23.481Z	HubAuth cache miss: token:[token]
2023-11-08T13:28:23.481Z	HubAuth cache miss: token:[token]
2023-11-08T13:28:23.481Z	No Hub user identified for request
2023-11-08T13:28:23.481Z	Token stored in cookie may have expired
2023-11-08T13:28:23.481Z	No user identified
2023-11-08T13:28:23.481Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:23.481Z	[W 2023-11-08 13:28:22.645 TerminalsExtensionApp] wrote error: ‘Forbidden’
2023-11-08T13:28:23.481Z	Traceback (most recent call last):
2023-11-08T13:28:23.481Z	File /opt/nbt/venvs/jupyter-server/lib/python3.10/site-packages/tornado/web.py, line 1784, in _execute
2023-11-08T13:28:23.481Z	result = method(self.path_args, *self.path_kwargs)
2023-11-08T13:28:23.481Z	File /opt/nbt/venvs/jupyter-server/lib/python3.10/site-packages/tornado/web.py, line 3278, in wrapper
2023-11-08T13:28:23.481Z	url = self.get_login_url()
2023-11-08T13:28:23.481Z	File /opt/nbt/venvs/jupyter-server/lib/python3.10/site-packages/jupyterhub/singleuser/extension.py, line 148, in get_login_url
2023-11-08T13:28:23.481Z	return original_get_login_url()
2023-11-08T13:28:23.481Z	File /opt/nbt/venvs/jupyter-server/lib/python3.10/site-packages/jupyter_server/base/handlers.py, line 753, in get_login_url
2023-11-08T13:28:23.481Z	raise web.HTTPError(403)
2023-11-08T13:28:23.482Z	tornado.web.HTTPError: HTTP 403: Forbidden
2023-11-08T13:28:23.482Z	403 GET /user/[user]/api/terminals?1699450102503 (@10.49.241.58) 10.14ms
2023-11-08T13:28:23.482Z	No Hub user identified for request
2023-11-08T13:28:23.482Z	Token stored in cookie may have expired
2023-11-08T13:28:23.482Z	No user identified
2023-11-08T13:28:23.482Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:23.482Z	wrote error: ‘Forbidden’
2023-11-08T13:28:23.482Z	403 GET /user/[user]/api/kernels?1699450102503 (@10.49.241.58) 10.28ms
2023-11-08T13:28:23.482Z	Token stored in cookie may have expired
2023-11-08T13:28:23.482Z	No user identified
2023-11-08T13:28:23.482Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&[state]
2023-11-08T13:28:23.482Z	wrote error: ‘Forbidden’
2023-11-08T13:28:23.482Z	403 GET /user/[user]/api/sessions?1699450102554 (@10.49.241.58) 1.94ms
2023-11-08T13:28:25.483Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: status (busy)
2023-11-08T13:28:25.483Z	test_parity_check.replay_anomaly_start
2023-11-08T13:28:25.483Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: execute_input
2023-11-08T13:28:25.483Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: execute_result
2023-11-08T13:28:25.483Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: status (idle)
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	304 GET /user/[user]/static/favicons/favicon-busy-1.ico (@10.49.241.58) 1.66ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104575 (@10.49.241.58) 1.56ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104575 (@10.49.241.58) 2.07ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104576 (@10.49.241.58) 2.80ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104576 (@10.49.241.58) 1.10ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104577 (@10.49.241.58) 1.18ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104577 (@10.49.241.58) 1.37ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104578 (@10.49.241.58) 2.12ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104579 (@10.49.241.58) 1.61ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104579 (@10.49.241.58) 2.23ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.483Z	Referer. user: [user]
2023-11-08T13:28:25.483Z	Successfully submited the metrics!
2023-11-08T13:28:25.483Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450104578 (@10.49.241.58) 1.16ms
2023-11-08T13:28:25.483Z	Token stored in cookie may have expired
2023-11-08T13:28:25.483Z	No user identified
2023-11-08T13:28:25.484Z	Detected unused OAuth state cookies
2023-11-08T13:28:25.484Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:25.484Z	wrote error: ‘Forbidden’
2023-11-08T13:28:25.484Z	403 GET /user/[user]/api/contents?1699450105155 (@10.49.241.58) 2.69ms
2023-11-08T13:28:37.490Z	Token stored in cookie may have expired
2023-11-08T13:28:37.490Z	No user identified
2023-11-08T13:28:37.490Z	Detected unused OAuth state cookies
2023-11-08T13:28:37.490Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:37.490Z	wrote error: ‘Forbidden’
2023-11-08T13:28:37.490Z	403 GET /user/[user]/api/sessions?1699450116407 (@10.49.241.58) 2.41ms
2023-11-08T13:28:37.581Z	fetching config
2023-11-08T13:28:37.581Z	successfully fetched and wrote configuration
2023-11-08T13:28:42.494Z	Token stored in cookie may have expired
2023-11-08T13:28:42.494Z	No user identified
2023-11-08T13:28:42.494Z	Detected unused OAuth state cookies
2023-11-08T13:28:42.494Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:42.494Z	wrote error: ‘Forbidden’
2023-11-08T13:28:42.494Z	403 GET /user/[user]/api/me?1699450121572 (@10.49.241.58) 2.48ms
2023-11-08T13:28:42.494Z	Token stored in cookie may have expired
2023-11-08T13:28:42.494Z	No user identified
2023-11-08T13:28:42.494Z	Detected unused OAuth state cookies
2023-11-08T13:28:42.494Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:42.494Z	wrote error: ‘Forbidden’
2023-11-08T13:28:42.494Z	403 GET /user/[user]/api/kernelspecs?1699450121573 (@10.49.241.58) 1.96ms
2023-11-08T13:28:42.494Z	Token stored in cookie may have expired
2023-11-08T13:28:42.494Z	No user identified
2023-11-08T13:28:42.494Z	Detected unused OAuth state cookies
2023-11-08T13:28:42.494Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:42.494Z	wrote error: ‘Forbidden’
2023-11-08T13:28:42.494Z	403 GET /user/[user]/api/contents?1699450121759 (@10.49.241.58) 2.71ms
2023-11-08T13:28:43.495Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: status (busy)
2023-11-08T13:28:43.495Z	test_parity_check.replay_anomaly_start == np.nan
2023-11-08T13:28:43.495Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: execute_input
2023-11-08T13:28:43.495Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: execute_result
2023-11-08T13:28:43.495Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: status (idle)
2023-11-08T13:28:43.495Z	Token stored in cookie may have expired
2023-11-08T13:28:43.495Z	No user identified
2023-11-08T13:28:43.495Z	304 GET /user/[user]/static/favicons/favicon-busy-1.ico (@10.49.241.58) 2.05ms
2023-11-08T13:28:44.495Z	Token stored in cookie may have expired
2023-11-08T13:28:44.495Z	No user identified
2023-11-08T13:28:44.495Z	Referer. user: [user]
2023-11-08T13:28:44.495Z	Successfully submited the metrics!
2023-11-08T13:28:44.495Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123385 (@10.49.241.58) 2.27ms
2023-11-08T13:28:44.495Z	Token stored in cookie may have expired
2023-11-08T13:28:44.495Z	No user identified
2023-11-08T13:28:44.495Z	Referer. user: [user]
2023-11-08T13:28:44.495Z	Successfully submited the metrics!
2023-11-08T13:28:44.495Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123386 (@10.49.241.58) 1.69ms
2023-11-08T13:28:44.495Z	Token stored in cookie may have expired
2023-11-08T13:28:44.495Z	No user identified
2023-11-08T13:28:44.495Z	Referer. user: [user]
2023-11-08T13:28:44.495Z	Successfully submited the metrics!
2023-11-08T13:28:44.495Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123387 (@10.49.241.58) 1.49ms
2023-11-08T13:28:44.495Z	Token stored in cookie may have expired
2023-11-08T13:28:44.495Z	No user identified
2023-11-08T13:28:44.495Z	Referer. user: [user]
2023-11-08T13:28:44.495Z	Successfully submited the metrics!
2023-11-08T13:28:44.495Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123387 (@10.49.241.58) 1.78ms
2023-11-08T13:28:44.495Z	Token stored in cookie may have expired
2023-11-08T13:28:44.495Z	No user identified
2023-11-08T13:28:44.495Z	Referer. user: [user]
2023-11-08T13:28:44.495Z	Successfully submited the metrics!
2023-11-08T13:28:44.495Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123388 (@10.49.241.58) 2.82ms
2023-11-08T13:28:44.495Z	Token stored in cookie may have expired
2023-11-08T13:28:44.495Z	No user identified
2023-11-08T13:28:44.495Z	Referer. user: [user]
2023-11-08T13:28:44.495Z	Successfully submited the metrics!
2023-11-08T13:28:44.495Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123389 (@10.49.241.58) 2.52ms
2023-11-08T13:28:44.495Z	Token stored in cookie may have expired
2023-11-08T13:28:44.495Z	No user identified
2023-11-08T13:28:44.495Z	Referer. user: [user]
2023-11-08T13:28:44.496Z	Successfully submited the metrics!
2023-11-08T13:28:44.496Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123389 (@10.49.241.58) 3.41ms
2023-11-08T13:28:44.496Z	Token stored in cookie may have expired
2023-11-08T13:28:44.496Z	No user identified
2023-11-08T13:28:44.496Z	Referer. user: [user]
2023-11-08T13:28:44.496Z	Successfully submited the metrics!
2023-11-08T13:28:44.496Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123390 (@10.49.241.58) 4.09ms
2023-11-08T13:28:44.496Z	Token stored in cookie may have expired
2023-11-08T13:28:44.496Z	No user identified
2023-11-08T13:28:44.496Z	Referer. user: [user]
2023-11-08T13:28:44.496Z	Successfully submited the metrics!
2023-11-08T13:28:44.496Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123388 (@10.49.241.58) 1.72ms
2023-11-08T13:28:44.496Z	Token stored in cookie may have expired
2023-11-08T13:28:44.496Z	No user identified
2023-11-08T13:28:44.496Z	Referer. user: [user]
2023-11-08T13:28:44.496Z	Successfully submited the metrics!
2023-11-08T13:28:44.496Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450123388 (@10.49.241.58) 2.70ms
2023-11-08T13:28:47.497Z	Token stored in cookie may have expired
2023-11-08T13:28:47.497Z	No user identified
2023-11-08T13:28:47.497Z	Detected unused OAuth state cookies
2023-11-08T13:28:47.497Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:47.497Z	[W 2023-11-08 13:28:47.068 TerminalsExtensionApp] wrote error: ‘Forbidden’
2023-11-08T13:28:47.497Z	Traceback (most recent call last):
2023-11-08T13:28:47.497Z	File /opt/nbt/venvs/jupyter-server/lib/python3.10/site-packages/tornado/web.py, line 1784, in _execute
2023-11-08T13:28:47.497Z	result = method(self.path_args, *self.path_kwargs)
2023-11-08T13:28:47.497Z	File /opt/nbt/venvs/jupyter-server/lib/python3.10/site-packages/tornado/web.py, line 3278, in wrapper
2023-11-08T13:28:47.497Z	url = self.get_login_url()
2023-11-08T13:28:47.497Z	File /opt/nbt/venvs/jupyter-server/lib/python3.10/site-packages/jupyterhub/singleuser/extension.py, line 148, in get_login_url
2023-11-08T13:28:47.497Z	return original_get_login_url()
2023-11-08T13:28:47.497Z	File /opt/nbt/venvs/jupyter-server/lib/python3.10/site-packages/jupyter_server/base/handlers.py, line 753, in get_login_url
2023-11-08T13:28:47.497Z	raise web.HTTPError(403)
2023-11-08T13:28:47.497Z	tornado.web.HTTPError: HTTP 403: Forbidden
2023-11-08T13:28:47.497Z	403 GET /user/[user]/api/terminals?1699450126941 (@10.49.241.58) 2.49ms
2023-11-08T13:28:49.498Z	Token stored in cookie may have expired
2023-11-08T13:28:49.498Z	No user identified
2023-11-08T13:28:49.498Z	Detected unused OAuth state cookies
2023-11-08T13:28:49.499Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:49.499Z	wrote error: ‘Forbidden’
2023-11-08T13:28:49.499Z	403 GET /user/[user]/api/kernels?1699450128817 (@10.49.241.58) 2.64ms
2023-11-08T13:28:49.499Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: status (busy)
2023-11-08T13:28:49.499Z	(test_parity_check.replay_anomaly_start == np.nan).sum()
2023-11-08T13:28:49.499Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: execute_input
2023-11-08T13:28:49.499Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: execute_result
2023-11-08T13:28:49.499Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: status (idle)
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	304 GET /user/[user]/static/favicons/favicon-busy-1.ico (@10.49.241.58) 1.92ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129135 (@10.49.241.58) 1.88ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129136 (@10.49.241.58) 1.62ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129136 (@10.49.241.58) 1.64ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129137 (@10.49.241.58) 2.14ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129137 (@10.49.241.58) 3.21ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129138 (@10.49.241.58) 4.31ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129138 (@10.49.241.58) 1.91ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129140 (@10.49.241.58) 3.04ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129139 (@10.49.241.58) 1.69ms
2023-11-08T13:28:49.499Z	Token stored in cookie may have expired
2023-11-08T13:28:49.499Z	No user identified
2023-11-08T13:28:49.499Z	Referer. user: [user]
2023-11-08T13:28:49.499Z	Successfully submited the metrics!
2023-11-08T13:28:49.499Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450129139 (@10.49.241.58) 2.79ms
2023-11-08T13:28:50.500Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: stream
2023-11-08T13:28:57.505Z	Token stored in cookie may have expired
2023-11-08T13:28:57.505Z	No user identified
2023-11-08T13:28:57.505Z	Detected unused OAuth state cookies
2023-11-08T13:28:57.505Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:28:57.505Z	wrote error: ‘Forbidden’
2023-11-08T13:28:57.505Z	403 GET /user/[user]/api/contents?1699450136667 (@10.49.241.58) 2.72ms
2023-11-08T13:28:58.506Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: status (busy)
2023-11-08T13:28:58.506Z	(test_parity_check.replay_anomaly_start is np.nan).sum()
2023-11-08T13:28:58.506Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: execute_input
2023-11-08T13:28:58.506Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: error
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	304 GET /user/[user]/static/favicons/favicon-busy-1.ico (@10.49.241.58) 1.95ms
2023-11-08T13:28:58.506Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: status (idle)
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137770 (@10.49.241.58) 2.05ms
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137771 (@10.49.241.58) 1.62ms
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137773 (@10.49.241.58) 2.01ms
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137772 (@10.49.241.58) 2.55ms
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137774 (@10.49.241.58) 2.31ms
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137774 (@10.49.241.58) 2.68ms
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137775 (@10.49.241.58) 4.84ms
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137775 (@10.49.241.58) 5.66ms
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137776 (@10.49.241.58) 6.29ms
2023-11-08T13:28:58.506Z	Token stored in cookie may have expired
2023-11-08T13:28:58.506Z	No user identified
2023-11-08T13:28:58.506Z	Referer. user: [user]
2023-11-08T13:28:58.506Z	Successfully submited the metrics!
2023-11-08T13:28:58.506Z	200 POST /user/[user]/ddmetrics_lab/increment?1699450137777 (@10.49.241.58) 6.97ms
2023-11-08T13:29:02.508Z	Token stored in cookie may have expired
2023-11-08T13:29:02.508Z	No user identified
2023-11-08T13:29:02.508Z	Detected unused OAuth state cookies
2023-11-08T13:29:02.508Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:29:02.508Z	wrote error: ‘Forbidden’
2023-11-08T13:29:02.508Z	403 GET /user/[user]/api/contents/notebooks/jump_detection/replay_jump_detection.ipynb?content=0&1699450141551 (@10.49.241.58) 2.83ms
2023-11-08T13:29:06.511Z	Token stored in cookie may have expired
2023-11-08T13:29:06.511Z	No user identified
2023-11-08T13:29:06.511Z	Detected unused OAuth state cookies
2023-11-08T13:29:06.511Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:29:06.511Z	wrote error: ‘Forbidden’
2023-11-08T13:29:06.511Z	403 GET /user/[user]/api/contents/notebooks/jump_detection/replay_jump_detection.ipynb?content=0&1699450145824 (@10.49.241.58) 2.80ms
2023-11-08T13:29:07.600Z	fetching config
2023-11-08T13:29:07.600Z	successfully fetched and wrote configuration
2023-11-08T13:29:09.513Z	Token stored in cookie may have expired
2023-11-08T13:29:09.513Z	No user identified
2023-11-08T13:29:09.513Z	Detected unused OAuth state cookies
2023-11-08T13:29:09.513Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:29:09.513Z	wrote error: ‘Forbidden’
2023-11-08T13:29:09.513Z	403 GET /user/[user]/api/sessions?1699450149071 (@10.49.241.58) 2.97ms
2023-11-08T13:29:09.513Z	Token stored in cookie may have expired
2023-11-08T13:29:09.513Z	No user identified
2023-11-08T13:29:09.513Z	Detected unused OAuth state cookies
2023-11-08T13:29:09.513Z	Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-[user]&redirect_uri=%2Fuser%2F[user]%2Foauth_callback&response_type=code&state=[state]
2023-11-08T13:29:09.513Z	wrote error: ‘Forbidden’
2023-11-08T13:29:09.513Z	403 GET /user/[user]/api/kernels (@10.49.241.58) 2.90ms
2023-11-08T13:29:37.618Z	fetching config
2023-11-08T13:29:37.618Z	successfully fetched and wrote configuration
2023-11-08T13:29:49.538Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: status (busy)
2023-11-08T13:29:49.538Z	(test_parity_check[~(test_parity_check[replay_anomaly_start] > 0))
2023-11-08T13:29:49.539Z	activity on ff944a42-2f3d-4a4d-94b9-24d9cb6d9a47: execute_input

minrk · November 13, 2023, 8:33am

Thanks for the logs! I think we have our lead. The code that’s supposed to prevent login redirects for api requests appears to be preventing the actual 302 redirect (it’s successfully turning it into 403), but only after the process has begun with setting state cookies, etc. So that would result in setting lots of oauth cookies that never get used. I’ll have to look into what’s going on there.

The short-term workaround ought to be to run jupyterhub not as an Server Extension, but the older subclass implementation by setting:

JUPYTERHUB_SINGLEUSER_EXTENSION=0

in the single-user env. No other behavior should be different.

minrk · November 13, 2023, 9:18am

Actually, re-reading the code for this bug report, I don’t think that this issue is specific to the Extension implementation, I think it’s unavoidable without a patch to JupyterHub.

I believe this is fixed by #4630.

Kurt · December 1, 2023, 2:20am

I’m having the same problem, hopefully the PR can be merged soon!

lillstrumpa · March 25, 2024, 12:38pm

@minrk I have upgraded to the 4.1.0 release of JupyterHub (using z2jh helm chart version 3.3.2). I am unfortunately still experiencing this issue.
JuputerHub is using ADFS as an external OAuth provider, and when the token expires loads of oauth-state cookies are created and eventually I get the 431-error.

I’m seeing the below log-snippet repeated in logs for the notebook-server. I am using scipy-notebook:hub-4.0.2

[W 2024-03-25 10:02:04.257 ServerApp] 403 GET /user/<user>/api/contents?content=1&hash=0&1711360924239 (@::ffff:10.130.2.10) 4.57ms
[W 2024-03-25 10:02:07.105 ServerApp] Token stored in cookie may have expired
[W 2024-03-25 10:02:07.105 ServerApp] Detected unused OAuth state cookies
[W 2024-03-25 10:02:07.105 ServerApp] wrote error: 'Forbidden'
Traceback (most recent call last):
File "/opt/conda/lib/python3.11/site-packages/tornado/web.py", line 1788, in _execute
result = method(*self.path_args, **self.path_kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/conda/lib/python3.11/site-packages/tornado/web.py", line 3289, in wrapper
url = self.get_login_url()
^^^^^^^^^^^^^^^^^^^^
File "/opt/conda/lib/python3.11/site-packages/jupyterhub/singleuser/extension.py", line 148, in get_login_url
return original_get_login_url()
^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/conda/lib/python3.11/site-packages/jupyter_server/base/handlers.py", line 782, in get_login_url
raise web.HTTPError(403)
tornado.web.HTTPError: HTTP 403: Forbidden

minrk · March 26, 2024, 9:14am

@lillstrumpa can you try the hub-4.1.1 image? There will probably be a 4.1.3 tomorrow.

But this fix is in the singleuser code, so if you are using the hub-4.0.2 image, it’s not getting this fix.

lillstrumpa · March 26, 2024, 9:38am

Yes I can. I’ll upgrade to the latest and report back.

I didn’t find any jupyterlab images for the 4.1-hub when I uppgraded earlier. I’ll upgrade those images too if there are any newer.

Topic		Replies	Views
400 OAuth state mismatch or OAuth state missing from cookies on login JupyterHub	3	1333	July 2, 2021
400 : Bad Request OAuth state missing from cookies JupyterHub	4	1293	December 11, 2023
Jupyter + Jeycloak 400 : Bad Request OAuth state missing from cookies Zero to JupyterHub on Kubernetes	1	255	April 24, 2024
599 Empty Reply from Server - oauth Zero to JupyterHub on Kubernetes jupyterhub	2	1021	February 16, 2023
JupyterHub "400 : Bad Request OAuth state missing from cookies" generic authentication JupyterHub jupyterhub , help-wanted	3	1388	October 7, 2021

Error 431 (headers too big) during singleuser oauth

How to reproduce

Expected behaviour

Actual behaviour

Your personal set up

Related topics