login page stops working after a few days (error 500)

ibayer commented 4 years ago

Bug description

After a few days without issues https://xxx.com/hub/login returns a blank page.

GET: https://xxx.com/hub/login returns 500 Internal Server Error

Response Headers

HTTP/2 500 Internal Server Error
access-control-allow-headers: accept, content-type, authorization
content-security-policy: frame-ancestors 'self'; report-uri /hub/security/csp-report
content-type: text/html
date: Fri, 06 Nov 2020 09:02:59 GMT
server: TornadoServer/6.0.4
x-jupyterhub-version: 1.1.0
content-length: 0
X-Firefox-Spdy: h2

warning in browser terminal

The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol. login

Note 1 still works for logged in user https://xxx.com/user/my-user/tree?

Note 2

The issue can be temporally fixed by restarting traefik sudo tljh-config reload proxy

Expected behaviour

jupyterhub stays available

Actual behaviour

jupyterhub stops serving the login page after a few days

How to reproduce

I don't know how to reproduce this. I checked the logs but couldn't find something telling. Please let me know what other infos I can provide.

Your personal set up

OS: Ubuntu 18.04.5 LTS

Version:

not sure how to check version but it should be a very recent one

2020-10-29 07:54:02,411 Checking if TLJH is already installed...
2020-10-29 07:54:02,412 TLJH already installed, upgrading...
2020-10-29 07:54:02,412 Upgrading TLJH installer...
2020-10-29 07:54:04,432 Upgraded pip
2020-10-29 07:54:07,848 Setup tljh package
2020-10-29 07:54:07,848 Starting TLJH installer...
2020-10-29 07:54:08,261 Setting up admin users
2020-10-29 07:54:08,275 Granting passwordless sudo to JupyterHub admins...
2020-10-29 07:54:08,275 Setting up user environment...
2020-10-29 07:54:37,971 Setting up JupyterHub...
2020-10-29 07:55:26,008 Waiting for JupyterHub to come up (1/20 tries)
2020-10-29 07:55:27,013 Waiting for JupyterHub to come up (2/20 tries)

Configuration:

sudo tljh-config show
users:
admin:
- xxx
auth:
type: nativeauthenticator.NativeAuthenticator
NativeAuthenticator:
minimum_password_length: 6
check_common_password: true
allowed_failed_logins: 3
seconds_before_next_try: 120
https:
enabled: true
letsencrypt:
email: admin+jupyterhub@xxx.io
domains:
- xxx.com

welcome[bot] commented 4 years ago

Thank you for opening your first issue in this project! Engagement like this is essential for open source projects! :hugs:
If you haven't done so already, check out Jupyter's Code of Conduct. Also, please try to follow the issue template as it helps other other community members to contribute more effectively. welcome You can meet the other Jovyans by joining our Discourse forum. There is also an intro thread there where you can stop by and say Hi! :wave:
Welcome to the Jupyter community! :tada:

ibayer commented 4 years ago

fund something in the logs sudo journalctl -u jupyterhub but I'm not sure what to make out of it.

