[Date Prev][Date Next] [Chronological] [Thread] [Top]
LDAPS: ldapsearch working, back-ldap failing?

To: <openldap-technical@openldap.org>
Subject: LDAPS: ldapsearch working, back-ldap failing?
From: Mitchell Im <sogarthm@hotmail.com>
Date: Mon, 31 Mar 2014 20:37:19 -0700
Content-language: en-us
Thread-index: AQABAgMEgY8BlT3HOE7oweHUwEqsEA==
Hi there,

After several hours of beating on this (including multiple searches over the
general internet and the mailing list), I've hit a dead end. So, I've
decided to ask the experts, since it may require poking idassert-bind, which
is pretty opaque to me (I can only partially understand the man page).
Here's the problem: I'm setting up OpenLDAP as a proxy to another LDAP
server (Active Directory, if it matters). I'm able to perform an ldapsearch
against the backend LDAP server via ldaps://. The OpenLDAP proxy works if it
connects to the backend LDAP server via ldap://. The OpenLDAP proxy does
*not* work if it connects to the backend LDAP server via ldaps://, though.
What am I missing?

This is on CentOS 6.5, packages openldap-servers-2.4.23-34.el6_5.1.x86_64,
nss-3.15.3-6.el6_5.x86_64 (Red Hat's decision).

========================================
* Backend LDAP server, ldaps://

$ ldapsearch -x -W -D 'cn=bindbot,cn=users,dc=domain,dc=local' -H
ldaps://ad.domain.local -b 'dc=domain,dc=local' 'uid=bindbot'
Enter LDAP Password:
# extended LDIF
#
# LDAPv3
# base <dc=domain,dc=local> with scope subtree
# filter: uid=bindbot
# requesting: ALL
#

# BindBot, Users, domain.local
dn: CN=BindBot,CN=Users,DC=domain,DC=local
...
..
.

========================================
* OpenLDAP server, connecting to the backend via ldap://

$ ldapsearch -x -W -D 'cn= bindbot,cn=users,dc=domain,dc=local' -H
ldaps://openldap.domain.local -b 'dc=domain,dc=local' 'uid=bindbot'
Enter LDAP Password:
# extended LDIF
#
# LDAPv3
# base <dc=domain,dc=local> with scope subtree
# filter: uid=bindbot
# requesting: ALL
#

# BindBot, Users, domain.local
dn: cn=BindBot,cn=Users,dc=domain,dc=local
...
..
.

========================================
* OpenLDAP server, connecting to the backend via ldaps:// (adding only the s
to olcDbURI's ldap:// connection)

$ ldapsearch -x -W -D 'cn= bindbot,cn=users,dc=domain,dc=local' -H
ldaps://openldap.domain.local -b 'dc=domain,dc=local' 'uid=bindbot'
Enter LDAP Password:
ldap_bind: Server is unavailable (52)
        additional info: Proxy operation retry failed

========================================
* LDIF specifying the backend:

dn: olcDatabase={2}ldap
objectClass: olcDatabaseConfig
objectClass: olcLDAPConfig
olcDatabase: {2}ldap
olcSuffix: cn=users,dc=domain,dc=local
olcSubordinate: TRUE
olcAccess: {0}to dn.subtree="dc=domain,dc=local"  by * read
olcDbURI: "ldap://ad.domain.local";
olcDbIDAssertBind: bindmethod=simple
binddn="cn=bindbot,cn=users,dc=domain,dc=
 local" credentials="********" tls_cacert=/etc/openldap/certs/ad.crt
olcDbIDAssertAuthzFrom: *
olcDbRebindAsUser: TRUE

========================================
* Snippet of /var/log/ldaplog (olcLogLevel 65535):

Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: slap_listener_activate(9):
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9 busy
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: >>> slap_listener(ldaps:///)
Mar 30 21:21:37 openldap slapd[14645]: daemon: listen=9, new connection on
15
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: added 15r (active)
listener=(nil)
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]: conn=1000 fd=15 ACCEPT from
IP=10.0.0.202:40342 (IP=0.0.0.0:636)
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:  15r
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: read active on 15
Mar 30 21:21:37 openldap slapd[14645]: connection_get(15)
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: connection_get(15): got connid=1000
Mar 30 21:21:37 openldap slapd[14645]: connection_read(15): checking for
input on id=1000
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:  15r
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: read active on 15
Mar 30 21:21:37 openldap slapd[14645]: connection_get(15)
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: connection_get(15): got connid=1000
Mar 30 21:21:37 openldap slapd[14645]: connection_read(15): checking for
input on id=1000
Mar 30 21:21:37 openldap slapd[14645]: connection_read(15): unable to get
TLS client DN, error=49 id=1000
Mar 30 21:21:37 openldap slapd[14645]: conn=1000 fd=15 TLS established
tls_ssf=256 ssf=256
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:  15r
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: read active on 15
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: connection_get(15)
Mar 30 21:21:37 openldap slapd[14645]: connection_get(15): got connid=1000
Mar 30 21:21:37 openldap slapd[14645]: connection_read(15): checking for
input on id=1000
Mar 30 21:21:37 openldap slapd[14645]: op tag 0x60, time 1396239697
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: conn=1000 op=0 do_bind
Mar 30 21:21:37 openldap slapd[14645]: >>> dnPrettyNormal:
<cn=bindbot,cn=users,dc=domain,dc=local>
Mar 30 21:21:37 openldap slapd[14645]: <<< dnPrettyNormal:
<cn=bindbot,cn=users,dc=domain,dc=local>,
<cn=bindbot,cn=users,dc=domain,dc=local>
Mar 30 21:21:37 openldap slapd[14645]: conn=1000 op=0 BIND
dn="cn=bindbot,cn=users,dc=domain,dc=local" method=128
Mar 30 21:21:37 openldap slapd[14645]: do_bind: version=3
dn="cn=bindbot,cn=users,dc=domain,dc=local" method=128
Mar 30 21:21:37 openldap slapd[14645]: [rw] bindDN:
"cn=bindbot,cn=users,dc=domain,dc=local" ->
"cn=bindbot,cn=users,dc=domain,dc=local"
Mar 30 21:21:37 openldap slapd[14645]: send_ldap_result: conn=1000 op=0 p=3
Mar 30 21:21:37 openldap slapd[14645]: send_ldap_result: err=52 matched=""
text="Proxy operation retry failed"
Mar 30 21:21:37 openldap slapd[14645]: send_ldap_response: msgid=1 tag=97
err=52
Mar 30 21:21:37 openldap slapd[14645]: conn=1000 op=0 RESULT tag=97 err=52
text=Proxy operation retry failed
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:  15r
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: read active on 15
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: connection_get(15)
Mar 30 21:21:37 openldap slapd[14645]: connection_get(15): got connid=1000
Mar 30 21:21:37 openldap slapd[14645]: connection_read(15): checking for
input on id=1000
Mar 30 21:21:37 openldap slapd[14645]: ber_get_next on fd 15 failed errno=0
(Success)
Mar 30 21:21:37 openldap slapd[14645]: connection_read(15): input error=-2
id=1000, closing.
Mar 30 21:21:37 openldap slapd[14645]: connection_closing: readying
conn=1000 sd=15 for close
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on 1 descriptor
Mar 30 21:21:37 openldap slapd[14645]: daemon: activity on:
Mar 30 21:21:37 openldap slapd[14645]:
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=7
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=9
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=10
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: daemon: epoll: listen=11
active_threads=0 tvp=zero
Mar 30 21:21:37 openldap slapd[14645]: connection_close: conn=1000 sd=15
Mar 30 21:21:37 openldap slapd[14645]: =>ldap_back_conn_destroy: fetching
conn 1000
Mar 30 21:21:37 openldap slapd[14645]: daemon: removing 15
Mar 30 21:21:37 openldap slapd[14645]: conn=1000 fd=15 closed (connection
lost)

========================================
* Other miscellaneous information:

- /etc/openldap/ldap.conf also sets TLS_CACERT, /etc/openldap/certs/ad.crt,
the CA public PEM.
- The "unable to get TLS client DN, error=49 id=1000" error happens whether
OpenLDAP attempts to connect to the backend LDAP server via ldap:// or
ldaps://.
- Adding tls_reqcert=allow to olcDbIDAssertBind doesn't help.
- Explicitly specifying :636 doesn't help.
Follow-Ups:
- Re: LDAPS: ldapsearch working, back-ldap failing?
  - From: Michael Ströder <michael@stroeder.com>
Next by Date: RE: Slave not able to update master pwdFailureTime via chain.
Index(es):
- Chronological
- Thread