Export (0) Print
Expand All
Expand Minimize

Exchange Server 2007 Process Tracking Log Tool

 

Topic Last Modified: 2010-04-05

As a Microsoft Exchange Server 2007 administrator, you can experience situations that may require parsing, monitoring, and analyzing Message Tracking logs. These situations include the following scenarios:

  • Growth of a transaction log or of a database
  • A server experiencing many unsolicited commercial e-mail messages (also known as spam)
  • A looping message
  • Transport queue backup
  • Poor server performance

In such scenarios, you may have to review and analyze the Exchange Message Tracking logs. The following factors or combination of factors can make it difficult or impossible to analyze the message tracking logs manually:

  • Many fields
  • A large amount of data in message tracking logs
  • Large message tracking log files

Additionally, if you have to review message tracking log files from multiple servers, the task becomes even more complex.

Process Tracking Log tool simplifies reviewing message tracking logs by automating the parsing and analysis of Message tracking logs, and then generating an .xls or .txt output file for reporting. This tool provides useful data about monitoring, administration, and troubleshooting. This tool also provides important data about 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.

importantImportant:
The Process Tracking Log tool script was developed by Todd Luttinen, Principal Program Manager at Microsoft. However, this tool is not an official Microsoft tool. Therefore, we recommend that you review the script before you run this tool in a production environment.

To download the Process Tracking Log tool (Processtrackinglog.vbs), see the Exchange Server Team Blog article Processtrackinglog.vbs script

To run this tool, use the following script:

cscript ProcessTrackingLog.vbs <LogFilePath> <NumFiles> <hub|edge|all> [ <mm/dd/yyyy> | today | yesterday ]

noteNote:
This syntax assumes that the "HUB" or "GWY" exists in the directory path. If neither of these entries is displayed in the directory path, specify "all" in the command-line.

The following command-line examples provide usage scenarios for the Process Tracking Log tool.

cscript ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking\MSGTRK20070804-1.LOG" 1 all

cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 1 all

cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 0 all

cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 0 all

cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 3 all

cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 0 all yesterday

cscript \data\scripts\ProcessTrackingLog.vbs "D:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking" 0 all 10/29/2007

The results from the Process Tracking Log tool are stored in the c:\temp\msgtrack\output directory. If you install the Winzip command-line tools in the default path on drive C, the Process Tracking Log tool automatically archives the results in a compressed (.zip) file.

The following sections describe each output file that the Process Tracking Log tool generates, together with interpretations of example data.

The MTDsnFailureResults.csv file includes details of all failure reasons.

noteNote:
Not all delivery failures result in the generation of a non-delivery report.

The file includes fields such as Timestamp, ServerName, Reason for failure, ReturnPath, and Recipients. The MTDsnFailureResults.csv includes NDR reason codes and recipients together with other information. If you are troubleshooting a particular NDR code or specific recipient issues, you can use the filtering features in Microsoft Office Excel to obtain statistical data about a particular server or organization. To do this in Excel, click Filter on the Data menu. This data may give you information that is relevant to the delivery issue.

For example, you may be troubleshooting a "550 5.2.2 STOREDRV.Deliver: mailbox full" NDR reason code. During your investigation, you may want to know how many users on a server actually have their mailboxes full.

noteNote:
The MTSummaryResults.txt file includes a section that summarizes NDR reason codes by the "Unique FAIL Recipient Status codes" and "FAIL Event Sources" fields.

The MTDuplicateDeliveryResults.csv file is useful to help troubleshoot duplicate mail delivery issues that occur on a particular server or across an organization.

The MTNextHopResults.csv file includes a count of messages together with the average message size for each next hop server through SMTP and the StoreDriver component. The file includes statistics that are based on the following fields:

  • ClientName,Source
  • Server
  • MsgCount,AvgMsgBytes
  • MsgCountServerSLAMet
  • PercentServerSLAMet
  • MsgCountDeliverSLAMet
  • PercentDeliverSLAMet

This file is one of the three most important files for data analysis purposes. You can use pivot tables that are based on this file to analyze the destination of server traffic. Also, you can group multiple servers into a pivot table that is based on the MTNextHopResults.csv file to obtain an overall traffic analysis. It is best to analyze the data based on the following three fields:

  • StoreDriver
  • IntraOrg SMTP
  • External SMTP delivery

The MTExpandResults.csv file includes the distribution group SMTP address, the number of recipients per distribution group expansion operation, and the number of distribution group expansions performed.

In the example results that are displayed in the following table, the MTExpandResults.csv file shows that the DL100@contoso.com distribution group has a recipient count of 49,426. The distribution group was expanded 21 times, and has an average expansion latency of 3,045 seconds (50.75 minutes). This amount of latency could cause server performance issues. You can use this output file to help troubleshoot server performance issues that you may experience.

 

Number SMTP Recipient Count Expansion Count Avg Expansion Latency

95

DL1@contoso.com

116

1

14

96

DL1199@contoso.com

228

2

24

97

DLTest@contoso.com

3,341

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

3,346

1

179

noteNote:
Average expansion latency is calculated in seconds.

To obtain a graphical view of the data, use Microsoft Excel to plot this data in a chart.

The MTLogStatistics.csv file includes many statistics for each log file that is processed. The file contains the following fields:

  • LogFilePath
  • ServerName
  • iLogFileEventCount
  • Events/MsgId
  • LogDateTimeStart
  • LogDateTimeEnd
  • LogDuration(Min)
  • iAvgStoreDriverReceiveRatePerMin
  • iAvgSmtpReceiveRatePerMin
  • iAvgStoreDriverDeliverRatePerMin
  • iAvgSmtpSendRatePerMin
  • iAvgDsnFailRatePerMin
  • iAvgFailRatePerMin
  • iServerLatencyTotalCount
  • iPercentServerLatencySLAMet
  • iPercentServerLatencyRecipientsCounted
  • iDeliveryLatencyTotalCount
  • iPercentDeliveryLatencySLAMet

You can use these values to verify the percentage of messages that are counted in latency SLA measurements.

noteNote:
Message tracking does not include events that indicate the final disposition of every handled message. Instead, most message tracking events are related to delivery status notification suppression. This occurs when messages are sent to distribution groups that have DSN suppression enabled.

The "percent SLA met" numbers are the most significant because they indicate the percentage of messages that are below the server default of 30 seconds and the delivery default of 90 seconds. These values are default levels that you can modify to obtain the appropriate percentiles.

The server latency and delivery latency SLA goals are defined as variables in the script. The default values are 30 seconds and 90 seconds respectively. Server latency represents the delay from when the message is submitted to transport to when the message is delivered or relayed. For the server latency calculation, each set of recipient deliveries is counted separately. Delivery latency represents the end-to-end latency based on the difference between the organization's submission time and the final delivery event time stamp.

noteNote:
The final disposition of a message could be the transfer of a bifurcated copy of the message to recipients. Therefore, final disposition does not always represent a message delivery or message relay.
noteNote:
The "org submission time" is defined as the message entry time into the message transport at the header firewall (the first transport server in the forest).

For example, the combination of iAvgStoreDriverReceiveRatePerMin and iAvgSmtpReceiveRatePerMin in the MTLogStatistics.csv file indicates the average rate at which the transport component receives messages.

noteNote:
This calculation is valid only if there are no message submissions through the Pickup or Replay directories.

The combination of iAvgStoreDriverDeliverRatePerMin and iAvgSmtpSendRatePerMin specifies the average delivery rate for the transport component. This rate assumes that there are no deliveries to the Drop directory.

The comparison of these two combinations may give you an indication of whether the transport component is effectively processing messages or whether the transport or one of its dependent components is a performance bottleneck. To determine this status, you may have to examine other factors that can affect the results. For example, you may have to adjust the calculation to take the iAvgDsnFailRatePerMin value into consideration.

