In Learning Transport Agent Pipeline Tracing Hands-on (Part 1), we introduced this subject and applied it to capture an Exchange generated Non Delivery Report NDR. Today we continue with more examples and analyze more closely the trace results.
Test 3: Rejected Email
We now move to testing some scenarios where we apply pipeline tracing to anti-spam agents. We employ Recipient Filtering to test the rejection of an incorrect recipient address. We configure the pipeline tracing sender address to sender@adminstop.com as follows:
Set-TransportServer HAMRUN -PipelineTracingSenderAddress sender@adminstop.com
Set-TransportServer HAMRUN -PipelineTracingEnabled $True
Next we enable Recipient filtering and enable Recipient Filtering | 'Block messages sent to recipients that do not exist in the directory'
from the Management Console:
We now submit an email to a non-existing recipient (WrongAddress@wtest-dom1.local) using telnet until we get to the user unknown rejection:
telnet 192.168.0.60 25
ehlo test.adminstop.com
MAIL FROM: sender@adminstop.com
RCPT TO: WrongAddress@wtest-dom1.local
DATA
From: sender@adminstop.com
To: WrongAddress@wtest-dom1.local
Subject: Sending Email to Wrong Address
Sending Email to Wrong Address
bye
.
Looking at the trace data the dump is interesting since in this case we terminated the session immediately after that the recipient was rejected. In this case we only have one file (Original.eml) that contains just a few headers. This makes sense since we didn't really submit any email content ourselves. Here is all we got:
X-CreatedBy: MessageSnapshot-Begin injected headers
X-MessageSnapshot-UTC-Time: 2012-06-04T10:31:48.079Z
X-MessageSnapshot-Protocol-Id: 08CF10486E2A504C;2012-06-04T10:31:09.502Z;1
X-MessageSnapshot-Source: Original
X-Sender: sender@adminstop.com
X-Receiver: WrongAddress@wtest-dom1.local
Test 4: Email on the IP Allow List
In the last example we put our client machine IP to the Allow list, submit an email and see what happens. The IP Allow List is enabled from the anti-spam page shown in the previous example but the IP is added at the server configuration as shown below:
We retain the same pipeline tracing settings and submit the email:
telnet 192.168.0.60 25
ehlo test.adminstop.com
MAIL FROM: sender@adminstop.com
RCPT TO: user1@wtest-dom1.local
DATA
From: sender@adminstop.com
To: user1@wtest-dom1.local
Subject: Testing IP Allow List
Testing IP Allow List
bye
.
A Closer Look at the Trace Output
It's now time to take a closer look at the files generated by pipeline tracing. We will look at the snapshots produced in the last test.
As discussed earlier the number of snapshot files and the changes observed here depend on the set of transport agents installed. To best follow this article, you should at least be running the Exchange anti-spam agents at your transport server.
The last test should have generated three set of files:
Original.eml
SmtpReceive????.eml
Routing????.eml
Original.eml - The first snapshot showing the message before this is processed by any agents.
SmtpReceive???.eml - Are generated following agent processing for the SMTP events of type OnEndOfHeaders and OnEndofData.
Routing????.eml - Are generated following agent processing for the routing events OnRoutedMessage and OnSubmittedMessage.
Explaining the exact meaning of these event types is beyond the scope. Just keep in mind that an email goes through a number of stages. For example when all the email headers are received an OnEndOfHeaders event is raised. When the entire email is received an OnEndofData event is raised.
Go ahead and open SmtpReceive0001.eml and SmtpReceive0002.eml with notepad, in my case these files only contain headers. Take a look at one specific header X-MessageSnapshot-Source:
SmtpReceive0001.eml
X-MessageSnapshot-Source: OnEndOfHeaders
SmtpReceive0002.eml
X-MessageSnapshot-Source: OnEndOfHeaders,Inbound Trust Agent
The X-MessageSnapshot-Source is showing the Event type and the Agent name for which the dump was created. You may want to open subsequent files side by side and see if anything changed. Very often you will see that the only header changing is X-MessageSnapshot-Source which is a header injected into the snapshots by pipeline tracing and not part of the message itself.
If we keep on going through the SmtpReceive files, we get to a file that includes the email body. This will have a different event type:
X-MessageSnapshot-Source: OnEndOfData
Keep on opening the files until getting to the one having:
X-MessageSnapshot-Source: OnEndOfData,Content Filter Agent
Compare the headers in this file to the previous one. Here we can see that the Content Filter Agent added the headers:
X-MS-Exchange-Organization-Antispam-Report: IPOnAllowList
X-MS-Exchange-Organization-SCL: -1
X-MS-Exchange-Organization-Antispam-Report is telling us the reason for the SCL -1 assignment i.e. the IP of the machine submitting the email is on the IP Allow List. So this confirms that our IP Allow entry worked as expected.
We could go on opening the other files using the same approach to see what changes are the agents injecting.
Final Tips
Today we walked through a number of pipeline tracing tests seeing how the configuration changes were reflected in the trace output.
This type of investigation can of course be carried out when we are uncertain which Agent (if any) is responsible for some unwanted email modifications. It may turn out that the changes are not being done at the transport at all. For example there might be some client side application.
Pipeline tracing gives us a low level view that can be very helpful in narrowing down our investigation.
References
Learning Transport Agent Pipeline Tracing Hands-on (Part 1)
Enable Pipeline Tracing
Using Pipeline Tracing to Diagnose Transport Agent Problems
Telnet Port 25
The Exchange 2007 Content Filter Agent