Scott Oseychik

Microsoft | Embedded Escalation Engineer | Exchange People Groups Team

“Rough and Tough” guide to identifying patterns in Transaction Logs

“Rough and Tough” guide to identifying patterns in Transaction Logs

Rate This
  • Comments 38

Often times, either due to a misconfiguration/bug/solar eclipse or otherwise, customers call into Microsoft Product Support Services complaining that their Exchange server is churning out transaction logfiles at an alarming rate.  For every instance of this symptom, there are at least a dozen reasons why this is happening.  Regardless, there's never been a good way to parse the transaction logs and extract any useful patterns.  In lieu of rolling up my sleeves and actually writing code to accomplish such a task, I've slapped together a bunch of utilities that will do the job.  Ugly?  Sure.  Useful?  You bet.  Having used it against many customer issues, I can attest that this actually works, and works quite well.

 

1.    Download the "Unix for Win32" utilities from http://downloads.sourceforge.net/unxutils/UnxUtils.zip?modtime=1172730504&big_mirror=0

2.    Extract all files from the UnxUtils\usr\local\wbin subsirectory to C:\UNIX

3.    Download strings.exe from http://live.sysinternals.com/strings.exe, and place strings.exe into C:\UNIX

4.    Make a C:\TMP directory (Unix tools need a Win32 equivalent of /tmp)

5.    Make a directory for all your transaction log files (i.e. D:\customers\test), and place all the logs in this dir

6.    From a cmd prompt, navigate to your C:\UNIX dir

7.    Run the following command:

 

strings -q -n 16 D:\customers\test\*.log | cut -f3 -d: | sort | uniq -c | sort | tee c:\log-output.wri

 

 

What this is doing:

 

·         Identifies all strings in the logs greater than 16 chars

·         Removes the D:\customers\test\E00xxxx.log: from the output

·         Sorts the output

·         Finds all duplicate records, and retains a count

·         Sorts the final output (ending with the largest # of occurrences)

·         Writes all the output to c:\log-output.wri (use WordPad / write.exe to open; notepad.exe mangles the output)

 

 

If you're running this on Windows 7 or above, you'll have to modify the output directory as follows (as it won't let you write directly to the root of the C: drive) ...

 

strings -q -n 16 D:\customers\test\*.log | cut -f3 -d: | sort | uniq -c | sort | tee c:\users\yourname\log-output.wri

 

 

The output will be sorted from the least number of repeating occurences to greatest, so crack open that log-output.wri file, scroll to the bottom, and commence spelunking!

Comments
  • Well, not bad, but unfortunately it gave me this result after running through around 20 logfiles:

        <.. cut ..>

        10 <p class=MsoNormal><span style='font-size

        11 font-family

        14 <p class=MsoNormal><o

        14 <p class=MsoNormal><span style='color

       192 E

    (These logs were generated by E2K7)

    E? Is this longer than 16 characters?

  • - Given that E12 transaction logs are only 1MB now, you'll improve your odds of success by sampling more logs.

    - Try swapping the 16 with 8, and see if that yields better/more results.

    thanks,

    -scott

  • This is a great string parser routine and I've used for other things. Thanks so much Scott. I know many of my peers refer to it as well, great impact.

    As I use this as needed, I copy all of the unix exe's into the main unix folder. Once done this puppy runs quite well.

    Thanks again Scott!

    -T

  • What should I be looking for?  I'm trying to find out why we are having an excessive spike in log creation lately.  Here's the last bunch of lines from the results:

       318 00) Eastern Time (US & Canada)

       319 quoted-printable

       327 08

       328 12

       334 7bit

       347 55

       353 46

       354 Mon, 15 Sep 2008 10

       358 10pt; COLOR

       361 15 Sep 2008 15

       361 0in;

       362 15

       397 12.75pt'>

       404 Monday, September 15, 2008 10

       407 text/plain;

       416 (S

       426 from TC3705.domain.com ([172.22.227.140]) by TC3647.domain.com with Microsoft SMTPSVC(6.0.3790.1830);

       436 schemas-microsoft-com

       446 schemas

       462 3px;;text-align

       513 Mon, 15 Sep 2008 11

       542 10pt; FONT-FAMILY

       563 54

       586 MAILTO

       650 application/ms-tnef;

       685 binary

       813 #d4d0c8; BACKGROUND-COLOR

       815 Produced By Microsoft Exchange V6.5

       845 10.0pt;font-family

       916 urn

      1133

      1168 1.0

      1253 p></o

      1637 content-classes

      1677 #d4d0c8; BORDER-TOP

    619297

  • Can you re-run the same command, only this time instead of looking for strings 16 chars (or greater), let's go with 8.  The command line will look like this:

    strings -q -n 8 D:\customers\test\*.log | cut -f3 -d: | sort | uniq -c | sort | tee c:\log-output.wri

  • Does it work on Exchange 2007?

  • Hi Gsalgun,

    Yes, this technique will work on Exchange 2007.

    Kind Regards,

    Scott

  • I get 'cut' is not recognized as an internal or external command, operable program or batch file.  What am I doing wrong?

  • It's not in your path.  Place cut.exe in your path, and you should be good to go ...

    Scott

  • Hi Scott,

    Thanks for the guide.  I've got an Exchange 2003 environment where "Junk E-mail Rule" is the highest repeating occurence.  Any ideas why this would be?

    Thanks

    Steve

  • Hi Steve,

    In conjuction with analyzing the transaction logs, you can also use Exmon to [hopefully] pinpoint a specific user who may be thrashing the server; perhaps their Junk E-mail Rule is corrupted:

    http://msexchangeteam.com/archive/2005/04/06/403409.aspx

    http://www.msexchange.org/tutorials/Microsoft-Exchange-Server-User-Monitor.html

    Thanks,

    Scott

  • Hey Scott,

    Many thanks for this.Worked well at the first shot!!!

    Silju

  • Glad to hear it helped out, Silju!

    Regards,

    Scott Oseychik

  •   1028 Microsoft Exchange Server

      1033 text-decoration

      1066 color

      1090 style=3D'font-size

      1146 Content-Type

      1239 10.0pt;font-family

      1319 IPM.Schedule.Meeting.Resp.Pos

      1365 Received

      1470 <b><span style='font-weight

      1485 IPM.Schedule.Meeting.Request

      2212 Updated

      2330 style='font-size

      2927 font-family

      2959 [1/21/2010 16

      4346 IPM.Note.StorageQuotaWarning

      4363 EDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWNEDWN

      4434 jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1jRA1

      4484 NY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0QNY0Q

      6495 ////////////////////////////////////////////////////////////////////////////

      8294 AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA

    This is what I'm seeing after analyzing 200MB of log files...any thoughts?

  • Based on the data, it seems someone is initiating a mail loop (or is merely blasting the same content repeatedly) ... note the WNED (I'm guessing it's short for PWNED).

    My recommendation: use ExMon to identify the users with the highest amount of activity, then disable their mailboxes one-by-one until the transaction log growth stops.

    http://www.microsoft.com/downloads/details.aspx?FamilyId=9A49C22E-E0C7-4B7C-ACEF-729D48AF7BC9&displaylang=en

Page 1 of 3 (38 items) 123
Leave a Comment
  • Please add 3 and 6 and type the answer here:
  • Post