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.