TLDR || ERTP = email did not match rule. ETR = email DID match rule – Then match the <GUID> to a rule (get-transportrule <GUID> | fl description) and you’ve worked out the rule. + sometimes you need to look deeper into tracking because messages bifurcate when they have multiple recipients and are processed separately. To find the bifurcated things message track harder bro.

Back story

At work my team fixes things busted on the servers. We don’t help educate the customer how to use the servers. Education belongs to the internet and or other teams here. Few days ago a ticket was raised to my team with “NDR caused by rule – tell us what rule” I closed the ticket with ” homie don’t play that, customer self-service – message tracking, agentinfo, eventdata – it is all there” – Next day the ticket came back with “customer needs help” Normally I’m pretty helpful, but I have a personal rule created out of pain about Transport rules – NEVER TOUCH A RULE | once you touch a rule you OWN THE RULE FOR LIFE –

Following my own rules, I closed the ticket again and said “no call someone who teaches nothing is wrong here.” But, having a hard time letting go I kept working on the ticket and wanted provide the answer. Looking through the message tracking in the case I was not able to work out which rule was NDRing the message. Customer had ~27 rules configured to NDR things. The NDR could have been any one of them. I spent a few hours trying to work out which one then, ended up saying F-it and asked for help to work out the rule. Help and I eventually ended up talking with the transport Devs and we still had a hard time working out what was going on. – By now I’m a few hours into working it out, reading code, and talking to people and still don’t have much of a clue yet. Another of my rules, if you have to search for more than 20 minutes to find an answer then you must write the answer. – Now I’m writing about working out rules and researching what all of the letters mean.

Some learning about Reading Transport rules

In my head I thought I’d figured out read message tracking to work out which rule hit a message. Then this case. Below I’ll layout what I thought I understood with some of the new learning tossed in then after the wall of GUIDS I’ll explain what hit in the side of the face on this issue caused the confusion.

Message tracking

We tracked the message based on sender and subject. This KB covers what all of the words mean much better than I can cover them. Each EventId below represents transport doing something to a message. We care about rules touching messages, so we care about the AGENTINFO EventId.

AGENTINFO event

The Agentinfo block shows data about the agents touching a message during Categorization. Again, this KB covers what all of the words mean much better than I can cover them. When you are analyzing rule application the data you care about resides in the EVENTDATA field of the AGENTINFO event which is a super messy not simple to read field.

Eventdata stuff cleaned up

The Eventdata stuff is far from simple to read being all full of numbers and letters not meaning much to normal humans, plus piles of GUIDS, and bad wrapping after the cut and paste from PowerShell. I cleaned it up a bit removing all of the extra spaces, and added a line break every time ], showed up in the data string. After cleaning the data, it becomes a bit simpler to read – see below. Things you’ll want to know to help reading the wall of GUIDS:

• TRA = Transport Rules Agent – simply saying the rules agent is doing the thing, vs AMA = Anti-malware agent doing the thing. We care about TRA for rules
• ETRP = Exchange Transport Rule Performance information. It’s showing how long it took the rule to be processed against message.
• ETR = Transport Rule or Data loss prevention (DLP) rule hit the message and was applied

In the EventData below we start with some AMA anti-malware events [1]. The second one tells us we have an attachment on the file. The next two AMA events tell us which anti-malware engines we are using and which signature file the engines used to touch the message. After the AMA events we are onto the TRA rule agent events filled with piles of ETRP performance events. Mixed in there is a single ETR, rule was processed event. Then some other stuff at the bottom. Our problem, the message in the ticket I was working on was NDRed based on message rule. The rule matching GUID e5qacqe7-897e-447q-8qe7-f5c19qc3c1q8 is not an NDR rule, it’s an apply a footer rule – enter the confusion.

