DebugDiag 消息线程似乎没有在等待远程服务器响应
DebugDiag Message Thread Does Not Appear to be Waiting on the Remote Server to Respond
我们有一个 C# Windows 服务,该服务 运行 是一个拆分为多个任务的进程。大多数任务使用 WCF 联系 Web 服务以对数据库执行工作。该服务的任务在多个线程中 运行。
一位客户向我们提出了支持案例,称 Windows 服务偶尔无法响应,需要重新启动。我从 Windows 服务获取了内存转储。我运行DebugDiag 2.0分析转储文件。
DebugDiag 报告的摘要中有一个有趣的条目:
The following threads in WindowsService.DMP are attempting to make an HttpWebRequest, however they do not appear to be waiting on the remote server to respond (eg. not 'on the wire'). One or more of these requests are using at least half of its maximum number of available connections.
( 17 18 27 31 32 33 42 ) 12.07% of threads blocked (7 threads)
If many threads are in this state, it is often an indication that a throttling limit (i.e. the 'maxconnection' setting) has been exhausted. Click on any thread in the list to the left to review the throttling details for the WebRequest on which it is waiting.
If necessary, you can increase the number of connections available by either modifying the 'maxconnection' parameter in the application configuration file (see <connectionManagement>
Element), or by modifying the appropriate ConnectionLimit property programmatically (see Managing Connections).
我跳到线程 17 看到了这个:
Thread 17 - System ID 4612
Entry point mscorwks!Thread::intermediateThreadProc
Create time 9/10/2015 10:13:14 AM
Time spent in user mode 0 Days 00:00:00.000
Time spent in kernel mode 0 Days 00:00:00.000
This thread is attempting to make an HttpWebRequest, however they do not appear to be waiting on the remote server to respond (eg. not
'on the wire'). One or more of these requests are using at least half
of its maximum number of available connections.
Warning, at least half of the availabe connections are being used
HttpRequest URI:http://WebServer/MyWebSite/SubDir/MyService.svc
ServicePoint - ConnectionLimit:48 CurrentConnections:44
The HttpWebRequest object is a loopback address but the connection limit still applies to this webrequest object because the
connection limit is defined (either through autoconfig set to true in
the processModel section or by adding a * entry inside
connectionManagement section
.NET 调用堆栈如下:
Function
[[HelperMethodFrame_1OBJ] (System.Threading.WaitHandle.WaitOneNative)] System.Threading.WaitHandle.WaitOneNative(Microsoft.Win32.SafeHandles.SafeWaitHandle, UInt32, Boolean, Boolean)
mscorlib_ni!System.Threading.WaitHandle.WaitOne(Int64, Boolean)+2f
mscorlib_ni!System.Threading.WaitHandle.WaitOne(Int32, Boolean)+25
System_ni!System.Net.LazyAsyncResult.WaitForCompletion(Boolean)+d3
System_ni!System.Net.Connection.SubmitRequest(System.Net.HttpWebRequest)+2b7
System_ni!System.Net.ServicePoint.SubmitRequest(System.Net.HttpWebRequest, System.String)+7c
System_ni!System.Net.HttpWebRequest.SubmitRequest(System.Net.ServicePoint)+f9
System_ni!System.Net.HttpWebRequest.GetRequestStream(System.Net.TransportContext ByRef)+1d3
System_ni!System.Net.HttpWebRequest.GetRequestStream()+e
System_ServiceModel_ni!System.ServiceModel.Channels.HttpOutput+WebRequestHttpOutput.GetOutputStream()+45
System_ServiceModel_ni!System.ServiceModel.Channels.HttpOutput.Send(System.TimeSpan)+f6
System_ServiceModel_ni!System.ServiceModel.Channels.HttpChannelFactory+HttpRequestChannel+HttpChannelRequest.SendRequest(System.ServiceModel.Channels.Message, System.TimeSpan)+121
System_ServiceModel_ni!System.ServiceModel.Channels.RequestChannel.Request(System.ServiceModel.Channels.Message, System.TimeSpan)+cb
System_ServiceModel_ni!System.ServiceModel.Dispatcher.RequestChannelBinder.Request(System.ServiceModel.Channels.Message, System.TimeSpan)+17
System_ServiceModel_ni!System.ServiceModel.Channels.ServiceChannel.Call(System.String, Boolean, System.ServiceModel.Dispatcher.ProxyOperationRuntime, System.Object[], System.Object[], System.TimeSpan)+1a2
System_ServiceModel_ni!System.ServiceModel.Channels.ServiceChannel.Call(System.String, Boolean, System.ServiceModel.Dispatcher.ProxyOperationRuntime, System.Object[], System.Object[])+33
System_ServiceModel_ni!System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(System.Runtime.Remoting.Messaging.IMethodCallMessage, System.ServiceModel.Dispatcher.ProxyOperationRuntime)+43
System_ServiceModel_ni!System.ServiceModel.Channels.ServiceChannelProxy.Invoke(System.Runtime.Remoting.Messaging.IMessage)+65
mscorlib_ni!System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(System.Runtime.Remoting.Proxies.MessageData ByRef, Int32)+bd
[[TPMethodFrame] (IMyWebService.GetDataSet)]
IMyWebService.GetDataSet(System.Guid, System.String, System.Data.DataSet)
<service code snipped>
mscorlib_ni!System.Threading.ThreadHelper.ThreadStart_Context(System.Object)+66
mscorlib_ni!System.Threading.ExecutionContext.runTryCode(System.Object)+51
[[HelperMethodFrame_PROTECTOBJ] (System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup)]
System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup(TryCode, CleanupCode, System.Object)
mscorlib_ni!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+67
mscorlib_ni!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+45
mscorlib_ni!System.Threading.ThreadHelper.ThreadStart()+44
[[GCFrame]]
我看到它提出的建议并开始研究它们。我的问题是:
为什么 DebugDiag 说线程不是似乎在等待服务器响应?
查看 .NET Reference Source,请求似乎已成功提交,服务似乎正在等待响应。
更新
进入正常调用后,我确实看到调用堆栈在 ws2_2 处等待,如下面 Puneet Gupta 所建议的:
ntdll.dll!_NtWaitForSingleObject@12()
mswsock.dll!_SockWaitForSingleObject@16()
mswsock.dll!_WSPRecv@36()
***ws2_32.dll!_recv@16()***
System.ni.dll!6c084a13()
[Managed to Native Transition]
System.dll!System.Net.Sockets.Socket.Receive(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags, out System.Net.Sockets.SocketError errorCode)
System.dll!System.Net.Sockets.Socket.Receive(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags)
System.dll!System.Net.Sockets.NetworkStream.Read(byte[] buffer, int offset, int size)
System.dll!System.Net.PooledStream.Read(byte[] buffer, int offset, int size)
System.dll!System.Net.Connection.SyncRead(System.Net.HttpWebRequest request, bool userRetrievedStream, bool probeRead)
System.dll!System.Net.ConnectStream.ProcessWriteCallDone(System.Net.ConnectionReturnResult returnResult)
System.dll!System.Net.HttpWebRequest.WriteCallDone(System.Net.ConnectStream stream, System.Net.ConnectionReturnResult returnResult)
System.dll!System.Net.ConnectStream.CallDone(System.Net.ConnectionReturnResult returnResult)
System.dll!System.Net.ConnectStream.ResubmitWrite(System.Net.ConnectStream oldStream, bool suppressWrite)
System.dll!System.Net.HttpWebRequest.EndWriteHeaders_Part2()
System.dll!System.Net.HttpWebRequest.EndWriteHeaders(bool async)
System.dll!System.Net.HttpWebRequest.WriteHeadersCallback(System.Net.WebExceptionStatus errorStatus, System.Net.ConnectStream stream, bool async)
System.dll!System.Net.ConnectStream.WriteHeaders(bool async)
System.dll!System.Net.HttpWebRequest.EndSubmitRequest()
System.dll!System.Net.HttpWebRequest.CheckDeferredCallDone(System.Net.ConnectStream stream)
System.dll!System.Net.HttpWebRequest.GetResponse()
System.ServiceModel.dll!System.ServiceModel.Channels.HttpChannelFactory<System.ServiceModel.Channels.IRequestChannel>.HttpRequestChannel.HttpChannelRequest.WaitForReply(System.TimeSpan timeout)
System.ServiceModel.dll!System.ServiceModel.Channels.RequestChannel.Request(System.ServiceModel.Channels.Message message, System.TimeSpan timeout)
System.ServiceModel.dll!System.ServiceModel.Dispatcher.RequestChannelBinder.Request(System.ServiceModel.Channels.Message message, System.TimeSpan timeout) Unknown
System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannel.Call(string action, bool oneway, System.ServiceModel.Dispatcher.ProxyOperationRuntime operation, object[] ins, object[] outs, System.TimeSpan timeout)
System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(System.Runtime.Remoting.Messaging.IMethodCallMessage methodCall, System.ServiceModel.Dispatcher.ProxyOperationRuntime operation)
System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannelProxy.Invoke(System.Runtime.Remoting.Messaging.IMessage message)
mscorlib.dll!System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(ref System.Runtime.Remoting.Proxies.MessageData msgData, int type)
所以通常情况下,它将等待来自 Windows 套接字的响应。在这种情况下,线程可能正在等待连接变为可用于处理请求——如其他 DebugDiag 消息所示。
消息说它似乎没有在线等待的原因是因为线程上的最后一帧是 waithandle.waitone。
对于真正在线上等待的线程,我们应该看到 ws2_32(在本机堆栈中),它是 windows 套接字库或 system.net.sockets 中的一些函数托管堆栈。
您是否能够捕获多个转储?如果是,您是否看到线程状态在一次转储与第二次转储中发生了变化?
!dso (!DumpStackObjects) 是否显示当前线程中的任何连接对象?如果是这样,System.Net.Connection 对象中的 m_WaitList 值是什么,m_CurrentRequest 的值是什么?
由于您的调用堆栈未显示我们正在等待 ws2_32 (WinSock),这表明 HWR 仍在等待获取可用连接或套接字。
我们有一个 C# Windows 服务,该服务 运行 是一个拆分为多个任务的进程。大多数任务使用 WCF 联系 Web 服务以对数据库执行工作。该服务的任务在多个线程中 运行。
一位客户向我们提出了支持案例,称 Windows 服务偶尔无法响应,需要重新启动。我从 Windows 服务获取了内存转储。我运行DebugDiag 2.0分析转储文件。
DebugDiag 报告的摘要中有一个有趣的条目:
The following threads in WindowsService.DMP are attempting to make an HttpWebRequest, however they do not appear to be waiting on the remote server to respond (eg. not 'on the wire'). One or more of these requests are using at least half of its maximum number of available connections.
( 17 18 27 31 32 33 42 ) 12.07% of threads blocked (7 threads)
If many threads are in this state, it is often an indication that a throttling limit (i.e. the 'maxconnection' setting) has been exhausted. Click on any thread in the list to the left to review the throttling details for the WebRequest on which it is waiting.
If necessary, you can increase the number of connections available by either modifying the 'maxconnection' parameter in the application configuration file (see
<connectionManagement>
Element), or by modifying the appropriate ConnectionLimit property programmatically (see Managing Connections).
我跳到线程 17 看到了这个:
Thread 17 - System ID 4612
Entry point mscorwks!Thread::intermediateThreadProc Create time 9/10/2015 10:13:14 AM Time spent in user mode 0 Days 00:00:00.000 Time spent in kernel mode 0 Days 00:00:00.000
This thread is attempting to make an HttpWebRequest, however they do not appear to be waiting on the remote server to respond (eg. not 'on the wire'). One or more of these requests are using at least half of its maximum number of available connections.
Warning, at least half of the availabe connections are being used
HttpRequest URI:
http://WebServer/MyWebSite/SubDir/MyService.svc
ServicePoint - ConnectionLimit:48 CurrentConnections:44The HttpWebRequest object is a loopback address but the connection limit still applies to this webrequest object because the connection limit is defined (either through autoconfig set to true in the processModel section or by adding a * entry inside connectionManagement section
.NET 调用堆栈如下:
Function
[[HelperMethodFrame_1OBJ] (System.Threading.WaitHandle.WaitOneNative)] System.Threading.WaitHandle.WaitOneNative(Microsoft.Win32.SafeHandles.SafeWaitHandle, UInt32, Boolean, Boolean)
mscorlib_ni!System.Threading.WaitHandle.WaitOne(Int64, Boolean)+2f
mscorlib_ni!System.Threading.WaitHandle.WaitOne(Int32, Boolean)+25
System_ni!System.Net.LazyAsyncResult.WaitForCompletion(Boolean)+d3
System_ni!System.Net.Connection.SubmitRequest(System.Net.HttpWebRequest)+2b7
System_ni!System.Net.ServicePoint.SubmitRequest(System.Net.HttpWebRequest, System.String)+7c
System_ni!System.Net.HttpWebRequest.SubmitRequest(System.Net.ServicePoint)+f9
System_ni!System.Net.HttpWebRequest.GetRequestStream(System.Net.TransportContext ByRef)+1d3
System_ni!System.Net.HttpWebRequest.GetRequestStream()+e
System_ServiceModel_ni!System.ServiceModel.Channels.HttpOutput+WebRequestHttpOutput.GetOutputStream()+45
System_ServiceModel_ni!System.ServiceModel.Channels.HttpOutput.Send(System.TimeSpan)+f6
System_ServiceModel_ni!System.ServiceModel.Channels.HttpChannelFactory+HttpRequestChannel+HttpChannelRequest.SendRequest(System.ServiceModel.Channels.Message, System.TimeSpan)+121
System_ServiceModel_ni!System.ServiceModel.Channels.RequestChannel.Request(System.ServiceModel.Channels.Message, System.TimeSpan)+cb
System_ServiceModel_ni!System.ServiceModel.Dispatcher.RequestChannelBinder.Request(System.ServiceModel.Channels.Message, System.TimeSpan)+17
System_ServiceModel_ni!System.ServiceModel.Channels.ServiceChannel.Call(System.String, Boolean, System.ServiceModel.Dispatcher.ProxyOperationRuntime, System.Object[], System.Object[], System.TimeSpan)+1a2
System_ServiceModel_ni!System.ServiceModel.Channels.ServiceChannel.Call(System.String, Boolean, System.ServiceModel.Dispatcher.ProxyOperationRuntime, System.Object[], System.Object[])+33
System_ServiceModel_ni!System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(System.Runtime.Remoting.Messaging.IMethodCallMessage, System.ServiceModel.Dispatcher.ProxyOperationRuntime)+43
System_ServiceModel_ni!System.ServiceModel.Channels.ServiceChannelProxy.Invoke(System.Runtime.Remoting.Messaging.IMessage)+65
mscorlib_ni!System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(System.Runtime.Remoting.Proxies.MessageData ByRef, Int32)+bd
[[TPMethodFrame] (IMyWebService.GetDataSet)]
IMyWebService.GetDataSet(System.Guid, System.String, System.Data.DataSet)
<service code snipped>
mscorlib_ni!System.Threading.ThreadHelper.ThreadStart_Context(System.Object)+66
mscorlib_ni!System.Threading.ExecutionContext.runTryCode(System.Object)+51
[[HelperMethodFrame_PROTECTOBJ] (System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup)]
System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup(TryCode, CleanupCode, System.Object)
mscorlib_ni!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+67
mscorlib_ni!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+45
mscorlib_ni!System.Threading.ThreadHelper.ThreadStart()+44
[[GCFrame]]
我看到它提出的建议并开始研究它们。我的问题是:
为什么 DebugDiag 说线程不是似乎在等待服务器响应?
查看 .NET Reference Source,请求似乎已成功提交,服务似乎正在等待响应。
更新
进入正常调用后,我确实看到调用堆栈在 ws2_2 处等待,如下面 Puneet Gupta 所建议的:
ntdll.dll!_NtWaitForSingleObject@12()
mswsock.dll!_SockWaitForSingleObject@16()
mswsock.dll!_WSPRecv@36()
***ws2_32.dll!_recv@16()***
System.ni.dll!6c084a13()
[Managed to Native Transition]
System.dll!System.Net.Sockets.Socket.Receive(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags, out System.Net.Sockets.SocketError errorCode)
System.dll!System.Net.Sockets.Socket.Receive(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags)
System.dll!System.Net.Sockets.NetworkStream.Read(byte[] buffer, int offset, int size)
System.dll!System.Net.PooledStream.Read(byte[] buffer, int offset, int size)
System.dll!System.Net.Connection.SyncRead(System.Net.HttpWebRequest request, bool userRetrievedStream, bool probeRead)
System.dll!System.Net.ConnectStream.ProcessWriteCallDone(System.Net.ConnectionReturnResult returnResult)
System.dll!System.Net.HttpWebRequest.WriteCallDone(System.Net.ConnectStream stream, System.Net.ConnectionReturnResult returnResult)
System.dll!System.Net.ConnectStream.CallDone(System.Net.ConnectionReturnResult returnResult)
System.dll!System.Net.ConnectStream.ResubmitWrite(System.Net.ConnectStream oldStream, bool suppressWrite)
System.dll!System.Net.HttpWebRequest.EndWriteHeaders_Part2()
System.dll!System.Net.HttpWebRequest.EndWriteHeaders(bool async)
System.dll!System.Net.HttpWebRequest.WriteHeadersCallback(System.Net.WebExceptionStatus errorStatus, System.Net.ConnectStream stream, bool async)
System.dll!System.Net.ConnectStream.WriteHeaders(bool async)
System.dll!System.Net.HttpWebRequest.EndSubmitRequest()
System.dll!System.Net.HttpWebRequest.CheckDeferredCallDone(System.Net.ConnectStream stream)
System.dll!System.Net.HttpWebRequest.GetResponse()
System.ServiceModel.dll!System.ServiceModel.Channels.HttpChannelFactory<System.ServiceModel.Channels.IRequestChannel>.HttpRequestChannel.HttpChannelRequest.WaitForReply(System.TimeSpan timeout)
System.ServiceModel.dll!System.ServiceModel.Channels.RequestChannel.Request(System.ServiceModel.Channels.Message message, System.TimeSpan timeout)
System.ServiceModel.dll!System.ServiceModel.Dispatcher.RequestChannelBinder.Request(System.ServiceModel.Channels.Message message, System.TimeSpan timeout) Unknown
System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannel.Call(string action, bool oneway, System.ServiceModel.Dispatcher.ProxyOperationRuntime operation, object[] ins, object[] outs, System.TimeSpan timeout)
System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(System.Runtime.Remoting.Messaging.IMethodCallMessage methodCall, System.ServiceModel.Dispatcher.ProxyOperationRuntime operation)
System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannelProxy.Invoke(System.Runtime.Remoting.Messaging.IMessage message)
mscorlib.dll!System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(ref System.Runtime.Remoting.Proxies.MessageData msgData, int type)
所以通常情况下,它将等待来自 Windows 套接字的响应。在这种情况下,线程可能正在等待连接变为可用于处理请求——如其他 DebugDiag 消息所示。
消息说它似乎没有在线等待的原因是因为线程上的最后一帧是 waithandle.waitone。
对于真正在线上等待的线程,我们应该看到 ws2_32(在本机堆栈中),它是 windows 套接字库或 system.net.sockets 中的一些函数托管堆栈。
您是否能够捕获多个转储?如果是,您是否看到线程状态在一次转储与第二次转储中发生了变化?
!dso (!DumpStackObjects) 是否显示当前线程中的任何连接对象?如果是这样,System.Net.Connection 对象中的 m_WaitList 值是什么,m_CurrentRequest 的值是什么? 由于您的调用堆栈未显示我们正在等待 ws2_32 (WinSock),这表明 HWR 仍在等待获取可用连接或套接字。