问题简介
在ASP.NET程序中我们经常遇到错误消息为"Request
Timed Out"的HttpException,浏览器中的出错信息如下图所示，
同时应用程序日志中也会出现一条警告消息如下
如何重现这种异常？
线程在处理逻辑的过程中是如何被打断而抛出超时异常？
如何调试这种异常？
这篇文章我们从CLR源代码级别来分析一下该问题发生的原因以及相应的调试方法。
重现问题
首先我们先尝试重现这个问题，在ASP.NET程序web.config中有一个executionTimeout的设置，默认值为110秒，也就是说一个请求的执行时间超过110秒就会timeout从而产生HttpException
"Request Timed Out"。这个设置可以通过IIS Configuration Editor或者web.config进行更改。
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appSettings />
<connectionStrings />
<system.web>
<compilation>
</compilation>
<authentication mode="Windows" />
<httpRuntime executionTimeout="10" />
</system.web>
</configuration>
为了快速重现这个问题我们将executionTimeout默认值改为10秒。然后建立一个让请求超时的asp.net页面如下。
<%@ Page Language="C#" AutoEventWireup="true" Inherits="System.Web.UI.Page" %>
<script runat="server">
protected void Page_Load(object sender, EventArgs e)
{
System.Threading.Thread.Sleep(120000);
}
</script>
<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
<html xmlns="http://www.w3.org/1999/xhtml">
<head runat="server">
<title></title>
</head>
<body>
<form id="form1" runat="server">
<div>
</div>
</form>
</body>
</html>
将页面部署在IIS上，然后请求页面，等待10秒到25秒左右问题重现。
产生原理
这里有一个值得注意的地方，为什么我们页面逻辑在执行Sleep却抛出了HttpException，执行线程被谁打断了，是怎么打断的？
研究这个问题我们首先要用windbg来察看一下这个异常发生的调用栈信息。
通过windbg attach到w3wp进程，然后输入命令'sxe
clr'捕获clrfirst chance exception
CLR exception - code e0434f4d (first chance)
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
KERNELBASE!RaiseException+0x68:
000007fb`bbb789cc 488b8c24c0000000 mov rcx,qword ptr [rsp+0C0h] ss:000000da`6bf0da20=38a1bff3b7640000
0:023> KL
Child-SP RetAddr Call Site
000000da`6bf0d960 000007fb`a0da98ef KERNELBASE!RaiseException+0x68
000000da`6bf0da40 000007fb`a0d03e07 mscorwks!RaiseTheExceptionInternalOnly+0x2ff
000000da`6bf0db30 000007fb`a0cc58cf mscorwks!Thread::HandleThreadAbort+0x19b
000000da`6bf0dbd0 000007fb`a0cbe815 mscorwks!Thread::HandleThreadInterrupt+0x7b
000000da`6bf0dc30 000007fb`a1280769 mscorwks!Thread::UserSleep+0x89
000000da`6bf0dc90 000007fb`415d09ee mscorwks!ThreadNative::Sleep+0xf9
000000da`6bf0de40 000007fb`41630f39 App_Web_kng1ridv!ASP.sleep120_aspx.Page_Load(System.Object, System.EventArgs)+0xe
…
000000da`6bf0fae0 000007fb`beb53501 KERNEL32!BaseThreadInitThunk+0x1a
000000da`6bf0fb10 00000000`00000000 ntdll!RtlUserThreadStart+0x21栈上面的first chanceexception为ThreadAbortException。
0:023> !dso
OS Thread Id: 0x12e0 (23)
RSP/REG Object Name
000000da6bf0d968 000000da0aac3ea0 System.Threading.ThreadAbortException
000000da6bf0da30 000000da0aac3ea0 System.Threading.ThreadAbortException
000000da6bf0da48 000000da0aac3ea0 System.Threading.ThreadAbortException
000000da6bf0db30 000000da0aac3ea0 System.Threading.ThreadAbortException
000000da6bf0dc98 000000da0aa93c90 System.Web.HttpContext
000000da6bf0dca0 000000da0aac3498 System.ComponentModel.EventHandlerList
000000da6bf0dd70 000000da0aac3498 System.ComponentModel.EventHandlerList
000000da6bf0dd90 000000da0aa93c90 System.Web.HttpContext
从这个调用栈上我们可以看出来这个异常来自于Thread::UserSleep -> Thread::HandleThreadInterrupt ->Thread::HandleThreadAbort
由于这个调用栈是CLR非托管代码，我们需要一份.NETFrameworkCLR的源代码作为参考，可以到微软下载一份Share
Source CLI。找到\sscli20_20060311\sscli20\clr\src\vm\threads.cpp这个源文件，这个类封装的一系列CLR线程相关的属性和方法。
因为我们调用了Sleep方法，首先看一下Sleep函数的实现。原来线程调用Sleep方法之后进入系统内核，内核将其置于等待状态，一旦CLRSleepEx返回WAIT_IO_COMPLETION并且通过m_State
& TS_Interrupted两个标志位来判断是interrupt的话，系统将开始执行HandleThreadInterrupt方法，进而在HandleThreadInterrupt方法中抛出ThreadAbortException。
// Implementation of Thread.Sleep().
void Thread::UserSleep(INT32 time)
{
CONTRACTL {
THROWS;
GC_TRIGGERS;
}
CONTRACTL_END;
INCONTRACT(_ASSERTE(!GetThread()->GCNoTrigger()));
DWORD res;
GCX_PREEMP();
// A word about ordering for Interrupt. If someone tries to interrupt a thread
// that's in the interruptible state, we queue an APC. But if they try to interrupt
// a thread that's not in the interruptible state, we just record that fact. So
// we have to set TS_Interruptible before we test to see whether someone wants to
// interrupt us or else we have a race condition that causes us to skip the APC.
FastInterlockOr((ULONG *) &m_State, TS_Interruptible);
// If someone has interrupted us, we should not enter the wait.
if (IsUserInterrupted())
{
HandleThreadInterrupt(FALSE);
}
ThreadStateHolder tsh(TRUE, TS_Interruptible | TS_Interrupted);
FastInterlockAnd((ULONG *) &m_State, ~TS_Interrupted);
retry:
res = ClrSleepEx (time, TRUE);
if (res == WAIT_IO_COMPLETION)
{
// We could be woken by some spurious APC or an EE APC queued to
// interrupt us. In the latter case the TS_Interrupted bit will be set
// in the thread state bits. Otherwise we just go back to sleep again.
if ((m_State & TS_Interrupted))
{
HandleThreadInterrupt(FALSE);
}
// Don't bother with accurate accounting here. Just ensure we make progress.
// Note that this is not us doing the APC.
if (time == 0)
{
res = WAIT_TIMEOUT;
}
else
{
if (time != (INT32) INFINITE)
{
time--;
}
goto retry;
}
}
_ASSERTE(res == WAIT_TIMEOUT || res == WAIT_OBJECT_0);
}
接下来一个问题是到底是什么使得ClrSleepEx方法返回了呢？根据注释我们可以看到APC很可能是打断等待线程的原因。接下来我们继续通过debug验证一下。根据msdn用户模式可以调用kernel32!QueueUserAPC方法发送一个APC到指定线程。我们在这个方法上设置一个断点然后重现这个问题。结果抓到了这个调用栈。
0:022> kL
Child-SP RetAddr Call Site
000000da`6bbfe808 000007fb`a10ce75b KERNEL32!QueueUserAPCStub
000000da`6bbfe810 000007fb`a0e37e88 mscorwks!Thread::Alert+0xdb
000000da`6bbfe880 000007fb`a103d0d4 mscorwks!Thread::UserInterrupt+0x30
000000da`6bbfe8b0 000007fb`a11f5699 mscorwks!Thread::UserAbort+0x3984d0
000000da`6bbfe9d0 000007fb`997c4519 mscorwks!ThreadNative::Abort+0x169
000000da`6bbfebd0 000007fb`988f835f mscorlib_ni!System.Threading.Thread.Abort(System.Object)+0x39
000000da`6bbfec20 000007fb`97e94547 System_Web_ni!System.Web.RequestTimeoutManager+RequestTimeoutEntry.TimeoutIfNeeded(System.DateTime)+0xa63d4f
000000da`6bbfec60 000007fb`99772bdb System_Web_ni!System.Web.RequestTimeoutManager.CancelTimedOutRequests(System.DateTime)+0x167
…
000000da`6bbff8a0 00000000`00000000 ntdll!RtlUserThreadStart+0x21
看一下栈上的信息，究竟是哪个线程正在被abort。
0:022> !dso
OS Thread Id: 0x14e4 (22)
RSP/REG Object Name
000000da6bbfe9c0 000000da0aa84400 System.Threading.Thread
000000da6bbfea28 000000d9cab1efe8 System.Web.HttpApplication+CancelModuleException
000000da6bbfea38 000000da0aa84400 System.Threading.Thread
000000da6bbfea88 000000d9caa4c810 System.String
0:022> !do 000000da0aa84400
Name: System.Threading.Thread
MethodTable: 000007fb998b86c0
EEClass: 000007fb994bea18
Size: 104(0x68) bytes
(C:\windows\assembly\GAC_64\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)
Fields:
MT Field Offset Type VT Attr Value Name
000007fb998f01b0 4000690 8 ....Contexts.Context 0 instance 000000d9caa285c0 m_Context
000007fb998b2bd0 4000691 10 ....ExecutionContext 0 instance 000000da0aace570 m_ExecutionContext
000007fb998b7c20 4000692 18 System.String 0 instance 0000000000000000 m_Name
000007fb998b8438 4000693 20 System.Delegate 0 instance 0000000000000000 m_Delegate
000007fb998aefe0 4000694 28 System.Object[][] 0 instance 0000000000000000 m_ThreadStaticsBuckets
000007fb998bed40 4000695 30 System.Int32[] 0 instance 0000000000000000 m_ThreadStaticsBits
000007fb998c05a0 4000696 38 ...ation.CultureInfo 0 instance 0000000000000000 m_CurrentCulture
000007fb998c05a0 4000697 40 ...ation.CultureInfo 0 instance 0000000000000000 m_CurrentUICulture
000007fb998b7510 4000698 48 System.Object 0 instance 0000000000000000 m_ThreadStartArg
000007fb998ba628 4000699 50 System.IntPtr 1 instance
da6b789d60 DONT_USE_InternalThread
000007fb998bee90 400069a 58 System.Int32 1 instance 2 m_Priority
000007fb998bee90 400069b 5c System.Int32 1 instance 7 m_ManagedThreadId
000007fb998ac8d8 400069c 2d8 ...LocalDataStoreMgr 0 shared static s_LocalDataStoreMgr
>> Domain:Value 000000d9c90512d0:0000000000000000 000000d9ca176610:0000000000000000 <<
000007fb998b7510 400069d 2e0 System.Object 0 shared static s_SyncObject
>> Domain:Value 000000d9c90512d0:000000d9caa23bf0 000000d9ca176610:000000da0aa2d410 <<
0:022> !threads
ThreadCount: 10
UnstartedThread: 0
BackgroundThread: 9
PendingThread: 0
DeadThread: 1
Hosted Runtime: no
PreEmptive Lock
ID OSID ThreadOBJ State GC GC Alloc Context Domain Count APT Exception
3 1 150c 000000d9ca125a90 8220 Enabled 0000000000000000:0000000000000000 000000d9c90512d0 0 Ukn
19 2 23c8 000000d9ca12f510 b220 Enabled 000000da0aa8a238:000000da0aa8c200 000000d9c90512d0 0 MTA (Finalizer)
20 3 1a98 000000d9ca174ab0 80a220 Enabled 0000000000000000:0000000000000000 000000d9c90512d0 0 MTA (Threadpool Completion Port)
21 4 23f4 000000d9ca175b60 1220 Enabled 0000000000000000:0000000000000000 000000d9c90512d0 0 Ukn
22 5 14e4 000000da6b779c50 180b220 Disabled 000000d9cab1f000:000000d9cab20b18 000000d9ca176610 1 MTA (Threadpool Worker)
XXXX 6 0 000000da6b77d9d0 10820 Enabled 0000000000000000:0000000000000000 000000d9c90512d0 0 Ukn
23 7 12e0 000000da6b789d60
3a0b221 Enabled 000000da0aafd860:000000da0aafe2a8 000000d9ca176610 1 MTA (Threadpool Worker)
15 8 2180 000000da6b78a330 880a220 Enabled 0000000000000000:0000000000000000 000000d9c90512d0 0 MTA (Threadpool Completion Port)
24 9 13a4 000000da6b7903a0 220 Enabled 000000d9caae2e48:000000d9caae4aa8 000000d9c90512d0 0 Ukn
25 a e5c 000000d9ca107180 220 Enabled 000000d9cab20c68:000000d9cab22b18 000000d9c90512d0 0 Ukn
结果我们看到是23号线程是被abort的目标。23号线程正在做什么？查看23号线程调用栈正好是我们的Sleep方法线程。
0:023> kL
Child-SP RetAddr Call Site
000000da`6bf0db08 000007fb`bbb611f2 ntdll!NtDelayExecution+0xa
000000da`6bf0db10 000007fb`a10c369d KERNELBASE!SleepEx+0xaa
000000da`6bf0dbb0 000007fb`a0cbe7fd mscorwks!EESleepEx+0x2d
000000da`6bf0dc30 000007fb`a1280769 mscorwks!Thread::UserSleep+0x71
000000da`6bf0dc90 000007fb`415d09ee mscorwks!ThreadNative::Sleep+0xf9
000000da`6bf0de40 000007fb`41630f39
App_Web_kng1ridv!ASP.sleep120_aspx.Page_Load(System.Object, System.EventArgs)+0xe
…
000000da`6bf0f750 000007fb`a0d1970a mscorwks!UnManagedPerAppDomainTPCount::DispatchWorkItem+0x157
000000da`6bf0f7f0 000007fb`a0dcf3a4 mscorwks!ThreadpoolMgr::WorkerThreadStart+0x1ba
000000da`6bf0f890 000007fb`bc53167e mscorwks!Thread::intermediateThreadProc+0x78
000000da`6bf0fae0 000007fb`beb53501 KERNEL32!BaseThreadInitThunk+0x1a
000000da`6bf0fb10 00000000`00000000 ntdll!RtlUserThreadStart+0x21
到此我们可以证明我们的想法了，原来ASP.NET启动了一个RequestTimeoutManager来负责查看超时线程，然后通过发送APC的方式打断超时线程使之抛出ThreadAbortException结束等待，最后ThreadAbortException被包装成HttpException抛出，记录在日志以及显示在客户端。
调试方法
现实过程中Timeout不一定是出在线程Sleep上，也不是所有的ThreadAbortException都代表Timeout的问题发生。我们还是要总结一下类似问题的调试方法。
第一，观察timeout的时间，是否是100秒左右，与配置中的数值是否相符(注意这里比一定是一秒不差，因为查看RequestTimeoutManager逻辑可以发现他是每隔15秒查看一下超时线程，所有存在15秒左右的误差。
第二，如果不是超时时间设置过小的原因，那就要通过抓dump的方式来查看具体的超时请求超时在什么操作上。因为我们最终得到的ThreadAbortException中没有调用栈信息。
如何抓到对的dump是个值得研究的问题，我们可以把断点设在以下调用栈上的某个点上，注意断点越接近栈顶，这个方法可能被调用的次数就越多，抓到没有用的dump的可能性越大。
0:022> kL
Child-SP RetAddr Call Site
000000da`6bbfe808 000007fb`a10ce75b KERNEL32!QueueUserAPCStub
000000da`6bbfe810 000007fb`a0e37e88 mscorwks!Thread::Alert+0xdb
000000da`6bbfe880 000007fb`a103d0d4 mscorwks!Thread::UserInterrupt+0x30
000000da`6bbfe8b0 000007fb`a11f5699 mscorwks!Thread::UserAbort+0x3984d0
000000da`6bbfe9d0 000007fb`997c4519 mscorwks!ThreadNative::Abort+0x169
000000da`6bbfebd0 000007fb`988f835f mscorlib_ni!System.Threading.Thread.Abort(System.Object)+0x39
000000da`6bbfec20 000007fb`97e94547 System_Web_ni!System.Web.RequestTimeoutManager+RequestTimeoutEntry.TimeoutIfNeeded(System.DateTime)+0xa63d4f
000000da`6bbfec60 000007fb`99772bdb System_Web_ni!System.Web.RequestTimeoutManager.CancelTimedOutRequests(System.DateTime)+0x167
…
000000da`6bbff8a0 00000000`00000000 ntdll!RtlUserThreadStart+0x21
通过ILSpy查看CancelTimedOutRequests和TimeoutIfNeeded源代码，可以看到进入这个方法并不一定代表有线程会被abort，所以我们要从下面一层抓。最终结论是如果我们想要研究Timeout的ThreadAbortException，我们可以在mscorlib_ni!System.Threading.Thread.Abort上面设置断点抓dump，然后查看堆栈上面的线程，最终找到正在被abort的线程以及相应执行的调用栈信息。
// System.Web.RequestTimeoutManager
privatevoidCancelTimedOutRequests(DateTime now)
{
if(Interlocked.CompareExchange(refthis._inProgressLock,1,0)!=0)
{
return;
}
ArrayList arrayList =newArrayList(this._requestCount);
for(inti =0;i<this._lists.Length;i++)
{
DoubleLinkList obj;
Monitor.Enter(obj =this._lists[i]);
try
{
DoubleLinkListEnumerator enumerator =this._lists[i].GetEnumerator();
while(enumerator.MoveNext())
{
arrayList.Add(enumerator.GetDoubleLink());
}
}
finally
{
Monitor.Exit(obj);
}
}
intcount = arrayList.Count;
for(intj =0;j<count;j++)
{
((RequestTimeoutManager.RequestTimeoutEntry)arrayList[j]).TimeoutIfNeeded(now);
}
Interlocked.Exchange(refthis._inProgressLock,0);
}
// System.Web.RequestTimeoutManager.RequestTimeoutEntry
internalvoidTimeoutIfNeeded(DateTime now)
{
Thread thread =this._context.MustTimeout(now);
if(thread!=null)
{
this.RemoveFromList();
thread.Abort(newHttpApplication.CancelModuleException(true));
}
}
分享到：
相关推荐
主要介绍了ASP.NET从客户端中检测到有潜在危险的request.form值的3种解决方法,这是ASP.NET开发中一个比较常见的经典的问题,需要的朋友可以参考下
/// 初始化 System.Web.HttpException 类的新实例并创建一个空 System.Web.HttpException 对象。 /// public HttpException() { } /// /// 使用所提供的错误消息初始化 System.Web.HttpException ...
Johnny换上Win7已经有几个月的... 异常详细信息: System.Web.HttpException: 请求在此上下文中不可用 源错误: 代码如下: 行 28: protected void Application_Start(Object sender, EventArgs e) 行 29: { 行 30: Appli
win7的IIS中部署Web应用时经常会遇到“应用程序中的服务器错误”。这是我找到的一个解决方法，挺管用的，大家可以试试
import org.apache.http.HttpException; import org.apache.http.HttpRequest; import org.apache.http.HttpRequestInterceptor; import org.apache.http.HttpResponse; import org.apache.http.HttpStatus; ...
System.out.println("发生网络异常!"); e.printStackTrace(); } finally { /* 6 .释放连接 */ getMethod.releaseConnection(); } return response; } /** * post请求 * @param url * @param json * @...
ctw-middleware-http-exception $ composer require ctw/ctw-middleware-http-exception
// 创建GET方法的实例 GetMethod getMethod = new GetMethod(strURL); // 使用系统提供的默认的恢复策略 getMethod.getParams().setParameter(HttpMethodParams.RETRY_HANDLER, new ...
public synchronized void setHttpConnectionFactoryTimeout(long timeout) { } public synchronized void setConnectionTimeout(int newTimeoutInMilliseconds) { } public int executeMethod(HttpMethod method...
” 错误发生的原因是当ASP.NET检测到Web站点配置为使用ASP.NET 4.0，本地ASP.NET 4.0 的组件会传递一个不能扩展的 URL到ASP.NET的管理程序作进一步处理。但是，如果一个低于ASP.NET 4.0 的网站配置为使用ASP.NET ...
于是开始检测，查找原因。 1. 出错提示 “/”应用程序中的服务器错误。 验证视图状态 MAC 失败。如果此应用程序由网络场或群集承载，请确保 <machineKey> 配置指定了相同的 validationKey 和验证算法。不能在群...
异常详细信息: System.Web.HttpException: 无法向会话状态服务器发出会话状态请求。请确保已启动 ASP.NET State service，并且客户端和服务器端口是相同的。如果服务器位于远程计算机上，请检查 HKEY_LOCAL_MACHINE\...
android.httpAsnc安卓网络请求工具
在我们的项目中遇到”超过了最大请求长度”如下图所示,是因为IIS默认请求长度4M,当请求长度大于这个值的时候报错,下面是解决方案. 解决方案:修改web.config文件 1、注意在mvc中有两个web.config文件，如下图，一个...
WepApi 异常管道添加ExceptionFilterAttribute的管道，以便我们可以在发生异常时执行多个操作。 添加一个自定义 ExceptionFilter，可以将 WebApi 操作中抛出的异常转换为正确的 http 状态代码和原因短语。 这使我们...
网络爬虫System.out.println("response="+getMethod.getResponseBodyAsString()); } catch (HttpException e) { // TODO Auto-generated catch block e.printStackTrace(); } catch (IOException e) { // TODO ...
主要介绍了IIS7.5 检测到在集成的托管管道模式下不适用的 ASP.NET设置 ,需要的朋友可以参考下
HttpException httpEx = (HttpException) ex; int responseCode = httpEx.getCode(); String responseMsg = httpEx.getMessage(); String errorResult = httpEx.getResult(); // ... } else { // 其他错误 //...
代码如下:void Application_Error(object sender, EventArgs e... HttpException ev = ex as HttpException; if(ev!= null) { if(ev.GetHttpCode() == 404) { ctx.ClearError(); Response.Redirect(“~/nofound.aspx”,