Dec  6 14:05:04 hiro slapd[20062]: daemon: epoll: listen=9 active_threads=0 tvp=NULL 
Dec  6 14:05:04 hiro slapd[20062]: daemon: epoll: listen=10 active_threads=0 tvp=NULL 
Dec  6 14:05:04 hiro slapd[20062]: daemon: epoll: listen=11 active_threads=0 tvp=NULL 
Dec  6 14:05:04 hiro slapd[20062]: daemon: epoll: listen=12 active_threads=0 tvp=NULL 
Dec  6 14:05:08 hiro slapd[20062]: daemon: activity on 1 descriptor 
Dec  6 14:05:08 hiro slapd[20062]: daemon: activity on:
Dec  6 14:05:08 hiro slapd[20062]:  
Dec  6 14:05:08 hiro slapd[20062]: >>> slap_listener(ldapi:///) 
Dec  6 14:05:08 hiro slapd[20062]: daemon: listen=12, new connection on 16 
Dec  6 14:05:08 hiro slapd[20062]: daemon: added 16r (active) listener=(nil) 
Dec  6 14:05:08 hiro slapd[20062]: conn=0 fd=16 ACCEPT from PATH=/var/run/slapd/ldapi (PATH=/var/run/slapd/ldapi) 
Dec  6 14:05:08 hiro slapd[20062]: daemon: epoll: listen=8 active_threads=0 tvp=NULL 
Dec  6 14:05:08 hiro slapd[20062]: daemon: epoll: listen=9 active_threads=0 tvp=NULL 
Dec  6 14:05:08 hiro slapd[20062]: daemon: epoll: listen=10 active_threads=0 tvp=NULL 
Dec  6 14:05:08 hiro slapd[20062]: daemon: epoll: listen=11 active_threads=0 tvp=NULL 
Dec  6 14:05:08 hiro slapd[20062]: daemon: epoll: listen=12 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: activity on 1 descriptor 
Dec  6 14:05:09 hiro slapd[20062]: daemon: activity on:
Dec  6 14:05:09 hiro slapd[20062]:  16r
Dec  6 14:05:09 hiro slapd[20062]:  
Dec  6 14:05:09 hiro slapd[20062]: daemon: read active on 16 
Dec  6 14:05:09 hiro slapd[20062]: connection_get(16) 
Dec  6 14:05:09 hiro slapd[20062]: connection_get(16): got connid=0 
Dec  6 14:05:09 hiro slapd[20062]: connection_read(16): checking for input on id=0 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=8 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=9 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=10 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=11 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=12 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: do_bind 
Dec  6 14:05:09 hiro slapd[20062]: >>> dnPrettyNormal: <> 
Dec  6 14:05:09 hiro slapd[20062]: <<< dnPrettyNormal: <>, <> 
Dec  6 14:05:09 hiro slapd[20062]: do_sasl_bind: dn () mech PLAIN 
Dec  6 14:05:09 hiro slapd[20062]: conn=0 op=0 BIND dn="" method=163 
Dec  6 14:05:09 hiro slapd[20062]: ==> sasl_bind: dn="" mech=PLAIN datalen=24 
Dec  6 14:05:09 hiro slapd[20062]: SASL Canonicalize [conn=0]: authcid="abrown@olp.net" 
Dec  6 14:05:09 hiro slapd[20062]: slap_sasl_getdn: conn 0 id=abrown@olp.net [len=14] 
Dec  6 14:05:09 hiro slapd[20062]: slap_sasl_getdn: u:id converted to uid=abrown@olp.net,cn=PLAIN,cn=auth 
Dec  6 14:05:09 hiro slapd[20062]: >>> dnNormalize: <uid=abrown@olp.net,cn=PLAIN,cn=auth> 
Dec  6 14:05:09 hiro slapd[20062]: <<< dnNormalize: <uid=abrown@olp.net,cn=plain,cn=auth> 
Dec  6 14:05:09 hiro slapd[20062]: ==>slap_sasl2dn: converting SASL name uid=abrown@olp.net,cn=plain,cn=auth to a DN 
Dec  6 14:05:09 hiro slapd[20062]: slap_authz_regexp: converting SASL name uid=abrown@olp.net,cn=plain,cn=auth 
Dec  6 14:05:09 hiro slapd[20062]: slap_authz_regexp: converted SASL name to ldap:///ou=people,dc=olp,dc=net??one?(btcAltUid=abrown@olp.net) 
Dec  6 14:05:09 hiro slapd[20062]: slap_parseURI: parsing ldap:///ou=people,dc=olp,dc=net??one?(btcAltUid=abrown@olp.net) 
Dec  6 14:05:09 hiro slapd[20062]: str2filter "(btcAltUid=abrown@olp.net)" 
Dec  6 14:05:09 hiro slapd[20062]: begin get_filter 
Dec  6 14:05:09 hiro slapd[20062]: EQUALITY 
Dec  6 14:05:09 hiro slapd[20062]: end get_filter 0 
Dec  6 14:05:09 hiro slapd[20062]: >>> dnNormalize: <ou=people,dc=olp,dc=net> 
Dec  6 14:05:09 hiro slapd[20062]: <<< dnNormalize: <ou=people,dc=olp,dc=net> 
Dec  6 14:05:09 hiro slapd[20062]: slap_sasl2dn: performing internal search (base=ou=people,dc=olp,dc=net, scope=1) 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_search 
Dec  6 14:05:09 hiro slapd[20062]: bdb_dn2entry("ou=people,dc=olp,dc=net") 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_dn2id("dc=olp,dc=net") 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_dn2id: got id=0x00000001 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_dn2id("ou=people,dc=olp,dc=net") 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_dn2id: got id=0x00000003 
Dec  6 14:05:09 hiro slapd[20062]: entry_decode: "ou=people,dc=olp,dc=net" 
Dec  6 14:05:09 hiro slapd[20062]: <= entry_decode(ou=people,dc=olp,dc=net) 
Dec  6 14:05:09 hiro slapd[20062]: search_candidates: base="ou=people,dc=olp,dc=net" (0x00000003) scope=1 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_dn2idl("ou=people,dc=olp,dc=net") 
Dec  6 14:05:09 hiro slapd[20062]: bdb_idl_fetch_key: %ou=people,dc=olp,dc=net 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_dn2idl: id=68 first=7 last=136 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_filter_candidates 
Dec  6 14:05:09 hiro slapd[20062]: ^IAND 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_list_candidates 0xa0 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_filter_candidates 
Dec  6 14:05:09 hiro slapd[20062]: ^IOR 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_list_candidates 0xa1 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_filter_candidates 
Dec  6 14:05:09 hiro slapd[20062]: ^IEQUALITY 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_equality_candidates (objectClass) 
Dec  6 14:05:09 hiro slapd[20062]: => key_read 
Dec  6 14:05:09 hiro slapd[20062]: bdb_idl_fetch_key: [b49d1940] 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_index_read: failed (-30990) 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_equality_candidates: id=0, first=0, last=0 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_filter_candidates: id=0 first=0 last=0 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_filter_candidates 
Dec  6 14:05:09 hiro slapd[20062]: ^IEQUALITY 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_equality_candidates (btcAltUID) 
Dec  6 14:05:09 hiro slapd[20062]: => key_read 
Dec  6 14:05:09 hiro slapd[20062]: bdb_idl_fetch_key: [b0f0ea63] 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_index_read 1 candidates 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_equality_candidates: id=1, first=7, last=7 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_filter_candidates: id=1 first=7 last=7 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_list_candidates: id=1 first=7 last=7 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_filter_candidates: id=1 first=7 last=7 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_list_candidates: id=1 first=7 last=7 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_filter_candidates: id=1 first=7 last=7 
Dec  6 14:05:09 hiro slapd[20062]: bdb_search_candidates: id=1 first=7 last=7 
Dec  6 14:05:09 hiro slapd[20062]: entry_decode: "uid=abrown@olp.net,ou=People,dc=olp,dc=net" 
Dec  6 14:05:09 hiro slapd[20062]: <= entry_decode: str2ad(PWDHISTORY): attribute type undefined 
Dec  6 14:05:09 hiro slapd[20062]: UNKNOWN attributeDescription "PWDHISTORY" inserted. 
Dec  6 14:05:09 hiro slapd[20062]: <= entry_decode: str2ad(PWDCHANGEDTIME): attribute type undefined 
Dec  6 14:05:09 hiro slapd[20062]: UNKNOWN attributeDescription "PWDCHANGEDTIME" inserted. 
Dec  6 14:05:09 hiro slapd[20062]: <= entry_decode: str2ad(PWDFAILURETIME): attribute type undefined 
Dec  6 14:05:09 hiro slapd[20062]: UNKNOWN attributeDescription "PWDFAILURETIME" inserted. 
Dec  6 14:05:09 hiro slapd[20062]: <= entry_decode(uid=abrown@olp.net,ou=People,dc=olp,dc=net) 
Dec  6 14:05:09 hiro slapd[20062]: => bdb_dn2id("uid=abrown@olp.net,ou=people,dc=olp,dc=net") 
Dec  6 14:05:09 hiro slapd[20062]: <= bdb_dn2id: got id=0x00000007 
Dec  6 14:05:09 hiro slapd[20062]: => test_filter 
Dec  6 14:05:09 hiro slapd[20062]:     EQUALITY 
Dec  6 14:05:09 hiro slapd[20062]: => access_allowed: auth access to "uid=abrown@olp.net,ou=People,dc=olp,dc=net" "btcAltUID" requested 
Dec  6 14:05:09 hiro slapd[20062]: => dnpat: [1] ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 
Dec  6 14:05:09 hiro slapd[20062]: => dnpat: [2] .*,ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 
Dec  6 14:05:09 hiro slapd[20062]: => dn: [3] ou=people,dc=olp,dc=net 
Dec  6 14:05:09 hiro slapd[20062]: => dn: [4] ou=groups,dc=olp,dc=net 
Dec  6 14:05:09 hiro slapd[20062]: => acl_get: [7] attr btcAltUID 
Dec  6 14:05:09 hiro slapd[20062]: => acl_mask: access to entry "uid=abrown@olp.net,ou=People,dc=olp,dc=net", attr "btcAltUID" requested 
Dec  6 14:05:09 hiro slapd[20062]: => acl_mask: to value by "", (=0)  
Dec  6 14:05:09 hiro slapd[20062]: <= check a_dn_pat: anonymous 
Dec  6 14:05:09 hiro slapd[20062]: <= acl_mask: [1] applying auth(=xd) (stop) 
Dec  6 14:05:09 hiro slapd[20062]: <= acl_mask: [1] mask: auth(=xd) 
Dec  6 14:05:09 hiro slapd[20062]: => slap_access_allowed: auth access granted by auth(=xd) 
Dec  6 14:05:09 hiro slapd[20062]: => access_allowed: auth access granted by auth(=xd) 
Dec  6 14:05:09 hiro slapd[20062]: <= test_filter 6 
Dec  6 14:05:09 hiro slapd[20062]: send_ldap_result: conn=0 op=0 p=3 
Dec  6 14:05:09 hiro slapd[20062]: send_ldap_result: err=0 matched="" text="" 
Dec  6 14:05:09 hiro slapd[20062]: <==slap_sasl2dn: Converted SASL name to uid=abrown@olp.net,ou=people,dc=olp,dc=net 
Dec  6 14:05:09 hiro slapd[20062]: slap_sasl_getdn: dn:id converted to uid=abrown@olp.net,ou=people,dc=olp,dc=net 
Dec  6 14:05:09 hiro slapd[20062]: SASL Canonicalize [conn=0]: slapAuthcDN="uid=abrown@olp.net,ou=people,dc=olp,dc=net" 
Dec  6 14:05:09 hiro slapd[20062]: SASL [conn=0] Notice: transitioning user abrown@olp.net to auxprop database 
Dec  6 14:05:09 hiro slapd[20062]: SASL [conn=0] Error: setpass failed for abrown@olp.net: invalid parameter supplied 
Dec  6 14:05:09 hiro slapd[20062]: SASL [conn=0] Failure: Error putting OTP secret 
Dec  6 14:05:09 hiro slapd[20062]: SASL [conn=0] Error: OTP: failed to set secret for abrown@olp.net: invalid parameter supplied (Success) 
Dec  6 14:05:09 hiro slapd[20062]: SASL Canonicalize [conn=0]: authzid="abrown@olp.net" 
Dec  6 14:05:09 hiro slapd[20062]: SASL proxy authorize [conn=0]: authcid="abrown@olp.net" authzid="abrown@olp.net" 
Dec  6 14:05:09 hiro slapd[20062]: SASL [conn=0] Failure: invalid authcid 
Dec  6 14:05:09 hiro slapd[20062]: send_ldap_result: conn=0 op=0 p=3 
Dec  6 14:05:09 hiro slapd[20062]: send_ldap_result: err=50 matched="" text="SASL(-14): authorization failure: invalid authcid" 
Dec  6 14:05:09 hiro slapd[20062]: send_ldap_response: msgid=1 tag=97 err=50 
Dec  6 14:05:09 hiro slapd[20062]: conn=0 op=0 RESULT tag=97 err=50 text=SASL(-14): authorization failure: invalid authcid 
Dec  6 14:05:09 hiro slapd[20062]: <== slap_sasl_bind: rc=50 
Dec  6 14:05:09 hiro slapd[20062]: daemon: activity on 1 descriptor 
Dec  6 14:05:09 hiro slapd[20062]: daemon: activity on:
Dec  6 14:05:09 hiro slapd[20062]:  16r
Dec  6 14:05:09 hiro slapd[20062]:  
Dec  6 14:05:09 hiro slapd[20062]: daemon: read active on 16 
Dec  6 14:05:09 hiro slapd[20062]: connection_get(16) 
Dec  6 14:05:09 hiro slapd[20062]: connection_get(16): got connid=0 
Dec  6 14:05:09 hiro slapd[20062]: connection_read(16): checking for input on id=0 
Dec  6 14:05:09 hiro slapd[20062]: ber_get_next on fd 16 failed errno=0 (Success) 
Dec  6 14:05:09 hiro slapd[20062]: connection_read(16): input error=-2 id=0, closing. 
Dec  6 14:05:09 hiro slapd[20062]: connection_closing: readying conn=0 sd=16 for close 
Dec  6 14:05:09 hiro slapd[20062]: connection_close: conn=0 sd=-1 
Dec  6 14:05:09 hiro slapd[20062]: daemon: removing 16 
Dec  6 14:05:09 hiro slapd[20062]: conn=0 fd=16 closed (connection lost) 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=8 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=9 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=10 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=11 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=12 active_threads=0 tvp=NULL 
Dec  6 14:05:09 hiro slapd[20062]: daemon: activity on 1 descriptor 
Dec  6 14:05:09 hiro slapd[20062]: daemon: activity on:
Dec  6 14:05:09 hiro slapd[20062]:  
Dec  6 14:05:09 hiro slapd[20062]: daemon: epoll: listen=8 active_threads=0 tvp=NU