Making sense of Exchange Logs using ExLogAnalyzer
Published Jan 20 2010 05:21 PM 42.6K Views

Early 2008 we have posted a blog entry with a VB script that generates some pre-canned reports that are based on message tracking logs. The script has proven to be useful in understanding Microsoft's Exchange work load and guide some design decision for Exchange 2010. This script was developed by Todd Luttinen, Principal Program Manager at Microsoft.

During the development of Exchange 2010, we needed to extended our log analysis beyond just message tracking and to answer a variety of questions that assist with design decisions. This exposed a bottle neck with having a single script that has all the parsing and analyzers bundled together.

This resulted in the creation of ExLogAnalyzer by Victor Boctor, Principal Architect at Microsoft. ExLogAnalyzer was developed in C# with the following goals:

  • Separation of syntax and semantics.
  • Multi-Server support (process log files that span multiple servers). Log events across servers are processed in chronological order.
  • Multi-Log Type support (process / cross reference logs of different log types to produce a single report). Log events across log types are processed in chronological order.
  • Provide an extensibility model to support rapid development and distribution of extensions (to support new log types) and analyzers (to encapsulate reporting logic).
  • Ability for the community to develop their own analyzers or even extensions.
  • Support for Exchange 2007 / 2010 log types.

The main shift in this model, compared to the previous script, is that ExLogAnalyzer is built as a framework that can be used to analyze Exchange as well as possibly any other log format. New log types are supported via plugins called "extensions". Extensions are responsible for doing all the parsing and converting of log lines into events, where each event triggers a method and passes all the pre-parsed information as the event arguments. The specific reports are also implemented as plugins known as "analyzers", where each analyzer handles the events it is interested in and does the appropriate accounting and report generation (typically in CSV format). Implementing each analyzer in isolation (rather than one script that answers multiple questions) makes it much simpler to develop, understand and distribute such analyzers. Such extensions and analyzers can also be easily shared given the plugin model. The following simple diagram summarizes the architecture of this tool:

The ExLogAnalyzer is now released to the community with the following extensions / analyzers available out of the box:

  • Message Tracking Log
    • MsgTrkTopSendersByDeliverLogAnalyzer - Generates the top 1000 senders based on mailbox deliveries. Messages to the internet are not counted.
    • MsgTrkTopSendersBySubmitLogAnalyzer - Provides an analysis of the sender load distribution based on number of messages sent from their mailboxes.
    • MsgTrkTopRecipientLogAnalyzer - Generates the top 1000 recipients based on mailbox deliveries. Messages to the internet are not counted.
    • MsgTrkMessageSizeDistributionLogAnalyzer - Provides an understanding of the message size distribution.
    • MsgTrkRecipientNotFoundLogAnalyzer - Discover and summarize recipients for which "Recipient Not Found" error was generated.
    • MsgTrkMailflowVisualizerLogAnalyzer - Generates a directed graph showing the server being analyzed and all the inbound / outbound mail flow paths.
    • MsgTrkComponentLatencyPercentileLogAnalyzer (E14) - Analyzes the latencies of the different components and determines the latencies experienced by the specified percentiles of messages.
    • MsgTrkDuplicateDeliveryLogAnalyzer - Analyzes the sources for duplicate deliveries to Store. Note that end users don't see such duplicates.
    • MsgTrkEventFrequencyLogAnalyzer - Provides an understanding of the distribution of the event + source combinations.
    • MsgTrkEventTimeDistributionLogAnalyzer - Provides an understanding of the event distribution over time with a per hour resolution.
    • MsgTrkExpandLogAnalyzer - Analyzes the distribution list expansion load on the system.
    • MsgTrkReceiveLogAnalyzer - Analyzes the distribution of the sources for the messages received by a server or a set of servers.
  • Smtp Receive Log
    • SmtpReceiveWorkLoadLogAnalyzer - Analyzes the SMTP receive work load over time while tracking tarpitting, client time outs, etc.
    • SmtpReceiveDelayedAckLogAnalyzer (E14) - Analysis of delayed ack performance over time. This report provides an overview of the redundancy that is achieved for legacy systems via delayed ack.
    • SmtpReceiveFormatterLogAnalyzer - Re-writes the logs with each session in a separate file, it also reformats the log so that the common session information is included in the header, hence, making the session details more readable.
    • SmtpReceiveSeparatorLogAnalyzer - Re-writes the logs with each session in a separate file while maintaining the exact log format.
    • SmtpReceiveSessionIndexLogAnalyzer - Provides a summary of all sessions processed within the provided logs.
  • Connectivity Log
    • ConnectivityWorkLoadLogAnalyzer - An analyzer that samples the connections over time. This analyzer generates a CSV file per source (e.g. SMTP or MAPI).
    • ConnectivityStatsLogAnalyzer - An analyzer that provides the frequency of sessions, failed and DNS failures per source + destination combination.
    • ConnectivityFormatterLogAnalyzer - Re-writes the sessions as a file per session, moved all the common session information to the header to make the sessions more readable.

