Some new SOS functions

  • Article

Hi all. Here is a short tutorial about !gchandleleaks and managed breakpoints in windbg. You need at least a Whidbey Beta2 build to run it. Soon Whidbey RTM will be out too (yay!)

 

WINDOWH.EXE (the code is below) - from a sample app which illustrates calling EnumWindows. I modified it to run in a loop, and forget to free a gc handle each time. Over time, this will cause the gc heap to grow and finally you'll run out of memory. For this document, the demo is running on an x64 machine.

 

Let the program run for a few minutes. Eventually it will become a large memory user in Task Manager. Break in:

 

Windbg.exe –pn windowh.exe

 

And let’s see how large the gc heap is:

 

(9f0.7c8): Break instruction exception - code 80000003 (first chance)

ntdll!DbgBreakPoint:

00000000`77efa850 cc int 3

0:003> !eeheap -gc

Number of GC Heaps: 1

generation 0 starts at 0x0000000010355a10

generation 1 starts at 0x0000000010354998

generation 2 starts at 0x0000000010351000

ephemeral segment allocation context: none

         segment begin allocated size

000000000019f420 00000000027c0008 00000000027c0020 0x0000000000000018(24)

0000000000199890 0000064237482c80 00000642374f5668 0x00000000000729e8(469480)

0000000010350000 0000000010351000 000000001038da28 0x000000000003ca28(248360)

Large object heap starts at 0x0000000020351000

         segment begin allocated size

0000000020350000 0000000020351000 000000002759bbc8 0x000000000724abc8(119843784)

Total Size 0x72f9ff0(120561648)

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

GC Heap Size 0x72f9ff0(120561648)

About 120 megabytes, mostly in the large object heap. You could let it run some more and verify the growth.

 

Why is the heap so big? We don’t have the source code (pretend), and know nothing about the program. But !dumpheap can help us:

0:003> !dumpheap -stat

total 11466 objects

Statistics:

              MT Count TotalSize Class Name

0000064237554400 1 24 System.Text.EncoderExceptionFallback

0000064237553b30 1 24 System.Text.DecoderExceptionFallback

000006423757d308 1 32 System.Security.PermissionToken

0000064237522870 1 32 System.Version

0000064237518650 1 32 System.Guid

000006423756d4a0 1 40 System.IO.TextWriter+NullTextWriter

000006423755bd18 1 40 Microsoft.Win32.SafeHandles.SafeViewOfFileHandle

000006423755b998 1 40 Microsoft.Win32.SafeHandles.SafeFileMappingHandle

000006423755b8b8 1 40 Microsoft.Win32.SafeHandles.SafeFileHandle

000006423755aa20 1 40 Microsoft.Win32.Win32Native+InputRecord

0000064237554180 1 40 System.Text.InternalEncoderBestFitFallback

00000642375201c0 1 40 System.SharedStatics

00000642375e4608 1 48 System.Int64[]

000006423757d600 1 48 System.Security.PermissionListSet

000006423756d6f0 1 48 System.IO.TextWriter+SyncTextWriter

0000064237556678 1 48 System.Text.UTF8Encoding

0000064237553fd0 1 48 System.Text.EncoderNLS

00000642375538e0 1 48 System.Text.InternalDecoderBestFitFallback

000006423753cdf8 1 48 System.Reflection.Assembly

000006423751b810 1 48 System.OperatingSystem

000006423757d420 1 56 System.Security.PermissionTokenFactory

000006423756dfb8 1 56 System.IO.Stream+NullStream

000006423755cbb8 1 56 System.Security.Util.TokenBasedSet

00000642375568e0 1 56 System.Text.UTF8Encoding+UTF8Encoder

00000642375d5088 1 72 System.LogLevel[]

0000064237579f90 3 72 System.Security.Permissions.SecurityPermission

000006423756e348 1 72 System.IO.__ConsoleStream

00000642375103b0 1 80 System.AppDomainSetup

0000064237550fa0 3 96 System.Globalization.CultureTableItem

00000642375258f0 1 104 System.Threading.Thread

00000642375e4838 4 128 System.Int32[]

000006423757c6f0 2 128 System.Security.PermissionSet

00000642375559e8 1 136 System.Text.SBCSCodePageEncoding

0000064237550e80 1 136 System.Globalization.CultureTable

0000064237525f68 1 136 System.Threading.ThreadAbortException

000006423750da40 1 136 System.ExecutionEngineException

000006423750d7c0 1 136 System.StackOverflowException

000006423750d680 1 136 System.OutOfMemoryException

0000064237551540 2 176 System.Globalization.CultureTableRecord

00000642375d48d0 1 200 System.SwitchStructure[]

000006423750f7a8 1 200 System.AppDomain

0000064237571d78 2 208 System.IO.StreamWriter

000006423754b208 2 256 System.Globalization.CultureInfo

0000064237509990 12 288 System.Object

000006423751d220 8 320 System.RuntimeType

00000642375505d0 2 432 System.Globalization.NumberFormatInfo

0000064237534d40 7 616 System.Collections.Hashtable

0000064237518f60 27 648 System.Int32

00000642375db1b8 10 1328 System.Char[]

0000064280131980 25 1600 CallBack

00000642375b05c8 7 2016 System.Collections.Hashtable+bucket[]

00000642801315c0 234 7488 BloatedObject

0000000000186780 238 12888 Free

00000642375d4358 8 18040 System.Object[]

000006423750c758 2088 83520 System.Text.StringBuilder

000006423750b800 8509 612640 System.String

00000642375dba38 237 119814344 System.Byte[]

Total 11466 objects

This shows that 237 System.Byte[] objects make up the bulk of the problem. Why are we creating those? If we can list those objects, we might find a root to one of them and get a better understanding of why they are being created.

0:003> !dumpheap -type System.Byte[]

         Address MT Size

0000000010351de0 00000642375dba38 24

0000000010353700 00000642375dba38 416

0000000010353b08 00000642375dba38 288

0000000020357048 00000642375dba38 512024

00000000203d4078 00000642375dba38 512024

0000000020451090 00000642375dba38 512024

… (a few hundred byte arrays of size 512024 here)

00000000274a1b68 00000642375dba38 512024

000000002751eb98 00000642375dba38 512024

total 237 objects

Statistics:

              MT Count TotalSize Class Name

00000642375dba38 237 119814344 System.Byte[]

Total 237 objects

!GCRoot will search handles, stacks and the freachable queue for pointers that ultimately keep the object in question alive. I’ll try it on the last one in the list:

0:003> !gcroot 000000002751eb98

Note: Roots found on stacks may be false positives. Run "!help gcroot" for

more info.

Scan Thread 0 OSTHread 5f0

Scan Thread 2 OSTHread 318

DOMAIN(000000000016F260):HANDLE(Strong):1dc1e30:Root:000000001038ac40(BloatedObject)->000000002751eb98(System.Byte[])

So a GCHandle keeps a “BloatedObject” alive (strong hint, eh), which keeps this Byte array alive. Running !gcroot on other arrays reveals the same thing. I’m suspecting a handle leak. Another way that makes this more clear is to run !GCHandles:

0:003> !gchandles

GC Handle Statistics:

Strong Handles: 245

Pinned Handles: 4

Async Pinned Handles: 0

Ref Count Handles: 0

Weak Long Handles: 25

Weak Short Handles: 1

Other Handles: 0

Statistics:

              MT Count TotalSize Class Name

0000064237579f90 1 24 System.Security.Permissions.SecurityPermission

0000064237509990 1 24 System.Object

00000642375201c0 1 40 System.SharedStatics

000006423757d600 1 48 System.Security.PermissionListSet

000006423753cdf8 1 48 System.Reflection.Assembly

000006423757c6f0 1 64 System.Security.PermissionSet

0000064237525f68 1 136 System.Threading.ThreadAbortException

000006423750da40 1 136 System.ExecutionEngineException

000006423750d7c0 1 136 System.StackOverflowException

000006423750d680 1 136 System.OutOfMemoryException

000006423750f7a8 1 200 System.AppDomain

00000642375258f0 2 208 System.Threading.Thread

0000064280131980 25 1600 CallBack

00000642801315c0 234 7488 BloatedObject

00000642375d4358 3 17440 System.Object[]

Total 275 objects

BloatedObject comes up with over 200 handles. So where are these handles stored, if they are stored at all? If a GCHandle is forgotten about before calling Free(), there is no way to release the memory it keeps alive. !GCHandleLeaks tries to help determine if you have a leak by a brute force search of memory for instances of any strong gc handles that exist. If it doesn’t find some, that is indicative of a leak. Let’s run it:

0:003> !gchandleleaks

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

GCHandleLeaks will report any GCHandles that couldn't be found in memory.

Strong and Pinned GCHandles are reported at this time. You can safely abort the

memory scan with Control-C or Control-Break.

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

Found 249 handles:

0000000001dc1200 0000000001dc1208 0000000001dc1210 0000000001dc1218

0000000001dc1220 0000000001dc1228 0000000001dc1230 0000000001dc1238

0000000001dc1240 0000000001dc1248 0000000001dc1250 0000000001dc1258

0000000001dc1260 0000000001dc1268 0000000001dc1270 0000000001dc1278

0000000001dc1280 0000000001dc1288 0000000001dc1290 0000000001dc1298

0000000001dc12a0 0000000001dc12a8 0000000001dc12b0 0000000001dc12b8

… (the list goes on)

Searching memory

Found 0000000001dc1ff8 at location 000000000012ce48

Found 0000000001dc1380 at location 0000000000145870

Found 0000000001dc1390 at location 0000000000145918

Found 0000000001dc1378 at location 00000000001557f8

Found 0000000001dc13f8 at location 000000000016fd50

Found 0000000001dc13f0 at location 0000000000182b70

Found 0000000001dc13b0 at location 000000000019eab8

Found 0000000001dc17f8 at location 000000000019fc08

Found 0000000001dc17e8 at location 00000000001a2148

…

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

Some handles were not found. If the number of not-found handles grows over the

lifetime of your application, you may have a GCHandle leak. This will cause

the GC Heap to grow larger as objects are being kept alive, referenced only

by the orphaned handle. If the number doesn't grow over time, note that there

may be some noise in this output, as an unmanaged application may be storing

the handle in a non-standard way, perhaps with some bits flipped. The memory

scan wouldn't be able to find those.

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

Didn't find 232 handles:

0000000001dc1200 0000000001dc1208 0000000001dc1210 0000000001dc1218

0000000001dc1220 0000000001dc1228 0000000001dc1230 0000000001dc1238

0000000001dc1240 0000000001dc1248 0000000001dc1250 0000000001dc1258

0000000001dc1260 0000000001dc1268 0000000001dc1270 0000000001dc1278

0000000001dc1280 0000000001dc1288 0000000001dc1290 0000000001dc1298

0000000001dc12a0 0000000001dc12a8 0000000001dc12b0 0000000001dc12b8

0000000001dc12c0 0000000001dc12c8 0000000001dc12d0 0000000001dc12d8

0000000001dc12e0 0000000001dc12e8 0000000001dc12f0 0000000001dc12f8

0000000001dc1300 0000000001dc1308 0000000001dc1310 0000000001dc1318

0000000001dc1320 0000000001dc1328 0000000001dc1330 0000000001dc1338

0000000001dc1340 0000000001dc1348 0000000001dc1350 0000000001dc1358

0000000001dc1360 0000000001dc1368 0000000001dc1370 0000000001dc1388

0000000001dc1800 0000000001dc1808 0000000001dc1810 0000000001dc1818

0000000001dc1820 0000000001dc1828 0000000001dc1830 0000000001dc1838

0000000001dc1840 0000000001dc1848 0000000001dc1850 0000000001dc1858

0000000001dc1860 0000000001dc1868 0000000001dc1870 0000000001dc1878

0000000001dc1880 0000000001dc1888 0000000001dc1890 0000000001dc1898

0000000001dc18a0 0000000001dc18a8 0000000001dc18b0 0000000001dc18b8

…

Let’s look at one of the handles that wasn’t found. We can view the object it keeps alive by dereferencing it. I’ll use the handy poi debugger command to reduce the number of pointers I have to type:

0:003> !dumpobj poi(0000000001dc18b8)

Name: BloatedObject

MethodTable: 00000642801315c0

EEClass: 0000064280163cd0

Size: 32(0x20) bytes

 (C:\pub\eetwc\windowh.exe)

Fields:

              MT Field Offset Type VT Attr Value Name

000006423756d248 4000001 8 System.IO.TextWriter 0 instance 0000000010353c28 tw

00000642375dba38 4000002 10 System.Byte[] 0 instance 0000000022e50080 ba

Naturally, it’s a BloatedObject. And the byte array is in field ba. You could run the new !DumpArray command on ba, but I don’t recommend it, it is too boring for such a large array! We’ll settle for !DumpObj (shorthand !do):

0:003> !do 22e50080

Name: System.Byte[]

MethodTable: 00000642375dba38

EEClass: 00000642376efd28

Size: 512024(0x7d018) bytes

Array: Rank 1, Number of elements 512000, Type Byte

Element Type: System.Byte

Fields:

None

Who is creating these objects? Let’s try and find a handle to that. One way would be to run ILDASM.EXE and dump the disassembly to a file, then search for instances of BloatedObject to see where they get created. I’ll try just setting a breakpoint on the constructor of BloatedObject (if one exists).

0:003> !name2ee windowh.exe BloatedObject..ctor

Module: 00000000001b0300 (windowh.exe)

Token: 0x0000000006000009

MethodDesc: 0000064280131508

Name: BloatedObject..ctor(System.IO.TextWriter)

JITTED Code Address: 00000642801706e0

We know the code is jitted, so we could just use the debugger’s built-in bp command at 642801706e0. But !bpmd works even if the code isn’t jitted yet, so I tend to use it for managed code.

0:003> !bpmd windowh.exe BloatedObject..ctor

Found 1 methods...

MethodDesc = 0000064280131508

Method is jitted, placing breakpoint at code addr 00000642801706e0

0:003> g

Breakpoint 0 hit

windowh!BloatedObject..ctor(System.IO.TextWriter):

00000642`801706e0 53 push rbx

