How to Debug Handle leak (using !htrace) in w3wp.exe

by jask2002 23. January 2012 07:55

What is the Handles? huh

From the application (user mode) perspective handles are the reference to the kernel mode objects(device/registry/token/event/file).It does not have the semantics of a programming reference but what it does do is allow the system resources to know what you are referring to when it is passed in an API call.They are 32 bit unsigned values that the Windows OS owns.

 

Handle Leak?

Looking at the Task manager if you notice w3wp.exe or your application exe handle count are increasing at steady/fast pace and  also if you notice event id 2020 and/or 2019 then it’s time to get ready to debug.

 

Handle leak can make system unstable and could also lead to BOD.

  

We can also use Perfmon(Process -> Handle Count) to determine Handle leak and pattern. For example following graph show w3wp.exe handle count goes hand in hand with lsass.exe.

 

If you explicitly kill w3wp.exe you would see handle count going down.

 

 

 

If you happen to see above pattern then there is good possibility security TOKEN handle is being leaked.(Tip: Grab the dump for the both processes)

 

What kind/type of handle’s are being leaked by my application?

Good question . To figure out what kind handle are being you can either use Process Explorer , handle.exe or simply grab leak track injected dump using Debug Diag 1.1.

I took the latter approach. In Debug Diag created Memory and Handle Leak rule and targeted w3wp.exe . General idea is to inject leak from the time when the worker process is spawned so that we can monitor for leak from the start.

 

After opening dump in windbg we can see process uptime was only 13 mins!

Run !handle 0 0 in windbg against w3wp.exe

 

0:00>!hande 0 0

66316 Handles

Type                      Count

None                     9

Event                    339

Section                  32

File                         107

Port                       17

Directory             2

Mutant                  6

WindowStation   3

Semaphore       80

Key                        65602    ==>  Large Value

Token                   9

Process                1

Thread                  82

Desktop               3

IoCompletion    21

Timer                    2

KeyedEvent      1

 

We can clearly make out they “Key” handle is being leaked . It corresponds to registry handle. That means from the application we would be trying to access registry locations. Now to figure out what locations?

 

0:00>!handle 0 ff Key

Handle 000007e0

  Type          Key

  Attributes    0

  GrantedAccess 0x20019:

         ReadControl

         QueryValue,EnumSubKey,Notify

  HandleCount   2

  PointerCount  3

  Name          \REGISTRY\MACHINE\SOFTWARE\Classes

  No object specific information available

 

 

Handle 000007fc

  Type          Key

  Attributes    0

  GrantedAccess 0xf003f:

         Delete,ReadControl,WriteDac,WriteOwner

         QueryValue,SetValue,CreateSubKey,EnumSubKey,Notify,CreateLink

  HandleCount   2

  PointerCount  3

  Name          <none>

  No object specific information available

 

Handle 00000834

  Type          Key

  Attributes    0

  GrantedAccess 0xf003f:

         Delete,ReadControl,WriteDac,WriteOwner

         QueryValue,SetValue,CreateSubKey,EnumSubKey,Notify,CreateLink

  HandleCount   2

  PointerCount  3

  Name          <none>

  No object specific information available

 

Most of Name column on Kay handle is <none>.This time we are not lucky enough to get registry info..

Most of name is <none>  !!!!!!

 

