###
### Args, Trace, Stats log of meta lookup that fails.
###
Dec 12 14:53:54 swapus slapd[8082]: conn=663 op=5 MOD dn="cn=Log,cn=Monitor"
Dec 12 14:53:54 swapus slapd[8082]: conn=663 op=5 MOD attr=managedInfo managedInfo
Dec 12 14:53:54 swapus slapd[8082]: send_ldap_result: conn=663 op=5 p=3
Dec 12 14:53:54 swapus slapd[8082]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:53:54 swapus slapd[8082]: send_ldap_response: msgid=6 tag=103 err=0
Dec 12 14:53:54 swapus slapd[8082]: conn=663 op=5 RESULT tag=103 err=0 text=
Dec 12 14:53:54 swapus slapd[8082]: connection_get(43)
Dec 12 14:53:54 swapus slapd[8082]: connection_get(43): got connid=663
Dec 12 14:53:54 swapus slapd[8082]: connection_read(43): checking for input on id=663
Dec 12 14:53:54 swapus slapd[8082]: ber_get_next on fd 43 failed errno=0 (Success)
Dec 12 14:53:54 swapus slapd[8082]: connection_read(43): input error=-2 id=663, closing.
Dec 12 14:53:54 swapus slapd[8082]: connection_closing: readying conn=663 sd=43 for close
Dec 12 14:53:54 swapus slapd[8082]: connection_close: conn=663 sd=43
Dec 12 14:53:54 swapus slapd[8082]: =>meta_back_conn_destroy: fetching conn 663
Dec 12 14:53:54 swapus slapd[8082]: conn=663 fd=43 closed (connection lost)
Dec 12 14:53:58 swapus slapd[8082]: conn=664 fd=43 ACCEPT from IP=127.0.0.1:52576 (IP=0.0.0.0:636)
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43)
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43): got connid=664
Dec 12 14:53:58 swapus slapd[8082]: connection_read(43): checking for input on id=664
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43)
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43): got connid=664
Dec 12 14:53:58 swapus slapd[8082]: connection_read(43): checking for input on id=664
Dec 12 14:53:58 swapus slapd[8082]: connection_read(43): unable to get TLS client DN, error=49 id=664
Dec 12 14:53:58 swapus slapd[8082]: conn=664 fd=43 TLS established tls_ssf=256 ssf=256
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43)
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43): got connid=664
Dec 12 14:53:58 swapus slapd[8082]: connection_read(43): checking for input on id=664
Dec 12 14:53:58 swapus slapd[8082]: ber_get_next on fd 43 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:53:58 swapus slapd[8082]: do_bind
Dec 12 14:53:58 swapus slapd[8082]: >>> dnPrettyNormal: <>
Dec 12 14:53:58 swapus slapd[8082]: <<< dnPrettyNormal: <>, <>
Dec 12 14:53:58 swapus slapd[8082]: do_bind: version=3 dn="" method=128
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=0 BIND dn="" method=128
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: conn=664 op=0 p=3
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_response: msgid=1 tag=97 err=0
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=0 RESULT tag=97 err=0 text=
Dec 12 14:53:58 swapus slapd[8082]: do_bind: v3 anonymous bind
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43)
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43): got connid=664
Dec 12 14:53:58 swapus slapd[8082]: connection_read(43): checking for input on id=664
Dec 12 14:53:58 swapus slapd[8082]: ber_get_next on fd 43 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:53:58 swapus slapd[8082]: do_search
Dec 12 14:53:58 swapus slapd[8082]: >>> dnPrettyNormal: <ou=ecmbi,o=ibm>
Dec 12 14:53:58 swapus slapd[8082]: <<< dnPrettyNormal: <ou=ecmbi,o=ibm>, <ou=ecmbi,o=ibm>
Dec 12 14:53:58 swapus slapd[8082]: SRCH "ou=ecmbi,o=ibm" 2 0
Dec 12 14:53:58 swapus slapd[8082]:     12 15 0
Dec 12 14:53:58 swapus slapd[8082]:     filter: (notesShortName=pfnguyen)
Dec 12 14:53:58 swapus slapd[8082]:     attrs:
Dec 12 14:53:58 swapus slapd[8082]:  1.1
Dec 12 14:53:58 swapus slapd[8082]:
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=1 SRCH base="ou=ecmbi,o=ibm" scope=2 deref=0 filter="(notesShortName=pfnguyen)"
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=1 SRCH attr=1.1
Dec 12 14:53:58 swapus slapd[8082]: ==> limits_get: conn=664 op=1 dn="[anonymous]"
Dec 12 14:53:58 swapus slapd[8082]: => bdb_search
Dec 12 14:53:58 swapus slapd[8082]: bdb_dn2entry("ou=ecmbi,o=ibm")
Dec 12 14:53:58 swapus slapd[8082]: search_candidates: base="ou=ecmbi,o=ibm" (0x00000001) scope=2
Dec 12 14:53:58 swapus slapd[8082]: => bdb_dn2idl("ou=ecmbi,o=ibm")
Dec 12 14:53:58 swapus slapd[8082]: => bdb_equality_candidates (objectClass)
Dec 12 14:53:58 swapus slapd[8082]: => key_read
Dec 12 14:53:58 swapus slapd[8082]: bdb_idl_fetch_key: [b49d1940]
Dec 12 14:53:58 swapus slapd[8082]: <= bdb_index_read: failed (-30990)
Dec 12 14:53:58 swapus slapd[8082]: <= bdb_equality_candidates: id=0, first=0, last=0
Dec 12 14:53:58 swapus slapd[8082]: => bdb_equality_candidates (notesShortName)
Dec 12 14:53:58 swapus slapd[8082]: => key_read
Dec 12 14:53:58 swapus slapd[8082]: bdb_idl_fetch_key: [f3a9c9ec]
Dec 12 14:53:58 swapus slapd[8082]: <= bdb_index_read: failed (-30990)
Dec 12 14:53:58 swapus slapd[8082]: <= bdb_equality_candidates: id=0, first=0, last=0
Dec 12 14:53:58 swapus slapd[8082]: bdb_search_candidates: id=0 first=1 last=0
Dec 12 14:53:58 swapus slapd[8082]: bdb_search: no candidates
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: conn=664 op=1 p=3
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=1: meta_back_init_one_conn(0)
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=1: meta_back_init_one_conn(1)
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=1: meta_back_init_one_conn(2)
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=1 meta_back_getconn: candidates=3 conn=-1 fetched
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=1 meta_back_dobind: conn=-1
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=1 meta_back_dobind: conn=-1 bound=3
Dec 12 14:53:58 swapus slapd[8082]: [rw] searchBase: "c=us,ou=sso,ou=ecmbi,o=ibm" -> "c=us,ou=bluepages,o=ibm.com"
Dec 12 14:53:58 swapus slapd[8082]: [rw] searchBase: "c=cn,ou=sso,ou=ecmbi,o=ibm" -> "c=cn,ou=bluepages,o=ibm.com"
Dec 12 14:53:58 swapus slapd[8082]: [rw] searchBase: "ou=sso,ou=ecmbi,o=ibm" -> "ou=SSO Stub,ou=ecmbi,o=ibm"
Dec 12 14:53:58 swapus slapd[8082]: connection_get(23)
Dec 12 14:53:58 swapus slapd[8082]: connection_get(23): got connid=12
Dec 12 14:53:58 swapus slapd[8082]: connection_read(23): checking for input on id=12
Dec 12 14:53:58 swapus slapd[8082]: ber_get_next on fd 23 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:53:58 swapus slapd[8082]: do_search
Dec 12 14:53:58 swapus slapd[8082]: >>> dnPrettyNormal: <ou=SSO Stub,ou=ecmbi,o=ibm>
Dec 12 14:53:58 swapus slapd[8082]: <<< dnPrettyNormal: <ou=SSO Stub,ou=ecmbi,o=ibm>, <ou=sso stub,ou=ecmbi,o=ibm>
Dec 12 14:53:58 swapus slapd[8082]: SRCH "ou=SSO Stub,ou=ecmbi,o=ibm" 2 0
Dec 12 14:53:58 swapus slapd[8082]:     12 15 0
Dec 12 14:53:58 swapus slapd[8082]:     filter: (notesShortName=pfnguyen)
Dec 12 14:53:58 swapus slapd[8082]:     attrs:
Dec 12 14:53:58 swapus slapd[8082]:  1.1
Dec 12 14:53:58 swapus slapd[8082]:
Dec 12 14:53:58 swapus slapd[8082]: conn=12 op=12 SRCH base="ou=SSO Stub,ou=ecmbi,o=ibm" scope=2 deref=0 filter="(notesShortName=pfnguyen)"
Dec 12 14:53:58 swapus slapd[8082]: conn=12 op=12 SRCH attr=1.1
Dec 12 14:53:58 swapus slapd[8082]: ==> limits_get: conn=12 op=12 dn="[anonymous]"
Dec 12 14:53:58 swapus slapd[8082]: => bdb_search
Dec 12 14:53:58 swapus slapd[8082]: bdb_dn2entry("ou=sso stub,ou=ecmbi,o=ibm")
Dec 12 14:53:58 swapus slapd[8082]: search_candidates: base="ou=sso stub,ou=ecmbi,o=ibm" (0x00000026) scope=2
Dec 12 14:53:58 swapus slapd[8082]: => bdb_dn2idl("ou=sso stub,ou=ecmbi,o=ibm")
Dec 12 14:53:58 swapus slapd[8082]: bdb_idl_fetch_key: @ou=sso stub,ou=ecmbi,o=ibm
Dec 12 14:53:58 swapus slapd[8082]: <= bdb_dn2idl: id=1 first=38 last=38
Dec 12 14:53:58 swapus slapd[8082]: => bdb_equality_candidates (objectClass)
Dec 12 14:53:58 swapus slapd[8082]: => key_read
Dec 12 14:53:58 swapus slapd[8082]: bdb_idl_fetch_key: [b49d1940]
Dec 12 14:53:58 swapus slapd[8082]: <= bdb_index_read: failed (-30990)
Dec 12 14:53:58 swapus slapd[8082]: <= bdb_equality_candidates: id=0, first=0, last=0
Dec 12 14:53:58 swapus slapd[8082]: => bdb_equality_candidates (notesShortName)
Dec 12 14:53:58 swapus slapd[8082]: => key_read
Dec 12 14:53:58 swapus slapd[8082]: bdb_idl_fetch_key: [f3a9c9ec]
Dec 12 14:53:58 swapus slapd[8082]: <= bdb_index_read: failed (-30990)
Dec 12 14:53:58 swapus slapd[8082]: <= bdb_equality_candidates: id=0, first=0, last=0
Dec 12 14:53:58 swapus slapd[8082]: bdb_search_candidates: id=0 first=38 last=0
Dec 12 14:53:58 swapus slapd[8082]: bdb_search: no candidates
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: conn=12 op=12 p=3
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: conn=12 op=12 p=3
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_response: msgid=13 tag=101 err=0
Dec 12 14:53:58 swapus slapd[8082]: conn=12 op=12 SEARCH RESULT tag=101 err=0 nentries=0 text=
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: conn=664 op=1 p=3
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: conn=664 op=1 p=3
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:53:58 swapus slapd[8082]: send_ldap_response: msgid=2 tag=101 err=0
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text=
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43)
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43): got connid=664
Dec 12 14:53:58 swapus slapd[8082]: connection_read(43): checking for input on id=664
Dec 12 14:53:58 swapus slapd[8082]: ber_get_next on fd 43 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:53:58 swapus slapd[8082]: do_unbind
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43)
Dec 12 14:53:58 swapus slapd[8082]: connection_get(43): got connid=664
Dec 12 14:53:58 swapus slapd[8082]: connection_read(43): checking for input on id=664
Dec 12 14:53:58 swapus slapd[8082]: ber_get_next on fd 43 failed errno=0 (Success)
Dec 12 14:53:58 swapus slapd[8082]: connection_read(43): input error=-2 id=664, closing.
Dec 12 14:53:58 swapus slapd[8082]: connection_closing: readying conn=664 sd=43 for close
Dec 12 14:53:58 swapus slapd[8082]: connection_close: deferring conn=664 sd=43
Dec 12 14:53:58 swapus slapd[8082]: conn=664 op=2 UNBIND
Dec 12 14:53:58 swapus slapd[8082]: connection_resched: attempting closing conn=664 sd=43
Dec 12 14:53:58 swapus slapd[8082]: connection_close: conn=664 sd=43
Dec 12 14:53:58 swapus slapd[8082]: =>meta_back_conn_destroy: fetching conn 664
Dec 12 14:53:58 swapus slapd[8082]: conn=664 fd=43 closed
Dec 12 14:54:02 swapus slapd[8082]: conn=665 fd=43 ACCEPT from IP=127.0.0.1:52577 (IP=0.0.0.0:636)
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43)
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43): got connid=665
Dec 12 14:54:02 swapus slapd[8082]: connection_read(43): checking for input on id=665
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43)
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43): got connid=665
Dec 12 14:54:02 swapus slapd[8082]: connection_read(43): checking for input on id=665
Dec 12 14:54:02 swapus slapd[8082]: connection_read(43): unable to get TLS client DN, error=49 id=665
Dec 12 14:54:02 swapus slapd[8082]: conn=665 fd=43 TLS established tls_ssf=256 ssf=256
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43)
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43): got connid=665
Dec 12 14:54:02 swapus slapd[8082]: connection_read(43): checking for input on id=665
Dec 12 14:54:02 swapus slapd[8082]: ber_get_next on fd 43 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:54:02 swapus slapd[8082]: do_search
Dec 12 14:54:02 swapus slapd[8082]: >>> dnPrettyNormal: <>
Dec 12 14:54:02 swapus slapd[8082]: <<< dnPrettyNormal: <>, <>
Dec 12 14:54:02 swapus slapd[8082]: SRCH "" 0 0
Dec 12 14:54:02 swapus slapd[8082]:     12 15 0
Dec 12 14:54:02 swapus slapd[8082]:     filter: (objectClass=*)
Dec 12 14:54:02 swapus slapd[8082]:     attrs:
Dec 12 14:54:02 swapus slapd[8082]:  supportedSASLMechanisms
Dec 12 14:54:02 swapus slapd[8082]:
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=0 SRCH attr=supportedSASLMechanisms
Dec 12 14:54:02 swapus slapd[8082]: => send_search_entry: conn 665 dn=""
Dec 12 14:54:02 swapus slapd[8082]: <= send_search_entry: conn 665 exit.
Dec 12 14:54:02 swapus slapd[8082]: send_ldap_result: conn=665 op=0 p=3
Dec 12 14:54:02 swapus slapd[8082]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:54:02 swapus slapd[8082]: send_ldap_response: msgid=1 tag=101 err=0
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text=
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43)
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43): got connid=665
Dec 12 14:54:02 swapus slapd[8082]: connection_read(43): checking for input on id=665
Dec 12 14:54:02 swapus slapd[8082]: ber_get_next on fd 43 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:54:02 swapus slapd[8082]: do_bind
Dec 12 14:54:02 swapus slapd[8082]: >>> dnPrettyNormal: <>
Dec 12 14:54:02 swapus slapd[8082]: <<< dnPrettyNormal: <>, <>
Dec 12 14:54:02 swapus slapd[8082]: do_sasl_bind: dn () mech GSSAPI
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=1 BIND dn="" method=163
Dec 12 14:54:02 swapus slapd[8082]: ==> sasl_bind: dn="" mech=GSSAPI datalen=527
Dec 12 14:54:02 swapus slapd[8082]: send_ldap_sasl: err=14 len=156
Dec 12 14:54:02 swapus slapd[8082]: send_ldap_response: msgid=2 tag=97 err=14
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=1 RESULT tag=97 err=14 text=
Dec 12 14:54:02 swapus slapd[8082]: <== slap_sasl_bind: rc=14
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43)
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43): got connid=665
Dec 12 14:54:02 swapus slapd[8082]: connection_read(43): checking for input on id=665
Dec 12 14:54:02 swapus slapd[8082]: ber_get_next on fd 43 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:54:02 swapus slapd[8082]: do_bind
Dec 12 14:54:02 swapus slapd[8082]: >>> dnPrettyNormal: <>
Dec 12 14:54:02 swapus slapd[8082]: <<< dnPrettyNormal: <>, <>
Dec 12 14:54:02 swapus slapd[8082]: do_sasl_bind: dn () mech GSSAPI
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=2 BIND dn="" method=163
Dec 12 14:54:02 swapus slapd[8082]: ==> sasl_bind: dn="" mech=<continuing> datalen=0
Dec 12 14:54:02 swapus slapd[8082]: send_ldap_sasl: err=14 len=32
Dec 12 14:54:02 swapus slapd[8082]: send_ldap_response: msgid=3 tag=97 err=14
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=2 RESULT tag=97 err=14 text=
Dec 12 14:54:02 swapus slapd[8082]: <== slap_sasl_bind: rc=14
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43)
Dec 12 14:54:02 swapus slapd[8082]: connection_get(43): got connid=665
Dec 12 14:54:02 swapus slapd[8082]: connection_read(43): checking for input on id=665
Dec 12 14:54:02 swapus slapd[8082]: ber_get_next on fd 43 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:54:02 swapus slapd[8082]: do_bind
Dec 12 14:54:02 swapus slapd[8082]: >>> dnPrettyNormal: <>
Dec 12 14:54:02 swapus slapd[8082]: <<< dnPrettyNormal: <>, <>
Dec 12 14:54:02 swapus slapd[8082]: do_sasl_bind: dn () mech GSSAPI
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=3 BIND dn="" method=163
Dec 12 14:54:02 swapus slapd[8082]: ==> sasl_bind: dn="" mech=<continuing> datalen=32
Dec 12 14:54:02 swapus slapd[8082]: SASL Canonicalize [conn=665]: authcid="pfnguyen"
Dec 12 14:54:02 swapus slapd[8082]: slap_sasl_getdn: conn 665 id=pfnguyen [len=8]
Dec 12 14:54:02 swapus slapd[8082]: slap_sasl_getdn: u:id converted to uid=pfnguyen,cn=GSSAPI,cn=auth
Dec 12 14:54:02 swapus slapd[8082]: >>> dnNormalize: <uid=pfnguyen,cn=GSSAPI,cn=auth>
Dec 12 14:54:02 swapus slapd[8082]: <<< dnNormalize: <uid=pfnguyen,cn=gssapi,cn=auth>
Dec 12 14:54:02 swapus slapd[8082]: ==>slap_sasl2dn: converting SASL name uid=pfnguyen,cn=gssapi,cn=auth to a DN
Dec 12 14:54:02 swapus slapd[8082]: slap_authz_regexp: converting SASL name uid=pfnguyen,cn=gssapi,cn=auth
Dec 12 14:54:02 swapus slapd[8082]: slap_authz_regexp: converted SASL name to uid=pfnguyen,ou=People,ou=ecmbi,o=ibm
Dec 12 14:54:02 swapus slapd[8082]: slap_parseURI: parsing uid=pfnguyen,ou=People,ou=ecmbi,o=ibm
Dec 12 14:54:02 swapus slapd[8082]: >>> dnNormalize: <uid=pfnguyen,ou=People,ou=ecmbi,o=ibm>
Dec 12 14:54:02 swapus slapd[8082]: <<< dnNormalize: <uid=pfnguyen,ou=people,ou=ecmbi,o=ibm>
Dec 12 14:54:02 swapus slapd[8082]: <==slap_sasl2dn: Converted SASL name to uid=pfnguyen,ou=people,ou=ecmbi,o=ibm
Dec 12 14:54:02 swapus slapd[8082]: slap_sasl_getdn: dn:id converted to uid=pfnguyen,ou=people,ou=ecmbi,o=ibm
Dec 12 14:54:02 swapus slapd[8082]: SASL Canonicalize [conn=665]: slapAuthcDN="uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"
Dec 12 14:54:02 swapus slapd[8082]: SASL proxy authorize [conn=665]: authcid="pfnguyen" authzid="pfnguyen"
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=3 BIND authcid="pfnguyen" authzid="pfnguyen"
Dec 12 14:54:02 swapus slapd[8082]: SASL Authorize [conn=665]:  proxy authorization allowed authzDN=""
Dec 12 14:54:02 swapus slapd[8082]: send_ldap_sasl: err=0 len=-1
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=3 BIND dn="uid=pfnguyen,ou=people,ou=ecmbi,o=ibm" mech=GSSAPI ssf=56
Dec 12 14:54:02 swapus slapd[8082]: do_bind: SASL/GSSAPI bind: dn="uid=pfnguyen,ou=people,ou=ecmbi,o=ibm" ssf=56
Dec 12 14:54:02 swapus slapd[8082]: send_ldap_response: msgid=4 tag=97 err=0
Dec 12 14:54:02 swapus slapd[8082]: conn=665 op=3 RESULT tag=97 err=0 text=
Dec 12 14:54:02 swapus slapd[8082]: <== slap_sasl_bind: rc=0
Dec 12 14:54:03 swapus slapd[8082]: connection_get(43)
Dec 12 14:54:03 swapus slapd[8082]: connection_get(43): got connid=665
Dec 12 14:54:03 swapus slapd[8082]: connection_read(43): checking for input on id=665
Dec 12 14:54:03 swapus slapd[8082]: ber_get_next on fd 43 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:54:03 swapus slapd[8082]: do_search
Dec 12 14:54:03 swapus slapd[8082]: >>> dnPrettyNormal: <cn=Log,cn=Monitor>
Dec 12 14:54:03 swapus slapd[8082]: <<< dnPrettyNormal: <cn=Log,cn=Monitor>, <cn=log,cn=monitor>
Dec 12 14:54:03 swapus slapd[8082]: SRCH "cn=Log,cn=Monitor" 0 0
Dec 12 14:54:03 swapus slapd[8082]:     0 15 0
Dec 12 14:54:03 swapus slapd[8082]:     filter: (objectClass=*)
Dec 12 14:54:03 swapus slapd[8082]:     attrs:
Dec 12 14:54:03 swapus slapd[8082]:
Dec 12 14:54:03 swapus slapd[8082]: conn=665 op=4 SRCH base="cn=Log,cn=Monitor" scope=0 deref=0 filter="(objectClass=*)"
Dec 12 14:54:03 swapus slapd[8082]: ==> limits_get: conn=665 op=4 dn="uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"
Dec 12 14:54:03 swapus slapd[8082]: => monitor_back_search
Dec 12 14:54:03 swapus slapd[8082]: => bdb_entry_get: ndn: "cn=directory admins,ou=groups,ou=ecmbi,o=ibm"
Dec 12 14:54:03 swapus slapd[8082]: => bdb_entry_get: oc: "groupOfNames", at: "member"
Dec 12 14:54:03 swapus slapd[8082]: bdb_dn2entry("cn=directory admins,ou=groups,ou=ecmbi,o=ibm")
Dec 12 14:54:03 swapus slapd[8082]: bdb_entry_get: rc=0
Dec 12 14:54:03 swapus slapd[8082]: dnMatch 0   "uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"         "uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"
Dec 12 14:54:03 swapus slapd[8082]: => send_search_entry: conn 665 dn="cn=Log,cn=Monitor"
Dec 12 14:54:03 swapus slapd[8082]: <= send_search_entry: conn 665 exit.
Dec 12 14:54:03 swapus slapd[8082]: send_ldap_result: conn=665 op=4 p=3
Dec 12 14:54:03 swapus slapd[8082]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:54:03 swapus slapd[8082]: send_ldap_response: msgid=5 tag=101 err=0
Dec 12 14:54:03 swapus slapd[8082]: conn=665 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text=
Dec 12 14:54:07 swapus slapd[8082]: connection_get(43)
Dec 12 14:54:07 swapus slapd[8082]: connection_get(43): got connid=665
Dec 12 14:54:07 swapus slapd[8082]: connection_read(43): checking for input on id=665
Dec 12 14:54:07 swapus slapd[8082]: ber_get_next on fd 43 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:54:07 swapus slapd[8082]: do_modify
Dec 12 14:54:07 swapus slapd[8082]: do_modify: dn (cn=Log,cn=Monitor)
Dec 12 14:54:07 swapus slapd[8082]: >>> dnPrettyNormal: <cn=Log,cn=Monitor>
Dec 12 14:54:07 swapus slapd[8082]: <<< dnPrettyNormal: <cn=Log,cn=Monitor>, <cn=log,cn=monitor>
Dec 12 14:54:07 swapus slapd[8082]: modifications:
Dec 12 14:54:07 swapus slapd[8082]:     delete: managedInfo
Dec 12 14:54:07 swapus slapd[8082]:             one value, length 4
Dec 12 14:54:07 swapus slapd[8082]:     delete: managedInfo
Dec 12 14:54:07 swapus slapd[8082]:             one value, length 5
Dec 12 14:54:07 swapus slapd[8082]: conn=665 op=5 MOD dn="cn=Log,cn=Monitor"
Dec 12 14:54:07 swapus slapd[8082]: conn=665 op=5 MOD attr=managedInfo managedInfo
Dec 12 14:54:07 swapus slapd[8082]: monitor_back_modify:
Dec 12 14:54:07 swapus slapd[8082]: => bdb_entry_get: ndn: "cn=directory admins,ou=groups,ou=ecmbi,o=ibm"
Dec 12 14:54:07 swapus slapd[8082]: => bdb_entry_get: oc: "groupOfNames", at: "member"
Dec 12 14:54:07 swapus slapd[8082]: bdb_dn2entry("cn=directory admins,ou=groups,ou=ecmbi,o=ibm")
Dec 12 14:54:07 swapus slapd[8082]: bdb_entry_get: rc=0
Dec 12 14:54:07 swapus slapd[8082]: dnMatch 0   "uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"         "uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_required entry (cn=Log,cn=Monitor), objectClass "monitorContainer"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "objectClass"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "structuralObjectClass"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "cn"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "creatorsName"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "createTimestamp"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "description"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "managedInfo"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "entryCSN"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "modifiersName"
Dec 12 14:54:07 swapus slapd[8082]: oc_check_allowed type "modifyTimestamp"
Dec 12 14:54:07 swapus slapd[8082]: conn=665 op=5 RESULT tag=103 err=0 text=
Dec 12 14:54:07 swapus slapd[8082]: conn=665 fd=43 closed (connection lost)

