.NET对象与Windows句柄(三):句柄泄露实例分析

时间:2021-08-10 06:18:03

在上篇文章.NET对象与Windows句柄(二):句柄分类和.NET句柄泄露的例子中,我们有一个句柄泄露的例子。例子中多次创建和Dispose了DataReceiver和DataAnalyzer对象,但由于忘记调用DataAnalyzer的Stop方法,导致产生句柄泄露。本文假定我们已经发现了泄露现象但还不知道原因,讨论如何在这种情况下分析问题。

一、发现问题

在程序运行约一个小时以后,通过任务管理器发现句柄数超过5000,线程数也超过1000。对于一段只需要并行接收和分析数据的简易代码来说,这显然太不正常了,我们可以判断程序已经产生了泄露。

通过任务管理器可以非常方便的查看程序实时的资源占用情况,但无法了解到历史数据和趋势。程序是一开始就需要分配和使用这么多资源,还是长时间运行的结果?如果是后者,那么是运行过程中平稳持续的增长,还是在某个时间节点之后的突然增长?弄清楚这些问题是必要的,我们可以借此初步判断出内存泄露是与用户的特定操作相关,,或者与特定时间点上产生的事件相关;是跟程序的初始化有关,还是跟某些从始至终运行的后台任务相关。

性能监视器可以很直观的显示这一趋势,其中内置了很多有用的计数器,我们可以从图形化界面中观察这些计数器值的变化规律,了解系统和进程的运行状况。使用Win + R组合键打开“运行”窗口,输入perfmon打开性能监视器。点击绿色加号按钮打开“添加计数器”对话框,选择Process中的Handle Count和Thread Count,然后选择LeakExample进程作为实例,添加这两个计数器。

接下来观察这些数值的变化。在这期间,我们像往常一样的使用程序,可以重复进行一些可能造成内存泄露的操作。在运行过一段时间后,得到了如下的图表。句柄数和线程数在持续的增长,很容易猜测到跟Timer有关,因为Timer定期触发,并且每次触发都需要使用线程。即便如此,仍然需要确切的定位究竟是什么对象产生了泄露,因为实际的项目中可能用到的Timer或者后台线程的代码远远不止一两处。

二、分析运行中的进程

首先应该找出5000多个句柄究竟代表什么对象。利用Process Explorer查看该进程,在下方面板中检查句柄列表,发现有大量的Event句柄和Thread句柄,更进一步的,我们想知道到底有多少Event和Thread。

在这个列表中难以看出各种句柄的数量。可以按下Ctrl+A组合键,将Process Explorer中的进程列表和选中进程的句柄列表保存为文本文件,而后利用你所习惯使用的文本查看工具统计其中特定句柄的数量,我们这里使用Chrome浏览器的搜索功能看到约有4063个Event句柄和1008个Thread句柄(注:也可以使用Windbg的!handle命令查看句柄统计信息)。

到这里,我们有一个大致的印象,即泄露的对象是Event和Thread,其中Event占大多数。下一步需要找出是谁创建出了这些对象,可以使用Windbg跟踪对象的创建。Windbg是非常方便的Windows调试工具,可以利用强大的SOS扩展命令诊断.NET程序中的各种问题,最新的Windbg(截止2016年4月)可以从MSDN的Download the WDK, WinDbg, and associated tools页面下载,点击页面上的Get Debugging Tools for Windows (WinDbg)链接即可。

将Windbg附加到LeakExample.exe进程,而后使用!handle和!htrace命令对进程句柄进行分析。!handle命令可以列出进程内所有句柄,也可以查看特定句柄的信息,而!htrace显示句柄的堆栈跟踪。我们先使用!htrace -enable启用句柄跟踪,然后让进程继续运行几分钟时间,再中断程序的执行,用!htrace -diff查看自上次快照以来新打开的句柄。由于命令输出过长,一些不重要的信息被隐去用省略号代替。

0:482> !htrace -enable

Handle tracing enabled.

Handle tracing information snapshot successfully taken.

0:482> g

(1988.2f3c): Break instruction exception - code 80000003 (first chance)

eax=7fbc0000 ebx=00000000 ecx=00000000 edx=779fd23d esi=00000000 edi=00000000

eip=77993540 esp=5a75ff28 ebp=5a75ff54 iopl=0         nv up ei pl zr na pe nc

cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000246

ntdll!DbgBreakPoint:

77993540 cc              int     3

0:015> !htrace -diff

Handle tracing information snapshot successfully taken.

0x6 new stack traces since the previous snapshot.

Ignoring handles that were already closed...

Outstanding handles opened since the previous snapshot:

--------------------------------------

Handle = 0x00000b68 - OPEN

Thread ID = 0x00002a68, Process ID = 0x00001988

0x779a4b7c: ntdll!ZwCreateThreadEx+0x0000000c

0x75d3bc5d: KERNELBASE!CreateRemoteThreadEx+0x00000161

0x7643281d: KERNEL32!CreateThreadStub+0x00000020

0x6c54b51f: clr!Thread::CreateNewOSThread+0x0000009b

0x6c54b358: clr!Thread::CreateNewThread+0x000000a8

0x6c54b8ad: clr!ThreadpoolMgr::CreateUnimpersonatedThread+0x00000275

0x6c54b9fc: clr!ThreadpoolMgr::MaybeAddWorkingWorker+0x00000129

0x6c53f298: clr!ManagedPerAppDomainTPCount::SetAppDomainRequestsActive+0x0000002f

--------------------------------------

Handle = 0x00000b64 - OPEN

Thread ID = 0x00002a68, Process ID = 0x00001988

0x779a49fc: ntdll!ZwCreateEvent+0x0000000c

0x75d376a0: KERNELBASE!CreateEventExW+0x0000006e

0x75d376f0: KERNELBASE!CreateEventW+0x00000027

0x6c54a106: clr!CLREventBase::CreateManualEvent+0x00000036

0x6c54a84f: clr!Thread::AllocHandles+0x00000064

0x6c54b4f4: clr!Thread::CreateNewOSThread+0x00000074

0x6c54b358: clr!Thread::CreateNewThread+0x000000a8

0x6c54b8ad: clr!ThreadpoolMgr::CreateUnimpersonatedThread+0x00000275

0x6c54b9fc: clr!ThreadpoolMgr::MaybeAddWorkingWorker+0x00000129

0x6c53f298: clr!ManagedPerAppDomainTPCount::SetAppDomainRequestsActive+0x0000002f

0x6ae49bd3: mscorlib_ni+0x00389bd3

0x6adcd38c: mscorlib_ni+0x0030d38c

--------------------------------------

Handle = 0x00000b60 - OPEN

Thread ID = 0x00002a68, Process ID = 0x00001988

0x779a49fc: ntdll!ZwCreateEvent+0x0000000c

… …

--------------------------------------

Handle = 0x00000b70 - OPEN

Thread ID = 0x00002a68, Process ID = 0x00001988

0x779a49fc: ntdll!ZwCreateEvent+0x0000000c

… …

--------------------------------------

Handle = 0x00000b54 - OPEN

Thread ID = 0x00002a68, Process ID = 0x00001988

0x779a49fc: ntdll!ZwCreateEvent+0x0000000c

… …

--------------------------------------

Handle = 0x00000b50 - OPEN

Thread ID = 0x000011f8, Process ID = 0x00001988

0x779a49fc: ntdll!ZwCreateEvent+0x0000000c

… …

--------------------------------------

Displayed 0x6 stack traces for outstanding handles opened since the previous snapshot.