Looking at the Debug Diag Memory Leak report on leak track enabled dumps (It helps most of time but not this time

 

Call stack sample 1

Handle   0x00000614

Allocation Time   00:03:36 since tracking started

Function   Destination

ole32!CComClassInfo::FinalConstruct+75   0x4601B3

ole32!CStdIdentity::CInternalUnk::QueryInterface+33   

MyCustomDll+2af0   

ntdll!ZwWaitForSingleObject+c   

kernel32!WaitForSingleObjectEx+ac   ntdll!ZwWaitForSingleObject

ole32!CComClassInfo::QueryInterface+98   

ole32!CComCatalog::GetClassInfoInternal+185   

MyCustomDll +1a17 

 

Call stack sample 3

Handle   0x00000600

Allocation Time   00:03:36 since tracking started

 

Function   Destination

ole32!CComClassInfo::FinalConstruct+75   0x4601B3

ole32!CComRegCatalog::GetClassInfoW+216   

clbcatq!StgTSICRReadOnly::QueryByColumns+35   

clbcatq!IsComplusLegacyComponent+e6   

clbcatq!IsComplusLegacyComponent+110   

ole32!CComCatalog::GetClassInfoInternal+41d   

ole32!CComCatalog::GetClassInfoW+22   ole32!CComCatalog::GetClassInfoInternal

ole32!GetClassInfoFromClsid+2d   

ole32!LookForConfiguredClsid+33   ole32!GetClassInfoFromClsid

ole32!ICoCreateInstanceEx+135   ole32!LookForConfiguredClsid

ole32!CComActivator::DoCreateInstance+6a   ole32!ICoCreateInstanceEx

ole32!CoCreateInstanceEx+23   ole32!CComActivator::DoCreateInstance

ole32!CoCreateInstance+3c   ole32!CoCreateInstanceEx

MyCustomDll+1dea 

 

Next Stop is to capture htrace data

Open windbg attach to the process in question for example w3wp.exe

Enable htrace and take first snapshot

!htrace -enable

Take another snapshot to compare with first

!htrace -snapshot

!htrace -diff   This would show us any handles left open between the first and second snapshot, all the closed handles are removed.

 

Following were the results of the htrace on the production environment

 

Handle = 0x00000bdc - OPEN

Thread ID = 0x000014a4, Process ID = 0x0000151c

 0x7c827369: ntdll!ZwOpenKey+0x0000000c

0x008b6cb1: advapi32_5_2_3790_4455!LocalBaseRegOpenKey+0x000000d0

0x008b7bbd: advapi32_5_2_3790_4455!RegOpenKeyExW+0x00000116

0x0086277d: MyCustomDll!RegSetValueW+0x00001543

0x008638db: MyCustomDll!RegSetValueW+0x000026a1

0x776aba50: ole32!CComClassInfo::FinalConstruct+0x00000075

 

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

Handle = 0x00000b50 - OPEN

Thread ID = 0x000014a4, Process ID = 0x0000151c

0x7c827369: ntdll!ZwOpenKey+0x0000000c

0x008b6cb1: advapi32_5_2_3790_4455!LocalBaseRegOpenKey+0x000000d0

0x008b7bbd: advapi32_5_2_3790_4455!RegOpenKeyExW+0x00000116

0x0086277d: MyCustomDll!RegSetValueW+0x00001543

0x008638db: MyCustomDll!RegSetValueW+0x000026a1

0x776aba50: ole32!CComClassInfo::FinalConstruct+0x00000075

 

Seems like that the MyCustomDll is opening registry KEY handle and not closing at the same rate J

 

References:

 

Htrace Video

http://channel9.msdn.com/Blogs/jeff_dailey/Understanding-handle-leaks-and-how-to-use-htrace-to-find-them

Handle leak tutorial

http://www.codeproject.com/Articles/6988/Debug-Tutorial-Part-5-Handle-Leaksv

 

 

 


PayPal — The safer, easier way to pay online. Has this post helped you? Saved you? If you'd like to show your appreciation. Please buy me a coffee or make a small contribution toward blog's maintenance(to keep it Ads free )

Tags: , ,

Debugging

Pingbacks and trackbacks (1)+

Add comment

  Country flag

biuquote
  • Comment
  • Preview
Loading

About me

Hi there,

My name is  Jas and I'm currently working with Microsoft IIS/ASP.Net Escalation services.

Tag cloud

Month List

RecentComments

Comment RSS
 

Disclaimer
The opinions expressed herein are my own personal opinions and do not represent my employer's view in any way.