Welcome to Exchange Team Blog Sign in | Join | Help

Syndication

This Blog

Making sense of Exchange Logs using ExLogAnalyzer

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 BypassMessageSizeLimit 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

Published Wednesday, January 20, 2010 2:21 PM by Exchange
Filed Under: , , , , ,

Comment Notification

If you would like to receive an email when updates are made to this post, please register here

Subscribe to this post's comments using RSS

Comments

 

Trix said:

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.
January 20, 2010 6:09 PM
 

Michael Dragone said:

Looks interesting! Will check this out.
January 20, 2010 6:11 PM
 

Chris Lehr said:

Awesome - cannot wait to run this and get some more measurable usage numbers.
January 22, 2010 7:04 PM
 

aschnelk said:

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!!
January 25, 2010 3:40 PM
 

Bastien Lamoureux said:

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="\\myhub01\d$\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking"  />
 <add key="MsgTrkInputPath" value="\\myhub02\d$\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\MessageTracking"  />





January 27, 2010 10:41 AM
 

Victor Boctor said:

@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.
January 27, 2010 12:04 PM
 

JohnB said:

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?
February 8, 2010 3:34 PM
 

Victor Boctor said:

@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?
February 23, 2010 1:34 AM
 

rveltrop said:

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.
March 4, 2010 10:30 AM

What do you think?

(required) 
(optional)
 
Enter the code you see below

(required) 

News


This blog and its contents are provided "AS IS" with no warranties, and they confer no rights. Use of any included script samples are subject to the terms specified in the Terms of Use.
New! Would you like to suggest a topic for the Exchange team to blog about? Send suggestions to us.

Exchange Server 2010 - Get the Release Candidate



Poll:

Other Exchange Blogs from MSFT