The MTDeliveryLatencyExceptions.csv file includes the MinDeliveryLatency and MaxDeliveryLatency fields. These fields contain latency measurements, in seconds. The fields are used to measure deliveries that have occurred for a particular message. These measurements are valid if only one message delivery is made. You can use this information to help determine whether a single next hop in the message delivery process was the cause of latency for a subset of recipients.

The MTMbxFullRecipResults.csv file contains the results of "mailbox full" events. This file includes the SMTP addresses and NDR counts for full mailboxes.

The following table shows some example output from this file. In this output, the full mailbox for User2 has caused 4,283 NDRs.

 

Mailbox DsnFailureCount

User1@contoso.com

278

User1@contoso.com

4283

User1@contoso.com

58

User1@contoso.com

19

User1@contoso.com

24

User1@contoso.com

19

You can use this information to notify users to delete messages from their mailboxes. This reduces server overhead.

The MTReceiveResults.csv file includes the number of messages together with the average message size for each host that submits messages by using SMTP or by using the StoreDriver component. The .csv file includes the following fields:

  • ServerName
  • Client IP
  • MsgCount

This file helps display the StoreDriver receive results for the Hub role. The following table contains example output from the MTReceiveResults.csv file. The output indicates that IP address 192.168.0.190 has submitted a very high number of messages (349,230) to the server that is named GCS1E2K7.

 

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

This kind of message count requires additional investigation. It could indicate a spam issue. For example, a server may have a receive connector that is configured incorrectly so that the volume of spam increases.

The MTTopRecipientResults.csv file includes the SMTP addresses, mailbox server name, and messages that are received for the top recipients. Top recipients are those who receive more than the average number of messages. The following table contains example output from the MTTopRecipientResults.csv file. In this output, User1245@contoso.com stands out.

 

Server name SMTP address Message count

GCS1E2K7

User1099@contoso.com

1950

GCS1E2K7

User1245@contoso.com

211738

GCS1E2K7

User2398@contoso.com

2124

GCS1E2K7

User3276@contoso.com

4784

GCS1E2K7

User7612@contoso.com

1861

You can use the charting feature in a spreadsheet program such as Excel to obtain a graphical view of the top message recipients.

The MTTopSendersbyDeliverResults.csv file includes the SMTP addresses together with the number of sent messages for the top message senders. Top senders are those who send more than the average number of messages. This includes messages from senders who are outside the organization. The following table contains example output from the MTTopSendersbyDeliverResults.csv file. In this output, User1176@contoso.com stands out.

 

Sender Message count

User1099@contoso.com

6074

User1176@contoso.com

112240

User3245@contoso.com

6571

User2367@contoso.com

3245

User2003@contoso.com

5732

The MTTopSendersbySubmitResults.csv file includes the SMTP addresses, mailbox server name, and messages that are sent for top senders. Top senders are users who send more messages than average. This file only includes messages that are submitted from mailboxes by using the StoreDriver (not SMTP). The following table contains example output from the MTTopSendersbySubmitResults.csv file. In this output, User2389@contoso.com stands out.

 

Mailbox server Sender Message count

GCS2E2K7

User1478@contoso.com

867

GCS2E2K7

User6512@contoso.com

654

GCS2E2K7

User3625@contoso.com

727

GCS2E2K7

User1367@contoso.com

3532

GCS2E2K7

User2389@contoso.com

9984

The MTEventTimeDistribution.csv file displays Event distributions based on an hourly count. This file helps provide a means to graph events over time. This may help determine which source is submitting messages, and the message destination. The following table contains example output from this file.

 

Server Event Source Month Day Hour Count

GCS1E2K7

RECEIVE

SMTP(SERVER01\Default SERVER01)

8

2

0

5198

GCS1E2K7

DELIVER

STOREDRIVER

8

2

0

3868

GCS1E2K7

RECEIVE

STOREDRIVER

8

2

0

341

GCS1E2K7

DSN

DSN(Delivery)

8

2

0

