使用 Office365 作为中继服务器的 Postfix 上的 SASL 身份验证失败
Posted
技术标签:
【中文标题】使用 Office365 作为中继服务器的 Postfix 上的 SASL 身份验证失败【英文标题】：SASL Authentication Failed on Postfix as relay server with office365 【发布时间】：2019-02-09 21:16:23 【问题描述】：我正在将 postfix 服务器设置为 Office 365 中帐户的中继。
我配置主文件/etc/postfix/main.cf如下：
relayhost = [smtp.office365.com]:587
smtp_sasl_auth_enable = yes
smtp_sasl_password_maps = hash:/etc/postfix/sasl_passwd
smtp_sasl_mechanism_filter = login
smtp_use_tls = yes
smtp_always_send_ehlo = yes
#smtp_tls_security_level = secure
smtp_tls_security_level = may
smtp_tls_mandatory_protocols = TLSv1
smtp_tls_mandatory_ciphers = high
smtp_tls_secure_cert_match = nexthop
#Check that this path exists -- these are the certificates used by TLS
smtp_tls_CAfile = /etc/pki/tls/certs/ca-bundle.crt
#Set the sasl options
smtp_sasl_security_options = noanonymous
sender_canonical_maps = regexp:/etc/postfix/sender_canonical
还做了一个sasl_password文件：
[smtp.office365.com]:587 username@domain.com:thepassword
并应用了 postmap 命令：
postmap sasl_passwd
消息未传递，日志显示下一条消息
Aug 29 11:22:04 relaysmtp postfix/error[13501]: 0CA2C82CD1: to=<username@domain.com>, relay=none, delay=6538, delays=6538/0/0/0.01, dsn=4.7.3, status=deferred (delivery temporarily suspended: SASL authentication failed; server smtp.office365.com[40.102.32.146] said: 535 5.7.3 Authentication unsuccessful [PT1sdsaoPP.akpr0.prod.outlook.com])
CentOS 6.10 中的 postfix 版本是 3.2.3
我将 Postfix 的日志配置为更详细的输出；然后我用另一台主机的 Telnet 命令进行了测试。 我将粘贴原语和后缀的输出，用符号分隔：
telnet 192.168.0.10 25
Trying 192.168.0.10...
Connected to 192.168.0.10.
Escape character is '^]'.
220 **************************************
Sep 4 18:28:37 relaysmtp postfix/smtpd[9402]: < unknown[192.168.0.15]: quit
Sep 4 18:28:37 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 221 2.0.0 Bye
Sep 4 18:28:37 relaysmtp postfix/smtpd[9402]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? 0.0.0.0/0
Sep 4 18:28:37 relaysmtp postfix/smtpd[9402]: match_hostaddr: smtpd_client_event_limit_exceptions: 192.168.0.15 ~? 0.0.0.0/0
Sep 4 18:28:37 relaysmtp postfix/smtpd[9402]: disconnect from unknown[192.168.0.15] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Sep 4 18:28:37 relaysmtp postfix/smtpd[9402]: master_notify: status 1
Sep 4 18:28:37 relaysmtp postfix/smtpd[9402]: connection closed
Sep 4 18:28:37 relaysmtp postfix/smtpd[9402]: proxymap stream disconnect
Sep 4 18:28:37 relaysmtp postfix/smtpd[9402]: rewrite stream disconnect
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: connection established
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: master_notify: status 0
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: name_mask: resource
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: name_mask: software
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: connect from unknown[192.168.0.15]
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: match_list_match: unknown: no match
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: match_list_match: 192.168.0.15: no match
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: match_list_match: unknown: no match
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: match_list_match: 192.168.0.15: no match
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: smtp_stream_setup: maxtime=300 enable_deadline=0
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? 0.0.0.0/0
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: match_hostaddr: smtpd_client_event_limit_exceptions: 192.168.0.15 ~? 0.0.0.0/0
Sep 4 18:28:46 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 220 relay.domain.com ESMTP Postfix
---------------------------------------------------------------------------------------------------------------------------
ehlo localhost
250-relay.domain.com
250-PIPELINING
250-SIZE 10240000
250-VRFY
250-ETRN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: < unknown[192.168.0.15]: ehlo localhost
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: match_list_match: unknown: no match
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: match_list_match: 192.168.0.15: no match
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250-relay.domain.comhos
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250-PIPELINING
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250-SIZE 10240000
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250-VRFY
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250-ETRN
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250-ENHANCEDSTATUSCODES
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250-8BITMIME
Sep 4 18:29:44 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250 DSN
-----------------------------------------------------------------------------------------------------------------------
mail from: <username@domain.com>
250 2.1.0 Ok
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: < unknown[192.168.0.15]: mail from: <username@domain.com>
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: extract_addr: input: <username@domain.com>
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: smtpd_check_addr: addr=username@domain.com
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: ctable_locate: leave existing entry key ?username@domain.com
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: extract_addr: in: <username@domain.com>, result: username@domain.com
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: smtpd_check_rewrite: trying: permit_inet_interfaces
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: permit_inet_interfaces: unknown 192.168.0.15
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: fsspace: .: block size 4096, blocks free 2121461
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: smtpd_check_queue: blocks 4096 avail 2121461 min_free 0 msg_size_limit 10240000
Sep 4 18:33:21 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250 2.1.0 Ok
----------------------------------------------------------------------------------------------------------------------------
rcpt to: <otheruser@testmail.com>
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: < unknown[192.168.0.15]: rcpt to: <otheruser@testmail.com>
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: extract_addr: input: <otheruser@testmail.com>
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: smtpd_check_addr: addr=otheruser@testmail.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: connect to subsystem private/rewrite
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr request = rewrite
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr rule = local
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr address = username@domain.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: flags
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: flags
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: 0
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: address
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: address
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: username@domain.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: (list terminator)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: (end)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: rewrite_clnt: local: username@domain.com -> username@domain.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr request = rewrite
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr rule = local
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr address = otheruser@testmail.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: flags
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: flags
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: 0
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: address
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: address
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: otheruser@testmail.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: (list terminator)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: (end)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: rewrite_clnt: local: otheruser@testmail.com -> otheruser@testmail.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr request = resolve
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr sender = username@domain.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr address = otheruser@testmail.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: flags
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: flags
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: 0
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: transport
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: transport
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: smtp
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: nexthop
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: nexthop
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: [smtp.office365.com]:587
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: recipient
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: recipient
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: otheruser@testmail.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: flags
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: flags
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: 4096
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: private/rewrite socket: wanted attribute: (list terminator)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: (end)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: resolve_clnt: `username@domain.com' -> `otheruser@testmail.com' -> transp=`smtp' host=`[smtp.office365.com]:587' rcpt=`otheruser@testmail.com' flags= class=default
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: ctable_locate: install entry key username@domain.com?otheruser@testmail.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: extract_addr: in: <otheruser@testmail.com>, result: otheruser@testmail.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: >>> START Recipient address RESTRICTIONS <<<
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: generic_checks: name=permit_mynetworks
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: permit_mynetworks: unknown 192.168.0.15
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_hostname: mynetworks: unknown ~? 0.0.0.0/0
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_hostaddr: mynetworks: 192.168.0.15 ~? 0.0.0.0/0
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: smtpd_acl_permit: checking smtpd_log_access_permit_actions settings
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_list_match: permit_mynetworks: no match
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: smtpd_acl_permit: smtpd_log_access_permit_actions: no match
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: generic_checks: name=permit_mynetworks status=1
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: >>> END Recipient address RESTRICTIONS <<<
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: >>> CHECKING Recipient address VALIDATION MAPS <<<
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: ctable_locate: leave existing entry key username@domain.com?otheruser@testmail.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: maps_find: recipient_canonical_maps: otheruser@testmail.com: not found
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_string: mydestination: testmail.com ~? relay.domain.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_string: mydestination: testmail.com ~? localhost.domain.comf
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_string: mydestination: testmail.com ~? localhost
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_list_match: testmail.com: no match
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: maps_find: recipient_canonical_maps: @testmail.com: not found
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: mail_addr_find: otheruser@testmail.com -> (not found)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: maps_find: canonical_maps: otheruser@testmail.com: not found
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_string: mydestination: testmail.com ~? relay.domain.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_string: mydestination: testmail.com ~? localhost.domain.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_string: mydestination: testmail.com ~? localhost
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_list_match: testmail.com: no match
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: maps_find: canonical_maps: @testmail.com: not found
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: mail_addr_find: otheruser@testmail.com -> (not found)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: maps_find: virtual_alias_maps: otheruser@testmail.com: not found
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_string: mydestination: testmail.com ~? relay.domain.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_string: mydestination: testmail.com ~? localhost.domain.com
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_string: mydestination: testmail.com ~? localhost
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: match_list_match: testmail.com: no match
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: maps_find: virtual_alias_maps: @testmail.com: not found
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: mail_addr_find: otheruser@testmail.com -> (not found)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: before input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: after input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: name_mask: sendmail
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: name_mask: verify
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: connect to subsystem public/cleanup
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: public/cleanup socket: wanted attribute: queue_id
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: queue_id
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute value: 64FFA85196
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: public/cleanup socket: wanted attribute: (list terminator)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: input attribute name: (end)
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: send attr flags = 178
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: 64FFA85196: client=unknown[192.168.0.15]
Sep 4 18:34:16 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250 2.1.5 Ok
-----------------------------------------------------------------------------------------------------------------------------------
data
354 End data with <CR><LF>.<CR><LF>
Sep 4 18:35:40 relaysmtp postfix/smtpd[9402]: < unknown[192.168.0.15]: data
Sep 4 18:35:40 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 354 End data with <CR><LF>.<CR><LF>
--------------------------------------------------------------------------------------------------------------------------------------
subject: Test mail
Test message
.
Sep 4 18:36:43 relaysmtp postfix/cleanup[9488]: 64FFA85196: message-id=<>
Sep 4 18:36:43 relaysmtp postfix/smtpd[9402]: public/cleanup socket: wanted attribute: status
Sep 4 18:36:43 relaysmtp postfix/smtpd[9402]: input attribute name: status
Sep 4 18:36:43 relaysmtp postfix/smtpd[9402]: input attribute value: 0
Sep 4 18:36:43 relaysmtp postfix/smtpd[9402]: public/cleanup socket: wanted attribute: reason
Sep 4 18:36:43 relaysmtp postfix/smtpd[9402]: input attribute name: reason
Sep 4 18:36:43 relaysmtp postfix/smtpd[9402]: input attribute value: (end)
Sep 4 18:36:43 relaysmtp postfix/smtpd[9402]: public/cleanup socket: wanted attribute: (list terminator)
Sep 4 18:36:43 relaysmtp postfix/smtpd[9402]: input attribute name: (end)
Sep 4 18:36:43 relaysmtp postfix/smtpd[9402]: > unknown[192.168.0.15]: 250 2.0.0 Ok: queued as 64FFA85196
Sep 4 18:36:43 relaysmtp postfix/qmgr[9399]: 64FFA85196: from=<username@domain.com>, size=225, nrcpt=1 (queue active)
Sep 4 18:36:55 relaysmtp postfix/smtp[9520]: 64FFA85196: SASL authentication failed; server smtp.office365.com[191.232.101.210] said: 535 5.7.3 Authentication unsuccessful [FR1PR80CA0078.lamprd80.prod.outlook.com]
Sep 4 18:37:06 relaysmtp postfix/smtp[9520]: 64FFA85196: SASL authentication failed; server smtp.office365.com[191.232.104.2] said: 535 5.7.3 Authentication unsuccessful [RO1P152CA0065.LAMP152.PROD.OUTLOOK.COM]
似乎 postfix 甚至没有使用用 postmap 生成的 sasl_passwd.db 文件。
我错过了什么？
感谢您的帮助
【问题讨论】：
由于没有Linux环境，无法重现这个问题，但是我找到了一个可以参考的话题：secopsmonkey.com/mail-relaying-postfix-through-office-365.html 我按照说明，结果是一样的 仅供参考，我尝试使用来自同一域的另一个帐户并进行身份验证，我可以发送电子邮件。 【参考方案1】：当您重新加载 postfix 时，您是否可以看到 /var/log/mail 或 postfix 的 maillog 文件中缺少任何内容？在某些情况下，它会告诉您缺少什么。如果您只看到它重新加载正常，那么您可能需要检查 master.cf 文件并尝试将其注释掉：
#-o smtp_fallback_relay=
您还可以通过“postconf -n”查看实时后缀配置
所做的任何更改都需要“postmap 文件名”才能重新生成 db 文件并重新加载 postfix。与alias.db不同，使用“postalias alias”重新生成alias.db
【讨论】：
【参考方案2】：我尝试使用另一个帐户，并且身份验证有效并且可以传递消息。
【讨论】：
以上是关于使用 Office365 作为中继服务器的 Postfix 上的 SASL 身份验证失败的主要内容，如果未能解决你的问题，请参考以下文章