Ugh. And my attempts at redacting yielded an incomplete log. I’ve got to slow down. Here is the complete log:
[2023.03.06] 13:39:02.921 [204.101.223.59][57867550] rsp: 220 mail.mercury.net [2023.03.06] 13:39:02.921 [204.101.223.59][57867550] connected at 3/6/2023 1:39:02 PM [2023.03.06] 13:39:02.921 [204.101.223.59][57867550] Country code: CA [2023.03.06] 13:39:02.952 [204.101.223.59][57867550] cmd: EHLO ESA2-Dor.bell.ca [2023.03.06] 13:39:02.952 [204.101.223.59][57867550] rsp: 250-mail.mercury.net Hello [204.101.223.59]250-SIZE 69905066250-AUTH LOGIN CRAM-MD5250-STARTTLS250-8BITMIME250-DSN250 OK [2023.03.06] 13:39:02.983 [204.101.223.59][57867550] cmd: STARTTLS [2023.03.06] 13:39:02.983 [204.101.223.59][57867550] rsp: 220 Start TLS negotiation [2023.03.06] 13:39:03.077 [204.101.223.59][57867550] cmd: EHLO ESA2-Dor.bell.ca [2023.03.06] 13:39:03.077 [204.101.223.59][57867550] rsp: 250-mail.mercury.net Hello [204.101.223.59]250-SIZE 69905066250-AUTH LOGIN CRAM-MD5250-8BITMIME250-DSN250 OK [2023.03.06] 13:39:03.108 [204.101.223.59][57867550] cmd: MAIL FROM: SIZE=16961 [2023.03.06] 13:39:03.108 [204.101.223.59][57867550] senderEmail(1): [email protected] parsed using: [2023.03.06] 13:43:28.716 [204.101.223.59][57867550] rsp: 250 OK Sender ok [2023.03.06] 13:43:28.716 [204.101.223.59][57867550] Sender accepted. Weight: 4. Block threshold: 36. Failed checks: _SPF (4,None) [2023.03.06] 13:43:28.748 [204.101.223.59][57867550] cmd: RCPT TO: [2023.03.06] 13:43:28.748 [204.101.223.59][57867550] rsp: 250 OK Recipient ok [2023.03.06] 13:43:28.763 [204.101.223.59][57867550] cmd: DATA [2023.03.06] 13:43:28.763 [204.101.223.59][57867550] Performing PTR host name lookup for 204.101.223.59 [2023.03.06] 13:43:28.763 [204.101.223.59][57867550] PTR host name for 204.101.223.59 resolved as esa2-dor.bell.ca [2023.03.06] 13:43:28.763 [204.101.223.59][57867550] rsp: 354 Start mail input; end with . [2023.03.06] 13:43:28.810 [204.101.223.59][57867550] senderEmail(2): [email protected] parsed using: “Redacted” <[email protected]> [2023.03.06] 13:43:28.810 [204.101.223.59][57867550] Sender accepted. Weight: 4. Block threshold: 36. Failed checks: _SPF (4,None) [2023.03.06] 13:45:33.408 [204.101.223.59][57867550] rsp: 421 Command timeout, closing transmission channel [2023.03.06] 13:45:33.408 [204.101.223.59][57867550] disconnected at 3/6/2023 1:45:33 PM [2023.03.06] 13:48:59.847 [204.101.223.59][57867550] rsp: 250 OK [2023.03.06] 13:48:59.847 [204.101.223.59][57867550] Client socket is disconnected! Disconnect exception encountered: True, IsDisconnected: True, This message will still be accepted. [2023.03.06] 13:48:59.847 [204.101.223.59][57867550] Received message size: 17588 bytes [2023.03.06] 13:48:59.847 [204.101.223.59][57867550] Successfully wrote to the HDR file. (d:\mail\spool\SubSpool9\1391309161820.hdr) [2023.03.06] 13:48:59.847 [204.101.223.59][57867550] Data transfer succeeded, writing mail to 1391309161820.eml (MessageID: ) My apologies for the signal to noise ratio. Dave > On Mar 7, 2023, at 1:29 PM, David Sovereen via mailop <[email protected]> > wrote: > > >> On Mar 7, 2023, at 12:54 PM, Bastian Blank via mailop <[email protected]> >> wrote: >> >> Hi David >> >> On Tue, Mar 07, 2023 at 12:26:41PM -0500, David Sovereen via mailop wrote: >>> I’m trying to reach someone at bell.ca <http://bell.ca/> who can help us >>> with two inter-related issues. >> >> Why do you link to http://bell.ca/? Or is that some unhelpful client >> again? > > Yes, an unhelpful mail client. > >> >>> 1. Their SMTP servers send mail without a QUIT. If we require a QUIT, our >>> users cannot receive any bell.ca <http://bell.ca/> mail. >> >> SMTP servers don't send e-mail, they receive e-mail. You mean SMTP >> client. However an e-mail transaction ends with <CRLF>.<CRLF>. So at >> the time QUIT would be sent, no e-mail transaction is running. > > My apologies. I was trying to get an email out quickly before running to a > meeting and completely mischaracterized the problem. The problem is that the > *client* disconnects before receiving 250 OK. Here’s a log: > > [2023.03.06] 13:43:28.763 [204.101.223.59][57867550] cmd: DATA > [2023.03.06] 13:43:28.763 [204.101.223.59][57867550] Performing PTR host name > lookup for 204.101.223.59 > [2023.03.06] 13:43:28.763 [204.101.223.59][57867550] PTR host name for > 204.101.223.59 resolved as esa2-dor.bell.ca > [2023.03.06] 13:43:28.763 [204.101.223.59][57867550] rsp: 354 Start mail > input; end with <CRLF>.<CRLF> > [2023.03.06] 13:43:28.810 [204.101.223.59][57867550] senderEmail(2): > [email protected] parsed using: “Redacted” <[email protected]> > [2023.03.06] 13:43:28.810 [204.101.223.59][57867550] Sender accepted. Weight: > 4. Block threshold: 36. Failed checks: _SPF (4,None) > [2023.03.06] 13:45:33.408 [204.101.223.59][57867550] rsp: 421 Command > timeout, closing transmission channel > [2023.03.06] 13:45:33.408 [204.101.223.59][57867550] disconnected at 3/6/2023 > 1:45:33 PM > [2023.03.06] 13:48:59.847 [204.101.223.59][57867550] rsp: 250 OK > [2023.03.06] 13:48:59.847 [204.101.223.59][57867550] Client socket is > disconnected! Disconnect exception encountered: True, IsDisconnected: True, > This message will still be accepted. > [2023.03.06] 13:48:59.847 [204.101.223.59][57867550] Received message size: > 17588 bytes > [2023.03.06] 13:48:59.847 [204.101.223.59][57867550] Successfully wrote to > the HDR file. (d:\mail\spool\SubSpool9\1391309161820.hdr) > > If we accept delivery as we did here where they disconnect before we send 250 > OK, the message gets delivered to our end user. But the end user sometimes > gets duplicate messages, sometimes many duplicate messages. If we don’t > accept messages from clients that stay connected until the 250 OK is given, > no bell.ca emails get through. > > Dave > _______________________________________________ > mailop mailing list > [email protected] > https://list.mailop.org/listinfo/mailop _______________________________________________ mailop mailing list [email protected] https://list.mailop.org/listinfo/mailop