###
### Args, Trace, Stats log of meta lookup that succeeds
###
Dec 12 14:56:12 swapus slapd[3264]: conn=2 op=5 MOD dn="cn=Log,cn=Monitor"
Dec 12 14:56:12 swapus slapd[3264]: conn=2 op=5 MOD attr=managedInfo
Dec 12 14:56:12 swapus slapd[3264]: send_ldap_result: conn=2 op=5 p=3
Dec 12 14:56:12 swapus slapd[3264]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:56:12 swapus slapd[3264]: send_ldap_response: msgid=6 tag=103 err=0
Dec 12 14:56:12 swapus slapd[3264]: conn=2 op=5 RESULT tag=103 err=0 text=
Dec 12 14:56:12 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:12 swapus slapd[3264]: connection_get(15): got connid=2
Dec 12 14:56:12 swapus slapd[3264]: connection_read(15): checking for input on id=2
Dec 12 14:56:12 swapus slapd[3264]: ber_get_next on fd 15 failed errno=0 (Success)
Dec 12 14:56:12 swapus slapd[3264]: connection_read(15): input error=-2 id=2, closing.
Dec 12 14:56:12 swapus slapd[3264]: connection_closing: readying conn=2 sd=15 for close
Dec 12 14:56:12 swapus slapd[3264]: connection_close: conn=2 sd=15
Dec 12 14:56:12 swapus slapd[3264]: =>meta_back_conn_destroy: fetching conn 2
Dec 12 14:56:12 swapus slapd[3264]: conn=2 fd=15 closed (connection lost)
Dec 12 14:56:13 swapus slapd[3264]: conn=3 fd=15 ACCEPT from IP=127.0.0.1:36277 (IP=0.0.0.0:636)
Dec 12 14:56:13 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:13 swapus slapd[3264]: connection_get(15): got connid=3
Dec 12 14:56:13 swapus slapd[3264]: connection_read(15): checking for input on id=3
Dec 12 14:56:13 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:13 swapus slapd[3264]: connection_get(15): got connid=3
Dec 12 14:56:13 swapus slapd[3264]: connection_read(15): checking for input on id=3
Dec 12 14:56:13 swapus slapd[3264]: connection_read(15): unable to get TLS client DN, error=49 id=3
Dec 12 14:56:13 swapus slapd[3264]: conn=3 fd=15 TLS established tls_ssf=256 ssf=256
Dec 12 14:56:13 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:13 swapus slapd[3264]: connection_get(15): got connid=3
Dec 12 14:56:13 swapus slapd[3264]: connection_read(15): checking for input on id=3
Dec 12 14:56:13 swapus slapd[3264]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:13 swapus slapd[3264]: do_bind
Dec 12 14:56:13 swapus slapd[3264]: >>> dnPrettyNormal: <>
Dec 12 14:56:13 swapus slapd[3264]: <<< dnPrettyNormal: <>, <>
Dec 12 14:56:13 swapus slapd[3264]: do_bind: version=3 dn="" method=128
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=0 BIND dn="" method=128
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_result: conn=3 op=0 p=3
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_response: msgid=1 tag=97 err=0
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=0 RESULT tag=97 err=0 text=
Dec 12 14:56:13 swapus slapd[3264]: do_bind: v3 anonymous bind
Dec 12 14:56:13 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:13 swapus slapd[3264]: connection_get(15): got connid=3
Dec 12 14:56:13 swapus slapd[3264]: connection_read(15): checking for input on id=3
Dec 12 14:56:13 swapus slapd[3264]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:13 swapus slapd[3264]: do_search
Dec 12 14:56:13 swapus slapd[3264]: >>> dnPrettyNormal: <ou=ecmbi,o=ibm>
Dec 12 14:56:13 swapus slapd[3264]: <<< dnPrettyNormal: <ou=ecmbi,o=ibm>, <ou=ecmbi,o=ibm>
Dec 12 14:56:13 swapus slapd[3264]: SRCH "ou=ecmbi,o=ibm" 2 0
Dec 12 14:56:13 swapus slapd[3264]:     12 15 0
Dec 12 14:56:13 swapus slapd[3264]:     filter: (notesShortName=pfnguyen)
Dec 12 14:56:13 swapus slapd[3264]:     attrs:
Dec 12 14:56:13 swapus slapd[3264]:  1.1
Dec 12 14:56:13 swapus slapd[3264]:
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=1 SRCH base="ou=ecmbi,o=ibm" scope=2 deref=0 filter="(notesShortName=pfnguyen)"
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=1 SRCH attr=1.1
Dec 12 14:56:13 swapus slapd[3264]: ==> limits_get: conn=3 op=1 dn="[anonymous]"
Dec 12 14:56:13 swapus slapd[3264]: => bdb_search
Dec 12 14:56:13 swapus slapd[3264]: bdb_dn2entry("ou=ecmbi,o=ibm")
Dec 12 14:56:13 swapus slapd[3264]: search_candidates: base="ou=ecmbi,o=ibm" (0x00000001) scope=2
Dec 12 14:56:13 swapus slapd[3264]: => bdb_dn2idl("ou=ecmbi,o=ibm")
Dec 12 14:56:13 swapus slapd[3264]: => bdb_equality_candidates (objectClass)
Dec 12 14:56:13 swapus slapd[3264]: => key_read
Dec 12 14:56:13 swapus slapd[3264]: bdb_idl_fetch_key: [b49d1940]
Dec 12 14:56:13 swapus slapd[3264]: <= bdb_index_read: failed (-30990)
Dec 12 14:56:13 swapus slapd[3264]: <= bdb_equality_candidates: id=0, first=0, last=0
Dec 12 14:56:13 swapus slapd[3264]: => bdb_equality_candidates (notesShortName)
Dec 12 14:56:13 swapus slapd[3264]: => key_read
Dec 12 14:56:13 swapus slapd[3264]: bdb_idl_fetch_key: [f3a9c9ec]
Dec 12 14:56:13 swapus slapd[3264]: <= bdb_index_read: failed (-30990)
Dec 12 14:56:13 swapus slapd[3264]: <= bdb_equality_candidates: id=0, first=0, last=0
Dec 12 14:56:13 swapus slapd[3264]: bdb_search_candidates: id=0 first=1 last=0
Dec 12 14:56:13 swapus slapd[3264]: bdb_search: no candidates
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_result: conn=3 op=1 p=3
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=1: meta_back_init_one_conn(0)
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=1: meta_back_init_one_conn(1)
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=1: meta_back_init_one_conn(2)
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=1 meta_back_getconn: candidates=3 conn=-1 fetched
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=1 meta_back_dobind: conn=-1
Dec 12 14:56:13 swapus slapd[3264]: conn=3 op=1 meta_back_dobind: conn=-1 bound=3
Dec 12 14:56:13 swapus slapd[3264]: [rw] searchBase: "c=us,ou=sso,ou=ecmbi,o=ibm" -> "c=us,ou=bluepages,o=ibm.com"
Dec 12 14:56:13 swapus slapd[3264]: [rw] searchBase: "c=cn,ou=sso,ou=ecmbi,o=ibm" -> "c=cn,ou=bluepages,o=ibm.com"
Dec 12 14:56:13 swapus slapd[3264]: [rw] searchBase: "ou=sso,ou=ecmbi,o=ibm" -> "ou=SSO Stub,ou=ecmbi,o=ibm"
Dec 12 14:56:13 swapus slapd[3264]: connection_get(21)
Dec 12 14:56:13 swapus slapd[3264]: connection_get(21): got connid=1
Dec 12 14:56:13 swapus slapd[3264]: connection_read(21): checking for input on id=1
Dec 12 14:56:13 swapus slapd[3264]: ber_get_next on fd 21 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:13 swapus slapd[3264]: do_search
Dec 12 14:56:13 swapus slapd[3264]: >>> dnPrettyNormal: <ou=SSO Stub,ou=ecmbi,o=ibm>
Dec 12 14:56:13 swapus slapd[3264]: <<< dnPrettyNormal: <ou=SSO Stub,ou=ecmbi,o=ibm>, <ou=sso stub,ou=ecmbi,o=ibm>
Dec 12 14:56:13 swapus slapd[3264]: SRCH "ou=SSO Stub,ou=ecmbi,o=ibm" 2 0
Dec 12 14:56:13 swapus slapd[3264]:     12 15 0
Dec 12 14:56:13 swapus slapd[3264]:     filter: (notesShortName=pfnguyen)
Dec 12 14:56:13 swapus slapd[3264]:     attrs:
Dec 12 14:56:13 swapus slapd[3264]:  1.1
Dec 12 14:56:13 swapus slapd[3264]:
Dec 12 14:56:13 swapus slapd[3264]: conn=1 op=2 SRCH base="ou=SSO Stub,ou=ecmbi,o=ibm" scope=2 deref=0 filter="(notesShortName=pfnguyen)"
Dec 12 14:56:13 swapus slapd[3264]: conn=1 op=2 SRCH attr=1.1
Dec 12 14:56:13 swapus slapd[3264]: ==> limits_get: conn=1 op=2 dn="[anonymous]"
Dec 12 14:56:13 swapus slapd[3264]: => bdb_search
Dec 12 14:56:13 swapus slapd[3264]: bdb_dn2entry("ou=sso stub,ou=ecmbi,o=ibm")
Dec 12 14:56:13 swapus slapd[3264]: search_candidates: base="ou=sso stub,ou=ecmbi,o=ibm" (0x00000026) scope=2
Dec 12 14:56:13 swapus slapd[3264]: => bdb_dn2idl("ou=sso stub,ou=ecmbi,o=ibm")
Dec 12 14:56:13 swapus slapd[3264]: bdb_idl_fetch_key: @ou=sso stub,ou=ecmbi,o=ibm
Dec 12 14:56:13 swapus slapd[3264]: <= bdb_dn2idl: id=1 first=38 last=38
Dec 12 14:56:13 swapus slapd[3264]: => bdb_equality_candidates (objectClass)
Dec 12 14:56:13 swapus slapd[3264]: => key_read
Dec 12 14:56:13 swapus slapd[3264]: bdb_idl_fetch_key: [b49d1940]
Dec 12 14:56:13 swapus slapd[3264]: <= bdb_index_read: failed (-30990)
Dec 12 14:56:13 swapus slapd[3264]: <= bdb_equality_candidates: id=0, first=0, last=0
Dec 12 14:56:13 swapus slapd[3264]: => bdb_equality_candidates (notesShortName)
Dec 12 14:56:13 swapus slapd[3264]: => key_read
Dec 12 14:56:13 swapus slapd[3264]: bdb_idl_fetch_key: [f3a9c9ec]
Dec 12 14:56:13 swapus slapd[3264]: <= bdb_index_read: failed (-30990)
Dec 12 14:56:13 swapus slapd[3264]: <= bdb_equality_candidates: id=0, first=0, last=0
Dec 12 14:56:13 swapus slapd[3264]: bdb_search_candidates: id=0 first=38 last=0
Dec 12 14:56:13 swapus slapd[3264]: bdb_search: no candidates
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_result: conn=1 op=2 p=3
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_result: conn=1 op=2 p=3
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:56:13 swapus slapd[3264]: send_ldap_response: msgid=3 tag=101 err=0
Dec 12 14:56:13 swapus slapd[3264]: conn=1 op=2 SEARCH RESULT tag=101 err=0 nentries=0 text=
Dec 12 14:56:14 swapus slapd[3264]: [rw] searchResult: "uid=828197897,c=us,ou=bluepages,o=ibm.com" -> "uid=828197897,c=us,ou=sso,ou=ecmbi,o=ibm"
Dec 12 14:56:14 swapus slapd[3264]: >>> dnPrettyNormal: <uid=828197897,c=us,ou=sso,ou=ecmbi,o=ibm>
Dec 12 14:56:14 swapus slapd[3264]: <<< dnPrettyNormal: <uid=828197897,c=us,ou=sso,ou=ecmbi,o=ibm>, <uid=828197897,c=us,ou=sso,ou=ecmbi,o=ibm>
Dec 12 14:56:14 swapus slapd[3264]: => send_search_entry: conn 3 dn="uid=828197897,c=us,ou=sso,ou=ecmbi,o=ibm"
Dec 12 14:56:14 swapus slapd[3264]: <= send_search_entry: conn 3 exit.
Dec 12 14:56:14 swapus slapd[3264]: send_ldap_result: conn=3 op=1 p=3
Dec 12 14:56:14 swapus slapd[3264]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:56:14 swapus slapd[3264]: send_ldap_result: conn=3 op=1 p=3
Dec 12 14:56:14 swapus slapd[3264]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:56:14 swapus slapd[3264]: send_ldap_response: msgid=2 tag=101 err=0
Dec 12 14:56:14 swapus slapd[3264]: conn=3 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Dec 12 14:56:14 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:14 swapus slapd[3264]: connection_get(15): got connid=3
Dec 12 14:56:14 swapus slapd[3264]: connection_read(15): checking for input on id=3
Dec 12 14:56:14 swapus slapd[3264]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:14 swapus slapd[3264]: do_unbind
Dec 12 14:56:14 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:14 swapus slapd[3264]: connection_get(15): got connid=3
Dec 12 14:56:14 swapus slapd[3264]: connection_read(15): checking for input on id=3
Dec 12 14:56:14 swapus slapd[3264]: ber_get_next on fd 15 failed errno=0 (Success)
Dec 12 14:56:14 swapus slapd[3264]: connection_read(15): input error=-2 id=3, closing.
Dec 12 14:56:14 swapus slapd[3264]: connection_closing: readying conn=3 sd=15 for close
Dec 12 14:56:14 swapus slapd[3264]: connection_close: deferring conn=3 sd=15
Dec 12 14:56:14 swapus slapd[3264]: conn=3 op=2 UNBIND
Dec 12 14:56:14 swapus slapd[3264]: connection_resched: attempting closing conn=3 sd=15
Dec 12 14:56:14 swapus slapd[3264]: connection_close: conn=3 sd=15
Dec 12 14:56:14 swapus slapd[3264]: =>meta_back_conn_destroy: fetching conn 3
Dec 12 14:56:14 swapus slapd[3264]: conn=3 fd=15 closed
Dec 12 14:56:15 swapus slapd[3264]: conn=4 fd=15 ACCEPT from IP=127.0.0.1:36278 (IP=0.0.0.0:636)
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15): got connid=4
Dec 12 14:56:15 swapus slapd[3264]: connection_read(15): checking for input on id=4
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15): got connid=4
Dec 12 14:56:15 swapus slapd[3264]: connection_read(15): checking for input on id=4
Dec 12 14:56:15 swapus slapd[3264]: connection_read(15): unable to get TLS client DN, error=49 id=4
Dec 12 14:56:15 swapus slapd[3264]: conn=4 fd=15 TLS established tls_ssf=256 ssf=256
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15): got connid=4
Dec 12 14:56:15 swapus slapd[3264]: connection_read(15): checking for input on id=4
Dec 12 14:56:15 swapus slapd[3264]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:15 swapus slapd[3264]: do_search
Dec 12 14:56:15 swapus slapd[3264]: >>> dnPrettyNormal: <>
Dec 12 14:56:15 swapus slapd[3264]: <<< dnPrettyNormal: <>, <>
Dec 12 14:56:15 swapus slapd[3264]: SRCH "" 0 0
Dec 12 14:56:15 swapus slapd[3264]:     12 15 0
Dec 12 14:56:15 swapus slapd[3264]:     filter: (objectClass=*)
Dec 12 14:56:15 swapus slapd[3264]:     attrs:
Dec 12 14:56:15 swapus slapd[3264]:  supportedSASLMechanisms
Dec 12 14:56:15 swapus slapd[3264]:
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=0 SRCH attr=supportedSASLMechanisms
Dec 12 14:56:15 swapus slapd[3264]: => send_search_entry: conn 4 dn=""
Dec 12 14:56:15 swapus slapd[3264]: <= send_search_entry: conn 4 exit.
Dec 12 14:56:15 swapus slapd[3264]: send_ldap_result: conn=4 op=0 p=3
Dec 12 14:56:15 swapus slapd[3264]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:56:15 swapus slapd[3264]: send_ldap_response: msgid=1 tag=101 err=0
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text=
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15): got connid=4
Dec 12 14:56:15 swapus slapd[3264]: connection_read(15): checking for input on id=4
Dec 12 14:56:15 swapus slapd[3264]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:15 swapus slapd[3264]: do_bind
Dec 12 14:56:15 swapus slapd[3264]: >>> dnPrettyNormal: <>
Dec 12 14:56:15 swapus slapd[3264]: <<< dnPrettyNormal: <>, <>
Dec 12 14:56:15 swapus slapd[3264]: do_sasl_bind: dn () mech GSSAPI
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=1 BIND dn="" method=163
Dec 12 14:56:15 swapus slapd[3264]: ==> sasl_bind: dn="" mech=GSSAPI datalen=527
Dec 12 14:56:15 swapus slapd[3264]: send_ldap_sasl: err=14 len=156
Dec 12 14:56:15 swapus slapd[3264]: send_ldap_response: msgid=2 tag=97 err=14
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15): got connid=4
Dec 12 14:56:15 swapus slapd[3264]: connection_read(15): checking for input on id=4
Dec 12 14:56:15 swapus slapd[3264]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:15 swapus slapd[3264]: do_bind
Dec 12 14:56:15 swapus slapd[3264]: >>> dnPrettyNormal: <>
Dec 12 14:56:15 swapus slapd[3264]: <<< dnPrettyNormal: <>, <>
Dec 12 14:56:15 swapus slapd[3264]: do_sasl_bind: dn () mech GSSAPI
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=2 BIND dn="" method=163
Dec 12 14:56:15 swapus slapd[3264]: ==> sasl_bind: dn="" mech=<continuing> datalen=0
Dec 12 14:56:15 swapus slapd[3264]: send_ldap_sasl: err=14 len=32
Dec 12 14:56:15 swapus slapd[3264]: send_ldap_response: msgid=3 tag=97 err=14
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=1 RESULT tag=97 err=14 text=
Dec 12 14:56:15 swapus slapd[3264]: <== slap_sasl_bind: rc=14
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:15 swapus slapd[3264]: connection_get(15): got connid=4
Dec 12 14:56:15 swapus slapd[3264]: connection_read(15): checking for input on id=4
Dec 12 14:56:15 swapus slapd[3264]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:15 swapus slapd[3264]: do_bind
Dec 12 14:56:15 swapus slapd[3264]: >>> dnPrettyNormal: <>
Dec 12 14:56:15 swapus slapd[3264]: <<< dnPrettyNormal: <>, <>
Dec 12 14:56:15 swapus slapd[3264]: do_sasl_bind: dn () mech GSSAPI
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=3 BIND dn="" method=163
Dec 12 14:56:15 swapus slapd[3264]: ==> sasl_bind: dn="" mech=<continuing> datalen=32
Dec 12 14:56:15 swapus slapd[3264]: SASL Canonicalize [conn=4]: authcid="pfnguyen"
Dec 12 14:56:15 swapus slapd[3264]: slap_sasl_getdn: conn 4 id=pfnguyen [len=8]
Dec 12 14:56:15 swapus slapd[3264]: slap_sasl_getdn: u:id converted to uid=pfnguyen,cn=GSSAPI,cn=auth
Dec 12 14:56:15 swapus slapd[3264]: >>> dnNormalize: <uid=pfnguyen,cn=GSSAPI,cn=auth>
Dec 12 14:56:15 swapus slapd[3264]: <<< dnNormalize: <uid=pfnguyen,cn=gssapi,cn=auth>
Dec 12 14:56:15 swapus slapd[3264]: ==>slap_sasl2dn: converting SASL name uid=pfnguyen,cn=gssapi,cn=auth to a DN
Dec 12 14:56:15 swapus slapd[3264]: slap_authz_regexp: converting SASL name uid=pfnguyen,cn=gssapi,cn=auth
Dec 12 14:56:15 swapus slapd[3264]: slap_authz_regexp: converted SASL name to uid=pfnguyen,ou=People,ou=ecmbi,o=ibm
Dec 12 14:56:15 swapus slapd[3264]: slap_parseURI: parsing uid=pfnguyen,ou=People,ou=ecmbi,o=ibm
Dec 12 14:56:15 swapus slapd[3264]: >>> dnNormalize: <uid=pfnguyen,ou=People,ou=ecmbi,o=ibm>
Dec 12 14:56:15 swapus slapd[3264]: <<< dnNormalize: <uid=pfnguyen,ou=people,ou=ecmbi,o=ibm>
Dec 12 14:56:15 swapus slapd[3264]: <==slap_sasl2dn: Converted SASL name to uid=pfnguyen,ou=people,ou=ecmbi,o=ibm
Dec 12 14:56:15 swapus slapd[3264]: slap_sasl_getdn: dn:id converted to uid=pfnguyen,ou=people,ou=ecmbi,o=ibm
Dec 12 14:56:15 swapus slapd[3264]: SASL Canonicalize [conn=4]: slapAuthcDN="uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"
Dec 12 14:56:15 swapus slapd[3264]: SASL proxy authorize [conn=4]: authcid="pfnguyen" authzid="pfnguyen"
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=3 BIND authcid="pfnguyen" authzid="pfnguyen"
Dec 12 14:56:15 swapus slapd[3264]: SASL Authorize [conn=4]:  proxy authorization allowed authzDN=""
Dec 12 14:56:15 swapus slapd[3264]: send_ldap_sasl: err=0 len=-1
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=3 BIND dn="uid=pfnguyen,ou=people,ou=ecmbi,o=ibm" mech=GSSAPI ssf=56
Dec 12 14:56:15 swapus slapd[3264]: do_bind: SASL/GSSAPI bind: dn="uid=pfnguyen,ou=people,ou=ecmbi,o=ibm" ssf=56
Dec 12 14:56:15 swapus slapd[3264]: send_ldap_response: msgid=4 tag=97 err=0
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=3 RESULT tag=97 err=0 text=
Dec 12 14:56:15 swapus slapd[3264]: <== slap_sasl_bind: rc=0
Dec 12 14:56:15 swapus slapd[3264]: conn=4 op=2 RESULT tag=97 err=14 text=
Dec 12 14:56:15 swapus slapd[3264]: <== slap_sasl_bind: rc=14
Dec 12 14:56:16 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:16 swapus slapd[3264]: connection_get(15): got connid=4
Dec 12 14:56:16 swapus slapd[3264]: connection_read(15): checking for input on id=4
Dec 12 14:56:16 swapus slapd[3264]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:16 swapus slapd[3264]: do_search
Dec 12 14:56:16 swapus slapd[3264]: >>> dnPrettyNormal: <cn=Log,cn=Monitor>
Dec 12 14:56:16 swapus slapd[3264]: <<< dnPrettyNormal: <cn=Log,cn=Monitor>, <cn=log,cn=monitor>
Dec 12 14:56:16 swapus slapd[3264]: SRCH "cn=Log,cn=Monitor" 0 0
Dec 12 14:56:16 swapus slapd[3264]:     0 15 0
Dec 12 14:56:16 swapus slapd[3264]:     filter: (objectClass=*)
Dec 12 14:56:16 swapus slapd[3264]:     attrs:
Dec 12 14:56:16 swapus slapd[3264]:
Dec 12 14:56:16 swapus slapd[3264]: conn=4 op=4 SRCH base="cn=Log,cn=Monitor" scope=0 deref=0 filter="(objectClass=*)"
Dec 12 14:56:16 swapus slapd[3264]: ==> limits_get: conn=4 op=4 dn="uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"
Dec 12 14:56:16 swapus slapd[3264]: => monitor_back_search
Dec 12 14:56:16 swapus slapd[3264]: => bdb_entry_get: ndn: "cn=directory admins,ou=groups,ou=ecmbi,o=ibm"
Dec 12 14:56:16 swapus slapd[3264]: => bdb_entry_get: oc: "groupOfNames", at: "member"
Dec 12 14:56:16 swapus slapd[3264]: bdb_dn2entry("cn=directory admins,ou=groups,ou=ecmbi,o=ibm")
Dec 12 14:56:16 swapus slapd[3264]: bdb_entry_get: rc=0
Dec 12 14:56:16 swapus slapd[3264]: dnMatch 0   "uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"         "uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"
Dec 12 14:56:16 swapus slapd[3264]: => send_search_entry: conn 4 dn="cn=Log,cn=Monitor"
Dec 12 14:56:16 swapus slapd[3264]: <= send_search_entry: conn 4 exit.
Dec 12 14:56:16 swapus slapd[3264]: send_ldap_result: conn=4 op=4 p=3
Dec 12 14:56:16 swapus slapd[3264]: send_ldap_result: err=0 matched="" text=""
Dec 12 14:56:16 swapus slapd[3264]: send_ldap_response: msgid=5 tag=101 err=0
Dec 12 14:56:16 swapus slapd[3264]: conn=4 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text=
Dec 12 14:56:19 swapus slapd[3264]: connection_get(15)
Dec 12 14:56:19 swapus slapd[3264]: connection_get(15): got connid=4
Dec 12 14:56:19 swapus slapd[3264]: connection_read(15): checking for input on id=4
Dec 12 14:56:19 swapus slapd[3264]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
Dec 12 14:56:19 swapus slapd[3264]: do_modify
Dec 12 14:56:19 swapus slapd[3264]: do_modify: dn (cn=Log,cn=Monitor)
Dec 12 14:56:19 swapus slapd[3264]: >>> dnPrettyNormal: <cn=Log,cn=Monitor>
Dec 12 14:56:19 swapus slapd[3264]: <<< dnPrettyNormal: <cn=Log,cn=Monitor>, <cn=log,cn=monitor>
Dec 12 14:56:19 swapus slapd[3264]: modifications:
Dec 12 14:56:19 swapus slapd[3264]:     delete: managedInfo
Dec 12 14:56:19 swapus slapd[3264]:             one value, length 4
Dec 12 14:56:19 swapus slapd[3264]:     delete: managedInfo
Dec 12 14:56:19 swapus slapd[3264]:             one value, length 5
Dec 12 14:56:19 swapus slapd[3264]: conn=4 op=5 MOD dn="cn=Log,cn=Monitor"
Dec 12 14:56:19 swapus slapd[3264]: conn=4 op=5 MOD attr=managedInfo managedInfo
Dec 12 14:56:19 swapus slapd[3264]: monitor_back_modify:
Dec 12 14:56:19 swapus slapd[3264]: => bdb_entry_get: ndn: "cn=directory admins,ou=groups,ou=ecmbi,o=ibm"
Dec 12 14:56:19 swapus slapd[3264]: => bdb_entry_get: oc: "groupOfNames", at: "member"
Dec 12 14:56:19 swapus slapd[3264]: bdb_dn2entry("cn=directory admins,ou=groups,ou=ecmbi,o=ibm")
Dec 12 14:56:19 swapus slapd[3264]: bdb_entry_get: rc=0
Dec 12 14:56:19 swapus slapd[3264]: dnMatch 0   "uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"         "uid=pfnguyen,ou=people,ou=ecmbi,o=ibm"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_required entry (cn=Log,cn=Monitor), objectClass "monitorContainer"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "objectClass"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "structuralObjectClass"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "cn"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "creatorsName"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "createTimestamp"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "description"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "managedInfo"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "entryCSN"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "modifiersName"
Dec 12 14:56:19 swapus slapd[3264]: oc_check_allowed type "modifyTimestamp"
Dec 12 14:56:19 swapus slapd[3264]: conn=4 op=5 RESULT tag=103 err=0 text=
Dec 12 14:56:19 swapus slapd[3264]: conn=4 fd=15 closed (connection lost)