Messages

1

22.7 Legacy Series / Re: Outgoing SMTP Timeout Issue Upgrading Past 22.1

« on: December 09, 2022, 02:02:31 am »

As their were not firewall log failures, we started changing various mail settings, disabling DKIM, changing SMTP ports, STARTTLS, etc. We changed the LAN MTU to 1500 MTU. Evidently the DKIM payload added to the end of the DATA stream was causing the receiving server to not receive the DKIM and the connection time-outs occurred.
< solved >

2

22.7 Legacy Series / Outgoing SMTP Timeout Issue Upgrading Past 22.1

« on: December 08, 2022, 01:53:31 am »

Have multiple app servers that run a SMTPClient.  One of them "hangs" (really a timeout) during the DATA part of sending SMTP mail while behind an OPNsense firewall higher than 21.7.

We also tried with a previously used SonicWall, an old Netgear VPN firewall, and that server can send SMTP out okay.

The other app servers do not have DKIM enabled. This one does, and is the only one that is experiencing the issue. That said, I don't know that DKIM being set-up is the cause.

Firewall Set-up:
OPNsense 22.7.9-amd64
FreeBSD 13.1-RELEASE-p5
OpenSSL 1.1.1s 1 Nov 2022

WAN:
Static IP, with /27 mask
2000 MTU
Virtual IPs

LAN:
/24 network
9000 MTU
DHCPv4
UnboundDNS

Set-up like this:
www.mindwatering.com/SupportRef.nsf/all/9e8e197f3fa8f50d8525890f0059da37

If I decide to perform STARTTLS and not use port 587 submission,  my outgoing transfer pauses after the DATA initial content is transferred, then a minute or so later, the timeout occurs. It goes to disconnect and is "already disconnected".

[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: Attempting to Connect: Host mx02.mail.ICLOUD.COM, Port 25, SSL Port 0, Connecting Domain myserver.mydomain.com
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: Connection successful
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 220 iCloud SMTP - pv33p00im-smtpin025.me.com 3.5.0 (2304BSE8-291bbfc7afcc)
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: CommandEHLO: EHLO myserver.mydomain.com
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250-pv33p00im-smtpin025.me.com
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250-PIPELINING
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250-SIZE 28311552
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250-ETRN
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250-STARTTLS
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250-ENHANCEDSTATUSCODES
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250-8BITMIME
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250-DSN
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250 CHUNKING
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: CommandSTARTTLS: STARTTLS
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:25 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 220 2.0.0 Ready to start TLS
SMTPClient: SMTP Authentication is not required by local server. Username: -blank-
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:31 PM Router: Transferring mail to domain ICLOUD.COM (host mx02.mail.ICLOUD.COM [17.56.9.19]) via SMTP
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:31 PM [013510:000014-00007F5E93CBE700] SMTPClient: Attempting to SubmitMessage:
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:31 PM [013510:000014-00007F5E93CBE700] SMTPClient: Pipelined commands:
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:31 PM [013510:000014-00007F5E93CBE700] SMTPClient: MAIL FROM:<design@mydomain.com> SIZE=5664
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:31 PM [013510:000014-00007F5E93CBE700] SMTPClient: RCPT TO:<targetrecipientname@icloud.com>
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:31 PM [013510:000014-00007F5E93CBE700] SMTPClient: DATA
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:31 PM [013510:000014-00007F5E93CBE700] SMTPClient: End of pipelined commands
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:32 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250 2.1.0 Ok
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:32 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 250 2.1.5 Ok
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:32 PM [013510:000014-00007F5E93CBE700] SMTPClient: ReceiveResponse: 354 End data with <CR><LF>.<CR><LF>
[013510:000014-00007F5E93CBE700] 12/05/2022 10:46:32 PM [013510:000014-00007F5E93CBE700] SMTPClient: Data Send Succeeded 5548 bytes
...
<wait until timeout>
...
[013903:000015-00007FB1B78CA700] 12/05/2022 11:09:50 PM [013903:000015-00007FB1B78CA700] SMTPClient: ReceiveResponse: 421 4.4.2 pmx.abv.bg Error: timeout exceeded
[013903:000015-00007FB1B78CA700] 12/05/2022 11:09:50 PM [013903:000015-00007FB1B78CA700] SMTPClient: Attempting to Disconnect:
[013903:000015-00007FB1B78CA700] 12/05/2022 11:09:50 PM [013903:000015-00007FB1B78CA700] SMTPClient: CommandQUIT:
[013903:000014-00007FB1B79CC700] 12/05/2022 11:09:51 PM [013903:000014-00007FB1B79CC700] SMTPClient: ReceiveResponse: 421 4.4.2 pv33p00im-smtpin034.me.com Error: timeout exceeded
[013903:000014-00007FB1B79CC700] 12/05/2022 11:09:51 PM [013903:000014-00007FB1B79CC700] SMTPClient: Attempting to Disconnect:
[013903:000014-00007FB1B79CC700] 12/05/2022 11:09:51 PM [013903:000014-00007FB1B79CC700] SMTPClient: CommandQUIT:
[013903:000014-00007FB1B79CC700] 12/05/2022 11:09:51 PM [013903:000014-00007FB1B79CC700] SMTPClient: Connection terminated with status: 2562
[013903:000014-00007FB1B79CC700] 12/05/2022 11:09:51 PM Router: No messages transferred to ICLOUD.COM (host mx02.mail.ICLOUD.COM) via SMTP


If I decide to disable TLS on port 25, and use port 587 submission, my outgoing transfer briefly pauses after the DATA initial content is transferred, and I may see an error "status 2567" depending on the target/receiving mail server.
...
[013903:000015-00007FB1B78CA700] 12/06/2022 09:36:35 AM [013903:000015-00007FB1B78CA700] SMTPClient: Data Send Failed 311144 bytes, Status: 2567
[013903:000015-00007FB1B78CA700] 12/06/2022 09:36:35 AM [013903:000015-00007FB1B78CA700] SMTPClient: Connection broken after an error sending DATA command
[013903:000015-00007FB1B78CA700] 12/06/2022 09:36:35 AM [013903:000015-00007FB1B78CA700] SMTPClient: Attempting to Disconnect:
[013903:000015-00007FB1B78CA700] 12/06/2022 09:36:35 AM [013903:000015-00007FB1B78CA700] SMTPClient: Connection already disconnected
[013903:000015-00007FB1B78CA700] 12/06/2022 09:36:35 AM Router: No messages transferred to GMAIL.COM (host gmail-smtp-in.l.google.COM) via SMTP