Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
ibayer opened this issue Nov 10, 2020 · 20 comments
Closed

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

ibayer opened this issue Nov 10, 2020 · 20 comments
Labels
bug Something isn't working

Comments

@ibayer
Copy link
Contributor

ibayer commented Nov 10, 2020

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
@ibayer ibayer added the bug Something isn't working label Nov 10, 2020
@welcome
Copy link

welcome bot commented Nov 10, 2020

Thank you for opening your first issue in this project! Engagement like this is essential for open source projects! 🤗

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! 👋

Welcome to the Jupyter community! 🎉

@ibayer
Copy link
Contributor Author

ibayer commented Nov 10, 2020

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
Copy link
Contributor Author

ibayer commented Nov 12, 2020

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.
jupyterhub/nativeauthenticator#105 (comment)

@lambdaTotoro
Copy link

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
Copy link
Contributor Author

ibayer commented Nov 12, 2020

@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
Copy link

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
Copy link
Contributor Author

ibayer commented Nov 13, 2020

@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.

@ibayer ibayer closed this as completed Nov 13, 2020
@lambdaTotoro
Copy link

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

@f-pasquarella
Copy link

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

@lambdaTotoro
Copy link

lambdaTotoro commented Apr 24, 2021

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

@f-pasquarella
Copy link

f-pasquarella commented Apr 24, 2021

@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
Copy link

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
Copy link
Contributor Author

ibayer commented Apr 24, 2021

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
Copy link

@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
Copy link

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
Copy link

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
Copy link

@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
Copy link

@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
Copy link

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
Copy link

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

4 participants