<div dir="ltr"><div dir="ltr">Postfix debug peer logging<div><br></div><div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > <a href="http://server.example.org">server.example.org</a>[XX.XX.XX.XX]: 250 2.1.5 Ok</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: 0x55ef4ec020180</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: vstream_fflush_some: fd 10 flush 28</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: vstream_buf_get_ready: fd 10 got 15</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: <
<a href="http://server.example.org">server.example.org</a> [
XX.XX.XX.XX]: BDAT 326 LAST</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: smtpd_forbidden_commands: bdat ~? connect</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: smtpd_forbidden_commands: bdat ~? get</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: smtpd_forbidden_commands: bdat ~? post</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_list_match: BDAT: no match</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: >
<a href="http://server.example.org">server.example.org</a> [ XX.XX.XX.XX] : 502 5.5.2 Error: command not recognized</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: 0x55ef4ec020180</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: vstream_fflush_some: fd 10 flush 41</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: vstream_buf_get_ready: fd 10 got 326</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: <
<a href="http://server.example.org">server.example.org</a> [ XX.XX.XX.XX] : Content-Type: text/plain; charset=us-ascii</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: warning: non-SMTP command from
<a href="http://server.example.org">server.example.org</a> [ XX.XX.XX.XX] : Content-Type: text/plain; charset=us-ascii</div><div>Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: >
<a href="http://server.example.org">server.example.org</a> [ XX.XX.XX.XX] ]: 221 2.7.0 Error: I can break rules, too. Goodbye.</div></div><div><br></div></div></div><br><div class="gmail_quote"><div dir="ltr">Op di 18 dec. 2018 om 17:01 schreef Ruud Voorjans <<a href="mailto:ruud.voorjans@gmail.com">ruud.voorjans@gmail.com</a>>:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr"><div>doveconf -n output:</div><div># 2.3.2.1 (0719df592): /etc/dovecot/dovecot.conf</div><div># Pigeonhole version 0.5.2 ()</div><div># OS: Linux 4.18.0-12-generic x86_64 Ubuntu 18.10</div><div># Hostname: <a href="http://mail.example.org" target="_blank">mail.example.org</a></div><div>auth_debug = yes</div><div>auth_debug_passwords = yes</div><div>auth_mechanisms = plain login</div><div>auth_verbose = yes</div><div>director_mail_servers = XX.XX.XX.XX</div><div>hostname = <a href="http://mail.example.org" target="_blank">mail.example.org</a></div><div>log_path = /var/log/dovecot.log</div><div>login_trusted_networks = XX.XX.XX.XX</div><div>mail_debug = yes</div><div>mail_location = mbox:~/mail:INBOX=/var/mail/%u</div><div>mail_privileged_group = mail</div><div>namespace inbox {</div><div> inbox = yes</div><div> location =</div><div> mailbox Drafts {</div><div> special_use = \Drafts</div><div> }</div><div> mailbox Junk {</div><div> special_use = \Junk</div><div> }</div><div> mailbox Sent {</div><div> special_use = \Sent</div><div> }</div><div> mailbox "Sent Messages" {</div><div> special_use = \Sent</div><div> }</div><div> mailbox Trash {</div><div> special_use = \Trash</div><div> }</div><div> prefix =</div><div>}</div><div>passdb {</div><div> args = proxy=y host=XX.XX.XX nopassword=y</div><div> driver = static</div><div>}</div><div>protocols = imap submission</div><div>service director {</div><div> fifo_listener login/proxy-notify {</div><div> mode = 0600</div><div> user = $default_login_user</div><div> }</div><div> inet_listener {</div><div> port = 9090</div><div> }</div><div> unix_listener director-userdb {</div><div> mode = 0600</div><div> }</div><div> unix_listener login/director {</div><div> mode = 0666</div><div> }</div><div>}</div><div>service imap-login {</div><div> executable = imap-login director</div><div>}</div><div>service submission-login {</div><div> executable = submission-login</div><div>}</div><div>ssl = required</div><div>ssl_cert = </etc/letsencrypt/live/<a href="http://mail.example.org/fullchain.pem" target="_blank">mail.example.org/fullchain.pem</a></div><div>ssl_cipher_list = AES256+EECDH:AES256+EDH:ECDH+AESGCM:DH+AESGCM:ECDH+AES256:DH+AES256:ECDH+AES128:DH+AES:ECDH+3DES:DH+3DES:RSA+AESGCM:RSA+AES:RSA+3DES:!aNULL:!MD5</div><div>ssl_dh = # hidden, use -P to show it</div><div>ssl_key = # hidden, use -P to show it</div><div>ssl_min_protocol = TLSv1.2</div><div>ssl_prefer_server_ciphers = yes</div><div>submission_relay_host = XX.XX.XX.XX</div><div>submission_relay_rawlog_dir = /var/log/dovecot.log</div><div>submission_relay_trusted = yes</div><div>verbose_ssl = yes</div><div><br></div><div><br></div><div>Logging:</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Connection created</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Received new command: EHLO [10.225.11.41]</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO; 250 reply: Submitted</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO: Ready to reply</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger output</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending replies</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO: Completed</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Connection state reset</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO; 250 reply: Sent: <a href="http://250-mail.example.org" target="_blank">250-mail.example.org</a> 8BITMIME BURL imap CHUNKING ENHANCEDSTATUSCODES SIZE STARTTLS PIPELINING</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO: Destroy</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO; 250 reply: Destroy</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger output</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more commands pending</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending replies</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more commands pending</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Received new command: STARTTLS</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command STARTTLS: Next to reply</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command STARTTLS; 220 reply: Submitted</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command STARTTLS: Ready to reply</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger output</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending replies</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command STARTTLS; 220 reply: Sent: 220 2.0.0 Begin TLS negotiation now.</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command STARTTLS: Destroy</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Starting TLS</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Connection clear</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Connection state reset</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command STARTTLS; 220 reply: Destroy</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger output</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more commands pending</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x10, ret=1: before SSL initialization</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: before SSL initialization</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: before SSL initialization</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client hello</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server hello</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write certificate</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write key exchange</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending replies</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more commands pending</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write server done</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS read client key exchange</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS read client key exchange</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending replies</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS read client key exchange</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more commands pending</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS read client key exchange</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS read client key exchange</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS read client key exchange</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS read client key exchange</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read client key exchange</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read change cipher spec</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS read finished</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write change cipher spec</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: SSLv3/TLS write finished</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully</div><div>Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending replies</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more commands pending</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Received new command: EHLO [XX.XX.XX.XX]</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO; 250 reply: Submitted</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO: Ready to reply</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger output</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending replies</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO: Completed</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Connection state reset</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO; 250 reply: Sent: <a href="http://250-mail.example.org" target="_blank">250-mail.example.org</a> 8BITMIME AUTH PLAIN LOGIN BURL imap CHUNKING ENHANCEDSTATUSCODES SIZE PIPELINING</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO: Destroy</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command EHLO; 250 reply: Destroy</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger output</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more commands pending</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending replies</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more commands pending</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Received new command: AUTH PLAIN</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command AUTH: Next to reply</div><div>Dec 18 16:36:39 auth: Debug: client in: AUTH 1 PLAIN service=submission secured=tls session= lip=XX.XX.XX.XX rip=XX.XX.XX.XX lport=587 rport=49679 local_name=<a href="http://mail.example.org" target="_blank">mail.example.org</a> ssl_cipher=ECDHE-RSA-AES256-GCM-SHA384 ssl_cipher_bits=256 ssl_pfs= ssl_protocol=TLSv1.2 resp= (previous base64 data may contain sensitive data)</div><div>Dec 18 16:36:39 auth: Debug: static(): lookup</div><div>Dec 18 16:36:39 auth: Debug: static(): Allowing any password</div><div>Dec 18 16:36:39 auth: Debug: client passdb out: OK 1 user= proxy host= XX.XX.XX.XX pass=</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command AUTH; 235 reply: Submitted</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command AUTH: Ready to reply</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger output</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending replies</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command AUTH: Completed</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command AUTH; 235 reply: Sent: 235 2.7.0 Authentication successful</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command AUTH: Destroy</div><div>Dec 18 16:36:39 submission-login: Info: proxy( ): started proxying to XX.XX.XX.XX:587: user=< >, method=PLAIN, rip=XX.XX.XX.XX, lip=XX.XX.XX.XX, TLS, session=<></div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Disconnected: Connection closed</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command AUTH; 235 reply: Destroy</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Connection destroy</div><div>Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Connection state reset</div><div>Dec 18 16:36:40 submission-login: Info: proxy( ): disconnecting XX.XX.XX.XX (Disconnected by server(0s idle, in=533, out=295)): user=< >, method=PLAIN, rip=XX.XX.XX.XX, lip=XX.XX.XX.XX, TLS, session=<></div><div>Dec 18 16:36:40 submission-login: Debug: SSL alert: close notify</div><div><br></div></div></div><br><div class="gmail_quote"><div dir="ltr">Op di 18 dec. 2018 om 07:18 schreef Aki Tuomi <<a href="mailto:aki.tuomi@open-xchange.com" target="_blank">aki.tuomi@open-xchange.com</a>>:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><u></u>
<div>
<div>
<br>
</div>
<blockquote type="cite">
<div>
On 18 December 2018 at 02:30 Adi Pircalabu via dovecot <
<a href="mailto:dovecot@dovecot.org" target="_blank">dovecot@dovecot.org</a>> wrote:
</div>
<div>
<br>
</div>
<div>
<br>
</div>
<div>
On 2018-12-18 07:33, Ruud Voorjans wrote:
</div>
<blockquote type="cite">
<div>
Dear all,
</div>
<div>
<br>
</div>
<div>
I'm running dovecot # 2.3.2.1 - Pigeonhole version 0.5.2 () - OS:
</div>
<div>
Linux 4.18.0-12-generic x86_64 Ubuntu 18.10 with Submission.
</div>
<div>
It works great except with apple mail (Iphone).
</div>
<div>
<br>
</div>
<div>
I get an error with the MTA (postfix):
</div>
<div>
""postfix/submission/smtpd[32552]: warning: non-SMTP command from
</div>
<div>
<a href="http://mail.example.org" target="_blank">mail.example.org</a> [1][xx.xx.xx.xx]: Content-Transfer-Encoding: 7bit""
</div>
<div>
<br>
</div>
<div>
with other mail-client(s) (Outlook (Desktop and Iphone app)) i have no
</div>
<div>
problem and it proxy-sends the e-mail beautiful out to the recipient.
</div>
</blockquote>
<div>
Hardly anything to do with Dovecot. When it comes to email clients Apple
</div>
<div>
Mail has been and is still one of the worst flops (no offence intended,
</div>
<div>
just my opinion based on personal experience). If you can reliably
</div>
<div>
reproduce it, try and log the raw SMTP conversation between Postfix and
</div>
<div>
the client by enabling per IP debugging in Postfix:
</div>
<div>
postconf -e "debug_peer_level = 20"
</div>
<div>
postconf -e "debug_peer_list = xx.xx.xx.xx"
</div>
<div>
postfix reload
</div>
<div>
where xx.xx.xx.xx is the unlucky client IP address.
</div>
<div>
<br>
</div>
<div>
Possibly some crappy SMTP PIPELINING implementation at the Apple end,
</div>
<div>
who knows.
</div>
<div>
<br>
</div>
<div>
--
</div>
<div>
Adi Pircalabu
</div>
</blockquote>
<div>
<br>
</div>
<div>
It's not unconceivable that there are bugs in submission either. Can you provide doveconf -n and submission rawlogs? See <a href="https://wiki.dovecot.org/Submission" target="_blank">https://wiki.dovecot.org/Submission</a> for settings.
</div>
<div>
<br>
</div>
<div class="gmail-m_-7391584706188361190gmail-m_-9082603563682581505io-ox-signature">
---
<br>Aki Tuomi
</div>
</div>
</blockquote></div>
</blockquote></div>