47

GCS1E2K7

SEND

SMTP(Intra-Organization SMTP Send Connector)

8

2

0

2169

GCS1E2K7

DSN

DSN(Failure)

8

2

0

93

GCS1E2K7

FAIL

STOREDRIVER

8

2

0

93

GCS1E2K7

BADMAIL

DSN

8

2

0

87

GCS1E2K7

FAIL

ROUTING

8

2

0

87

GCS1E2K7

TRANSFER

ROUTING(Resolver)

8

2

0

55

GCS1E2K7

TRANSFER

ROUTING(Content Conversion)

8

2

0

66

GCS1E2K7

REDIRECT

ROUTING

8

2

0

1

GCS1E2K7

EXPAND

ROUTING

8

2

0

6

GCS1E2K7

FAIL

AGENT(FSE Routing Agent)

8

2

0

2

 

RECEIVE

AGENT()

8

2

0

2

GCS1E2K7

DEFER

AGENT(Transport Rule Agent)

8

2

0

2

GCS1E2K7

DELIVER

STOREDRIVER

8

2

1

4748

GCS1E2K7

RECEIVE

SMTP(SERVER01\Default SERVER01)

8

2

1

6492

GCS1E2K7

RECEIVE

STOREDRIVER

8

2

1

389

GCS1E2K7

DSN

DSN(Delivery)

8

2

1

35

GCS1E2K7

SEND

SMTP(Intra-Organization SMTP Send Connector)

8

2

1

2809

GCS1E2K7

TRANSFER

ROUTING(Resolver)

8

2

1

152

GCS1E2K7

TRANSFER

ROUTING(Content Conversion)

8

2

1

65

The MTMessageSizeDistribution.csv file shows the distribution of messages based on message size. The distribution is broken down according to the number of messages, a percentage of the total messages, and the percentage of messages that are smaller than the current message size. This may help determine the spectrum of message size distribution in an organization. The following table contains example output from this file.

 

Size range Message count Percentage of total Percent under current size

0-1 KB

63

0.02%

0.02%

1-2 KB

11846

4.66%

4.68%

2-4 KB

45172

17.76%

22.44%

4-8 KB

47072

18.50%

40.94%

8-16 KB

39641

15.58%

56.53%

16-32 KB

28810

11.33%

67.85%

32-64 KB

20251

7.96%

75.81%

64-128 KB

20252

7.96%

83.77%

128-256 KB

13228

5.20%

88.97%

256-512 KB

9022

3.55%

92.52%

512-1024 KB

7460

2.93%

95.45%

1024-2048 KB

5243

2.06%

97.51%

2048-4096 KB

3925

1.54%

99.05%

4096-8192 KB

2399

0.94%

100%

8192-16384 KB

5

0%

100%

16384-32768 KB

0

0%

100%

32768-65536 KB

0

0%

100%

The MTRecipientNotFoundResults.csv file contains statistics about recipients who could not be located in the global address list (GAL) or Active Directory directory service. The following table contains example output from this file. In this output, the high count for User1001 may indicate that this user is no longer associated with the organization.

 

Recipient not found Count

User1001@contoso.com

2149

User2167@contoso.com

19

User3267@contoso.com

6

User1282@contoso.com

6

User1491@contoso.com

8

The MTDomainExpiredResults.csv contains entries that may be helpful to troubleshoot DSN failures. For example, these entries may help you troubleshoot if a DSN failure occurs because of a misspelling, or if a destination server is unavailable for more than two days (the default expiration time-out). The following table contains example output from this file.

 

Domain Recipient failures Message failures Original expiry Last expiry MTBF (hours)

Hotmail.com

6

6

1/9/2008 19:06

1/11/2008 20:20

8

contoso.com

7

7

1/9/2008 3:47

1/12/2008 8:13

11

fourthcoffee.com

4

4

1/9/2008 19:15

1/10/2008 15:51

5

msn.com

23

23

1/9/2008 20:40

1/11/2008 17:10