{[AMA,EV|engine=M|v=0|sig=1.217.1767.0|name=|file=]
[AMA,SUM|v=0|action=|error=|atch=1]
[AMA,EV|engine=A|v=0|sig=201604192138|name=|file=]
[AMA,EV|engine=K|v=0|sig=19.4.2016 17:11:0|name=|file=]
[TRA,ETRP|ruleid=8qce6210-f8e4-47e4-8qq5-988a469ffaa0|st=2015-12-04T16:19:49.0000000Z|ExecW=0|ExecC=0]
[TRA,ETRP|ruleid=5405aq6q-3418-4c6c-95f1-qf3f8e5qqc5q|st=2016-03-16T16:11:18.0000000Z|ExecW=37|ExecC=15|Conditions=AttachmentContainsWordsPredicate,,4|Components=FIPS_TE,0,32]
[TRA,ETRP|ruleid=f2ae471a-5e65-478q-a81q-cec87ff901q5|st=2016-01-13T14:57:53.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=75ffe833-6a8q-4q64-9e1q-qfq41f913c3a|st=2015-12-04T16:19:49.0000000Z|ExecW=0|ExecC=0]
[TRA,ETRP|ruleid=q2e74344-e676-4q48-aff4-fcq0478306ec|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=5381f075-39f9-4q46-a4q4-e2700q62c195|st=2016-01-13T14:57:53.0000000Z|ExecW=3|ExecC=0|Conditions=MatchesRegexPredicate,Message.Body,2]
[TRA,ETRP|ruleid=172f13fq-4567-4e07-qa2q-07q39a0qfe01|st=2016-01-19T06:29:18.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=8q9q6qq1-c189-44q0-af91-31e2f3a9qe93|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=a2c63qqq-957a-4ca9-qf37-078q7eq53803|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETR |ruleid=e5qacqe7-897e-447q-8qe7-f5c19qc3c1q8|st=12/11/2015 4:05:17PM|action=SetHeaqer|sev=1|mode=Enforce]
[TRA,ETRP|ruleid=e5qacqe7-897e-447q-8qe7-f5c19qc3c1q8|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=37277454-79a7-4549-95q7-9f9032151201|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=9c74479f-6ce4-4qc4-80f4-92693e6e3ef5|st=2015-12-11T16:05:17.0000000Z|ExecW=0|ExecC=0]
[TRA,ETRP|ruleid=qce64cqe-3296-4cq1-8365-175a8969af5e|st=2015-12-11T16:05:17.0000000Z|ExecW=0|ExecC=0]
[TRA,ETRP|ruleid=0444ce0f-c417-4595-a665-cc950e465aa8|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=15]
[TRA,ETRP|ruleid=q9ec46qf-e6e9-4718-a4ee-qef1352q990e|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=5a5c4q9e-8513-4e2a-8989-36ca6e6aq27f|st=2016-02-29T14:51:57.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=c83c04fq-aqqq-41a4-983f-f3aafcc3aq72|st=2016-02-29T14:54:22.0000000Z|ExecW=2|ExecC=0|Conditions=MatchesRegexPredicate,Message.EnvelopeRecipients,1]
[TRA,ETRP|ruleid=8a268569-q804-4a4q-a8q6-fec44764q7ff|st=2016-01-27T14:41:28.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=0eq2fqec-f65f-4fq1-800e-59e93268f20f|st=2016-02-15T07:03:55.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=c3c44e7a-ef26-40fa-9811-c1c92q1ef42a|st=2016-02-29T14:50:10.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=02e6f520-974q-4q87-91f0-70747a415424|st=2016-03-01T07:25:57.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=q7qq6q86-q347-4969-q818-3q1f96fc9q63|st=2016-04-08T08:28:41.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=4831q0c5-cc4e-4428-qc87-4121710425ae|st=2016-04-13T08:26:03.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=c7020c87-e211-42fe-90eq-928f43fc09q6|st=2016-04-15T07:06:06.0000000Z|ExecW=1|ExecC=15]
[TRA,ETRP|ruleid=35388c07-39a5-48c1-9a87-94817qa05c09|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=aa6fq810-8656-4eq4-q560-88586003q892|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=7123f018-67ef-4656-q50a-360q07a6aac7|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=e8q752ee-13f8-4c5q-8597-qqq85qc40ac0|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=846f3981-q908-4148-q809-c042aq7qqca0|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=eaa7qe02-q1qa-4f68-9f72-q891c1754481|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=208aa189-q4f0-44e9-q01q-20f32q95cac1|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=cf415a39-90q9-4e7q-8e85-05q9qa6c5032|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=c2c956ce-q22a-4f89-aqc4-58f9c3a65qf5|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=q7c400f2-5133-4q6a-9a40-550c5691q76c|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=27q13f23-fff1-47c3-8q1c-80q9e67a18a7|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=15]
[TRA,ETRP|ruleid=e23a5e59-c87a-4qe2-q89a-6eaq916a788q|st=2016-03-28T20:49:50.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=6946q83f-65c4-47q6-8826-qcqfqcfa7c09|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=7730e203-9c64-4cfc-8caq-q608a0e06858|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=0167qf47-fq9e-467c-af81-q9894qqqec16|st=2016-02-25T20:27:45.0000000Z|ExecW=3|ExecC=0|Conditions=MatchesRegexPredicate,Message.Body,2]
[TRA,ETRP|ruleid=q02qe0eq-6800-47q1-a074-38ca321q849a|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=e02q52qa-9100-441q-81q3-f8fq8498ee9a|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=238q9q3f-75qc-4q43-a090-c0q92qc813c3|st=2016-01-13T14:57:53.0000000Z|ExecW=0|ExecC=0]
[TRA,ETRP|ruleid=ce66339q-0af4-4050-84c0-19147e19f9cf|st=2015-12-11T16:05:17.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=9c2e8600-8462-47e7-a841-318c30q1cc2a|st=2016-02-23T20:53:54.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=0302ef91-70cc-448a-qca1-91q3a7q7cq93|st=2016-04-07T17:42:33.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=904955ac-qa5a-46qq-8f23-0a2066304f88|st=2016-01-13T14:57:53.0000000Z|ExecW=1|ExecC=15]
[TRA,ETRP|ruleid=ae860q9q-6f20-4qq7-a49e-0cff058aee78|st=2016-01-13T14:57:53.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=9e259ec8-5053-48qc-8q4q-560f2e4c016f|st=2016-01-29T21:54:11.0000000Z|ExecW=0|ExecC=0]
[TRA,ETRP|ruleid=aff3250q-fc31-41q1-99aq-972fq3893358|st=2016-03-15T17:22:08.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=f3511c93-cc5q-4fq6-94c3-q6ae81839q19|st=2016-02-25T21:06:43.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRP|ruleid=e04e4977-10eq-477q-q66e-aq88c1067816|st=2016-03-22T15:40:11.0000000Z|ExecW=1|ExecC=0]
[TRA,ETRI|MsgType=Undefined|Ex=|IsKnown=|FipsStatus=Success]
[TRA,ETRP|ruleid=a54f0qq4-qccq-4133-q5f1-819c278cq1q7|st=2014-02-11T00:30:19.0000000Z|ExecW=0|ExecC=0]
[TRA,ETRI|MsgType=Undefined|Ex=|IsKnown=|FipsStatus=NoFips]
[CompCost, |AMA=0|ETR=0]
[DeliveryPriority, Normal]
[AccountForest, XXXXXX.com]}

