Postfix debug peer logging Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > server.example.org[XX.XX.XX.XX]: 250 2.1.5 Ok Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: 0x55ef4ec020180 Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: vstream_fflush_some: fd 10 flush 28 Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: vstream_buf_get_ready: fd 10 got 15 Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: < server.example.org [ XX.XX.XX.XX]: BDAT 326 LAST Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: smtpd_forbidden_commands: bdat ~? connect Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: smtpd_forbidden_commands: bdat ~? get Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: smtpd_forbidden_commands: bdat ~? post Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_list_match: BDAT: no match Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > server.example.org [ XX.XX.XX.XX] : 502 5.5.2 Error: command not recognized Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: 0x55ef4ec020180 Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: vstream_fflush_some: fd 10 flush 41 Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: vstream_buf_get_ready: fd 10 got 326 Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: < server.example.org [ XX.XX.XX.XX] : Content-Type: text/plain; charset=us-ascii Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: warning: non-SMTP command from server.example.org [ XX.XX.XX.XX] : Content-Type: text/plain; charset=us-ascii Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > server.example.org [ XX.XX.XX.XX] ]: 221 2.7.0 Error: I can break rules, too. Goodbye. Op di 18 dec. 2018 om 17:01 schreef Ruud Voorjans <ruud.voorjans at gmail.com>:> doveconf -n output: > # 2.3.2.1 (0719df592): /etc/dovecot/dovecot.conf > # Pigeonhole version 0.5.2 () > # OS: Linux 4.18.0-12-generic x86_64 Ubuntu 18.10 > # Hostname: mail.example.org > auth_debug = yes > auth_debug_passwords = yes > auth_mechanisms = plain login > auth_verbose = yes > director_mail_servers = XX.XX.XX.XX > hostname = mail.example.org > log_path = /var/log/dovecot.log > login_trusted_networks = XX.XX.XX.XX > mail_debug = yes > mail_location = mbox:~/mail:INBOX=/var/mail/%u > mail_privileged_group = mail > namespace inbox { > inbox = yes > location > mailbox Drafts { > special_use = \Drafts > } > mailbox Junk { > special_use = \Junk > } > mailbox Sent { > special_use = \Sent > } > mailbox "Sent Messages" { > special_use = \Sent > } > mailbox Trash { > special_use = \Trash > } > prefix > } > passdb { > args = proxy=y host=XX.XX.XX nopassword=y > driver = static > } > protocols = imap submission > service director { > fifo_listener login/proxy-notify { > mode = 0600 > user = $default_login_user > } > inet_listener { > port = 9090 > } > unix_listener director-userdb { > mode = 0600 > } > unix_listener login/director { > mode = 0666 > } > } > service imap-login { > executable = imap-login director > } > service submission-login { > executable = submission-login > } > ssl = required > ssl_cert = </etc/letsencrypt/live/mail.example.org/fullchain.pem > 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 > ssl_dh = # hidden, use -P to show it > ssl_key = # hidden, use -P to show it > ssl_min_protocol = TLSv1.2 > ssl_prefer_server_ciphers = yes > submission_relay_host = XX.XX.XX.XX > submission_relay_rawlog_dir = /var/log/dovecot.log > submission_relay_trusted = yes > verbose_ssl = yes > > > Logging: > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > Connection created > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Received > new command: EHLO [10.225.11.41] > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO; 250 reply: Submitted > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO: Ready to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger > output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending > replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO: Completed > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > Connection state reset > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO; 250 reply: Sent: 250-mail.example.org 8BITMIME BURL imap CHUNKING > ENHANCEDSTATUSCODES SIZE STARTTLS PIPELINING > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO; 250 reply: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger > output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more > commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending > replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more > commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Received > new command: STARTTLS > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > STARTTLS: Next to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > STARTTLS; 220 reply: Submitted > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > STARTTLS: Ready to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger > output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending > replies > 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. > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > STARTTLS: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Starting > TLS > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > Connection clear > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > Connection state reset > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > STARTTLS; 220 reply: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger > output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more > commands pending > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x10, ret=1: before > SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: before > SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: before > SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: before > SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: before > SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: before > SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: before > SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS read client hello > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write server hello > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write certificate > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending > replies > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more > commands pending > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending > replies > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more > commands pending > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: > SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS read change cipher spec > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS read finished > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write change cipher spec > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write finished > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x20, ret=1: SSL > negotiation finished successfully > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=1: SSL > negotiation finished successfully > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending > replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more > commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Received > new command: EHLO [XX.XX.XX.XX] > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO; 250 reply: Submitted > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO: Ready to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger > output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending > replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO: Completed > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > Connection state reset > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO; 250 reply: Sent: 250-mail.example.org 8BITMIME AUTH PLAIN LOGIN > BURL imap CHUNKING ENHANCEDSTATUSCODES SIZE PIPELINING > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > EHLO; 250 reply: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger > output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more > commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending > replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No more > commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Received > new command: AUTH PLAIN > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > AUTH: Next to reply > 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> mail.example.org 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) > Dec 18 16:36:39 auth: Debug: static(): lookup > Dec 18 16:36:39 auth: Debug: static(): Allowing any password > Dec 18 16:36:39 auth: Debug: client passdb out: OK 1 user> proxy host= XX.XX.XX.XX pass> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > AUTH; 235 reply: Submitted > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > AUTH: Ready to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Trigger > output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: Sending > replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > AUTH: Completed > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > AUTH; 235 reply: Sent: 235 2.7.0 Authentication successful > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > AUTH: Destroy > 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=<> > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > Disconnected: Connection closed > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: command > AUTH; 235 reply: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > Connection destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > Connection state reset > 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=<> > Dec 18 16:36:40 submission-login: Debug: SSL alert: close notify > > > Op di 18 dec. 2018 om 07:18 schreef Aki Tuomi <aki.tuomi at open-xchange.com > >: > >> >> On 18 December 2018 at 02:30 Adi Pircalabu via dovecot < >> dovecot at dovecot.org> wrote: >> >> >> On 2018-12-18 07:33, Ruud Voorjans wrote: >> >> Dear all, >> >> I'm running dovecot # 2.3.2.1 - Pigeonhole version 0.5.2 () - OS: >> Linux 4.18.0-12-generic x86_64 Ubuntu 18.10 with Submission. >> It works great except with apple mail (Iphone). >> >> I get an error with the MTA (postfix): >> ""postfix/submission/smtpd[32552]: warning: non-SMTP command from >> mail.example.org [1][xx.xx.xx.xx]: Content-Transfer-Encoding: 7bit"" >> >> with other mail-client(s) (Outlook (Desktop and Iphone app)) i have no >> problem and it proxy-sends the e-mail beautiful out to the recipient. >> >> Hardly anything to do with Dovecot. When it comes to email clients Apple >> Mail has been and is still one of the worst flops (no offence intended, >> just my opinion based on personal experience). If you can reliably >> reproduce it, try and log the raw SMTP conversation between Postfix and >> the client by enabling per IP debugging in Postfix: >> postconf -e "debug_peer_level = 20" >> postconf -e "debug_peer_list = xx.xx.xx.xx" >> postfix reload >> where xx.xx.xx.xx is the unlucky client IP address. >> >> Possibly some crappy SMTP PIPELINING implementation at the Apple end, >> who knows. >> >> -- >> Adi Pircalabu >> >> >> It's not unconceivable that there are bugs in submission either. Can you >> provide doveconf -n and submission rawlogs? See >> https://wiki.dovecot.org/Submission for settings. >> >> --- >> Aki Tuomi >> >-------------- next part -------------- An HTML attachment was scrubbed... URL: <https://dovecot.org/pipermail/dovecot/attachments/20181218/3f7206ff/attachment-0001.html>
On 2018-12-19 03:17, Ruud Voorjans wrote:> Postfix debug peer logging > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > server.example.org [4][XX.XX.XX.XX]: 250 2.1.5 Ok > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: > 0x55ef4ec020180 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > vstream_fflush_some: fd 10 flush 28 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > vstream_buf_get_ready: fd 10 got 15 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: < > server.example.org [4] [ XX.XX.XX.XX]: BDAT 326 LAST > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: > smtpd_forbidden_commands: bdat ~? connect > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: > smtpd_forbidden_commands: bdat ~? get > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: > smtpd_forbidden_commands: bdat ~? post > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > match_list_match: BDAT: no match > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > server.example.org [4] [ XX.XX.XX.XX] : 502 5.5.2 Error: command not > recognized > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: > 0x55ef4ec020180 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > vstream_fflush_some: fd 10 flush 41 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > vstream_buf_get_ready: fd 10 got 326 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: < > server.example.org [4] [ XX.XX.XX.XX] : Content-Type: text/plain; > charset=us-ascii > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: warning: > non-SMTP command from server.example.org [4] [ XX.XX.XX.XX] : > Content-Type: text/plain; charset=us-ascii > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > server.example.org [4] [ XX.XX.XX.XX] ]: 221 2.7.0 Error: I can > break rules, too. Goodbye.Do you have the submission logs for the same timestamp? You server doesn't support BDAT command. However, looking at the logs below I have a suspicion your submission is advertising CHUNKING incorrectly. Misconfiguration or bug? https://tools.ietf.org/html/rfc1830 -- Adi Pircalabu> > Op di 18 dec. 2018 om 17:01 schreef Ruud Voorjans > >> doveconf -n output: >> # 2.3.2.1 (0719df592): /etc/dovecot/dovecot.conf >> # Pigeonhole version 0.5.2 () >> # OS: Linux 4.18.0-12-generic x86_64 Ubuntu 18.10 >> # Hostname: mail.example.org [1] >> auth_debug = yes >> auth_debug_passwords = yes >> auth_mechanisms = plain login >> auth_verbose = yes >> director_mail_servers = XX.XX.XX.XX >> hostname = mail.example.org [1] >> log_path = /var/log/dovecot.log >> login_trusted_networks = XX.XX.XX.XX >> mail_debug = yes >> mail_location = mbox:~/mail:INBOX=/var/mail/%u >> mail_privileged_group = mail >> namespace inbox { >> inbox = yes >> location >> mailbox Drafts { >> special_use = \Drafts >> } >> mailbox Junk { >> special_use = \Junk >> } >> mailbox Sent { >> special_use = \Sent >> } >> mailbox "Sent Messages" { >> special_use = \Sent >> } >> mailbox Trash { >> special_use = \Trash >> } >> prefix >> } >> passdb { >> args = proxy=y host=XX.XX.XX nopassword=y >> driver = static >> } >> protocols = imap submission >> service director { >> fifo_listener login/proxy-notify { >> mode = 0600 >> user = $default_login_user >> } >> inet_listener { >> port = 9090 >> } >> unix_listener director-userdb { >> mode = 0600 >> } >> unix_listener login/director { >> mode = 0666 >> } >> } >> service imap-login { >> executable = imap-login director >> } >> service submission-login { >> executable = submission-login >> } >> ssl = required >> ssl_cert = </etc/letsencrypt/live/mail.example.org/fullchain.pem [2] >> 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 >> ssl_dh = # hidden, use -P to show it >> ssl_key = # hidden, use -P to show it >> ssl_min_protocol = TLSv1.2 >> ssl_prefer_server_ciphers = yes >> submission_relay_host = XX.XX.XX.XX >> submission_relay_rawlog_dir = /var/log/dovecot.log >> submission_relay_trusted = yes >> verbose_ssl = yes >> >> Logging: >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Connection created >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Received new command: EHLO [10.225.11.41] >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO; 250 reply: Submitted >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO: Ready to reply >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Trigger output >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Sending replies >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO: Completed >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Connection state reset >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO; 250 reply: Sent: 250-mail.example.org [3] 8BITMIME >> BURL imap CHUNKING ENHANCEDSTATUSCODES SIZE STARTTLS PIPELINING >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO: Destroy >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO; 250 reply: Destroy >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Trigger output >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No >> more commands pending >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Sending replies >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No >> more commands pending >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Received new command: STARTTLS >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command STARTTLS: Next to reply >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command STARTTLS; 220 reply: Submitted >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command STARTTLS: Ready to reply >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Trigger output >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Sending replies >> 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. >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command STARTTLS: Destroy >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Starting TLS >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Connection clear >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Connection state reset >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command STARTTLS; 220 reply: Destroy >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Trigger output >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No >> more commands pending >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x10, ret=1: >> before SSL initialization >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> before SSL initialization >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> before SSL initialization >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> before SSL initialization >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> before SSL initialization >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> before SSL initialization >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> before SSL initialization >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS read client hello >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS write server hello >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS write certificate >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS write key exchange >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS write server done >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS write server done >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS write server done >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Sending replies >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS write server done >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No >> more commands pending >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS write server done >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS write server done >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS write server done >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS write server done >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS write server done >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS read client key exchange >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS read client key exchange >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Sending replies >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS read client key exchange >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No >> more commands pending >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS read client key exchange >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS read client key exchange >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS read client key exchange >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=-1: >> SSLv3/TLS read client key exchange >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS read client key exchange >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS read change cipher spec >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS read finished >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS write change cipher spec >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: >> SSLv3/TLS write finished >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x20, ret=1: SSL >> negotiation finished successfully >> Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=1: >> SSL negotiation finished successfully >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Sending replies >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No >> more commands pending >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Received new command: EHLO [XX.XX.XX.XX] >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO; 250 reply: Submitted >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO: Ready to reply >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Trigger output >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Sending replies >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO: Completed >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Connection state reset >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO; 250 reply: Sent: 250-mail.example.org [3] 8BITMIME >> AUTH PLAIN LOGIN BURL imap CHUNKING ENHANCEDSTATUSCODES SIZE >> PIPELINING >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO: Destroy >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command EHLO; 250 reply: Destroy >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Trigger output >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No >> more commands pending >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Sending replies >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: No >> more commands pending >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Received new command: AUTH PLAIN >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command AUTH: Next to reply >> 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=mail.example.org [1] >> 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) >> Dec 18 16:36:39 auth: Debug: static(): lookup >> Dec 18 16:36:39 auth: Debug: static(): Allowing any password >> Dec 18 16:36:39 auth: Debug: client passdb out: OK 1 >> user= proxy host= XX.XX.XX.XX pass>> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command AUTH; 235 reply: Submitted >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command AUTH: Ready to reply >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Trigger output >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Sending replies >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command AUTH: Completed >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command AUTH; 235 reply: Sent: 235 2.7.0 Authentication successful >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command AUTH: Destroy >> 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=<> >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Disconnected: Connection closed >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> command AUTH; 235 reply: Destroy >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Connection destroy >> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: >> Connection state reset >> 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=<> >> Dec 18 16:36:40 submission-login: Debug: SSL alert: close notify >> >> Op di 18 dec. 2018 om 07:18 schreef Aki Tuomi >> <aki.tuomi at open-xchange.com>: >> >> On 18 December 2018 at 02:30 Adi Pircalabu via dovecot < >> dovecot at dovecot.org> wrote: >> >> On 2018-12-18 07:33, Ruud Voorjans wrote: >> Dear all, >> >> I'm running dovecot # 2.3.2.1 - Pigeonhole version 0.5.2 () - OS: >> Linux 4.18.0-12-generic x86_64 Ubuntu 18.10 with Submission. >> It works great except with apple mail (Iphone). >> >> I get an error with the MTA (postfix): >> ""postfix/submission/smtpd[32552]: warning: non-SMTP command from >> mail.example.org [1] [1][xx.xx.xx.xx]: Content-Transfer-Encoding: >> 7bit"" >> >> with other mail-client(s) (Outlook (Desktop and Iphone app)) i have >> no >> problem and it proxy-sends the e-mail beautiful out to the >> recipient. >> Hardly anything to do with Dovecot. When it comes to email clients >> Apple >> Mail has been and is still one of the worst flops (no offence >> intended, >> just my opinion based on personal experience). If you can reliably >> reproduce it, try and log the raw SMTP conversation between Postfix >> and >> the client by enabling per IP debugging in Postfix: >> postconf -e "debug_peer_level = 20" >> postconf -e "debug_peer_list = xx.xx.xx.xx" >> postfix reload >> where xx.xx.xx.xx is the unlucky client IP address. >> >> Possibly some crappy SMTP PIPELINING implementation at the Apple >> end, >> who knows. >> >> -- >> Adi Pircalabu > > It's not unconceivable that there are bugs in submission either. Can > you provide doveconf -n and submission rawlogs? See > https://wiki.dovecot.org/Submission for settings. > > --- > Aki Tuomi > > Links: > ------ > [1] http://mail.example.org > [2] http://mail.example.org/fullchain.pem > [3] http://250-mail.example.org > [4] http://server.example.org
Hi, Below, you have only the submission-login debug log (authentication). I'm more interested in what happens after that. You'll need to enable mail_debug=yes (at least for the user involved) to get that. Regards, Stephan. Op 18/12/2018 om 17:17 schreef Ruud Voorjans:> Postfix debug peer logging > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > server.example.org <http://server.example.org>[XX.XX.XX.XX]: 250 2.1.5 Ok > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: > 0x55ef4ec020180 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > vstream_fflush_some: fd 10 flush 28 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > vstream_buf_get_ready: fd 10 got 15 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: < > server.example.org <http://server.example.org> [ XX.XX.XX.XX]: BDAT > 326 LAST > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: > smtpd_forbidden_commands: bdat ~? connect > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: > smtpd_forbidden_commands: bdat ~? get > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: > smtpd_forbidden_commands: bdat ~? post > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > match_list_match: BDAT: no match > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > server.example.org <http://server.example.org> [?XX.XX.XX.XX]? : 502 > 5.5.2 Error: command not recognized > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: > 0x55ef4ec020180 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > vstream_fflush_some: fd 10 flush 41 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > vstream_buf_get_ready: fd 10 got 326 > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: < > server.example.org <http://server.example.org> [?XX.XX.XX.XX]? : > Content-Type: text/plain; charset=us-ascii > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: warning: > non-SMTP command from server.example.org <http://server.example.org> > [?XX.XX.XX.XX]? : Content-Type: text/plain; charset=us-ascii > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > server.example.org <http://server.example.org> [?XX.XX.XX.XX]? ]: 221 > 2.7.0 Error: I can break rules, too. Goodbye. > > > Op di 18 dec. 2018 om 17:01 schreef Ruud Voorjans > <ruud.voorjans at gmail.com <mailto:ruud.voorjans at gmail.com>>: > > doveconf -n output: > # 2.3.2.1 (0719df592): /etc/dovecot/dovecot.conf > # Pigeonhole version 0.5.2 () > # OS: Linux 4.18.0-12-generic x86_64 Ubuntu 18.10 > # Hostname: mail.example.org <http://mail.example.org> > auth_debug = yes > auth_debug_passwords = yes > auth_mechanisms = plain login > auth_verbose = yes > director_mail_servers = XX.XX.XX.XX > hostname = mail.example.org <http://mail.example.org> > log_path = /var/log/dovecot.log > login_trusted_networks = XX.XX.XX.XX > mail_debug = yes > mail_location = mbox:~/mail:INBOX=/var/mail/%u > mail_privileged_group = mail > namespace inbox { > ? inbox = yes > ? location > ? mailbox Drafts { > ? ? special_use = \Drafts > ? } > ? mailbox Junk { > ? ? special_use = \Junk > ? } > ? mailbox Sent { > ? ? special_use = \Sent > ? } > ? mailbox "Sent Messages" { > ? ? special_use = \Sent > ? } > ? mailbox Trash { > ? ? special_use = \Trash > ? } > ? prefix > } > passdb { > ? args = proxy=y host=XX.XX.XX nopassword=y > ? driver = static > } > protocols = imap submission > service director { > ? fifo_listener login/proxy-notify { > ? ? mode = 0600 > ? ? user = $default_login_user > ? } > ? inet_listener { > ? ? port = 9090 > ? } > ? unix_listener director-userdb { > ? ? mode = 0600 > ? } > ? unix_listener login/director { > ? ? mode = 0666 > ? } > } > service imap-login { > ? executable = imap-login director > } > service submission-login { > ? executable = submission-login > } > ssl = required > ssl_cert = </etc/letsencrypt/live/mail.example.org/fullchain.pem > <http://mail.example.org/fullchain.pem> > 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 > ssl_dh =? # hidden, use -P to show it > ssl_key =? # hidden, use -P to show it > ssl_min_protocol = TLSv1.2 > ssl_prefer_server_ciphers = yes > submission_relay_host = XX.XX.XX.XX > submission_relay_rawlog_dir = /var/log/dovecot.log > submission_relay_trusted = yes > verbose_ssl = yes > > > Logging: > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Connection created > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Received new command: EHLO [10.225.11.41] > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO; 250 reply: Submitted > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO: Ready to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Trigger output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Sending replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO: Completed > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Connection state reset > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO; 250 reply: Sent: 250-mail.example.org > <http://250-mail.example.org> 8BITMIME BURL imap CHUNKING > ENHANCEDSTATUSCODES SIZE STARTTLS PIPELINING > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO; 250 reply: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Trigger output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > No more commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Sending replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > No more commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Received new command: STARTTLS > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command STARTTLS: Next to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command STARTTLS; 220 reply: Submitted > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command STARTTLS: Ready to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Trigger output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Sending replies > 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. > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command STARTTLS: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Starting TLS > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Connection clear > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Connection state reset > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command STARTTLS; 220 reply: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Trigger output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > No more commands pending > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x10, ret=1: > before SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > before SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: before SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: before SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: before SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: before SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > before SSL initialization > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS read client hello > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write server hello > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write certificate > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Sending replies > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > No more commands pending > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write server done > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Sending replies > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > No more commands pending > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > ret=-1: SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS read client key exchange > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS read change cipher spec > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS read finished > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write change cipher spec > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > SSLv3/TLS write finished > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x20, ret=1: > SSL negotiation finished successfully > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=1: > SSL negotiation finished successfully > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Sending replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > No more commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Received new command: EHLO [XX.XX.XX.XX] > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO; 250 reply: Submitted > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO: Ready to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Trigger output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Sending replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO: Completed > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Connection state reset > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO; 250 reply: Sent: 250-mail.example.org > <http://250-mail.example.org> 8BITMIME AUTH PLAIN LOGIN BURL imap > CHUNKING ENHANCEDSTATUSCODES SIZE PIPELINING > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command EHLO; 250 reply: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Trigger output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > No more commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Sending replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > No more commands pending > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Received new command: AUTH PLAIN > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command AUTH: Next to reply > 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=mail.example.org > <http://mail.example.org> ?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) > Dec 18 16:36:39 auth: Debug: static(): lookup > Dec 18 16:36:39 auth: Debug: static(): Allowing any password > Dec 18 16:36:39 auth: Debug: client passdb out: OK ? 1? ? ? > ?user=? ? proxy? ?host=? XX.XX.XX.XX ?pass> Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command AUTH; 235 reply: Submitted > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command AUTH: Ready to reply > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Trigger output > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Sending replies > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command AUTH: Completed > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command AUTH; 235 reply: Sent: 235 2.7.0 Authentication successful > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command AUTH: Destroy > 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=<> > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Disconnected: Connection closed > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > command AUTH; 235 reply: Destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Connection destroy > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn? ?[0]: > Connection state reset > 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=<> > Dec 18 16:36:40 submission-login: Debug: SSL alert: close notify > > > Op di 18 dec. 2018 om 07:18 schreef Aki Tuomi > <aki.tuomi at open-xchange.com <mailto:aki.tuomi at open-xchange.com>>: > > >> On 18 December 2018 at 02:30 Adi Pircalabu via dovecot < >> dovecot at dovecot.org <mailto:dovecot at dovecot.org>> wrote: >> >> >> On 2018-12-18 07:33, Ruud Voorjans wrote: >>> Dear all, >>> >>> I'm running dovecot # 2.3.2.1 - Pigeonhole version 0.5.2 () >>> - OS: >>> Linux 4.18.0-12-generic x86_64 Ubuntu 18.10 with Submission. >>> It works great except with apple mail (Iphone). >>> >>> I get an error with the MTA (postfix): >>> ""postfix/submission/smtpd[32552]: warning: non-SMTP command >>> from >>> mail.example.org <http://mail.example.org> [1][xx.xx.xx.xx]: >>> Content-Transfer-Encoding: 7bit"" >>> >>> with other mail-client(s) (Outlook (Desktop and Iphone app)) >>> i have no >>> problem and it proxy-sends the e-mail beautiful out to the >>> recipient. >> Hardly anything to do with Dovecot. When it comes to email >> clients Apple >> Mail has been and is still one of the worst flops (no offence >> intended, >> just my opinion based on personal experience). If you can >> reliably >> reproduce it, try and log the raw SMTP conversation between >> Postfix and >> the client by enabling per IP debugging in Postfix: >> postconf -e "debug_peer_level = 20" >> postconf -e "debug_peer_list = xx.xx.xx.xx" >> postfix reload >> where xx.xx.xx.xx is the unlucky client IP address. >> >> Possibly some crappy SMTP PIPELINING implementation at the >> Apple end, >> who knows. >> >> -- >> Adi Pircalabu > > It's not unconceivable that there are bugs in submission > either. Can you provide doveconf -n and submission rawlogs? > See https://wiki.dovecot.org/Submission for settings. > > --- > Aki Tuomi >
After the submission with dovecot it sends it to postfix, the postfix log is: postfix/submission/smtpd[19509]: connect from example.org[192.168.1.1] postfix/submission/smtpd[19509]: client=example.org[192.168.1.1], sasl_method=PLAIN, sasl_username=test at example.org postfix/submission/smtpd[19509]: *warning: non-SMTP command from example.org <http://example.org>[192.168.1.1]: Content-Transfer-Encoding: 7bit* postfix/submission/smtpd[19509]: disconnect from example.org[192.168.1.1] ehlo=1 auth=1 mail=1 rcpt=1 unknown=0/2 commands=4/6 postfix/submission/smtpd[19509]: connect from example.org[192.168.1.1] postfix/submission/smtpd[19509]: client=example.org[192.168.1.1], sasl_method=PLAIN, sasl_username=test at example.org postfix/submission/smtpd[19509]: *warning: non-SMTP command from example.org <http://example.org>[192.168.1.1]: Content-Type: text/plain; charset=us-ascii* postfix/submission/smtpd[19509]: disconnect from example.org[192.168.1.1] ehlo=1 auth=1 mail=1 rcpt=1 unknown=0/2 commands=4/6 postfix/submission/smtpd[18882]: *timeout after END-OF-MESSAGE from example.org <http://example.org>[192.168.1.1]* postfix/submission/smtpd[18882]: disconnect from example.org[192.168.1.1] ehlo=1 auth=1 mail=1 rcpt=1 data=1 commands=5 As you can see it is a "non-SMTP command" given by Postfix. Am guessing it has something to do with the placement of the mail content. The outlook application is functional normally, i upgraded to 2.3.4 of Dovecot but still same result. Not sure if it is a Dovecot issue or Postfix.. On Sun, Dec 23, 2018 at 11:46 AM Stephan Bosch <stephan at rename-it.nl> wrote:> Hi, > > Below, you have only the submission-login debug log (authentication). > I'm more interested in what happens after that. You'll need to enable > mail_debug=yes (at least for the user involved) to get that. > > Regards, > > Stephan. > > Op 18/12/2018 om 17:17 schreef Ruud Voorjans: > > Postfix debug peer logging > > > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > > server.example.org <http://server.example.org>[XX.XX.XX.XX]: 250 2.1.5 > Ok > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: > > 0x55ef4ec020180 > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > vstream_fflush_some: fd 10 flush 28 > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > vstream_buf_get_ready: fd 10 got 15 > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: < > > server.example.org <http://server.example.org> [ XX.XX.XX.XX]: BDAT > > 326 LAST > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: > > smtpd_forbidden_commands: bdat ~? connect > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: > > smtpd_forbidden_commands: bdat ~? get > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: match_string: > > smtpd_forbidden_commands: bdat ~? post > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > match_list_match: BDAT: no match > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > > server.example.org <http://server.example.org> [ XX.XX.XX.XX] : 502 > > 5.5.2 Error: command not recognized > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: watchdog_pat: > > 0x55ef4ec020180 > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > vstream_fflush_some: fd 10 flush 41 > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > vstream_buf_get_ready: fd 10 got 326 > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: < > > server.example.org <http://server.example.org> [ XX.XX.XX.XX] : > > Content-Type: text/plain; charset=us-ascii > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: warning: > > non-SMTP command from server.example.org <http://server.example.org> > > [ XX.XX.XX.XX] : Content-Type: text/plain; charset=us-ascii > > Dec 18 17:08:11 mail postfix/submission/smtpd[10626]: > > > server.example.org <http://server.example.org> [ XX.XX.XX.XX] ]: 221 > > 2.7.0 Error: I can break rules, too. Goodbye. > > > > > > Op di 18 dec. 2018 om 17:01 schreef Ruud Voorjans > > <ruud.voorjans at gmail.com <mailto:ruud.voorjans at gmail.com>>: > > > > doveconf -n output: > > # 2.3.2.1 (0719df592): /etc/dovecot/dovecot.conf > > # Pigeonhole version 0.5.2 () > > # OS: Linux 4.18.0-12-generic x86_64 Ubuntu 18.10 > > # Hostname: mail.example.org <http://mail.example.org> > > auth_debug = yes > > auth_debug_passwords = yes > > auth_mechanisms = plain login > > auth_verbose = yes > > director_mail_servers = XX.XX.XX.XX > > hostname = mail.example.org <http://mail.example.org> > > log_path = /var/log/dovecot.log > > login_trusted_networks = XX.XX.XX.XX > > mail_debug = yes > > mail_location = mbox:~/mail:INBOX=/var/mail/%u > > mail_privileged_group = mail > > namespace inbox { > > inbox = yes > > location > > mailbox Drafts { > > special_use = \Drafts > > } > > mailbox Junk { > > special_use = \Junk > > } > > mailbox Sent { > > special_use = \Sent > > } > > mailbox "Sent Messages" { > > special_use = \Sent > > } > > mailbox Trash { > > special_use = \Trash > > } > > prefix > > } > > passdb { > > args = proxy=y host=XX.XX.XX nopassword=y > > driver = static > > } > > protocols = imap submission > > service director { > > fifo_listener login/proxy-notify { > > mode = 0600 > > user = $default_login_user > > } > > inet_listener { > > port = 9090 > > } > > unix_listener director-userdb { > > mode = 0600 > > } > > unix_listener login/director { > > mode = 0666 > > } > > } > > service imap-login { > > executable = imap-login director > > } > > service submission-login { > > executable = submission-login > > } > > ssl = required > > ssl_cert = </etc/letsencrypt/live/mail.example.org/fullchain.pem > > <http://mail.example.org/fullchain.pem> > > 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 > > ssl_dh = # hidden, use -P to show it > > ssl_key = # hidden, use -P to show it > > ssl_min_protocol = TLSv1.2 > > ssl_prefer_server_ciphers = yes > > submission_relay_host = XX.XX.XX.XX > > submission_relay_rawlog_dir = /var/log/dovecot.log > > submission_relay_trusted = yes > > verbose_ssl = yes > > > > > > Logging: > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Connection created > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Received new command: EHLO [10.225.11.41] > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO; 250 reply: Submitted > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO: Ready to reply > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Trigger output > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Sending replies > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO: Completed > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Connection state reset > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO; 250 reply: Sent: 250-mail.example.org > > <http://250-mail.example.org> 8BITMIME BURL imap CHUNKING > > ENHANCEDSTATUSCODES SIZE STARTTLS PIPELINING > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO: Destroy > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO; 250 reply: Destroy > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Trigger output > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > No more commands pending > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Sending replies > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > No more commands pending > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Received new command: STARTTLS > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command STARTTLS: Next to reply > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command STARTTLS; 220 reply: Submitted > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command STARTTLS: Ready to reply > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Trigger output > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Sending replies > > 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. > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command STARTTLS: Destroy > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Starting TLS > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Connection clear > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Connection state reset > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command STARTTLS; 220 reply: Destroy > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Trigger output > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > No more commands pending > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x10, ret=1: > > before SSL initialization > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > before SSL initialization > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: before SSL initialization > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: before SSL initialization > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: before SSL initialization > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: before SSL initialization > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > before SSL initialization > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS read client hello > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS write server hello > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS write certificate > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS write key exchange > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS write server done > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS write server done > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS write server done > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Sending replies > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS write server done > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > No more commands pending > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS write server done > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS write server done > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS write server done > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS write server done > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS write server done > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS read client key exchange > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS read client key exchange > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Sending replies > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS read client key exchange > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > No more commands pending > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS read client key exchange > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS read client key exchange > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS read client key exchange > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, > > ret=-1: SSLv3/TLS read client key exchange > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS read client key exchange > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS read change cipher spec > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS read finished > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS write change cipher spec > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2001, ret=1: > > SSLv3/TLS write finished > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x20, ret=1: > > SSL negotiation finished successfully > > Dec 18 16:36:39 submission-login: Debug: SSL: where=0x2002, ret=1: > > SSL negotiation finished successfully > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Sending replies > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > No more commands pending > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Received new command: EHLO [XX.XX.XX.XX] > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO; 250 reply: Submitted > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO: Ready to reply > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Trigger output > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Sending replies > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO: Completed > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Connection state reset > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO; 250 reply: Sent: 250-mail.example.org > > <http://250-mail.example.org> 8BITMIME AUTH PLAIN LOGIN BURL imap > > CHUNKING ENHANCEDSTATUSCODES SIZE PIPELINING > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO: Destroy > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command EHLO; 250 reply: Destroy > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Trigger output > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > No more commands pending > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Sending replies > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > No more commands pending > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Received new command: AUTH PLAIN > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command AUTH: Next to reply > > 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=mail.example.org > > <http://mail.example.org> 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) > > Dec 18 16:36:39 auth: Debug: static(): lookup > > Dec 18 16:36:39 auth: Debug: static(): Allowing any password > > Dec 18 16:36:39 auth: Debug: client passdb out: OK 1 > > user= proxy host= XX.XX.XX.XX pass> > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command AUTH; 235 reply: Submitted > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command AUTH: Ready to reply > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Trigger output > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Sending replies > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command AUTH: Completed > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command AUTH; 235 reply: Sent: 235 2.7.0 Authentication successful > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command AUTH: Destroy > > 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=<> > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Disconnected: Connection closed > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > command AUTH; 235 reply: Destroy > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Connection destroy > > Dec 18 16:36:39 submission-login: Debug: smtp-server: conn [0]: > > Connection state reset > > 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=<> > > Dec 18 16:36:40 submission-login: Debug: SSL alert: close notify > > > > > > Op di 18 dec. 2018 om 07:18 schreef Aki Tuomi > > <aki.tuomi at open-xchange.com <mailto:aki.tuomi at open-xchange.com>>: > > > > > >> On 18 December 2018 at 02:30 Adi Pircalabu via dovecot < > >> dovecot at dovecot.org <mailto:dovecot at dovecot.org>> wrote: > >> > >> > >> On 2018-12-18 07:33, Ruud Voorjans wrote: > >>> Dear all, > >>> > >>> I'm running dovecot # 2.3.2.1 - Pigeonhole version 0.5.2 () > >>> - OS: > >>> Linux 4.18.0-12-generic x86_64 Ubuntu 18.10 with Submission. > >>> It works great except with apple mail (Iphone). > >>> > >>> I get an error with the MTA (postfix): > >>> ""postfix/submission/smtpd[32552]: warning: non-SMTP command > >>> from > >>> mail.example.org <http://mail.example.org> [1][xx.xx.xx.xx]: > >>> Content-Transfer-Encoding: 7bit"" > >>> > >>> with other mail-client(s) (Outlook (Desktop and Iphone app)) > >>> i have no > >>> problem and it proxy-sends the e-mail beautiful out to the > >>> recipient. > >> Hardly anything to do with Dovecot. When it comes to email > >> clients Apple > >> Mail has been and is still one of the worst flops (no offence > >> intended, > >> just my opinion based on personal experience). If you can > >> reliably > >> reproduce it, try and log the raw SMTP conversation between > >> Postfix and > >> the client by enabling per IP debugging in Postfix: > >> postconf -e "debug_peer_level = 20" > >> postconf -e "debug_peer_list = xx.xx.xx.xx" > >> postfix reload > >> where xx.xx.xx.xx is the unlucky client IP address. > >> > >> Possibly some crappy SMTP PIPELINING implementation at the > >> Apple end, > >> who knows. > >> > >> -- > >> Adi Pircalabu > > > > It's not unconceivable that there are bugs in submission > > either. Can you provide doveconf -n and submission rawlogs? > > See https://wiki.dovecot.org/Submission for settings. > > > > --- > > Aki Tuomi > > >-------------- next part -------------- An HTML attachment was scrubbed... URL: <https://dovecot.org/pipermail/dovecot/attachments/20190107/b105d8e2/attachment-0001.html>