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(a)some.local.company.de
mailLocalAddress: f.name(a)some.local.company.de
mailLocalAddress: myUID(a)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