. NET object with Windows handle (III): Handle Disclosure Instance Analysis

In the previous article. NET object with Windows handle (ii): Handle classification and. NET Handle disclosure example, we have a handle leak example. The Datareceiver and Dataanalyzer objects were created and dispose of in the example many times, but the handle disclosure was caused by forgetting to call Dataanalyzer's Stop method. This article assumes that we have discovered a leak but don't know why, and discuss how to analyze the problem in this case.

First, the problem found

After the program has been running for approximately one hours, the task manager finds that the number of handles exceeds 5000 and the number of threads exceeds 1000. This is obviously too unusual for a simple code that only needs to receive and analyze data in parallel, and we can tell that the program has been compromised.

The Task Manager makes it easy to see the real-time resource usage of the program, but it doesn't understand historical data and trends. is the program the first time you need to allocate and use so many resources, or is it a long-running result? If it is the latter, is it a steady, continuous increase in the running process or a sudden increase after a certain time node? It is necessary to figure out these issues, and we can use this to initially determine whether the memory leaks are related to a particular operation of the user or to events that occur at a particular point in time, whether it is related to the initialization of the program or some background task that runs from start to finish.

Performance Monitor can be very intuitive to display this trend, which built up a lot of useful counters, we can from the graphical interface to observe the changes in these counter values, understanding the system and process health. Use the win + R key combination to open the Run window and enter Perfmon to open Performance Monitor. Click the Green Plus button to open the Add Counters dialog box, select Handle Count and thread count in process, and then select the Leakexample process as an instance to add both counters.

Next, observe the changes in these values. During this time, we use the program as usual and can repeat some of the operations that may have caused a memory leak. After running for a period of time, the following chart is obtained. The number of handles and the number of threads continues to grow, and it is easy to guess about the timer, because the timer triggers periodically and threads are required for each trigger. Even so, there is still a need to pinpoint exactly what the object is leaking from, because the code for the timer or background thread that might be used in the actual project is far more than one or two.

Second, the analysis of the process in operation

The first thing you should do is find out what the 5,000 + handles represent. Using the Process Explorer to see the progress, checking the handle list in the next panel, discovering a large number of event handles and thread handles, further, we want to know exactly how many event and thread.

It is difficult to see the number of handles in this list. You can press CTRL + A to save the list of processes in Process Explorer and the handle list of the selected process as a text file, and then use the text viewing tool that you are accustomed to use to count the number of specific handles. We see about 4,063 event handles and 1008 thread handles using Chrome's search function (note: Handle statistics can also be viewed using WinDbg's!handle command).

Here, we have a general impression that the leaked object is the event and thread, where the event is the majority. The next step is to find out who created these objects and can use WinDbg to track the creation of objects. WINDBG is a very handy Windows debugging tool that can take advantage of the powerful SOS Extension command to diagnose various problems in. NET programs, the latest WINDBG (as of April 2016) can be download from MSDN to the WDK, WINDBG, and Associated Tools page download, click on the Get Debugging Tools for Windows (WINDBG) link on the page.

Attach WinDbg to the LeakExample.exe process, and then use the!handle and!htrace commands to parse the process handle. The!handle command lists all the handles within the process, or you can view the information for a particular handle, and!htrace displays a stack trace of the handle. We first use!htrace-enable to enable handle tracking, then let the process continue running for a few minutes, then interrupt the execution of the program, and use!htrace-diff to view the newly opened handle since the last snapshot. Because the command output is too long, some unimportant information is implicitly replaced with an ellipsis.

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.

As you can see, there are 6 handle open between the two!htrace commands, known by the call stack as 1 thread objects and 5 event objects, and 4 event after the 1th thread object belongs to that thread. If you repeat!htrace-diff multiple times, you can find a rule that after each thread object is created, then there will be 4 event objects opened in the same thread, stating that in this case the source of the leak is the thread object, This also explains why the number of event handles is roughly 4 times times that of thread. In fact, each thread creates 4 manual Event at the time of creation, as can be seen from the call stack when the above handle is opened, clr! In addition to creating a thread object, the Thread::createnewosthread method also creates several manual Reset event to control the thread's suspend and resume.

View the details of the event and thread handle, and the output below shows the thread ID pointed to by the thread handle and the event handle information that follows.

0:015> !handle 0x00000b68 F Handle b68 Type Thread Attributes 0 Grantedaccess 0X1FFFFF: Delete,readcontrol,writedac,writeowner,synch Terminate,suspend,alert,getcontext,setcontext,setinfo,queryinfo,settoken,impersonate,directimpersonate Handlecount 4 Pointercount 6 Name <none> Object Specific Information Thread Id 1988.261c Priority 10 Base Priority 0 Start Address 6c54a086 clr! Thread::intermediatethreadproc 0:015> !handle 0x00000b64 F Handle b64 Type Event Attributes 0 Grantedaccess 0x1f0003: Delete,readcontrol,writedac,writeowner,synch Querystate,modifystate Handlecount 2 Pointercount 3 Name <none> Object Specific Information Event Type Manual Reset Event is Set

