<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>