As I reviewed some papers, that I unfortunately killed trees printing out months ago, I buoyantly ran into a blog posting by Andre Klingsheim.
I found out about Andre while googling for IIS 500. The relevant post is ” IIS 500 errors leave clues in the log ” ( http://www.dotnetnoob.com/2012/03/iis-500-errors-leave-clues-in-log.html ).
In the post, he was able to fix a pesky problem by reviewing IIS Logs and has an afterthought, he said, one can also accomplish the same via “Failed Requests Tracing”.
Log Files Parsing
As I reviewed some of our IIS Log files, I started noticing things that I had not previously noticed. And, so decided to see what tools exist for parsing and aggregating data from log files.
In the rest of this post we will talk more about using “Log Parser Studio” to interactively query IIS Log files.
Log Parser Studio was written and maintained by Kary Wall. His Bio @ https://social.technet.microsoft.com/profile/Kary%20Wall has him as a Senior Engineer with the Microsoft Exchange Support Team.
Let us download and install the following utilities:
- Log Parser 2.2
- Log parser is a powerful, versatile tool that provides universal query access to text-based data such as log files, XML files and CSV files, as well as key data sources on the Windows® operating system such as the Event Log, the Registry, the file system, and Active Directory®.
- Log Parser Studio
- Simple GUI for editing, running, and saving LogParser queries
Once downloaded, please install.
Avail IIS Logs
We need IIS Logs to churn on. I will suggest that you have your Operations Team share the IIS Log folder on your web servers or copy them over to a network location where you have access.
Run Log Parser Studio
Like other GUI Applications, to configure and initiate requests we will use the menu or tool bar.
Here is what this Application’s offering looks like.
Specify Log Files
Upon invoking that request the “Log File Manager” dialog appears; within that new window, currently specified log folders and files are listed. Requests to add new individual files and Folders can also be initiated. Existing Log Files and Folders can also be pruned from our request list.
Here is what ours looks like.
If you attempt to run a query without specifying Log Folders and Files, you will be greeted with this choice.
Queries – Aggregate by HTTP Status Code
Thankfully in the shipped library, there is an existing query that groups all requests by HTTP Status Code.
To per-use the query, please access the “Library” tab and navigate to the entry titled “IIS: Status/SubStatus Report”.
Once you find the Query, please select it and double-click your selection. A new tab with its query pane pre-filled with the canned query is furbished.
SELECT STRCAT(TO_STRING(sc-status) , STRCAT('.', TO_STRING(sc-substatus)) ) AS Status , COUNT(*) AS Total FROM '[LOGFILEPATH]' GROUP BY Status ORDER BY Total DESC
- A couple of things are immediately obvious, most of entries are earmarked with HTTP 200.
- HTTP 200 is good as it means everything is OK
- There is quite a few 405.0.
- 405.0 is not so good, has it means that we are trying to access pages with the wrong HTTP Method. Please read more here – “Error message when a user visits a website that is hosted on a server that is running Internet Information Services 7.0: ‘HTTP Error 405.0 – Method not allowed’ ” – http://support.microsoft.com/kb/942051
- And, then there are others such as 500.0, 500.24
Queries – Aggregate by HTTP Status Code (include percentile)
If your manager is like mine, he will like the data broken down into percentiles, as well.
/* HTTP Status Codes with Hits percentile */ SELECT STRCAT(TO_STRING(sc-status) , STRCAT('.', TO_STRING(sc-substatus))) AS Status , COUNT(*) AS Total , MUL(PROPCOUNT(*), 100) AS [PercentOfTotal] , Max(TO_LOCALTIME(TO_TIMESTAMP(date, time))) as [TimestampOfLastEntry] FROM '[LOGFILEPATH]' GROUP BY Status ORDER BY Total DESC
Explanation: In the output displayed above, we have added % and also the last time the error occurred. Our last 200 entry occurred on Dec 17th and our 500.24 was back in September 18th. Yes, this is my local development machine, the Production box has more recent errors; but you get my drift about the queries.
Queries – Aggregate HTTP 500 Entries (with percentile)
/* Count and sort HTTP 500 status codes */ SELECT STRCAT(TO_STRING(sc-status), STRCAT('.', TO_STRING(sc-substatus))) As Status , sc-win32-status , WIN32_ERROR_DESCRIPTION(sc-win32-status) as Description , count(*) as Hits , MUL(PROPCOUNT(sc-win32-status), 100) AS [PercentOfTotal] , Max(TO_LOCALTIME(TO_TIMESTAMP(date, time))) as [TimestampOfLastEntry] FROM '[LOGFILEPATH]' where sc-status = 500 group by sc-status , sc-substatus , sc-win32-status order by Hits desc
- Status = 500
- What does SubStatus = 0 mean?
- Module or ISAPI error occurred. ( The HTTP status code in IIS 7.0, IIS 7.5, and IIS 8.0 – http://support.microsoft.com/kb/943891/ )
- If sc-win32-status has a value other than 0, then utilize “net helpmsg <#>” to determine the actual Windows OS Error
- When win32-status is 64, the actual Windows OS Error is “The specified network name is no longer available.”
- When win32-status is 50, the actual Windows OS Error is “The request is not supported.”
- What does SubStatus = 0 mean?
Queries – HTTP 500 Entries – Details – Column – cs-uri-query
As I visually inspected the log files, I found entries that have the literal ODBC in them. They are indicating actual database errors. Let us use LogParser to make sense of them.
/* Filter cs-uri-query like %ODBC% */ SELECT TOP 25 STRCAT(TO_STRING(sc-status), STRCAT('.', TO_STRING(sc-substatus))) As Status , sc-win32-status , WIN32_ERROR_DESCRIPTION(sc-win32-status) as Description , to_localtime(to_timestamp(date, time)) as LocalTime , cs-uri-query FROM '[LOGFILEPATH]' where cs-uri-query like '%ODBC%' order by LocalTime desc
- The cs-uri-query is an overloaded field
- In this case it is being used to give us an elaborate view of ODBC DB Errors
- Here are the distinct errors
This is the line number in the source code file.
Second and Third Code
Here is our second and third values in tabular form.
The first error with missing SP is because we had yet to port a new SP to this DB Environment.
And, the second problem was due to a SQL Server Language & Internalization setting that was yet configured for the user.
We posted about same error here – “The conversion of a nvarchar data type to a datetime data type resulted in an out-of-range value“. ( https://danieladeniji.wordpress.com/2014/11/15/microsoft-sql-server-transact-sql-error-the-conversion-of-a-nvarchar-data-type-to-a-datetime-data-type-resulted-in-an-out-of-range-value/ ).
At this point the chart’s interface is very minimal and it does not appear that we can configure X and Y axis much. And, so we ended up striping away extraneous columns and having only the columns we wanted to chart on.
Here is the query for looking at our 500’s against Win32 Error Codes.
/* Count and sort HTTP 500 status codes */ SELECT sc-win32-status , count(*) as Hits FROM '[LOGFILEPATH]' where sc-status = 500 group by sc-status , sc-substatus , sc-win32-status order by Hits desc
As I always say the good thing about writing is that it forces and encourages one to publicly give credit. Most of the LogParser queries are seeded by the ones shared by James Skemp @ http://logparserplus.com/Examples.
Set out to write more about HTTP 500 and SQL Server time outs.
But, like Jude, whose book I have been listening to via a shared commentary on YouTube, I found myself with a problem.
Here is Jude’s opening Salvo:
Dear friends, although I was very eager to write to you about the salvation we share, I felt compelled to write and urge you to contend for the faith…
Mine is far away simpler. And, I will anchor on what my far younger “Play Sister” told me last weekend. She wanted me to do something for her, and I wanted to avoid doing it. And, so she quipped “Hey Mister….”.
More on the semblance later.
The talk about Jude took me back to “Hey Jude” by the Beatles. Here is a fabulous song I only just discovered within the same journey.
John Lennon – Beautiful Boy
And, the song does make a shared, universal sense and truth, as “Life is what happens to you while you’re busy making other plans” – John Lennon. I can’t believe it is 34 years to the month already.
IIS W3c Extended Log Format
- MICROSOFT IIS W3C EXTENDED LOG FORMAT ( Nihuo Software )
IIS Status and Substatus codes
- IIS 6 Status and Substatus codes
- HTTP 500.x — Internal Server Error Codes
- How to use HTTP Detailed errors in IIS
Log Parser Query Samples
- Log Parser Plus
Log Parser Studio
- Getting Started with Log Parser Studio
- Log Parser Studio 2.0 Released!