bonsai: "Can't contact LDAP server" on 1.0.0 version

I’ve update bonsai from 0.9.1 to 1.0.0 and it has started to get connection error “bonsai.errors.ConnectionError: Can’t contact LDAP server. (0xFFFF [-1])” every time, no matter if I set credentials / certificate options or not. Debug output:

client = bonsai.LDAPClient("ldaps://my.ldap:636")
client.set_credentials('simple', user='ou=condn', password='password')
conn = client.connect()
DBG: ldapconnection_new [self:0x7fd9c87fdd08]
DBG: ldapconnection_init (self:0x7fd9c87fdd08)
DBG: ldapconnection_open (self:0x7fd9c87fdd08)
DBG: connecting (self:0x7fd9c87fdd08)
DBG: create_conn_info (mech:SIMPLE, sock:-1, creds:0x7fd9af8f8240)
DBG: ldapconnectiter_new [self:0x7fd9af8f8f18]
DBG: create_init_thread_data (client:0x7fd9ae68d940, sock:-1)
DBG: create_init_thread (ld:0x29145e0, info:0x2913460, thread:0)
DBG: ldapconnection_result (self:0x7fd9c87fdd08, args:0x7fd9ae6940c8, kwds:(nil))[msgid:-1]
DBG: LDAPConnection_Result (self:0x7fd9c87fdd08, msgid:-1, millisec:-1)
DBG: LDAPConnectIter_Next (self:0x7fd9af8f8f18, timeout:-1) [tls:0, state:0]
DBG: _ldap_finish_init_thread (async:0, thread:140573321987840, timeout:-1, misc:0x29145e0)
DBG: _pthread_mutex_timedlock
DBG: LDAPConnectIter_Next (self:0x7fd9af8f8f18, timeout:-1) [tls:0, state:0]
DBG: _ldap_finish_init_thread (async:0, thread:140573321987840, timeout:-1, misc:0x29145e0)
DBG: _pthread_mutex_timedlock
ldap_create
ldap_url_parse_ext(ldaps://my.ldap:636)
ldap_sasl_bind
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP my.ldap:636
ldap_new_socket: 19
ldap_prepare_socket: 19
ldap_connect_to_host: Trying 10.0.0.1:636
ldap_pvt_connect: fd: 19 tm: 0 async: -1
ldap_ndelay_on: 19
attempting to connect: 
connect errno: 115
ldap_open_defconn: successful
ldap_send_server_request
ldap_msgfree
ldap_result ld 0x7fd9b40076d0 msgid 1
wait4msg ld 0x7fd9b40076d0 msgid 1 (infinite timeout)
wait4msg continue ld 0x7fd9b40076d0 msgid 1 all 1
** ld 0x7fd9b40076d0 Connections:
* host: my.ldap  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Fri Jan 25 16:11:58 2019
** ld 0x7fd9b40076d0 Outstanding Requests:
 * msgid 1,  origid 1, status Writing
   outstanding referrals 0, parent count 0
  ld 0x7fd9b40076d0 request count 1 (abandoned 0)
** ld 0x7fd9b40076d0 Response Queue:
   Empty
  ld 0x7fd9b40076d0 response count 0
ldap_chkResponseList ld 0x7fd9b40076d0 msgid 1 all 1
ldap_chkResponseList returns ld 0x7fd9b40076d0 NULL
ldap_int_select
wait4msg continue ld 0x7fd9b40076d0 msgid 1 all 1
** ld 0x7fd9b40076d0 Connections:
* host: my.ldap  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Fri Jan 25 16:11:58 2019
** ld 0x7fd9b40076d0 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x7fd9b40076d0 request count 1 (abandoned 0)
** ld 0x7fd9b40076d0 Response Queue:
   Empty
  ld 0x7fd9b40076d0 response count 0
ldap_chkResponseList ld 0x7fd9b40076d0 msgid 1 all 1
ldap_chkResponseList returns ld 0x7fd9b40076d0 NULL
ldap_int_select
DBG: ldap_init_thread_func (params:0x29145e0)
DBG: set_cert_policy (ld:0x7fd9b40076d0, cert_policy:4)
DBG: ldap_init_thread_func [retval:0]
DBG: LDAPConnectIter_Next (self:0x7fd9af8f8f18, timeout:-1) [tls:0, state:0]
DBG: _ldap_finish_init_thread (async:0, thread:140573321987840, timeout:-1, misc:0x29145e0)
DBG: _pthread_mutex_timedlock
DBG: set_certificates (self:0x7fd9af8f8f18)
DBG: binding [state:3]
DBG: _ldap_bind (ld:0x7fd9b40076d0, info:0x2913460, ppolicy:0, result:(nil), msgid:0)
DBG: LDAPConnectIter_Next (self:0x7fd9af8f8f18, timeout:-1) [tls:0, state:4]
DBG: binding [state:4]
DBG: ldapconnectiter_dealloc (self:0x7fd9af8f8f18)
DBG: dealloc_conn_info (info:0x2913460)
read1msg: ld 0x7fd9b40076d0 msgid 1 all 1
ldap_msgfree
ldap_err2string
Traceback (most recent call last):
  File "/home/pkirillov/.virtualenvs/amp/lib/python3.6/site-packages/IPython/core/interactiveshell.py", line 2961, in run_code
    exec(code_obj, self.user_global_ns, self.user_ns)
  File "<ipython-input-29-a00ee1f64c39>", line 1, in <module>
    conn = client.connect()
  File "/home/pkirillov/.virtualenvs/amp/lib/python3.6/site-packages/bonsai/ldapclient.py", line 577, in connect
    return LDAPConnection(self).open(timeout)
  File "/home/pkirillov/.virtualenvs/amp/lib/python3.6/site-packages/bonsai/ldapconnection.py", line 292, in open
    return super().open(timeout)
  File "/home/pkirillov/.virtualenvs/amp/lib/python3.6/site-packages/bonsai/ldapconnection.py", line 53, in open
    return self._evaluate(super().open(), timeout)
  File "/home/pkirillov/.virtualenvs/amp/lib/python3.6/site-packages/bonsai/ldapconnection.py", line 241, in _evaluate
    return self.get_result(msg_id, timeout)
bonsai.errors.ConnectionError: Can't contact LDAP server. (0xFFFF [-1])

And debug output from 0.9.1 version:

client = bonsai.LDAPClient("ldaps://my.ldap:636")
client.set_credentials('simple', ('ou=conndn', 'password'))
conn = client.connect()
DBG: ldapconnection_new [self:0x7f9e1a63bd08]
DBG: ldapconnection_init (self:0x7f9e1a63bd08)
DBG: ldapconnection_open (self:0x7f9e1a63bd08)
DBG: connecting (self:0x7f9e1a63bd08)
DBG: create_conn_info (mech:SIMPLE, sock:-1, creds:0x7f9e084eed48)
DBG: ldapconnectiter_new [self:0x7f9e0973c9c0]
DBG: create_init_thread_data (client:0x7f9e09781080, sock:-1)
DBG: create_init_thread (ld:0x2323cf0, info:0x2014a00, thread:0)
DBG: ldapconnection_result (self:0x7f9e1a63bd08, args:0x7f9e084f08c8, kwds:(nil))[msgid:-1]
DBG: LDAPConnection_Result (self:0x7f9e1a63bd08, msgid:-1, millisec:-1)
DBG: LDAPConnectIter_Next (self:0x7f9e0973c9c0, timeout:-1) [tls:0, state:0]
DBG: _ldap_finish_init_thread (async:0, thread:140316997838592, timeout:-1, misc:0x2323cf0)
DBG: ldap_init_thread_func (params:0x2323cf0)
DBG: set_cert_policy (ld:0x7f9e0400fcd0, cert_policy:4)
DBG: ldap_init_thread_func [retval:0]
DBG: _pthread_mutex_timedlock
DBG: set_certificates (self:0x7f9e0973c9c0)
DBG: binding [state:3]
DBG: _ldap_bind (ld:0x7f9e0400fcd0, info:0x2014a00, ppolicy:0, result:(nil), msgid:0)
ldap_create
ldap_url_parse_ext(ldaps://my.ldap:636)
ldap_sasl_bind
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP my.ldap:636
ldap_new_socket: 10
ldap_prepare_socket: 10
ldap_connect_to_host: Trying 10.0.0.1:636
ldap_pvt_connect: fd: 10 tm: -1 async: 0
attempting to connect: 
connect success
ldap_open_defconn: successful
ldap_send_server_request
ldap_msgfree
ldap_result ld 0x7f9e0400fcd0 msgid 1
wait4msg ld 0x7f9e0400fcd0 msgid 1 (infinite timeout)
wait4msg continue ld 0x7f9e0400fcd0 msgid 1 all 1
** ld 0x7f9e0400fcd0 Connections:
* host: my.ldap  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Fri Jan 25 16:30:09 2019
** ld 0x7f9e0400fcd0 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x7f9e0400fcd0 request count 1 (abandoned 0)
** ld 0x7f9e0400fcd0 Response Queue:
   Empty
  ld 0x7f9e0400fcd0 response count 0
ldap_chkResponseList ld 0x7f9e0400fcd0 msgid 1 all 1
ldap_chkResponseList returns ld 0x7f9e0400fcd0 NULL
ldap_int_select
read1msg: ld 0x7f9e0400fcd0 msgid 1 all 1
read1msg: ld 0x7f9e0400fcd0 msgid 1 message type bind
read1msg: ld 0x7f9e0400fcd0 0 new referrals
read1msg:  mark request completed, ld 0x7f9e0400fcd0 msgid 1
request done: ld 0x7f9e0400fcd0 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ldap_msgfree
DBG: LDAPConnectIter_Next (self:0x7f9e0973c9c0, timeout:-1) [tls:0, state:4]
DBG: binding [state:4]
DBG: ldapconnectiter_dealloc (self:0x7f9e0973c9c0)
DBG: dealloc_conn_info (info:0x2014a00)
DBG: ldapconnection_dealloc (self:0x7f9e18d570a8)

ldap lib versions: Ubuntu 18.10: libldap-2.4-2/cosmic-updates,now 2.4.46+dfsg-5ubuntu1.1 amd64 Centos 7.5: openldap-2.4.44-15.el7_5.x86_64

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Comments: 16 (6 by maintainers)

Most upvoted comments

Unfortunately, it does. When bonsai.set_connect_async(False) is set, then the socket using for the connection doesn’t have the non-blocking socket flag set. Therefore building up the connection with the LDAP server will definitely cause blocking and the underlying event loop won’t be able to switch to other coroutines.

Things get better after you have a built connection, because running an LDAP operation is asynchronous on API level (e.g. you can get a coroutine switch during a LDAP search).

It’s quite unfortunate, that this issue reappears time to time. 😦 But it seems that the integration between OpenLDAP and the different TLS libraries isn’t seamless. (To the best of my knowledge, the TLS libraries being unaware of the non-blocking socket causes this problem.)

+2
noirello on Jun 26, 2020

Thanks to @tck42, there’s a module function currently on dev branch that can turn off the async connection process.

There’s a few things I’d like to do before a new release, I’ll assess my time on the weekend how many of them can be done in a short period of time. I’d like to make a new release at the end of the month.

+1
noirello on Mar 4, 2019
Read more comments on GitHub
← noir: Unreachable Error when calling std::verify_proof() multiple times in recursion circuit
emoji-picker-element: Error: Failed to execute 'transaction' on 'IDBDatabase' while changing routes →