The problem tracking

The problem was caused by insufficient tracking data provided in the case. We only had a single AGENTINFO event and the AGENTINFO event did not indicate an NDR rule was hitting the message. We know the message being NDRed because we had an NDR. After a bunch of digging and talking to DEV it turns out we had not performed enough message tracking. If you look at the recipients in the message tracking blob, you’ll notice there are more than 1 recipient is external – I anonymized the addresses and GUIDS in the data , so internal vs. external is not obvious. When a message is sent to an internal recipient and some external recipients the message bifurcates into multiple messages. You have to find all of those streams to find the ETR hitting your message.

Appendix Kev

More data about what the words and letters mean / how to read logs was obtained from the following sources, which might or might not be things you have access to.

• \XXXXXX\Transport\XXXXXX\LoggingEnums.XXX    — found all of the ETR, ETRP, TRA things here in source code with comments
• \XXXXXXX\MessageTracing\XXXXX\LogConstants.XXX — found all of the ETR, ETRP, TRA things here in source code with comments
• https://technet.microsoft.com/en-us/library/jj150520(v=exchg.150).aspx — explains what the ETR, ETRP, TRA things mean
• https://technet.microsoft.com/en-us/library/bb124375(v=exchg.160).aspx – explains what the message tracking fields / headers mean
• https://blogs.technet.microsoft.com/eopfieldnotes/2015/12/01/parsing-an-extended-message-trace-2/ — blog covers reading message tracking logs for EOP which applies well to Exchange.

[1] not reddit ask me anything events.