Microtip: Stack corruption? windbg dps to the rescue.

Everyone encounters it sooner or later. A crash with a corrupted callstack. You know what the stack pointer is, but it is clearly not unwinding properly. With a little elbow grease I've found the WinDbg command "dps" to be extremely helpful in this situation.

With this, you're telling the debugger to dump data, in "pointer size" chunks, and also try to match against loaded symbols. You'll quickly start seeing *some* sort of callstack with this display. Now the trick is to sort through the various locations to find the actual callstack. Windbg can help with this as well, you can tell it where the stack actually starts using the kn = [base address] command to verify if what you think is a good stack really is one. The trick is to look at address offsets. Pretty much all real function return addresses will have a non-zero offset. Usually, there are a small enough number of these that you can just brute force it -- like you see me doing (although I skipped a few for brevity). If there are a ton of these potential addresses, it may require additional detective work. Also, one important gotcha -- there may appear to be more than one valid stack, so at this point you need to read the source code or disassembly, and determine what makes the most sense. Also, knowing the ABI of the platform you're working on is invaluable.

This is a little tedious, but the worst bugs only rarely repro and can hold up a product release...

0:000> kn
 # Child-SP          RetAddr           Call Site
00 0000006d`6dcdf310 0000006d`6dd80000 ntdll!RtlEnterCriticalSection+0x22
01 0000006d`6dcdf318 6f6e6d6c`402c0062 0x0000006d`6dd80000
02 0000006d`6dcdf320 00000000`00000470 0x6f6e6d6c`402c0062
03 0000006d`6dcdf328 00000000`00000480 0x470
04 0000006d`6dcdf330 00000000`00000000 0x480
0:000> * Oh noooooooo!!!!
0:000> dps 0000006d`6dcdf310
0000006d`6dcdf310  0000006d`6dd80000
0000006d`6dcdf318  6f6e6d6c`402c0062
0000006d`6dcdf320  00000000`00000470
0000006d`6dcdf328  00000000`00000480
0000006d`6dcdf330  00000000`00000000
0000006d`6dcdf338  0000006d`6dcdf428
0000006d`6dcdf340  77767574`73727170
0000006d`6dcdf348  00007fff`ba9738d8 KERNELBASE!VirtualQuery+0x28
0000006d`6dcdf350  87868584`83828180
0000006d`6dcdf358  8f9e8d9c`8b9a8988
0000006d`6dcdf360  97969594`93929190
0000006d`6dcdf368  ff9e9d9c`9b9a9998
0000006d`6dcdf370  00000000`00000030
0000006d`6dcdf378  0000006d`6dcdf3a8
0000006d`6dcdf380  0000006d`6dcdf440
0000006d`6dcdf388  00007fff`ba983552 KERNELBASE!SetUnhandledExceptionFilter+0x24a
0:000> dps
0000006d`6dcdf390  e7e6e5e4`e3e2e1e0
0000006d`6dcdf398  efeeedec`ebeae9e8
0000006d`6dcdf3a0  d7f6f5f4`f3f2f1f0
0000006d`6dcdf3a8  00000000`00000030
0000006d`6dcdf3b0  00000000`0000021a
0000006d`6dcdf3b8  00000000`00000000
0000006d`6dcdf3c0  00007ff6`d6290000 MicroLogUtil!__ImageBase
0000006d`6dcdf3c8  01000000`00000080
0000006d`6dcdf3d0  00000000`00095000
0000006d`6dcdf3d8  00007fff`bd24dcb7 ntdll!RtlDecodePointer+0x27
0000006d`6dcdf3e0  00000000`00000000
0000006d`6dcdf3e8  00000000`00000000
0000006d`6dcdf3f0  00000000`00000000
0000006d`6dcdf3f8  00000000`00000000
0000006d`6dcdf400  00000000`00000000
0000006d`6dcdf408  00007ff6`d62a5ec0 MicroLogUtil!__CxxUnhandledExceptionFilter
0:000> dps
0000006d`6dcdf410  000012b3`e0966000
0000006d`6dcdf418  00007fff`ba983476 KERNELBASE!SetUnhandledExceptionFilter+0x16e
0000006d`6dcdf420  00000000`00000000
0000006d`6dcdf428  00000000`959f04b3
0000006d`6dcdf430  0000006d`6dd86480
0000006d`6dcdf438  00007ff6`d6295a90 MicroLogUtil!_lock+0x50
0000006d`6dcdf440  00007ff6`d6290000 MicroLogUtil!__ImageBase
0000006d`6dcdf448  00000000`00095000
0000006d`6dcdf450  03810381`01000000
0000006d`6dcdf458  00000000`005a0058
0000006d`6dcdf460  0000006d`6dcdf468
0000006d`6dcdf468  00007ff6`d6299232 MicroLogUtil!_heap_alloc_dbg_impl+0x32
0000006d`6dcdf470  00000000`00000004
0000006d`6dcdf478  00007fff`bd2e1ebc ntdll!RtlZeroHeap+0x6e8
0000006d`6dcdf480  006b0073`00690064
0000006d`6dcdf488  0075006c`006f0056
0:000> dps
0000006d`6dcdf490  005c0032`0065006d
0000006d`6dcdf498  005c0070`006d0074
0000006d`6dcdf4a0  00720063`0069004d
0000006d`6dcdf4a8  0067006f`10070017
0000006d`6dcdf4b0  00000000`6dd86310
0000006d`6dcdf4b8  00007fff`bd2be5e7 ntdll!memset+0x1fa27
0000006d`6dcdf4c0  00000000`00000000
0000006d`6dcdf4c8  00000000`00000001
0000006d`6dcdf4d0  0000006d`6dd80000
0000006d`6dcdf4d8  00007ff6`d6299ab9 MicroLogUtil!_nh_malloc_dbg_impl+0x39
0000006d`6dcdf4e0  00000000`00000030
0000006d`6dcdf4e8  00000000`00000001
0000006d`6dcdf4f0  00000000`00000000
0000006d`6dcdf4f8  00007fff`00000000
0000006d`6dcdf500  0000006d`6dcdf560
0000006d`6dcdf508  00000000`00000000
0:000> dps
0000006d`6dcdf510  00000000`00000000
0000006d`6dcdf518  02100210`02100210
0000006d`6dcdf520  00000000`00000101
0000006d`6dcdf528  00007ff6`d6299a49 MicroLogUtil!_nh_malloc_dbg+0x49
0000006d`6dcdf530  00000000`00000030
0000006d`6dcdf538  00007ff6`00000000
0000006d`6dcdf540  00000000`00000001
0000006d`6dcdf548  00000000`00000000
0000006d`6dcdf550  00000000`00000000
0000006d`6dcdf558  0000006d`6dcdf560
0000006d`6dcdf560  00000000`00000000
0000006d`6dcdf568  00000000`00000000
0000006d`6dcdf570  00000000`00000000
0000006d`6dcdf578  00007ff6`d6294b7a MicroLogUtil!malloc+0x2a
0000006d`6dcdf580  00000000`00000030
0000006d`6dcdf588  0000006d`00000000
0:000> dps
0000006d`6dcdf590  0000006d`00000001
0000006d`6dcdf598  00000000`00000000
0000006d`6dcdf5a0  00000000`00000000
0000006d`6dcdf5a8  00007ff6`d6295db2 MicroLogUtil!_unlock+0x22
0000006d`6dcdf5b0  00000000`00000000
0000006d`6dcdf5b8  02100302`00000030
0000006d`6dcdf5c0  00007ff6`00000000
0000006d`6dcdf5c8  00007ff6`d62915e6 MicroLogUtil!AstNodeCreate+0x26
0000006d`6dcdf5d0  00000000`00000030
0000006d`6dcdf5d8  00007ff6`d62999b4 MicroLogUtil!_msize_dbg+0x234
0000006d`6dcdf5e0  0000006d`00000004
0000006d`6dcdf5e8  00007ff6`d62aa677 MicroLogUtil!_setmbcp_nolock+0x447
0000006d`6dcdf5f0  00000000`00000000
0000006d`6dcdf5f8  00007fff`bd265a63 ntdll!RtlEncodePointer+0x27
0000006d`6dcdf600  00000000`00000100
0000006d`6dcdf608  00007ff6`d62919e8 MicroLogUtil!AstStateInit+0x48
0:000> dps
0000006d`6dcdf610  00000000`00000000
0000006d`6dcdf618  00007ff6`d631bec0 MicroLogUtil!pairNode `RTTI Type Descriptor'+0x5a0
0000006d`6dcdf620  00000000`00000001
0000006d`6dcdf628  0000006d`6dcdf680
0000006d`6dcdf630  00000000`00000000
0000006d`6dcdf638  00007ff6`d6291115 MicroLogUtil!ProcessFile+0x85
0000006d`6dcdf640  0000006d`6dcdf6c0
0000006d`6dcdf648  0000006d`6dd827c8
0000006d`6dcdf650  00000000`00000000
0000006d`6dcdf658  00007fff`bd265a63 ntdll!RtlEncodePointer+0x27
0000006d`6dcdf660  00000000`00000002
0000006d`6dcdf668  00007ff6`d6307020 MicroLogUtil!`string'
0000006d`6dcdf670  0000006d`00000000
0000006d`6dcdf678  00000000`00000000
0000006d`6dcdf680  00000000`00000000
0000006d`6dcdf688  00007ff6`d62a5414 MicroLogUtil!__crtSetUnhandledExceptionFilter+0x14
0:000> dps
0000006d`6dcdf690  00000000`00000000
0000006d`6dcdf698  00000000`00000000
0000006d`6dcdf6a0  00000000`00000000
0000006d`6dcdf6a8  00000000`00000000
0000006d`6dcdf6b0  00007ff6`d62a7810 MicroLogUtil!_RTC_Terminate
0000006d`6dcdf6b8  00007ff6`d62a5f50 MicroLogUtil!__CxxSetUnhandledExceptionFilter+0x10
0000006d`6dcdf6c0  00000000`00000000
0000006d`6dcdf6c8  00000000`00000000
0000006d`6dcdf6d0  00000000`00000000
0000006d`6dcdf6d8  00000000`00000000
0000006d`6dcdf6e0  00000000`00000000
0000006d`6dcdf6e8  00000000`00000000
0000006d`6dcdf6f0  00000000`00000000
0000006d`6dcdf6f8  00000000`00000000
0000006d`6dcdf700  00000000`00000000
0000006d`6dcdf708  00000000`00000000
0:000> * Hmmm, that looks a little more promising...
0:000> * Looking for offsets that make sense... is it the VirtualQuery+0x28???
0:000> kn = 0000006d`6dcdf348
 # Child-SP          RetAddr           Call Site
