1
Odd email delivery issue
Problem reported by Scot Desort - 4/5/2024 at 10:36 AM
Submitted
So I have come across a strange issue sending email to a particular email address. This email address is one for the Intercom helpdesk system. Email coming into smartermail is being forwarded to IntercomMail for the purposes of creating a ticket. I have sent the same test email from various email addresses, and also tried with 2 email clients (Outlook desktop and Apple mail on a mobile device). The results are always the same:

[2024.04.05] 10:26:28.283 [23000731] Attempting to send to MXRecord 'inbound-smtp.us-east-1.amazonaws.com' ip: '54.164.173.191'
[2024.04.05] 10:26:28.283 [23000731] Sending remote mail to: redacted@intercom-mail.com
[2024.04.05] 10:26:28.283 [23000731] Initiating connection to 54.164.173.191
[2024.04.05] 10:26:28.283 [23000731] Connecting to 54.164.173.191:25 (Id: 2)
[2024.04.05] 10:26:28.283 [23000731] Binding to local IP X (Id: 2)
[2024.04.05] 10:26:28.309 [23000731] Connection to 54.164.173.191:25 from X:53137 succeeded (Id: 2)
[2024.04.05] 10:26:28.341 [23000731] RSP: 220 inbound-smtp.us-east-1.amazonaws.com ESMTP Amazon SES BJO8o3LwJ92BQgb7JBE1
[2024.04.05] 10:26:28.343 [23000731] CMD: EHLO redacted
[2024.04.05] 10:26:28.388 [23000731] RSP: 250-inbound-smtp.us-east-1.amazonaws.com
[2024.04.05] 10:26:28.388 [23000731] RSP: 250-8BITMIME
[2024.04.05] 10:26:28.388 [23000731] RSP: 250-STARTTLS
[2024.04.05] 10:26:28.388 [23000731] RSP: 250 Ok
[2024.04.05] 10:26:28.388 [23000731] CMD: STARTTLS
[2024.04.05] 10:26:28.420 [23000731] RSP: 220 Ready to start TLS
[2024.04.05] 10:26:28.665 [23000731] CMD: EHLO redacted
[2024.04.05] 10:26:28.701 [23000731] RSP: 250-inbound-smtp.us-east-1.amazonaws.com
[2024.04.05] 10:26:28.701 [23000731] RSP: 250-8BITMIME
[2024.04.05] 10:26:28.701 [23000731] RSP: 250-STARTTLS
[2024.04.05] 10:26:28.701 [23000731] RSP: 250 Ok
[2024.04.05] 10:26:28.701 [23000731] CMD: MAIL FROM:<redacted>
[2024.04.05] 10:26:28.732 [23000731] RSP: 250 Ok
[2024.04.05] 10:26:28.732 [23000731] CMD: RCPT TO:<redacted@intercom-mail.com>
[2024.04.05] 10:26:28.795 [23000731] RSP: 250 Ok
[2024.04.05] 10:26:28.795 [23000731] CMD: DATA
[2024.04.05] 10:26:28.826 [23000731] RSP: 354 End data with <CR><LF>.<CR><LF>
[2024.04.05] 10:26:28.826 [23000731] Exception: Object reference not set to an instance of an object.
[2024.04.05] Stack:    at MailService.RelayServer.Clients.SMTP.SmtpClientSession.SendData()   at MailService.RelayServer.Clients.SMTP.SmtpClientSession.GiveData()   at MailService.RelayServer.Clients.SMTP.SmtpClientSession.StartProcessing(String sessionId)10:26:28.826 [23000731] CMD: QUIT
[2024.04.05] 10:26:33.857 [23000731] Attempt to ip, '54.164.173.191' success: 'True'

And while it shows "success:true", the email isn't delivered. It DID eventually get delivered after several re-tries. Not really sure why one attempt would fail and another would succeed, without an error being thrown from the receiving server.



3 Replies

Reply to Thread
1
Douglas Foster Replied
Which Build?
0
Scot Desort Replied
Sorry. 8818
0
Sébastien Riccio Replied
Strange issue indeed.

According to the log timestamps I would say it looks like the latest response from the remote mail server "354 End data with <CR><LF>.<CR><LF>" is triggering an exception.

Maybe SM doesn't like the <CR><LF>.<CR><LF> stuff in the server response when it answer to DATA command.
Hypothetically, maybe it tries to parse the content between <> as e-mail addresses and this could trigger an exception ?


[2024.04.05] 10:26:28.826 [23000731] RSP: 354 End data with <CR><LF>.<CR><LF>
[2024.04.05] 10:26:28.826 [23000731] Exception: Object reference not set to an instance of an object.

I guess at this point only a SM dev could answer this one though...

Kind regards
Sébastien Riccio System & Network Admin https://swisscenter.com

Reply to Thread