Sample Reports

Following are some samples to provide a feel of the outputs of some of these analyzers.

Mail Flow Visualizer (demonstrated possible visualization using directed graphs):

Message Size Distribution:

SmtpReceiveFormatterLog (log re-writing for splitting sessions and making them more readable):

# Session Id: 08CBDCECE3DDF231
# Start Time (local): 2009-07-28T11:07:46.922
# End Time (local): 2009-07-28T11:07:46.953
# Start Time (UTC): 2009-07-28T18:07:46.922Z
# End Time (UTC): 2009-07-28T18:07:46.953Z
# Disconnect Type: Local
# Connector Id: MyServer\MyServer_CrossForest
# Local End Point: 157.54.7.153:25
# Remote End Point: 157.54.71.39:4183

0000000,+,,
0000000,*,None,Set Session Permissions
0000000,*,SMTPSubmit SMTPAcceptAnyRecipient SMTPAcceptAuthenticationFlag SMTPAcceptAnySender SMTPAcceptAuthoritativeDomainSender BypassAntiSpam Byp assMessageSizeLimit SMTPAcceptEXCH50 AcceptRoutingHeaders AcceptForestHeaders AcceptOrganizationHeaders SMTPAcceptXShadow,Set Session Permissions
0000000,>,220 MyServer E14 Cross Forest,
0000000,<,EHLO otherhost.otherforest.microsoft.com,
0000000,>,250-MyServer.redmond.corp.contoso.com Hello [157.54.71.39],
0000000,>,250-SIZE 10485760,
0000000,>,250-PIPELINING,
0000000,>,250-DSN,
0000000,>,250-ENHANCEDSTATUSCODES,
0000000,>,250-AUTH,
0000000,>,250-8BITMIME,
0000000,>,250-BINARYMIME,
0000000,>,250-CHUNKING,
0000000,>,250-XEXCH50,
0000000,>,250 XSHADOW,
0000000,<,XSHADOW 3333YTkxYjEtYzE1OC00NDcxLWI4OTktMDA2NDI5YmVmZWRlQFRLNUVYMTRNTFRXNjUxLndpbmdyb3VwLndpbmRlcGxveS5udGRldi5taWNyb3NvZnQuY39t,
0000000,>,250 q7rdaFIdKk3NNRTbjRsjrQ==,
0000000,<,MAIL FROM:<sender@contoso.com> SIZE=25477 XSHADOW=70136df4-c89b-4700-9654-b642c4eb78bb,
0000000,*,08CBDCECE3DDF231;2009-07-28T18:07:46.922Z;1,receiving message
0000000,<,RCPT TO:<receiver@contoso.com> ORCPT=rfc822;receiver2@contoso.com,
0000000,>,250 2.1.0 Sender OK,
0000000,>,250 2.1.5 Recipient OK,
0000000,<,XEXCH50 1136 2,
0000000,>,354 Send binary data,
0000015,>,250 2.0.0 XEXCH50 OK,
0000015,<,BDAT 25477 LAST,
0000031,>,250 2.6.0 <DB82FD8C490D4F43ACE766C04B23A7050F0F12@someserver.otherforest.contoso.com> [InternalId=16796908] Queued mail for delivery,
0000031,<,XQDISCARD 50,
0000031,>,251 OK, no discard events,
0000031,<,QUIT,
0000031,>,221 2.0.0 Service closing transmission channel,
0000031,-,,Local

Top Senders by Submit (analysis yielding CSV - full report has top 1000):

MailboxServer

Sender

Count

mbx01.contoso.com

support_person@contoso.com

162

mbx01.contoso.com

sales_person@contoso.com

124

mbx02.contoso.com

ceo@contoso.com

61

Sender Distribution by Submit (analysis yielding CSV):

SentMsgRange

Count

Percent

Percentile

1-5 msgs

23310

86.59%

86.59%

6-10 msgs

3078

11.43%

98.02%

11-20 msgs

497

1.85%

99.87%

21-30 msgs

28

0.10%

99.97%

31+ msgs

7

0.03%

100.00%

Distribution Group Expansion Analyzer (analysis yielding CSV):

Recipient

RecipCount

ExpandCount

info@contoso.com

