I'm experiencing crashes in slapd when attempting to bind via SASL using the OTP mech.
I'm using openldap version 2.3.39 for both slapd and my ldap utils (ldapsearch). I'm using the bdb backend.
I'm also using Debian Etch with the following versions of software:
Cyrus SASL 2.1.22(.dfsg1-8) libdb 4.2.52(+dfsg-2) libc6 2.3.6(.ds1-13etch2)
I've compiled cyrus sasl to use it's internal implementation of OTP, rather than OPIE:
--enable-otp (--with-opie is not enabled)
The problem I'm experiencing isn't when I successfully authenticate; that seems to work fine. It's when I run an ldapsearch, but instead of entering an OTP password, I press ctrl-c to cancel the search.
From the shell, when I perform an LDAP search, all appears normal:
hiro:~# ldapsearch -Y OTP -U abrown@olp.net SASL/OTP authentication started Challenge: otp-md5 497 hi3182 ext Please enter your one-time password:<ctrl-c> hiro:~#
However my slapd process dies.
Here's a gdb backtrace of the server process:
... Core was generated by `/usr/sbin/slapd'. Program terminated with signal 11, Segmentation fault. #0 0x080b448e in slap_auxprop_store (glob_context=0x0, sparams=0x820b2a0, prctx=0x82351c0, user=0x820a148 "abrown@olp.net", ulen=14) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/sasl.c:478 478 op.o_hdr = conn->c_sasl_bindop->o_hdr; (gdb) bt #0 0x080b448e in slap_auxprop_store (glob_context=0x0, sparams=0x820b2a0, prctx=0x82351c0, user=0x820a148 "abrown@olp.net", ulen=14) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/sasl.c:478 #1 0xb7eb17d7 in sasl_auxprop_store () from /usr/lib/libsasl2.so.2 #2 0xb7973c89 in otp_server_plug_init () from /usr/lib/sasl2/libotp.so.2 #3 0xb7ebde36 in sasl_server_new () from /usr/lib/libsasl2.so.2 #4 0xb7eb6194 in sasl_dispose () from /usr/lib/libsasl2.so.2 #5 0x080b2992 in slap_sasl_close (conn=0xb7ec3618) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/sasl.c:1331 #6 0x0806cf27 in connection_close (c=0xb75b1148) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/connection.c:715 #7 0x0806e116 in connection_read (s=12) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/connection.c:1458 #8 0x0806a49f in slapd_daemon_task (ptr=0x0) at /usr/src/build/openldap/openldap2.3-2.3.39/servers/slapd/daemon.c:2468 #9 0xb7cd3240 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0 #10 0xb7c674ae in clone () from /lib/tls/i686/cmov/libc.so.6 (gdb) quit
I've added a debug statement within slap_auxprop_store, so the openldap debug information below will include some additional information about what's being modified.
Here's output from an attempt that crashed (when I pressed ctrl-c in my ldapsearch):
Dec 3 13:39:06 hiro slapd[11134]: daemon: activity on 1 descriptor Dec 3 13:39:06 hiro slapd[11134]: daemon: activity on: Dec 3 13:39:06 hiro slapd[11134]: Dec 3 13:39:06 hiro slapd[11134]: >>> slap_listener(ldapi:///) Dec 3 13:39:06 hiro slapd[11134]: daemon: listen=12, new connection on 16 Dec 3 13:39:06 hiro slapd[11134]: daemon: added 16r (active) listener=(nil) Dec 3 13:39:06 hiro slapd[11134]: conn=3 fd=16 ACCEPT from PATH=/var/run/slapd/ldapi (PATH=/var/run/slapd/ldapi) Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=9 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=10 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=11 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=12 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: activity on 1 descriptor Dec 3 13:39:06 hiro slapd[11134]: daemon: activity on: Dec 3 13:39:06 hiro slapd[11134]: 16r Dec 3 13:39:06 hiro slapd[11134]: Dec 3 13:39:06 hiro slapd[11134]: daemon: read active on 16 Dec 3 13:39:06 hiro slapd[11134]: connection_get(16) Dec 3 13:39:06 hiro slapd[11134]: connection_get(16): got connid=3 Dec 3 13:39:06 hiro slapd[11134]: connection_read(16): checking for input on id=3 Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=9 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: do_bind Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=10 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: >>> dnPrettyNormal: <> Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=11 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: <<< dnPrettyNormal: <>, <> Dec 3 13:39:06 hiro slapd[11134]: daemon: epoll: listen=12 active_threads=0 tvp=NULL Dec 3 13:39:06 hiro slapd[11134]: do_sasl_bind: dn () mech OTP Dec 3 13:39:06 hiro slapd[11134]: conn=3 op=0 BIND dn="" method=163 Dec 3 13:39:06 hiro slapd[11134]: ==> sasl_bind: dn="" mech=OTP datalen=29 Dec 3 13:39:06 hiro slapd[11134]: SASL Canonicalize [conn=3]: authcid="abrown@olp.net" Dec 3 13:39:06 hiro slapd[11134]: slap_sasl_getdn: conn 3 id=abrown@olp.net [len=14] Dec 3 13:39:06 hiro slapd[11134]: slap_sasl_getdn: u:id converted to uid=abrown@olp.net,cn=OTP,cn=auth Dec 3 13:39:06 hiro slapd[11134]: >>> dnNormalize: <uid=abrown@olp.net,cn=OTP,cn=auth> Dec 3 13:39:06 hiro slapd[11134]: <<< dnNormalize: <uid=abrown@olp.net,cn=otp,cn=auth> Dec 3 13:39:06 hiro slapd[11134]: ==>slap_sasl2dn: converting SASL name uid=abrown@olp.net,cn=otp,cn=auth to a DN Dec 3 13:39:06 hiro slapd[11134]: slap_authz_regexp: converting SASL name uid=abrown@olp.net,cn=otp,cn=auth Dec 3 13:39:06 hiro slapd[11134]: slap_authz_regexp: converted SASL name to ldap:///ou=people,dc=olp,dc=net??one?(btcAltUid=abrown@olp.net) Dec 3 13:39:06 hiro slapd[11134]: slap_parseURI: parsing ldap:///ou=people,dc=olp,dc=net??one?(btcAltUid=abrown@olp.net) Dec 3 13:39:06 hiro slapd[11134]: str2filter "(btcAltUid=abrown@olp.net)" Dec 3 13:39:06 hiro slapd[11134]: begin get_filter Dec 3 13:39:06 hiro slapd[11134]: EQUALITY Dec 3 13:39:06 hiro slapd[11134]: end get_filter 0 Dec 3 13:39:06 hiro slapd[11134]: >>> dnNormalize: <ou=people,dc=olp,dc=net> Dec 3 13:39:06 hiro slapd[11134]: <<< dnNormalize: <ou=people,dc=olp,dc=net> Dec 3 13:39:06 hiro slapd[11134]: slap_sasl2dn: performing internal search (base=ou=people,dc=olp,dc=net, scope=1) Dec 3 13:39:06 hiro slapd[11134]: => bdb_search Dec 3 13:39:06 hiro slapd[11134]: bdb_dn2entry("ou=people,dc=olp,dc=net") Dec 3 13:39:06 hiro slapd[11134]: search_candidates: base="ou=people,dc=olp,dc=net" (0x00000003) scope=1 Dec 3 13:39:06 hiro slapd[11134]: => bdb_dn2idl("ou=people,dc=olp,dc=net") Dec 3 13:39:06 hiro slapd[11134]: bdb_idl_fetch_key: %ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: <= bdb_dn2idl: id=68 first=7 last=136 Dec 3 13:39:06 hiro slapd[11134]: => bdb_filter_candidates Dec 3 13:39:06 hiro slapd[11134]: ^IAND Dec 3 13:39:06 hiro slapd[11134]: => bdb_list_candidates 0xa0 Dec 3 13:39:06 hiro slapd[11134]: => bdb_filter_candidates Dec 3 13:39:06 hiro slapd[11134]: ^IOR Dec 3 13:39:06 hiro slapd[11134]: => bdb_list_candidates 0xa1 Dec 3 13:39:06 hiro slapd[11134]: => bdb_filter_candidates Dec 3 13:39:06 hiro slapd[11134]: ^IEQUALITY Dec 3 13:39:06 hiro slapd[11134]: => bdb_equality_candidates (objectClass) Dec 3 13:39:06 hiro slapd[11134]: => key_read Dec 3 13:39:06 hiro slapd[11134]: bdb_idl_fetch_key: [b49d1940] Dec 3 13:39:06 hiro slapd[11134]: <= bdb_index_read: failed (-30990) Dec 3 13:39:06 hiro slapd[11134]: <= bdb_equality_candidates: id=0, first=0, last=0 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_filter_candidates: id=0 first=0 last=0 Dec 3 13:39:06 hiro slapd[11134]: => bdb_filter_candidates Dec 3 13:39:06 hiro slapd[11134]: ^IEQUALITY Dec 3 13:39:06 hiro slapd[11134]: => bdb_equality_candidates (btcAltUID) Dec 3 13:39:06 hiro slapd[11134]: => key_read Dec 3 13:39:06 hiro slapd[11134]: bdb_idl_fetch_key: [b0f0ea63] Dec 3 13:39:06 hiro slapd[11134]: <= bdb_index_read 1 candidates Dec 3 13:39:06 hiro slapd[11134]: <= bdb_equality_candidates: id=1, first=7, last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_filter_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_list_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_filter_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_list_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: <= bdb_filter_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: bdb_search_candidates: id=1 first=7 last=7 Dec 3 13:39:06 hiro slapd[11134]: => test_filter Dec 3 13:39:06 hiro slapd[11134]: EQUALITY Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access to "uid=abrown@olp.net,ou=People,dc=olp,dc=net" "btcAltUID" requested Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [1] ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [2] .*,ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dn: [3] ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dn: [4] ou=groups,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => acl_get: [7] attr btcAltUID Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: access to entry "uid=abrown@olp.net,ou=People,dc=olp,dc=net", attr "btcAltUID" requested Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: to value by "", (=0) Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: anonymous Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [1] applying auth(=xd) (stop) Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [1] mask: auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: <= test_filter 6 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: conn=3 op=0 p=3 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: err=0 matched="" text="" Dec 3 13:39:06 hiro slapd[11134]: <==slap_sasl2dn: Converted SASL name to uid=abrown@olp.net,ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: slap_sasl_getdn: dn:id converted to uid=abrown@olp.net,ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: SASL Canonicalize [conn=3]: slapAuthcDN="uid=abrown@olp.net,ou=people,dc=olp,dc=net" Dec 3 13:39:06 hiro slapd[11134]: => bdb_search Dec 3 13:39:06 hiro slapd[11134]: bdb_dn2entry("uid=abrown@olp.net,ou=people,dc=olp,dc=net") Dec 3 13:39:06 hiro slapd[11134]: base_candidates: base: "uid=abrown@olp.net,ou=people,dc=olp,dc=net" (0x00000007) Dec 3 13:39:06 hiro slapd[11134]: => test_filter Dec 3 13:39:06 hiro slapd[11134]: PRESENT Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access to "uid=abrown@olp.net,ou=People,dc=olp,dc=net" "objectClass" requested Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [1] ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [2] .*,ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dn: [3] ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dn: [4] ou=groups,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [12] .*n=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [13] .*n=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [14] ^cn=admin,cn=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [15] ^cn=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [16] ^cn=admin,cn=([^,]+),ou=groups,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => acl_get: [17] attr objectClass Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: access to entry "uid=abrown@olp.net,ou=People,dc=olp,dc=net", attr "objectClass" requested Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: to all values by "", (=0) Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: self Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: anonymous Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [8] applying auth(=xd) (stop) Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [8] mask: auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: <= test_filter 6 Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access to "uid=abrown@olp.net,ou=People,dc=olp,dc=net" "cmusaslsecretOTP" requested Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [1] ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [2] .*,ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dn: [3] ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dn: [4] ou=groups,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => acl_get: [8] attr cmusaslsecretOTP Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: access to entry "uid=abrown@olp.net,ou=People,dc=olp,dc=net", attr "cmusaslsecretOTP" requested Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: to all values by "", (=0) Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: anonymous Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [1] applying auth(=xd) (stop) Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [1] mask: auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: auth access granted by auth(=xd) Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: conn=3 op=0 p=3 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: err=0 matched="" text="" Dec 3 13:39:06 hiro slapd[11134]: SASL Canonicalize [conn=3]: authzid="abrown@olp.net" Dec 3 13:39:06 hiro slapd[11134]: slap_auxprop_store [conn=3]: Getting ready to set cmusaslsecretOTP to md5^I0499^Ihi5935^I0e81b33e30182715^I00000000001196711046. Dec 3 13:39:06 hiro slapd[11134]: bdb_modify: uid=abrown@olp.net,ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: bdb_dn2entry("uid=abrown@olp.net,ou=people,dc=olp,dc=net") Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: 0x00000007: uid=abrown@olp.net,ou=People,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: delete access to "uid=abrown@olp.net,ou=People,dc=olp,dc=net" "cmusaslsecretOTP" requested Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [1] ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dnpat: [2] .*,ou=addressbooks,uid=([^,]+),ou=people,dc=olp,dc=net$ nsub: 1 Dec 3 13:39:06 hiro slapd[11134]: => dn: [3] ou=people,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => dn: [4] ou=groups,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: => acl_get: [8] attr cmusaslsecretOTP Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: no res from state (cmusaslsecretOTP) Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: access to entry "uid=abrown@olp.net,ou=People,dc=olp,dc=net", attr "cmusaslsecretOTP" requested Dec 3 13:39:06 hiro slapd[11134]: => acl_mask: to all values by "uid=abrown@olp.net,ou=people,dc=olp,dc=net", (=0) Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: anonymous Dec 3 13:39:06 hiro slapd[11134]: <= check a_dn_pat: self Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [2] applying write(=wrscxd) (stop) Dec 3 13:39:06 hiro slapd[11134]: <= acl_mask: [2] mask: write(=wrscxd) Dec 3 13:39:06 hiro slapd[11134]: => slap_access_allowed: delete access granted by write(=wrscxd) Dec 3 13:39:06 hiro slapd[11134]: => access_allowed: delete access granted by write(=wrscxd) Dec 3 13:39:06 hiro slapd[11134]: acl: internal mod entryCSN: modify access granted Dec 3 13:39:06 hiro slapd[11134]: acl: internal mod modifiersName: modify access granted Dec 3 13:39:06 hiro slapd[11134]: acl: internal mod modifyTimestamp: modify access granted Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: replace cmusaslsecretOTP Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: replace entryCSN Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: replace modifiersName Dec 3 13:39:06 hiro slapd[11134]: bdb_modify_internal: replace modifyTimestamp Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "account" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "posixAccount" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "shadowAccount" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "krb5KDCEntry" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "krb5Principal" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "sambaSamAccount" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "radiusprofile" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "btcAuthUser" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "cmuSaslUser" Dec 3 13:39:06 hiro slapd[11134]: oc_check_required entry (uid=abrown@olp.net,ou=People,dc=olp,dc=net), objectClass "pkiUser" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "uid" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "cn" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "uidNumber" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "gidNumber" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "homeDirectory" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "loginShell" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowMin" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowMax" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowWarning" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowExpire" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "gecos" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "structuralObjectClass" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "entryUUID" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "creatorsName" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "createTimestamp" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5PrincipalName" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5MaxLife" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5MaxRenew" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5KDCFlags" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaSID" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaAcctFlags" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaPrimaryGroupSID" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "shadowLastChange" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "radiusGroupName" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "btcCertificatePassword" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "btcAltUID" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "UNDEFINED" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "userPassword" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaPwdLastSet" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaLMPassword" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "sambaNTPassword" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5KeyVersionNumber" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "krb5Key" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "UNDEFINED" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "objectClass" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "UNDEFINED" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "cmusaslsecretOTP" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "entryCSN" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "modifiersName" Dec 3 13:39:06 hiro slapd[11134]: oc_check_allowed type "modifyTimestamp" Dec 3 13:39:06 hiro slapd[11134]: => entry_encode(0x00000007): uid=abrown@olp.net,ou=People,dc=olp,dc=net Dec 3 13:39:06 hiro slapd[11134]: bdb_modify: updated id=00000007 dn="uid=abrown@olp.net,ou=people,dc=olp,dc=net" Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: conn=3 op=0 p=3 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_result: err=0 matched="" text="" Dec 3 13:39:06 hiro slapd[11134]: send_ldap_sasl: err=14 len=22 Dec 3 13:39:06 hiro slapd[11134]: send_ldap_response: msgid=1 tag=97 err=14 Dec 3 13:39:06 hiro slapd[11134]: conn=3 op=0 RESULT tag=97 err=14 text= Dec 3 13:39:06 hiro slapd[11134]: <== slap_sasl_bind: rc=14 Dec 3 13:39:07 hiro slapd[11134]: daemon: activity on 1 descriptor Dec 3 13:39:07 hiro slapd[11134]: daemon: activity on: Dec 3 13:39:07 hiro slapd[11134]: 16r Dec 3 13:39:07 hiro slapd[11134]: Dec 3 13:39:07 hiro slapd[11134]: daemon: read active on 16 Dec 3 13:39:07 hiro slapd[11134]: connection_get(16) Dec 3 13:39:07 hiro slapd[11134]: connection_get(16): got connid=3 Dec 3 13:39:07 hiro slapd[11134]: connection_read(16): checking for input on id=3 Dec 3 13:39:07 hiro slapd[11134]: ber_get_next on fd 16 failed errno=0 (Success) Dec 3 13:39:07 hiro slapd[11134]: connection_read(16): input error=-2 id=3, closing. Dec 3 13:39:07 hiro slapd[11134]: connection_closing: readying conn=3 sd=16 for close Dec 3 13:39:07 hiro slapd[11134]: connection_close: conn=3 sd=-1 Dec 3 13:39:07 hiro slapd[11134]: slap_auxprop_store [conn=-1]: Getting ready to set cmusaslsecretOTP to md5^I0499^Ihi5935^I0e81b33e30182715^I00000000000000000000.
If I enter a good OTP password, I get this in my logs:
Dec 3 13:43:26 hiro slapd[11159]: slap_auxprop_store [conn=3]: Getting ready to set cmusaslsecretOTP to md5^I0499^Ihi5865^Iec8123986aec6550^I00000000001196711306. Dec 3 13:44:26 hiro slapd[11159]: slap_auxprop_store [conn=3]: Getting ready to set cmusaslsecretOTP to md5^I0498^Ihi5865^Ic3570f027cf46ed0^I00000000000000000000.
If I enter an incorrect password, I get this:
Dec 3 13:45:21 hiro slapd[11159]: slap_auxprop_store [conn=4]: Getting ready to set cmusaslsecretOTP to md5^I0498^Ihi5865^Ic3570f027cf46ed0^I00000000001196711421. Dec 3 13:45:22 hiro slapd[11159]: slap_auxprop_store [conn=4]: Getting ready to set cmusaslsecretOTP to md5^I0498^Ihi5865^Ic3570f027cf46ed0^I00000000000000000000.
So in the case where it's crashing, it appears the Cyrus SASL is attempting to revert the OTP entry back to the previous version to "unlock" it. I assume that the connection id of '-1' is relevant to the crash.
You should be able to reproduce this error with the following steps:
Compile SASL with OTP, but without OPIE
Configure a dummy SASL service configuration file, e.g.: hiro:~# cat > /usr/lib/sasl2/test.conf <<EOF > auxprop_plugin: ldapdb > ldapdb_uri: ldapi:/// > ldapdb_mech: EXTERNAL > EOF hiro:~#
Create a schema including an attribute of cmusaslsecretOTP, and create an entry in the directory which can use this attribute.
Configure slapd.conf with the appropriate sasl configuration to convert both the openldap user (connecting via ldapi:///) and the user specified in the ldapsearch, for example: sasl-regexp "gidNumber=0\+uidNumber=0,cn=peercred,cn=external,cn=auth" cn=admin,dc=olp,dc=net
sasl-regexp "uid=([^,]+),cn=otp,cn=auth" ldap:///ou=people,dc=olp,dc=net??one?(btcAltUid=$1)
Issue a saslpasswd2 to initialize the cmusaslsecretOTP attribute for the user:
hiro:~# saslpasswd2 -a test -n abrown@olp.net Password: Again (for verification):
The cmusaslsecretOTP attribute should look something like: md5 0499 hi8351 1c19abc81f35dc63 00000000000000000000
opiekey can be used to convert the OTP challenge into the appropriate response. For instance:
hiro:~# ldapsearch -Y OTP -U abrown@olp.net SASL/OTP authentication started Challenge: otp-md5 498 hi8351 ext Please enter your one-time password:
Using opiekey to obtain response:
dwhite@zek:~$ opiekey -5 -x 498 hi8351 Using the MD5 algorithm to compute response. Reminder: Don't use opiekey from telnet or dial-in sessions. Enter secret pass phrase: 556A 99B3 52FA CEB1
Feed the secret pass phrase back into ldapsearch for a successful bind.
To reproduce the bug, of course just kill the ldapsearch before entering any response.
- Dan White BTC Broadband
--On December 3, 2007 7:55:13 PM -0600 Dan White dwhite@olp.net wrote:
I'm experiencing crashes in slapd when attempting to bind via SASL using the OTP mech.
Hi Dan,
Thanks for the report! Can you please file this into the ITS system at http://wwww.openldap.org/its so that it gets a bug number assigned? :)
Thanks, Quanah
--
Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration