Debian
Dovecot 立即連接關閉
我在https://thomas-leister.de/en/mailserver-debian-stretch/之後設置了一個郵件伺服器，當嘗試連接客戶端（Outlook 365）時，它無法連接到 SMTP 伺服器。使用完整的 Dovecot 詳細程度檢查 mail.log 看起來它正在驗證 IMAP，然後立即關閉連接。
這是我嘗試連接客戶端一次時的 mail.log。
Jun 21 07:53:50 mail dovecot: master: Warning: Killed with signal 15 (by pid=10163 uid=0 code=kill) Jun 21 07:53:50 mail dovecot: imap(Josh@mysite.ca): Server shutting down. in=152 out=2220 Jun 21 07:53:50 mail dovecot: master: Dovecot v2.2.27 (c0f36b0) starting up for imap, lmtp, sieve (core dumps disabled) Jun 21 07:53:56 mail postfix[10184]: Postfix is running with backwards-compatible default settings Jun 21 07:53:56 mail postfix[10184]: See http://www.postfix.org/COMPATIBILITY_README.html for details Jun 21 07:53:56 mail postfix[10184]: To disable backwards compatibility use "postconf compatibility_level=2" and "postfix reload" Jun 21 07:53:56 mail postfix/postfix-script[10190]: stopping the Postfix mail system Jun 21 07:53:56 mail postfix/master[5066]: terminating on signal 15 Jun 21 07:53:56 mail postfix[10253]: Postfix is running with backwards-compatible default settings Jun 21 07:53:56 mail postfix[10253]: See http://www.postfix.org/COMPATIBILITY_README.html for details Jun 21 07:53:56 mail postfix[10253]: To disable backwards compatibility use "postconf compatibility_level=2" and "postfix reload" Jun 21 07:53:57 mail postfix/postfix-script[10352]: starting the Postfix mail system Jun 21 07:53:57 mail postfix/master[10354]: daemon started -- version 3.1.8, configuration /etc/postfix Jun 21 07:54:00 mail dovecot: auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth Jun 21 07:54:00 mail dovecot: auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so Jun 21 07:54:00 mail dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat Jun 21 07:54:00 mail dovecot: auth: Debug: auth client connected (pid=10359) Jun 21 07:54:00 mail dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured#011session=g4gzkiVv7OesUygU#011lip=208.146.44.129#011rip=172.83.40.20#011lport=993#011rport=59372#011local_name=imap.mysite.ca#011resp=AEpvc2hAandha2UuY2EAMXBPb3AyVFQ= (previous base64 data may contain sensitive data) Jun 21 07:54:00 mail dovecot: auth-worker(10362): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth Jun 21 07:54:00 mail dovecot: auth-worker(10362): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so Jun 21 07:54:00 mail dovecot: auth-worker(10362): Debug: sql(josh@mysite.ca,172.83.40.20,<g4gzkiVv7OesUygU>): query: SELECT username AS user, domain, password FROM accounts WHERE username = 'josh' AND domain = 'mysite.ca' and enabled = true; Jun 21 07:54:00 mail dovecot: auth-worker(10362): Debug: sql(josh@mysite.ca,172.83.40.20,<g4gzkiVv7OesUygU>): username changed josh@mysite.ca -> Josh Jun 21 07:54:00 mail dovecot: auth-worker(10362): Debug: sql(Josh,172.83.40.20,<g4gzkiVv7OesUygU>): username changed Josh -> Josh@mysite.ca Jun 21 07:54:00 mail dovecot: auth: Debug: sql(josh@mysite.ca,172.83.40.20,<g4gzkiVv7OesUygU>): username changed josh@mysite.ca -> Josh@mysite.ca Jun 21 07:54:00 mail dovecot: auth: Debug: sql(Josh@mysite.ca,172.83.40.20,<g4gzkiVv7OesUygU>): username changed Josh@mysite.ca -> Josh Jun 21 07:54:00 mail dovecot: auth: Debug: sql(Josh,172.83.40.20,<g4gzkiVv7OesUygU>): username changed Josh -> Josh@mysite.ca Jun 21 07:54:00 mail dovecot: auth: Debug: client passdb out: OK#0111#011user=Josh@mysite.ca Jun 21 07:54:00 mail dovecot: auth: Debug: master in: REQUEST#0111298792449#01110359#0111#011eea41cbba6c921b40a93a702989eed61#011session_pid=10363#011request_auth_token Jun 21 07:54:00 mail dovecot: auth-worker(10362): Debug: sql(Josh@mysite.ca,172.83.40.20,<g4gzkiVv7OesUygU>): SELECT concat('*:storage=', quota, 'M') AS quota_rule FROM accounts WHERE username = 'Josh' AND domain = 'mysite.ca' AND sendonly = false; Jun 21 07:54:00 mail dovecot: auth: Debug: master userdb out: USER#0111298792449#011Josh@mysite.ca#011quota_rule=*:storage=2048M#011auth_token=6716f415ff804ba96add892baeeaecff7f0592cd Jun 21 07:54:00 mail dovecot: imap-login: Login: user=<Josh@mysite.ca>, method=PLAIN, rip=172.83.40.20, lip=208.146.44.129, mpid=10363, TLS, session=<g4gzkiVv7OesUygU> Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Loading modules from directory: /usr/lib/dovecot/modules Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Module loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Module loaded: /usr/lib/dovecot/modules/lib90_antispam_plugin.so Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Added userdb setting: plugin/quota_rule=*:storage=2048M Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Effective uid=1001, gid=1001, home=/var/vmail/mailboxes/mysite.ca/Josh Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Quota root: name=User quota backend=maildir args= Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Quota rule: root=User quota mailbox=* bytes=2147483648 messages=0 Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Quota grace: root=User quota bytes=214748364 (10%) Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/mail:LAYOUT=fs Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: fs: root=/var/vmail/mailboxes/mysite.ca/Josh/mail, index=, indexpvt=, control=, inbox=/var/vmail/mailboxes/mysite.ca/Josh/mail, alt= Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: quota: quota_over_flag check: STORAGE ret=1 value=0 limit=2097152 Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: quota: quota_over_flag check: MESSAGE ret=0 value=0 limit=0 Jun 21 07:54:00 mail dovecot: imap(Josh@mysite.ca): Debug: quota: quota_over_flag=0((null)) vs currently overquota=0 Jun 21 07:54:33 mail dovecot: auth: Debug: auth client connected (pid=10381) Jun 21 07:54:34 mail dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured#011session=vIIvlCVv8eesUygU#011lip=208.146.44.129#011rip=172.83.40.20#011lport=143#011rport=59377#011local_name=mail.mysite.ca#011resp=AEpvc2hAandha2UuY2EAMXBPb3AyVFQ= (previous base64 data may contain sensitive data) Jun 21 07:54:34 mail dovecot: auth-worker(10362): Debug: sql(josh@mysite.ca,172.83.40.20,<vIIvlCVv8eesUygU>): query: SELECT username AS user, domain, password FROM accounts WHERE username = 'josh' AND domain = 'mysite.ca' and enabled = true; Jun 21 07:54:34 mail dovecot: auth-worker(10362): Debug: sql(josh@mysite.ca,172.83.40.20,<vIIvlCVv8eesUygU>): username changed josh@mysite.ca -> Josh Jun 21 07:54:34 mail dovecot: auth-worker(10362): Debug: sql(Josh,172.83.40.20,<vIIvlCVv8eesUygU>): username changed Josh -> Josh@mysite.ca Jun 21 07:54:34 mail dovecot: auth: Debug: sql(josh@mysite.ca,172.83.40.20,<vIIvlCVv8eesUygU>): username changed josh@mysite.ca -> Josh@mysite.ca Jun 21 07:54:34 mail dovecot: auth: Debug: sql(Josh@mysite.ca,172.83.40.20,<vIIvlCVv8eesUygU>): username changed Josh@mysite.ca -> Josh Jun 21 07:54:34 mail dovecot: auth: Debug: sql(Josh,172.83.40.20,<vIIvlCVv8eesUygU>): username changed Josh -> Josh@mysite.ca Jun 21 07:54:34 mail dovecot: auth: Debug: client passdb out: OK#0111#011user=Josh@mysite.ca Jun 21 07:54:34 mail dovecot: auth: Debug: master in: REQUEST#0111986658305#01110381#0111#0114a81a655e2fd95775a69d67377032381#011session_pid=10382#011request_auth_token Jun 21 07:54:34 mail dovecot: auth-worker(10362): Debug: sql(Josh@mysite.ca,172.83.40.20,<vIIvlCVv8eesUygU>): SELECT concat('*:storage=', quota, 'M') AS quota_rule FROM accounts WHERE username = 'Josh' AND domain = 'mysite.ca' AND sendonly = false; Jun 21 07:54:34 mail dovecot: auth: Debug: master userdb out: USER#0111986658305#011Josh@mysite.ca#011quota_rule=*:storage=2048M#011auth_token=345528122fb785f133c083192ec59c03663f0b95 Jun 21 07:54:34 mail dovecot: imap-login: Login: user=<Josh@mysite.ca>, method=PLAIN, rip=172.83.40.20, lip=208.146.44.129, mpid=10382, TLS, session=<vIIvlCVv8eesUygU> Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Loading modules from directory: /usr/lib/dovecot/modules Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Module loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Module loaded: /usr/lib/dovecot/modules/lib90_antispam_plugin.so Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Added userdb setting: plugin/quota_rule=*:storage=2048M Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Effective uid=1001, gid=1001, home=/var/vmail/mailboxes/mysite.ca/Josh Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Quota root: name=User quota backend=maildir args= Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Quota rule: root=User quota mailbox=* bytes=2147483648 messages=0 Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Quota grace: root=User quota bytes=214748364 (10%) Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/mail:LAYOUT=fs Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: fs: root=/var/vmail/mailboxes/mysite.ca/Josh/mail, index=, indexpvt=, control=, inbox=/var/vmail/mailboxes/mysite.ca/Josh/mail, alt= Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: quota: quota_over_flag check: STORAGE ret=1 value=0 limit=2097152 Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: quota: quota_over_flag check: MESSAGE ret=0 value=0 limit=0 Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Debug: quota: quota_over_flag=0((null)) vs currently overquota=0 Jun 21 07:54:34 mail dovecot: imap(Josh@mysite.ca): Connection closed (IDLE running for 0.001 + waiting input for 0.001 secs, 2 B in + 10+10 B out, state=wait-input) in=11 out=372 Jun 21 07:57:10 mail postfix/postscreen[10463]: CONNECT from [185.234.218.188]:64778 to [208.146.44.129]:25 Jun 21 07:57:10 mail postfix/postscreen[10463]: PREGREET 11 after 0.16 from [185.234.218.188]:64778: EHLO User\r\n Jun 21 07:57:10 mail postfix/postscreen[10463]: DISCONNECT [185.234.218.188]:64778 Jun 21 07:58:51 mail dovecot: auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth Jun 21 07:58:51 mail dovecot: auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so Jun 21 07:58:51 mail dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat Jun 21 07:58:51 mail dovecot: auth: Debug: auth client connected (pid=10530) Jun 21 08:01:52 mail dovecot: imap-login: Disconnected: Inactivity (no auth attempts in 181 secs): user=<>, rip=92.63.193.40, lip=208.146.44.129, TLS, session=<4VNJriVvVWVcP8Eo>不活動時，我會時不時地得到
Jun 21 08:17:12 mail dovecot: auth: Debug: sql(Josh@mysite.ca,92.63.193.40,<KGX85CVv3MlcP8Eo>): username changed Josh@mysite.ca -> Josh Jun 21 08:17:12 mail dovecot: auth: Debug: sql(Josh,92.63.193.40,<KGX85CVv3MlcP8Eo>): username changed Josh -> Josh@mysite.ca Jun 21 08:17:14 mail dovecot: auth: Debug: client passdb out: FAIL#0111#011user=Josh@mysite.ca#011original_user=josh@mysite.ca Jun 21 08:17:14 mail dovecot: imap-login: Debug: Ignoring unknown passdb extra field: original_user Jun 21 08:17:25 mail dovecot: imap-login: Disconnected (auth failed, 1 attempts in 16 secs): user=<Josh@mysite.ca>, method=PLAIN, rip=92.63.193.40, lip=208.146.44.129, TLS, session=<KGX85CVv3MlcP8Eo>現在我不知道從這裡去哪裡。如果需要更多日誌或配置，請告訴我。
Outlook 中的伺服器設置：
Incoming: mail.mysite.ca port 143 STARTTLS Outgoing: mail.mysite.ca port 587 STARTTLS編輯1：
我注意到當 postfix 在日誌中顯示它試圖連接埠 25 時，我認為？它很少出現在日誌中。在 Outlook 上嘗試埠 25 不起作用。
沒關係查找它，pregreet 在埠 25 上是正常的。
編輯2：
將 dovecot 設置為性能似乎並沒有改變任何東西。
編輯3：
netstat：看起來我的伺服器正在監聽 25 和 587 埠，對吧？
Active Internet connections (only servers) Proto Recv-Q Send-Q Local Address Foreign Address State tcp 0 0 0.0.0.0:143 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:53 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:7832 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:25 0.0.0.0:* LISTEN tcp 0 0 208.146.44.129:25 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:8953 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:4190 0.0.0.0:* LISTEN tcp 0 0 0.0.0.0:993 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:11332 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:11333 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:11334 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:3306 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:587 0.0.0.0:* LISTEN tcp 0 0 208.146.44.129:587 0.0.0.0:* LISTEN tcp 0 0 127.0.0.1:6379 0.0.0.0:* LISTEN tcp6 0 0 :::143 :::* LISTEN tcp6 0 0 :::80 :::* LISTEN tcp6 0 0 :::7832 :::* LISTEN tcp6 0 0 ::1:25 :::* LISTEN tcp6 0 0 ::1:8953 :::* LISTEN tcp6 0 0 :::443 :::* LISTEN tcp6 0 0 :::4190 :::* LISTEN tcp6 0 0 :::993 :::* LISTEN tcp6 0 0 ::1:11332 :::* LISTEN tcp6 0 0 ::1:11333 :::* LISTEN tcp6 0 0 ::1:11334 :::* LISTEN tcp6 0 0 ::1:587 :::* LISTEN udp 0 0 0.0.0.0:21902 0.0.0.0:* udp 0 0 127.0.0.1:53 0.0.0.0:* udp 0 0 0.0.0.0:26738 0.0.0.0:*編輯4：
netstat -nap | awk 'NR<3 || /:25/ || /:587/'Active Internet connections (servers and established) Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name tcp 0 0 127.0.0.1:25 0.0.0.0:* LISTEN 814/master tcp 0 0 208.146.44.129:25 0.0.0.0:* LISTEN 814/master tcp 0 0 127.0.0.1:587 0.0.0.0:* LISTEN 814/master tcp 0 0 208.146.44.129:587 0.0.0.0:* LISTEN 814/master tcp6 0 0 ::1:25 :::* LISTEN 814/master tcp6 0 0 ::1:587 :::* LISTEN 814/master
在這裡，一個 SMTP 客戶端在與它說話之前正在說話：
Jun 21 07:57:10 mail postfix/postscreen[10463]: CONNECT from [185.234.218.188]:64778 to [208.146.44.129]:25 Jun 21 07:57:10 mail postfix/postscreen[10463]: PREGREET 11 after 0.16 from [185.234.218.188]:64778: EHLO User\r\n Jun 21 07:57:10 mail postfix/postscreen[10463]: DISCONNECT [185.234.218.188]:64778這違反了協議，因此連接被丟棄。甚至可能被列入黑名單一段時間。
您的客戶真的應該在 587 而非 25 上通過身份驗證進行交談。