Understanding IIS Logs

6 Mar

Webserver logs provides lot of information to the performance engineer with regard to errors, response time and many other things which cannot be seen from the front end or User interface side of the application. So it’s important for the performance engineer to understand as what information these logs contain and what type of issues we can identify and confirm from the Webserver logs. So for the sake of understanding, I would take the example of IIS and quickly run through the some of the fields these  logs contains.

The typical IIS logs (taken from Microsoft Site) will contain the below mentioned data in its access logs,

Date

date

The date on which the activity occurred.

Time

time

The time, in coordinated universal time (UTC), at which the activity occurred.

Client IP Address

c-ip

The IP address of the client that made the request.

User Name

cs-username

The name of the authenticated user who accessed your server. Anonymous users are indicated by a hyphen.

Service Name and Instance Number

s-sitename

The Internet service name and instance number that was running on the client.

Server Name

s-computername

The name of the server on which the log file entry was generated.

Server IP Address

s-ip

The IP address of the server on which the log file entry was generated.

Server Port

s-port

The server port number that is configured for the service.

Method

cs-method

The requested action, for example, a GET method.

URI Stem

cs-uri-stem

The target of the action, for example, Default.htm.

URI Query

cs-uri-query

The query, if any, that the client was trying to perform. A Universal Resource Identifier (URI) query is necessary only for dynamic pages.

HTTP Status

sc-status

The HTTP status code.

Win32 Status

sc-win32-status

The Windows status code.

Bytes Sent

sc-bytes

The number of bytes that the server sent.

Bytes Received

cs-bytes

The number of bytes that the server received.

Time Taken

time-taken

The length of time that the action took, in milliseconds.

Protocol Version

cs-version

The protocol version —HTTP or FTP —that the client used.

Host

cs-host

The host header name, if any.

User Agent

cs(User-Agent)

The browser type that the client used.

Cookie

cs(Cookie)

The content of the cookie sent or received, if any.

Referrer

cs(Referrer)

The site that the user last visited. This site provided a link to the current site.

Protocol Substatus

sc-substatus

The substatus error code.

Some fields in the above logs are optional and so they need to be enabled in some cases. I suggest you if your logs don’t contain all those fields, then probably you should talk to server admin and get those enabled.Its always helps to have as many fields as possible enabled.

From the response time prospective, time taken field gives the information about the processing time it takes for IIS to process the request and in most cases contains the network timelines as well. For IIS 5x, its just the processing time at IIS level without network timeline. However starting from IIS 6x/7x , time taken field contains processing time as well as network time. This is one of most important log field which can help  to quickly identify URL’s which are taking high response time.All you need to do pull the URL with high time taken value and map it back to script and from script pull the transaction details.

sc-win32-status is also one of the important fields which we need to check in the IIS logs, if your tests contains lot of client abort exceptions or system.net exceptions, this field can confirm you your doubts about network issues.There are many integers codes which are written for every request IIS serves and whenever if any kind of issues are encountered by IIS , appropriate win32 code is written for that request in the logs. Interpreting that code can help you in identifying the root cause of the issue.To know the meaning of each sc-win32-status code, all you need to do is go to cmd command and type below lines

c: >net helpmsg  <your sc-win32-statuscode>

for example,
C:\>net helpmsg 64

The specified network name is no longer available.

s-ip and s-port  can also be helpful in cases where in your application user interface layer is protected at front end by load balancer and in these cases its load balancer which routes the requests to the various backend server using its own ip address.So If you are troubleshooting load balancing issues, then ip and port here can save you lot of time.Believe me its real pain to through packets and open around 1gb of pcap files and run through each frame.

IIS logs can also help you in confirming various issues that we normally encounter during load testing. If time taken field in IIS logs shows more response time than response time SLA’s then probably you don’t need to go into any kind of test results analysis and just post these logs to concerned teams so that they can have a look at the application or environment without wasting any further time of testing.Then there are also some cases where in advanced analysis of logs can confirm or deny some kind of network contention issues,

for example consider the below data from access logs,

#Fields: date time s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs(User-Agent) sc-status sc-substatus sc-win32-status sc-bytes cs-bytes

2009-08-11 20:19:32 x.x.x.x GET /File.aspx – 80 – y.y.y.y Mozilla/4.0+(compatible;+MSIE+8.0;+Windows+NT;+WOW64;+Trident/4.0; 200 0 0 2232 123

2009-08-11 20:19:45 x.x.x.x POST /File.aspx – 80 – y.y.y.y Mozilla/4.0+(compatible;+MSIE+8.0;+Windows+NT;+Trident/4.0; 200 0 64 0 123

In the above example, if you look at the sc-win32-status code, its 64 which means that network name is not available and http status is 200, if you see many such lines in your logs during load test, you can easily make the conclusion that something went wrong on the network side where as  IIS was able to process request successfully ,but for some reasons was not able to send the response back to client due to some network issue or say communication issues between server and the client. Checking for sc-bytes as 0 confirms that nothing was send to the client for that request. This kind of analysis will directly help you in ruling out other causes and will help you in identifying the root cause quickly.

Then there might be cases where in you might also need to map IIS logs data to the native performance counters like asp.net request queued or requests failed etc to confirm or deny some variables which might give confusing symptoms specially in cases where in we see appdomain unload events or application restart events during load tests.

So if you are having application which deals with IIS, then please do make sure that you ask for access to IIS Access logs in addition to HTTP Err logs. Both these logs will help you in identifying and fixing some of the hardest performance issues.

 

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google+ photo

You are commenting using your Google+ account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

%d bloggers like this: