There are many scenarios in Exchange 2007 Server which requires parsing, monitoring, and analyzing Message Tracking logs. For example, in transaction log file and / or Database growth scenarios, Server got hit with spam messages, Looping message scenario, Transport queue backup scenarios, and Server performance scenarios, and many other administrative, monitoring, and troubleshooting scenarios - it absolutely becomes necessary to review and analyze Message Tracking Logs. The amount of fields and tremendous amount of data present in message tracking logs, and the amount of extremely high messaging traffic that Exchange servers process these days ( i.e. the sheer size of message tracking log files ) makes it extremely difficult, if not impossible, to analyze these message tracking logs manually. The task is further complicated when you have to review message tracing logs from multiple servers, and especially on a pretty regular basis.
Process Tracking Log tool simplifies these tasks by automating the parsing and analysis of Message tracking logs, and then reporting it back by producing xls or txt output files with meaningful data, which is extremely useful in a lot of Administration, troubleshooting, and monitoring scenarios in Exchange 2007, as discussed above. Besides rich useful data regarding monitoring, administration, and troubleshooting, the tool also provides critical data on End-To-End Delivery Latency Distribution for all Messages Delivered, Server Latency Distribution for all Messages Processed and Server Latency Distribution for all Individual Deliveries. The tool is developed by Todd Luttinen, Principal Program Manager at Microsoft, and is released with this blog post.
Please note: the attached script is not officially supported by Microsoft. Please see the script for more details!
USAGE:
cscript ProcessTrackingLog.vbs <LogFilePath> <NumFiles> <hub|edge|all> [ <mm/dd/yyyy> | today | yesterday ]
EXAMPLES:
1) To parse one file:
cscript ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking\MSGTRK20070804-1.LOG" 1 all
2) To parse one file in a single directory:
cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 1 all
3) To parse all files in a single directory:
cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 0 all
4) To parse all files in all subdirectories in a single directory:
cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 0 all
5) To parse 3 files in each subdirectory:
cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 3 all
6) To parse all files in each subdirectory that were logged yesterday:
cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 0 all yesterday
7) To parse all files in each subdirectory that were logged on 10/29/2007:
cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 0 all 10/29/2007
NOTE: use of hub and edge assume "HUB" or "GWY" in directory path, otherwise specify all.
All results are stored in c:\temp\msgtrack\output directory. Please note, if you install Winzip command line tools into default path on C: drive, it will archive results.
Below are descriptions of each output file which this tool produces, along with sample data excerpts from these output files:
MTDsnFailureResults.csv includes details of all Failure reasons (although it is important to understand not all failures result in NDR). This file includes details like Timestamp, ServerName, Reason for failure, ReturnPath, and Recipients. MTDsnFailureResults.csv shows the NDR reason codes and Recipients (besides other information). If Admin is concerned about particular NDR codes or particular recipients, they can use the Filtering features of Excel (Data menu, Filter command) to quickly get statistical facts o their server or org to find out relevant inof. For example, an Admin may be interested in "550 5.2.2 STOREDRV.Deliver: mailbox full" NDR reason code and wanted to see how many users on a server actually have their mailboxes full, or during troubleshooting an issue they may be after "550 5.2.3 RESOLVER.RST.RecipSizeLimit: message too large for this recipient" or "550 5.2.3 RESOLVER.RST.SendSizeLimit: message too large for this sender" NDR reason codes. I also wanted to point out that there is a section in MTSummaryResults.txt that summarizes the NDR codes with counts by "Unique FAIL Recipient Status codes" and "FAIL Event Sources".
MTDuplicateDeliveryResults.csv output file can become very useful in troubleshooting duplicate mail delivery occurring on a particular server or across your org.
MTNextHopResults.csv includes count of messages and average message size for each next hop server via SMTP and StoreDriver. It includes stats such as, ClientName,Source, Server, MsgCount,AvgMsgBytes,MsgCountServerSLAMet, PercentServerSLAMet, and MsgCountDeliverSLAMet,PercentDeliverSLAMet. This is probably one of the 3 most important files, as pivots on this data allow for analysis of where traffic from a server is destined (if processing log files from multiple servers, can group in pivot). It should show StoreDriver, IntraOrg SMTP, and external SMTP delivery.
MTExpandResults.csv includes Distribution Group SMTP address, number of recipients per expansion and number of expansions performed. In the example below, MTExpandResults.csv output file shows that DL100@Contoso.com with ReciptCount of 49,426 was expanded 21 times with an AvgExpansionLatency of 3,045 sec (or 50.75 minutes). This caused Server performance issues. This output file can be very helpful in detecting these kinds of issues. AvgExpansionLatency is computed in seconds.
| Number | SMTP | Recip Count | Expand Count | AvgExpansion Latency |
| 95 | DL1@Contoso.com | 116 | 1 | 14 |
| 96 | DL1199@Contoso.com | 228 | 2 | 24 |
| 97 | DLTest@Contoso.com | 3341 | 1 | 190 |
| 90 | DL100@Contoso.com | 49,426 | 21 | 3,045 |
| 91 | DL9999@Contoso.com | 374 | 1 | 59 |
| 92 | DL1010@Contoso.com | 458 | 1 | 65 |
| 146 | DL99110@Contoso.com | 3346 | 1 | 179 |
A plot of above data provides us with following graphical views:
MTLogStatistics.csv includes many statistics for each log file processed. It outputs the following data:
LogFilePath, ServerName, iLogFileEventCount, Events/MsgId, LogDateTimeStart, LogDateTimeEnd, LogDuration(Min), iAvgStoreDriverReceiveRatePerMin, iAvgSmtpReceiveRatePerMin, iAvgStoreDriverDeliverRatePerMin, iAvgSmtpSendRatePerMin, iAvgDsnFailRatePerMin, iAvgFailRatePerMin, iServerLatencyTotalCount, iPercentServerLatencySLAMet, iPercentServerLatencyRecipientsCounted, iDeliveryLatencyTotalCount, iPercentDeliveryLatencySLAMet.
These values are used to validate that the percentage of messages counted in latency SLA measurements (since we know that tracking does not have events indicating final disposition of every message handled, but most are related to our suppression of DSN's when sending to DG's that DSN suppression enabled). The Percent SLA met numbers are the most important; they show the percentile of messages that are below the server (30 sec default) and delivery (90 sec default). This is just as an example and you can modify the goal as appropriate to get percentiles they want. The server latency and delivery latency SLA goals are defined as variables in the script (defaults are 30 and 90 sec respectively). Server latency is the delay from Submission to transport until delivery/relay completed (each set of recipient deliveries counted separately). Delivery latency is the end-to-end based on difference between org submission time and final delivery event timestamp.
Note 1: Final disposition could be transfer all recipients to a bifurcated copy of the message, so it doesn't always result in delivery/relay.
Note 2: The "org submission time" is defined as the entry into transport at the header firewall (first transport server in forest). This is carried cross-forest if cross forest connectors are used between the orgs.
For example, in this output file, combination of iAvgStoreDriverReceiveRatePerMin and iAvgSmtpReceiveRatePerMin tells us the average rate that Transport is receiving messages (assuming there are no submission via Pickup and Replay directories). The combination of iAvgStoreDriverDeliverRatePerMin and iAvgSmtpSendRatePerMin gives us the average delivery rate for Transport (assuming there are no deliveries to Drop directory). The comparison of two can tell us if Transport is effectively processing messages or if Transport or one of its dependant components is a performance bottleneck. Please note, that there may be other factors which we may have to take into consideration, for example, we may have to adjust for iAvgDsnFailRatePerMin.
MTDeliveryLatencyExceptions.csv, MinDeliveryLatency and MaxDeliveryLatency are for deliveries that have occurred for the specific message (will be equal if only one delivery made). This is useful in determining when a single next hop was the cause of latency for a subset of recipients. Both measurements are in sec.
MTMbxFullRecipResults.csv includes SMTP address and count of NDR's caused due to mailbox full. For example, one of the excerpts of this output file shows the following output shown below. Here User2's "full mailbox" has resulted in 4283 NDRs. This can serve administrative and monitoring purpose to notify users (e.g. via phone message) to clean up their mailboxes, as it's resulting in unnecessary and additional overhead on Server resources.
| Mailbox | DsnFailureCount |
| User1@ Contoso.com | 278 |
| User2@ Contoso.com | 4283 |
| User3@ Contoso.com | 58 |
| User4@ Contoso.com | 19 |
| User5@ Contoso.com | 24 |
| User6@ Contoso.com | 19 |
MTReceiveResults.csv includes count of messages and average message size for each host submitting via SMTP and StoreDriver. This output files produces following info: ServerName, Client IP, and MsgCount. This file is useful to show StoreDriver receive results on hub role. Below is an excerpt from this file. This clearly shows that IP address 192.168.0.190 has submitted an enormously high number of messages (349230) to the server GCS1E2K7. This definitely needed investigation, and it turned out to be a spam situation due to incorrectly configured receive connector.
| ServerName | Source | Client | MsgCount | AvgBytes |
| GCS1E2K7 | SMTP(GCS1E2K7\ Default Receive) | 192.168.0.190 | 349230 | 294987 |
| GCS1E2K7 | SMTP(GCS1E2K7\ Default Receive) | 10.10.0.110 | 1429 | 82019 |
| GCS1E2K7 | SMTP(GCS1E2K7\ Default Receive) | 10.10.0.120 | 389 | 69041 |
| GCS1E2K7 | STOREDRIVER | GCS4E2K7.contoso.com | 209 | 926738 |
| GCS1E2K7 | STOREDRIVER | GCS3E2K7.contoso.com | 147 | 5737 |
| GCS1E2K7 | STOREDRIVER | GCS2E2K7.contoso.com | 408 | 17774 |
| GCS1E2K7 | PICKUP | | 1 | 774 |
A plot between Client IP and Message Count shows the following:
MTTopRecipientResults.csv includes SMTP address, mailbox server name and messages received for top recipients (receiving more messages than average). MTTopRecipientResults.csv shows the top recipients on the server. It provides the actual SMTP addresses of top recipients. Below is an excerpt out of this output file. In the data below User1245@ Contoso.com stands out.
| GCS1E2K7 | User1099@ Contoso.com | 1950 |
| GCS1E2K7 | User1245@ Contoso.com | 211738 |
| GCS1E2K7 | User2398@ Contoso.com | 2124 |
| GCS1E2K7 | User3267@ Contoso.com | 4784 |
| GCS1E2K7 | User7612@ Contoso.com | 1861 |
| GCS1E2K7 | User2367@ Contoso.com | 9898 |
Graphical representation of above data is as follows:
MTTopSendersbyDeliverResults.csv includes SMTP address and messages sent for top senders (sending more messages than average, includes all senders). MTTopSendersbyDeliverResults.csv provides the top senders e-mail addresses and the message count. This includes messages from senders outside the organization. In data below, User1176@ Contoso.com clearly stands out.
| Sender | MessageCount |
| User1099@ Contoso.com | 6074 |
| User1176@ Contoso.com | 112240 |
| User3245@ Contoso.com | 6571 |
| User2367@ Contoso.com | 3245 |
| User2003@ Contoso.com | 5732 |
| User6743@ Contoso.com | 1749 |
A pie chart of Top Senders data looks like this:
MTTopSendersbySubmitResults.csv includes SMTP address, mailbox server name and messages sent for top senders (sending more messages than average). MTTopSendersbySubmitResults.csv shows the top senders on the server. It provides the actual SMTP addresses of top senders. This only includes messages submitted from mailboxes via StoreDriver (not SMTP). Below is an excerpt out of this output file. In the data below User2389@ Contoso.com stands out.