-1

I have a weird problem trying to autheticate postfix against saslauthd.

I am on a standard linux system: Linux smswtc 3.16.0-4-amd64 #1 SMP Debian 3.16.51-3 (2017-12-13) x86_64 GNU/Linux

postfix configuration is very basic

root@smswtc:/etc/postfix# cat /etc/postfix/main.cf |grep -v "#" |grep -v ^$

smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU) 

biff = no    

append_dot_mydomain = no 

readme_directory = no    

smtpd_tls_cert_file=/etc/ssl/certs/ssl-cert-snakeoil.pem    

smtpd_tls_key_file=/etc/ssl/private/ssl-cert-snakeoil.key    

smtpd_use_tls=yes 

smtpd_tls_session_cache_database =   btree:${data_directory}/smtpd_scache 

smtp_tls_session_cache_database    = btree:${data_directory}/smtp_scache 

smtpd_relay_restrictions = permit_mynetworks permit_sasl_authenticated defer_unauth_destination    

myhostname = smswtc 

alias_maps = hash:/etc/aliases 

alias_database = hash:/etc/aliases 

myorigin = /etc/mailname 

mydestination = wtc99.com, localhost, localhost.localdomain, localhost relayhost = out.alice.sm    

mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128 10.0.0.0/8     

mailbox_command = procmail -a "$EXTENSION" 

mailbox_size_limit = 0    

recipient_delimiter = + 

inet_interfaces = all 

smtpd_sasl_local_domain = "" 

smtpd_sasl_auth_enable = yes 

broken_sasl_auth_clients = yes 

relay_domains = wtc99.com 

smtpd_recipient_restrictions = permit_sasl_authenticated, permit_mynetworks, reject_unauth_destination

root@smswtc:/etc/postfix# cat sasl/smtpd.conf 

pwcheck_method: saslauthd

mech_list: PLAIN LOGIN

saslauthd configuration is again very basic:

/etc/default/saslauthd-postfix

root@smswtc:/etc/postfix# cat /etc/default/saslauthd-postfix 

START=yes

DESC="SASL Auth. Daemon for Postfix"

NAME="saslauthd"      # max. 15 char.

OPTIONS="-c -m /var/spool/postfix/var/run/saslauthd"

I have started saslauthd in debug mode and I made a little test

1) basic sasl auth test ----------> sasl auth test is OK

request -

root@smswtc:/var/log# testsaslauthd  -u user -p pass -r smswtc -f /var/spool/postfix/var/run/saslauthd/mux
0: OK "Success."

  • saslauthd[9759] :rel_accept_lock : released accept lock

    saslauthd[9758] :get_accept_lock : acquired accept lock

    saslauthd[9759] :cache_get_rlock : attempting a read lock on slot: 138

    saslauthd[9759] :cache_lookup : [login=user] [service=imap] [realm=smswtc]: found with valid passwd

    saslauthd[9759] :cache_un_lock : attempting to release lock on slot: 138

    saslauthd[9759] :do_auth : auth success (cached): [user=user] [service=imap] [realm=smswtc]

    saslauthd[9759] :do_request : response: OK

The I have tried authentication through in postfix. No success:

2) postfix auth ---------> NOT OK

request -

smpp@smsbg:~/smsqueue$ telnet 10.1.0.249 25

Trying 10.1.0.249...

Connected to 10.1.0.249.

Escape character is '^]'.

220 smswtc ESMTP Postfix (Debian/GNU)

ehlo smpp

250-smswtc

250-PIPELINING 

250-SIZE 10240000

250-VRFY

250-ETRN

250-STARTTLS

250-AUTH PLAIN LOGIN

250-AUTH=PLAIN LOGIN

250-ENHANCEDSTATUSCODES

250-8BITMIME

250 DSN

AUTH PLAIN dXNlcm5hbWUAdXNlcgBwYXNz

535 5.7.8 Error: authentication failed: authentication failure

quit

221 2.0.0 Bye

Connection closed by foreign host.

postfix mail log -

root@smswtc:/etc/postfix# cat /var/log/mail.log

Feb 15 10:24:31 smswtc postfix/smtpd[10399]: connect from unknown[10.1.1.249]
Feb 15 10:24:40 smswtc postfix/smtpd[10399]: warning: SASL authentication failure: Requested identity not authenticated identity
Feb 15 10:24:40 smswtc postfix/smtpd[10399]: warning: unknown[10.1.1.249]: SASL PLAIN authentication failed: authentication failure
Feb 15 10:24:42 smswtc postfix/smtpd[10399]: disconnect from unknown[10.1.1.249]

Postfix complains about failed authentication but log from saslauthd shows that authetication was successful:

s

aslauthd[9767] :get_accept_lock : acquired accept lock

saslauthd[9768] :rel_accept_lock : released accept lock

saslauthd[9768] :cache_get_rlock : attempting a read lock on slot: 2

saslauthd[9768] :cache_lookup    : [login=user] [service=smtp] [realm=""]: found with valid passwd

saslauthd[9768] :cache_un_lock   : attempting to release lock on slot: 2

saslauthd[9768] :do_auth         : auth success (cached): [user=user] [service=smtp] [realm=""]

saslauthd[9768] :do_request      : response: OK

Also from strace log of the smtpd process of process it is clear that it receives OK back from saslauthd

root@smswtc:/etc/postfix# strace -f -s 512 -p 10399

.....

write(10, "250-smswtc\r\n250-PIPELINING\r\n250-SIZE 10240000\r\n250-VRFY\r\n250-ETRN\r\n250-STARTTLS\r\n250-AUTH PLAIN LOGIN\r\n250-AUTH=PLAIN LOGIN\r\n250-ENHANCEDSTATUSCODES\r\n250-8BITMIME\r\n250 DSN\r\n", 173) = 173

poll([{fd=10, events=POLLIN}], 1, 300000) = 1 ([{fd=10, revents=POLLIN}])
read(10, "AUTH PLAIN dXNlcm5hbWUAdXNlcgBwYXNz\r\n", 4096) = 37

socket(PF_LOCAL, SOCK_STREAM, 0)        = 12

connect(12, {sa_family=AF_LOCAL, sun_path="/var/run/saslauthd/mux"}, 110) = 0

**writev(12, [{"\0\4user\0\4pass\0\4smtp\0\2\"\"", 22}], 1) = 22

read(12, "\0\2", 2)                     = 2

read(12, "OK", 2)                       = 2

close(12)                               = 0**

sendto(8, "<20>Feb 15 10:24:40 postfix/smtpd[10399]: warning: SASL authentication failure: Requested identity not authenticated identity", 125, MSG_NOSIGNAL, NULL, 0) = 125

sendto(8, "<20>Feb 15 10:24:40 postfix/smtpd[10399]: warning: unknown[10.1.1.249]: SASL PLAIN authentication failed: authentication failure", 128, MSG_NOSIGNAL, NULL, 0) = 128

poll([{fd=10, events=POLLOUT}], 1, 300000) = 1 ([{fd=10, revents=POLLOUT}])

....

Any idea?

HBruijn
  • 77,029
  • 24
  • 135
  • 201
Andrew Highlanders
  • 1

1 Answers1

0

dirty fix

from smtpd.c

/* smtpd_sasl_auth_cmd_wrapper - smtpd_sasl_auth_cmd front-end */

static int smtpd_sasl_auth_cmd_wrapper(SMTPD_STATE *state, int argc, SMTPD_TOKEN *argv)

from smtpd_sasl_proto.c

/* smtpd_sasl_auth_cmd - process AUTH command */

int smtpd_sasl_auth_cmd(SMTPD_STATE *state, int argc, SMTPD_TOKEN *argv)

from smtpd_sasl_glue.c

/* smtpd_sasl_authenticate - per-session authentication */

int smtpd_sasl_authenticate(SMTPD_STATE *state, const char *sasl_method, const char *init_response) { int status; const char *sasl_username;

.........

    /*
     * HERE WE ARE.
     * it seems that status is always != XSASL_AUTH_DONE for some unknown reason !!!!!!!
     * I am not too much into this code but the problem is here
     * Even though saslauthd answer OK status is not the right value so authentication fails.

     * for my golas I have commented the code so to skip check (very dirty hack)
     * and recompiled postfsix from scratch
     */

if (status != XSASL_AUTH_DONE) {
    msg_warn("%s: SASL %s authentication failed: %s",
             state->namaddr, sasl_method,
             STR(state->sasl_reply));
    /* RFC 4954 Section 6. */
    if (status == XSASL_AUTH_TEMP)
        smtpd_chat_reply(state, "454 4.7.0 Temporary authentication failure: %s",
                         STR(state->sasl_reply));
    else
        smtpd_chat_reply(state, "535 5.7.8 Error: authentication failed: %s",
                         STR(state->sasl_reply));
    return (-1);
}

..........

return (0);

}

Andrew Highlanders
  • 1