IIS log-a good helper for website O & M

For a website that requires long-term maintenance, it is meaningful to make the website run stably for a long time.
Some problems that are not exposed in the development phase may occur in the O & M phase, which is also normal.
Sometimes, we want to constantly optimize the website so that the website can respond to user requests more quickly,
These events occur in the O & M phase after development.

Unlike the development phase, the O & M phase cannot allow debugging.Program, Discover various problems,
We can only analyze the website running status through various system logs,
IIS logs provide the most valuable information for websites deployed on IIS. We can analyze the website response and determine whether the website has performance problems,
Or where improvements are needed.

What information does IIS log contain?

As I mentioned earlier, [IIS logs provide the most valuable information]. What information does this provide? Let's take a look at this:

The record is as follows:
1. When the request occurs,
2. Which client IP address accesses the port of the server IP address,
3. What is the client tool type and version,
4. The request URL and query string Parameters,
5. The request method is get or post,
6. What is the request processing result: HTTP status code and the underlying status code of the operating system,
7. How much data is uploaded by the client and how much data is sent by the server during the request,
8. The total length of time the request occupies the server, and so on.

What is the purpose of this information for analysis? I will talk about it later. First, you can have an impression on it.

IIS log Configuration

By default, IIS generates log files. However, some parameters are worth our attention.
The IIS setting interface is as follows (This article uses the IIS 8 interface as an example ).

In IIS manager, select a website and double-click the log icon. For more information, see:

The (main part) interface is as follows:

In, the log creation method is to generate a new file every day and generate a file name by date (this is the default value ).
Note: IIS uses UTC time, so I checked the bottom check box to tell IIS to use local time to generate a file name.

Click Select field. The following dialog box is displayed:

Note:[Number of sent fields] and [number of received bytes] are not selected by default.We recommend that you select them.
For other fields, you can decide whether to select them as needed.

How to analyze IIS logs

