Hi all,
I want to try a translucent configuration: The local ldap shall overlay the central ldap with local information on mail routing. I only have read access to the central ldap server.
Generally it works fine, when using bind with a locally known user. But when I try bind with a user of the central ldap (for mail user authentication) it fails.
Example: $ ldapsearch -LLL -w pass -b cn=sendmail,dc=some,dc=local,dc=company,dc=de -H ldap://localhost/ -b ou=People,dc=company,dc=de uid=myUID cn uid mailLocalAddress
returns me absolutely correct: dn: uid=myUID,ou=people,dc=company,dc=de uid: nyUID cn: Firstname Name mailLocalAddress: firstname.name@some.local.company.de mailLocalAddress: f.name@some.local.company.de mailLocalAddress: myUID@some.local.company.de
$ ldapsearch -LLL -w myPass -b uid=myUID,ou=People,dc=company,dc=de -H ldap://localhost/ -b ou=People,dc=company,dc=de uid=myUID cn did mailLocalAddress
returns no results.
When tcpdumping network traffic to central ldap I can see that the correct result is returned.
What am I possibly doing wrong? Thanks in advance for any hints.
Best regards, Frank
### Relevant parts of my configuration:
# {2}mdb, config dn: olcDatabase={2}mdb,cn=config objectClass: olcDatabaseConfig objectClass: olcMdbConfig olcDatabase: {2}mdb olcDbDirectory: /var/lib/ldap/translucent olcSuffix: ou=People,dc=company,dc=de olcRootDN: cn=local-admin,ou=People,dc=company,dc=de olcRootPW:: secret... olcDbIndex: objectClass eq olcAccess: {0}to attrs=userPassword,shadowLastChange by self write by anonym ous auth by * none olcAccess: {1}to dn.base="" by * read olcAccess: {2}to dn.children="ou=People,dc=company,dc=de" by dn="cn=sendmail,dc =some,dc=local,dc=company,dc=de" read
# {0}translucent, {2}mdb, config dn: olcOverlay={0}translucent,olcDatabase={2}mdb,cn=config objectClass: olcOverlayConfig objectClass: olcTranslucentConfig olcOverlay: {0}translucent olcTranslucentLocal: mailLocalAddress,mailRoutingAddress,mailHost
# {0}ldap, {0}translucent, {2}mdb, config dn: olcDatabase={0}ldap,olcOverlay={0}translucent,olcDatabase={2}mdb,cn=config objectClass: olcLDAPConfig objectClass: olcTranslucentDatabase olcDatabase: {0}ldap olcDbURI: "ldap://ldap.company.de" olcDbStartTLS: none starttls=no olcDbRebindAsUser: FALSE olcDbChaseReferrals: TRUE olcDbTFSupport: no olcDbProxyWhoAmI: FALSE olcDbProtocolVersion: 3 olcDbSingleConn: FALSE olcDbCancel: abandon olcDbUseTemporaryConn: FALSE olcDbConnectionPoolMax: 16 olcDbSessionTrackingRequest: FALSE olcDbNoRefs: FALSE olcDbNoUndefFilter: FALSE olcDbOnErr: continue olcDbKeepalive: 0:0:0
### Logfile on failed request:
May 22 13:46:24 ldap slapd[493]: daemon: activity on 1 descriptor May 22 13:46:24 ldap slapd[493]: daemon: activity on: May 22 13:46:24 ldap slapd[493]: May 22 13:46:24 ldap slapd[493]: slap_listener_activate(10): May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=9 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=10 busy May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=11 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=12 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=13 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: >>> slap_listener(ldap:///) May 22 13:46:24 ldap slapd[493]: daemon: listen=10, new connection on 22 May 22 13:46:24 ldap slapd[493]: daemon: added 22r (active) listener=(nil) May 22 13:46:24 ldap slapd[493]: conn=1874 fd=22 ACCEPT from IP=[::1]:49124 (IP=[::]:389) May 22 13:46:24 ldap slapd[493]: daemon: activity on 1 descriptor May 22 13:46:24 ldap slapd[493]: daemon: activity on: May 22 13:46:24 ldap slapd[493]: May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=9 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=10 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=11 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=12 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=13 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: activity on 1 descriptor May 22 13:46:24 ldap slapd[493]: daemon: activity on: May 22 13:46:24 ldap slapd[493]: 22r May 22 13:46:24 ldap slapd[493]: May 22 13:46:24 ldap slapd[493]: daemon: read active on 22 May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=9 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=10 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=11 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=12 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=13 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: connection_get(22) May 22 13:46:24 ldap slapd[493]: connection_get(22): got connid=1874 May 22 13:46:24 ldap slapd[493]: connection_read(22): checking for input on id=1874 May 22 13:46:24 ldap slapd[493]: op tag 0x60, time 1463917584 May 22 13:46:24 ldap slapd[493]: conn=1874 op=0 do_bind May 22 13:46:24 ldap slapd[493]: >>> dnPrettyNormal: <uid=myUID,ou=People,dc=company,dc=de> May 22 13:46:24 ldap slapd[493]: <<< dnPrettyNormal: <uid=myUID,ou=People,dc=company,dc=de>, <uid=myUID,ou=people,dc=company,dc=de> May 22 13:46:24 ldap slapd[493]: conn=1874 op=0 BIND dn="uid=myUID,ou=People,dc=company,dc=de" method=128 May 22 13:46:24 ldap slapd[493]: do_bind: version=3 dn="uid=myUID,ou=People,dc=company,dc=de" method=128 May 22 13:46:24 ldap slapd[493]: translucent_bind: <uid=myUID,ou=People,dc=company,dc=de> method 128 May 22 13:46:24 ldap slapd[493]: =>ldap_back_getconn: conn=1874 op=0: lc=0x7f3d44133a60 inserted refcnt=1 rc=0 May 22 13:46:24 ldap slapd[493]: daemon: activity on 1 descriptor May 22 13:46:24 ldap slapd[493]: daemon: activity on: May 22 13:46:24 ldap slapd[493]: May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=9 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=10 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=11 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=12 active_threads=0 tvp=zero May 22 13:46:24 ldap slapd[493]: daemon: epoll: listen=13 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: conn=1874 op=0 BIND dn="uid=myUID,ou=People,dc=company,dc=de" mech=SIMPLE ssf=0 May 22 13:46:25 ldap slapd[493]: do_bind: v3 bind: "uid=myUID,ou=People,dc=company,dc=de" to "uid=myUID,ou=People,dc=company,dc=de" May 22 13:46:25 ldap slapd[493]: send_ldap_result: conn=1874 op=0 p=3 May 22 13:46:25 ldap slapd[493]: send_ldap_result: err=0 matched="" text="" May 22 13:46:25 ldap slapd[493]: send_ldap_response: msgid=1 tag=97 err=0 May 22 13:46:25 ldap slapd[493]: conn=1874 op=0 RESULT tag=97 err=0 text= May 22 13:46:25 ldap slapd[493]: daemon: activity on 1 descriptor May 22 13:46:25 ldap slapd[493]: daemon: activity on: May 22 13:46:25 ldap slapd[493]: 22r May 22 13:46:25 ldap slapd[493]: May 22 13:46:25 ldap slapd[493]: daemon: read active on 22 May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=9 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=10 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=11 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=12 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=13 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: connection_get(22) May 22 13:46:25 ldap slapd[493]: connection_get(22): got connid=1874 May 22 13:46:25 ldap slapd[493]: connection_read(22): checking for input on id=1874 May 22 13:46:25 ldap slapd[493]: op tag 0x63, time 1463917585 May 22 13:46:25 ldap slapd[493]: conn=1874 op=1 do_search May 22 13:46:25 ldap slapd[493]: >>> dnPrettyNormal: <ou=People,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: <<< dnPrettyNormal: <ou=People,dc=company,dc=de>, <ou=people,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: SRCH "ou=People,dc=company,dc=de" 2 0 May 22 13:46:25 ldap slapd[493]: 0 0 0 May 22 13:46:25 ldap slapd[493]: begin get_filter May 22 13:46:25 ldap slapd[493]: EQUALITY May 22 13:46:25 ldap slapd[493]: end get_filter 0 May 22 13:46:25 ldap slapd[493]: filter: (uid=myUID) May 22 13:46:25 ldap slapd[493]: attrs: May 22 13:46:25 ldap slapd[493]: cn May 22 13:46:25 ldap slapd[493]: uid May 22 13:46:25 ldap slapd[493]: mailLocalAddress May 22 13:46:25 ldap slapd[493]: userPassword May 22 13:46:25 ldap slapd[493]: May 22 13:46:25 ldap slapd[493]: conn=1874 op=1 SRCH base="ou=People,dc=company,dc=de" scope=2 deref=0 filter="(uid=myUID)" May 22 13:46:25 ldap slapd[493]: conn=1874 op=1 SRCH attr=cn uid mailLocalAddress userPassword May 22 13:46:25 ldap slapd[493]: ==> limits_get: conn=1874 op=1 self="uid=myUID,ou=people,dc=company,dc=de" this="ou=people,dc=company,dc=de" May 22 13:46:25 ldap slapd[493]: ==> translucent_search: <ou=People,dc=company,dc=de> (uid=myUID) May 22 13:46:25 ldap slapd[493]: =>ldap_back_getconn: conn 0x7f3d44133a60 fetched refcnt=1. May 22 13:46:25 ldap slapd[493]: => ldap_back_munge_filter "(uid=myUID)" May 22 13:46:25 ldap slapd[493]: <= ldap_back_munge_filter "(uid=myUID)" (0) May 22 13:46:25 ldap slapd[493]: daemon: activity on 1 descriptor May 22 13:46:25 ldap slapd[493]: daemon: activity on: May 22 13:46:25 ldap slapd[493]: May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=9 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=10 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=11 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=12 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=13 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: >>> dnPrettyNormal: <uid=myUID,ou=people,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: <<< dnPrettyNormal: <uid=myUID,ou=people,dc=company,dc=de>, <uid=myUID,ou=people,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: >>> dnPretty: <cn=ldaproot,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: <<< dnPretty: <cn=ldaproot,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: >>> dnNormalize: <cn=ldaproot,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: <<< dnNormalize: <cn=ldaproot,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: >>> dnPretty: <cn=ldaproot,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: <<< dnPretty: <cn=ldaproot,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: >>> dnNormalize: <cn=ldaproot,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: <<< dnNormalize: <cn=ldaproot,dc=company,dc=de> May 22 13:46:25 ldap slapd[493]: ==> translucent_search_cb: uid=myUID,ou=people,dc=company,dc=de May 22 13:46:25 ldap slapd[493]: => mdb_entry_get: ndn: "uid=myUID,ou=people,dc=company,dc=de" May 22 13:46:25 ldap slapd[493]: => mdb_entry_get: oc: "(null)", at: "(null)" May 22 13:46:25 ldap slapd[493]: mdb_dn2entry("uid=myUID,ou=people,dc=company,dc=de") May 22 13:46:25 ldap slapd[493]: => mdb_dn2id("uid=myUID,ou=people,dc=company,dc=de") May 22 13:46:25 ldap slapd[493]: <= mdb_dn2id: got id=0x2 May 22 13:46:25 ldap slapd[493]: => mdb_entry_decode: May 22 13:46:25 ldap slapd[493]: <= mdb_entry_decode May 22 13:46:25 ldap slapd[493]: => mdb_entry_get: found entry: "uid=myUID,ou=people,dc=company,dc=de" May 22 13:46:25 ldap slapd[493]: mdb_entry_get: rc=0 May 22 13:46:25 ldap slapd[493]: => test_filter May 22 13:46:25 ldap slapd[493]: EQUALITY May 22 13:46:25 ldap slapd[493]: => access_allowed: search access to "uid=myUID,ou=people,dc=company,dc=de" "uid" requested May 22 13:46:25 ldap slapd[493]: => dn: [2] May 22 13:46:25 ldap slapd[493]: => dn: [3] ou=people,dc=company,dc=de May 22 13:46:25 ldap slapd[493]: => acl_get: [3] matched May 22 13:46:25 ldap slapd[493]: => acl_get: [3] attr uid May 22 13:46:25 ldap slapd[493]: => acl_mask: access to entry "uid=myUID,ou=people,dc=company,dc=de", attr "uid" requested May 22 13:46:25 ldap slapd[493]: => acl_mask: to value by "uid=myUID,ou=people,dc=company,dc=de", (=0) May 22 13:46:25 ldap slapd[493]: <= check a_dn_pat: cn=sendmail,dc=some,dc=local,dc=company,dc=de May 22 13:46:25 ldap slapd[493]: <= acl_mask: no more <who> clauses, returning =0 (stop) May 22 13:46:25 ldap slapd[493]: => slap_access_allowed: search access denied by =0 May 22 13:46:25 ldap slapd[493]: => access_allowed: no more rules May 22 13:46:25 ldap slapd[493]: <= test_filter 50 May 22 13:46:25 ldap slapd[493]: send_ldap_result: conn=1874 op=1 p=3 May 22 13:46:25 ldap slapd[493]: send_ldap_result: err=0 matched="" text="" May 22 13:46:25 ldap slapd[493]: send_ldap_response: msgid=2 tag=101 err=0 May 22 13:46:25 ldap slapd[493]: conn=1874 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text= May 22 13:46:25 ldap slapd[493]: daemon: activity on 1 descriptor May 22 13:46:25 ldap slapd[493]: daemon: activity on: May 22 13:46:25 ldap slapd[493]: 22r May 22 13:46:25 ldap slapd[493]: May 22 13:46:25 ldap slapd[493]: daemon: read active on 22 May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=9 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=10 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=11 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=12 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=13 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: connection_get(22) May 22 13:46:25 ldap slapd[493]: connection_get(22): got connid=1874 May 22 13:46:25 ldap slapd[493]: connection_read(22): checking for input on id=1874 May 22 13:46:25 ldap slapd[493]: op tag 0x42, time 1463917585 May 22 13:46:25 ldap slapd[493]: ber_get_next on fd 22 failed errno=0 (Success) May 22 13:46:25 ldap slapd[493]: connection_read(22): input error=-2 id=1874, closing. May 22 13:46:25 ldap slapd[493]: connection_closing: readying conn=1874 sd=22 for close May 22 13:46:25 ldap slapd[493]: connection_close: deferring conn=1874 sd=22 May 22 13:46:25 ldap slapd[493]: conn=1874 op=2 do_unbind May 22 13:46:25 ldap slapd[493]: conn=1874 op=2 UNBIND May 22 13:46:25 ldap slapd[493]: connection_resched: attempting closing conn=1874 sd=22 May 22 13:46:25 ldap slapd[493]: connection_close: conn=1874 sd=22 May 22 13:46:25 ldap slapd[493]: translucent_connection_destroy May 22 13:46:25 ldap slapd[493]: =>ldap_back_conn_destroy: fetching conn 1874 May 22 13:46:25 ldap slapd[493]: =>ldap_back_conn_destroy: destroying conn 1874 refcnt=0 flags=0x00000101 May 22 13:46:25 ldap slapd[493]: daemon: removing 22 May 22 13:46:25 ldap slapd[493]: conn=1874 fd=22 closed May 22 13:46:25 ldap slapd[493]: daemon: activity on 1 descriptor May 22 13:46:25 ldap slapd[493]: daemon: activity on: May 22 13:46:25 ldap slapd[493]: May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=9 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=10 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=11 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=12 active_threads=0 tvp=zero May 22 13:46:25 ldap slapd[493]: daemon: epoll: listen=13 active_threads=0 tvp=zero