tail -n 50 hub-log 
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/loaders.py", line 426, in load
Nov 10 21:02:49 abc-hub2 python3[26737]:         return loader.load(environment, name, globals)
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/loaders.py", line 426, in load
Nov 10 21:02:49 abc-hub2 python3[26737]:         return loader.load(environment, name, globals)
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/loaders.py", line 426, in load
Nov 10 21:02:49 abc-hub2 python3[26737]:         return loader.load(environment, name, globals)
Nov 10 21:02:49 abc-hub2 python3[26737]:       [Previous line repeated 980 more times]
Nov 10 21:02:49 abc-hub2 python3[26737]:     RecursionError: maximum recursion depth exceeded
Nov 10 21:02:49 abc-hub2 python3[26737]:     
Nov 10 21:02:49 abc-hub2 python3[26737]: [E 2020-11-10 21:02:49.412 JupyterHub web:1220] Uncaught exception in write_error
Nov 10 21:02:49 abc-hub2 python3[26737]:     Traceback (most recent call last):
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/tornado/web.py", line 1218, in send_error
Nov 10 21:02:49 abc-hub2 python3[26737]:         self.write_error(status_code, **kwargs)
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 1195, in write_error
Nov 10 21:02:49 abc-hub2 python3[26737]:         html = self.render_template('%s.html' % status_code, **ns)
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 1119, in render_template
Nov 10 21:02:49 abc-hub2 python3[26737]:         template = self.get_template(name)
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 1113, in get_template
Nov 10 21:02:49 abc-hub2 python3[26737]:         return self.settings['jinja2_env'].get_template(name)
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/environment.py", line 883, in get_template
Nov 10 21:02:49 abc-hub2 python3[26737]:         return self._load_template(name, self.make_globals(globals))
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/environment.py", line 857, in _load_template
Nov 10 21:02:49 abc-hub2 python3[26737]:         template = self.loader.load(self, name, globals)
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/loaders.py", line 426, in load
Nov 10 21:02:49 abc-hub2 python3[26737]:         return loader.load(environment, name, globals)
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/loaders.py", line 426, in load
Nov 10 21:02:49 abc-hub2 python3[26737]:         return loader.load(environment, name, globals)
Nov 10 21:02:49 abc-hub2 python3[26737]:       File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/loaders.py", line 426, in load
Nov 10 21:02:49 abc-hub2 python3[26737]:         return loader.load(environment, name, globals)
Nov 10 21:02:49 abc-hub2 python3[26737]:       [Previous line repeated 975 more times]
Nov 10 21:02:49 abc-hub2 python3[26737]:     RecursionError: maximum recursion depth exceeded
Nov 10 21:02:49 abc-hub2 python3[26737]:     
Nov 10 21:02:49 abc-hub2 python3[26737]: [E 2020-11-10 21:02:49.423 JupyterHub log:166] {
Nov 10 21:02:49 abc-hub2 python3[26737]:       "Host": "abc-hub.mydomain.com",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "User-Agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:81.0) Gecko/20100101 Firefox/81.0",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "Accept": "application/json, text/javascript, */*; q=0.01",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "Accept-Encoding": "gzip, deflate, br",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "Accept-Language": "de,en-US;q=0.7,en;q=0.3",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "Cookie": "_xsrf=[secret]; jupyterhub-session-id=[secret]",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "Referer": "https://abc-hub.mydomain.com/user/user.name@xxx.abc.de/notebooks/ets-vorbereitung.ipynb",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "Te": "trailers",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "X-Forwarded-For": "79.209.48.248",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "X-Forwarded-Host": "abc-hub.mydomain.com",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "X-Forwarded-Port": "443",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "X-Forwarded-Proto": "https",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "X-Forwarded-Server": "abc-hub2",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "X-Real-Ip": "79.209.48.248",
Nov 10 21:02:49 abc-hub2 python3[26737]:       "X-Requested-With": "XMLHttpRequest"
Nov 10 21:02:49 abc-hub2 python3[26737]:     }
Nov 10 21:02:49 ihk-hub2 python3[26737]: [E 2020-11-10 21:02:49.423 JupyterHub log:174] 500 GET /hub/login?next=%2Fhub%2Fuser%2Fruser.namek%40city.aaa.de%2Fmetrics (@79.209.48.248) 20.78ms

ibayer commented 4 years ago

Removing

auth:
  type: nativeauthenticator.NativeAuthenticator
  NativeAuthenticator:
    minimum_password_length: 6
    check_common_password: true
    allowed_failed_logins: 3
    seconds_before_next_try: 120

from the config seemed to resolve the issue. I'm not sure why this is the case. https://github.com/jupyterhub/nativeauthenticator/issues/105#issuecomment-726113014

lambdaTotoro commented 4 years ago

From a glance, that looks like nativeauthenticator/#114 which was closed two weeks ago by nativeauthenticator/#115. I don't think it's related to nativeauthenticator/#105, that something entirely different.

Are you using the current master version of NativeAuthenticator or an older version?

ibayer commented 4 years ago

@lambdaTotoro thanks for the feedback, I'm using the latest version on pypi.

jsonschema==3.2.0
jupyter-telemetry==0.1.0
jupyterhub==1.1.0
jupyterhub-dummyauthenticator==0.3.1
jupyterhub-firstuseauthenticator==0.14.1
jupyterhub-idle-culler==1.0
jupyterhub-ldapauthenticator==1.3.0
**jupyterhub-nativeauthenticator==0.0.5**
jupyterhub-systemdspawner==0.14
jupyterhub-tmpauthenticator==0.6
jupyterhub-traefik-proxy==0.1.6

lambdaTotoro commented 4 years ago

Yeah, the current pypi version doesn't have the fix yet. I recommend to switch to git or wait until the next version releases. We currently have an issue that talks about that.

ibayer commented 4 years ago

@lambdaTotoro Ok I'll wait till the next release but please note that this issue is really severe if it affects all recent pip installs. I think everyone currently updating tljh will be effected (deps are not pinned).

What makes this so tricky is that the issue only starts delayed and it's really hard to know where the problem comes from even when locking at logs etc. I only realized that nativeauthenticator triggers this by try and error.

Closing since this is not caused by tljh.

