Hi,
We are having issue with one sender. All emails are usually delivered with no delay but from time to time the email would be delayed for few hours. I'm stuck and i don't know how to troubleshoot this issue. Client says it's on our side but recently another recipient reported delayed emails from the same sender. They are running Microsoft 2012 IIS SMTP server. All messages on our side look like this:
29 May 2019 15:59:06 (GMT +01:00) SMTP delivery connection (DCID 10968581) opened from Cisco IronPort interface 10.20.1.13 to IP address 10.20.1.25 on port 25.
29 May 2019 15:59:06 (GMT +01:00) Delivery connection (DCID 10968581) successfully accepted TLS protocol TLSv1.2 cipher ECDHE-RSA-AES256-SHA384 .
29 May 2019 15:59:11 (GMT +01:00) Protocol SMTP interface Data1 (IP 10.20.1.13) on incoming connection (ICID 26861598) from sender IP xxx.xxx.xxx.xxx. Reverse DNS host revdns.domain.com verified no.
29 May 2019 15:59:11 (GMT +01:00) (ICID 26861598) ACCEPT sender group UNKNOWNLIST match sbrs[-1.0:10.0] SBRS 3.5 sender IP xxx.xxx.xxx.xxx country United States
29 May 2019 15:59:12 (GMT +01:00) Incoming connection (ICID 26861598) successfully accepted TLS protocol TLSv1.2 cipher DHE-RSA-AES256-GCM-SHA384.
29 May 2019 15:59:12 (GMT +01:00) Start message 29386240 on incoming connection (ICID 26861598).
29 May 2019 15:59:12 (GMT +01:00) Message 29386240 enqueued on incoming connection (ICID 26861598) from sender@domain.com.
29 May 2019 15:59:12 (GMT +01:00) Message 29386240 on incoming connection (ICID 26861598) added recipient (recipient@domain.com).
29 May 2019 15:59:13 (GMT +01:00) Message 29386240 contains message ID header '<smtp@domain.com>'.
29 May 2019 15:59:13 (GMT +01:00) Message 29386240 original subject on injection: Subject
29 May 2019 15:59:13 (GMT +01:00) Message 29386240 (1519 bytes) from sender@domain.com ready.
29 May 2019 15:59:13 (GMT +01:00) (ICID 26861598) Unknown command: .
29 May 2019 15:59:13 (GMT +01:00) (ICID 26861598) Unknown command: .
29 May 2019 15:59:13 (GMT +01:00) (ICID 26861598) Unknown command: .
29 May 2019 15:59:13 (GMT +01:00) (ICID 26861598) Unknown command: ----_mabry_161574d547f9779c64035d8a.
29 May 2019 15:59:13 (GMT +01:00) Incoming connection (ICID 26861598) disconnected address xxx.xxx.xxx.xxx. Maximum number of bad SMTP commands exceeded.
29 May 2019 15:59:13 (GMT +01:00) Message 29386240 matched per-recipient policy Generic Mailboxes Policy for inbound mail policies.
29 May 2019 15:59:13 (GMT +01:00) Message 29386240 scanned by Anti-Virus engine Sophos. Interim verdict: CLEAN
29 May 2019 15:59:13 (GMT +01:00) Message 29386240 scanned by Anti-Virus engine. Final verdict: Negative
29 May 2019 15:59:13 (GMT +01:00) Message 29386240 scanned by Outbreak Filters. Verdict: Negative
29 May 2019 15:59:13 (GMT +01:00) Message 29386240 queued for delivery.
29 May 2019 15:59:13 (GMT +01:00) (DCID 10968581) Delivery started for message 29386240 to recipient@domain.com.
29 May 2019 15:59:13 (GMT +01:00) (DCID 10968581) Delivery details: Message 29386240 sent to recipient@domain.com
29 May 2019 15:59:13 (GMT +01:00) Message 29386240 to recipient@domain.com received remote SMTP response '2.6.0 <smtp@domain.com> [InternalId=607868] Queued mail for delivery'.
I tracked all rejected connections and it seems they are the only sender that gets rejected for exceeding bad commands.
Where from their side it looks like they are getting stuck after receiving 354 go ahead from ironport:
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionResponse SMTPSVC1 smtp@domain.com - 0 - - 220+ironport.anotherdomain.com+ESMTP 0 0 33 0 110 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionCommand SMTPSVC1 smtp@domain.com - 0 EHLO - smtp.domain.com 0 0 4 0 110 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionResponse SMTPSVC1 smtp@domain.com - 0 - - 250-ironport.anotherdomain.com 0 0 27 0 219 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionCommand SMTPSVC1 smtp@domain.com - 0 STARTTLS - - 0 0 8 0 219 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionResponse SMTPSVC1 smtp@domain.com - 0 - - 220+Go+ahead+with+TLS 0 0 21 0 329 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionCommand SMTPSVC1 smtp@domain.com - 0 EHLO - smtp.domain.com 0 0 4 0 750 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionResponse SMTPSVC1 smtp@domain.com - 0 - - 250-ironport.anotherdomain.com 0 0 27 0 844 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionCommand SMTPSVC1 smtp@domain.com - 0 MAIL - FROM:<sender@domain.com>+SIZE=157953 0 0 4 0 844 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionResponse SMTPSVC1 smtp@domain.com - 0 - - 250+sender+<sender@domain.com>+ok 0 0 45 0 954 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionCommand SMTPSVC1 smtp@domain.com - 0 RCPT - TO:<recipient@anotherdomain.com> 0 0 4 0 954 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionResponse SMTPSVC1 smtp@domain.com - 0 - - 250+recipient+<recipient@anotherdomain.com>+ok 0 0 49 0 1063 SMTP - - - -
2019-05-29 14:59:11 xxx.xxx.xxx.xxx OutboundConnectionCommand SMTPSVC1 smtp@domain.com - 0 DATA - - 0 0 4 0 1063 SMTP - - - -
2019-05-29 14:59:12 xxx.xxx.xxx.xxx OutboundConnectionResponse SMTPSVC1 smtp@domain.com - 0 - - 354+go+ahead 0 0 12 0 1172 SMTP - - - -
Their are getting rejected connection error but their emails gets delivered. Is that because they send <dot> and then they send another <dot> command but server expects <quit>?
Which side the issue is on?
How to troubleshoot this issue?
Thanks