00 0000006d`6dcdf348 00007fff`ba9738d8 ntdll!RtlEnterCriticalSection+0x22
01 0000006d`6dcdf350 00007fff`ba983552 KERNELBASE!VirtualQuery+0x28
02 0000006d`6dcdf390 00007fff`ba983476 KERNELBASE!SetUnhandledExceptionFilter+0x24a
03 0000006d`6dcdf420 00007ff6`d62a5414 KERNELBASE!SetUnhandledExceptionFilter+0x16e
04 0000006d`6dcdf690 00007ff6`d62a5f50 MicroLogUtil!__crtSetUnhandledExceptionFilter+0x14
05 0000006d`6dcdf6c0 00000000`00000000 MicroLogUtil!__CxxSetUnhandledExceptionFilter+0x10
0:000> * Hmm, doesn't look like it.  How about  KERNELBASE!SetUnhandledExceptionFilter+0x24a?
0:000> kn = 0000006d`6dcdf388
 # Child-SP          RetAddr           Call Site
00 0000006d`6dcdf388 00007fff`ba983552 ntdll!RtlEnterCriticalSection+0x22
01 0000006d`6dcdf390 00007fff`ba983476 KERNELBASE!SetUnhandledExceptionFilter+0x24a
02 0000006d`6dcdf420 00007ff6`d62a5414 KERNELBASE!SetUnhandledExceptionFilter+0x16e
03 0000006d`6dcdf690 00007ff6`d62a5f50 MicroLogUtil!__crtSetUnhandledExceptionFilter+0x14
04 0000006d`6dcdf6c0 00000000`00000000 MicroLogUtil!__CxxSetUnhandledExceptionFilter+0x10
0:000> * Nope.  Okay... skipping ahead to the correct one:  MicroLogUtil!_lock+0x50
0:000> kn = 0000006d`6dcdf438
 # Child-SP          RetAddr           Call Site