lambdaTotoro commented 3 years ago

Addendum: we have since released a new version of nativeauthenticator, this issue should trouble users no longer.

f-pasquarella commented 3 years ago

Addendum: we have since released a new version of nativeauthenticator, this issue should trouble users no longer.

Hello, I've recently updated tljh, but it seems I've this exactly issue:

[E 2021-04-23 08:26:26.267 JupyterHub web:1220] Uncaught apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: apr 23 08:26:26 v01gp2-jupyterhub.sphostserver.com python3[852]: exception in write_error Traceback (most recent call last): File "/opt/tljh/hub/lib/python3.6/site-packages/tornado/web.py", line 1218, in send_error self.write_error(status_code, kwargs) File "/opt/tljh/hub/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 1254, in write_error html = self.render_template('%s.html' % status_code, ns) File "/opt/tljh/hub/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 1176, in render_template template = self.get_template(name) File "/opt/tljh/hub/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 1170, in get_template return self.settings['jinja2_env'].get_template(name) File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/environment.py", line 883, in get_template return self._load_template(name, self.make_globals(globals)) File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/environment.py", line 857, in _load_template template = self.loader.load(self, name, globals) File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/loaders.py", line 426, in load return loader.load(environment, name, globals) File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/loaders.py", line 426, in load return loader.load(environment, name, globals) File "/opt/tljh/hub/lib/python3.6/site-packages/jinja2/loaders.py", line 426, in load return loader.load(environment, name, globals) [Previous line repeated 975 more times] RecursionError: maximum recursion depth exceeded

lambdaTotoro commented 3 years ago

Can you confirm which version of nativeauthenticator you are running, @toccalenuvole73 ?

f-pasquarella commented 3 years ago

@lambdaTotoro unfortunately I wasn't able to check the version. I installed last version of tljh got by curl, while pip -list gives me:

jupyter-client 6.1.12 jupyter-core 4.7.1 jupyter-telemetry 0.1.0 jupyterhub 1.3.0 jupyterlab-pygments 0.1.2 jupyterlab-widgets 1.0.0 ... tornado 6.1

How can I check it? Thank you

lambdaTotoro commented 3 years ago

It seems like the current version of TLJH requires exactly nativeauthenticator 0.0.5 for some reason. That is a version before the bug got fixed. I recommend upgrading your nativeauthenticator package.

ibayer commented 3 years ago

Either this has changed or I was wrong before:

I think everyone currently updating tljh will be effected (deps are not pinned).

Obviously it's very unfortunate if its pinned to a buggy version. Do you see a downside to bumping the pinned dep version?

f-pasquarella commented 3 years ago

@lambdaTotoro I can't see nativeauthenticator among installed packages... sudo -E conda list -> command not found sudo -E pip3 list -> there isn't any jupyterhub-nativeauthenticator

lambdaTotoro commented 3 years ago

Obviously it's very unfortunate if its pinned to a buggy version. Do you see a downside to bumping the pinned dep version?

@ibayer Absolutely not. From our side, it either shouldn't be pinned at all or at least be pinned to 0.0.7.

@toccalenuvole73 What about just nativeauthenticator instead of jupyterhub-nativeauthenticator?

f-pasquarella commented 3 years ago

What about just nativeauthenticator instead of jupyterhub-nativeauthenticator?

@lambdaTotoro nothing... ... matplotlib 3.3.4 mistune 0.8.4 multidict 5.1.0 nbclient 0.5.3 nbconvert 6.0.7 nbformat 5.1.3 nest-asyncio 1.5.1 ...

lambdaTotoro commented 3 years ago

@toccalenuvole73 If it's not in the obvious places, you might have to look for it yourself (or open a new issue). I can only tell you that the problem you're having stems from an outdated NativeAuthenticator version.

f-pasquarella commented 3 years ago

@toccalenuvole73 If it's not in the obvious places, you might have to look for it yourself (or open a new issue). I can only tell you that the problem you're having stems from an outdated NativeAuthenticator version.

@lambdaTotoro

find . -name nativeauthenticator ./opt/tljh/hub/lib/python3.6/site-packages/jupyterhub_nativeauthenticator-0.0.5.dist-info

what should I do?

thank you

lambdaTotoro commented 3 years ago

I can't tell you, @toccalenuvole73, I have never deployed tljh. If you don't know, open another issue at an appropriate place, don't keep commenting here.

meeseeksmachine commented 3 years ago

This issue has been mentioned on Jupyter Community Forum. There might be relevant details there:

https://discourse.jupyter.org/t/upgrade-nativeauthenticator-in-tljh/8901/1

jupyterhub / the-littlest-jupyterhub