Oct 14 21:01:53 test slapd[31707]: connection_closing: readying conn=1000 sd=15 for close Oct 14 21:01:53 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:53 test slapd[31707]: daemon: waked Oct 14 21:01:53 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:53 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:53 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:53 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:53 test slapd[31707]: connection_close: conn=1000 sd=15 Oct 14 21:01:53 test slapd[31707]: daemon: removing 15 Oct 14 21:01:53 test slapd[31707]: conn=1000 fd=15 closed (connection lost) Oct 14 21:01:58 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:58 test slapd[31707]: slap_listener_activate(8): Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=8 busy Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: >>> slap_listener(ldap:///) Oct 14 21:01:58 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:58 test slapd[31707]: daemon: waked Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: listen=8, new connection on 15 Oct 14 21:01:58 test slapd[31707]: daemon: added 15r (active) listener=0x0 Oct 14 21:01:58 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:58 test slapd[31707]: daemon: waked Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:58 test slapd[31707]: daemon: activity on: Oct 14 21:01:58 test slapd[31707]: 15r Oct 14 21:01:58 test slapd[31707]: Oct 14 21:01:58 test slapd[31707]: daemon: read activity on 15 Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: conn=1014 fd=15 ACCEPT from IP=192.168.250.150:38548 (IP=0.0.0.0:389) Oct 14 21:01:58 test slapd[31707]: connection_get(15) Oct 14 21:01:58 test slapd[31707]: connection_get(15): got connid=1014 Oct 14 21:01:58 test slapd[31707]: connection_read(15): checking for input on id=1014 Oct 14 21:01:58 test slapd[31707]: op tag 0x60, time 1287082918 Oct 14 21:01:58 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:58 test slapd[31707]: daemon: waked Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: conn=1014 op=0 do_bind Oct 14 21:01:58 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:01:58 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:01:58 test slapd[31707]: conn=1014 op=0 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:01:58 test slapd[31707]: do_bind: version=3 dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:01:58 test slapd[31707]: ==> bdb_bind: dn: cn=admin,ou=SystemAccounts,dc=test,dc=com Oct 14 21:01:58 test slapd[31707]: bdb_dn2entry("cn=admin,ou=systemaccounts,dc=test,dc=com") Oct 14 21:01:58 test slapd[31707]: => access_allowed: result not in cache (userPassword) Oct 14 21:01:58 test slapd[31707]: => access_allowed: auth access to "cn=admin,ou=SystemAccounts,dc=test,dc=com" "userPassword" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default auth access granted to "(anonymous)" Oct 14 21:01:58 test slapd[31707]: => access_allowed: auth access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: conn=1014 op=0 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" mech=SIMPLE ssf=0 Oct 14 21:01:58 test slapd[31707]: do_bind: v3 bind: "cn=admin,ou=SystemAccounts,dc=test,dc=com" to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: send_ldap_result: conn=1014 op=0 p=3 Oct 14 21:01:58 test slapd[31707]: send_ldap_result: err=0 matched="" text="" Oct 14 21:01:58 test slapd[31707]: send_ldap_response: msgid=1 tag=97 err=0 Oct 14 21:01:58 test slapd[31707]: conn=1014 op=0 RESULT tag=97 err=0 text= Oct 14 21:01:58 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:58 test slapd[31707]: daemon: activity on: Oct 14 21:01:58 test slapd[31707]: 15r Oct 14 21:01:58 test slapd[31707]: Oct 14 21:01:58 test slapd[31707]: daemon: read activity on 15 Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: connection_get(15) Oct 14 21:01:58 test slapd[31707]: connection_get(15): got connid=1014 Oct 14 21:01:58 test slapd[31707]: connection_read(15): checking for input on id=1014 Oct 14 21:01:58 test slapd[31707]: op tag 0x63, time 1287082918 Oct 14 21:01:58 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:58 test slapd[31707]: daemon: waked Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:58 test slapd[31707]: conn=1014 op=1 do_search Oct 14 21:01:58 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:01:58 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:01:58 test slapd[31707]: SRCH "ou=People,dc=test,dc=com" 2 0 Oct 14 21:01:58 test slapd[31707]: 1 0 0 Oct 14 21:01:58 test slapd[31707]: begin get_filter Oct 14 21:01:58 test slapd[31707]: AND Oct 14 21:01:58 test slapd[31707]: begin get_filter_list Oct 14 21:01:58 test slapd[31707]: begin get_filter Oct 14 21:01:58 test slapd[31707]: EQUALITY Oct 14 21:01:58 test slapd[31707]: end get_filter 0 Oct 14 21:01:58 test slapd[31707]: begin get_filter Oct 14 21:01:58 test slapd[31707]: EQUALITY Oct 14 21:01:58 test slapd[31707]: end get_filter 0 Oct 14 21:01:58 test slapd[31707]: end get_filter_list Oct 14 21:01:58 test slapd[31707]: end get_filter 0 Oct 14 21:01:58 test slapd[31707]: filter: (&(objectClass=posixAccount)(uid=ttest)) Oct 14 21:01:58 test slapd[31707]: attrs: Oct 14 21:01:58 test slapd[31707]: uid Oct 14 21:01:58 test slapd[31707]: userPassword Oct 14 21:01:58 test slapd[31707]: uidNumber Oct 14 21:01:58 test slapd[31707]: gidNumber Oct 14 21:01:58 test slapd[31707]: cn Oct 14 21:01:58 test slapd[31707]: homeDirectory Oct 14 21:01:58 test slapd[31707]: loginShell Oct 14 21:01:58 test slapd[31707]: gecos Oct 14 21:01:58 test slapd[31707]: description Oct 14 21:01:58 test slapd[31707]: objectClass Oct 14 21:01:58 test slapd[31707]: shadowLastChange Oct 14 21:01:58 test slapd[31707]: shadowMax Oct 14 21:01:58 test slapd[31707]: shadowExpire Oct 14 21:01:58 test slapd[31707]: loginClass Oct 14 21:01:58 test slapd[31707]: Oct 14 21:01:58 test slapd[31707]: conn=1014 op=1 SRCH base="ou=People,dc=test,dc=com" scope=2 deref=0 filter="(&(objectClass=posixAccount)(uid=ttest))" Oct 14 21:01:58 test slapd[31707]: conn=1014 op=1 SRCH attr=uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass shadowLastChange shadowMax shadowExpire loginClass Oct 14 21:01:58 test slapd[31707]: ==> limits_get: conn=1014 op=1 self="cn=admin,ou=systemaccounts,dc=test,dc=com" this="ou=people,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => bdb_search Oct 14 21:01:58 test slapd[31707]: bdb_dn2entry("ou=people,dc=test,dc=com") Oct 14 21:01:58 test slapd[31707]: => access_allowed: search access to "ou=People,dc=test,dc=com" "entry" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: search_candidates: base="ou=people,dc=test,dc=com" (0x00000003) scope=2 Oct 14 21:01:58 test slapd[31707]: => bdb_dn2idl("ou=people,dc=test,dc=com") Oct 14 21:01:58 test slapd[31707]: bdb_idl_fetch_key: @ou=people,dc=test,dc=com Oct 14 21:01:58 test slapd[31707]: <= bdb_dn2idl: id=362 first=3 last=610 Oct 14 21:01:58 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:58 test slapd[31707]: AND Oct 14 21:01:58 test slapd[31707]: => bdb_list_candidates 0xa0 Oct 14 21:01:58 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:58 test slapd[31707]: OR Oct 14 21:01:58 test slapd[31707]: => bdb_list_candidates 0xa1 Oct 14 21:01:58 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:58 test slapd[31707]: EQUALITY Oct 14 21:01:58 test slapd[31707]: => bdb_equality_candidates (objectClass) Oct 14 21:01:58 test slapd[31707]: => key_read Oct 14 21:01:58 test slapd[31707]: bdb_idl_fetch_key: [b49d1940] Oct 14 21:01:58 test slapd[31707]: <= bdb_index_read: failed (-30989) Oct 14 21:01:58 test slapd[31707]: <= bdb_equality_candidates: id=0, first=0, last=0 Oct 14 21:01:58 test slapd[31707]: <= bdb_filter_candidates: id=0 first=0 last=0 Oct 14 21:01:58 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:58 test slapd[31707]: AND Oct 14 21:01:58 test slapd[31707]: => bdb_list_candidates 0xa0 Oct 14 21:01:58 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:58 test slapd[31707]: EQUALITY Oct 14 21:01:58 test slapd[31707]: => bdb_equality_candidates (objectClass) Oct 14 21:01:58 test slapd[31707]: => key_read Oct 14 21:01:58 test slapd[31707]: bdb_idl_fetch_key: [5941c014] Oct 14 21:01:58 test slapd[31707]: <= bdb_index_read 299 candidates Oct 14 21:01:58 test slapd[31707]: <= bdb_equality_candidates: id=299, first=13, last=610 Oct 14 21:01:58 test slapd[31707]: <= bdb_filter_candidates: id=299 first=13 last=610 Oct 14 21:01:58 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:58 test slapd[31707]: EQUALITY Oct 14 21:01:58 test slapd[31707]: => bdb_equality_candidates (uid) Oct 14 21:01:58 test slapd[31707]: => key_read Oct 14 21:01:58 test slapd[31707]: bdb_idl_fetch_key: [47eac4d5] Oct 14 21:01:58 test slapd[31707]: <= bdb_index_read 1 candidates Oct 14 21:01:58 test slapd[31707]: <= bdb_equality_candidates: id=1, first=567, last=567 Oct 14 21:01:58 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:01:58 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:01:58 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:01:58 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:01:58 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:01:58 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:01:58 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:01:58 test slapd[31707]: bdb_search_candidates: id=1 first=567 last=567 Oct 14 21:01:58 test slapd[31707]: => test_filter Oct 14 21:01:58 test slapd[31707]: AND Oct 14 21:01:58 test slapd[31707]: => test_filter_and Oct 14 21:01:58 test slapd[31707]: => test_filter Oct 14 21:01:58 test slapd[31707]: EQUALITY Oct 14 21:01:58 test slapd[31707]: => access_allowed: search access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "objectClass" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: <= test_filter 6 Oct 14 21:01:58 test slapd[31707]: => test_filter Oct 14 21:01:58 test slapd[31707]: EQUALITY Oct 14 21:01:58 test slapd[31707]: => access_allowed: search access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uid" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: <= test_filter 6 Oct 14 21:01:58 test slapd[31707]: <= test_filter_and 6 Oct 14 21:01:58 test slapd[31707]: <= test_filter 6 Oct 14 21:01:58 test slapd[31707]: => send_search_entry: conn 1014 dn="cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "entry" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: => access_allowed: result not in cache (objectClass) Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "objectClass" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: => access_allowed: result was in cache (objectClass) Oct 14 21:01:58 test last message repeated 2 times Oct 14 21:01:58 test slapd[31707]: => access_allowed: result not in cache (loginShell) Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "loginShell" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: => access_allowed: result not in cache (gidNumber) Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "gidNumber" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: => access_allowed: result not in cache (uid) Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uid" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: => access_allowed: result not in cache (cn) Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "cn" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: => access_allowed: result not in cache (uidNumber) Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uidNumber" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: => access_allowed: result not in cache (homeDirectory) Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "homeDirectory" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: => access_allowed: result not in cache (userPassword) Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "userPassword" requested Oct 14 21:01:58 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:58 test slapd[31707]: conn=1014 op=1 ENTRY dn="cn=test test,ou=operations,ou=hq,ou=people,dc=test,dc=com" Oct 14 21:01:58 test slapd[31707]: <= send_search_entry: conn 1014 exit. Oct 14 21:01:58 test slapd[31707]: send_ldap_result: conn=1014 op=1 p=3 Oct 14 21:01:58 test slapd[31707]: send_ldap_result: err=0 matched="" text="" Oct 14 21:01:58 test slapd[31707]: send_ldap_response: msgid=2 tag=101 err=0 Oct 14 21:01:58 test slapd[31707]: conn=1014 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= Oct 14 21:01:59 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:59 test slapd[31707]: slap_listener_activate(8): Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=8 busy Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: >>> slap_listener(ldap:///) Oct 14 21:01:59 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:59 test slapd[31707]: daemon: waked Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: listen=8, new connection on 18 Oct 14 21:01:59 test slapd[31707]: daemon: added 18r (active) listener=0x0 Oct 14 21:01:59 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:59 test slapd[31707]: daemon: waked Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: conn=1015 fd=18 ACCEPT from IP=192.168.250.150:38549 (IP=0.0.0.0:389) Oct 14 21:01:59 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:59 test slapd[31707]: daemon: activity on: Oct 14 21:01:59 test slapd[31707]: 18r Oct 14 21:01:59 test slapd[31707]: Oct 14 21:01:59 test slapd[31707]: daemon: read activity on 18 Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: connection_get(18) Oct 14 21:01:59 test slapd[31707]: connection_get(18): got connid=1015 Oct 14 21:01:59 test slapd[31707]: connection_read(18): checking for input on id=1015 Oct 14 21:01:59 test slapd[31707]: op tag 0x60, time 1287082919 Oct 14 21:01:59 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:59 test slapd[31707]: daemon: waked Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: conn=1015 op=0 do_bind Oct 14 21:01:59 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:01:59 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:01:59 test slapd[31707]: conn=1015 op=0 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:01:59 test slapd[31707]: do_bind: version=3 dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:01:59 test slapd[31707]: ==> bdb_bind: dn: cn=admin,ou=SystemAccounts,dc=test,dc=com Oct 14 21:01:59 test slapd[31707]: bdb_dn2entry("cn=admin,ou=systemaccounts,dc=test,dc=com") Oct 14 21:01:59 test slapd[31707]: => access_allowed: result not in cache (userPassword) Oct 14 21:01:59 test slapd[31707]: conn=1015 op=0 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" mech=SIMPLE ssf=0 Oct 14 21:01:59 test slapd[31707]: do_bind: v3 bind: "cn=admin,ou=SystemAccounts,dc=test,dc=com" to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: send_ldap_result: conn=1015 op=0 p=3 Oct 14 21:01:59 test slapd[31707]: send_ldap_result: err=0 matched="" text="" Oct 14 21:01:59 test slapd[31707]: send_ldap_response: msgid=1 tag=97 err=0 Oct 14 21:01:59 test slapd[31707]: conn=1015 op=0 RESULT tag=97 err=0 text= Oct 14 21:01:59 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:59 test slapd[31707]: daemon: activity on: Oct 14 21:01:59 test slapd[31707]: 18r Oct 14 21:01:59 test slapd[31707]: Oct 14 21:01:59 test slapd[31707]: daemon: read activity on 18 Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: connection_get(18) Oct 14 21:01:59 test slapd[31707]: connection_get(18): got connid=1015 Oct 14 21:01:59 test slapd[31707]: connection_read(18): checking for input on id=1015 Oct 14 21:01:59 test slapd[31707]: op tag 0x63, time 1287082919 Oct 14 21:01:59 test slapd[31707]: conn=1015 op=1 do_search Oct 14 21:01:59 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:01:59 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:01:59 test slapd[31707]: SRCH "ou=People,dc=test,dc=com" 2 0 Oct 14 21:01:59 test slapd[31707]: 1 0 0 Oct 14 21:01:59 test slapd[31707]: begin get_filter Oct 14 21:01:59 test slapd[31707]: AND Oct 14 21:01:59 test slapd[31707]: begin get_filter_list Oct 14 21:01:59 test slapd[31707]: begin get_filter Oct 14 21:01:59 test slapd[31707]: EQUALITY Oct 14 21:01:59 test slapd[31707]: end get_filter 0 Oct 14 21:01:59 test slapd[31707]: begin get_filter Oct 14 21:01:59 test slapd[31707]: EQUALITY Oct 14 21:01:59 test slapd[31707]: end get_filter 0 Oct 14 21:01:59 test slapd[31707]: end get_filter_list Oct 14 21:01:59 test slapd[31707]: end get_filter 0 Oct 14 21:01:59 test slapd[31707]: filter: (&(objectClass=posixAccount)(uid=ttest)) Oct 14 21:01:59 test slapd[31707]: attrs: Oct 14 21:01:59 test slapd[31707]: uid Oct 14 21:01:59 test slapd[31707]: userPassword Oct 14 21:01:59 test slapd[31707]: uidNumber Oct 14 21:01:59 test slapd[31707]: gidNumber Oct 14 21:01:59 test slapd[31707]: cn Oct 14 21:01:59 test slapd[31707]: homeDirectory Oct 14 21:01:59 test slapd[31707]: loginShell Oct 14 21:01:59 test slapd[31707]: gecos Oct 14 21:01:59 test slapd[31707]: description Oct 14 21:01:59 test slapd[31707]: objectClass Oct 14 21:01:59 test slapd[31707]: shadowLastChange Oct 14 21:01:59 test slapd[31707]: shadowMax Oct 14 21:01:59 test slapd[31707]: shadowExpire Oct 14 21:01:59 test slapd[31707]: loginClass Oct 14 21:01:59 test slapd[31707]: Oct 14 21:01:59 test slapd[31707]: conn=1015 op=1 SRCH base="ou=People,dc=test,dc=com" scope=2 deref=0 filter="(&(objectClass=posixAccount)(uid=ttest))" Oct 14 21:01:59 test slapd[31707]: conn=1015 op=1 SRCH attr=uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass shadowLastChange shadowMax shadowExpire loginClass Oct 14 21:01:59 test slapd[31707]: ==> limits_get: conn=1015 op=1 self="cn=admin,ou=systemaccounts,dc=test,dc=com" this="ou=people,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => bdb_search Oct 14 21:01:59 test slapd[31707]: bdb_dn2entry("ou=people,dc=test,dc=com") Oct 14 21:01:59 test slapd[31707]: => access_allowed: search access to "ou=People,dc=test,dc=com" "entry" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: search_candidates: base="ou=people,dc=test,dc=com" (0x00000003) scope=2 Oct 14 21:01:59 test slapd[31707]: => bdb_dn2idl("ou=people,dc=test,dc=com") Oct 14 21:01:59 test slapd[31707]: bdb_idl_fetch_key: @ou=people,dc=test,dc=com Oct 14 21:01:59 test slapd[31707]: <= bdb_dn2idl: id=362 first=3 last=610 Oct 14 21:01:59 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:59 test slapd[31707]: AND Oct 14 21:01:59 test slapd[31707]: => bdb_list_candidates 0xa0 Oct 14 21:01:59 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:59 test slapd[31707]: OR Oct 14 21:01:59 test slapd[31707]: => bdb_list_candidates 0xa1 Oct 14 21:01:59 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:59 test slapd[31707]: EQUALITY Oct 14 21:01:59 test slapd[31707]: => bdb_equality_candidates (objectClass) Oct 14 21:01:59 test slapd[31707]: => key_read Oct 14 21:01:59 test slapd[31707]: bdb_idl_fetch_key: [b49d1940] Oct 14 21:01:59 test slapd[31707]: <= bdb_index_read: failed (-30989) Oct 14 21:01:59 test slapd[31707]: <= bdb_equality_candidates: id=0, first=0, last=0 Oct 14 21:01:59 test slapd[31707]: <= bdb_filter_candidates: id=0 first=0 last=0 Oct 14 21:01:59 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:59 test slapd[31707]: AND Oct 14 21:01:59 test slapd[31707]: => bdb_list_candidates 0xa0 Oct 14 21:01:59 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:59 test slapd[31707]: EQUALITY Oct 14 21:01:59 test slapd[31707]: => bdb_equality_candidates (objectClass) Oct 14 21:01:59 test slapd[31707]: => key_read Oct 14 21:01:59 test slapd[31707]: bdb_idl_fetch_key: [5941c014] Oct 14 21:01:59 test slapd[31707]: <= bdb_index_read 299 candidates Oct 14 21:01:59 test slapd[31707]: <= bdb_equality_candidates: id=299, first=13, last=610 Oct 14 21:01:59 test slapd[31707]: <= bdb_filter_candidates: id=299 first=13 last=610 Oct 14 21:01:59 test slapd[31707]: => bdb_filter_candidates Oct 14 21:01:59 test slapd[31707]: EQUALITY Oct 14 21:01:59 test slapd[31707]: => bdb_equality_candidates (uid) Oct 14 21:01:59 test slapd[31707]: => key_read Oct 14 21:01:59 test slapd[31707]: bdb_idl_fetch_key: [47eac4d5] Oct 14 21:01:59 test slapd[31707]: <= bdb_index_read 1 candidates Oct 14 21:01:59 test slapd[31707]: <= bdb_equality_candidates: id=1, first=567, last=567 Oct 14 21:01:59 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:01:59 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:01:59 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:01:59 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:01:59 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:01:59 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:01:59 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:01:59 test slapd[31707]: bdb_search_candidates: id=1 first=567 last=567 Oct 14 21:01:59 test slapd[31707]: => test_filter Oct 14 21:01:59 test slapd[31707]: AND Oct 14 21:01:59 test slapd[31707]: => test_filter_and Oct 14 21:01:59 test slapd[31707]: => test_filter Oct 14 21:01:59 test slapd[31707]: EQUALITY Oct 14 21:01:59 test slapd[31707]: => access_allowed: search access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "objectClass" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: <= test_filter 6 Oct 14 21:01:59 test slapd[31707]: => test_filter Oct 14 21:01:59 test slapd[31707]: EQUALITY Oct 14 21:01:59 test slapd[31707]: => access_allowed: search access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uid" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: <= test_filter 6 Oct 14 21:01:59 test slapd[31707]: <= test_filter_and 6 Oct 14 21:01:59 test slapd[31707]: <= test_filter 6 Oct 14 21:01:59 test slapd[31707]: => send_search_entry: conn 1015 dn="cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "entry" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: => access_allowed: result not in cache (objectClass) Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "objectClass" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: => access_allowed: result was in cache (objectClass) Oct 14 21:01:59 test last message repeated 2 times Oct 14 21:01:59 test slapd[31707]: => access_allowed: result not in cache (loginShell) Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "loginShell" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: => access_allowed: result not in cache (gidNumber) Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "gidNumber" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: => access_allowed: result not in cache (uid) Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uid" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: => access_allowed: result not in cache (cn) Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "cn" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: => access_allowed: result not in cache (uidNumber) Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uidNumber" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: => access_allowed: result not in cache (homeDirectory) Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "homeDirectory" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: => access_allowed: result not in cache (userPassword) Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "userPassword" requested Oct 14 21:01:59 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:01:59 test slapd[31707]: conn=1015 op=1 ENTRY dn="cn=test test,ou=operations,ou=hq,ou=people,dc=test,dc=com" Oct 14 21:01:59 test slapd[31707]: <= send_search_entry: conn 1015 exit. Oct 14 21:01:59 test slapd[31707]: send_ldap_result: conn=1015 op=1 p=3 Oct 14 21:01:59 test slapd[31707]: send_ldap_result: err=0 matched="" text="" Oct 14 21:01:59 test slapd[31707]: send_ldap_response: msgid=2 tag=101 err=0 Oct 14 21:01:59 test slapd[31707]: conn=1015 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= Oct 14 21:01:59 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:01:59 test slapd[31707]: daemon: waked Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:01:59 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:02 test slapd[31707]: slap_listener_activate(8): Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=8 busy Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: >>> slap_listener(ldap:///) Oct 14 21:02:02 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:02 test slapd[31707]: daemon: waked Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: listen=8, new connection on 28 Oct 14 21:02:02 test slapd[31707]: daemon: added 28r (active) listener=0x0 Oct 14 21:02:02 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:02 test slapd[31707]: daemon: waked Oct 14 21:02:02 test slapd[31707]: conn=1016 fd=28 ACCEPT from IP=192.168.250.150:38550 (IP=0.0.0.0:389) Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:02 test slapd[31707]: daemon: activity on: Oct 14 21:02:02 test slapd[31707]: 28r Oct 14 21:02:02 test slapd[31707]: Oct 14 21:02:02 test slapd[31707]: daemon: read activity on 28 Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: connection_get(28) Oct 14 21:02:02 test slapd[31707]: connection_get(28): got connid=1016 Oct 14 21:02:02 test slapd[31707]: connection_read(28): checking for input on id=1016 Oct 14 21:02:02 test slapd[31707]: op tag 0x60, time 1287082922 Oct 14 21:02:02 test slapd[31707]: conn=1016 op=0 do_bind Oct 14 21:02:02 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:02:02 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:02:02 test slapd[31707]: conn=1016 op=0 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:02:02 test slapd[31707]: do_bind: version=3 dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:02:02 test slapd[31707]: ==> bdb_bind: dn: cn=admin,ou=SystemAccounts,dc=test,dc=com Oct 14 21:02:02 test slapd[31707]: bdb_dn2entry("cn=admin,ou=systemaccounts,dc=test,dc=com") Oct 14 21:02:02 test slapd[31707]: => access_allowed: result not in cache (userPassword) Oct 14 21:02:02 test slapd[31707]: => access_allowed: auth access to "cn=admin,ou=SystemAccounts,dc=test,dc=com" "userPassword" requested Oct 14 21:02:02 test slapd[31707]: => slap_access_allowed: backend default auth access granted to "(anonymous)" Oct 14 21:02:02 test slapd[31707]: => access_allowed: auth access granted by read(=rscxd) Oct 14 21:02:02 test slapd[31707]: conn=1016 op=0 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" mech=SIMPLE ssf=0 Oct 14 21:02:02 test slapd[31707]: do_bind: v3 bind: "cn=admin,ou=SystemAccounts,dc=test,dc=com" to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:02 test slapd[31707]: send_ldap_result: conn=1016 op=0 p=3 Oct 14 21:02:02 test slapd[31707]: send_ldap_result: err=0 matched="" text="" Oct 14 21:02:02 test slapd[31707]: send_ldap_response: msgid=1 tag=97 err=0 Oct 14 21:02:02 test slapd[31707]: conn=1016 op=0 RESULT tag=97 err=0 text= Oct 14 21:02:02 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:02 test slapd[31707]: daemon: waked Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:02 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: activity on: Oct 14 21:02:03 test slapd[31707]: 28r Oct 14 21:02:03 test slapd[31707]: Oct 14 21:02:03 test slapd[31707]: daemon: read activity on 28 Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: connection_get(28) Oct 14 21:02:03 test slapd[31707]: connection_get(28): got connid=1016 Oct 14 21:02:03 test slapd[31707]: connection_read(28): checking for input on id=1016 Oct 14 21:02:03 test slapd[31707]: op tag 0x63, time 1287082923 Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: waked Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: conn=1016 op=1 do_search Oct 14 21:02:03 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:02:03 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:02:03 test slapd[31707]: SRCH "ou=People,dc=test,dc=com" 2 0 Oct 14 21:02:03 test slapd[31707]: 1 0 0 Oct 14 21:02:03 test slapd[31707]: begin get_filter Oct 14 21:02:03 test slapd[31707]: AND Oct 14 21:02:03 test slapd[31707]: begin get_filter_list Oct 14 21:02:03 test slapd[31707]: begin get_filter Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: end get_filter 0 Oct 14 21:02:03 test slapd[31707]: begin get_filter Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: end get_filter 0 Oct 14 21:02:03 test slapd[31707]: end get_filter_list Oct 14 21:02:03 test slapd[31707]: end get_filter 0 Oct 14 21:02:03 test slapd[31707]: filter: (&(objectClass=posixAccount)(uid=ttest)) Oct 14 21:02:03 test slapd[31707]: attrs: Oct 14 21:02:03 test slapd[31707]: host Oct 14 21:02:03 test slapd[31707]: authorizedService Oct 14 21:02:03 test slapd[31707]: shadowExpire Oct 14 21:02:03 test slapd[31707]: shadowFlag Oct 14 21:02:03 test slapd[31707]: shadowInactive Oct 14 21:02:03 test slapd[31707]: shadowLastChange Oct 14 21:02:03 test slapd[31707]: shadowMax Oct 14 21:02:03 test slapd[31707]: shadowMin Oct 14 21:02:03 test slapd[31707]: shadowWarning Oct 14 21:02:03 test slapd[31707]: uidNumber Oct 14 21:02:03 test slapd[31707]: Oct 14 21:02:03 test slapd[31707]: conn=1016 op=1 SRCH base="ou=People,dc=test,dc=com" scope=2 deref=0 filter="(&(objectClass=posixAccount)(uid=ttest))" Oct 14 21:02:03 test slapd[31707]: conn=1016 op=1 SRCH attr=host authorizedService shadowExpire shadowFlag shadowInactive shadowLastChange shadowMax shadowMin shadowWarning uidNumber Oct 14 21:02:03 test slapd[31707]: ==> limits_get: conn=1016 op=1 self="cn=admin,ou=systemaccounts,dc=test,dc=com" this="ou=people,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => bdb_search Oct 14 21:02:03 test slapd[31707]: bdb_dn2entry("ou=people,dc=test,dc=com") Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access to "ou=People,dc=test,dc=com" "entry" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: search_candidates: base="ou=people,dc=test,dc=com" (0x00000003) scope=2 Oct 14 21:02:03 test slapd[31707]: => bdb_dn2idl("ou=people,dc=test,dc=com") Oct 14 21:02:03 test slapd[31707]: bdb_idl_fetch_key: @ou=people,dc=test,dc=com Oct 14 21:02:03 test slapd[31707]: <= bdb_dn2idl: id=362 first=3 last=610 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: AND Oct 14 21:02:03 test slapd[31707]: => bdb_list_candidates 0xa0 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: OR Oct 14 21:02:03 test slapd[31707]: => bdb_list_candidates 0xa1 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => bdb_equality_candidates (objectClass) Oct 14 21:02:03 test slapd[31707]: => key_read Oct 14 21:02:03 test slapd[31707]: bdb_idl_fetch_key: [b49d1940] Oct 14 21:02:03 test slapd[31707]: <= bdb_index_read: failed (-30989) Oct 14 21:02:03 test slapd[31707]: <= bdb_equality_candidates: id=0, first=0, last=0 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=0 first=0 last=0 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: AND Oct 14 21:02:03 test slapd[31707]: => bdb_list_candidates 0xa0 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => bdb_equality_candidates (objectClass) Oct 14 21:02:03 test slapd[31707]: => key_read Oct 14 21:02:03 test slapd[31707]: bdb_idl_fetch_key: [5941c014] Oct 14 21:02:03 test slapd[31707]: <= bdb_index_read 299 candidates Oct 14 21:02:03 test slapd[31707]: <= bdb_equality_candidates: id=299, first=13, last=610 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=299 first=13 last=610 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => bdb_equality_candidates (uid) Oct 14 21:02:03 test slapd[31707]: => key_read Oct 14 21:02:03 test slapd[31707]: bdb_idl_fetch_key: [47eac4d5] Oct 14 21:02:03 test slapd[31707]: <= bdb_index_read 1 candidates Oct 14 21:02:03 test slapd[31707]: <= bdb_equality_candidates: id=1, first=567, last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: bdb_search_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: => test_filter Oct 14 21:02:03 test slapd[31707]: AND Oct 14 21:02:03 test slapd[31707]: => test_filter_and Oct 14 21:02:03 test slapd[31707]: => test_filter Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "objectClass" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: <= test_filter 6 Oct 14 21:02:03 test slapd[31707]: => test_filter Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uid" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: <= test_filter 6 Oct 14 21:02:03 test slapd[31707]: <= test_filter_and 6 Oct 14 21:02:03 test slapd[31707]: <= test_filter 6 Oct 14 21:02:03 test slapd[31707]: => send_search_entry: conn 1016 dn="cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "entry" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (uidNumber) Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uidNumber" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: conn=1016 op=1 ENTRY dn="cn=test test,ou=operations,ou=hq,ou=people,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: <= send_search_entry: conn 1016 exit. Oct 14 21:02:03 test slapd[31707]: send_ldap_result: conn=1016 op=1 p=3 Oct 14 21:02:03 test slapd[31707]: send_ldap_result: err=0 matched="" text="" Oct 14 21:02:03 test slapd[31707]: send_ldap_response: msgid=2 tag=101 err=0 Oct 14 21:02:03 test slapd[31707]: conn=1016 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: activity on: Oct 14 21:02:03 test slapd[31707]: 28r Oct 14 21:02:03 test slapd[31707]: Oct 14 21:02:03 test slapd[31707]: daemon: read activity on 28 Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: connection_get(28) Oct 14 21:02:03 test slapd[31707]: connection_get(28): got connid=1016 Oct 14 21:02:03 test slapd[31707]: connection_read(28): checking for input on id=1016 Oct 14 21:02:03 test slapd[31707]: op tag 0x60, time 1287082923 Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: waked Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: conn=1016 op=2 do_bind Oct 14 21:02:03 test slapd[31707]: conn=1016 op=2 BIND anonymous mech=implicit ssf=0 Oct 14 21:02:03 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:02:03 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:02:03 test slapd[31707]: conn=1016 op=2 BIND dn="cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" method=128 Oct 14 21:02:03 test slapd[31707]: do_bind: version=3 dn="cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" method=128 Oct 14 21:02:03 test slapd[31707]: ==> bdb_bind: dn: cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com Oct 14 21:02:03 test slapd[31707]: bdb_dn2entry("cn=test test,ou=operations,ou=hq,ou=people,dc=test,dc=com") Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (userPassword) Oct 14 21:02:03 test slapd[31707]: => access_allowed: auth access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "userPassword" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default auth access granted to "" Oct 14 21:02:03 test slapd[31707]: => access_allowed: auth access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: send_ldap_result: conn=1016 op=2 p=3 Oct 14 21:02:03 test slapd[31707]: send_ldap_result: err=49 matched="" text="" Oct 14 21:02:03 test slapd[31707]: send_ldap_response: msgid=3 tag=97 err=49 Oct 14 21:02:03 test slapd[31707]: conn=1016 op=2 RESULT tag=97 err=49 text= Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: activity on: Oct 14 21:02:03 test slapd[31707]: 28r Oct 14 21:02:03 test slapd[31707]: Oct 14 21:02:03 test slapd[31707]: daemon: read activity on 28 Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: connection_get(28) Oct 14 21:02:03 test slapd[31707]: connection_get(28): got connid=1016 Oct 14 21:02:03 test slapd[31707]: connection_read(28): checking for input on id=1016 Oct 14 21:02:03 test slapd[31707]: op tag 0x60, time 1287082923 Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: waked Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: conn=1016 op=3 do_bind Oct 14 21:02:03 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:02:03 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:02:03 test slapd[31707]: conn=1016 op=3 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:02:03 test slapd[31707]: do_bind: version=3 dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:02:03 test slapd[31707]: ==> bdb_bind: dn: cn=admin,ou=SystemAccounts,dc=test,dc=com Oct 14 21:02:03 test slapd[31707]: bdb_dn2entry("cn=admin,ou=systemaccounts,dc=test,dc=com") Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (userPassword) Oct 14 21:02:03 test slapd[31707]: => access_allowed: auth access to "cn=admin,ou=SystemAccounts,dc=test,dc=com" "userPassword" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default auth access granted to "(anonymous)" Oct 14 21:02:03 test slapd[31707]: => access_allowed: auth access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: conn=1016 op=3 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" mech=SIMPLE ssf=0 Oct 14 21:02:03 test slapd[31707]: do_bind: v3 bind: "cn=admin,ou=SystemAccounts,dc=test,dc=com" to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: send_ldap_result: conn=1016 op=3 p=3 Oct 14 21:02:03 test slapd[31707]: send_ldap_result: err=0 matched="" text="" Oct 14 21:02:03 test slapd[31707]: send_ldap_response: msgid=4 tag=97 err=0 Oct 14 21:02:03 test slapd[31707]: conn=1016 op=3 RESULT tag=97 err=0 text= Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: activity on: Oct 14 21:02:03 test slapd[31707]: 18r Oct 14 21:02:03 test slapd[31707]: Oct 14 21:02:03 test slapd[31707]: daemon: read activity on 18 Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: connection_get(18) Oct 14 21:02:03 test slapd[31707]: connection_get(18): got connid=1015 Oct 14 21:02:03 test slapd[31707]: connection_read(18): checking for input on id=1015 Oct 14 21:02:03 test slapd[31707]: ber_get_next on fd 18 failed errno=0 (Undefined error: 0) Oct 14 21:02:03 test slapd[31707]: connection_read(18): input error=-2 id=1015, closing. Oct 14 21:02:03 test slapd[31707]: connection_closing: readying conn=1015 sd=18 for close Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: waked Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: connection_close: conn=1015 sd=18 Oct 14 21:02:03 test slapd[31707]: daemon: removing 18 Oct 14 21:02:03 test slapd[31707]: conn=1015 fd=18 closed (connection lost) Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: activity on: Oct 14 21:02:03 test slapd[31707]: 28r Oct 14 21:02:03 test slapd[31707]: Oct 14 21:02:03 test slapd[31707]: daemon: read activity on 28 Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: connection_get(28) Oct 14 21:02:03 test slapd[31707]: connection_get(28): got connid=1016 Oct 14 21:02:03 test slapd[31707]: connection_read(28): checking for input on id=1016 Oct 14 21:02:03 test slapd[31707]: ber_get_next on fd 28 failed errno=0 (Undefined error: 0) Oct 14 21:02:03 test slapd[31707]: connection_read(28): input error=-2 id=1016, closing. Oct 14 21:02:03 test slapd[31707]: connection_closing: readying conn=1016 sd=28 for close Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: waked Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: connection_close: conn=1016 sd=28 Oct 14 21:02:03 test slapd[31707]: daemon: removing 28 Oct 14 21:02:03 test slapd[31707]: conn=1016 fd=28 closed (connection lost) Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: slap_listener_activate(8): Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 busy Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: >>> slap_listener(ldap:///) Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: waked Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: listen=8, new connection on 18 Oct 14 21:02:03 test slapd[31707]: daemon: added 18r (active) listener=0x0 Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: waked Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: conn=1017 fd=18 ACCEPT from IP=192.168.250.150:38551 (IP=0.0.0.0:389) Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: activity on: Oct 14 21:02:03 test slapd[31707]: 18r Oct 14 21:02:03 test slapd[31707]: Oct 14 21:02:03 test slapd[31707]: daemon: read activity on 18 Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: connection_get(18) Oct 14 21:02:03 test slapd[31707]: connection_get(18): got connid=1017 Oct 14 21:02:03 test slapd[31707]: connection_read(18): checking for input on id=1017 Oct 14 21:02:03 test slapd[31707]: op tag 0x60, time 1287082923 Oct 14 21:02:03 test slapd[31707]: conn=1017 op=0 do_bind Oct 14 21:02:03 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:02:03 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:02:03 test slapd[31707]: conn=1017 op=0 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:02:03 test slapd[31707]: do_bind: version=3 dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" method=128 Oct 14 21:02:03 test slapd[31707]: ==> bdb_bind: dn: cn=admin,ou=SystemAccounts,dc=test,dc=com Oct 14 21:02:03 test slapd[31707]: bdb_dn2entry("cn=admin,ou=systemaccounts,dc=test,dc=com") Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (userPassword) Oct 14 21:02:03 test slapd[31707]: => access_allowed: auth access to "cn=admin,ou=SystemAccounts,dc=test,dc=com" "userPassword" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default auth access granted to "(anonymous)" Oct 14 21:02:03 test slapd[31707]: => access_allowed: auth access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: conn=1017 op=0 BIND dn="cn=admin,ou=SystemAccounts,dc=test,dc=com" mech=SIMPLE ssf=0 Oct 14 21:02:03 test slapd[31707]: do_bind: v3 bind: "cn=admin,ou=SystemAccounts,dc=test,dc=com" to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: send_ldap_result: conn=1017 op=0 p=3 Oct 14 21:02:03 test slapd[31707]: send_ldap_result: err=0 matched="" text="" Oct 14 21:02:03 test slapd[31707]: send_ldap_response: msgid=1 tag=97 err=0 Oct 14 21:02:03 test slapd[31707]: conn=1017 op=0 RESULT tag=97 err=0 text= Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: waked Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: activity on: Oct 14 21:02:03 test slapd[31707]: 18r Oct 14 21:02:03 test slapd[31707]: Oct 14 21:02:03 test slapd[31707]: daemon: read activity on 18 Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: connection_get(18) Oct 14 21:02:03 test slapd[31707]: connection_get(18): got connid=1017 Oct 14 21:02:03 test slapd[31707]: connection_read(18): checking for input on id=1017 Oct 14 21:02:03 test slapd[31707]: op tag 0x63, time 1287082923 Oct 14 21:02:03 test slapd[31707]: daemon: activity on 1 descriptor Oct 14 21:02:03 test slapd[31707]: daemon: waked Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=6 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=9 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: daemon: select: listen=10 active_threads=0 tvp=NULL Oct 14 21:02:03 test slapd[31707]: conn=1017 op=1 do_search Oct 14 21:02:03 test slapd[31707]: >>> dnPrettyNormal: Oct 14 21:02:03 test slapd[31707]: <<< dnPrettyNormal: , Oct 14 21:02:03 test slapd[31707]: SRCH "ou=People,dc=test,dc=com" 2 0 Oct 14 21:02:03 test slapd[31707]: 1 0 0 Oct 14 21:02:03 test slapd[31707]: begin get_filter Oct 14 21:02:03 test slapd[31707]: AND Oct 14 21:02:03 test slapd[31707]: begin get_filter_list Oct 14 21:02:03 test slapd[31707]: begin get_filter Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: end get_filter 0 Oct 14 21:02:03 test slapd[31707]: begin get_filter Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: end get_filter 0 Oct 14 21:02:03 test slapd[31707]: end get_filter_list Oct 14 21:02:03 test slapd[31707]: end get_filter 0 Oct 14 21:02:03 test slapd[31707]: filter: (&(objectClass=posixAccount)(uid=ttest)) Oct 14 21:02:03 test slapd[31707]: attrs: Oct 14 21:02:03 test slapd[31707]: uid Oct 14 21:02:03 test slapd[31707]: userPassword Oct 14 21:02:03 test slapd[31707]: uidNumber Oct 14 21:02:03 test slapd[31707]: gidNumber Oct 14 21:02:03 test slapd[31707]: cn Oct 14 21:02:03 test slapd[31707]: homeDirectory Oct 14 21:02:03 test slapd[31707]: loginShell Oct 14 21:02:03 test slapd[31707]: gecos Oct 14 21:02:03 test slapd[31707]: description Oct 14 21:02:03 test slapd[31707]: objectClass Oct 14 21:02:03 test slapd[31707]: shadowLastChange Oct 14 21:02:03 test slapd[31707]: shadowMax Oct 14 21:02:03 test slapd[31707]: shadowExpire Oct 14 21:02:03 test slapd[31707]: loginClass Oct 14 21:02:03 test slapd[31707]: Oct 14 21:02:03 test slapd[31707]: conn=1017 op=1 SRCH base="ou=People,dc=test,dc=com" scope=2 deref=0 filter="(&(objectClass=posixAccount)(uid=ttest))" Oct 14 21:02:03 test slapd[31707]: conn=1017 op=1 SRCH attr=uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass shadowLastChange shadowMax shadowExpire loginClass Oct 14 21:02:03 test slapd[31707]: ==> limits_get: conn=1017 op=1 self="cn=admin,ou=systemaccounts,dc=test,dc=com" this="ou=people,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => bdb_search Oct 14 21:02:03 test slapd[31707]: bdb_dn2entry("ou=people,dc=test,dc=com") Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access to "ou=People,dc=test,dc=com" "entry" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: search_candidates: base="ou=people,dc=test,dc=com" (0x00000003) scope=2 Oct 14 21:02:03 test slapd[31707]: => bdb_dn2idl("ou=people,dc=test,dc=com") Oct 14 21:02:03 test slapd[31707]: bdb_idl_fetch_key: @ou=people,dc=test,dc=com Oct 14 21:02:03 test slapd[31707]: <= bdb_dn2idl: id=362 first=3 last=610 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: AND Oct 14 21:02:03 test slapd[31707]: => bdb_list_candidates 0xa0 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: OR Oct 14 21:02:03 test slapd[31707]: => bdb_list_candidates 0xa1 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => bdb_equality_candidates (objectClass) Oct 14 21:02:03 test slapd[31707]: => key_read Oct 14 21:02:03 test slapd[31707]: bdb_idl_fetch_key: [b49d1940] Oct 14 21:02:03 test slapd[31707]: <= bdb_index_read: failed (-30989) Oct 14 21:02:03 test slapd[31707]: <= bdb_equality_candidates: id=0, first=0, last=0 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=0 first=0 last=0 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: AND Oct 14 21:02:03 test slapd[31707]: => bdb_list_candidates 0xa0 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => bdb_equality_candidates (objectClass) Oct 14 21:02:03 test slapd[31707]: => key_read Oct 14 21:02:03 test slapd[31707]: bdb_idl_fetch_key: [5941c014] Oct 14 21:02:03 test slapd[31707]: <= bdb_index_read 299 candidates Oct 14 21:02:03 test slapd[31707]: <= bdb_equality_candidates: id=299, first=13, last=610 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=299 first=13 last=610 Oct 14 21:02:03 test slapd[31707]: => bdb_filter_candidates Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => bdb_equality_candidates (uid) Oct 14 21:02:03 test slapd[31707]: => key_read Oct 14 21:02:03 test slapd[31707]: bdb_idl_fetch_key: [47eac4d5] Oct 14 21:02:03 test slapd[31707]: <= bdb_index_read 1 candidates Oct 14 21:02:03 test slapd[31707]: <= bdb_equality_candidates: id=1, first=567, last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_list_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: <= bdb_filter_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: bdb_search_candidates: id=1 first=567 last=567 Oct 14 21:02:03 test slapd[31707]: => test_filter Oct 14 21:02:03 test slapd[31707]: AND Oct 14 21:02:03 test slapd[31707]: => test_filter_and Oct 14 21:02:03 test slapd[31707]: => test_filter Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "objectClass" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: <= test_filter 6 Oct 14 21:02:03 test slapd[31707]: => test_filter Oct 14 21:02:03 test slapd[31707]: EQUALITY Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uid" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default search access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: search access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: <= test_filter 6 Oct 14 21:02:03 test slapd[31707]: <= test_filter_and 6 Oct 14 21:02:03 test slapd[31707]: <= test_filter 6 Oct 14 21:02:03 test slapd[31707]: => send_search_entry: conn 1017 dn="cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "entry" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (objectClass) Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "objectClass" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: => access_allowed: result was in cache (objectClass) Oct 14 21:02:03 test last message repeated 2 times Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (loginShell) Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "loginShell" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (gidNumber) Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "gidNumber" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (uid) Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uid" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (cn) Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "cn" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (uidNumber) Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "uidNumber" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (homeDirectory) Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "homeDirectory" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: => access_allowed: result not in cache (userPassword) Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access to "cn=Test Test,ou=Operations,ou=HQ,ou=People,dc=test,dc=com" "userPassword" requested Oct 14 21:02:03 test slapd[31707]: => slap_access_allowed: backend default read access granted to "cn=admin,ou=SystemAccounts,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: => access_allowed: read access granted by read(=rscxd) Oct 14 21:02:03 test slapd[31707]: conn=1017 op=1 ENTRY dn="cn=test test,ou=operations,ou=hq,ou=people,dc=test,dc=com" Oct 14 21:02:03 test slapd[31707]: <= send_search_entry: conn 1017 exit. Oct 14 21:02:03 test slapd[31707]: send_ldap_result: conn=1017 op=1 p=3 Oct 14 21:02:03 test slapd[31707]: send_ldap_result: err=0 matched="" text="" Oct 14 21:02:03 test slapd[31707]: send_ldap_response: msgid=2 tag=101 err=0 Oct 14 21:02:03 test slapd[31707]: conn=1017 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=