00 0000006d`6dcdf438 00007ff6`d6295a90 ntdll!RtlEnterCriticalSection+0x22
01 0000006d`6dcdf440 00007ff6`d6299232 MicroLogUtil!_lock+0x50
02 0000006d`6dcdf470 00007ff6`d6299ab9 MicroLogUtil!_heap_alloc_dbg_impl+0x32
03 0000006d`6dcdf4e0 00007ff6`d6299a49 MicroLogUtil!_nh_malloc_dbg_impl+0x39
04 0000006d`6dcdf530 00007ff6`d6294b7a MicroLogUtil!_nh_malloc_dbg+0x49
05 0000006d`6dcdf580 00007ff6`d62915e6 MicroLogUtil!malloc+0x2a
06 0000006d`6dcdf5d0 00007ff6`d62919e8 MicroLogUtil!AstNodeCreate+0x26
07 0000006d`6dcdf610 00007ff6`d6291115 MicroLogUtil!AstStateInit+0x48
08 0000006d`6dcdf640 00007ff6`d6291473 MicroLogUtil!ProcessFile+0x85
09 0000006d`6dcdf730 00007ff6`d629549c MicroLogUtil!wmain+0x33
0a 0000006d`6dcdf770 00007ff6`d62955de MicroLogUtil!__tmainCRTStartup+0xec
0b 0000006d`6dcdf7c0 00007fff`bcc916ad MicroLogUtil!wmainCRTStartup+0xe
0c 0000006d`6dcdf7f0 00007fff`bd2734a5 KERNEL32!BaseThreadInitThunk+0xd
0d 0000006d`6dcdf820 00000000`00000000 ntdll!RtlUserThreadStart+0x1d
0:000> * Hey yo!  That's looking like a correct stack!

