dotnet clr: I'm trying to use windbg's "!htrace" command to find the source of a
handle leak in a C# app I have. To understand the !htrace output, I
have created a little sample app that just opens a file:


static void Main(string[] args)
{
FileStream fs =3D File.OpenRead(@"c:\foo.txt");
Console.ReadLine(); // don't exit app
}

I then started my app, and I can see in process explorer that the file
handle for "foo.txt" is 0x2FC. So I start windbg and attach to the
app, and do "!htrace 2fc", which complains about symbols for
mscorlib.dll, but does give a stack trace (below).

Unfortunately, the htrace stack isn't very helpful. I was hoping to
see the symbols from my C# code somewhere in there (like
"ScratchConsoleApp.Class1.Main=AD").

I asked this question over in the microsoft.public.windbg group and got
an explanation about why my C# symbols don't show up in the !htrace
stack dump. I understand it, but I am still wondering if it's possible
to translate an address from the !htrace stack into a JIT-ed method.
In other words, I just want to figure out what code was responsible for
allocating the handle.

It looks like the !IP2MD command does something similar but when I
entered some addresses from the stack, it said it was not a valid
address (or something to that effect).

Can this be done?


PS> For what it's worth, I have loaded the SOS extensions and I can get
a full C# stack trace from !ClrStack just fine (also below).



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


0:000> !htrace 2fc
------------------------------=AD--------
Handle =3D 0x000002FC - OPEN
Thread ID =3D 0x00000A58, Process ID =3D 0x00000EB8


0x0208A0D5: +0x0208A0D5
*** WARNING: Unable to verify checksum for
c:\windows\assembly\nativeimag=ADes1_v1.1.4322\mscorlib\1.0.500=AD0.0__b77a=
5c561934e089_4cd9dcc5=AD\mscorlib.dll

*** ERROR: Module load completed but symbols could not be loaded for
c:\windows\assembly\nativeimag=ADes1_v1.1.4322\mscorlib\1.0.500=AD0.0__b77a=
5c561934e089_4cd9dcc5=AD\mscorlib.dll

0x799B49DD: mscorlib_79990000+0x000249DD
0x799DE5BE: mscorlib_79990000+0x0004E5BE
0x791D94BC: mscorwks!CallDescrWorker+0x000=AD00030
0x791ED194: mscorwks!MethodDesc::CallDescr=AD+0x000001B8
0x791ED54B: mscorwks!MethodDesc::CallDescr=AD+0x0000004F
0x791ED5B9: mscorwks!MethodDesc::Call+0x00=AD000097
0x7921D82B: mscorwks!ClassLoader::CanAcces=ADs+0x000001D6
0x7921DA72: mscorwks!ClassLoader::ExecuteM=ADainMethod+0x0000049D

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

0:000> !ClrStack
Thread 0
ESP EIP
0x0012f5d8 0x7c90eb94 [FRAME: NDirectMethodFrameStandalone] [DEFAULT]
I4 System.IO.__ConsoleStream.Read=ADFile(I,Ptr UI1,I4,ByRef I4,I)
0x0012f5f4 0x79aa78c9 [DEFAULT] I4
System.IO.__ConsoleStream.Read=ADFileNative(I,SZArray UI1,I4,I4,I4,ByRef

I4)
0x0012f620 0x79aa7762 [DEFAULT] [hasThis] I4
System.IO.__ConsoleStream.Read=AD(SZArray UI1,I4,I4)
0x0012f640 0x799ea04f [DEFAULT] [hasThis] I4
System.IO.StreamReader.ReadBuf=ADfer()
0x0012f64c 0x799e9f02 [DEFAULT] [hasThis] String
System.IO.StreamReader.ReadLin=ADe()
0x0012f660 0x79ab15ab [DEFAULT] [hasThis] String
System.IO.TextReader/SyncTextR=ADeader.ReadLine()
0x0012f668 0x79a097a5 [DEFAULT] String System.Console.ReadLine()
0x0012f68c 0x0251007b [DEFAULT] Void
ScratchConsoleApp.Class1.Main(=ADSZArray String)
at [+0x23] [+0x10] c:\dev\test\cs\scratchconsolea=ADpp\class1.cs:12
0x0012f8b0 0x791d94bc [FRAME: GCFrame]
0x0012f9b0 0x791d94bc [FRAME: GCFrame]
0x0012fa94 0x791d94bc [FRAME: GCFrame]

What happens if you do !u on one of these return addresses?
If that doesn't work, what about plain 'u' - does this produce
something that looks like valid code?

