hello everyone,

I'm having issue with the pcachBind that it's not getting update from the upstream proxy ldap.

The use case is that after users have updated userPassword on the upstream LDAP, the new password is updated and it's authenticated correctly with the updated password when directly query the upstream LDAP.

But with the proxyldap pcache setting that I have with 3 attributes set of pcache configuration as below:

overlay pcache
pcache hdb 100000 3 1000 60
pcacheAttrset 0 +

pcacheTemplate (uid=) 0 120 0 0 30
pcacheTemplate (&(uid=)(objectClass=)) 0 60 0 0 30
pcacheTemplate (&(objectClass=)(uidNumber=)) 0 60 0 0 30
pcacheTemplate (&(uid=)(memberOf=)) 0 60 0 0 30
pcacheBind (uid=) 0 30 sub "o=mycompany.com"

pcacheAttrset 1 memberOf
pcacheTemplate (objectClass=*) 1 360 0 0 30
pcacheTemplate (uid=) 1 360 0 0 30
pcacheBind (uid=) 1 30 sub "o=mycompany.com"

pcacheAttrset 2 memberOf member
pcacheTemplate (uid=) 2 360 0 0 30
pcacheBind (uid=) 2 30 sub "o=mycompany.com"

pcacheOffline TRUE
pcacheValidate TRUE