Native or Managed?

I want to start a project with a friend to upgrade the UI of windbg. It's not too bad right now, but more importantly I think it could be so much more.

So here's the problem: Making an "awesome" UI is much easier in C# than in C++ using native code. However, the APIs for the debugging engine are all COM based and there aren't bindings for C#. There are a few unofficial bindings, but nothing really available. So, we'd probably have to roll our own bindings, which is not something I want to do.

I think a hybrid option would be to use C++/CLI. At least we'd be able to use the COM methods pretty easily and maybe even use the header files without any modification. We could also then use the managed API for the GUI. I think I'm going to suggest this as the route to take.

There's some concerns that .Net wouldn't be installed on all the environments you'd want to use the new UI but I don't think that should stop us. It's pretty easy to install and a version of .Net ships with modern Windows distributions already.

A bit to think about, but I think the C++/CLI approach is going to be the way to go. It will get me writing code faster and having SOMETHING working much faster than a native solution. I've recently worked on native GDI+ code and although it's nicer than GDI it's still not something I'd want to force myself on for a GUI intensive project.

WinDBG microtip

I constantly find myself reading variables and structures the hard way in WinDBG... Why don't I ever just use the "??" command!?

DBH: How the Debugger Help utility can help.

My work in servicing Windows usually results in a bunch of "This component is crashing, please investigate it" questions. One of the first things I always need to do is locate the source code for that component. Lately, I've been using a nice little utility, dbh.exe to accomplish this.