1

2242

skiing@contoso.com

43

848

parents@contoso.com

223

203

all@contoso.com

2325

17

Getting started

  • Download ExLogAnalyzer from here.
  • Checkout the Power Point slide deck included in the download for more details about ExLogAnalyzer.
  • Use ExLogAnalyzer and its distributed sample analyzers to analyze your logs.
  • Develop your own analyzers. Visual Studio and Visual C# Express Edition are the recommended tools. However, you can use Notepad or your favorite editor, given that ExLogAnalyzer detects and compiles the analyzer CSharp files at runtime.
  • Provide us with feedback about ExLogAnalyzer, sample analyzers or the development process.
  • Share your analyzers or ideas for useful new analyzers with the Exchange community.

- Victor Boctor

12 Comments
Not applicable
Other than the pre-packaged queries and reports, how is this any better than LogParser? It's always been able to parse virtually any kind of log you throw at it.

Still, it is nice to have the pre-packaged queries; I'm not exactly an SQL guru.
Not applicable
Looks interesting! Will check this out.
Not applicable
Awesome - cannot wait to run this and get some more measurable usage numbers.
Not applicable
This has been a great (FREE) tool for measuring hub transport load and statistics. This tool easily identifies who is sending/receiving the most mail through your hub transport servers. Between two hub servers, I am processing over 7gb of message tracking logs and receive csv reports with 15 minutes. I can also create formatted smtp receive logs for every receive connector session.

Cool tool Victor!!
Not applicable
I have always been complaining for the lack of any reports in Exchange
It was hard to get data to make some graphs, show trends or find any anormal traffic

This seems to be the tool I have been waiting for so many years

Only did a few tests until now, but I was not able to get data from 2 differents MsgTracking Input Path in the same report despite you told that the tool has "Multi-Server support"

I used the MsgTrkInputPath key 2 times, but maybe this is not the good way to to that?
 <add key="MsgTrkInputPath" value="\myhub01d$Program FilesMicrosoftExchange ServerTransportRolesLogsMessageTracking"  />
 <add key="MsgTrkInputPath" value="\myhub02d$Program FilesMicrosoftExchange ServerTransportRolesLogsMessageTracking"  />





Not applicable
@Bastien Lamoureux - You should only have one entry for MsgTrkInputPath and use semi-colon (;) to separate the different paths.  For more details see slide 15 in the slide deck distributed with the ExLogAnalyzer (ExLogAnalyzer.ppt).

@aschnelk - I'm glad you like the functionality and performance of the tool.  Note that the performance is affected by the analyzers you run.  The ones that re-write all of the logs (e.g. smtp sessions one) will be the ones that will add the most time to your run.

@Trix - LogParser works well for certain kinds of queries against relatively well structured logs.  However, ExLogAnalyzer will provide you with more flexibility in processing behavior over time, supporting concepts like sessions, having state machines in your analyzers and analyzing logs like smtp receive, which would be much harder to analyze using LogParser.  I believe there are benefits to both tools.  Would like to hear your feedback once you try out the prepackaged analyzers.

@everyone, thanks for the feedback.  Please keep positing your opinions, ideas, usage experience and feature requests too.
Not applicable
I am noticing that the tool runs extremly slow compared the similar VBscript-based tool. By Slow, I mean that it takes a large amount of time to parse the tracking logs. Anyone else has noticed this?
Not applicable
@JohnB, what you are noticing is unusual, the only case that I can think of where this can happen, is if you have enabled the analyzers that re-write the logs (e.g. smtp session formatter, smtp session separator, etc).

What analyzers do you have enabled?
Not applicable
I ran the analyser on some servers and got a MsgTrkComponentLatencyPercentage report.

It shows a lot of components and their latency.
similar to:
ServerFqdn Component AvgLatency
HUBServer BATCH 1
HUBServer CAT 2
HUBServer CATRT
HUBServer CATRT-RMS Encryption Agent 10
HUBServer CATRT-Transport Rule Agent 4
HUBServer CATSM 8
HUBServer CATSM-RMS Decryption Agent 8
HUBServer CCC 1
HUBServer CRSL 3
HUBServer DFR 124
HUBServer QD 8
HUBServer QS 11
HUBServer RST 12
HUBServer SDD 1
HUBServer SDDCM 1
HUBServer SDDCM-Meeting Message Processing Agent 1
HUBServer SDDCM-Message Records Management Delivery Agent 1
HUBServer SDDDLV 1
HUBServer SDDDLV-Mailbox Rules Agent 1
HUBServer SDDPM 1
HUBServer SDDPM-Conversations Processing Agent 1
HUBServer SDDPM-Mailbox Rules Agent 1
HUBServer SDS 2
HUBServer SMR 2
HUBServer SMS 4
HUBServer SMSC 3
But can you explain where I can find more info about the different components which are shown?
For instance there is a latency of 124 on the DFR component.
But I have no idea what DFR means and if it the latency is too high.
Not applicable
rveltrop,
Please see below an updated sorted list of Latency Component short and long names . Someone is going to provide a more detailed spec about components soon. Regarding DFR, as you can see in the list below, it specifieds latency for Deferral. The data you obtained with the component latency report indicates that messages spent 124 sec in Deferral on average. Though the reason is unknown, the fact that messages spent most of the time in Deferral may point to a problem.