Next look at what code this newly-started thread is executing, and this information will help us find out where the code was created for that thread. We need to load the SOS extension and take advantage of the thread ID information that was output above.

0:015> . Loadby SOS CLR 0:015> !threads threadcount:323 unstartedthread:0 backgroundthread:266 pendingthread:0 deadthread:56 Hosted Runtime:no Lock ID OSID Threadobj State GC Mode GC Alloc Context Domain Count Apt Exception 0 1 fb8 005015e8 26020 preemptive 4eec2a44:00000000 004f9540 0 STA 2 2 A20 0050e080 2b220 preemptive 00000000:00000000 004f9540 0 MTA (Finalizer) 8 5 14cc 00553c48 102a220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 284 280 f34 1178fa50 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 286 283 1ff4 117bd278 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 761 764 229c 24cfc070 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 849 865 1bc8 490eb860 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) XXXX 868 0 490e82f0 1039820 preemptive 00000000:00000000 004f9540 0 Ukn (Threadpool Worker) 1054 490edd58 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 898 901 654 490d9370 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 903 903 828 490d9e00 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) XXXX 904 0 490ead30 1039820 preemptive 00000000:00000000 004f9540 0 Ukn (Threadpool Worker) XXXX 1004 0 11758b70 1039820 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 1005 2844 117590b8 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 7 1006 314 11759600 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) ... ... ... ... 804 2164 0054f960 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 318 803 1758 24a3e810 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 317 802 27bc 116e1540 3029220 preemptive 00000000:00000000 004f9540 0 MTA (Threadpool Worker) 5 801 261c 117152d0 3029220 preemptive 4eec0c44:00000000 004f9540 0 MTA (Threadpool Worker) 0:015> ~5s eax=00000000 ebx=00000258 ecx=00000001 edx=4fa6bc17 esi=0465ee48 edi=00000000 EIP=779A64F4 ESP=0465EE04 ebp=0465ee6c iopl=0 nv up ei pl nz na pe nc cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000206 ntdll! Kifastsystemcallret: 779A64F4 c3 ret 0:005> !clrstack OS Thread id:0x261c (5) Child SP IP Call Site 0465EEF4 779a64f4 [HELPERMETHODFRAME:0465EEF4] System.Threading.Thread.SleepInternal (Int32) 0465ef68 6ad83365 System.Threading.Thread.Sleep (Int32) 0465EF6C 001d04cd LeakExample.DataAnalyzer.DoAnalyze (System.Object) [D: \timerleak\timerleak\form1.cs @ 88] 0465ef7c 6adede48 System.Threading.TimerQueueTimer.CallCallbackInContext (System.Object) 0465ef80 6adc2367 System.Threading.ExecutionContext.RunInternal (...) 0465EFEC 6adc22a6 System.Threading.ExecutionContext.Run (...) 0465f000 6adedd91 System.Threading.TimerQueueTimer.CallCallback () 0465f034 6adedc4c System.Threading.TimerQueueTimer.Fire () 0465f074 6ade11a5 System.Threading.TimerQueue.FireQueuedTimerCompletion (System.Object) 0465f078 6adcdd34 System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem () 0465f08c 6adcd509 System.Threading.ThreadPoolWorkQueue.Dispatch () 0465F0DC 6adcd3a5 System.threading._threadpoolwaitcallback.performwaitcallback () 0465f300 6c432652 [debuggeru2mcatchhandlerframe:0465f300]

As can be seen from the call stack, the new thread is triggered by the timer, the callback function is Doanalyze, referring to the code in the previous article, that it is dataanalyzer in the Analyzetimer. This is not a problem in itself, but checking the call stack of multiple threads, repeating the above steps for multiple analysis, finds that all new threads are triggered by this timer. The timer itself is set to trigger once per second, and the execution time for each trigger is less than one second. There are a number of threads that indicate that the timer object itself is leaking, that there are a large number of timer instances running in the process, and that the program design is intended to have only one analyzetimer in the process. The problem is obvious here, and it's often possible to find out from the code review that Analyzetimer is not being dispose.

Third, summary

In this paper, a method of analysis is described for a program with a handle leaking. The parsed object is a running process, so this is a dynamic analysis, that is, we can reproduce the problem repeatedly during its operation, and then observe the new leak. In a real project, this process is the process of finding the key to the recurrence of a problem, as well as the process of guessing and validating it repeatedly and discovering new clues. It is actually fortunate to be able to perform dynamic analysis because in other cases it is difficult to reproduce the problem again, or the site environment does not allow us to try again and again. At this point we need to quickly collect the environment data, and play a good memory dump dump file, after the static analysis. In the next article, we still use this example to explore how to perform dump analysis and discuss some of the implementation details of a timer.

. NET object with Windows handle (III): Handle Disclosure Instance Analysis