Analyzing HTTP Traffic On Your IIS 7.0 Cluster

Article
11/29/2007

If you have ever run an enterprise web site you have probably received a panicked call from a customer or from your Tier 1 monitoring team that your site was responding slowly or throwing 500 errors and that you needed to resolve this issue ASAP. Maybe you are rolling out a new application or software across your site and want to perform side by side analysis of servers to ensure their health.

Over the past year we have rolled out multiple pre-release versions of Windows Server 2008 / IIS 7.0 onto the www.microsoft.com site. During this process we have had to monitor the overall health of the site. Which included being able to quickly identify content/application that were not behaving well on a server, cluster of servers or across the entire site. When running an enterprise of IIS servers it is invaluable to understand the traffic patterns of your site and to have the tools to help identify problem areas. There are many tools in the wild to monitor the health of your enterprise, but I will show you how to use Logparser to harvest your IIS logs and pinpoint a site problem. The goal of this blog is to help you identify issues or anomalous traffic patterns on your IIS web site.

For the purposes of this blog I will use an eight server cluster for our analysis. Sometimes tracking down issues on your site can be like trying to find a needle in a haystack. I like to start by looking at the overall health of the site or for the purposes of my examples, a cluster of servers. Next, I like to drill down into more detail on the server that looks unhealthy. In my examples I will drill down by URI and followed next by the associated window of time that the server/URI was unhealthy.

Here is where the fun begins! The first step is to perform a query by HTTP status codes for the cluster. Using Logparser I created a file called statuscodes_by_servers_in_cluster.sql and fed in the input IIS log files from all the IIS servers in the cluster which are called u_ex07111409.log. This result in an easy to read table showing you the summarized results by HTTP status code for each of the servers in your cluster.

Summarized HTTP status codes by server for a complete a complete cluster

logparser -rtp:-1 file:statuscodes_by_servers_in_cluster.sql?logfilename=u_ex07111409.log

sc-status Srv1 Srv2 Srv3 Srv4 Srv5 Srv6 Srv7 Srv8

--------- ------ ------ ------ ------ ------ ------ ------ ------

200 576313 585078 573956 574218 566388 599807 572982 589815

206 242 238 247 262 236 216 192 246

301 6148 6388 6378 6154 6140 6600 6293 6398

302 166817 168700 166471 165909 163386 172658 166764 170363

304 125493 126640 125908 126204 124139 130669 125855 129026

400 4 3 3 2 2 7 7 3

403 130 106 146 170 148 154 148 95

404 9023 9149 9835 8833 8811 9489 9250 9369

405 0 1 0 0 0 0 0 0

406 2 10 5 11 4 7 8 4

500 1361 342 363 337 332 323 340 351

501 18 22 21 25 31 27 34 30

I created the following Logparser file (statuscodes_by_servers_in_cluster.sql) to create the site by side server table of HTTP status code values.

statuscodes_by_servers_in_cluster.sql

SELECT

sc-status,

SUM(_Srv1) AS Srv1,

SUM(_Srv2) AS Srv2,

SUM(_Srv3) AS Srv3,

SUM(_Srv4) AS Srv4,

SUM(_Srv5) AS Srv5,

SUM(_Srv6) AS Srv6,

SUM(_Srv7) AS Srv7,

SUM(_Srv8) AS Srv8

USING

CASE s-computername WHEN 'ServerName1' THEN 1 ELSE 0 END AS _Srv1,

CASE s-computername WHEN 'ServerName2' THEN 1 ELSE 0 END AS _Srv2,

CASE s-computername WHEN 'ServerName3' THEN 1 ELSE 0 END AS _Srv3,

CASE s-computername WHEN 'ServerName4' THEN 1 ELSE 0 END AS _Srv4,

CASE s-computername WHEN 'ServerName5' THEN 1 ELSE 0 END AS _Srv5,

CASE s-computername WHEN 'ServerName6' THEN 1 ELSE 0 END AS _Srv6,

CASE s-computername WHEN 'ServerName7' THEN 1 ELSE 0 END AS _Srv7,

CASE s-computername WHEN 'ServerName8' THEN 1 ELSE 0 END AS _Srv8

FROM

\\ServerName1\logshare$\%logfilename%,

\\ServerName2\logshare$\%logfilename%,

\\ServerName3\logshare$\%logfilename%,

\\ServerName4\logshare$\%logfilename%,

\\ServerName5\logshare$\%logfilename%,

\\ServerName6\logshare$\%logfilename%,

\\ServerName7\logshare$\%logfilename%,

\\ServerName8\logshare$\%logfilename%

GROUP BY

sc-status

ORDER BY

sc-status

You will notice that the HTTP 500 status codes are rather high on one of our servers (SRV1). Now that we have identified which server looks unhealthy we can drill down and identify the problem application or URI which is causing the high level of 500’s server errors.

The next Logparser query I like to use is a spill by URI for the specific HTTP 500 status code on the cluster. Using Logparser I created a file called cs-uri-stem_by_servers_in_cluster.sql and fed in the same input IIS log files from all the IIS servers in the cluster called u_ex07111409.log.

URI spill for ‘500’ HTTP status code for a complete cluster:

logparser -rtp:-1 file:cs-uri-stem_by_servers_in_cluster.sql?logfilename=u_ex07111409.log

sc-status Srv1 Srv2 Srv3 Srv4 Srv5 Srv6 Srv7 Srv8 cs-uri-stem

--------- ---- ---- ---- ---- ---- ---- ---- ---- ----------------------------------------------

500 0 0 0 0 0 0 0 1 /brasil/pr/2002/ms_edu_minas.stm

500 0 0 0 1 0 0 0 0 /brasil/pr/2002/ms_games_br.stm

500 0 0 0 0 0 1 0 0 /brasil/technet/topicos/codered.stm

500 1 0 0 0 0 0 0 0 /brasil/windows2000/requisitos.stm

500 0 0 0 0 2 0 0 0 /egypt/

500 0 0 0 0 1 0 0 1 /esp

500 0 0 0 0 0 0 0 35 /fwquery/

500 28 9 10 35 21 20 23 31 /gbadapp/errorpages/error.aspx

500 267 160 184 260 270 270 274 275 /ibadapp/errorpages/error.aspx

500 1 0 0 0 0 0 0 0 /middleeast/press/2001/may/gold_cert.stm

500 0 0 0 1 0 0 0 0 /middleeast/press/2001/may/officexpa.stm

500 1060 7 17 38 35 32 38 0 /obadapp/errorpages/error.aspx

500 0 0 0 0 0 0 1 0 /projectserver

500 4 2 1 2 1 0 4 5 /shared/1/navigation.asmx/DisplayDlNavHtml

500 0 0 0 0 2 0 0 1 /shared/2/navigation.asmx/DisplayDlNavHtml

500 0 0 0 0 0 0 0 2 /xml/overview.asp

I created the following Logparser file (cs-uri-stem_by_servers_in_cluster.sql) to create the URI spill by server for the HTTP 500 status code.

cs-uri-stem_by_servers_in_cluster.sql