submission-relay: sends EHLO after a successful AUTH
Hello,
I have been migrating away from mailbox and notmuchto dovecot to archive my mail and it works great for this purpose so far! I figured out if I'm proxying IMAP, why not SMTP as well?
Unfortunately that part did not work as well, at least not Migadu that I use as my mail service. I would always get back a
530 5.7.0 authentication required.
from the server when issuing MAIL FROM even though the logs were showing an
apparent success in authenticating. From what I can tell the issue turns out
to be the fact that submission relay sends a fresh EHLO after it has already
successfully authenticated, resetting the state of the connection and dropping
the authentication it just worked to set up. I verified the theory issuing
commands directly to Migadu via openssl s_client:
EHLO, AUTH PLAIN, EHLO, MAIL FROM -> 530 EHLO, AUTH PLAIN, MAIL FROM -> 250
Is it me holding dovecot wrong or a genuine bug? A sanitized log of one tx is appended below.
Thank you, S.
master: Dovecot v2.4.5 (0cbb641e3e) starting up for imap, submission ... submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Server accepted connection (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Looking up IP address submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Performing asynchronous DNS lookup submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: dns(smtp.migadu.com): Lookup started submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Client connected (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Sending version handshake submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection started submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 235 2.7.0 Logged in. submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): dns(smtp.migadu.com): Lookup successful after 4 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: DNS lookup successful; got 6 IPs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connecting to 51.210.223.36:465 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Waiting for connect (fd=8) to finish for max 0 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnected: Connection closed (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnect: deinit submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Client connected (fd=8) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Starting SSL handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x10, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read encrypted extensions submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Internet Security Research Group/CN=ISRG Root X2 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=ISRG/CN=Root YE submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Let's Encrypt/CN=YE1 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /CN=smtp.migadu.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server certificate submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read server certificate verify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write change cipher spec submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x20, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: SSL handshake successful submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received greeting from server: 220 smtp.migadu.com ESMTP Service Ready submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticating as me@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Sent: AUTH PLAIN <snip> submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Got reply (1/1): 235 2.0.0 Authentication succeeded (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticated successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connection ready submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Received new command: MAIL FROM:<sender@example.com> submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: New command submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Execute command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Add transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Next to reply submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout stop submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start next transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Connection is ready for transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Sending MAIL command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Aborted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Removed from send queue submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Sent: MAIL FROM:<sender@example.com> AUTH=relay@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Reset timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Got reply (1/1): 530 5.7.0 authentication required (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: No commands pending; stop timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Got MAIL reply: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Aborted submission(me@example.com)<3453761><tfS6...>: Error: relay: Server requires authentication: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 421 4.3.5 mail.example.com Internal error occurred. Refer to server log for more information. submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection state reset submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Abort submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Destroy submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL alert: close notify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected: Connection closed (fd=8) submission(me@example.com)<3453761><tfS6...>: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) in=36 out=124 submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Connection closed (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Destroy (0 commands pending, 0 commands queued) submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Destroy
"Simonas" == Simonas Kazlauskas via dovecot <dovecot@dovecot.org> writes:
I have been migrating away from mailbox and notmuchto dovecot to archive my mail and it works great for this purpose so far! I figured out if I'm proxying IMAP, why not SMTP as well?
So what are you using to move the mail between the systems? imapsync or some other tool?
Unfortunately that part did not work as well, at least not Migadu that I use as my mail service. I would always get back a
Again, what tool? Or are you opening the Migadu server using Thunderbird or some other mail client, and then trying to save the email to a new dovecot imap instance?
530 5.7.0 authentication required.
This looks like SMTP commands...
from the server when issuing
MAIL FROMeven though the logs were showing an apparent success in authenticating. From what I can tell the issue turns out to be the fact that submission relay sends a fresh EHLO after it has already successfully authenticated, resetting the state of the connection and dropping the authentication it just worked to set up. I verified the theory issuing commands directly to Migadu viaopenssl s_client:
EHLO, AUTH PLAIN, EHLO, MAIL FROM -> 530 EHLO, AUTH PLAIN, MAIL FROM -> 250
Those are SMTP commands.
Is it me holding dovecot wrong or a genuine bug? A sanitized log of one tx is appended below.
You need to explain better what you're trying to do, and how you're doing it. The info you've provided isn't useful without more context and details.
Thank you, S.
master: Dovecot v2.4.5 (0cbb641e3e) starting up for imap, submission ... submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Server accepted connection (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Looking up IP address submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Performing asynchronous DNS lookup submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: dns(smtp.migadu.com): Lookup started submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Client connected (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Sending version handshake submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection started submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 235 2.7.0 Logged in. submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): dns(smtp.migadu.com): Lookup successful after 4 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: DNS lookup successful; got 6 IPs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connecting to 51.210.223.36:465 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Waiting for connect (fd=8) to finish for max 0 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnected: Connection closed (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnect: deinit submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Client connected (fd=8) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Starting SSL handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x10, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read encrypted extensions submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Internet Security Research Group/CN=ISRG Root X2 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=ISRG/CN=Root YE submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Let's Encrypt/CN=YE1 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /CN=smtp.migadu.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server certificate submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read server certificate verify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write change cipher spec submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x20, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: SSL handshake successful submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received greeting from server: 220 smtp.migadu.com ESMTP Service Ready submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticating as me@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Sent: AUTH PLAIN <snip> submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Got reply (1/1): 235 2.0.0 Authentication succeeded (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticated successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connection ready submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Received new command: MAIL FROM:<sender@example.com> submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: New command submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Execute command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Add transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Next to reply submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout stop submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start next transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Connection is ready for transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Sending MAIL command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Aborted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Removed from send queue submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Sent: MAIL FROM:<sender@example.com> AUTH=relay@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Reset timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Got reply (1/1): 530 5.7.0 authentication required (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: No commands pending; stop timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Got MAIL reply: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Aborted submission(me@example.com)<3453761><tfS6...>: Error: relay: Server requires authentication: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 421 4.3.5 mail.example.com Internal error occurred. Refer to server log for more information. submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection state reset submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Abort submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Destroy submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL alert: close notify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected: Connection closed (fd=8) submission(me@example.com)<3453761><tfS6...>: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) in=36 out=124 submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Connection closed (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Destroy (0 commands pending, 0 commands queued) submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Destroy
dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org
Hey John,
John Stoffel wrote:
"Simonas" == Simonas Kazlauskas via dovecot <dovecot@dovecot.org> writes:
I have been migrating away from mailbox and notmuchto dovecot to archive my mail and it works great for this purpose so far! I figured out if I'm proxying IMAP, why not SMTP as well?
So what are you using to move the mail between the systems? imapsync or some other tool?
This part of report, retrospectively, is not relevant to the issue. Migration itself worked alright and I shouldn't have included this.
Unfortunately that part did not work as well, at least not Migadu that I use as my mail service. I would always get back a
Again, what tool? Or are you opening the Migadu server using Thunderbird or some other mail client, and then trying to save the email to a new dovecot imap instance?
530 5.7.0 authentication required.
This looks like SMTP commands...
from the server when issuing
MAIL FROMeven though the logs were showing an apparent success in authenticating. From what I can tell the issue turns out to be the fact that submission relay sends a fresh EHLO after it has already successfully authenticated, resetting the state of the connection and dropping the authentication it just worked to set up. I verified the theory issuing commands directly to Migadu viaopenssl s_client:EHLO, AUTH PLAIN, EHLO, MAIL FROM -> 530 EHLO, AUTH PLAIN, MAIL FROM -> 250
Those are SMTP commands.
Is it me holding dovecot wrong or a genuine bug? A sanitized log of one tx is appended below.
You need to explain better what you're trying to do, and how you're doing it. The info you've provided isn't useful without more context and details.
The overarching goal is to have dovecot act as a bidirectional archiving proxy for my mail so that I can connect my mail clients to dovecot only and peruse the entire history of all mail I have collected. Receiving, archiving and reading parts work. Sending via dovecot's SMTP submission-relay did not.
I sent a mail from neomutt (also tried FairEmail) to dovecot's submission-queue (successfully), which would then try to forward the message over to Migadu. This forwarding from the submission relay to migadu is what failed. There are no other tools or services in play for this problem.
The attached log is precisely for one such attempt. Does that help to clarify the report?
Thank you, S.
master: Dovecot v2.4.5 (0cbb641e3e) starting up for imap, submission ... submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Server accepted connection (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Looking up IP address submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Performing asynchronous DNS lookup submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: dns(smtp.migadu.com): Lookup started submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Client connected (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Sending version handshake submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection started submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 235 2.7.0 Logged in. submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): dns(smtp.migadu.com): Lookup successful after 4 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: DNS lookup successful; got 6 IPs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connecting to 51.210.223.36:465 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Waiting for connect (fd=8) to finish for max 0 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnected: Connection closed (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnect: deinit submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Client connected (fd=8) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Starting SSL handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x10, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read encrypted extensions submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Internet Security Research Group/CN=ISRG Root X2 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=ISRG/CN=Root YE submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Let's Encrypt/CN=YE1 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /CN=smtp.migadu.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server certificate submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read server certificate verify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write change cipher spec submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x20, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: SSL handshake successful submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received greeting from server: 220 smtp.migadu.com ESMTP Service Ready submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticating as me@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Sent: AUTH PLAIN <snip> submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Got reply (1/1): 235 2.0.0 Authentication succeeded (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticated successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connection ready submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Received new command: MAIL FROM:<sender@example.com> submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: New command submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Execute command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Add transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Next to reply submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout stop submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start next transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Connection is ready for transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Sending MAIL command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Aborted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Removed from send queue submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Sent: MAIL FROM:<sender@example.com> AUTH=relay@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Reset timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Got reply (1/1): 530 5.7.0 authentication required (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: No commands pending; stop timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Got MAIL reply: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Aborted submission(me@example.com)<3453761><tfS6...>: Error: relay: Server requires authentication: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 421 4.3.5 mail.example.com Internal error occurred. Refer to server log for more information. submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection state reset submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Abort submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Destroy submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL alert: close notify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected: Connection closed (fd=8) submission(me@example.com)<3453761><tfS6...>: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) in=36 out=124 submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Connection closed (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Destroy (0 commands pending, 0 commands queued) submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Destroy
dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org
"Simonas" == Simonas Kazlauskas <dovecot@kazlauskas.me> writes:
Hey John, John Stoffel wrote:
> "Simonas" == Simonas Kazlauskas via dovecot <dovecot@dovecot.org> writes:
I have been migrating away from mailbox and notmuchto dovecot to archive my mail and it works great for this purpose so far! I figured out if I'm proxying IMAP, why not SMTP as well?
So what are you using to move the mail between the systems? imapsync or some other tool?
This part of report, retrospectively, is not relevant to the issue. Migration itself worked alright and I shouldn't have included this.
Ok, then please go back and re-write your report, but also send your configuration details!
Unfortunately that part did not work as well, at least not Migadu that I use as my mail service. I would always get back a
Again, what tool? Or are you opening the Migadu server using Thunderbird or some other mail client, and then trying to save the email to a new dovecot imap instance?
530 5.7.0 authentication required.
This looks like SMTP commands...
from the server when issuing
MAIL FROMeven though the logs were showing an apparent success in authenticating. From what I can tell the issue turns out to be the fact that submission relay sends a fresh EHLO after it has already successfully authenticated, resetting the state of the connection and dropping the authentication it just worked to set up. I verified the theory issuing commands directly to Migadu viaopenssl s_client:EHLO, AUTH PLAIN, EHLO, MAIL FROM -> 530 EHLO, AUTH PLAIN, MAIL FROM -> 250
Those are SMTP commands.
Is it me holding dovecot wrong or a genuine bug? A sanitized log of one tx is appended below.
You need to explain better what you're trying to do, and how you're doing it. The info you've provided isn't useful without more context and details.
The overarching goal is to have dovecot act as a bidirectional archiving proxy for my mail so that I can connect my mail clients to dovecot only and peruse the entire history of all mail I have collected. Receiving, archiving and reading parts work. Sending via dovecot's SMTP submission-relay did not.
Dovecot does not accept email for delivery, that's the role of your SMTP server, such as postfix. So again, please post your configuration of dovecot. But also explain which client you're using, how you're connecting, and how you expect to SEND email via dovecot. Dovecot only listens on the IMAP ports. You are trying to send via a local (I think, can't honestly tell) SMTP server and that's where you problem is.
John
I sent a mail from neomutt (also tried FairEmail) to dovecot's submission-queue (successfully), which would then try to forward the message over to Migadu. This forwarding from the submission relay to migadu is what failed. There are no other tools or services in play for this problem.
Post your neomutt and dovecot configurations. Yes yes, I'm sure you're worried that some nefarious person will use this information to hack your setup, but until you post what you're doing, we cannot help you.
The attached log is precisely for one such attempt. Does that help to clarify the report?
It doesn't help because we don't see your dovecot configuration.
Thank you, S.
master: Dovecot v2.4.5 (0cbb641e3e) starting up for imap, submission ... submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Server accepted connection (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Looking up IP address submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Performing asynchronous DNS lookup submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: dns(smtp.migadu.com): Lookup started submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Client connected (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Sending version handshake submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection started submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 235 2.7.0 Logged in. submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): dns(smtp.migadu.com): Lookup successful after 4 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: DNS lookup successful; got 6 IPs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connecting to 51.210.223.36:465 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Waiting for connect (fd=8) to finish for max 0 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnected: Connection closed (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnect: deinit submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Client connected (fd=8) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Starting SSL handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x10, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read encrypted extensions submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Internet Security Research Group/CN=ISRG Root X2 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=ISRG/CN=Root YE submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Let's Encrypt/CN=YE1 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /CN=smtp.migadu.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server certificate submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read server certificate verify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write change cipher spec submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x20, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: SSL handshake successful submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received greeting from server: 220 smtp.migadu.com ESMTP Service Ready submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticating as me@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Sent: AUTH PLAIN <snip> submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Got reply (1/1): 235 2.0.0 Authentication succeeded (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticated successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connection ready submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Received new command: MAIL FROM:<sender@example.com> submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: New command submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Execute command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Add transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Next to reply submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout stop submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start next transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Connection is ready for transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Sending MAIL command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Aborted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Removed from send queue submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Sent: MAIL FROM:<sender@example.com> AUTH=relay@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Reset timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Got reply (1/1): 530 5.7.0 authentication required (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: No commands pending; stop timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Got MAIL reply: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Aborted submission(me@example.com)<3453761><tfS6...>: Error: relay: Server requires authentication: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 421 4.3.5 mail.example.com Internal error occurred. Refer to server log for more information. submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection state reset submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Abort submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Destroy submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL alert: close notify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected: Connection closed (fd=8) submission(me@example.com)<3453761><tfS6...>: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) in=36 out=124 submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Connection closed (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Destroy (0 commands pending, 0 commands queued) submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Destroy
dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org
dovecot is strictly a mail delivery system (imap,pop etc)
you must use a seperate smtp server setup (postfix,sendmail etc) for smtp to work if you are still trying to receive emails directly then postfix (or whatever) needs to be programmed to deliver to that instance of dovecot.
On 2026-10-21 7:26 a.m., Simonas Kazlauskas via dovecot wrote:
Hello,
I have been migrating away from mailbox and notmuchto dovecot to archive my mail and it works great for this purpose so far! I figured out if I'm proxying IMAP, why not SMTP as well?
Unfortunately that part did not work as well, at least not Migadu that I use as my mail service. I would always get back a
530 5.7.0 authentication required.
from the server when issuing
MAIL FROMeven though the logs were showing an apparent success in authenticating. From what I can tell the issue turns out to be the fact that submission relay sends a fresh EHLO after it has already successfully authenticated, resetting the state of the connection and dropping the authentication it just worked to set up. I verified the theory issuing commands directly to Migadu viaopenssl s_client:EHLO, AUTH PLAIN, EHLO, MAIL FROM -> 530 EHLO, AUTH PLAIN, MAIL FROM -> 250
Is it me holding dovecot wrong or a genuine bug? A sanitized log of one tx is appended below.
Thank you, S.
master: Dovecot v2.4.5 (0cbb641e3e) starting up for imap, submission ... submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Server accepted connection (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connection created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Looking up IP address submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Performing asynchronous DNS lookup submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: dns(smtp.migadu.com): Lookup started submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Client connected (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Sending version handshake submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection started submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 235 2.7.0 Logged in. submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: conn unix:/run/dovecot2/dns-client (pid=3388288,uid=0): dns(smtp.migadu.com): Lookup successful after 4 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: DNS lookup successful; got 6 IPs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 [1]: Connecting to 51.210.223.36:465 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connecting submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Waiting for connect (fd=8) to finish for max 0 msecs submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/ dovecot2/dns-client (pid=3388288,uid=0): Disconnected: Connection closed (fd=15) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn unix:/run/ dovecot2/dns-client (pid=3388288,uid=0): Disconnect: deinit submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Client connected (fd=8) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Starting SSL handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x10, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: before SSL initialization submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server hello submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read encrypted extensions submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Internet Security Research Group/CN=ISRG Root X2 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=ISRG/CN=Root YE submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /C=US/O=Let's Encrypt/CN=YE1 submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: Received valid SSL certificate: /CN=smtp.migadu.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server certificate submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read server certificate verify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write change cipher spec submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write finished submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x20, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL: where=0x1002, ret=1: SSL negotiation finished successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: SSL handshake successful submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received greeting from server: 220 smtp.migadu.com ESMTP Service Ready submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp- client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticating as me@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Sent: AUTH PLAIN <snip> submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Got reply (1/1): 235 2.0.0 Authentication succeeded (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Authenticated successfully submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending EHLO handshake submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Submitted with priority submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command AUTH: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Sent: EHLO mail.example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received handshake reply submission(me@example.com)<3453761><tfS6...>: Warning: relay: smtp- client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received invalid EHLO response line: Unexpected character in EHLO keyword submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received server capabilities submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Connection ready submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command EHLO: Destroy (0 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Received new command: MAIL FROM:<sender@example.com> submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: New command submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Execute command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Created submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Start submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Add transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Next to reply submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Timeout stop submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start next transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Connection is ready for transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Sending MAIL command submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Submitted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Aborted submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Removed from send queue submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command [plug]: Destroy (0 commands pending, 1 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Sent: MAIL FROM:<sender@example.com> AUTH=relay@example.com submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Reset timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Got reply (1/1): 530 5.7.0 authentication required (1 commands pending, 0 commands queued) submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: No commands pending; stop timeout submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Got MAIL reply: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Aborted submission(me@example.com)<3453761><tfS6...>: Error: relay: Server requires authentication: 530 5.7.0 authentication required submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Sent: 421 4.3.5 mail.example.com Internal error occurred. Refer to server log for more information. submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection state reset submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Abort submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: command MAIL: Destroy submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: smtp.migadu.com: SSL alert: close notify submission(me@example.com)<3453761><tfS6...>: Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Disconnected: Connection closed (fd=8) submission(me@example.com)<3453761><tfS6...>: Disconnected: Internal error occurred. Refer to server log for more information. (unfinished MAIL command) (state=MAIL FROM) in=36 out=124 submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Disconnected: Connection closed (fd=9) submission(me@example.com)<3453761><tfS6...>: Debug: smtp-server: conn 192.168.70.182:50608 [1]: Connection destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Destroy submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: transaction: Abort submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort transaction submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command MAIL: Destroy (0 commands pending, 0 commands queued) submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Destroy
dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org
--
Thanks - Paul Kudla (Manager SCOM.CA Internet Services Inc.)
Have A Happy Saturday AND Happy Sucessful 2026 !
Scom.ca Internet Services <http://www.scom.ca> 104-1009 Byron Street South Whitby, Ontario - Canada L1N 4S3
Toronto 416.642.7266 Main 1.866.411.7266 Fax 1.888.892.7266 Email paul@scom.ca
Use dovecot's submission service instead. Submission proxy to mta directly is not supported.
See [1]https://doc.dovecot.org/latest/core/config/submission.html#submission-server
Aki
On 21/10/2026 14:26 EEST Simonas Kazlauskas via dovecot
<[2]dovecot@dovecot.org> wrote:
Hello,
I have been migrating away from mailbox and notmuchto dovecot to archive
my
mail and it works great for this purpose so far! I figured out if I'm
proxying
IMAP, why not SMTP as well?
Unfortunately that part did not work as well, at least not Migadu that I
use
as my mail service. I would always get back a
530 5.7.0 authentication required.
from the server when issuing `MAIL FROM` even though the logs were
showing an
apparent success in authenticating. From what I can tell the issue turns
out
to be the fact that submission relay sends a fresh EHLO after it has
already
successfully authenticated, resetting the state of the connection and
dropping
the authentication it just worked to set up. I verified the theory
issuing
commands directly to Migadu via `openssl s_client`:
EHLO, AUTH PLAIN, EHLO, MAIL FROM -> 530
EHLO, AUTH PLAIN, MAIL FROM -> 250
Is it me holding dovecot wrong or a genuine bug? A sanitized log of one
tx is
appended below.
Thank you,
S.
---
master: Dovecot v2.4.5 (0cbb641e3e) starting up for imap, submission
...
submission([3]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Server accepted connection (fd=9)
submission([4]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Connection created
submission([5]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: Connection created
submission([6]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: Disconnected
submission([7]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: Looking up IP address
submission([8]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: Performing asynchronous DNS
lookup
submission([9]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: conn
unix:/run/dovecot2/dns-client: dns(smtp.migadu.com): Lookup started
submission([10]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: conn
unix:/run/dovecot2/dns-client: Connecting
submission([11]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: conn
unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Client connected
(fd=15)
submission([12]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: conn
unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Sending version
handshake
submission([13]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Connection started
submission([14]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Sent: 235 2.7.0 Logged in.
submission([15]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: conn
unix:/run/dovecot2/dns-client (pid=3388288,uid=0): dns(smtp.migadu.com):
Lookup successful after 4 msecs
submission([16]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: DNS lookup successful; got 6
IPs
submission([17]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 [1]: Connecting to
51.210.223.36:465
submission([18]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
Connecting
submission([19]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Waiting
for connect (fd=8) to finish for max 0 msecs
submission([20]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn
unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnected:
Connection closed (fd=15)
submission([21]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: conn
unix:/run/dovecot2/dns-client (pid=3388288,uid=0): Disconnect: deinit
submission([22]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Client
connected (fd=8)
submission([23]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Starting
SSL handshake
submission([24]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x10, ret=1: before SSL initialization
submission([25]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: before SSL initialization
submission([26]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello
submission([27]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello
submission([28]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello
submission([29]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1002, ret=-1: SSLv3/TLS write client hello
submission([30]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write client hello
submission([31]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server hello
submission([32]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read encrypted
extensions
submission([33]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: Received valid SSL certificate: /C=US/O=Internet
Security Research Group/CN=ISRG Root X2
submission([34]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: Received valid SSL certificate: /C=US/O=ISRG/CN=Root YE
submission([35]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: Received valid SSL certificate: /C=US/O=Let's
Encrypt/CN=YE1
submission([36]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: Received valid SSL certificate: /CN=smtp.migadu.com
submission([37]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read server
certificate
submission([38]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: TLSv1.3 read server
certificate verify
submission([39]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS read finished
submission([40]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write change cipher
spec
submission([41]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1001, ret=1: SSLv3/TLS write finished
submission([42]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x20, ret=1: SSL negotiation finished
successfully
submission([43]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL: where=0x1002, ret=1: SSL negotiation finished
successfully
submission([44]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: SSL
handshake successful
submission([45]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received
greeting from server: 220 smtp.migadu.com ESMTP Service Ready
submission([46]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending
EHLO handshake
submission([47]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
EHLO: Submitted with priority
submission([48]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
EHLO: Sent: EHLO mail.example.com
submission([49]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com
PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN
AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued)
submission([50]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received
handshake reply
submission([51]me@example.com)<3453761><tfS6...>: Warning: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received
invalid EHLO response line: Unexpected character in EHLO keyword
submission([52]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received
server capabilities
submission([53]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
Authenticating as [54]me@example.com
submission([55]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
AUTH: Submitted with priority
submission([56]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
EHLO: Destroy (0 commands pending, 1 commands queued)
submission([57]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
AUTH: Sent: AUTH PLAIN <snip>
submission([58]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
AUTH: Got reply (1/1): 235 2.0.0 Authentication succeeded (1 commands
pending, 0 commands queued)
submission([59]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
Authenticated successfully
submission([60]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Sending
EHLO handshake
submission([61]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
EHLO: Submitted with priority
submission([62]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
AUTH: Destroy (0 commands pending, 1 commands queued)
submission([63]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
EHLO: Sent: EHLO mail.example.com
submission([64]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
EHLO: Got reply (1/1): 250 smtp.migadu.com Hello mail.example.com
PIPELINING 8BITMIME ENHANCEDSTATUSCODES CHUNKING AUTH PLAIN LOGIN
AUTH=PLAIN LOGIN SIZE 52428800 (1 commands pending, 0 commands queued)
submission([65]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received
handshake reply
submission([66]me@example.com)<3453761><tfS6...>: Warning: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received
invalid EHLO response line: Unexpected character in EHLO keyword
submission([67]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Received
server capabilities
submission([68]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
Connection ready
submission([69]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Timeout start
submission([70]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
EHLO: Destroy (0 commands pending, 0 commands queued)
submission([71]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Received new command: MAIL
FROM:<[72]sender@example.com>
submission([73]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: command MAIL: New command
submission([74]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: command MAIL: Execute command
submission([75]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
transaction: Created
submission([76]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
transaction: Start
submission([77]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Add
transaction
submission([78]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
[plug]: Submitted
submission([79]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: command MAIL: Next to reply
submission([80]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Timeout stop
submission([81]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start
next transaction
submission([82]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
transaction: Connection is ready for transaction
submission([83]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
transaction: Sending MAIL command
submission([84]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
MAIL: Submitted
submission([85]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
[plug]: Aborted
submission([86]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
[plug]: Removed from send queue
submission([87]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
[plug]: Destroy (0 commands pending, 1 commands queued)
submission([88]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
MAIL: Sent: MAIL FROM:<[89]sender@example.com>
[90]AUTH=relay@example.com
submission([91]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Start
timeout
submission([92]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Reset
timeout
submission([93]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: command
MAIL: Got reply (1/1): 530 5.7.0 authentication required (1 commands
pending, 0 commands queued)
submission([94]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: No
commands pending; stop timeout
submission([95]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
transaction: Got MAIL reply: 530 5.7.0 authentication required
submission([96]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
transaction: Abort
submission([97]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]: Abort
transaction
submission([98]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
transaction: Aborted
submission([99]me@example.com)<3453761><tfS6...>: Error: relay: Server
requires authentication: 530 5.7.0 authentication required
submission([100]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Sent: 421 4.3.5 mail.example.com Internal
error occurred. Refer to server log for more information.
submission([101]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Disconnected: Internal error occurred.
Refer to server log for more information. (unfinished MAIL command)
(state=MAIL FROM)
submission([102]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Connection state reset
submission([103]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: command MAIL: Abort
submission([104]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: command MAIL: Destroy
submission([105]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
Disconnected
submission([106]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
smtp.migadu.com: SSL alert: close notify
submission([107]me@example.com)<3453761><tfS6...>: Debug: relay:
smtp-client: conn smtp.migadu.com:465 (51.210.223.36:465) [1]:
Disconnected: Connection closed (fd=8)
submission([108]me@example.com)<3453761><tfS6...>: Disconnected:
Internal error occurred. Refer to server log for more information.
(unfinished MAIL command) (state=MAIL FROM) in=36 out=124
submission([109]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Disconnected: Connection closed (fd=9)
submission([110]me@example.com)<3453761><tfS6...>: Debug: smtp-server:
conn 192.168.70.182:50608 [1]: Connection destroy
submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465
(51.210.223.36:465) [1]: transaction: Destroy
submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465
(51.210.223.36:465) [1]: transaction: Abort
submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465
(51.210.223.36:465) [1]: Abort transaction
submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465
(51.210.223.36:465) [1]: command MAIL: Destroy (0 commands pending, 0
commands queued)
submission(3453761): Debug: relay: smtp-client: conn smtp.migadu.com:465
(51.210.223.36:465) [1]: Destroy
_______________________________________________
dovecot mailing list -- [111]dovecot@dovecot.org
To unsubscribe send an email to [112]dovecot-leave@dovecot.orgReferences
Visible links
- https://doc.dovecot.org/latest/core/config/submission.html#submission-server
- mailto:dovecot@dovecot.org
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:sender@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:sender@example.com
- mailto:AUTH=relay@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:me@example.com
- mailto:dovecot@dovecot.org
- mailto:dovecot-leave@dovecot.org
participants (4)
-
Aki Tuomi
-
John Stoffel
-
Paul Kudla
-
Simonas Kazlauskas