January 2014
Volume 29 Number 1
ASP.NET : Troubleshooting Applications with IIS Logs
Eduardo Sanabria | January 2014
Have you ever tried to troubleshoot or debug an application without having ever seen the code? Have you ever had a malfunctioning application, and neither the browser nor the application provided a useful error code?
I’ve encountered both scenarios many times, and it’s a good idea to be prepared for their eventuality. The techniques I’ll describe in this article will help you troubleshoot any application or system running under IIS, no matter what platform it’s coded on. These techniques have helped me troubleshoot applications and Web sites in a variety of situations, especially on devices other than PCs—a scenario that is becoming the norm these days. In a recent case, these techniques helped me discover why videos wouldn’t display on Apple devices though they ran perfectly on Windows-based devices.
Some Considerations
There are many valid techniques for debugging ASP.NET and other Web applications running under IIS. The browser itself often produces a specific error or set of errors that is enough to resolve the issues.
But suppose that information isn’t enough? This is where it becomes handy to know a few extra techniques. The simplest of these is also one of the quickest and best-known—running the application directly on the server. Sometimes the servers aren’t configured for this option, but if you can do it, the server will generally provide more useful debug information than an outside machine. This behavior is obviously built-in by Microsoft for security purposes. To get even more data on a server’s browser, turn off the “Show friendly HTTP error messages” option, which you’ll find in Internet Explorer, under Internet Options | Advanced.
Sometimes you’ll need more information, and that’s when logging becomes essential. Microsoft has built powerful logging facilities into its servers, which will help immensely on any troubleshooting quest, assuming you know what to look for, and where.
Turning on IIS Logging
The first step is to turn on Windows logging on the server. There are several ways to do this. The actual steps can vary (sometimes greatly) depending on which version of Windows Server is running.
Delving into those steps or describing the drawbacks and advantages of each is beyond the scope of this article. Here, I’ll simply point out that to properly use logging to debug your applications, you must turn it on before the actual errors occur. You’ll find a lot of useful information in these two MSDN articles for Windows Server 2003 and 2012: “How to configure Web site logging in Windows Server 2003” (bit.ly/cbS3xZ) and “Configure Logging in IIS” (bit.ly/18vvSgT). If these don’t meet your needs, there are plenty of other online articles relevant to turning on logging in IIS for other versions of Windows Server.
Determine the Proper ID Number
Once logging is on, you need to find out the ID number in IIS of the Web site you’re troubleshooting. This is crucial, as servers typically host more than one Web site, and trying to find the log folder manually can be daunting. (I attempted it on a server running 45 Web sites and it was almost impossible.)
Open IIS Manager to display all Web sites being hosted. For this example, suppose I’m attempting to find out why WebSite2 suddenly stopped working or is only working intermittently.
As you can see in Figure 1, the ID for WebSite2 is “3.” The next step is to open the corresponding log folder, which is typically (but not always) found in the Inetpub folder. Windows usually creates this folder in the root (C:) of the server, but in my case, the Inetpub folder is on the D: drive. Industry best practices advise keeping code and OS drives separate for easy swapping in case of failure.
.png "Finding the Web Site ID Number")
Figure 1 Finding the Web Site ID Number
Windows names all logging folders W3SVC#, where # is the ID of the given Web site. Because the ID of the site being debugged in this case is 3, the log files are located in a folder named W3SVC3, as shown in Figure 2.
.png "Opening the Log-File Folder")
Figure 2 Opening the Log-File Folder
Browse the Files
When you open the correct folder, you may see a lot of files. IIS usually keeps many different files, depending on how you’ve configured the server history or how long logging has been on. To find the file you need, an almost-sure bet is to scroll to the bottom of the list and open the last file, though if you have the exact time the error occurred, you can locate the file using the date and time in the name of the file. Either way, open the file using a file editor such as Notepad.exe.
You’ll probably see a lot of data in the file. At first glance, the information might seem cryptic and useless, but with a little study you can find plenty of gems buried within this data. I’ll look at some of the most useful data elements recorded by the logging process.
IIS and Windows log an individual line for each HTTP request. A typical line looks like this:
2013-08-28 00:01:12 128.128.128.20 GET /default.asp - 443 - 200.200.200.17 Mozilla/4.0+(compatible; +MSIE+8.0; +Windows+NT+6.1; +WOW64;+Trident/4.0;+SLCC2;+.NET+CLR+2.0.50727; +.NET+CLR+3.5.30729;+.NET+CLR+3.0.30729;+InfoPath.3;+MS-RTC+LM+8; +.NET4.0C;+.NET4.0E; +.NET+CLR+1.1.4322) 200 0 0 15
This is a line from an actual IIS log. The data shown here is in one of the “standard” formats. However, because this option is highly configurable, there’s no guarantee your files will look exactly like my sample. Instead of wading through all the data, I’m going to focus here on the elements that are of most interest to debugging an application.
The first bolded element in the sample is the date of the request. Keep in mind this is the server date. As many Web applications run worldwide across many servers deployed in different time zones, this date can be misleading. Make sure the date accurately reflects the actual time the errors occurred. Many servers use GMT time, but you should validate the format.
Next, you’ll see the IP address that was accessed, the HTTP operation type (GET) and the actual file requested or accessed. In the following sample line, the code is calling the default.asp file:
128.128.128.20 GET /default.asp
This information is valuable, as there may already be errors occurring at this stage of the process. For example, you might be expecting another file to be executed at this point.
The next part of the line shows the IP address where the request originated, as well as the receiving port:
443 - 200.200.200.17
This information is also important, as sometimes it’s necessary to verify that the request you’re troubleshooting actually came from a known source.
As you can see, the actual port used is also referenced. This seemingly unimportant bit of information is vital when looking for issues. For example, the firewall may not be configured correctly. This data is followed by a lot of information, mostly related to versions:
+MSIE+8.0; +Windows+NT+6.1;+WOW64;+Trident/4.0;+SLCC2; +.NET+CLR+2.0.50727; +.NET+CLR+3.5.30729;+.NET+CLR+3.0.30729; +InfoPath.3;+MS-RTC+LM+8; +.NET4.0C
For example, you can see whether the browser is running 32- or 64-bit, the CLR versions (for those who delve that deeply into the .NET universe), and the actual .NET version installed on the server (in this case, .NET 4 C).
Get to the Bottom of Things
Up to this point, I’ve shown the relatively obvious parts of the log file entry. Most importantly, you can see which browser is responding to the HTTP request. Sometimes this will suffice, as different browsers may produce different results. Here are some partial strings showing what Firefox and Chrome might look like in the file:
;+rv:17.0)+Gecko/20100101+Firefox/17.0 404 0 2 109
+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/28.0.1500.95+Safari/537.36 200 0 0 125
It can be difficult to detect which of several HTTP requests is being debugged because they all look similar. This is where changing the browser can come in handy. By adding an entry from a different (and unexpected) browser, such as Safari or Opera, it can be easier to find and consequently troubleshoot the entry in question.
Finally, take a look at the last four items on the line:
200 0 0 15
The last number, 15, is the response time (in milliseconds) of the HTTP request. This is a very useful piece of information. Knowing how long a request took to process can help you decide whether a given code snippet, Web service or process is taking the desired or “normal” amount of time.
It may surprise you to discover relatively simple steps in a process are taking unexpected processing time. In a recent case, an application sometimes logged in and sometimes failed to log in, without producing a trappable browser error—or any error at all. It just failed. After reviewing the response times in the log, the developers discovered this property in the web.config file:
<add name="CacheProfile1" duration="30" />
The value of this parameter, apparently harmlessly set to 30 seconds, was simply too large. Once it was reduced, the application worked as expected.
Now (repeating the line here for clarity) I’ll zero in on one of the most important parameters from the set I’m reviewing. The first item, 200, is the actual HTTP response from IIS:
200 0 0 15
That HTTP response code, 200, means success. Often, you’ll encounter a known error type, such as 404 (not found) or 500 (internal server error) and that may give you enough information to troubleshoot and resolve an issue. For an official list of HTTP status codes, visit bit.ly/17sGpwE.
I’ll now relate one more real-world case—the one that actually prompted me to share this article. I had a Web site that worked and executed perfectly on PCs, but as soon as the users accessed the site on their iPad devices, video streaming simply didn’t work. To make things worse, there was no error code; the video just refused to function.
This is where troubleshooting with the logs proved invaluable. By checking the logs and verifying the HTTP request was being made from Safari (to isolate the request), I discovered the server reported a 404 error. The error message was confusing and the error itself seemed implausible, as the PC version of the site worked perfectly.
Though the logs were reporting the object wasn’t being found, I knew very well the files were in place. This prompted me to review the different ways iOS and Windows handle and store files. As I explored the source code that loaded the video, I discovered that the actual path to the video files had been hard-coded in the source, and that the path didn’t exist in iOS iPad devices. That was the reason for the 404.
It’s important to note here that all the symptoms pointed elsewhere. For example, such a problem is typically resolved by checking for the existence of unsupported media types (or Multipurpose Internet Mail Extensions [MIMEs]) in IIS. However, if the problem were a missing MIME type, the error code would have been an HTTP 415 (unsupported Media type) or a similar error, and the logs didn’t report that. Debugging using the IIS logs proved instrumental in finding the problem. I saved a significant amount of time by seeing the actual error code and investigating it, rather than chasing after what would have initially seemed more likely. Once again, knowing how to read the logs saved the day.
Wrapping Up
Log files can be a powerful tool for debugging and troubleshooting applications, even in “blind” situations, provided you know where to find them and what the data means. Investigating the data in the logs is one of the simplest—yet more sophisticated and complete—methods you’ll find to resolve issues.
It takes a little practice and certainly some discipline, but once you’re comfortable with these techniques, you should be able to debug and resolve most application and IIS issues. I’ve put these techniques to good use, and so can you.
Eduardo Sanabria is a service delivery consultant IV for HP Enterprise Services in El Paso, Texas. There he delivers quality results that matter, serving as the .NET subject matter expert (SME) in his current project. Sanabria brings to Hewlett-Packard Co. more than 25 years of full-cycle application development experience. His specialties are .NET, database applications, data processing and Web development. Sanabria can be reached at EdSanabria@Yahoo.com.
THANKS to the following technical expert for reviewing this article: Roger Hawkins (Hewlett-Packard)
Roger Hawkins is the Chief Technologist for Applications Delivery for all the Americas at Hewlett-Packard, and a Distinguished Technologist for the company