The managed stack shows we are being called from App.Work():

0:000> !clrstack

OS Thread Id: 0x650 (0)

Child-SP RetAddr Call Site

000000000012e328 00000642801705aa BloatedObject..ctor(System.IO.TextWriter)

000000000012e330 0000064280170519 App.Work()

000000000012e390 000006426ec8839e App.Main()

Without digging too much further, I can tell by looking at App.Work() that a handle to the BloatedObject we just created is initialized:

0:000> !u 00000642801705aa

Normal JIT generated code

App.Work()

Begin 0000064280170570, size 12d

00000642`80170570 push rbx

00000642`80170571 push rsi

00000642`80170572 push rdi

00000642`80170573 sub rsp,0x40

00000642`80170577 xor eax,eax

00000642`80170579 mov [rsp+0x38],rax

00000642`8017057e xor eax,eax

00000642`80170580 mov [rsp+0x30],rax

00000642`80170585 call mscorlib_ni!System.Console.get_Out() (0000064236cd6a10)

00000642`8017058a mov rdi,rax

00000642`8017058d mov rcx,0x642801315c0 (MT: BloatedObject)

00000642`80170597 call mscorwks!JIT_TrialAllocSFastMP_InlineGetThread (000006426ec6d350)

00000642`8017059c mov rbx,rax

00000642`8017059f mov rdx,rdi

00000642`801705a2 mov rcx,rbx

00000642`801705a5 call CLRStub[EntryPointStub]@64280170270 (0000064280170270) (BloatedObject..ctor(System.IO.TextWriter), mdToken: 06000009)

>>> 00000642`801705aa mov edx,0x501

00000642`801705af mov ecx,0x1

00000642`801705b4 call mscorwks!JIT_GetSharedNonGCStaticBase_InlineGetAppDomain (000006426ec6d260)

00000642`801705b9 mov r8d,0x2

00000642`801705bf mov rdx,rbx // rdx = BloatedObject, arg1 for GCHandle ctor

00000642`801705c2 lea rcx,[rsp+0x28] // rsp+0x28 is the GCHandle

00000642`801705c7 call mscorlib_ni!System.Runtime.InteropServices.GCHandle..ctor(System.Object, System.Runtime.InteropServices.GCHandleType) (0000064236cd9370)

00000642`801705cc mov rax,[rsp+0x28]

00000642`801705d1 mov [rsp+0x38],rax

…

(I omitted code bytes in the output above for better formatting.)

We never see any more mention in the function of the GCHandle, but it does get passed to another function. Maybe that function is supposed to call Free()? I’ll leave that as an exercise for the reader.

 

 

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

Here is the windowh.cs code:

 

using System;
using System.Runtime.InteropServices;
using System.IO;
using System.Text;
using System.Threading;

public delegate bool CallBack( int handle, IntPtr param );

public class LibWrap
{
// Passes a managed object as an LPARAM type.
// Declares a managed prototype for the unmanaged function.
[ DllImport( "user32.dll" )]
public static extern bool EnumWindows( CallBack cb, IntPtr param );

[DllImport("user32.dll", SetLastError=true, CharSet=CharSet.Auto)]
public static extern int GetWindowTextLength(IntPtr hWnd);

[DllImport("user32.dll", SetLastError=true, CharSet=CharSet.Auto)]
public static extern int GetWindowText(IntPtr hWnd, [Out] StringBuilder lpString, int nMaxCount);
}

public class BloatedObject
{
public TextWriter tw;
public Byte[] ba;
public BloatedObject(TextWriter t)
{
tw = t;
ba = new Byte[500*1024];
// Do some "work"
for(int i=0;i<(500*1024);i++)
{
ba[i] = (byte) (i%256);
}
}
}

public class App
{
public static int NamedWindowCount = 0;

public static void Main()
{
while(true)
{
Work();
Thread.Sleep(500);
}
}
public static void Work()
{
TextWriter tw = System.Console.Out;
BloatedObject bo = new BloatedObject(tw);
GCHandle gch = GCHandle.Alloc( bo );
CallBack cewp = new CallBack( CaptureEnumWindowsProc );

// Platform invoke prevents the delegate from being garbage
// collected before the call ends.

NamedWindowCount = 0;
LibWrap.EnumWindows( cewp, (IntPtr)gch );
tw.Write ( App.NamedWindowCount + "\n");

// Don't handles free themselves? I will assume so. :p
// gch.Free();
}

public static string GetText(IntPtr hWnd)
{
// Allocate correct string length first
int length = LibWrap.GetWindowTextLength(hWnd);
StringBuilder sb = new StringBuilder(length + 1);
LibWrap.GetWindowText(hWnd, sb, sb.Capacity);
return sb.ToString();
}

private static bool CaptureEnumWindowsProc( int handle, IntPtr param )
{
GCHandle gch = (GCHandle)param;
BloatedObject bo = (BloatedObject)gch.Target;
String name = App.GetText((IntPtr)handle);
if (name.Length > 0)
{
App.NamedWindowCount++;
}

bo.tw.Write( "." );
return true;
}
}