You could also try !address <addr> to see how windbg
classifies this address.

--
This posting is provided "AS IS" with no warranties, and confers no
rights.

Well, it gives fairly useful info. Here's the call stack I get from
!htrace:

0x0208A0D5: +0x0208A0D5
0x799B49DD: mscorlib_79990000+0x000249DD
0x799DE5BE: mscorlib_79990000+0x0004E5BE
0x791D94BC: mscorwks!CallDescrWorker+0x00000030
0x791ED194: mscorwks!MethodDesc::CallDescr+0x000001B8
0x791ED54B: mscorwks!MethodDesc::CallDescr+0x0000004F
0x791ED5B9: mscorwks!MethodDesc::Call+0x00000097
0x7921D82B: mscorwks!ClassLoader::CanAccess+0x000001D6
0x7921DA72: mscorwks!ClassLoader::ExecuteMainMethod+0x0000049D

The very first entry (0x0208A0D5) looks like it's probably legit code
(?) but I don't recognize anything in it:

0:003> !u 0x0208A0D5
Will print '>>> ' at address: 0x0208a0d5
Unmanaged code
0208a0d5 50 push eax
0208a0d6 e85662887a call ntdll!RtlGetLastWin32Error (7c910331)
0208a0db 894374 mov [ebx+0x74],eax
0208a0de 58 pop eax
0208a0df c6430401 mov byte ptr [ebx+0x4],0x1
0208a0e3 833d14fb3d7900 cmp dword ptr [mscorwks!g_TrapReturningThreads
(793dfb14)],0x0
0208a0ea 751a jnz 0208a106
0208a0ec 8d66e8 lea esp,[esi-0x18]
0208a0ef 897b08 mov [ebx+0x8],edi
0208a0f2 83c408 add esp,0x8

When I put in the next 2 return addresses, I get good information like
I would expect:

0:003> !u 0x799B49DD
Will print '>>> ' at address: 0x799b49dd
preJIT generated code
[DEFAULT] [hasThis] Void System.IO.FileStream..ctor(String,ValueClass
System.IO.FileMode,ValueClass System.IO.FileAccess,ValueClass
System.IO.FileShare,I4,Boolean,String,Boolean)
Begin 0x799b4768, size 0x6ef
(etc...)

0:003> !u 0x799DE5BE
Will print '>>> ' at address: 0x799de5be
preJIT generated code
[DEFAULT] [hasThis] Void System.IO.FileStream..ctor(String,ValueClass
System.IO.FileMode,ValueClass System.IO.FileAccess,ValueClass
System.IO.FileShare)
Begin 0x799de590, size 0x33
(etc...)

Those look like what I want, but the next entry up the stack confuses
me:

0:003> !u 0x791D94BC
Will print '>>> ' at address: 0x791d94bc
Unmanaged code
791d94bc c9 leave
791d94bd c21000 ret 0x10
791d94c0 a140f73d79 mov eax,[mscorwks!SystemDomain::m_pSystemDomain
(793df740)]
791d94c5 8b80bc020000 mov eax,[eax+0x2bc]
791d94cb 85c0 test eax,eax
791d94cd 0f84e15c0700 je mscorwks!SystemDomain::SystemModule+0xf
(7924f1b4)
791d94d3 8b4034 mov eax,[eax+0x34]
791d94d6 c3 ret
791d94d7 55 push ebp
791d94d8 8bec mov ebp,esp

I was hoping this next entry in the stack would be my Main( ) routine.
I've tried !u on some of the numbers that look like addresses here, but
none of them look like code I recognize.


I also tried !address on some of the addresses to see what that showed.
I'm not sure what to make of this but it looks like most of the stack
frames are in mscorlib.dll and mscorwks.dll -- I didn't see any that
were in my EXE:


0:003> !address 0x0208A0D5
02080000 : 0208a000 - 00001000
Type 00020000 MEM_PRIVATE
Protect 00000040 PAGE_EXECUTE_READWRITE
State 00001000 MEM_COMMIT
Usage RegionUsageIsVAD
0:003> !address 0x799B49DD
79990000 : 79992000 - 001e8000
Type 01000000 MEM_IMAGE
Protect 00000020 PAGE_EXECUTE_READ
State 00001000 MEM_COMMIT
Usage RegionUsageImage
FullPath
c:\windows\assembly\nativeimages1_v1.1.4322\mscorlib\1.0.5000.0__b77a5c561934e089_4cd9dcc5\mscorlib.dll
0:003> !address 0x799DE5BE
79990000 : 79992000 - 001e8000
Type 01000000 MEM_IMAGE
Protect 00000020 PAGE_EXECUTE_READ
State 00001000 MEM_COMMIT
Usage RegionUsageImage
FullPath
c:\windows\assembly\nativeimages1_v1.1.4322\mscorlib\1.0.5000.0__b77a5c561934e089_4cd9dcc5\mscorlib.dll
0:003> !address 0x791D94BC
791b0000 : 791b1000 - 0022e000
Type 01000000 MEM_IMAGE
Protect 00000020 PAGE_EXECUTE_READ
State 00001000 MEM_COMMIT
Usage RegionUsageImage
FullPath
C:\WINDOWS\Microsoft.NET\Framework\v1.1.4322\mscorwks.dll
0:003> !address 0x791ED194
791b0000 : 791b1000 - 0022e000
Type 01000000 MEM_IMAGE
Protect 00000020 PAGE_EXECUTE_READ
State 00001000 MEM_COMMIT
Usage RegionUsageImage
FullPath
C:\WINDOWS\Microsoft.NET\Framework\v1.1.4322\mscorwks.dll
0:003> !address 0x791ED54B
791b0000 : 791b1000 - 0022e000
Type 01000000 MEM_IMAGE
Protect 00000020 PAGE_EXECUTE_READ
State 00001000 MEM_COMMIT
Usage RegionUsageImage
FullPath
C:\WINDOWS\Microsoft.NET\Framework\v1.1.4322\mscorwks.dll


So I guess I'm still wondering if there's a way to figure out that my
Main( ) routine was in the call stack of the file handle allocation.

Well, I've made a little more progress. I changed my app to look like
this:

static void Main(string[] args)
{
Function1();
}

static void Function1()
{
Function2();
}

static void Function2()
{
FileStream fs = File.OpenRead(@"c:\foo.txt");
Console.ReadLine();
}

And I get a call stack that looks like this:

0x0208A0D5: +0x0208A0D5
*** WARNING: Unable to verify checksum for
c:\windows\assembly\nativeimages1_v1.1.4322\mscorlib\1.0.5000.0__b77a5c561934e089_4cd9dcc5\mscorlib.dll
*** ERROR: Module load completed but symbols could not be loaded for
c:\windows\assembly\nativeimages1_v1.1.4322\mscorlib\1.0.5000.0__b77a5c561934e089_4cd9dcc5\mscorlib.dll
0x799B49DD: mscorlib_79990000+0x000249DD
0x799DE5BE: mscorlib_79990000+0x0004E5BE
0x02510089: +0x02510089
0x02510065: +0x02510065
0x791D94BC: mscorwks!CallDescrWorker+0x00000030
0x791ED194: mscorwks!MethodDesc::CallDescr+0x000001B8
0x791ED54B: mscorwks!MethodDesc::CallDescr+0x0000004F
0x791ED5B9: mscorwks!MethodDesc::Call+0x00000097

And those 2 new entries show up as useful information:

0:003> !u 0x02510065
Loaded Son of Strike data table version 5 from
"C:\WINDOWS\Microsoft.NET\Framework\v1.1.4322\mscorwks.dll"
Will print '>>> ' at address: 0x02510065
Normal JIT generated code
[DEFAULT] Void ScratchConsoleApp.Class1.Main(SZArray String)
(etc...)

0:003> !u 0x02510089
Will print '>>> ' at address: 0x02510089
Normal JIT generated code
[DEFAULT] Void ScratchConsoleApp.Class1.Function1()
(etc...)

It looks like the last call (Function2) still isn't showing up for some
reason... presumably that's why Main didn't show up in my original
example.

I'm still curious how to get the address of Function2, but this should
get me a lot further.

Stack traces collected by appverifier handle checks (or other similar
methods like gflags +ust) are not 100% reliable. They can easily be
broken by FPO optimizations for example. Before XP SP2 the OS
binaries were compiled with FPO so tools like !htrace or umdh were
a lot less useful then.

Something similar could be happening here - if the JITted code doesn't
created standard EBP frames then stack trace can be truncated or
might be missing some frames. You could look at the prolog code
with !u to see if this is the case.

Also, you could try disabling JIT optimizations by either using a debug
build or creating a .ini file as described here:

http://msdn.microsoft.com/library/default.asp?url=/library/en-us/cpguide/html/cpconmakingimageeasiertodebug.asp

--
This posting is provided "AS IS" with no warranties, and confers no
rights.

[quoted text, click to view]