Win2k8R2 / IIS 7.5 - users getting 503 response, no 503 error reported in logs

Question

I've got 2 web servers with mirrored content. There's a load balancer sitting in front of them.

Starting yesterday we've been getting people complaining about 503 errors. i can't find any 503 errors in the IIS log file. However the server host is saying these errors are due to .Net errors in our website which are causing the app pool to recycle.

They pointed out several errors in the windows application event log which look like this:

Log Name:      Application
Source:        ASP.NET 4.0.30319.0
Date:          3/31/2012 8:35:37 PM
Event ID:      1309
Task Category: Web Event
Level:         Warning
Keywords:      Classic
User:          N/A
Computer:      6251.local
Description:
Event code: 3005 
Event message: An unhandled exception has occurred. 
Event time: 3/31/2012 8:35:37 PM 
Event time (UTC): 4/1/2012 1:35:37 AM 
Event ID: e7a580c7b38545cca3416a8595408f24 
Event sequence: 97 
Event occurrence: 1 
Event detail code: 0 

Application information: 
    Application domain: /LM/W3SVC/2/ROOT-1-129777167518960645 
    Trust level: Full 
    Application Virtual Path: / 
    Application Path: C:\inetpub\wwwroot\mywebsite\ 
    Machine name: 6252 

Process information: 
    Process ID: 20000 
    Process name: w3wp.exe 
    Account name: IIS APPPOOL\MyAppPool

In particular they are saying that the account name under Process Information indicates that the app pool is recycling. They said if the app pool were not recycle, the accountname would instead be the folder where the website files are located.

I checked the app pool settings - it's set to recycle every 29 hours. And the rapid fail protection is set to the default of 5 failures in 5 minutes. But i have not seen 5 failures in the event log in that short of a time span.

Can anyone help me confirm if the 503 responses are indeed being generated by the app pools recycling? Or are these errors coming from somewhere else? My guess at the time was their load balancer was the one actually returning the 503 error. But that was just a guess.

Solution

You've mentioned "IIS Log File" (singular), but there are always two logs you need to evaluate:

• W3SVCnn logs (C:\Inetpub\Logs) from the website worker process, and
• HTTPERR logs (C:\Windows\System32\Logfiles\HTTPERR) from HTTP.SYS, which routes requests to worker processes and provides a kernel-mode queue designed to buffer clients from worker process changes (like recycling)

503s are far more likely to appear in HTTPERR logs, along with a reason for failure, because they're more likely to reflect a failure of HTTP.SYS to communicate with the worker process (or a queue overflow, which amounts to a similar thing).

See also http://support.microsoft.com/kb/820729 - not sure why there's a "Fix it" when the article describes what the logging does and (at the bottom) the reasons it might log for a failure.

A bit more

There are two queues in most app frameworks - the HTTP.SYS request queue (in kernel mode) and a user-mode request queue. If a user-mode framework (like ASP.Net) queues requests internally, then the failure of a worker process will result in a 503 (or at best a 500) for all requests queued within it, causing HTTP.SYS to regard those requests as abandoned and unsalvageable.

If your app is failing with unhandled exceptions, you need to fix that - there's nothing the IIS architecture can do to insulate {batches of in-flight requests} from {the app lunching itself} and you will get some form of error communicated to the client - Recycling ensures there's a new worker process ready to serve the second try.