注：以下步驟適用於ASP.NET 2.0 32bit應用程序
問題描述
超時問題發生時應用程序事件日志會出現以下警告。
通常這種問題發生的原因是由於請求的執行時間超過了服務器端配置的超時時間。在配置文件中可以通過httpRuntime/executionTimeout屬性設置此最大超時時間(.Net 2.0中默認為110 秒)。
Event Type: Warning Event Source: ASP.NET 2.0.50727.0 Event Category: Web Event Event ID: 1309 Event code: 3001 Event message: The request has been aborted. Event sequence: 2 Event occurrence: 1 Event detail code: 0 ... Exception information: Exception type: HttpException Exception message: Request timed out.
問題重現
創建一個命名為sleep.aspx的ASPX頁面。
<%@ Page Language="C#" %> <%@ import Namespace="System.Diagnostics" %> <script runat="server"> protected void Page_Load(object sender, EventArgs e) { DateTime time = DateTime.Now; Response.Write(String.Format("Time: {0}:{1}:{2}", time.Hour, time.Minute, time.Second) + "\tCurrent process: " +
Process.GetCurrentProcess().Id.ToString()); Response.Write("<BR>"); Response.Write(String.Format("This application is running in {0}", System.Environment.Version.ToString())); System.Threading.Thread.Sleep(20000); } </script> <html> <head> <title>ASP.NET Simple Page</title> </head> <body bgcolor="#FFFFFF"> <p><asp:label id="Message" runat="server" /></p> </body> </html>
創建web.config，並把它放在sleep.aspx相同的文件夾。將最大超時時間設置為5秒。
<?xml version="1.0" encoding="UTF-8"?> <configuration> <system.web> <httpRuntime executionTimeout="5"/> </system.web> </configuration>
使用瀏覽器訪問sleep.aspx，過一會就是收到頁面報錯"[HttpException (0x80004005): Request timed out.]"。警告也將紀錄在應用程序事件日志中。
注：
你可能會注意到，錯誤消息並非在5秒鍾后馬上出現。因為內部 ASP.NET 使用一個計時器(System.Threading.Timer)來調用請求取消該線程執行。計時器觸每15秒發一次。因此在現實中請求可能在5秒到20秒之間的任何時候超時。
詳細信息可以參考http://blogs.msdn.com/b/pedram/archive/2007/10/02/how-the-execution-timeout-is-managed-in-asp-net.aspx
數據收集
對於該問題的數據收集一個典型的"錯誤"是配置調試器來監視HttpException。實際上問題發生的時刻拋出的ThreadAbortException而非HttpException，所以嘗試捕獲到HttpException已經錯過了問題發生的時刻。
另外並非所有的ThreadAbortException都於此相關，我們可以通過以下方式來在這種ThreadAbortException觸發點上收集數據。
- 將以下的文本保存為c:\aspnet_timeout.cfg
<ADPlus Version='2'> <!-- Configuring ADPlus to log all first chance exceptions --> <!-- Will still create full dump for any type of second chance exceptions --> <KeyWords> <keyword Name="loadbysos"> .loadby sos mscorwks </keyword> <keyword Name="GetJIT"> !name2ee System.web.dll System.Web.RequestTimeoutManager.CancelTimedOutRequests </keyword> <keyword Name="JITAddress"> .foreach /pS 0n12 ( record {!name2ee System.web.dll System.Web.RequestTimeoutManager.CancelTimedOutRequests}) { r $t1= ${record}; bp $t1+0x172 ".dump /ma /u ${AdpDumpDirEsc}\\Full Request timed out ${AdpProcName}_.dmp;g"; .printf"*breakpoint list*\n"; bl} </keyword> </KeyWords> <Settings> <Option> NoDumpOnFirst </Option> <RunMode> CRASH </RunMode> </Settings> <PreCommands> <DebugActions> loadbysos; GetJIT; JITAddress </DebugActions> </PreCommands> </ADPlus>
- 通過管理員權限打開命令提示符，轉到windbg的安裝目錄(%programfiles%\Debugging Tools for Windows (x86))
- 運行以下命令來獲取應用程序池的進程號，
- %windir%\system32\inetsrv\appcmd list wp
- 然后運行下面的命令監控進程異常，如有問題發生在output folder中會生成相應的dmp文件，
- adplus.exe -c c:\aspnet_timeout.cfg -o <output folder> -p <pid>
數據分析
使用windbg打開dmp文件。然后加載sos。
0:025> .loadby sos mscorwks
轉儲當前線程的堆棧中的所有對象。你會發現計數對象：
0:025> !dso OS Thread Id: 0x444 (25) ESP/REG Object Name eax 05baf5b0 System.Threading.Thread ebx 05baf5b0 System.Threading.Thread ecx 01c4f300 System.Web.RequestTimeoutManager+RequestTimeoutEntry esi 01c4f300 System.Web.RequestTimeoutManager+RequestTimeoutEntry 0f1ff03c 05b33ad4 System.Web.Util.DoubleLinkList 0f1ff040 01c4b508 System.Collections.ArrayList 0f1ff044 05b3397c System.Web.RequestTimeoutManager 0f1ff064 01c4aa94 System.Threading.ContextCallback 0f1ff068 05b3397c System.Web.RequestTimeoutManager 0f1ff088 05b33b30 System.Threading._TimerCallback 0f1ff094 01c4b4e4 System.Threading.ExecutionContext 0f1ff0a0 01c4b4e4 System.Threading.ExecutionContext 0f1ff0a4 05b33b30 System.Threading._TimerCallback 0f1ff0b0 05b33b30 System.Threading._TimerCallback 0f1ff1c0 01c4b090 System.Collections.Hashtable+HashtableEnumerator 0f1ff25c 05b33b30 System.Threading._TimerCallback 0f1ff260 05b33b30 System.Threading._TimerCallback
轉儲計數對象的信息，查找DONT_USE_InternalThread字段：
0:025> !do 05baf5b0 Name: System.Threading.Thread MethodTable: 0e3c10f8 EEClass: 0e17d994 Size: 56(0x38) bytes (C:\Windows\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll) Fields: MT Field Offset Type VT Attr Value Name 0e3b1f08 400063f 4 ....Contexts.Context 0 instance 05b20528 m_Context 0e3bd818 4000640 8 ....ExecutionContext 0 instance 01c4d2c8 m_ExecutionContext 0e3c0b24 4000641 c System.String 0 instance 00000000 m_Name 0e3c0f88 4000642 10 System.Delegate 0 instance 00000000 m_Delegate 0e3ba220 4000643 14 System.Object[][] 0 instance 00000000 m_ThreadStaticsBuckets 0e3c2cc0 4000644 18 System.Int32[] 0 instance 00000000 m_ThreadStaticsBits 0e3c3720 4000645 1c ...ation.CultureInfo 0 instance 00000000 m_CurrentCulture 0e3c3720 4000646 20 ...ation.CultureInfo 0 instance 00000000 m_CurrentUICulture 0e3c0740 4000647 24 System.Object 0 instance 00000000 m_ThreadStartArg 0e3c33ec 4000648 28 System.IntPtr 1 instance 1915fa8 DONT_USE_InternalThread 0e3c2d70 4000649 2c System.Int32 1 instance 2 m_Priority 0e3c2d70 400064a 30 System.Int32 1 instance 5 m_ManagedThreadId 0e399740 400064b 16c ...LocalDataStoreMgr 0 shared static s_LocalDataStoreMgr
運行!threads命令來列出所有的線程，找到相應的線程(OS thread Id是dd4),
0:025> !threads ThreadCount: 7 UnstartedThread: 0 BackgroundThread: 7 PendingThread: 0 DeadThread: 0 Hosted Runtime: no PreEmptive GC Alloc Lock ID OSID ThreadOBJ State GC Context Domain Count APT Exception 8 1 1400 018ad710 8220 Enabled 05baea40:05baf074 018ac928 0 Ukn 19 2 132c 018b8658 b220 Enabled 00000000:00000000 018ac928 0 MTA (Finalizer) 22 3 16ec 018d7718 80a220 Enabled 00000000:00000000 018ac928 0 MTA (Threadpool Completion Port) 23 4 830 018d7ee8 1220 Enabled 00000000:00000000 018ac928 0 Ukn 24 5 dd4 01915fa8 380b220 Enabled 01c57b44:01c58fe8 018d8590 1 MTA (Threadpool Worker) 25 6 444 01923d00 180b220 Disabled 01c4b604:01c4d008 018d8590 0 MTA (Threadpool Worker) 14 7 180 01933348 880a220 Enabled 00000000:00000000 018ac928 0 MTA (Threadpool Completion Port)
切換到有問題的線程，並列出調用堆棧。
0:025> ~~[dd4]s eax=0000002d ebx=00000000 ecx=00004e20 edx=00000000 esi=0edced40 edi=00000000 eip=777f96f4 esp=0edcecfc ebp=0edced64 iopl=0 nv up ei pl nz na po nc cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000202 ntdll!KiFastSystemCallRet: 777f96f4 c3 ret 0:024> !clrstack OS Thread Id: 0xdd4 (24) ESP EIP 0edcee4c 777f96f4 [HelperMethodFrame: 0edcee4c] System.Threading.Thread.SleepInternal(Int32) 0edceea0 015806e1 ASP.sleep_aspx.Page_Load(System.Object, System.EventArgs) 0edceedc 6d59a7ff System.Web.Util.CalliHelper.EventArgFunctionCaller(IntPtr, System.Object, System.Object, System.EventArgs) 0edceeec 62562544 System.Web.Util.CalliEventHandlerDelegateProxy.Callback(System.Object, System.EventArgs) 0edcef00 6255ba44 System.Web.UI.Control.OnLoad(System.EventArgs) 0edcef14 6255ba83 System.Web.UI.Control.LoadRecursive() 0edcef2c 62557b34 System.Web.UI.Page.ProcessRequestMain(Boolean, Boolean) 0edcf084 62557764 System.Web.UI.Page.ProcessRequest(Boolean, Boolean) 0edcf0bc 62557691 System.Web.UI.Page.ProcessRequest() 0edcf0f4 62557626 System.Web.UI.Page.ProcessRequestWithNoAssert(System.Web.HttpContext) 0edcf100 62557602 System.Web.UI.Page.ProcessRequest(System.Web.HttpContext) 0edcf114 01580455 ASP.sleep_aspx.ProcessRequest(System.Web.HttpContext) 0edcf118 6255dad6 System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() 0edcf14c 6253132c System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef) 0edcf18c 62b2583f System.Web.HttpApplication+PipelineStepManager.ResumeSteps(System.Exception) 0edcf190 62b1b96c [InlinedCallFrame: 0edcf190] 0edcf230 62b06071 System.Web.HttpRuntime.ProcessRequestNotificationPrivate(System.Web.Hosting.IIS7WorkerRequest, System.Web.HttpContext) 0edcf2a0 62bdb5e6 System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32) 0edcf2a4 62bdb7d7 [InlinedCallFrame: 0edcf2a4] 0edcf7f8 005522b4 [NDirectMethodFrameStandalone: 0edcf7f8] System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr, System.Web.RequestNotificationStatus ByRef) 0edcf808 62bdb67d System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32) 0edcf88c 62bdb7d7 System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32) 0edcf98c 005522b4 [ContextTransitionFrame: 0edcf98c]
希望該示例對你有所幫助。
xinjin