dbh.exe is included with the Windows Debugging tools and it basically provides a command line interface to the dbghelp.dll. For code-finding purposes I'll use the "src" option.

Here's the output on a small utility I'm working on (it's much more useful for large source bases (like Windows) where the code is spread out in many separate source code depots):

c:\>dbh d:\data\projects\base\windd\Debug\windd.exe src *.c*

d:\data\projects\base\windd\windd\main.cpp
d:\data\projects\base\windd\windd\globals.cpp
d:\data\projects\base\windd\windd\datastream.cpp
d:\data\projects\base\windd\windd\commands.cpp
...

I had to cut off some more of the display because this is on a development machine with private Windows symbols -- it displays all the source paths for the Visual Studio CRT, Windows source files that define various GUIDs used by my application, and other miscellaneous junk.

The most important thing I tell people to answer the "Where does the code for XYZ live?" question is: "Check out dbh.exe in the debugging tools." If you have the symbols to your code it's amazing what you can do with the default tools. There are a few features I'd like to see (disassembly of a function with line data, etc...) and perhaps I'll be making my own version of dbh.exe shortly.

There's so much to dbh.exe and I haven't even scratched the surface with this post. I hope you find it as useful as I do.

No More Memory Leaks!

Introduction

One of the most common problems in coding is tracking down memory leaks. I remember working at IGT and trying to track down a really nasty problem -- we had some code that seemed to leak a very small amount of memory. On most products you may actually just yell, "Ship It!" and be done with it but this wasn't an option. The code in question had to run for a very long time -- multiple years depending on the quality of power at the location. A slot machine handles money and having software dealing with money slowly consume all the available memory on a system is not acceptable.

Tracking down the offending memory allocation was tedious and time consuming. Reviewing source code and making changes then setting up tests to stress the environment and monitor the memory growth using various system APIs to query available memory. I worked with a great electrical engineer who even spent the extra time to load the data into Excel and come up with graphs. (This didn't really increase our productivity, but it made it look like we were doing something substantial.)

Fast-forward about five years to my work on Microsoft Windows in the Windows Sustained Engineering group. Obviously, memory leaks are still an issue. More importantly, they are trouble for many of our customers. Whenever leaks are reported by customers we need to investigate, find the leak, and fix it. Code review is out of the question for something as substantial as Windows with literally gigabytes of source code. Luckily, there's some great tools available for use on Windows.

User Mode Stack Traces & UMDH

User Mode Stack Traces can be enabled by the gflags.exe utility available in the Debugging Tools for Windows package.

I won't provide a real link here for fear the tag will eventually expire, instead use your favorite search engine to find the latest version. NOTE: Gflags.exe is a powerful and terribly dangerous tool. I don't have time to review all the options available so please be careful.

Gflags is just a utility to enable the appropriate options at the OS level. Windows has plenty of diagnostic information available, this is one of the reasons I consider Windows so "developer friendly." The User Mode Stack Trace options can be found Image File tab of GFlags. You'll need to enter the application name in the image name dialog and hit TAB. Once that's done you can select Create user mode stack trace database to configure tracking for the executable. Make sure you click Apply and OK when done.

Another option is to use the command-line interface of gflags.

gflags.exe -i notepad.exe +ust

Now that Windows will track the allocations, you can start using UMDH to capture and analyze "dumps." UMDH stands for User Mode Dump Heap. UMDH.exe is a handy little utility provided with the Debugging Tools for Windows package which operates in two modes. The first mode creates dumps by accessing the user mode stack trace database windows creates for properly configured processes. The second mode analyzes the differences between any two dumps.

I like to think of UMDH dumps as allocation-state snapshots in time. UMDH allows you to compare two snapshots and view the differences between them. Not only will you see memory allocations but you will also see memory de-allocations.

Putting It Together

With the tools introduction done I can finally get to where the magic happens. Here's an example session using the tools:

--- Setup leaky.exe to track user mode stack traces.
C:\test>c:\debuggers\gflags.exe -i leaky.exe +ust

--- Launch leaky.exe (in a different window)

--- Take the first trace.
C:\test>c:\debuggers\umdh.exe -pn:leaky.exe -f:Dump0.txt

--- Take a second trace after executing "memory leaking" operations.
C:\test>c:\debuggers\umdh.exe -pn:leaky.exe -f:Dump1.txt

--- Use the second mode of UMDH to diff the traces.
C:\test>c:\debuggers\umdh.exe Dump0.txt Dump1.txt > Dump_output.txt

--- View the output.
C:\test>type Dump_output.txt
// _NT_SYMBOL_PATH set by default to C:\Windows\symbols
// Debug library initialized ...
DBGHELP: leaky - private symbols & lines 
        .\leaky.pdb
DBGHELP: ntdll - export symbols
DBGHELP: kernel32 - export symbols
DBGHELP: KERNELBASE - export symbols
//                                                                          
// Each log entry has the following syntax:                                 
//                                                                          
// + BYTES_DELTA (NEW_BYTES - OLD_BYTES) NEW_COUNT allocs BackTrace TRACEID 
// + COUNT_DELTA (NEW_COUNT - OLD_COUNT) BackTrace TRACEID allocations      
//     ... stack trace ...                                                  
//                                                                          
// where:                                                                   
//                                                                          
//     BYTES_DELTA - increase in bytes between before and after log         
//     NEW_BYTES - bytes in after log                                       
//     OLD_BYTES - bytes in before log                                      
//     COUNT_DELTA - increase in allocations between before and after log   
//     NEW_COUNT - number of allocations in after log                       
//     OLD_COUNT - number of allocations in before log                      
//     TRACEID - decimal index of the stack trace in the trace database     
//         (can be used to search for allocation instances in the original  
//         UMDH logs).                                                      
//                                                                          


+    1000 (  1c00 -   c00)      7 allocs BackTrace74F40
+       4 (     7 -     3) BackTrace74F40 allocations

 ntdll!MD5Final+0000B3DD
 leaky!malloc+0000005B (f:\dd\vctools\crt_bld\self_64_amd64\crt\src\malloc.c, 89)
 leaky!operator new+0000001F (f:\dd\vctools\crt_bld\self_64_amd64\crt\src\new.cpp, 59)
 leaky!Leaky+00000015 (d:\data\projects\base\leaky\leaky\main.cpp, 6)
 leaky!main+0000005C (d:\data\projects\base\leaky\leaky\main.cpp, 18)
 leaky!__tmainCRTStartup+0000013B (f:\dd\vctools\crt_bld\self_64_amd64\crt\src\crt0.c, 278)
 kernel32!BaseThreadInitThunk+0000000D
 ntdll!RtlUserThreadStart+00000021


Total increase ==   1000 requested +     d0 overhead =   10d0

I can clearly see that leaky!Leaky was called by leaky!main 4 times between the time I took Dump0 and Dump1. I can also see that the amount of memory allocated from these 4 calls was 0x1000 bytes, with a full allocation size including overhead of 0x10d0 bytes. One of the other nice things is I can see this was a C++ "new" allocation and that visual studio eventually converts a "new" into a "malloc" to actually request the memory.

Well, that's a very simple example but I've used this same technique for much more complicated memory leaks in the past -- there's just a few more entries in the call stacks list :). Now you know how to track down (and hopefully prevent) all memory leaks in your code. You can learn a lot when interpreting these UMDH logs. I've included the MSDN article for UMDH log interpretation in the references section. Also, because most system resources are backed by some sort of dynamically allocated memory this technique will also work for other resources leaks as well.

Happy coding!

References

http://support.microsoft.com/kb/268343
http://msdn.microsoft.com/en-us/Library/ff551046(v=VS.85).aspx