> From: owner-postfix-us...@postfix.org [mailto:owner-postfix-
> us...@postfix.org] On Behalf Of Patrick Ben Koetter
> * Simon Brereton <simon.brere...@dada.net>:
> > > > Saslfinger -s says:
> > >
> > > saslfinger also reports much other, useful information which we
> need
> > > to debug your problem. Please post complete output.
> >
> > Gladly. I was hoping you'd step in. Just to let you know, I've
> tried
> > both auxprop and saslauthd as the pwcheck method.
> >
> > I even tried rimap - and with courier authdaemon logging turned up
> to
> > 2, I can see the MYSQL is call is successful (i.e. IMAP validates)
> and
> > still SASL says authentication failed.
>
> We'll simplify first, and make it feature-complete later.
>
>
> > root@jonty:~# saslfinger -s
> > saslfinger - postfix Cyrus sasl configuration Wed Apr 13 05:52:12
> BST
> > 2011
> > version: 1.0.4
> > mode: server-side SMTP AUTH
> >
> > -- basics --
> > Postfix: 2.7.1
> > System: Debian GNU/Linux 6.0 \n \l
> >
> > -- smtpd is linked to --
> > libsasl2.so.2 => /usr/lib/libsasl2.so.2 (0xb7672000)
> >
> > -- active SMTP AUTH and TLS parameters for smtpd --
> > broken_sasl_auth_clients = yes smtpd_sasl_auth_enable = yes
> > smtpd_sasl_local_domain = spamfreeisp.net
>
> $smtpd_sasl_local_domain required or because you found it on a
> website?
Probably the latter - although I don't think I've touched it much since you
helped me set it up about 5 years ago.
> > smtpd_sasl_security_options = noanonymous smtpd_tls_CAfile =
> > /root/certauth/cacert.pem smtpd_tls_auth_only = no
> smtpd_tls_cert_file
> > = /etc/postfix/ssl/mail.spamfreeisp.net.cert
> > smtpd_tls_key_file = /etc/postfix/ssl/mail.spamfreeisp.net.key
>
> Just as a sidenote: You might want to move your key and certs to
> /etc/ssl/...
> and own them root:ssl-cert and then "adduser postfix ssl-cert" to
> make it the "Debian way".
Good point. Will do that when I get to the end.
> > smtpd_tls_loglevel = 1
> > smtpd_tls_received_header = yes
> > smtpd_tls_session_cache_database =
> > btree:${queue_directory}/smtpd_scache
> > smtpd_tls_session_cache_timeout = 3600s smtpd_use_tls = yes
<SNIP>
> > -- content of /etc/postfix/sasl/smtpd.conf --
>
> Make this as follows and REMOVE the semi-colon at the end of your
> sql_select:-statement:
>
> pwcheck_method: auxprop
> mech_list: PLAIN LOGIN CRAM-MD5 DIGEST-MD5
> auxprop_plugin: sql
> sql_engine: mysql
> sql_hostnames: localhost
> sql_user: --- replaced ---
> sql_passwd: --- replaced ---
> sql_database: Mail
> sql_select: SELECT Password FROM MailAccounts WHERE Username =
> '%u@%r'
Done.
> > -- active services in /etc/postfix/master.cf -- # service type
> > private unpriv chroot wakeup maxproc command + args
> > # (yes) (yes) (yes) (never) (100)
> > smtp inet n - - - - smtpd -v
> > submission inet n - n - - smtpd
> > -o receive_override_options=no_address_mappings
> > -o content_filter=dksign:[127.0.0.1]:10028
> > -o smtpd_enforce_tls=yes
> > -o smtpd_sasl_auth_enable=yes
> > -o smtpd_client_restrictions=permit_sasl_authenticated,reject
>
> Disable TLS for the moment.
> What do you get when you run "postconf smtpd_delay_reject"?
smtpd_delay_reject = yes
> Post verbose smtpd log that shows an authentication attempt if AUTH
> still fails after the changes.
>
> Caution
>
> When posting logs of the SASL negotiations to public lists,
> please keep in
> mind that username/password information is trivial to recover
> from the
> base64-encoded form written to log files.
Part of my problem is that I can't get SASL logging verbosity to the point
where I can see the passwords! If I could, that would help.
Two attempts.
Apr 13 14:54:10 jonty postfix/master[28058]: reload -- version 2.7.1,
configuration /etc/postfix
Apr 13 14:54:10 jonty postfix/anvil[1821]: statistics: max connection rate
1/60s for (smtp:192.168.1.4) at Apr 13 14:51:58
Apr 13 14:54:10 jonty postfix/anvil[1821]: statistics: max connection count 1
for (smtp:192.168.1.4) at Apr 13 14:51:58
Apr 13 14:54:10 jonty postfix/anvil[1821]: statistics: max cache size 1 at Apr
13 14:51:58
Apr 13 14:54:33 jonty postfix/smtpd[1834]: connect from unknown[192.168.1.4]
Apr 13 14:54:46 jonty postfix/smtpd[1834]: warning: SASL authentication
failure: Password verification failed
Apr 13 14:54:46 jonty postfix/smtpd[1834]: warning: unknown[192.168.1.4]: SASL
PLAIN authentication failed: authentication failure
Apr 13 14:54:58 jonty postfix/smtpd[1834]: disconnect from unknown[192.168.1.4]
Apr 13 14:55:05 jonty postfix/smtpd[1838]: connect from unknown[192.168.1.4]
Apr 13 14:55:22 jonty postfix/smtpd[1838]: warning: SASL authentication
failure: Password verification failed
Apr 13 14:55:22 jonty postfix/smtpd[1838]: warning: unknown[192.168.1.4]: SASL
PLAIN authentication failed: authentication failure
Apr 13 14:55:25 jonty postfix/smtpd[1838]: disconnect from unknown[192.168.1.4]
Turning up the -v on the smtpd and showing the relevant portion...
Apr 13 14:58:57 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]: 220
mail.spamfreeisp.net ESMTP Postfix (2.7.1) (Debian/GNU)
Apr 13 14:58:57 jonty postfix/smtpd[1860]: xsasl_cyrus_server_create: SASL
service=smtp, realm=(null)
Apr 13 14:58:57 jonty postfix/smtpd[1860]: name_mask: noanonymous
Apr 13 14:59:03 jonty postfix/smtpd[1860]: < unknown[192.168.1.4]: ehlo
simon-dada
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]:
250-mail.spamfreeisp.net
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]:
250-PIPELINING
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]: 250-SIZE
20480000
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]: 250-ETRN
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]: 250-STARTTLS
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]: 250-AUTH
LOGIN CRAM-MD5 DIGEST-MD5 PLAIN
Apr 13 14:59:03 jonty postfix/smtpd[1860]: match_list_match: unknown: no match
Apr 13 14:59:03 jonty postfix/smtpd[1860]: match_list_match: 192.168.1.4: no
match
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]:
250-AUTH=LOGIN CRAM-MD5 DIGEST-MD5 PLAIN
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]:
250-ENHANCEDSTATUSCODES
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]: 250-8BITMIME
Apr 13 14:59:03 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]: 250 DSN
Apr 13 14:59:17 jonty postfix/smtpd[1860]: < unknown[192.168.1.4]: AUTH PLAIN
--Base64 string--
Apr 13 14:59:17 jonty postfix/smtpd[1860]: xsasl_cyrus_server_first:
sasl_method PLAIN, init_response --Base64 String--
Apr 13 14:59:17 jonty postfix/smtpd[1860]: xsasl_cyrus_server_first: decoded
initial response correctu...@correctdomain.net
Apr 13 14:59:17 jonty postfix/smtpd[1860]: warning: SASL authentication
failure: Password verification failed
Apr 13 14:59:17 jonty postfix/smtpd[1860]: warning: unknown[192.168.1.4]: SASL
PLAIN authentication failed: authentication failure
Apr 13 14:59:17 jonty postfix/smtpd[1860]: > unknown[192.168.1.4]: 535 5.7.8
Error: authentication failed: authentication failure
I know the Base64 string is correct.
I turned up mysql logging and did another test - and no query appeared in the
mysql log! In an effort to prove to myself, I did an imap login attempt (which
also uses mysql) and the query appears in the mysql log. It looks to me as if
SASL isn't talking to mysql (but then I had the same impression it wasn't
listening to the imap server when I tried rimap too).