The cacheable template for uid= is set with TTL 120 and TTR at 30. The first time query to the proxy pcache server, it's cached uid= data

Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: slap_listener_activate(8):
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 busy
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: >>> slap_listener(ldap:///)
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: listen=8, new connection on 13
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: added 13r (active) listener=(nil)
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: conn=1000 fd=13 ACCEPT from IP=10.239.134.126:60966 (IP=0.0.0.0:389)
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: activity on 2 descriptors
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: 13r
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: read active on 13
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: connection_get(13)
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: connection_get(13): got connid=1000
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: connection_read(13): checking for input on id=1000
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: op tag 0x60, time 1655184692
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: conn=1000 op=0 do_bind
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: >>> dnPrettyNormal: <uid=userX,ou=employees,o=mycompany.com>
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: <<< dnPrettyNormal: <uid=userX,ou=employees,o=mycompany.com>, <uid=userX,ou=employees,o=mycompany.com>
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: conn=1000 op=0 BIND dn="uid=userX,ou=employees,o=mycompany.com" method=128
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: do_bind: version=3 dn="uid=userX,ou=employees,o=mycompany.com" method=128
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: => bdb_entry_get: ndn: "uid=userX,ou=employees,o=mycompany.com"
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: => bdb_entry_get: oc: "(null)", at: "(null)"
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: bdb_dn2entry("uid=userX,ou=employees,o=mycompany.com")
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: => hdb_dn2id("o=mycompany.com")
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: <= hdb_dn2id: got id=0x1
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: => hdb_dn2id("ou=employees,o=mycompany.com")
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: <= hdb_dn2id: got id=0x2
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: => hdb_dn2id("uid=userX,ou=employees,o=mycompany.com")
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: <= hdb_dn2id: got id=0x3
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: entry_decode: ""
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: <= entry_decode()
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: => bdb_entry_get: found entry: "uid=userX,ou=employees,o=mycompany.com"
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: bdb_entry_get: rc=0
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: str2filter "(uid=userX)"
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: begin get_filter
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: EQUALITY
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: end get_filter 0
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: Lock QC index = 0x5638d82e9910
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: Not answerable: Unlock QC index=0x5638d82e9910
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: QUERY NOT ANSWERABLE
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: QUERY CACHEABLE
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: =>ldap_back_getconn: conn=1000 op=0: lc=0x7f8710109d80 inserted refcnt=1 rc=0
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:31:32 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: => ldap_back_munge_filter "(uid=userX)"
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: <= ldap_back_munge_filter "(uid=userX)" (0)
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: >>> dnPrettyNormal: <uid=userX,OU=employees,O=mycompany.com>
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: <<< dnPrettyNormal: <uid=userX,ou=employees,o=mycompany.com>, <uid=userX,ou=employees,o=mycompany.com>
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: >>> dnPretty: <CN=cie_ldap_test,OU=Groups,O=mycompany.com>
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: <<< dnPretty: <cn=cie_ldap_test,ou=Groups,o=mycompany.com>
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: >>> dnPretty: <CN=hps_opsinf_admin,OU=Groups,O=mycompany.com>
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: <<< dnPretty: <cn=hps_opsinf_admin,ou=Groups,o=mycompany.com>
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: >>> dnNormalize: <cn=cie_ldap_test,ou=Groups,o=mycompany.com>
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: <<< dnNormalize: <cn=cie_ldap_test,ou=Groups,o=mycompany.com>
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: >>> dnNormalize: <cn=hps_opsinf_admin,ou=Groups,o=mycompany.com>
Jun 14 05:31:33 prd-ldap1-euc1 slapd[7178]: <<< dnNormalize: <cn=hps_opsinf_admin,ou=Groups,o=mycompany.com>

But any sub-sequence queries after that it's always using the entry that found in the cached (CACHED BIND) instead of re-query with new connection to the upstream LDAP as it's expired (longer that TTL/TTR). Same situation when users change password from the upstream LDAP, the proxy ldap doesn't take the update password.

Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: slap_listener_activate(8):
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 busy
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: >>> slap_listener(ldap:///)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: listen=8, new connection on 13
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: added 13r (active) listener=(nil)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: conn=1001 fd=13 ACCEPT from IP=10.239.134.126:60993 (IP=0.0.0.0:389)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: 13r
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: read active on 13
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: connection_get(13)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: connection_get(13): got connid=1001
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: connection_read(13): checking for input on id=1001
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: op tag 0x60, time 1655184873
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: conn=1001 op=0 do_bind
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: >>> dnPrettyNormal: <uid=userX,ou=employees,o=mycompany.com>
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: <<< dnPrettyNormal: <uid=userX,ou=employees,o=mycompany.com>, <uid=userX,ou=employees,o=mycompany.com>
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: conn=1001 op=0 BIND dn="uid=userX,ou=employees,o=mycompany.com" method=128
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: do_bind: version=3 dn="uid=userX,ou=employees,o=mycompany.com" method=128
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => bdb_entry_get: ndn: "uid=userX,ou=employees,o=mycompany.com"
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => bdb_entry_get: oc: "(null)", at: "(null)"
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: bdb_dn2entry("uid=userX,ou=employees,o=mycompany.com")
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => bdb_entry_get: found entry: "uid=userX,ou=employees,o=mycompany.com"
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: bdb_entry_get: rc=0
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: str2filter "(uid=userX)"
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: begin get_filter
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: EQUALITY
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: end get_filter 0
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: Lock QC index = 0x5638d82e9910
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: QUERY ANSWERABLE (answered 1 times)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => hdb_search
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: bdb_dn2entry("uid=userX,ou=employees,o=mycompany.com")
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => access_allowed: search access to "uid=userX,ou=employees,o=mycompany.com" "entry" requested
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: <= root access granted
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => access_allowed: search access granted by manage(=mwrscxd)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: base_candidates: base: "uid=userX,ou=employees,o=mycompany.com" (0x00000003)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => test_filter
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: EQUALITY
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => access_allowed: search access to "uid=userX,ou=employees,o=mycompany.com" "uid" requested
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: <= root access granted
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => access_allowed: search access granted by manage(=mwrscxd)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: <= test_filter 6
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: send_ldap_result: conn=1001 op=0 p=3
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: send_ldap_result: err=0 matched="" text=""
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: pcache_op_bind: CACHED BIND for uid=userX,ou=employees,o=mycompany.com
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: ==> hdb_bind: dn: uid=userX,ou=employees,o=mycompany.com
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: bdb_dn2entry("uid=userX,ou=employees,o=mycompany.com")
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => access_allowed: result not in cache (userPassword)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => access_allowed: auth access to "uid=userX,ou=employees,o=mycompany.com" "userPassword" requested
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => dn: [1]
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => dn: [2] cn=subschema
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => acl_get: [3] attr userPassword
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => acl_mask: access to entry "uid=userX,ou=employees,o=mycompany.com", attr "userPassword" requested
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => acl_mask: to value by "", (=0)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: <= check a_dn_pat: self
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: <= check a_dn_pat: anonymous
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: <= acl_mask: [2] applying auth(=xd) (stop)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: <= acl_mask: [2] mask: auth(=xd)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => slap_access_allowed: auth access granted by auth(=xd)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: => access_allowed: auth access granted by auth(=xd)
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: conn=1001 op=0 BIND dn="uid=userX,ou=employees,o=mycompany.com" mech=SIMPLE ssf=0
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: do_bind: v3 bind: "uid=userX,ou=employees,o=mycompany.com" to "uid=userX,ou=employees,o=mycompany.com"
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: send_ldap_result: conn=1001 op=0 p=3
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: send_ldap_result: err=0 matched="" text=""
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: send_ldap_response: msgid=1 tag=97 err=0
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: conn=1001 op=0 RESULT tag=97 err=0 text=
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:34:33 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: 13r
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: read active on 13
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_get(13)
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_get(13): got connid=1001
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_read(13): checking for input on id=1001
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: op tag 0x77, time 1655184874
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: conn=1001 op=1 do_extended
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: conn=1001 op=1 EXT oid=1.3.6.1.4.1.4203.1.11.3
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: do_extended: oid=1.3.6.1.4.1.4203.1.11.3
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: conn=1001 op=1 WHOAMI
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: send_ldap_extended: err=0 oid= len=43
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: send_ldap_response: msgid=2 tag=120 err=0
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: conn=1001 op=1 RESULT oid= err=0 text=
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: 13r
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: read active on 13
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_get(13)
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_get(13): got connid=1001
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_read(13): checking for input on id=1001
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: op tag 0x42, time 1655184874
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: ber_get_next on fd 13 failed errno=0 (Success)
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_read(13): input error=-2 id=1001, closing.
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_closing: readying conn=1001 sd=13 for close
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_close: deferring conn=1001 sd=13
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: conn=1001 op=2 do_unbind
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: conn=1001 op=2 UNBIND
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_resched: attempting closing conn=1001 sd=13
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: connection_close: conn=1001 sd=13
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: =>ldap_back_conn_destroy: fetching conn 1001
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: removing 13
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: conn=1001 fd=13 closed
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: activity on 1 descriptor
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: activity on:
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]:
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=9 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=10 active_threads=0 tvp=NULL
Jun 14 05:34:34 prd-ldap1-euc1 slapd[7178]: daemon: epoll: listen=11 active_threads=0 tvp=NULL

Wondering that if there is anything missing with configuration or if this is a bug that I can file for bug ticket.

Thanks,

-Tommy