Доброго всем дня. Второй месяц бьюсь с openldap. Изначально ставил на Windows, но из-за отсутствия sasl библиотек бросил это дело. Сейчас использую Linux Red Hat. Собственно по сабжу. На сервере развернут openldap, настроена аутентификация SASL/DIGEST-MD5. Через терминал команды ldapsearch/ldapmodify работают на ура, но при попытке авторизации с той же Windows 7 с помощью LdapAdmin вылазит ошибка:
неправильные учетные данные: SASL(-13): authentification failure: realm changed: authentication aborted
Jul 7 09:28:00 localhost slapd[24176]: slap_listener_activate(7):
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=7 busy
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: >>> slap_listener(ldap:///)
Jul 7 09:28:00 localhost slapd[24176]: daemon: listen=7, new connection on 20
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on:
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: added 20r (active) listener=(nil)
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 fd=20 ACCEPT from IP=10.0.1.116:50547 (IP=0.0.0.0:389)
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on 2 descriptors
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on:
Jul 7 09:28:00 localhost slapd[24176]: 20r
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: daemon: read active on 20
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: connection_get(20)
Jul 7 09:28:00 localhost slapd[24176]: connection_get(20): got connid=1542
Jul 7 09:28:00 localhost slapd[24176]: connection_read(20): checking for input on id=1542
Jul 7 09:28:00 localhost slapd[24176]: op tag 0x63, time 1467869280
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=0 do_search
Jul 7 09:28:00 localhost slapd[24176]: >>> dnPrettyNormal: <>
Jul 7 09:28:00 localhost slapd[24176]: <<< dnPrettyNormal: <>, <>
Jul 7 09:28:00 localhost slapd[24176]: SRCH "" 0 0
Jul 7 09:28:00 localhost slapd[24176]: 0 120 0
Jul 7 09:28:00 localhost slapd[24176]: begin get_filter
Jul 7 09:28:00 localhost slapd[24176]: PRESENT
Jul 7 09:28:00 localhost slapd[24176]: end get_filter 0
Jul 7 09:28:00 localhost slapd[24176]: filter: (objectClass=*)
Jul 7 09:28:00 localhost slapd[24176]: attrs:
Jul 7 09:28:00 localhost slapd[24176]: supportedCapabilities
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=0 SRCH attr=supportedCapabilities
Jul 7 09:28:00 localhost slapd[24176]: => test_filter
Jul 7 09:28:00 localhost slapd[24176]: PRESENT
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: search access to "" "objectClass" requested
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on:
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: => slap_access_allowed: backend default search access granted to "(anonymous)"
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: search access granted by read(=rscxd)
Jul 7 09:28:00 localhost slapd[24176]: <= test_filter 6
Jul 7 09:28:00 localhost slapd[24176]: => send_search_entry: conn 1542 dn=""
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: read access to "" "entry" requested
Jul 7 09:28:00 localhost slapd[24176]: => slap_access_allowed: backend default read access granted to "(anonymous)"
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: read access granted by read(=rscxd)
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=0 ENTRY dn=""
Jul 7 09:28:00 localhost slapd[24176]: <= send_search_entry: conn 1542 exit.
Jul 7 09:28:00 localhost slapd[24176]: send_ldap_result: conn=1542 op=0 p=3
Jul 7 09:28:00 localhost slapd[24176]: send_ldap_result: err=0 matched="" text=""
Jul 7 09:28:00 localhost slapd[24176]: send_ldap_response: msgid=86 tag=101 err=0
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on:
Jul 7 09:28:00 localhost slapd[24176]: 20r
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: daemon: read active on 20
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: connection_get(20)
Jul 7 09:28:00 localhost slapd[24176]: connection_get(20): got connid=1542
Jul 7 09:28:00 localhost slapd[24176]: connection_read(20): checking for input on id=1542
Jul 7 09:28:00 localhost slapd[24176]: op tag 0x63, time 1467869280
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=1 do_search
Jul 7 09:28:00 localhost slapd[24176]: >>> dnPrettyNormal: <>
Jul 7 09:28:00 localhost slapd[24176]: <<< dnPrettyNormal: <>, <>
Jul 7 09:28:00 localhost slapd[24176]: SRCH "" 0 0
Jul 7 09:28:00 localhost slapd[24176]: 0 120 0
Jul 7 09:28:00 localhost slapd[24176]: begin get_filter
Jul 7 09:28:00 localhost slapd[24176]: PRESENT
Jul 7 09:28:00 localhost slapd[24176]: end get_filter 0
Jul 7 09:28:00 localhost slapd[24176]: filter: (objectClass=*)
Jul 7 09:28:00 localhost slapd[24176]: attrs:
Jul 7 09:28:00 localhost slapd[24176]: supportedSASLMechanisms
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=1 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=1 SRCH attr=supportedSASLMechanisms
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:28:00 localhost slapd[24176]: => test_filter
Jul 7 09:28:00 localhost slapd[24176]: PRESENT
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: search access to "" "objectClass" requested
Jul 7 09:28:00 localhost slapd[24176]: => slap_access_allowed: backend default search access granted to "(anonymous)"
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: search access granted by read(=rscxd)
Jul 7 09:28:00 localhost slapd[24176]: <= test_filter 6
Jul 7 09:28:00 localhost slapd[24176]: => send_search_entry: conn 1542 dn=""
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: read access to "" "entry" requested
Jul 7 09:28:00 localhost slapd[24176]: => slap_access_allowed: backend default read access granted to "(anonymous)"
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: read access granted by read(=rscxd)
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on:
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: result not in cache (supportedSASLMechanisms)
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: read access to "" "supportedSASLMechanisms" requested
Jul 7 09:28:00 localhost slapd[24176]: => slap_access_allowed: backend default read access granted to "(anonymous)"
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: read access granted by read(=rscxd)
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: result was in cache (supportedSASLMechanisms)
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: result was in cache (supportedSASLMechanisms)
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=1 ENTRY dn=""
Jul 7 09:28:00 localhost slapd[24176]: <= send_search_entry: conn 1542 exit.
Jul 7 09:28:00 localhost slapd[24176]: send_ldap_result: conn=1542 op=1 p=3
Jul 7 09:28:00 localhost slapd[24176]: send_ldap_result: err=0 matched="" text=""
Jul 7 09:28:00 localhost slapd[24176]: send_ldap_response: msgid=87 tag=101 err=0
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on:
Jul 7 09:28:00 localhost slapd[24176]: 20r
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: daemon: read active on 20
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: connection_get(20)
Jul 7 09:28:00 localhost slapd[24176]: connection_get(20): got connid=1542
Jul 7 09:28:00 localhost slapd[24176]: connection_read(20): checking for input on id=1542
Jul 7 09:28:00 localhost slapd[24176]: op tag 0x63, time 1467869280
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=2 do_search
Jul 7 09:28:00 localhost slapd[24176]: >>> dnPrettyNormal: <>
Jul 7 09:28:00 localhost slapd[24176]: <<< dnPrettyNormal: <>, <>
Jul 7 09:28:00 localhost slapd[24176]: SRCH "" 0 0
Jul 7 09:28:00 localhost slapd[24176]: 0 120 0
Jul 7 09:28:00 localhost slapd[24176]: begin get_filter
Jul 7 09:28:00 localhost slapd[24176]: PRESENT
Jul 7 09:28:00 localhost slapd[24176]: end get_filter 0
Jul 7 09:28:00 localhost slapd[24176]: filter: (objectClass=*)
Jul 7 09:28:00 localhost slapd[24176]: attrs:
Jul 7 09:28:00 localhost slapd[24176]: supportedCapabilities
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=2 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=2 SRCH attr=supportedCapabilities
Jul 7 09:28:00 localhost slapd[24176]: => test_filter
Jul 7 09:28:00 localhost slapd[24176]: PRESENT
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: search access to "" "objectClass" requested
Jul 7 09:28:00 localhost slapd[24176]: => slap_access_allowed: backend default search access granted to "(anonymous)"
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: search access granted by read(=rscxd)
Jul 7 09:28:00 localhost slapd[24176]: <= test_filter 6
Jul 7 09:28:00 localhost slapd[24176]: => send_search_entry: conn 1542 dn=""
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: read access to "" "entry" requested
Jul 7 09:28:00 localhost slapd[24176]: => slap_access_allowed: backend default read access granted to "(anonymous)"
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: read access granted by read(=rscxd)
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=2 ENTRY dn=""
Jul 7 09:28:00 localhost slapd[24176]: <= send_search_entry: conn 1542 exit.
Jul 7 09:28:00 localhost slapd[24176]: send_ldap_result: conn=1542 op=2 p=3
Jul 7 09:28:00 localhost slapd[24176]: send_ldap_result: err=0 matched="" text=""
Jul 7 09:28:00 localhost slapd[24176]: send_ldap_response: msgid=88 tag=101 err=0
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on:
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:28:00 localhost slapd[24176]: daemon: activity on:
Jul 7 09:28:00 localhost slapd[24176]: 20r
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: daemon: read active on 20
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:28:00 localhost slapd[24176]: connection_get(20)
Jul 7 09:28:00 localhost slapd[24176]: connection_get(20): got connid=1542
Jul 7 09:28:00 localhost slapd[24176]: connection_read(20): checking for input on id=1542
Jul 7 09:28:00 localhost slapd[24176]: op tag 0x63, time 1467869280
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=3 do_search
Jul 7 09:28:00 localhost slapd[24176]: >>> dnPrettyNormal: <>
Jul 7 09:28:00 localhost slapd[24176]: <<< dnPrettyNormal: <>, <>
Jul 7 09:28:00 localhost slapd[24176]: SRCH "" 0 0
Jul 7 09:28:00 localhost slapd[24176]: 0 120 0
Jul 7 09:28:00 localhost slapd[24176]: begin get_filter
Jul 7 09:28:00 localhost slapd[24176]: PRESENT
Jul 7 09:28:00 localhost slapd[24176]: end get_filter 0
Jul 7 09:28:00 localhost slapd[24176]: filter: (objectClass=*)
Jul 7 09:28:00 localhost slapd[24176]: attrs:
Jul 7 09:28:00 localhost slapd[24176]: supportedSASLMechanisms
Jul 7 09:28:00 localhost slapd[24176]:
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=3 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Jul 7 09:28:00 localhost slapd[24176]: conn=1542 op=3 SRCH attr=supportedSASLMechanisms
Jul 7 09:28:00 localhost slapd[24176]: => test_filter
Jul 7 09:28:00 localhost slapd[24176]: PRESENT
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: search access to "" "objectClass" requested
Jul 7 09:28:00 localhost slapd[24176]: => slap_access_allowed: backend default search access granted to "(anonymous)"
Jul 7 09:28:00 localhost slapd[24176]: => access_allowed: search access granted by read(=rscxd)
Jul 7 09:28:00 localhost slapd[24176]: <= test_filter 6
Jul 7 09:28:00 localhost slapd[24176]: => send_search_entry: conn 1542 dn=""
Ну и логи при использовании команды ldapsearch с самого терминала сервера, где установлен openldap
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on:
Jul 7 09:36:39 localhost slapd[24176]:
Jul 7 09:36:39 localhost slapd[24176]: slap_listener_activate(8):
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=8 busy
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: >>> slap_listener(ldap:///)
Jul 7 09:36:39 localhost slapd[24176]: daemon: listen=8, new connection on 20
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on:
Jul 7 09:36:39 localhost slapd[24176]:
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: added 20r (active) listener=(nil)
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on:
Jul 7 09:36:39 localhost slapd[24176]: conn=1553 fd=20 ACCEPT from IP=[::1]:41605 (IP=[::]:389)
Jul 7 09:36:39 localhost slapd[24176]: 20r
Jul 7 09:36:39 localhost slapd[24176]:
Jul 7 09:36:39 localhost slapd[24176]: daemon: read active on 20
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: connection_get(20)
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:36:39 localhost slapd[24176]: connection_get(20): got connid=1553
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on:
Jul 7 09:36:39 localhost slapd[24176]: connection_read(20): checking for input on id=1553
Jul 7 09:36:39 localhost slapd[24176]:
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: op tag 0x63, time 1467869799
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: conn=1553 op=0 do_search
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:36:39 localhost slapd[24176]: >>> dnPrettyNormal: <>
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on:
Jul 7 09:36:39 localhost slapd[24176]: <<< dnPrettyNormal: <>, <>
Jul 7 09:36:39 localhost slapd[24176]:
Jul 7 09:36:39 localhost slapd[24176]: SRCH "" 0 0
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: 0 0 0
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: begin get_filter
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: PRESENT
Jul 7 09:36:39 localhost slapd[24176]: end get_filter 0
Jul 7 09:36:39 localhost slapd[24176]: filter: (objectClass=*)
Jul 7 09:36:39 localhost slapd[24176]: attrs:
Jul 7 09:36:39 localhost slapd[24176]: supportedSASLMechanisms
Jul 7 09:36:39 localhost slapd[24176]:
Jul 7 09:36:39 localhost slapd[24176]: conn=1553 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Jul 7 09:36:39 localhost slapd[24176]: conn=1553 op=0 SRCH attr=supportedSASLMechanisms
Jul 7 09:36:39 localhost slapd[24176]: => test_filter
Jul 7 09:36:39 localhost slapd[24176]: PRESENT
Jul 7 09:36:39 localhost slapd[24176]: => access_allowed: search access to "" "objectClass" requested
Jul 7 09:36:39 localhost slapd[24176]: => slap_access_allowed: backend default search access granted to "(anonymous)"
Jul 7 09:36:39 localhost slapd[24176]: => access_allowed: search access granted by read(=rscxd)
Jul 7 09:36:39 localhost slapd[24176]: <= test_filter 6
Jul 7 09:36:39 localhost slapd[24176]: => send_search_entry: conn 1553 dn=""
Jul 7 09:36:39 localhost slapd[24176]: => access_allowed: read access to "" "entry" requested
Jul 7 09:36:39 localhost slapd[24176]: => slap_access_allowed: backend default read access granted to "(anonymous)"
Jul 7 09:36:39 localhost slapd[24176]: => access_allowed: read access granted by read(=rscxd)
Jul 7 09:36:39 localhost slapd[24176]: => access_allowed: result not in cache (supportedSASLMechanisms)
Jul 7 09:36:39 localhost slapd[24176]: => access_allowed: read access to "" "supportedSASLMechanisms" requested
Jul 7 09:36:39 localhost slapd[24176]: => slap_access_allowed: backend default read access granted to "(anonymous)"
Jul 7 09:36:39 localhost slapd[24176]: => access_allowed: read access granted by read(=rscxd)
Jul 7 09:36:39 localhost slapd[24176]: => access_allowed: result was in cache (supportedSASLMechanisms)
Jul 7 09:36:39 localhost slapd[24176]: => access_allowed: result was in cache (supportedSASLMechanisms)
Jul 7 09:36:39 localhost slapd[24176]: conn=1553 op=0 ENTRY dn=""
Jul 7 09:36:39 localhost slapd[24176]: <= send_search_entry: conn 1553 exit.
Jul 7 09:36:39 localhost slapd[24176]: send_ldap_result: conn=1553 op=0 p=3
Jul 7 09:36:39 localhost slapd[24176]: send_ldap_result: err=0 matched="" text=""
Jul 7 09:36:39 localhost slapd[24176]: send_ldap_response: msgid=1 tag=101 err=0
Jul 7 09:36:39 localhost slapd[24176]: conn=1553 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on:
Jul 7 09:36:39 localhost slapd[24176]: 20r
Jul 7 09:36:39 localhost slapd[24176]:
Jul 7 09:36:39 localhost slapd[24176]: daemon: read active on 20
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: connection_get(20)
Jul 7 09:36:39 localhost slapd[24176]: connection_get(20): got connid=1553
Jul 7 09:36:39 localhost slapd[24176]: connection_read(20): checking for input on id=1553
Jul 7 09:36:39 localhost slapd[24176]: op tag 0x60, time 1467869799
Jul 7 09:36:39 localhost slapd[24176]: conn=1553 op=1 do_bind
Jul 7 09:36:39 localhost slapd[24176]: >>> dnPrettyNormal: <>
Jul 7 09:36:39 localhost slapd[24176]: <<< dnPrettyNormal: <>, <>
Jul 7 09:36:39 localhost slapd[24176]: conn=1553 op=1 BIND dn="" method=163
Jul 7 09:36:39 localhost slapd[24176]: do_bind: dn () SASL mech DIGEST-MD5
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:36:39 localhost slapd[24176]: daemon: activity on:
Jul 7 09:36:39 localhost slapd[24176]: ==> sasl_bind: dn="" mech=DIGEST-MD5 datalen=0
Jul 7 09:36:39 localhost slapd[24176]: SASL [conn=1553] Debug: DIGEST-MD5 server step 1
Jul 7 09:36:39 localhost slapd[24176]: send_ldap_sasl: err=14 len=182
Jul 7 09:36:39 localhost slapd[24176]: send_ldap_response: msgid=2 tag=97 err=14
Jul 7 09:36:39 localhost slapd[24176]: conn=1553 op=1 RESULT tag=97 err=14 text=SASL(0): successful result: security flags do not match required
Jul 7 09:36:39 localhost slapd[24176]: <== slap_sasl_bind: rc=14
Jul 7 09:36:39 localhost slapd[24176]:
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:36:39 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:36:42 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:36:42 localhost slapd[24176]: daemon: activity on:
Jul 7 09:36:42 localhost slapd[24176]: 20r
Jul 7 09:36:42 localhost slapd[24176]:
Jul 7 09:36:42 localhost slapd[24176]: daemon: read active on 20
Jul 7 09:36:42 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:36:42 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:36:42 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:36:42 localhost slapd[24176]: connection_get(20)
Jul 7 09:36:42 localhost slapd[24176]: connection_get(20): got connid=1553
Jul 7 09:36:42 localhost slapd[24176]: connection_read(20): checking for input on id=1553
Jul 7 09:36:42 localhost slapd[24176]: op tag 0x60, time 1467869802
Jul 7 09:36:42 localhost slapd[24176]: conn=1553 op=2 do_bind
Jul 7 09:36:42 localhost slapd[24176]: daemon: activity on 1 descriptor
Jul 7 09:36:42 localhost slapd[24176]: daemon: activity on:
Jul 7 09:36:42 localhost slapd[24176]:
Jul 7 09:36:42 localhost slapd[24176]: >>> dnPrettyNormal: <>
Jul 7 09:36:42 localhost slapd[24176]: <<< dnPrettyNormal: <>, <>
Jul 7 09:36:42 localhost slapd[24176]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Jul 7 09:36:42 localhost slapd[24176]: conn=1553 op=2 BIND dn="" method=163
Jul 7 09:36:42 localhost slapd[24176]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Jul 7 09:36:42 localhost slapd[24176]: do_bind: dn () SASL mech DIGEST-MD5
Jul 7 09:36:42 localhost slapd[24176]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Jul 7 09:36:42 localhost slapd[24176]: ==> sasl_bind: dn="" mech=<continuing> datalen=263
Jul 7 09:36:42 localhost slapd[24176]: SASL [conn=1553] Debug: DIGEST-MD5 server step 2
Jul 7 09:36:42 localhost slapd[24176]: SASL Canonicalize [conn=1553]: authcid="ivan"
Jul 7 09:36:42 localhost slapd[24176]: slap_sasl_getdn: conn 1553 id=ivan [len=4]
Jul 7 09:36:42 localhost slapd[24176]: slap_sasl_getdn: u:id converted to uid=ivan,cn=DIGEST-MD5,cn=auth
Jul 7 09:36:42 localhost slapd[24176]: >>> dnNormalize: <uid=ivan,cn=DIGEST-MD5,cn=auth>
Jul 7 09:36:42 localhost slapd[24176]: <<< dnNormalize: <uid=ivan,cn=digest-md5,cn=auth>
Jul 7 09:36:42 localhost slapd[24176]: ==>slap_sasl2dn: converting SASL name uid=ivan,cn=digest-md5,cn=auth to a DN
Jul 7 09:36:42 localhost slapd[24176]: ==> rewrite_context_apply [depth=1] string='uid=ivan,cn=digest-md5,cn=auth'
Jul 7 09:36:42 localhost slapd[24176]: ==> rewrite_rule_apply rule='uid=([^,]+),cn=digest-md5,cn=auth' string='uid=ivan,cn=digest-md5,cn=auth' [1 pass(es)]
Jul 7 09:36:42 localhost slapd[24176]: ==> rewrite_context_apply [depth=1] res={0,'ldap:///dc=test??sub?(uid=ivan)'}
Jul 7 09:36:42 localhost slapd[24176]: [rw] authid: "uid=ivan,cn=digest-md5,cn=auth" -> "ldap:///dc=test??sub?(uid=ivan)"
Jul 7 09:36:42 localhost slapd[24176]: slap_parseURI: parsing ldap:///dc=test??sub?(uid=ivan)
Jul 7 09:36:42 localhost slapd[24176]: str2filter "(uid=ivan)"
Jul 7 09:36:42 localhost slapd[24176]: begin get_filter
Jul 7 09:36:42 localhost slapd[24176]: EQUALITY
Jul 7 09:36:42 localhost slapd[24176]: end get_filter 0
Jul 7 09:36:42 localhost slapd[24176]: >>> dnNormalize: <dc=test>
Jul 7 09:36:42 localhost slapd[24176]: <<< dnNormalize: <dc=test>
Jul 7 09:36:42 localhost slapd[24176]: slap_sasl2dn: performing internal search (base=dc=test, scope=2)
Jul 7 09:36:42 localhost slapd[24176]: => bdb_search
Jul 7 09:36:42 localhost slapd[24176]: bdb_dn2entry("dc=test")
Jul 7 09:36:42 localhost slapd[24176]: => access_allowed: auth access to "dc=test" "entry" requested
Jul 7 09:36:42 localhost slapd[24176]: => dn: [1] dc=test
Jul 7 09:36:42 localhost slapd[24176]: => acl_get: [1] matched
Jul 7 09:36:42 localhost slapd[24176]: => acl_get: [1] attr entry
Jul 7 09:36:42 localhost slapd[24176]: => acl_mask: access to entry "dc=test", attr "entry" requested
Jul 7 09:36:42 localhost slapd[24176]: => acl_mask: to all values by "", (=0)
Jul 7 09:36:42 localhost slapd[24176]: <= check a_dn_pat: anonymous
Jul 7 09:36:42 localhost slapd[24176]: <= acl_mask: [1] applying read(=rscxd) (stop)
Jul 7 09:36:42 localhost slapd[24176]: <= acl_mask: [1] mask: read(=rscxd)
Jul 7 09:36:42 localhost slapd[24176]: => slap_access_allowed: auth access granted by read(=rscxd)
Jul 7 09:36:42 localhost slapd[24176]: => access_allowed: auth access granted by read(=rscxd)
Jul 7 09:36:42 localhost slapd[24176]: search_candidates: base="dc=test" (0x00000001) scope=2
Jul 7 09:36:42 localhost slapd[24176]: => bdb_dn2idl("dc=test")
Jul 7 09:36:42 localhost slapd[24176]: => bdb_filter_candidates
Jul 7 09:36:42 localhost slapd[24176]: #011AND
Jul 7 09:36:42 localhost slapd[24176]: => bdb_list_candidates 0xa0
Jul 7 09:36:42 localhost slapd[24176]: => bdb_filter_candidates
Jul 7 09:36:42 localhost slapd[24176]: #011OR
Jul 7 09:36:42 localhost slapd[24176]: => bdb_list_candidates 0xa1
Jul 7 09:36:42 localhost slapd[24176]: => bdb_filter_candidates
Jul 7 09:36:42 localhost slapd[24176]: #011EQUALITY
Jul 7 09:36:42 localhost slapd[24176]: => bdb_equality_candidates (objectClass)
Jul 7 09:36:42 localhost slapd[24176]: => key_read
Jul 7 09:36:42 localhost slapd[24176]: bdb_idl_fetch_key: [b49d1940]
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_index_read: failed (-30988)
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_equality_candidates: id=0, first=0, last=0
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_filter_candidates: id=0 first=0 last=0
Jul 7 09:36:42 localhost slapd[24176]: => bdb_filter_candidates
Jul 7 09:36:42 localhost slapd[24176]: #011EQUALITY
Jul 7 09:36:42 localhost slapd[24176]: => bdb_equality_candidates (uid)
Jul 7 09:36:42 localhost slapd[24176]: => key_read
Jul 7 09:36:42 localhost slapd[24176]: bdb_idl_fetch_key: [451b3b20]
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_index_read 1 candidates
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_equality_candidates: id=1, first=92, last=92
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_filter_candidates: id=1 first=92 last=92
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_list_candidates: id=1 first=92 last=92
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_filter_candidates: id=1 first=92 last=92
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_list_candidates: id=1 first=92 last=92
Jul 7 09:36:42 localhost slapd[24176]: <= bdb_filter_candidates: id=1 first=92 last=92
Jul 7 09:36:42 localhost slapd[24176]: bdb_search_candidates: id=1 first=92 last=92
Jul 7 09:36:42 localhost slapd[24176]: => test_filter
Jul 7 09:36:42 localhost slapd[24176]: EQUALITY
Jul 7 09:36:42 localhost slapd[24176]: => access_allowed: auth access to "uid=ivan,ou=Users,dc=test" "uid" requested
Jul 7 09:36:42 localhost slapd[24176]: => dn: [1] dc=test
Jul 7 09:36:42 localhost slapd[24176]: => acl_get: [1] matched
Jul 7 09:36:42 localhost slapd[24176]: => acl_get: [1] attr uid
Jul 7 09:36:42 localhost slapd[24176]: => acl_mask: access to entry "uid=ivan,ou=Users,dc=test", attr "uid" requested
Jul 7 09:36:42 localhost slapd[24176]: => acl_mask: to value by "", (=0)
Jul 7 09:36:42 localhost slapd[24176]: <= check a_dn_pat: anonymous