起因是发现一个同事编写的程序运行两个月左右,占用了服务器20G左右的内存。用WinDbg查看发现存在大量的Async Pinned Handles,而它们的gcroot都来自于SocketAsyncEventArgs。下面是场景的简易模拟代码(为了说明问题添加了手动GC):
for (var i = 0; i < 1000; ++i) { var endPoint = new IPEndPoint(IPAddress.Parse(host), port); var socket = new Socket(endPoint.AddressFamily, SocketType.Stream, ProtocolType.Tcp); socket.ReceiveBufferSize = bufferSize; socket.SendBufferSize = bufferSize; var iocp = new SocketAsyncEventArgs(); iocp.Completed += new EventHandler<SocketAsyncEventArgs>(OnIoSocketCompleted); iocp.SetBuffer(new Byte[bufferSize], 0, bufferSize); iocp.AcceptSocket = socket; try { socket.Connect(endPoint); Console.WriteLine(i); } catch (SocketException ex) { Console.WriteLine(ex.Message); } socket.Close(); //iocp.Dispose(); } GC.Collect(); GC.WaitForPendingFinalizers(); GC.Collect();
SocketAsyncEventArgs的SetBuffer函数内部会pin住buffer数据(查阅SetBufferInternal实现),它的析构函数会调用FreeOverlapped函数释放资源。而问题就是在于FreeOverlapped函数的实现和传递参数。来看一下Dispose、~SocketAsyncEventArgs的实现:
public void Dispose() { this.m_DisposeCalled = true; if (Interlocked.CompareExchange(ref this.m_Operating, 2, 0) != 0) { return; } this.FreeOverlapped(false); GC.SuppressFinalize(this); }
~SocketAsyncEventArgs() { this.FreeOverlapped(true); }
两者都会调用FreeOverlapped函数释放,但是一个传递了false、一个传递了true参数。再来看FreeOverlapped实现:
private void FreeOverlapped(bool checkForShutdown) { if (!checkForShutdown || !NclUtilities.HasShutdownStarted) { if (this.m_PtrNativeOverlapped != null && !this.m_PtrNativeOverlapped.IsInvalid) { this.m_PtrNativeOverlapped.Dispose(); this.m_PtrNativeOverlapped = null; this.m_Overlapped = null; this.m_PinState = SocketAsyncEventArgs.PinState.None; this.m_PinnedAcceptBuffer = null; this.m_PinnedSingleBuffer = null; this.m_PinnedSingleBufferOffset = 0; this.m_PinnedSingleBufferCount = 0; } if (this.m_SocketAddressGCHandle.IsAllocated) { this.m_SocketAddressGCHandle.Free(); } if (this.m_WSAMessageBufferGCHandle.IsAllocated) { this.m_WSAMessageBufferGCHandle.Free(); } if (this.m_WSARecvMsgWSABufferArrayGCHandle.IsAllocated) { this.m_WSARecvMsgWSABufferArrayGCHandle.Free(); } if (this.m_ControlBufferGCHandle.IsAllocated) { this.m_ControlBufferGCHandle.Free(); } } }
用WinDbg查看gchandles统计:
Statistics: MT Count TotalSize Class Name 000007fb1bdb6ae8 1 24 System.Object 000007fb1bdb6b80 1 48 System.SharedStatics 000007fb1bdb7f58 1 64 System.Security.PermissionSet 000007fb1bdb6a10 1 160 System.ExecutionEngineException 000007fb1bdb6998 1 160 System.StackOverflowException 000007fb1bdb6920 1 160 System.OutOfMemoryException 000007fb1bdb6738 1 160 System.Exception 000007fb1bdb7b90 2 192 System.Threading.Thread 000007fb1bdb6c40 1 216 System.AppDomain 000007fb1bdb6a88 2 320 System.Threading.ThreadAbortException 000007fb1ae19770 6 336 System.Net.Logging+NclTraceSource 000007fb1bdbf958 3 480 System.RuntimeType+RuntimeTypeCache 000007fb1ae19900 6 480 System.Diagnostics.SourceSwitch 000007fb1bd64458 6 34520 System.Object[] 000007fb1b6f5e40 1000 112000 System.Threading.OverlappedData Total 1033 objects Handles: Strong Handles: 12 Pinned Handles: 5 Async Pinned Handles: 1000 Weak Long Handles: 3 Weak Short Handles: 13
确实存在1000个Async Pinned Handles,也就是说无法通过SocketAsyncEventArgs的析构函数释放SafeNativeOverlapped相关的资源。将示例代码的"iocp.Dispose();"注释去除,并重新执行再次查看gchandles:
Statistics: MT Count TotalSize Class Name 000007fb1bdb6ae8 1 24 System.Object 000007fb1bdb6b80 1 48 System.SharedStatics 000007fb1bdb7f58 1 64 System.Security.PermissionSet 000007fb1bdb6a10 1 160 System.ExecutionEngineException 000007fb1bdb6998 1 160 System.StackOverflowException 000007fb1bdb6920 1 160 System.OutOfMemoryException 000007fb1bdb6738 1 160 System.Exception 000007fb1bdb7b90 2 192 System.Threading.Thread 000007fb1bdb6c40 1 216 System.AppDomain 000007fb1bdb6a88 2 320 System.Threading.ThreadAbortException 000007fb1ae19770 6 336 System.Net.Logging+NclTraceSource 000007fb1bdbf958 3 480 System.RuntimeType+RuntimeTypeCache 000007fb1ae19900 6 480 System.Diagnostics.SourceSwitch 000007fb1bd64458 6 34520 System.Object[] Total 33 objects Handles: Strong Handles: 12 Pinned Handles: 5 Weak Long Handles: 3 Weak Short Handles: 13
1000个Async Pinned Handles已不存在,但SocketAsyncEventArgs的析构函数从实现来看应该也可以完成释放,为什么失败了?
用!bpmd命令添加NclUtilities.HasShutdownStarted、 m_PtrNativeOverlapped.Dispose()的断点。
!bpmd System.dll System.Net.NclUtilities.get_HasShutdownStarted
!bpmd mscorlib.dll System.Runtime.InteropServices.SafeHandle.Dispose
以上函数无法命中,由于.NET Framework ngen的关系。实际可以看到SocketAsyncEventArgs的Finalize函数内联了FreeOverlapped。
0:002> !clrstack -a OS Thread Id: 0x46c (2) Child SP IP Call Site 000000002656f940 000007ff138485e9 System.Net.Sockets.SocketAsyncEventArgs.FreeOverlapped(Boolean) PARAMETERS: this = <no data> checkForShutdown = <no data> 000000002656f980 000007ff1385222d System.Net.Sockets.SocketAsyncEventArgs.Finalize() PARAMETERS: this (0x000000002656f9c0) = 0x000000000e140438 000000002656fd38 000007ff72c1c446 [DebuggerU2MCatchHandlerFrame: 000000002656fd38]
逐一单步执行可以发现NclUtilities.HasShutdownStarted也被内联,直接调用外部函数clr!SystemNative::HasShutdownStarted。
0:002> t 000007ff`138485ec 85c0 test eax,eax 0:002> t 000007ff`138485ee 7438 je 000007ff`13848628 [br=0] 0:002> t 000007ff`138485f0 e8c798485f call clr!SystemNative::HasShutdownStarted (000007ff`72cd1ebc)
那问题就在于HasShutdownStarted的返回值了,如果为false则肯定会释放资源。
0:002> t clr!SystemNative::HasShutdownStarted: 000007ff`72cd1ebc 4883ec28 sub rsp,28h 0:002> t clr!SystemNative::HasShutdownStarted+0x4: 000007ff`72cd1ec0 f60501767a0004 test byte ptr [clr!g_fEEShutDown (000007ff`734794c8)],4 ds:000007ff`734794c8=07 0:002> t clr!SystemNative::HasShutdownStarted+0xb: 000007ff`72cd1ec7 751a jne clr!SystemNative::HasShutdownStarted+0x27 (000007ff`72cd1ee3) [br=1] 0:002> t clr!SystemNative::HasShutdownStarted+0x27: 000007ff`72cd1ee3 b901000000 mov ecx,1 0:002> t clr!SystemNative::HasShutdownStarted+0x2c: 000007ff`72cd1ee8 ebf2 jmp clr!SystemNative::HasShutdownStarted+0x20 (000007ff`72cd1edc) 0:002> t clr!SystemNative::HasShutdownStarted+0x20: 000007ff`72cd1edc 8bc1 mov eax,ecx 0:002> t clr!SystemNative::HasShutdownStarted+0x22: 000007ff`72cd1ede 4883c428 add rsp,28h 0:002> t clr!SystemNative::HasShutdownStarted+0x26: 000007ff`72cd1ee2 c3 ret 0:002> t 000007ff`138485f5 0fb6c8 movzx ecx,al 0:002> t 000007ff`138485f8 85c9 test ecx,ecx
查看ecx的值发现竟然是1。
0:002> r ecx ecx=1 0:002> r al al=1