AGNT Agent
BATCH BatchPoint
CA Content Aggregation
CAMIC Content Aggregation MailItem Commit
CAT Categorizer
CATCM   Categorize rOn Categorized Message
CATRS Categorizer On Resolved Message
CATRT Categorize rOn Routed Message
CATSM Categorizer On Submitted Message
CBIF   Categorizer Bifurcation
CCC Categorizer Content Conversion
CFIN Categorizer Final
CRSL Categorizer Resolver
CRT Categorizer Routing
D Delivery
DAD Delivery Agent
DADM Delivery Agent On Deliver MailItem
DAOC Delivery Agen tOn Open Connection
DFR Deferral
DMP Dumpster
DSN Dsn Generator
ES External Servers
HB Heartbeat
MANY Too Many Components
MR Mailbox Rules
MSS Mail Submission Service
MSSFA Mail Submission Service Failed Attempt
MSSN Mail Submission Service Notify
MSSNRS Mail Submission Service NotifyRetrySchedule
MSSSRD Mail Submission Service ShadowResubmitDecision
MSST Mail Submission Service Throttling
NSGW Non Smtp Gateway
PCK Pickup
QD Delivery Queue
QP Poison Queue
QS Submission Queue
QSH Shadow Queue
QU Unreachable Queue
RMABL Rms Acquire B2B License
RMABR Rms Acquire B2BRac
RMAC Rms Acquire Clc
RMACM Rms Acquire Certification Mex Data
RMAL Rms Acquire License
RMAPL Rms Acquire Pre License
RMASLM Rms Acquire Server Licensing Mex Data
RMASR Rms Acquire Server Box Rac
RMAT Rms Acquire Templates
RMATI Rms Acquire Template Info
RMFSL Rms Find Service Location
RMRDT Rms Request Delegation Token
RPL Replay
RST Service Restart
SDD StoreDriver Delivery
SDDCM StoreDriver On Created Message
SDDDL StoreDriver On Delivered Message
SDDIM   StoreDriver On Initialized Message
SDDPM   StoreDriver On Promoted Message
SDS StoreDriver Submit
SDSDM StoreDriver On Demoted Message
SMR Smtp Receive
SMRDC Smtp Receiv eOn Data Command
SMRED Smtp Receive On EndOfData
SMREH   Smtp Receive On EndOfHeaders
SMRRC   Smtp Receive On RcptCommand
SMS Smtp Send
SMSC Smtp Send Connect
Not applicable
Hi Victor

Actually trying to generate some daily logs, I need to call ExLogAnalyzer from a planned task with arguments

If I enter parameters in config file "StartTimeLocal" and "EndTimeLocal", it does work

However, if I try to pass theses arguments when calling ExLogAnalyzer from command line, it does not seem to use arguments or tell me that string is not a valid DateTime

I tried with a variety of quotes, double quotes, single quotes


ExLogAnalyzer.exe -StartTimeLocal 2010-03-29 12:07:13Z -EndTimeLocal 2010-03-30 12:07:13Z
(does not work because of spaces)

ExLogAnalyzer.exe -StartTimeLocal "2010-03-29 12:07:13Z" -EndTimeLocal "2010-03-30 12:07:13Z"
(invalid datetime)

ExLogAnalyzer.exe -StartTimeLocal '2010-03-29 12:07:13Z' -EndTimeLocal '2010-03-30 12:07:13Z'
(invalid datetime)


Any idea for me?

Not applicable
By the way, for anyone who stumbles upon this page by searching for "delayed ack," you might want to search for "maxacknowledgementdelay" instead.  That can be a source of problems in Exchange 2010, which might show something like this in an SMTP log:

Tarpit for '0.00:00:33.119' due to 'DelayedAck',Expired;Timeout

(This has nothing to do with the TCP delayed ack.)
Version history
Last update:
‎Jan 20 2010 05:21 PM
Updated by: