Monday 11 August 2014

IIS Log information & structure

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.netexceptions, this field can confirm you your doubts about network issues.Thereare 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.

No comments:

Post a Comment