2

The MTMessageSizeExceptions.csv output file is generated only if there is a tracking log event for a message whose size exceeds the value for iMaxMessageSizeThresholdKB. The default threshold is 64MB. If there is no such tracking log event, the file is not generated.

The MTRunTimeLog.log file is the log file for the Process Tracking Log tool. This file contains the run-time log for the Processtrackinglog.vbs script.

The MTMailSubmissionDistribution.csv file contains the distribution of submissions by MessageClass and ClientType. This includes the ability to parse the SUBMIT event SourceContext field to determine the distribution of submissions by ClientType and by MessageClass. This file relies on the Mailbox role tracking logs.

You can use this file to help determine the distribution of client types when you analyze the Mailbox role tracking log.

The MTSummaryResults.txt file includes summary statistics for all the log files that are processed. This file contains many items. Some more significant items are as follows:

  • Total Events processed
  • Total Message Id's Processed
  • Total Messages received
  • Total Messages sent
  • Total Messages delivered
  • Total Messages delivered (duplicate)
  • Total Resolve
  • Total Transfer
  • Total Expand
  • Total Fail
  • Total Fail with NDR
  • Total Fail (valid Return Path)
  • Total Fail (Recipient)
  • Avg Fail Events/Min
  • Max Fail Events/Min
  • Max DSN(Fail) Events/Min
  • Total DSN Generated
  • Total DSN Badmail
  • Total DSN
  • Total DSN Delivered from CORP
  • Total Null Reverse Path Delivered
  • Total Null Reverse Path Delivered from Internal
  • Total Null Reverse Path Delivered from External
  • Total Defer
  • Total Poison
  • Total SMTP Receive
  • Total StoreDriver Receive
  • Total SMTP Send
  • Total StoreDriver Deliver
  • Total Expand
  • End-To-End Delivery Latency Distribution for all Messages Delivered
  • Server Latency Distribution for all Messages Processed
  • Server Latency Distribution for all Individual Deliveries
  • Unique Encapsulated Addresses
  • Unique DSN Source Context
  • Unique Defer Source Context
  • Unique StoreDriver Sender Domains
  • Transfer Source Context
  • FAIL Event Sources
  • Unique FAIL Recipient Status codes

The following example is an excerpt from an MTSummaryResults.txt file. This example illustrates some of the information that is collected.

 

Total Events processed: 671316 (Avg Events/Log: 26852.64)

Total Message Id's Processed: 291378 (Avg Events/MsgId: 2.30393509461936, Max: 3.03358797138353, Min: 1.41262468992453)

Total Messages received: 254389 (Avg Msg Size: 184 KB)

Total Messages sent: 95301

Total Messages delivered: 256995

Total Messages delivered (duplicate): 0 (0 recipients)

Total Resolve: 45

Total Transfer: 32610 (46.9% exceeded 30 sec before transfer, average 599 sec latency before transfer)

Total Expand: 5179

Total Fail: 10229 (0% *.contoso.com senders, 99.6% external senders)

Total Fail with NDR: 5759

Total Fail (valid Return Path): 5802 (0% *.contoso.com senders, 100% external senders)

Total Fail (Recipient): 11203

Avg Fail Events/Min: 7.1

Max Fail Events/Min: 280.3

Max DSN(Fail) Events/Min: 146.5

Total DSN Generated: 7240

Total DSN Badmail: 4352

Total DSN: 11592 (Percent DSN Badmail: 37.5%)

Total DSN Delivered from CORP: 0

Total DSN Delivered from CORP/EXCHANGE/NWTRADERS: 0

Total Null Reverse Path Delivered: 8604

Total Null Reverse Path Delivered from Internal: 3 (0%)

Total Null Reverse Path Delivered from External: 8601 (100%)

Total Defer: 42

Total Poison: 0

Total Split Errors: 22120

 
Was this page helpful?
(1500 characters remaining)
Thank you for your feedback

Community Additions

ADD
Show:
© 2014 Microsoft