Postfix 结合 Cyrus saslauthd 实现SMTP认证失败的排查求助

大家好，我现在正在尝试通过Postfix + Cyrus + saslauthd + PAM + MySQL配置SMTPD的连接认证，目前遇到了瓶颈，想请各位帮忙看看怎么进一步定位问题。

已完成的验证工作 #

• 目前courier-pop3和courier-imap结合MySQL的认证是完全正常的
• 单独测试saslauthd也没问题：执行命令testsaslauthd -u "me@examplecom" -p "password" -r "example.com" -s smtp，返回结果是0: OK "Success."，而且MySQL日志里能看到对应的查询语句：

758 Connect postfix@localhost on postfix
758 Init DB postfix
758 Query   SELECT password FROM mailbox WHERE username = 'me@example.com'
758 Query   SELECT password FROM mailbox WHERE username = 'me@example.com'
758 Quit
759 Connect postfix@localhost on postfix
759 Init DB postfix
759 Query   SELECT 0, password FROM mailbox WHERE username = 'me@example.com'
759 Quit

但奇怪的是，当我通过SMTP客户端尝试认证时，MySQL日志里完全看不到对应的查询请求，我怀疑是SASL的配置哪里出了问题。之前试过pwcheck_method auxprop和authdaemond这两种方式，但都没解决问题。

开启Debug后的mail.log片段 #

我已经打开了Postfix的debug日志，用户名和密码都是正确的，但日志里只显示认证失败，没有更详细的原因：

postfix/smtpd[26153]: connect from client.example.com[10.0.0.1]
postfix/smtpd[26153]: smtp_stream_setup: maxtime=300 enable_deadline=0
postfix/smtpd[26153]: match_hostname: client.example.com ~? all
postfix/smtpd[26153]: match_hostaddr: 10.0.0.1 ~? all
postfix/smtpd[26153]: match_list_match: client.example.com: no match
postfix/smtpd[26153]: match_list_match: 10.0.0.1: no match
postfix/smtpd[26153]: send attr request = connect
postfix/smtpd[26153]: send attr ident = smtp:10.0.0.1
postfix/smtpd[26153]: private/anvil: wanted attribute: status
postfix/smtpd[26153]: input attribute name: status
postfix/smtpd[26153]: input attribute value: 0
postfix/smtpd[26153]: private/anvil: wanted attribute: count
postfix/smtpd[26153]: input attribute name: count
postfix/smtpd[26153]: input attribute value: 1
postfix/smtpd[26153]: private/anvil: wanted attribute: rate
postfix/smtpd[26153]: input attribute name: rate
postfix/smtpd[26153]: input attribute value: 1
postfix/smtpd[26153]: private/anvil: wanted attribute: (list terminator)
postfix/smtpd[26153]: input attribute name: (end)
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 220 server.example.com ESMTP Postfix (Ubuntu)
postfix/smtpd[26153]: xsasl_cyrus_server_create: SASL service=smtp, realm=(null)
postfix/smtpd[26153]: name_mask: noanonymous
postfix/smtpd[26153]: watchdog_pat: 0x7f93f9fd1a20
postfix/smtpd[26153]: < client.example.com[10.0.0.1]: ehlo client.example.com
postfix/smtpd[26153]: match_list_match: client.example.com: no match
postfix/smtpd[26153]: match_list_match: 10.0.0.1: no match
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-server.example.com
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-PIPELINING
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-SIZE 40960000
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-VRFY
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-ETRN
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-STARTTLS
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-AUTH DIGEST-MD5 CRAM-MD5 NTLM PLAIN LOGIN
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-AUTH=DIGEST-MD5 CRAM-MD5 NTLM PLAIN LOGIN
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-ENHANCEDSTATUSCODES
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250-8BITMIME
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 250 DSN
postfix/smtpd[26153]: watchdog_pat: 0x7f93f9fd1a20
postfix/smtpd[26153]: < client.example.com[10.0.0.1]: auth login
postfix/smtpd[26153]: xsasl_cyrus_server_first: sasl_method login
postfix/smtpd[26153]: xsasl_cyrus_server_auth_response: uncoded server challenge: Username:
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 334 VXNlcm5hbWU6
postfix/smtpd[26153]: < client.example.com[10.0.0.1]: md5encoded
postfix/smtpd[26153]: xsasl_cyrus_server_next: decoded response: me@example.com
postfix/smtpd[26153]: xsasl_cyrus_server_auth_response: uncoded server challenge: Password:
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 334 UGFzc3dvcmQ6
postfix/smtpd[26153]: < client.example.com[10.0.0.1]: md5encoded
postfix/smtpd[26153]: xsasl_cyrus_server_next: decoded response: password
postfix/smtpd[26153]: warning: client.example.com[10.0.0.1]: SASL login authentication failed: authentication failure
postfix/smtpd[26153]: > client.example.com[10.0.0.1]: 535 5.7.8 Error: authentication failed: authentication failure
postfix/smtpd[26153]: watchdog_pat: 0x7f93f9fd1a20

saslfinger的完整输出信息 #

我也用saslfinger导出了当前的SASL和Postfix配置，供大家参考：

