ldap3.core.exceptions.LDAPStartTLSError: automatic start_tls befored bind not successful

[1kastner]

Bug description

A JupyterHub configuration that has worked in the past stopped working after I have pulled the newest library versions.

Expected behaviour

My previous configuration continues to work.

Actual behaviour

LDAP login leads to the exception ldap3.core.exceptions.LDAPStartTLSError: automatic start_tls befored bind not successful with the following stacktrace

[E 2020-08-10 16:12:04.735 JupyterHub web:1670] Uncaught exception POST /hub/login?next= (134.28.117.8)
    HTTPServerRequest(protocol='http', host='XXXX', method='POST', uri='/hub/login?next=', version='HTTP/1.1', remote_ip='134.28.117.8')
    Traceback (most recent call last):
      File "/opt/conda/lib/python3.6/site-packages/tornado/web.py", line 1592, in _execute
        result = yield result
      File "/opt/conda/lib/python3.6/site-packages/jupyterhub/handlers/login.py", line 81, in post
        user = await self.login_user(data)
      File "/opt/conda/lib/python3.6/site-packages/jupyterhub/handlers/base.py", line 473, in login_user
        authenticated = await self.authenticate(data)
      File "/opt/conda/lib/python3.6/site-packages/jupyterhub/auth.py", line 257, in get_authenticated_user
        authenticated = await maybe_future(self.authenticate(handler, data))
      File "/opt/conda/lib/python3.6/types.py", line 248, in wrapped
        coro = func(*args, **kwargs)
      File "/opt/conda/lib/python3.6/site-packages/ldapauthenticator/ldapauthenticator.py", line 382, in authenticate
        conn = self.get_connection(userdn, password)
      File "/opt/conda/lib/python3.6/site-packages/ldapauthenticator/ldapauthenticator.py", line 315, in get_connection
        server, user=userdn, password=password, auto_bind=auto_bind
      File "/opt/conda/lib/python3.6/site-packages/ldap3/core/connection.py", line 356, in __init__
        self._do_auto_bind()
      File "/opt/conda/lib/python3.6/site-packages/ldap3/core/connection.py", line 391, in _do_auto_bind
        raise LDAPStartTLSError(error)
    ldap3.core.exceptions.LDAPStartTLSError: automatic start_tls befored bind not successful

How to reproduce

I used the simple config lines:

c.JupyterHub.authenticator_class = 'ldapauthenticator.LDAPAuthenticator'
c.LDAPAuthenticator.server_address = 'ldaps://XXX'
c.LDAPAuthenticator.bind_dn_template = [
    "uid={username},ou=people,dc=XXX,dc=de"
]
c.LDAPAuthenticator.use_ssl = True

Your personal set up

• OS: Ubuntu
• Version: latest

[welcome[bot]]

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

[manics]

Is it only the ldapauthenticator package that was updated, or other packages too?

[1kastner]

Sorry I can't tell because the JupyterHub docker container was freshly created without any fixed versions. I can do some digging there. I can say that the LDAPS server continues to work since a small script that directly imports the ldap package continues to work as intended.

[manics]

There were a few large PRs in the last release https://github.com/jupyterhub/ldapauthenticator/blob/master/CHANGELOG.md Would you mind turning on debug logging and pasting the logs here?

[jrse]

@1kastner did you make it work? i have the same problem.

[1kastner]

Well, @manics, I tried the following adjustment at the configuration to get more information:

c.JupyterHub.log_level = 'DEBUG'
c.LDAPAuthenticator.debug = True
from ldap3.utils.log import set_library_log_detail_level, OFF, BASIC, NETWORK, EXTENDED
set_library_log_detail_level(EXTENDED)  # https://ldap3.readthedocs.io/en/latest/logging.html

But nothing showed up in the logs. I guess the reason is that maybe everything dies before the real action (exchange of information over network) even starts? Or were I missing something about the logs? I just checked the Jupyter logs that show up when I run docker-compose up. Is there any other source that might be of help for you?

The following script that uses vanilla ldap works:

connection = ldap.initialize("ldaps://XXX")
connection.bind_s(
    "uid={},ou=People,dc=XXX,dc=de".format(username),
    password
)
fields = ['uid', 'givenName', 'sn', 'mail']
result = connection.search_s(
    "ou=People,dc=XXX,dc=de",
    ldap.SCOPE_SUBTREE,
    "uid={}".format(username),
    fields,
)
connection.unbind_s()

[1kastner]

@jrse I have several other jobs as well so if you want to take over to share some logs that help here, feel free to do so! If at some point I make it work I will let everyone know.

[guillaumeeb]

Hi everyone, I have also the same problem. Running jupyterhub in debug mode does not give many more lines...

[I 2020-08-11 15:11:38.399 JupyterHub log:174] 302 GET /hub/ -> /hub/login (@132.149.8.29) 1.41ms
[I 2020-08-11 15:11:38.458 JupyterHub log:174] 200 GET /hub/login (@132.149.8.29) 35.67ms
[D 2020-08-11 15:11:45.909 JupyterHub ldapauthenticator:379] Attempting to bind eynardbg with uid=eynardbg,cn=users,cn=accounts,dc=SIS,dc=CNES,dc=FR
[E 2020-08-11 15:11:45.935 JupyterHub web:1792] Uncaught exception POST /hub/login?next= (132.149.8.29)
    HTTPServerRequest(protocol='https', host='jupyterhub-qualif.sis.cnes.fr', method='POST', uri='/hub/login?next=', version='HTTP/1.1', remote_ip='132.149.8.29')
    Traceback (most recent call last):
      File "/srv/conda-2020-08-11-14-21-39/lib/python3.7/site-packages/tornado/web.py", line 1703, in _execute
        result = await result
      File "/srv/conda-2020-08-11-14-21-39/lib/python3.7/site-packages/jupyterhub/handlers/login.py", line 144, in post
        user = await self.login_user(data)
      File "/srv/conda-2020-08-11-14-21-39/lib/python3.7/site-packages/jupyterhub/handlers/base.py", line 699, in login_user
        authenticated = await self.authenticate(data)
      File "/srv/conda-2020-08-11-14-21-39/lib/python3.7/site-packages/jupyterhub/auth.py", line 383, in get_authenticated_user
        authenticated = await maybe_future(self.authenticate(handler, data))
      File "/srv/conda-2020-08-11-14-21-39/lib/python3.7/site-packages/ldapauthenticator/ldapauthenticator.py", line 382, in authenticate
        conn = self.get_connection(userdn, password)
      File "/srv/conda-2020-08-11-14-21-39/lib/python3.7/site-packages/ldapauthenticator/ldapauthenticator.py", line 315, in get_connection
        server, user=userdn, password=password, auto_bind=auto_bind
      File "/srv/conda-2020-08-11-14-21-39/lib/python3.7/site-packages/ldap3/core/connection.py", line 356, in __init__
        self._do_auto_bind()
      File "/srv/conda-2020-08-11-14-21-39/lib/python3.7/site-packages/ldap3/core/connection.py", line 391, in _do_auto_bind
        raise LDAPStartTLSError(error)
    ldap3.core.exceptions.LDAPStartTLSError: automatic start_tls befored bind not successful

[D 2020-08-11 15:11:45.939 JupyterHub base:1197] No template for 500
[E 2020-08-11 15:11:45.945 JupyterHub log:166] {
      "X-Forwarded-Host": "jupyterhub-qualif.sis.cnes.fr",
      "X-Forwarded-Proto": "https",
      "X-Forwarded-Port": "443",
      "X-Forwarded-For": "132.149.8.29",
      "Upgrade-Insecure-Requests": "1",
      "Connection": "close",
      "Dnt": "1",
      "Origin": "https://jupyterhub-qualif.sis.cnes.fr",
      "Content-Length": "41",
      "Content-Type": "application/x-www-form-urlencoded",
      "Referer": "https://jupyterhub-qualif.sis.cnes.fr/hub/login",
      "Accept-Encoding": "gzip, deflate, br",
      "Accept-Language": "fr,fr-FR;q=0.8,en-US;q=0.5,en;q=0.3",
      "Accept": "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8",
      "User-Agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0",
      "Host": "jupyterhub-qualif.sis.cnes.fr"
    }
