|
I've attached the debug output from sasl using the new "ldap_debug: -7" attribute.
using the "%u" attribute makes no difference.
What I'm seeing in the tcpdump output is that the uid is being sent in full. In fact, the ldap search is finding the "dn" correctly.
We are using the "userPassword" attribute, and the password is encrypted. I"m not sure what the algo is. But the the thing is that with Auth Plain and Auth Login the password is being send in clear.
I don't see anything in the debug output that helps me know why this is happening.
I'm a bit reluctant to post the tcpdump because that has a lot more info than I'm really prepared to share in public.
Anything else I can share?
--
Robert G. Werner Systems Administrator University of California Merced, Office of Information Technology rwerner2@xxxxxxxxxxxx | it.ucmerced.edu | 209.201.4368From: Dan White <dwhite@xxxxxxx>
Sent: Tuesday, June 5, 2018 2:23 PM To: Robert Werner Cc: cyrus-sasl@xxxxxxxxxxxxxxxxxxxx Subject: Re: Problem using saslauthd against ldap server ... On 06/05/18 20:19 +0000, Robert Werner wrote:
>I tried running the saslauthd with the flags you suggested and got the >following output: > >lpmail01 01:09 PM ~ root (1031) : /usr/sbin/saslauthd -d -n 1 -m /run/saslauthd -a ldap -O /etc/saslauthd.conf >saslauthd[4718] :main : num_procs : 1 >saslauthd[4718] :main : mech_option: /etc/saslauthd.conf >saslauthd[4718] :main : run_path : /run/saslauthd >saslauthd[4718] :main : auth_mech : ldap >saslauthd[4718] :ipc_init : using accept lock file: /run/saslauthd/mux.accept >saslauthd[4718] :detach_tty : master pid is: 0 >saslauthd[4718] :ipc_init : listening on socket: /run/saslauthd/mux >saslauthd[4718] :main : using process model >saslauthd[4718] :get_accept_lock : acquired accept lock >saslauthd[4718] :rel_accept_lock : released accept lock >saslauthd[4718] :do_auth : auth failure: [user=rwerner2] [service=smtp] [realm=] [mech=ldap] [reason=Unknown] >saslauthd[4718] :do_request : response: NO >saslauthd[4718] :get_accept_lock : acquired accept lock > >The "debug: -1" flag didn't seem to affect the output . I gave you the wrong option. It's 'ldap_debug: -1'. >The problem doesn't seem to be username dependent. I've used several >different ones. I'm mostly testing with my own which is "rwerner2" but >I've also tested with "ucmit-mcp" . Does using 'ldap_filter: uid=%u' make any difference? To clarify, it is the user supplied password that is getting cut short, and not the ldap_bind_pw password? Are you using a password-hash/olcPasswordHash on the server side, e.g. {CRYPT}? >I'm seeing the same output from saslauthd in /var/log/secure after >directing the auth.debug facility there (in rsyslog). > >The only way I could tell that the saslauthd was sending out only 7 chars >of the password was by looking at the tcpdump of the conversation with the >ldap server. > >(as an FYI for anyone else messing with this on RHEL, I had to disable >selinux because the restrictions wouldn't let postfix talk to a saslauthd >launched from the command line as root; once this is resolved I'll >re-enable selinux). > >________________________________ >From: Dan White <dwhite@xxxxxxx> >Sent: Tuesday, June 5, 2018 8:42 AM >To: Robert Werner >Cc: cyrus-sasl@xxxxxxxxxxxxxxxxxxxx >Subject: Re: Problem using saslauthd against ldap server ... > >On 06/04/18 22:42 +0000, Robert Werner wrote: >>When saslauthd tries to bind with the credentials, it is only sending 7 >>characters of the password. I've validated this by using Wireshark to >>examine the sasl communications. The ldap search for the user is >>successful and saslauthd is finding the correct user and binding as >>desired. But the auth fails, obviously, because the only 7 characters of >>the actual (9 character) password is sent. >> >>ldap_bind_dn: <user> >>ldap_bind_pw: <password> >>ldap_servers: ldap://lplds.ucmerced.edu >>ldap_search_base: dc=ucmerced,dc=edu >>ldap_filter: uid=%U >>ldap_version: 3 >>log_level: 7 > >>log_level: 7 >>pwcheck_method: saslauthd >>mech_list: plain login > >Is this problem reproducable with testsaslauthd and smtptest? > >Disable saslauthd caching (without -c) and run in debug (-d) mode for >additional output. Set 'debug: -1' (man 3 ldap_set_option), in >saslauthd.conf to increase libldap's output. > >Is this problem specific to a particular user name? If so, would you mind >sharing what that username is? -- Dan White |
lpmail01 03:19 PM ~ root (1004) : /usr/sbin/saslauthd -d -n 1 -m /run/saslauthd -a ldap -O /etc/saslauthd.conf saslauthd[11368] :main : num_procs : 1 saslauthd[11368] :main : mech_option: /etc/saslauthd.conf saslauthd[11368] :main : run_path : /run/saslauthd saslauthd[11368] :main : auth_mech : ldap saslauthd[11368] :ipc_init : using accept lock file: /run/saslauthd/mux.accept saslauthd[11368] :detach_tty : master pid is: 0 saslauthd[11368] :ipc_init : listening on socket: /run/saslauthd/mux saslauthd[11368] :main : using process model saslauthd[11368] :get_accept_lock : acquired accept lock saslauthd[11368] :rel_accept_lock : released accept lock ldap_simple_bind_s ldap_sasl_bind_s ldap_sasl_bind ldap_send_initial_request ldap_new_connection 1 1 0 ldap_int_open_connection ldap_connect_to_host: TCP ldap.ucmerced.edu:389 ldap_new_socket: 10 ldap_prepare_socket: 10 ldap_connect_to_host: Trying 169.236.10.31:389 ldap_pvt_connect: fd: 10 tm: 5 async: 0 ldap_ndelay_on: 10 attempting to connect: connect errno: 115 ldap_int_poll: fd: 10 tm: 5 ldap_is_sock_ready: 10 ldap_ndelay_off: 10 ldap_pvt_connect: 0 ldap_open_defconn: successful ldap_send_server_request ldap_result ld 0x557f05125ac0 msgid 1 wait4msg ld 0x557f05125ac0 msgid 1 (timeout 5000000 usec) wait4msg continue ld 0x557f05125ac0 msgid 1 all 1 ** ld 0x557f05125ac0 Connections: * host: ldap.ucmerced.edu port: 389 (default) refcnt: 2 status: Connected last used: Tue Jun 5 15:21:35 2018 ** ld 0x557f05125ac0 Outstanding Requests: * msgid 1, origid 1, status InProgress outstanding referrals 0, parent count 0 ld 0x557f05125ac0 request count 1 (abandoned 0) ** ld 0x557f05125ac0 Response Queue: Empty ld 0x557f05125ac0 response count 0 ldap_chkResponseList ld 0x557f05125ac0 msgid 1 all 1 ldap_chkResponseList returns ld 0x557f05125ac0 NULL ldap_int_select read1msg: ld 0x557f05125ac0 msgid 1 all 1 read1msg: ld 0x557f05125ac0 msgid 1 message type bind read1msg: ld 0x557f05125ac0 0 new referrals read1msg: mark request completed, ld 0x557f05125ac0 msgid 1 request done: ld 0x557f05125ac0 msgid 1 res_errno: 0, res_error: <>, res_matched: <> ldap_free_request (origid 1, msgid 1) ldap_parse_result ldap_msgfree ldap_search put_filter: "uid=rwerner2" put_filter: default put_simple_filter: "uid=rwerner2" ldap_build_search_req ATTRS: dn ldap_send_initial_request ldap_send_server_request ldap_result ld 0x557f05125ac0 msgid 2 wait4msg ld 0x557f05125ac0 msgid 2 (timeout 5000000 usec) wait4msg continue ld 0x557f05125ac0 msgid 2 all 1 ** ld 0x557f05125ac0 Connections: * host: ldap.ucmerced.edu port: 389 (default) refcnt: 2 status: Connected last used: Tue Jun 5 15:21:35 2018 ** ld 0x557f05125ac0 Outstanding Requests: * msgid 2, origid 2, status InProgress outstanding referrals 0, parent count 0 ld 0x557f05125ac0 request count 1 (abandoned 0) ** ld 0x557f05125ac0 Response Queue: Empty ld 0x557f05125ac0 response count 0 ldap_chkResponseList ld 0x557f05125ac0 msgid 2 all 1 ldap_chkResponseList returns ld 0x557f05125ac0 NULL ldap_int_select read1msg: ld 0x557f05125ac0 msgid 2 all 1 read1msg: ld 0x557f05125ac0 msgid 2 message type search-entry wait4msg ld 0x557f05125ac0 4 s 997762 us to go wait4msg continue ld 0x557f05125ac0 msgid 2 all 1 ** ld 0x557f05125ac0 Connections: * host: ldap.ucmerced.edu port: 389 (default) refcnt: 2 status: Connected last used: Tue Jun 5 15:21:35 2018 ** ld 0x557f05125ac0 Outstanding Requests: * msgid 2, origid 2, status InProgress outstanding referrals 0, parent count 0 ld 0x557f05125ac0 request count 1 (abandoned 0) ** ld 0x557f05125ac0 Response Queue: * msgid 2, type 100 ld 0x557f05125ac0 response count 1 ldap_chkResponseList ld 0x557f05125ac0 msgid 2 all 1 ldap_chkResponseList returns ld 0x557f05125ac0 NULL ldap_int_select read1msg: ld 0x557f05125ac0 msgid 2 all 1 read1msg: ld 0x557f05125ac0 msgid 2 message type search-result read1msg: ld 0x557f05125ac0 0 new referrals read1msg: mark request completed, ld 0x557f05125ac0 msgid 2 request done: ld 0x557f05125ac0 msgid 2 res_errno: 0, res_error: <>, res_matched: <> ldap_free_request (origid 2, msgid 2) adding response ld 0x557f05125ac0 msgid 2 type 101: ldap_parse_result ldap_get_dn ldap_first_attribute ldap_msgfree ldap_simple_bind_s ldap_sasl_bind_s ldap_sasl_bind ldap_send_initial_request ldap_send_server_request ldap_result ld 0x557f05125ac0 msgid 3 wait4msg ld 0x557f05125ac0 msgid 3 (timeout 5000000 usec) wait4msg continue ld 0x557f05125ac0 msgid 3 all 1 ** ld 0x557f05125ac0 Connections: * host: ldap.ucmerced.edu port: 389 (default) refcnt: 2 status: Connected last used: Tue Jun 5 15:21:35 2018 ** ld 0x557f05125ac0 Outstanding Requests: * msgid 3, origid 3, status InProgress outstanding referrals 0, parent count 0 ld 0x557f05125ac0 request count 1 (abandoned 0) ** ld 0x557f05125ac0 Response Queue: Empty ld 0x557f05125ac0 response count 0 ldap_chkResponseList ld 0x557f05125ac0 msgid 3 all 1 ldap_chkResponseList returns ld 0x557f05125ac0 NULL ldap_int_select read1msg: ld 0x557f05125ac0 msgid 3 all 1 read1msg: ld 0x557f05125ac0 msgid 3 message type bind read1msg: ld 0x557f05125ac0 0 new referrals read1msg: mark request completed, ld 0x557f05125ac0 msgid 3 request done: ld 0x557f05125ac0 msgid 3 res_errno: 49, res_error: <>, res_matched: <> ldap_free_request (origid 3, msgid 3) ldap_parse_result ldap_msgfree saslauthd[11368] :do_auth : auth failure: [user=rwerner2] [service=smtp] [realm=] [mech=ldap] [reason=Unknown] saslauthd[11368] :do_request : response: NO saslauthd[11368] :get_accept_lock : acquired accept lock
