[Dovecot] Logging authentication failures when Dovecot's auth service used to authenticate postfix smtpd
Hello,
tl;dr: Is there a way to get dovecot's auth to log failed smtp authentications without having to switch on "auth_verbose"? postfix version 2.11.0 and dovecot version 2.2.12
I'm currently migrating my postfix+courier to postfix+dovecot and so far it's working as expected. Except for logging smtp login failures.
Despite Postfix logging successful authentications (see sample below), it doesn't log failed smtp logins. Feb 25 22:28:53 mailer2 postfix/submission[20274]: C981B20198: client=A-B-C-D.*****.net[A.B.C.D]:63107, sasl_method=PLAIN, sasl_username=joe@example.net
And since my postfix setup authenticates virtual users through Dovecot's auth, I thought maybe dovecot could report smtp login failures the same way it reports imap and pop3 login failures. Below is a sample extracted from "info_log_path" after several imap and pop3 login failures. (Obviously the IP 255.... is made up and irrelevant for this mater).
# begin extract "/var/log/dovecot-info.log" 2014-02-27 21:14:26 auth: Info: passwd-file(joe@example.net,255.255.255.255,<Y0lbzmnzfwAuQV80>): Password mismatch 2014-02-27 21:16:46 auth: Info: passwd-file(foobar,255.255.255.255,<Y0lbzmnzfwAuQV80>): unknown user 2014-02-27 21:52:00 auth: Info: passwd-file(foo@example.net,255.255.255.255,<0Su6VGrzGwAuQV80>): unknown user 2014-02-27 21:53:35 auth: Info: plain(?,255.255.255.255,<0Su6VGrzGwAuQV80>): Empty username 2014-02-27 21:53:55 auth: Info: plain(?,255.255.255.255,<0Su6VGrzGwAuQV80>): Username character disallowed by auth_username_chars: 0x5c (username: \0) 2014-02-27 22:08:05 auth: Info: plain(?,255.255.255.255): invalid input 2014-02-27 22:09:36 auth: Info: passwd-file(joe@example.net,255.255.255.255): Password mismatch 2014-02-27 22:09:53 auth: Info: login(?,255.255.255.255): Empty username # end extract
I've tried adding "-L -o info_log_path=/var/log/dovecot-info.log" to the both auth and auth-worker services but that yield nothing.
----------------------%<--------------------------------
auth_mechanisms = plain login auth_verbose = yes base_dir = /var/run/dovecot/ info_log_path = /var/log/dovecot-info.log log_path = /var/log/dovecot.log log_timestamp = "%Y-%m-%d %H:%M:%S "
passdb { args = scheme=CRYPT username_format=%u /etc/dovecot/virtual_users driver = passwd-file }
userdb { args = username_format=%u /etc/dovecot/virtual_users default_fields = uid=vmail gid=vmail driver = passwd-file override_fields = home=/home/vmail/%d/%u result_failure = return-fail result_internalfail = return-fail }
service auth-worker { executable = auth -w -L -o info_log_path=/var/log/dovecot-info.log }
service auth { executable = auth -L -o info_log_path=/var/log/dovecot-info.log unix_listener /var/spool/postfix/private/dovecot-auth { group = postfix user = postfix mode = 0660 } }
service lmtp { executable = lmtp -L -o info_log_path=/var/log/dovecot-info.log unix_listener /var/spool/postfix/private/dovecot-lmtp { group = postfix user = postfix mode = 0660 } }
---------------------->%--------------------------------
The relevant postfix config is ...
smtpd_sasl_type = dovecot smtpd_sasl_path = private/dovecot-auth virtual_transport = lmtp:unix:private/dovecot-lmtp
Please ignore my previous email. I guess the lack of sleep has taken the best of me.
What I was trying to achieve is, to have a log entry for every authentication attempted regardless of its success or failure. And from that log I should extract the client's IP.
My setup authenticates imap and pop3 users through a "passwd-file" authentication database. And postfix is setup to authenticate submissions through the dovecot socket "auth". So far so good.
Currently ("auth_verbose = yes" and "auth_debug = no") when a client connects to either imap, pop3 or submission/smtpd and fails to authenticate, Dovecot *immediately* logs the failure as below.
auth: Info: passwd-file(...) ... auth: Info: plain(...) ... auth: Info: login(...) ...
And when a client connects to either imap and pop3 successfully, Docecot *immediately* logs that too.
The reason I enforce _immediately_ is because successful submission/smtpd authentications are not logged until after postfix receives the command "RCPT TO". And as such, the following sequence of commands will not be logged by Dovecot, and will only be logged as connect+disconnect by Postfix.
connect to Postfix/Submission/587 Send EHLO... Send STARTTLS Send AUTH... Wait success Send QUIT Goto connect
And below is what postfix's log will show after the commands above are executed by the remote client.
... postfix/smtpd[1234]: connect from host.domain.tld[0.0.0.0] ... postfix/smtpd[1234]: disconnect from host.domain.tld[0.0.0.0] ... postfix/smtpd[5678]: connect from host.domain.tld[0.0.0.0] ... postfix/smtpd[5678]: disconnect from host.domain.tld[0.0.0.0]
So there's no trace in Postfix's log neither in Dovecot's log of the successful authentication because the client quit the connection after AUTH and before RCPT TO.
And finally, in order to have every AUTH logged (imap, pop3 and smtpd) I could set auth_verbose=yes and auth_debug=yes and use syslog to discard the excess debug messages keeping only the line that reads auth: Debug: client in: AUTH ... rip=<...> ... or instead I could keep auth_verbose=yes and auth_debug=no and patch src/auth/auth-client-connection.c (see attachment).
Am 28.02.2014 16:57, schrieb MV:
Please ignore my previous email. I guess the lack of sleep has taken the best of me.
What I was trying to achieve is, to have a log entry for every authentication attempted regardless of its success or failure. And from that log I should extract the client's IP.
My setup authenticates imap and pop3 users through a "passwd-file" authentication database. And postfix is setup to authenticate submissions through the dovecot socket "auth". So far so good.
Currently ("auth_verbose = yes" and "auth_debug = no") when a client connects to either imap, pop3 or submission/smtpd and fails to authenticate, Dovecot *immediately* logs the failure as below.
in case of SASL postfix is talking via a unix socket so there is no connection IP dovecot knows about
service auth { unix_listener /var/spool/postfix/private/auth { mode = 0660 user = postfix group = postfix } }
participants (2)
-
MV
-
Reindl Harald