A look at MOSS 2007 Performance Part II – IIS Log Analysis
Introduction
In part one of this performance series we focused on performance counters and thresholds around those counters in an effort to monitor the performance of your MOSS platform. In this section, I plan to walk through some helpful items in analyzing your IIS Logs.
This is by no means an exhaustive review of parsing the logs; however, I do want to go through some review on IIS log parsing as well as some samples. For an in depth review, please see the references section of this article.
The first thing that any good software company will do when a diagnostic ticket comes in is ask for the company's ULS and IIS logs. What do they do with those logs behind the proverbial curtain? The first thing that will need to happen, is to parse through the logs to seek the answers that you want.
What are we looking for? How do we do this parsing?
Log Parser
Log Parser 2.2 is a free download from https://www.microsoft.com/downloads/details.aspx?FamilyID=890cd06b-abf8-4c25-91b2-f8d975cf8c07&displaylang=en and is a command-line SQL-like tool that can be used to parse pretty much any file. It is very powerful and in my humble opinion, is extremely underutilized.
The data that you can extract is truly amazing and only your imagination will limit you here.
The Log Parser syntax is very similar to Transact SQL syntax. To call the query, you will add the following switches:
-i |
This is the input file type which can have values to read Event Logs, Performance Counters, IIS Logs and much more. The format for IIS Logs is "IISW3C" |
-o |
This is the output file type than can have values like NAT (Native or in console) and Chart which has quite a few more switches |
-rtp |
This switch will outline how many records will be output. For all, you simply will use a value of -1 |
These are just some of the switches you can include and for a complete reference, please read the log parser book referenced in the reference section.
In your FROM clause, you can separate multiple sources so if you have multiple folders where IIS logs are stored you can easily do this with little effort.
Examples
Hourly Request Count
Say we want to get a baseline of requests broken down by hour to IIS, we can run a query similar to:
logparser -i:IISW3C -o:NAT -rtp:-1 "SELECT QUANTIZE(TO_TIMESTAMP(date, time), 3600) AS Date_Hour, COUNT(*) INTO RequestsPerHourReport.txt FROM C:\IIS\W3SVC49737048\*.* WHERE (EXTRACT_EXTENSION(TO_LOWERCASE(cs-uri-stem)) IN ('aspx'; 'html'; 'asp')) GROUP BY Date_Hour" |
Note: Updated 11/3/09, per Mike Wise, we should modify this script to strip out 401 http responses to eliminate the anonymous requests in NTLM.
This shows some of the things that you can do with the language. You can change this up by converting this to a chart like:
logparser -i:IISW3C -o:chart -chartTitle:"HTTP Requests Per Hour" -view -chartType:ColumnStacked3d "SELECT QUANTIZE(TO_TIMESTAMP(date, time), 3600) AS Hour, COUNT(*) INTO RequestsPerHourReport.gif FROM C:\IIS\W3SVC49737048\*.* WHERE (EXTRACT_EXTENSION(TO_LOWERCASE(cs-uri-stem)) IN ('aspx'; 'html'; 'asp')) GROUP BY Hour" |
If you are not following section one of this series, you can get somewhat of a request per second (RPS) count dividing the values by 3600 again.
Status Code Breakdown
To breakdown a count and then do analysis on status codes for IIS you can run a query similar to the following:
logparser.exe -i:IISW3C -o:NAT -rtp:-1 "SELECT STRCAT(STRCAT(TO_STRING(sc-status),'.'),TO_STRING(sc-substatus)), COUNT(*) AS StatusCount INTO StatusCodeRatio.txt FROM C:\IIS\W3SVC49737048\*.* GROUP BY STRCAT(STRCAT(TO_STRING(sc-status),'.'),TO_STRING(sc-substatus))" |
Bandwidth Analysis
There are many times that you may want to measure bandwidth on your IIS servers for load purposes. You can do this by running a query like:
logparser -i:IISW3C -o:NAT -rtp:-1 "SELECT QUANTIZE(TO_TIMESTAMP(date, time), 3600) AS Hour, DIV(Sum(cs-bytes),1024) AS Incoming(K), DIV(Sum(sc-bytes),1024) AS Outgoing(K) INTO HourlyBandwidthReport.txt FROM C:\IIS\W3SVC49737048_0918_0919\*.* GROUP BY Hour" |
The possibilities continue on, but these are some of the more common that I personally use in initial diagnostics.
Extendibility
We can take the "SELECT" query out and create a "*.sql" file and call it that way. An example would be to create a file called "c:\myTest.sql" that contains the following text:
SELECT * FROM %source% |
We then can call myTest.sql like:
Logparser.exe file:myTest.sql?source="c:\locationofIISLogs\*.* –i:IISW3C –o:NAT –rtp:-1 > outputFile.txt |
As you can see, with the addition of parameterization and files, now we can extend this out much further.
References
Burnett, M., & Giuseppini, G. (2005). Microsoft Log Parser Toolkit. Syngress.