Troubleshoot failed Incoming emails in Exchange 2013 with Symantec Mail Security for Exchange

I thought I'd put up some of my notes used to track and troubleshoot failures of incoming emails. Most recently, our hosted Exchange server seems to be the center of the universe! Yes...in the eyes of our users, all missed and non delivered emails are somehow the fault our server and department! The hardest thing is getting enough basic information from our users so we have even a chance at tracking down the reason why an incoming message didn't make to our server safe and sound. I this basic list to remind folks what they need to give me so I can target the problem.  

·        ·           Email Address of failed sender
·          Date and Time the message was sent
·         Email Address(es) of the intended recipient(s)
·         A copy of the failed email message (if any)
·         Bounce back message\NDR from intended recipient (if any)
·         Attachment information: Size, File extension\type
·         Any other error information relating to the sending PC (ie virus alerts, connection errors, etc.)

Below are my notes in kind of a raw form- hopefully they prove usefully to somebody. This particular server hosts both the Mailbox and Client Access role...plus it's running Symantec Mail Security for Exchange-- so anything that makes it past the Connection Filtering agent (which checks incoming IPs wishing to connect to our server against our subscribed DNS Block lists) and the Default Front End receiver (all inbound SMTP mail), will subsequently be checked by the Symantec agents for content, viruses, etc. 

I realize this is not the normal setup. Most shops would have some sort of edge device and or load balancer that would scan the incoming mail before it reaches the MBX server...but we have a "condensed" setup if you will. Although traffic is firewalled via our ISP before it reaches our box


What I'm checking for here is why emails from Adrad.com are not making it to our recipients- here's the sequence and logs I used to find the culprit! 

Summary:

·         Exchange Connection Filtering logs

C:\Program Files\Microsoft\Exchange Server\V15\TransportRoles\Logs\FrontEnd\AgentLog

·         Front End Receive Logs

C:\Program Files\Microsoft\Exchange Server\V15\TransportRoles\Logs\FrontEnd\ProtocolLog\SmtpReceive

·         Message Tracking logs

C:\Program Files\Microsoft\Exchange Server\V15\TransportRoles\Logs\MessageTracking

·         Exchange Server  Application Log in Event Viewer (filter events to make log more manageable)

*********************************************************************************

Details:

Check the following logs in this order- note that exchange log entries are all time stamped in GMT time- so subtract 5 hours to get the adjusted military time for our zone. (EST)

Exchange Connection Filtering logs

C:\Program Files\Microsoft\Exchange Server\V15\TransportRoles\Logs\FrontEnd\AgentLog

Check this log FIRST!

If the sending server is on one of our block lists, then it's a done deal- won't go beyond here. Check the IP of the sending server from the CF logs- see if it's on other block lists, including SPAM Cop and Spamhaus (our lists) - in this case...adrad.com is clean! No entries here…

Front End Receive Logs

C:\Program Files\Microsoft\Exchange Server\V15\TransportRoles\Logs\FrontEnd\ProtocolLog\SmtpReceive

Check the Frontend to see if the message is even getting to our server at all. Search on sender and recipient email address and TIME message was sent!! Nice to have the TIME! This is crucial unless you want to aimlessly search tons of logs!

Note: Will not get subject here!

2014-01-14T16:20:36.117Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,0,10.38.187.3:25,170.163.48.241:52202,+,,

2014-01-14T16:20:36.117Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,1,10.38.187.3:25,170.163.48.241:52202,*,SMTPSubmit SMTPAcceptAnySender SMTPAcceptAuthoritativeDomainSender AcceptRoutingHeaders,Set Session Permissions

2014-01-14T16:20:36.117Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,2,10.38.187.3:25,170.163.48.241:52202,>,"220 EXCHANGE.ourdomain.net Microsoft ESMTP MAIL Service ready at Tue, 14 Jan 2014 11:20:35 -0500",

2014-01-14T16:20:36.133Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,3,10.38.187.3:25,170.163.48.241:52202,<,HELO wlfd1-sophos01.adrad.com,

2014-01-14T16:20:36.133Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,4,10.38.187.3:25,170.163.48.241:52202,>,250 EXCHANGE.ourdomain.net Hello [170.163.48.241],

2014-01-14T16:20:36.164Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,5,10.38.187.3:25,170.163.48.241:52202,<,MAIL FROM:<gina.coffin@adrad.com>,

2014-01-14T16:20:36.164Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,6,10.38.187.3:25,170.163.48.241:52202,*,08D0DAE814F1B85F;2014-01-14T16:20:36.117Z;1,receiving message

2014-01-14T16:20:36.164Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,7,10.38.187.3:25,170.163.48.241:52202,>,250 2.1.0 Sender OK,

2014-01-14T16:20:36.180Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,8,10.38.187.3:25,170.163.48.241:52202,<,RCPT TO:<gibsonj@ourdomain.net>,

2014-01-14T16:20:36.180Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,9,10.38.187.3:25,170.163.48.241:52202,>,250 2.1.5 Recipient OK,

2014-01-14T16:20:36.195Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,10,10.38.187.3:25,170.163.48.241:52202,<,RCPT TO:<neumeyeJ@ourdomain.net>,

2014-01-14T16:20:36.211Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,11,10.38.187.3:25,170.163.48.241:52202,>,250 2.1.5 Recipient OK,

2014-01-14T16:20:36.227Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,12,10.38.187.3:25,170.163.48.241:52202,<,DATA,

