[Date Prev][Date Next] [Chronological] [Thread] [Top]
openldap 2.1.6 & cyrus 2.1.9 & DIGEST-MD5: Error using ldappasswd

To: openldap-software@OpenLDAP.org
Subject: openldap 2.1.6 & cyrus 2.1.9 & DIGEST-MD5: Error using ldappasswd
From: "Josef.Irnberger" <Josef.Irnberger@fh-sbg.ac.at>
Date: Mon, 21 Oct 2002 10:57:25 GMT
Cc: hyc@highlandsun.com
Hi list, 

sorry about my previous mail without enough debugging info, so...

I compiled SASL 2.1.19 (with ./configure --with-pam=/etc/pam.d
--with-openssl=/usr/share/ssl --disable-krb4 --disable-gssapi --disable-otp
--with-ldap=/etc/openldap).

Then I configured openldap (with ./configure --enable-debug --enable-syslog
--with-cyrus-sasl --with-kerberos=no --with-tls --enable-crypt --enable-spasswd
--enable-slurpd) ...

In order to be able to use DIGEST-MD5 with the ldap directory as plaintext
password source, I added these lines to the slapd.conf (where ldapdemo.com is my
domain):

password-hash   {CLEARTEXT}
sasl-regexp     uid=(.*),cn=.*,cn=auth  uid=$1,dc=ldapdemo,dc=com

When I now execute "ldapsearch -Y DIGEST-MD5 -U jirnberg" everything works just
fine, but when I try to change the password with "ldappasswd -Y DIGEST-MD5 -U
jirnberg", it fails, as the entry can not be modified. The full debugging output
is below, with debugging level 4109:


--- client debugging output ---

# ldappasswd -Y DIGEST-MD5 -U jirnberg -d 4109
ldap_create
ldap_interactive_sasl_bind_s: user selected: DIGEST-MD5
ldap_int_sasl_bind: DIGEST-MD5
ldap_new_connection
ldap_int_open_connection
ldap_connect_to_host: TCP localhost:389
ldap_new_socket: 3
ldap_prepare_socket: 3
ldap_connect_to_host: Trying 127.0.0.1:389
ldap_connect_timeout: fd: 3 tm: -1 async: 0
ldap_ndelay_on: 3
ldap_is_sock_ready: 3
ldap_ndelay_off: 3
ldap_int_sasl_open: host=ldapslave.ldapdemo.com
SASL/DIGEST-MD5 authentication started
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ber_flush: 26 bytes to sd 3
ldap_result msgid 1
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 1
wait4msg continue, msgid 1, all 1
** Connections:
* host: localhost  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Mon Oct 21 12:35:03 2002

** Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 1, all 1
ber_get_next
ber_get_next: tag 0x30 len 211 contents:
ldap_read: message type bind msgid 1, original id 1
ber_scanf fmt ({iaa) ber:
read1msg:  0 new referrals
read1msg:  mark request completed, id = 1
request 1 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_sasl_bind_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (O) ber:
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (x) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
sasl_client_step: 2
Please enter your password:
sasl_client_step: 1
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ber_flush: 328 bytes to sd 3
ldap_result msgid 2
ldap_chkResponseList for msgid=2, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 2
wait4msg continue, msgid 2, all 1
** Connections:
* host: localhost  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Mon Oct 21 12:35:54 2002

** Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=2, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 2, all 1
ber_get_next
ber_get_next: tag 0x30 len 94 contents:
ldap_read: message type bind msgid 2, original id 2
ber_scanf fmt ({iaa) ber:
read1msg:  0 new referrals
read1msg:  mark request completed, id = 2
request 2 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 2, msgid 2)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_sasl_bind_result
ber_scanf fmt ({iaa) ber:
ldap_msgfree
ldap_perror
ldap_sasl_interactive_bind_s: Invalid credentials (49)
        additional info: SASL(-13): authentication failure: client response
doesn't match what we generated
[root@ldapslave etc]# ldappasswd -Y DIGEST-MD5 -U jirnberg -d 4109
ldap_create
ldap_interactive_sasl_bind_s: user selected: DIGEST-MD5
ldap_int_sasl_bind: DIGEST-MD5
ldap_new_connection
ldap_int_open_connection
ldap_connect_to_host: TCP localhost:389
ldap_new_socket: 3
ldap_prepare_socket: 3
ldap_connect_to_host: Trying 127.0.0.1:389
ldap_connect_timeout: fd: 3 tm: -1 async: 0
ldap_ndelay_on: 3
ldap_is_sock_ready: 3
ldap_ndelay_off: 3
ldap_int_sasl_open: host=ldapslave.ldapdemo.com
SASL/DIGEST-MD5 authentication started
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ber_flush: 26 bytes to sd 3
ldap_result msgid 1
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 1
wait4msg continue, msgid 1, all 1
** Connections:
* host: localhost  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Mon Oct 21 12:35:59 2002

** Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 1, all 1
ber_get_next
ber_get_next: tag 0x30 len 211 contents:
ldap_read: message type bind msgid 1, original id 1
ber_scanf fmt ({iaa) ber:
read1msg:  0 new referrals
read1msg:  mark request completed, id = 1
request 1 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_sasl_bind_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (O) ber:
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (x) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
sasl_client_step: 2
Please enter your password:
sasl_client_step: 1
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ber_flush: 328 bytes to sd 3
ldap_result msgid 2
ldap_chkResponseList for msgid=2, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 2
wait4msg continue, msgid 2, all 1
** Connections:
* host: localhost  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Mon Oct 21 12:36:01 2002

** Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=2, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 2, all 1
ber_get_next
ber_get_next: tag 0x30 len 54 contents:
ldap_read: message type bind msgid 2, original id 2
ber_scanf fmt ({iaa) ber:
read1msg:  0 new referrals
read1msg:  mark request completed, id = 2
request 2 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 2, msgid 2)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_sasl_bind_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (O) ber:
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (x) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
sasl_client_step: 0
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ber_flush: 26 bytes to sd 3
ldap_result msgid 3
ldap_chkResponseList for msgid=3, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 3
wait4msg continue, msgid 3, all 1
** Connections:
* host: localhost  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Mon Oct 21 12:36:01 2002

** Outstanding Requests:
 * msgid 3,  origid 3, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=3, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 3, all 1
ber_get_next
ber_get_next: tag 0x30 len 12 contents:
ldap_read: message type bind msgid 3, original id 3
ber_scanf fmt ({iaa) ber:
read1msg:  0 new referrals
read1msg:  mark request completed, id = 3
request 3 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 3, msgid 3)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_sasl_bind_result
ber_scanf fmt ({iaa) ber:
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
SASL username: jirnberg
SASL SSF: 128
SASL installing layers
ldap_pvt_sasl_install
ldap_extended_operation
ldap_send_initial_request
ldap_send_server_request
ber_flush: 32 bytes to sd 3
ldap_result msgid -1
ldap_chkResponseList for msgid=-1, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid -1
wait4msg continue, msgid -1, all 1
** Connections:
* host: localhost  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Mon Oct 21 12:36:01 2002

** Outstanding Requests:
 * msgid 4,  origid 4, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=-1, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 1
ber_get_next
ber_get_next: tag 0x30 len 45 contents:
ldap_read: message type extended-result msgid 4, original id 4
ber_scanf fmt ({iaa) ber:
read1msg:  0 new referrals
read1msg:  mark request completed, id = 4
request 4 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 4, msgid 4)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (x) ber:
ber_scanf fmt (}) ber:
ldap_parse_extended_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (O) ber:
ldap_msgfree
ber_scanf fmt ({a}) ber:
New password: .QhfUba.
ldap_err2string
Result: Internal (implementation specific) error (80)
Additional info: entry modify failed
ldap_unbind
ldap_free_connection
ldap_send_unbind
ber_flush: 7 bytes to sd 3
ldap_free_connection: actually freed

--- client debugging output end ---


--- server debugging output ----

daemon: activity on 1 descriptors
daemon: new connection on 13
daemon: added 13r
daemon: activity on:
daemon: select: listen=6 active_threads=0 tvp=NULL
daemon: activity on 1 descriptors
daemon: activity on: 13r
daemon: read activity on 13
connection_get(13)
connection_get(13): got connid=1
connection_read(13): checking for input on id=1
ber_get_next
ber_get_next: tag 0x30 len 24 contents:
ber_get_next
ber_get_next on fd 13 failed errno=11 (Resource temporarily unavailable)
daemon: select: listen=6 active_threads=1 tvp=NULL
do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt ({o) ber:
ber_scanf fmt (}}) ber:
>>> dnPrettyNormal: <>
<<< dnPrettyNormal: <>, <>
do_sasl_bind: dn () mech DIGEST-MD5
==> sasl_bind: dn="" mech=DIGEST-MD5 datalen=0
SASL [conn=1] Debug: DIGEST-MD5 server step 1
send_ldap_sasl: err=14 len=195
send_ldap_response: msgid=1 tag=97 err=14
ber_flush: 214 bytes to sd 13
<== slap_sasl_bind: rc=14             ## Here the client asks for the password
daemon: activity on 1 descriptors
daemon: activity on: 13r
daemon: read activity on 13
connection_get(13)
connection_get(13): got connid=0
connection_read(13): checking for input on id=0
ber_get_next
ber_get_next: tag 0x30 len 324 contents:
ber_get_next
ber_get_next on fd 13 failed errno=11 (Resource temporarily unavailable)
daemon: select: listen=6 active_threads=1 tvp=NULL
do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt ({o) ber:
ber_scanf fmt (m) ber:
ber_scanf fmt (}}) ber:
>>> dnPrettyNormal: <>
<<< dnPrettyNormal: <>, <>
do_sasl_bind: dn () mech DIGEST-MD5
==> sasl_bind: dn="" mech=<continuing> datalen=292
SASL [conn=0] Debug: DIGEST-MD5 server step 2
SASL Canonicalize [conn=0]: authcid="jirnberg"
slap_sasl_getdn: id=jirnberg
getdn: u:id converted to uid=jirnberg,cn=DIGEST-MD5,cn=auth
>>> dnNormalize: <uid=jirnberg,cn=DIGEST-MD5,cn=auth>
=> ldap_bv2dn(uid=jirnberg,cn=DIGEST-MD5,cn=auth,0)
<= ldap_bv2dn(uid=jirnberg,cn=DIGEST-MD5,cn=auth,0)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=jirnberg,cn=digest-md5,cn=auth,272)=0
<<< dnNormalize: <uid=jirnberg,cn=digest-md5,cn=auth>
==>slap_sasl2dn: converting SASL name uid=jirnberg,cn=digest-md5,cn=auth to a
DNslap_sasl_regexp: converting SASL name uid=jirnberg,cn=digest-md5,cn=auth
slap_sasl_regexp: converted SASL name to uid=jirnberg,dc=ldapdemo,dc=com
slap_parseURI: parsing uid=jirnberg,dc=ldapdemo,dc=com
ldap_url_parse_ext(uid=jirnberg,dc=ldapdemo,dc=com)
>>> dnNormalize: <uid=jirnberg,dc=ldapdemo,dc=com>
=> ldap_bv2dn(uid=jirnberg,dc=ldapdemo,dc=com,0)
<= ldap_bv2dn(uid=jirnberg,dc=ldapdemo,dc=com,0)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=jirnberg,dc=ldapdemo,dc=com,272)=0
<<< dnNormalize: <uid=jirnberg,dc=ldapdemo,dc=com>
<==slap_sasl2dn: Converted SASL name to uid=jirnberg,dc=ldapdemo,dc=com
getdn: dn:id converted to uid=jirnberg,dc=ldapdemo,dc=com
SASL Canonicalize [conn=0]: authcDN="uid=jirnberg,dc=ldapdemo,dc=com"
=> bdb_back_search
bdb_dn2entry_rw("uid=jirnberg,dc=ldapdemo,dc=com")
=> bdb_dn2id_matched( "uid=jirnberg,dc=ldapdemo,dc=com" )
<= bdb_dn2id_matched: id=0x00000005: entry uid=jirnberg,dc=ldapdemo,dc=com
entry_decode: "uid=jirnberg,dc=ldapdemo,dc=com"
<= entry_decode(uid=jirnberg,dc=ldapdemo,dc=com)
base_candidates: base: "uid=jirnberg,dc=ldapdemo,dc=com" (0x00000005)
====> bdb_cache_return_entry_r( 5 ): created (0)
====> bdb_cache_find_entry_id( 5 ) "uid=jirnberg,dc=ldapdemo,dc=com" (found) (1
tries)
slap_auxprop: str2ad(cmusaslsecretDIGEST-MD5): attribute type undefined
====> bdb_cache_return_entry_r( 5 ): returned (0)
SASL Canonicalize [conn=0]: authzid="jirnberg"
SASL Authorize [conn=0]: authcid="jirnberg" authzid="jirnberg"
send_ldap_sasl: err=14 len=40
send_ldap_response: msgid=2 tag=97 err=14
ber_flush: 56 bytes to sd 13
daemon: activity on 1 descriptors
daemon: activity on: 13r
daemon: read activity on 13
connection_get(13)
connection_get(13): got connid=0
connection_read(13): checking for input on id=0
ber_get_next
ber_get_next: tag 0x30 len 24 contents:
deferring operation
ber_get_next
ber_get_next on fd 13 failed errno=11 (Resource temporarily unavailable)
daemon: select: listen=6 active_threads=1 tvp=NULL
<== slap_sasl_bind: rc=14
do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt ({o) ber:
ber_scanf fmt (}}) ber:
>>> dnPrettyNormal: <>
<<< dnPrettyNormal: <>, <>
do_sasl_bind: dn () mech DIGEST-MD5
==> sasl_bind: dn="" mech=<continuing> datalen=0
send_ldap_sasl: err=0 len=-1
send_ldap_response: msgid=3 tag=97 err=0
ber_flush: 14 bytes to sd 13
daemon: activity on 1 descriptors
daemon: activity on: 13r
daemon: read activity on 13
connection_get(13)
connection_get(13): got connid=0
connection_read(13): checking for input on id=0
ldap_pvt_sasl_install
ber_get_next
ber_get_next: tag 0x30 len 30 contents:
deferring operation
ber_get_next
ber_get_next on fd 13 failed errno=11 (Resource temporarily unavailable)
<== slap_sasl_bind: rc=0
do_bind: SASL/DIGEST-MD5 bind: dn="uid=jirnberg,dc=ldapdemo,dc=com" ssf=128
daemon: select: listen=6 active_threads=2 tvp=NULL
do_extended
ber_scanf fmt ({m) ber:
do_extended: oid=1.3.6.1.4.1.4203.1.11.1
==> bdb_exop_passwd: ""
slap_passwd_generate
slap_passwd_return: 8
bdb_exop_passwd: "uid=jirnberg,dc=ldapdemo,dc=com"
>>> dnNormalize: <uid=jirnberg,dc=ldapdemo,dc=com>
=> ldap_bv2dn(uid=jirnberg,dc=ldapdemo,dc=com,0)
<= ldap_bv2dn(uid=jirnberg,dc=ldapdemo,dc=com,0)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=jirnberg,dc=ldapdemo,dc=com,272)=0
<<< dnNormalize: <uid=jirnberg,dc=ldapdemo,dc=com>
bdb_dn2entry_rw("uid=jirnberg,dc=ldapdemo,dc=com")
=> bdb_dn2id( "uid=jirnberg,dc=ldapdemo,dc=com" )
====> bdb_cache_find_entry_dn2id("uid=jirnberg,dc=ldapdemo,dc=com"): 5 (1
tries)====> bdb_cache_find_entry_id( 5 ) "uid=jirnberg,dc=ldapdemo,dc=com"
(found) (1
tries)
bdb_modify_internal: 0x00000005: uid=jirnberg,dc=ldapdemo,dc=com
====> bdb_cache_return_entry_w( 5 ): returned (0)
send_ldap_extended err=80 oid= len=12
send_ldap_response: msgid=4 tag=120 err=80
ber_flush: 47 bytes to sd 13
daemon: activity on 1 descriptors
daemon: activity on: 13r
daemon: read activity on 13
connection_get(13)
connection_get(13): got connid=0
connection_read(13): checking for input on id=0
ber_get_next
ber_get_next: tag 0x30 len 5 contents:
ber_get_next
ber_get_next on fd 13 failed errno=0 (Success)
connection_read(13): input error=-2 id=0, closing.
connection_closing: readying conn=0 sd=13 for close
connection_close: deferring conn=0 sd=13
connection_resched: attempting closing conn=0 sd=13
connection_close: deferring conn=0 sd=13
daemon: select: listen=6 active_threads=2 tvp=NULL
daemon: activity on 1 descriptors
daemon: select: listen=6 active_threads=2 tvp=NULL
do_unbind
connection_resched: attempting closing conn=0 sd=13
connection_close: conn=0 sd=13
daemon: removing 13

--- server debugging output end ---


If I got this right, SASL uses the LDAP directory server for retrieving the
plaintext passwords instead of the sasldb2. However, the file /etc/sasldb2 has
to be accessible for the slapd (which runs as user ldap), otherwise is doesn't
work at all. But I don't know why.


If anybody is able to determine, why slapd is not able to change the password,
please help me.
I would greatly appreciate it.


TIA

Josef
Irnberger
Follow-Ups:
- Re: openldap 2.1.6 & cyrus 2.1.9 & DIGEST-MD5: Error using ldappasswd
  - From: "Kurt D. Zeilenga" <Kurt@OpenLDAP.org>
Prev by Date: Re: Re: ldap_add: Object class violation
Next by Date: openldap V2.1.n and referral
Index(es):
- Chronological
- Thread