{"id":210,"date":"2007-12-29T07:00:04","date_gmt":"2007-12-28T19:00:04","guid":{"rendered":"http:\/\/craig.dubculture.co.nz\/blog\/2007\/12\/29\/debugging-w3wpexe-and-iis-application-pools\/"},"modified":"2008-03-22T09:13:01","modified_gmt":"2008-03-21T21:13:01","slug":"debugging-w3wpexe-and-iis-application-pools","status":"publish","type":"post","link":"http:\/\/craig.dubculture.co.nz\/blog\/2007\/12\/29\/debugging-w3wpexe-and-iis-application-pools\/","title":{"rendered":"Debugging w3wp.exe and IIS application pools"},"content":{"rendered":"<p>Problem: after hitting \"Login\" on an ASP.NET web application on IIS6, w3wp.exe races to high CPU usage, and about 70MB of memory.  CPU usage falls off, but memory usage increases a few KB every second.  No indication is made that the application has crashed or hung, no output.<\/p>\n<p>The first utility I installed to check this out was <a href=\"http:\/\/iismonitor.motobit.com\/\">IISTracer<\/a>.  Ignore the horrible web site - this is a nice little utility which lets you see what requests IIS is currently serving.  In this instance the default.aspx page calls a dashboard.aspx, which was timing out indefinitely without returning a response to the client.<\/p>\n<p>There are a number of utilities you can use to debug IIS faults.  <a href=\"http:\/\/blogs.msdn.com\/david.wang\/archive\/2005\/08\/29\/HOWTO_Understand_and_Diagnose_an_AppPool_Crash.aspx\">David Wang's guide on how to understand and diagnose an application pool crash<\/a> gives some insight into how it should be done - attach a debugger and wait for the fault, then look at the stack trace.  His suggestions include <a href=\"http:\/\/www.microsoft.com\/technet\/prodtechnol\/WindowsServer2003\/Library\/IIS\/993a8a36-5761-448f-889e-9ae58d072c09.mspx\">IISState<\/a>, an IIS resource kit utility, which will give you an output of the current state of an IIS process; and <a href=\"http:\/\/www.microsoft.com\/downloads\/details.aspx?FamilyID=28bd5941-c458-46f1-b24d-f60151d875a3&amp;displaylang=en\">DebugDiag<\/a>, a much nicer and newer interactive debugger for IIS.<\/p>\n<p>I spent a couple of days playing with DebugDiag, and unfortunately, due to the nature of my problem, I couldn't get anything useful.  It seems that the application wasn't ever actually crashing or hanging - states that DebugDiag should be able to deal with easily. IISState, on the other hand, suggested I was regularly getting <a href=\"http:\/\/blogs.msdn.com\/davidklinems\/archive\/2005\/07\/12\/438061.aspx\">first chance exceptions<\/a> thrown.  A first chance exception means an exception has been raised - if the application handles it, then nothing more is mentioned, else it becomes a second chance exception, and the debugger or system exception handler is called). So, more digging was required.<\/p>\n<p><a href=\"http:\/\/craig.dubculture.co.nz\/blog\/wp-content\/uploads\/2007\/12\/windbg.PNG\" title=\"WinDbg, the Windows Debugger\"><img decoding=\"async\" src=\"http:\/\/craig.dubculture.co.nz\/blog\/wp-content\/uploads\/2007\/12\/windbg.thumbnail.PNG\" alt=\"WinDbg, the Windows Debugger\" align=\"right\" \/><\/a>Enter the <a href=\"http:\/\/www.microsoft.com\/whdc\/devtools\/debugging\/default.mspx\">Windows debug tools<\/a>, and specifically <a href=\"http:\/\/en.wikipedia.org\/wiki\/WinDbg\">WinDbg<\/a>. This is what the professionals use, and as such, it's ultimately powerful and incredibly scary. It's updated regularly, except for the interface, which is <a href=\"http:\/\/msdn.microsoft.com\/msdnmag\/issues\/03\/06\/Bugslayer\/\">nicest described as \"circa-1990\"<\/a>.<\/p>\n<p>There are a number of blogs that mention running WinDbg, but none that actually put together all the pieces on how to debug this kind of problem.  So here's my story for you.<\/p>\n<p>First, attach the debugger to your w3wp.exe process.  I found it's process ID in Task Manager - you need to add the PID column.  At this point, I get a breakpoint hit - you might not, so use <u>D<\/u>ebug\/<u>B<\/u>reak or Ctrl-Break to stop the program.<\/p>\n<p>Debugging symbols let you see not just the memory location of a failure, but the name of the function that it is in.  They are not normally included with release software as they make it a lot larger, but can be downloaded separately in this case. DebugDiag is friendly and will automatically download appropriate debugging symbols for you from <a href=\"http:\/\/www.microsoft.com\/whdc\/devtools\/debugging\/debugstart.mspx\">Microsoft's symbol server<\/a>, and put them in c:\\symcache\\. WinDbg is less friendly and requires you set this up yourself.  I used the same path, as I already had some symbols downloaded - I told WinDbg to look at the local symbols first, and look at the online symbol server if they're not already cached there. Do this like so:<\/p>\n<pre>.sympath SRV*c:\\symcache*http:\/\/msdl.microsoft.com\/download\/symbols<\/pre>\n<p>Now, we need to load the <a href=\"http:\/\/blogs.msdn.com\/jasonz\/archive\/2003\/10\/21\/53581.aspx\">SOS debugger helper<\/a>, which lets you debug managed code in WinDbg  (Nerd note: SOS stands for Son of Strike, which is a <a href=\"http:\/\/blogs.msdn.com\/jasonz\/archive\/2003\/10\/21\/53581.aspx\">Microsoft in-joke<\/a>.) If you started the process inside the debugger, you can apparently do this:<\/p>\n<pre>0:033&gt; .loadby mscorlib sos\r\nUnable to find module 'sos'<\/pre>\n<p>I couldn't, so I'll do this:<\/p>\n<pre>0:033&gt; .load C:\\WINDOWS\\Microsoft.NET\\Framework\\v2.0.50727\\SOS.dll<\/pre>\n<p>If you're running .NET 1.1, you can <tt>.load clr10\\sos.dll<\/tt> for the version shipped with the debugger.<\/p>\n<p>Now, we instruct it to break whenever there is an exception thrown:<\/p>\n<p><tt>0:033&gt; sxe CLR<\/tt><\/p>\n<p>And hit <u>D<\/u>ebug\/<u>G<\/u>o, type 'g and hit Enter, or hit F5 to resume the program.<\/p>\n<p>No sooner than I hit 'g', we get results!<\/p>\n<pre>0:033&gt; g\r\n(a78.8b4): CLR exception - code e0434f4d (first chance)\r\nFirst chance exceptions are reported before any exception handling.\r\nThis exception may be expected and handled.\r\neax=0230ec7c ebx=000d9c50 ecx=00000000 edx=00000024 esi=0230ed08 edi=e0434f4d\r\neip=77e4bee7 esp=0230ec78 ebp=0230eccc iopl=0         nv up ei pl nz na po nc\r\ncs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00200202\r\nkernel32!RaiseException+0x3c:\r\n77e4bee7 5e              pop     esi<\/pre>\n<p>I don't speak assembly and really have no desire to.  Thankfully the SOS extension lets us look at the exception, and the call stack (the list of functions that we called to get where we are). Type <tt>!pe<\/tt> to print the exception, and <tt>!clrstack<\/tt> to see the call stack.<\/p>\n<pre>0:012&gt; !pe\r\nException object: 048f8a4c\r\nException type: System.Data.SqlClient.SqlException\r\nMessage: Cannot open database requested in login 'R622P1Sy1'. Login fails.\r\nLogin failed for user 'admin'.\r\nInnerException: &lt;none&gt;\r\nStackTrace (generated):\r\n&lt;none&gt;\r\nStackTraceString: &lt;none&gt;\r\nHResult: 80131904\r\n0:012&gt; !clrstack\r\nOS Thread Id: 0x8b4 (12)\r\nESP       EIP\r\n0230ed54 77e4bee7 [HelperMethodFrame: 0230ed54]\r\n0230edf8 6539bf14 System.Data.SqlClient.SqlInternalConnection.OnError(System.Data.SqlClient.SqlException, Boolean)\r\n0230ee0c 652f695d System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(System.Data.SqlClient.TdsParserStateObject)\r\n0230ee3c 652f79e5 System.Data.SqlClient.TdsParser.Run(System.Data.SqlClient.RunBehavior, System.Data.SqlClient.SqlCommand, System.Data.SqlClient.SqlDataReader, System.Data.SqlClient.BulkCopySimpleResultSet, System.Data.SqlClient.TdsParserStateObject)\r\n0230ee90 652e932a System.Data.SqlClient.SqlInternalConnectionTds.CompleteLogin(Boolean)<\/pre>\n<p>And there's the problem. A first-class exception is handled trying to connect to a database with incorrect login details, so it continues, probably never freeing the memory from the last connection.  This particular exception doesn't get logged and doesn't get displayed on screen (probably because it's being loaded in the background) and causes an infinite timeout.  Oops!<\/p>\n<p>Armed with a little knowledge about the debugging tools, it's easy to see what's going on inside your code, even if it's running in IIS.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>Problem: after hitting \"Login\" on an ASP.NET web application on IIS6, w3wp.exe races to high CPU usage, and about 70MB of memory. CPU usage falls off, but memory usage increases a few KB every second. No indication is made that the application has crashed or hung, no output. The first utility I installed to check [&hellip;]<\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":[],"categories":[66,68],"tags":[63,3,27,4],"_links":{"self":[{"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/posts\/210"}],"collection":[{"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/comments?post=210"}],"version-history":[{"count":1,"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/posts\/210\/revisions"}],"predecessor-version":[{"id":245,"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/posts\/210\/revisions\/245"}],"wp:attachment":[{"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/media?parent=210"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/categories?post=210"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/craig.dubculture.co.nz\/blog\/wp-json\/wp\/v2\/tags?post=210"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}