2014-01-14T16:20:36.227Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,13,10.38.187.3:25,170.163.48.241:52202,>,354 Start mail input; end with <CRLF>.<CRLF>,

2014-01-14T16:20:36.242Z,EXCHANGE\Default Frontend EXCHANGE,08D0DAE814F1B85F,14,10.38.187.3:25,170.163.48.241:52202,*,,Proxy destination(s) obtained from OnProxyInboundMessage event

Message Tracking logs

C:\Program Files\Microsoft\Exchange Server\V15\TransportRoles\Logs\MessageTracking

On to the Hub Transport service. Search on sender and recipient email addresses with TIME frame- look for "Agent,Fail"

Then you'll get the message subject here, and Agent that's involved...but still  no reason or match list term (SMSMSE)

2014-01-14T16:20:36.305Z,,,,EXCHANGE,No suitable shadow servers,,SMTP,HAREDIRECTFAIL,7292854469256,<0AE889256C2C3D4483EA9B8508D89C970C939D29@TRMB1-MSV01EXCH.addomain1.adrad.com>,027a9e0d-7900-41d1-74d5-08d0df5bb0ef,gibsonj@ourdomain.net;neumeyeJ@ourdomain.net,,20165,2,,,FW: ASE - GAME On - Monday,gina.coffin@adrad.com,gina.coffin@adrad.com,,Undefined,,,,S:DeliveryPriority=Normal

2014-01-14T16:20:36.570Z,172.16.240.11,EXCHANGE.ourdomain.net,172.16.240.11,EXCHANGE,08D0DAE7F4D6A13E;2014-01-14T16:19:00.680Z;0,EXCHANGE\Default EXCHANGE,SMTP,RECEIVE,7292854469256,<0AE889256C2C3D4483EA9B8508D89C970C939D29@TRMB1-MSV01EXCH.addomain1.adrad.com>,027a9e0d-7900-41d1-74d5-08d0df5bb0ef,gibsonj@ourdomain.net;neumeyeJ@ourdomain.net,,20165,2,,,FW: ASE - GAME On - Monday,gina.coffin@adrad.com,gina.coffin@adrad.com,0cA: ,Undefined,,170.163.48.241,10.38.187.3,S:FirstForestHop=EXCHANGE.ourdomain.net;S:ProxiedClientIPAddress=64.95.41.162;S:ProxiedClientHostname=eworker077.msgbsvc.com;S:ProxyHop1=EXCHANGE.ourdomain.net(10.38.187.3);S:DeliveryPriority=Normal

2014-01-14T16:20:36.602Z,,EXCHANGE,,,SMSMSERoutingAgent,,AGENT,FAIL,7292854469256,<0AE889256C2C3D4483EA9B8508D89C970C939D29@TRMB1-MSV01EXCH.addomain1.adrad.com>,027a9e0d-7900-41d1-74d5-08d0df5bb0ef,gibsonj@ourdomain.net,'550 4.3.2 QUEUE.TransportAgent; message deleted by transport agent',20165,1,,,FW: ASE - GAME On - Monday,gina.coffin@adrad.com,gina.coffin@adrad.com,2014-01-14T16:20:36.164Z;SRV=EXCHANGE.ourdomain.net:TOTAL=0;SRV=EXCHANGE.ourdomain.net:TOTAL=0;CAT|CATSM|CATSM-SMSMSERoutingAgent,Undefined,,,,S:E2ELatency=0;S:DeliveryPriority=Normal

2014-01-14T16:20:36.602Z,,EXCHANGE,,,SMSMSERoutingAgent,,AGENT,FAIL,7292854469256,<0AE889256C2C3D4483EA9B8508D89C970C939D29@TRMB1-MSV01EXCH.addomain1.adrad.com>,027a9e0d-7900-41d1-74d5-08d0df5bb0ef,neumeyeJ@ourdomain.net,'550 4.3.2 QUEUE.TransportAgent; message deleted by transport agent',20165,1,,,FW: ASE - GAME On - Monday,gina.coffin@adrad.com,gina.coffin@adrad.com,2014-01-14T16:20:36.164Z;SRV=EXCHANGE.ourdomain.net:TOTAL=0;SRV=EXCHANGE.ourdomain.net:TOTAL=0;CAT|CATSM|CATSM-SMSMSERoutingAgent,Undefined,,,,S:E2ELatency=0;S:DeliveryPriority=Normal

Exchange Server  Application Log in Event Viewer: (Symantec reports in the console suck- useless! Don't bother)

 Search for message subject you got from the Message Tracking  logs, then you can get the reason for the violation\deletion and the match list term.

In this case it's -  "you have received this email" (Matchlist name : Sample Message Body Words)

And there you go- You found the reason for the deletion….

Log Name:      Application

Source:        Symantec Mail Security for Microsoft Exchange

Date:          1/14/2014 11:21:20 AM

Event ID:      291

Task Category: Content Enforcement Rules

Level:         Warning

Keywords:      Classic

User:          N/A

Computer:      EXCHANGE.ourdomain.net

Description:

The message "FW: ASE - GAME On - Monday" located in SMTP has violated the following policy settings:

                Scan: Auto-Protect

                Rule: TPS Body

                Violating term(s):

                    you have received this email (Matchlist name : Sample Message Body Words)

The following actions were taken on it:

                The message "FW: ASE - GAME On - Monday" was marked for Deletion for the following reason(s):

                                A Filtering Rule was violated.