If you set IIS log parameters according to the method described above, IIS will generate IIS logs after processing the request (after a period of time.
You can click View log file in operation on the Right of log interface to quickly locate the IIS log root directory,
Find the corresponding log file in the directory (the directory is distinguished by the application pool serial number by default ).

For example, I found the log I needed:

This file contains a lot of dense characters. How can I analyze it now?

There isLog parserYou can use this tool to parse IIS logs and view the information in the logs.
For example, you can run the following command line (note: in order not to affect the page width, I wrap the command text ):

 
"C: \ Program Files \ log parser 2.2 \ logparser.exe"-I: iisw3c-O: DataGrid "select C-IP, CS-method, S-port, CS-Uri-stem, SC-status, sc-win32-status, SC-bytes, CS-bytes, time-taken from u_ex130615.log"
 

Now you can read IIS logs in a table:

Note:I do not recommend using this method to analyze IIS logs.There are two reasons:
1. Slow: When the log file is a little larger, it is a waste of time to use it for analysis (especially when multiple statistics are required ).
2. inconvenient: the query syntax supported by SQL Server is not as comprehensive as that of SQL Server for Data Table query.

Recommended IIS Log Analysis Methods

Although log parser supports parsing IIS logs in the form of tables for users to read, sometimes we may perform [multiple] queries in different ways when doing some detailed analysis,
If you run log parser directly for each query, you will waste a lot of time.
Fortunately, log parser supports exporting resolution results in multiple formats (The following is a help document ):

Here, we recommend that you select SQL as the output format.
Note: The SQL here does not refer to sqlserver, but to all databases that provide ODBC access interfaces.
I can use the following command to import IIS logs to sqlserver (note: in order not to affect the page width, I wrap the command text ):

 
"C: \ Program Files \ log parser 2.2 \ logparser.exe" "select * From 'd: \ temp \ u_ex130615.log 'to mymvc_weblog"-I: iisw3c-O: SQL-oconnstring: "Driver = {SQL Server}; server = localhost \ sqlexpress; database = mytestdb; Integrated Security = sspi"-createtable: On
 

After the import is complete, we can use the familiar sqlserver for various queries and statistical analysis, such as the following query:

SelectCIP,Csmethod,Sport,Csuristem,Scstatus,Scwin32status,Scbytes,Csbytes,TimetakenFromDBO.Mymvc_weblog
 

If:

Note:
1. When IIS logs export results to sqlserver, characters that do not conform to the identifier specification in the field name will be deleted.
For example, C-IP is changed to CIP, and s-port is changed to sport.
2. The time recorded in IIS logs is UTC time, and the date and time are separated. when exported to sqlserver, two fields are generated:

The date and time fields seem uncomfortable, right?
I am also very disgusted with this result. The two solutions are as follows:

1. Add a column in sqlserver and replace UTC time with the time in the local time zone. The T-SQL script is as follows:

 ALTER TABLE  Mymvc_weblog  Add  Requesttime  Datetimego  Update  Mymvc_weblog  Set  Requesttime  =  Dateadd (  HH  , 8 ,  Convert  (  Varchar  ( 10 ),  Date  , 120 ) +  ''  +  Convert  (  Varchar  ( 13),  Time  , 114 )) 

2. directly convert the time when exporting IIS logs. Modify the command at this time:

 
"C: \ Program Files \ log parser 2.2 \ logparser.exe" "select to_localtime (to_timestamp (add (to_string (date, 'yyyy-mm-dd'), to_string (time, 'hh: mm: ss'), 'yyyy-mm-dd hh: mm: ss') as requesttime, * From 'd: \ temp \ u_ex130615.log 'to mymvc_weblog2 "-I: iisw3c-O: SQL-oconnstring:" driver = {SQL Server}; server = localhost \ sqlexpress; database = mytestdb; integrated Security = sspi "-createtable: On
 

Let's look at these three columns:

SelectRequesttime,Date,Time fromMymvc_weblog2
 

After such processing, you can directly Delete the date and time columns (you can also ignore them when exporting IIS logs, but specify the names of each field ).

Here is the UTC time in IIS logs. I hope everyone understands it ~~~~~~~~~~~

IIS log exception records

The IIS log records the information of each request, including normal response requests and abnormal requests.

The [Exception] mentioned here has nothing to do with exceptions in. NET Framework.
For an ASP. NET program, if an uncaptured exception is thrown, it is recorded in the IIS log (500), but the exception I mentioned is not limited to this.

The exceptions mentioned in this article can be divided into four parts:
1. The uncaptured exception thrown by the (ASP. NET) program causes the server to generate a 500 response output.
2. A request resource such as 404 does not exist.
3. Server errors greater than 500, for example, 502,503
4. system error or network transmission error.

The first three types of exceptions can be obtained using the following query:

  select   scstatus  ,  count   (*)   as   count  ,   sum   (  timetaken   *  1.0 )/ 1000.0  as   sum_timetaken_second   from   mymvc_weblog   with   (  nolock  )   group by   scstatus   order by  3  DESC  

The IIS log contains a sc-win32-status that records system-level errors, such as network transfer errors, that occur during request processing.
Under normal circumstances, 0 indicates normal, and a non-zero value indicates an error. We can calculate such errors as follows:

 Declare  @ Reccount  Bigint  ;  Select  @ Reccount  =  Count  (*)  From  Mymvc_weblog  With  (  Nolock  )  Select Scwin32status  ,  Count  (*)  As  Count  ,(  Count  (*)* 100.0 /  @ Reccount  )  As  [Percent]  From  Mymvc_weblog  With  ( Nolock  )  Where  Scwin32status  > 0 Group  Scwin32status  Order 2 Desc 

The following table lists common network-related errors and explanations:

Scwin32status	Description
64	Client Connection closed (or disconnected)
121	Transmission timeout
1236	Local network interruption

All status codes can be interpreted using the following command:

The network name specified by D: \ Temp> net helpmsg 64 is no longer available.
 

For details about scwin32status and scstatus, I would like to add that they are not associated.
For example, request this address: http://www.abc.com/test.aspx
It is possible that scstatus = 200, but scwin32status = 64 indicates that ASP. NET has successfully processed the request, but when IIS sends the response, the client connection is disconnected.
In another case, scstatus = 500, but scwin32status = 0 indicates that no exception is caught during request processing, but the exception result is successfully sent to the client.

Let's talk about scwin32status = 64

I remember that I was not quite familiar with scstatus = 200 and scwin32status = 64, so I searched the internet and found all kinds of answers. Some even said they were related to web crawlers.
To verify the answers, I did a test. I wrote an ashx file and used it to simulate long-time network transmission,CodeAs follows:

 Public class  Test_iis_time_taken : Ihttphandler { Public void Processrequest ( Httpcontext Context) {Context. Response . Contenttype =  "Text/plain" ; System . Threading .  Thread  . Sleep ( 1000  *  2 ); Context . Response . Write ( String  . Format ("{0}, {1} \ r \ n" , "Start" , Datetime  . Now); Context . Response . Flush (); System . Threading .  Thread  . Sleep ( 1000  *  2 ); For ( Int I=  0 ; I <  20 ; I ++ ) {Context . Response . Write ( String  . Format ( "{0}, {1} \ r \ n" , I, Datetime  . Now); Context . Response . Flush (); System. Threading .  Thread  . Sleep ( 1000  *  1 );} Context . Response . Write ( "End" );}

This code is very simple. I don't want to explain it too much. I just want to say: I use the thread. Sleep and response. Flush methods to simulate a long continuous sending process.

We can see this output in the browser (it shows that I am not completely finished yet)

I performed this test eight times, and only two times were all displayed. I closed the browser window in advance for the other six times.
Then, let's look at the IIS log Content:

Based on IIS logs and my own operations, we can find that:
1. When I close the browser window in advance, I will see scstatus = 200, scwin32status = 64
2. If all the request content is displayed, I will see scstatus = 200, scwin32status = 0
From this experiment, we can also find that timetaken contains the network transmission time.

Based on the results of this test, have you ever thought of the following question:
If the IIS log of your website contains a large number of scstatus = 200, scwin32status = 64,
The request is initiated by the user's browser.
What is the cause?
My [conjecture] Is that users are unwilling to wait again when they visit this website. They have closed the browser window.
In other words, we can see from the statistical results of scwin32status = 64 whether the website response speed can satisfy users.

Find performance problems

The IIS log contains a column named timetaken, which indicates all time on the IIS interface.
The time used is defined as follows:The time from when the server receives the request from the first byte until all the response content is sent.
Microsoft's web site has made instructions on this field: http://support.microsoft.com/kb/944884

Once we understand the definition of timetaken, we can use it to analyze the processing time of some requests, that is, performance analysis.

For example, if you want to view the loading status of the slowest 20 pages, you can query them as follows:

 Select top 20 Csuristem  ,  Scstatus ,  Scwin32status  ,  Scbytes  ,  Csbytes  ,  Timetaken  From  DBO  .  Mymvc_weblog  With  (  Nolock  )  Where  Csuristem  Like '/Pages/%'  Order  Timetaken  Desc 

Or I want to see the response of the 20 slowest Ajax situations again, you can query it like this:

 Select top 20 Csuristem  ,  Scstatus  ,  Scwin32status  ,  Scbytes  ,  Csbytes  ,  Timetaken  From DBO  .  Mymvc_weblog  With  (  Nolock  )  Where  Csuristem  Like  '/Ajax/%'  Order  Timetaken  Desc 

In short, the way to find performance problems is to select the timetaken field in the query and use it for descending sorting.

Note:The two fields scbytes and csbytes are also worth our attention:
1. If csbytes is too large, we need to analyze whether the form contains too much useless data and whether the form can be split.
Another possibility is that the cookie is too large, but it will show that the csbytes of many requests are too large, so it is easy to distinguish.
2. If scbytes is too large, check whether there are no pages on the page, or consider loading as needed.
The typical situation is that when viewstate is used in large quantities, the values will increase. Therefore, we can detect viewstate misuse through IIS logs.
Another special case is that uploading and downloading files will also increase these two values, which I will not explain.

Scbytes and csbytes, no matter which value is large, will occupy the network transmission time. For users, it takes a longer wait time.

I suddenly talked about three fields. Which one should I refer to when looking for performance problems?
I think timetaken should be given priority, because its value directly reflects the user's waiting time (excluding the front-end rendering time ).
If timetaken is too large, check whether scbytes and csbytes are too large,
If the latter two are too large, the optimization direction is to reduce the amount of data transmission. Otherwise, it means that the processing of the program takes a lot of time and the optimization of the program code should be considered.

Find the target for improvement

In addition to discovering performance problems from IIS logs, you can also use it to find the target for improvement.
For example:
1. Is there a 404 error?
2. Is there a large number of 304 requests?
3. Is there a large number of repeated requests?

When 404 responses are detected, we should analyze the cause of 404:
1. Is the URL entered incorrectly?
2. Do developers still reference nonexistent resource files?
If it is the latter, it is necessary to remove invalid references as soon as possible, because 404 responses are also a page response, and they also occupy network transmission time,
In particular, such requests cannot be cached, and they will always appear, wasting network resources.

If you want to easily find the 404 error in the development stage, refer to my blog: some errors that should be discovered before the program is released.

If you find that there are a large number of 304 requests, you should analyze them carefully:
1. Is the 304 request generated due to the ASP. NET cache response?
2. Is the 304 request generated when a static resource file is requested?
If it is the latter, it may be related to browser settings or IIS settings.

IIS has the "enable content expiration" function, which can be used to set the cache header when the response is output to reduce the number of requests.
This function is useful for static files, and the results of ASP. NET processing are not affected.
For specific setting methods, refer to: some methods to optimize ASP. NET Website performance without modifying code

We can use this query to analyze the page loading frequency:

 Select top 20 Csuristem  ,  Count  (*)  As  [Count]  ,  AVG  (  Timetaken )  As  Avg_timetaken  ,  Max  (  Timetaken  )  As  Max_timetaken  From  Mymvc_weblog  With  (  Nolock  )  Where  Csuristem  Like '/Pages/%'  Group  Csuristem  Order 2 Desc 

If a large number of repeated requests are found, further careful analysis is required:
1. Does the Request Response content vary with different parameters?
2. The request URL is fixed, and the response content is rarely changed.
If it is the latter, you can consider using the page cache function. Example: ASP. NET outputcache

Some methods for optimizing ASP. NET Website performance without modifying code in my blog
This article introduces a function to cache requests without modifying the Code. If necessary, try it.

Influence of program architecture on IIS log analysis process

I have introduced some methods for analyzing IIS logs. These methods cannot be left alone.
Most of the time, we need to output URL Information (CS-Uri-stem) in the query and collect statistics based on their grouping,
Therefore,Reasonable URL design will facilitate later statistics,
More accurate statistical results can also be obtained.
An extreme counterexample is webforms's default development method. page loading and the submission of each button are the same URL. You will find it difficult to count the time spent on each operation.

What URL design can meet the statistical needs?
In my opinion, each user operation (page display or submission) should have a URL corresponding to it, and different URLs can reflect different operations.
In addition, it is recommended that different user operations be distinguished in URLs to facilitate more statistics (such as page loading, Ajax requests, and report display ).

Although we can use timetaken for Performance Statistics, when you use frameset or IFRAME in a large number of programs,
It is difficult to count how long it takes to load a page (a page containing IFRAME.
Because the entire page is divided into multiple requests, they are not consecutive in the IIS log, and you cannot accurately collect statistics based on user requests.
For example, a1.aspx embeds b1.aspx, b2.aspx, and b3.aspx in IFRAME mode. When you calculate the loading time of a1.aspx,
The result you get is always different from what you feel, because the timetaken of a1.aspx does not contain the timetaken of b1.aspx, b2.aspx, and b3.aspx!

Therefore, if you want to use IIS logs to analyze program performance, you should stop using IFRAME.

If you believe that reading this blog has some benefits, click 【Recommendation] Button.
If you want to discover my new blog more easily, click 【Follow fish Li].
Because my enthusiasm for writing is inseparable from your support.

Thank you for reading this article. If you are interested in the content of my blog, please continue to follow up on my blog. I am fish Li.