[E 2020-08-11 15:11:45.945 JupyterHub log:174] 500 POST /hub/login?next= (@132.149.8.29) 38.24ms

What I don't know, is where the IP 132.149.8.29 in my case comes from.

[1kastner]

At https://ldap3.readthedocs.io/en/latest/changelog.html they also mention that there were several changes just some days ago when a new library version has been published. At https://github.com/cannatag/ldap3/blob/191667cff76e874164dce94dafebf0acf344bd41/ldap3/core/connection.py#L391 we can see how the error message is created and there seem to be plenty of options what can go wrong. The changes at https://github.com/jupyterhub/ldapauthenticator/blob/master/ldapauthenticator/ldapauthenticator.py#L311 seem not that recent but the way LDAP interprets it has changed. If I have use_ssl=True, then the value of auto_bind will be True and according to https://github.com/cannatag/ldap3/blob/191667cff76e874164dce94dafebf0acf344bd41/ldap3/core/connection.py#L250 now it should not be a boolean anymore!

Therefore https://github.com/cannatag/ldap3/blob/191667cff76e874164dce94dafebf0acf344bd41/ldap3/core/connection.py#L250 is not a smart solution anymore because it relies on backward-compability. If use_ssl=True, then at https://github.com/cannatag/ldap3/blob/191667cff76e874164dce94dafebf0acf344bd41/ldap3/core/connection.py#L252 it defaults to AUTO_BIND_NO_TLS and since I wanted to use SSL, I am not sure whether that is a smart decision.

This is just a quick static manual code analysis, the weather is hot, and I am not deeply rooted in any of the projects, so there might be flaws in my reasoning. But I believe https://github.com/jupyterhub/ldapauthenticator/blame/master/ldapauthenticator/ldapauthenticator.py#L312 needs some adjustments.

[guillaumeeb]

I'll try redeploying my Jupyterhub and pinning ldap3 lib to 2.7 version to see if it works. Thanks for the analysis.

[manics]

@1kastner Thanks for investigating! One of the problems with LDAP is it can be extremely complex, and prior to the last release there were no CI tests which made maintainance very difficult.

Thanks to https://github.com/jupyterhub/ldapauthenticator/pull/134 which added Travis tests this is much improved but unfortunately it looks like some bugs crept in. Would you mind opening a PR if you figure out the cause, and/or perhaps add a failing test case to https://github.com/jupyterhub/ldapauthenticator/blob/master/ldapauthenticator/tests/test_ldapauthenticator.py? Thanks!

[1kastner]

@manics I will see when I find time for it. If somebody else urgently needs a solution, better don't wait for me.

[guillaumeeb]

I'll try redeploying my Jupyterhub and pinning ldap3 lib to 2.7 version to see if it works. Thanks for the analysis.

Pinning ldap3 to 2.7 in the Python environment where the Jupyterhub is started did the trick for me.

[1kastner]

@manics Maybe then for the meantime we should also pin the version in the setup.py?

[1kastner]

My quick analysis yesterday was faulty because of the behavior of the and/or operator:

>>> True and ldap3.AUTO_BIND_TLS_BEFORE_BIND or ldap3.AUTO_BIND_NO_TLS
'TLS_BEFORE_BIND'
>>> False and ldap3.AUTO_BIND_TLS_BEFORE_BIND or ldap3.AUTO_BIND_NO_TLS
'NO_TLS'

which is equivalent to the more Pythonic version

>>> ldap3.AUTO_BIND_TLS_BEFORE_BIND if True else ldap3.AUTO_BIND_NO_TLS
'TLS_BEFORE_BIND'
>>> ldap3.AUTO_BIND_TLS_BEFORE_BIND if False else ldap3.AUTO_BIND_NO_TLS
'NO_TLS'

[1kastner]

Let's hope we will get some insights from the ldap3 developer team at https://github.com/cannatag/ldap3/issues/855.

[1kastner]

I'll try redeploying my Jupyterhub and pinning ldap3 lib to 2.7 version to see if it works. Thanks for the analysis.

Pinning ldap3 to 2.7 in the Python environment where the Jupyterhub is started did the trick for me.

Just for the complete picture: I did the same and it worked for me too.

[manics]

@1kastner I just retriggered the travis tests for master on my fork and they're failing, so it definitely seems to be due to the new ldap3 release. Do you want to open a PR to pin it?

[1kastner]

Ok, I have created a pull request for pinning the version. Once we have some feedback from the ldap3 developer team, we can see whether and how to adjust the code. If they intendedly broke something, it could get quite complex if both old and new library versions need to be supported.

[oharach1]

I'll try redeploying my Jupyterhub and pinning ldap3 lib to 2.7 version to see if it works. Thanks for the analysis.

Pinning ldap3 to 2.7 in the Python environment where the Jupyterhub is started did the trick for me.

Hi, how did you select the version 2.7 for ldap3? I mean in which part do you specified the version to use? thanks for your help.

[1kastner]

Hi, how did you select the version 2.7 for ldap3? I mean in which part do you specified the version to use? thanks for your help.

It pretty much depends on how you run the JupyterHub. You don't even need to store it somewhere but instead just install the older ldap3 version manually where it is needed.

If you use docker, you could for example take this JupyterHub Dockerfile and use pip to install the right version (see here) for how to fix a version.

FROM jupyterhub/jupyterhub:0.9.4

ADD jupyterhub_config.py /srv/jupyterhub/jupyterhub_config.py

RUN pip install dockerspawner jupyterhub-ldapauthenticator ldap3==2.7

[oharach1]

Hi, how did you select the version 2.7 for ldap3? I mean in which part do you specified the version to use? thanks for your help.

It pretty much depends on how you run the JupyterHub. You don't even need to store it somewhere but instead just install the older ldap3 version manually where it is needed.

If you use docker, you could for example take this JupyterHub Dockerfile and use pip to install the right version (see here) for how to fix a version.

FROM jupyterhub/jupyterhub:0.9.4

ADD jupyterhub_config.py /srv/jupyterhub/jupyterhub_config.py

RUN pip install dockerspawner jupyterhub-ldapauthenticator ldap3==2.7

Thanks for the insight, I was able to use version 2.7 for ldap3.

[manics]

I've just released https://pypi.org/project/jupyterhub-ldapauthenticator/1.3.1/ with @1kastner's PR to limit the version of ldap3. Hopefully we'll have a proper fix soon.

[oharach1]

Hi, how did you select the version 2.7 for ldap3? I mean in which part do you specified the version to use? thanks for your help.

It pretty much depends on how you run the JupyterHub. You don't even need to store it somewhere but instead just install the older ldap3 version manually where it is needed.

If you use docker, you could for example take this JupyterHub Dockerfile and use pip to install the right version (see here) for how to fix a version.

FROM jupyterhub/jupyterhub:0.9.4

ADD jupyterhub_config.py /srv/jupyterhub/jupyterhub_config.py

RUN pip install dockerspawner jupyterhub-ldapauthenticator ldap3==2.7

Hi, sorry for these questions, I think these could be basic, but I am trying to install dockerspawner and I am able to do this via Dockerfile, but I have some questions about how I should configure JupyterHub in order to initialize the dockerspawner, not sure if this is something related to enable on jupyterhub_configuration file, any advise will be appreciated. Thanks.

[oharach1]

Ok, I have created a pull request for pinning the version. Once we have some feedback from the ldap3 developer team, we can see whether and how to adjust the code. If they intendedly broke something, it could get quite complex if both old and new library versions need to be supported.

Hi, sorry for these questions, I think these could be very basic, but I am trying to install dockerspawner and I am able to do this via Dockerfile, but I have some questions about how I should configure JupyterHub in order to initialize the dockerspawner, not sure if this is something related to enable on jupyterhub_configuration file, any advise will be appreciated. Thanks.

[1kastner]

That is a bit unrelated to this issue. Please look at the corresponding github repos, check out the manuals, and if a question is left, you can always turn to https://discourse.jupyter.org/

[1kastner]

Thanks @manics for that quick new release. For me the bug is fixed now. As soon as I get a response to https://github.com/cannatag/ldap3/issues/855 I would discuss this in a separate issue if that is fine for everyone.

[1kastner]

At https://github.com/cannatag/ldap3/issues/855#issuecomment-674766920 a solution is pointed out.