How To View what ASP.NET Requests are doing at runtime on IIS 6.0
This is just a quick blog to mention a forgotten tool. The managed stack explorer can be run on an IIS 6.0 Server running ASP.NET 2.0 to investigate the managed call stacks. Looking at the call stacks when an ASP.NET application is not responding may help identify what the requests are doing.
Setting up the tool
Download the Managed Stack Explorer from here:
Run the MSI and install to a directory of your choice. The default location is C:\Program Files\Power Toys for Visual Studio\Managed Stack Explorer
How the Tool Works
The Managed Stack Explorer contains a User Interface that allows you to choose a process and thread and see the managed call stack at that point in time. See below:
The UI also gives a quick glimpse at the % time a process has spent in the GC. As a general rule, if that number is > 10-15% it might indicate a performance problem. For more information on monitoring ASP.NET Performance see this whitepaper: https://msdn.microsoft.com/en-us/library/ms972959.aspx
The Managed stack explorer also has a stack logging feature that can log the stack trace over time. When using the UI it takes a snapshot whenever a thread is selected in the thread window. It takes a snapshot of only this thread at that point in time. It does this by attaching to the process, collecting information about the thread and then detaching. When using the stack logging, the tool can be configured to scan the managed threads of a single process at a specified interval and log that to a file.
Using the stack Logging feature
For most cases where someone will want to use this tool, the stack logging feature is a good idea. IIS Server administrators might get notified that their ASP.NET Application is not responding, or the site is slow. When this happens the Managed Stack Explorer can be run with stack logging enabled for a period of time, then the log analyzed to determine what the threads and ASP.NET Requests were doing during the period of poor performance.
The following steps show how to configure Managed Stack Explorer with stack logging.
1) Choose Options->Preferences and configure the stack logging rate. The default is to log the call stack every 5 seconds. The other settings only apply to the auto refresh of the User interface.
2) Determine the Process ID Of the application to monitor. The Managed Stack Explorer shows the processes that have the .NET runtime loaded in the left pane. When multiple W3WP.exe’s are running use the following command to determine the Application Pools process ID.
a. Cscript.exe %systemroot%\system32\iisapp.vbs
3) In the processes window double-click the w3wp.exe in which the ASP.NET Application is running. This will cause the thread window to populate with a list of managed threads in that process.
4) In the Thread list window select all threads, by selecting the first thread, holding shift and then selecting the last thread in the list. The stack logging will only monitor the selected threads, so make sure to select all of them.
5) Choose Action->Start Stack Logging from the menu and specify a file to log the stack traces too. This will start the stack logging
6) Stop the trace after enough data is collected and then choose Action->Stop Stack Logging from the menu.
7) Open the generated log file and look at what the threads were doing.
Analyzing the stack log file
Open the generated log file in notepad or another text editor. You will get output similar to the following for each thread:
4/28/2009 11:31:14 AM
Stack trace depth is set to show all frames
Thread ID: 5196
0. _Default.Page_Load (Source Unavailable)
1. System.Web.Util.CalliHelper.EventArgFunctionCaller (Source Unavailable)
2. System.Web.Util.CalliEventHandlerDelegateProxy.Callback (Source Unavailable)
3. System.Web.UI.Control.OnLoad (Source Unavailable)
4. System.Web.UI.Control.LoadRecursive (Source Unavailable)
5. System.Web.UI.Page.ProcessRequestMain (Source Unavailable)
6. System.Web.UI.Page.ProcessRequest (Source Unavailable)
7. System.Web.UI.Page.ProcessRequest (Source Unavailable)
8. System.Web.UI.Page.ProcessRequestWithNoAssert (Source Unavailable)
9. System.Web.UI.Page.ProcessRequest (Source Unavailable)
10. ASP.default_aspx.ProcessRequest (Source Unavailable)
11. System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute (Source Unavailable)
12. System.Web.HttpApplication.ExecuteStep (Source Unavailable)
13. System.Web.HttpApplication.ApplicationStepManager.ResumeSteps (Source Unavailable)
14. System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest (Source Unavailable)
15. System.Web.HttpRuntime.ProcessRequestInternal (Source Unavailable)
16. System.Web.HttpRuntime.ProcessRequestNoDemand (Source Unavailable)
17. System.Web.Hosting.ISAPIRuntime.ProcessRequest (Source Unavailable)
The key pieces are the Thread ID and the Date/Time. Look for instances where the same thread ID is in the same call for more than a couple of intervals. In the above stack we can see that it is currently executing the Default.aspx Page_Load routine. If this stack is identical at our configured 5 second intervals, then this would indicate that something in the Default.aspx page’s Page_load routine is taking greater than 5-10 seconds. Therefore, that routine should be investigated.
Depending on the application, the call stacks may be different. The stacks may indicate a connectivity problem to a backend database, call to a web service, or something else. Either way the Managed Stack explorer can be used to quickly collect data that may be helpful before using more invasive tools. And the information generated can help developers of the application understand what the application is doing when it is performing slowly.
If the output does not show any activity on any of the threads, then another form of troubleshooting might be needed. Some causes of the threads being empty could be:
1) The request finished before stack logging started
2) The request is being handled by an Asynchronous handler, and it hasn’t notified ASP.NET that the request has finished.
3) The request has not been delivered to ASP.NET yet and is still running on a native thread.
Conclusions
The Managed Stack Explorer is a tool that can be used to view what .NET call stacks are doing at runtime. It does this by attaching to the process and taking a snapshot of the thread and displays it in the UI or logs it to a file. The managed stack can be used to determine what an ASP.NET request is doing at the time of the snapshot, and by capturing snapshots over a period of time, where the ASP.NET Request might be running slowly, it can be used to help identify what the bottleneck may be.
Lastly, this tool also has source code available for anyone that might want to extend its features. Please see the following site for information on how to do that.
Comments
Anonymous
May 06, 2009
PingBack from http://bogdanbrinzarea.wordpress.com/2009/05/07/summary/Anonymous
May 08, 2009
Bret wrote a post about Managed Stack Explorer , a really nice tool that was developed in 2006 but sinceAnonymous
February 17, 2011
You will need to recompile it to get it working with .NET 2.0, and it doesn't work with .NET 4.0 because the debug interfaces have changed.