saslfinger - postfix Cyrus sasl configuration
version: 1.0.4
mode: server-side SMTP AUTH

-- basics --
Postfix: 2.9.6
System: Ubuntu 12.04.5 LTS \n \l

-- smtpd is linked to --
libsasl2.so.2 => /usr/lib/x86_64-linux-gnu/libsasl2.so.2 (0x00007f0f4de7f000)

-- active SMTP AUTH and TLS parameters for smtpd --
broken_sasl_auth_clients = yes
smtpd_sasl_auth_enable = yes
smtpd_sasl_authenticated_header = no
smtpd_sasl_local_domain =
smtpd_sasl_path = /etc/postfix/sasl:/usr/lib/sasl2
smtpd_sasl_security_options = noanonymous
smtpd_sasl_type = cyrus
smtpd_tls_cert_file = /etc/ssl/certs/ssl-cert-snakeoil.pem
smtpd_tls_key_file = /etc/ssl/private/ssl-cert-snakeoil.key
smtpd_tls_loglevel = 1
smtpd_tls_received_header = no
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtpd_use_tls = yes

-- listing of /usr/lib/sasl2 --
total 28
drwxr-xr-x  2 root root  4096 Jan  9 23:05 .
drwxr-xr-x 60 root root 12288 Jan  8 17:05 ..
-rw-r--r--  1 root root     4 Jan  8 18:33 berkeley_db.active
-rw-r--r--  1 root root     4 Jan 28  2020 berkeley_db.txt
-rw-r--r--  1 root root    63 Jan 10 22:42 smtpd.conf

-- listing of /etc/postfix/sasl --
total 16
drwxr-xr-x 2 root root 4096 Jan 10 22:42 .
drwxr-xr-x 3 root root 4096 Jan 10 18:56 ..
-rw-r--r-- 1 root root   63 Jan 10 22:42 smtpd.conf
-rw-r--r-- 1 root root  493 Jan 10 16:19 smtpd.conf~

-- content of /usr/lib/sasl2/smtpd.conf --
pwcheck_method: saslauthd
log_level: 7
mech_list: plain login

-- content of /etc/postfix/sasl/smtpd.conf --
pwcheck_method: saslauthd
log_level: 7
mech_list: plain login

-- content of /etc/postfix/sasl/smtpd.conf --
pwcheck_method: saslauthd
log_level: 7
mech_list: plain login

-- active services in /etc/postfix/master.cf --
# service type  private unpriv  chroot  wakeup  maxproc command + args
#               (yes)   (yes)   (yes)   (never) (100)
smtp      inet  n       -       n       -       -       smtpd
pickup    fifo  n       -       -       60      1       pickup
cleanup   unix  n       -       -       -       0       cleanup
qmgr      fifo  n       -       n       300     1       qmgr
tlsmgr    unix  -       -       -       1000?   1       tlsmgr
rewrite   unix  -       -       -       -       -       trivial-rewrite
bounce    unix  -       -       -       -       0       bounce
defer     unix  -       -       -       -       0       bounce
trace     unix  -       -       -       -       0       bounce
verify    unix  -       -       -       -       1       verify
flush     unix  n       -       -       1000?   0       flush
proxymap  unix  -       -       n       -       -       proxymap
proxywrite unix -       -       n       -       1       proxymap
smtp      unix  -       -       -       -       -       smtp
relay     unix  -       -       -       -       -       smtp
showq     unix  n       -       -       -       -       showq
error     unix  -       -       -       -       -       error
retry     unix  -       -       -       -       -       error
discard   unix  -       -       -       -       -       discard
local     unix  -       n       n       -       -       local
virtual   unix  -       n       n       -       -       virtual
lmtp      unix  -       -       -       -       -       lmtp
anvil     unix  -       -       -       -       1       anvil
scache    unix  -       -       -       -       1       scache
maildrop  unix  -       n       n       -       -       pipe
flags=DRhu user=vmail argv=/usr/bin/maildrop -d ${recipient}
uucp      unix  -       n       n       -       -       pipe
flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail ($recipient)
ifmail    unix  -       n       n       -       -       pipe
flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
bsmtp     unix  -       n       n       -       -       pipe
flags=Fq. user=bsmtp argv=/usr/lib/bsmtp/bsmtp -t$nexthop -f$sender $recipient
scalemail-backend unix  -   n   n   -   2   pipe
flags=R user=scalemail argv=/usr/lib/scalemail/bin/scalemail-store ${nexthop} ${user} ${extension}
mailman   unix  -       n       n       -       -       pipe
flags=FR user=list argv=/usr/lib/mailman/bin/postfix-to-mailman.py
${nexthop} ${user}

-- mechanisms on localhost --
250-AUTH DIGEST-MD5 CRAM-MD5 NTLM PLAIN LOGIN
250-AUTH=DIGEST-MD5 CRAM-MD5 NTLM PLAIN LOGIN

-- end of saslfinger output --

想请教的问题 #

目前我能看到的信息只有SMTP认证失败，但找不到更深层的原因，想问问大家有没有什么办法可以获取更详细的调试日志，或者有没有什么配置细节我可能漏掉了？

备注：内容来源于stack exchange，提问作者Mathew