Archive for August 6th, 2007

Memory Dump Analysis Patterns

Monday, August 6th, 2007

Because the number of crash dump analysis patterns is growing I created a page that lists them and new will be added to it as soon as I write them. Some patterns are not really related to crashes, for example, memory leaks or CPU spikes so it would be better to call all of them memory dump analysis patterns instead. 

Memory Dump Analysis Patterns

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 20a)

Monday, August 6th, 2007

Memory Leak is another pattern that may be finally manifested as Insufficient Memory pattern in a crash dump. In this part I’ll cover process heap memory leaks. They are usually identified when the process virtual memory size grows over time. It starts with 80Mb and instead of fluctuating normally below 100Mb it suddenly starts growing to 150Mb after some time and then to 300Mb next day and then grows to 600Mb and so on.

Usually a process heap is under suspicion here. To confirm this we need to sample 2-3 consecutive user memory dumps at process sizes 100Mb, 200Mb and 300Mb, for example. This can be done by using Microsoft userdump.exe command line tool. Then we can see whether there is any heap growth by using !heap -s WinDbg command:

1st dump

0:000> !heap -s
  Heap     Flags   Reserv  Commit  Virt
                    (k)     (k)    (k)
---------------------------------------
00140000 00000002    2048   1048   1112
00240000 00008000      64     12     12
00310000 00001002    7232   4308   4600
00420000 00001002    1024    520    520
00340000 00001002     256     40     40
00720000 00001002      64     32     32
00760000 00001002      64     48     48
01020000 00001002     256     24     24
02060000 00001002      64     16     16
02070000 00001003     256    120    120
020b0000 00001003     256      4      4
020f0000 00001003     256      4      4
02130000 00001003     256      4      4
02170000 00001003     256      4      4
021f0000 00001002    1088     76     76
021e0000 00001002      64     16     16
02330000 00001002    1088    428    428
02340000 00011002     256     12     12
02380000 00001002      64     12     12
024c0000 00001003      64      8      8
028d0000 00001002    7232   3756   6188
02ce0000 00001003      64      8      8
07710000 00001002      64     20     20
07b20000 00001002      64     16     16
07f30000 00001002      64     16     16
09050000 00001002     256     12     12
09c80000 00001002  130304 102340 102684
007d0000 00001003     256    192    192
00810000 00001003     256      4      4
0bdd0000 00001003     256      4      4
0be10000 00001003     256      4      4
0be50000 00001003     256      4      4
0be90000 00001003     256     56     56
0bed0000 00001003     256      4      4
0bf10000 00001003     256      4      4
0bf50000 00001003     256      4      4
0bf90000 00001003     256      4      4
00860000 00001002      64     20     20
00870000 00001002      64     20     20
0d760000 00001002     256     12     12
0dc60000 00001002    1088    220    220
0c3a0000 00001002      64     12     12
0c3d0000 00001002    1088    160    364
08420000 00001002      64     64     64

2nd dump

0:000> !heap -s
  Heap     Flags   Reserv  Commit  Virt
                    (k)     (k)    (k)
---------------------------------------
00140000 00000002    8192   4600   4600
00240000 00008000      64     12     12
00310000 00001002    7232   4516   4600
00420000 00001002    1024    520    520
00340000 00001002     256     44     44
00720000 00001002      64     32     32
00760000 00001002      64     48     48
01020000 00001002     256     24     24
02060000 00001002      64     16     16
02070000 00001003     256    124    124
020b0000 00001003     256      4      4
020f0000 00001003     256      4      4
02130000 00001003     256      4      4
02170000 00001003     256      4      4
021f0000 00001002    1088     76     76
021e0000 00001002      64     16     16
02330000 00001002    1088    428    428
02340000 00011002     256     12     12
02380000 00001002      64     12     12
024c0000 00001003      64      8      8
028d0000 00001002    7232   3796   6768
02ce0000 00001003      64      8      8
07710000 00001002      64     20     20
07b20000 00001002      64     16     16
07f30000 00001002      64     16     16
09050000 00001002     256     12     12
09c80000 00001002  261376 221152 221928
007d0000 00001003     256    192    192
00810000 00001003     256      4      4
0bdd0000 00001003     256      4      4
0be10000 00001003     256      4      4
0be50000 00001003     256      4      4
0be90000 00001003     256     60     60
0bed0000 00001003     256      4      4
0bf10000 00001003     256      4      4
0bf50000 00001003     256      4      4
0bf90000 00001003     256      4      4
00860000 00001002      64     20     20
00870000 00001002      64     20     20
0d760000 00001002     256     12     12
0dc60000 00001002    1088    228    228
0c3a0000 00001002      64     12     12
0c3d0000 00001002    1088    168    224
08450000 00001002      64     64     64

We see that the only significant heap growth is at 09c80000 address, from 130Mb to 260Mb. However this doesn’t say which code uses it. In order to find the code we need to enable the so called user mode stack trace database. Please refer to the following Citrix article:

http://support.citrix.com/article/CTX106970

The example in the article is for Citrix IMA service but you can replace ImaSrv.exe with any other executable name.

Suppose that after enabling user mode stack trace database and restarting the program or service we see the growth and we get memory dumps with the following suspicious heap highlighted in red:

0:000> !gflag
Current NtGlobalFlag contents: 0x00001000
ust - Create user mode stack trace database

0:000> !heap -s
NtGlobalFlag enables following debugging aids for new heaps:
  stack back traces
LFH Key: 0x2687ed29
  Heap     Flags   Reserv  Commit  Virt
                    (k)     (k)    (k)
---------------------------------------
00140000 58000062    4096    488    676
00240000 58008060      64     12     12
00360000 58001062    3136   1152   1216
003b0000 58001062      64     32     32
01690000 58001062     256     32     32
016d0000 58001062    1024    520    520
003e0000 58001062      64     48     48
02310000 58001062     256     24     24
02b30000 58001062      64     16     16
02b40000 58001063     256     64     64
02b80000 58001063     256      4      4
02bc0000 58001063     256      4      4
02c00000 58001063     256      4      4
02c40000 58001063     256      4      4
02c80000 58001063     256      4      4
02cc0000 58001063     256      4      4
02d30000 58001063      64      4      4
03140000 58001062    7232   4160   4896
03550000 58001063      64      4      4
07f70000 58001062      64     12     12
08380000 58001062      64     12     12
08790000 58001062      64     12     12
091d0000 58011062     256     12     12
09210000 58001062      64     16     16
09220000 58001062      64     12     12
092a0000 58001062      64     12     12
09740000 58001062     256     12     12
0b1a0000 58001062      64     12     12
0b670000 58001062   64768  39508  39700
0b7b0000 58001062      64     12     12
0c650000 58001062    1088    192    192

Every heap is subdivided into several segments and to see which segments have grown the most we can use !heap -m <heap address> command:

0:000> !heap -m 0b670000
Index   Address  Name      Debugging options enabled
29:   0b670000
    Segment at 0b670000 to 0b6b0000 (00040000 bytes committed)
    Segment at 0c760000 to 0c860000 (00100000 bytes committed)
    Segment at 0c980000 to 0cb80000 (001fe000 bytes committed)
    Segment at 0cb80000 to 0cf80000 (003cc000 bytes committed)
    Segment at 0dc30000 to 0e430000 (00800000 bytes committed)
    Segment at 12330000 to 13330000 (01000000 bytes committed)
    Segment at 13330000 to 15330000 (0078b000 bytes committed)



If we use !heap -a <heap address> command then in addition to the list of heap segments individual heap allocation entries will be dumped as well. This could be very big output and we should open the log file in advance by using .logopen <file name> command.

The output can be like this (taken from another dump):

0:000> !heap -a 000a0000
...
...
...
    Segment00 at 000a0000:
        Flags:           00000000
        Base:            000a0000
        First Entry:     000a0580
        Last Entry:      000b0000
        Total Pages:     00000010
        Total UnCommit:  00000002
        Largest UnCommit:00000000
        UnCommitted Ranges: (1)

    Heap entries for Segment00 in Heap 000a0000
        000a0000: 00000 . 00580 [101] - busy (57f)
        000a0580: 00580 . 00240 [101] - busy (23f)
        000a07c0: 00240 . 00248 [101] - busy (22c)
        000a0a08: 00248 . 00218 [101] - busy (200)
        000a0c20: 00218 . 00ce0 [100]
        000a1900: 00ce0 . 00f88 [101] - busy (f6a)
        000a2888: 00f88 . 04418 [101] - busy (4400)
        000a6ca0: 04418 . 05958 [101] - busy (5940)
        000ac5f8: 05958 . 00928 [101] - busy (90c)
        000acf20: 00928 . 010c0 [100]
        000adfe0: 010c0 . 00020 [111] - busy (1d)
        000ae000:      00002000      - uncommitted bytes.

Then we can inspect individual entries to see stack traces that allocated them by using !heap -p -a <heap entry address> command:

0:000> !heap -p -a 000a6ca0
    address 000a6ca0 found in
    _HEAP @ a0000
      HEAP_ENTRY Size Prev Flags    UserPtr UserSize - state
        000a6ca0 0b2b 0000  [00]   000a6cb8    05940 - (busy)
        Trace: 2156ac
        7704dab4 ntdll!RtlAllocateHeap+0x0000021d
        75c59b12 USP10!UspAllocCache+0x0000002b
        75c62381 USP10!AllocSizeCache+0x00000048
        75c61c74 USP10!FindOrCreateSizeCacheWithoutRealizationID+0x00000124
        75c61bc0 USP10!FindOrCreateSizeCacheUsingRealizationID+0x00000070
        75c59a97 USP10!UpdateCache+0x0000002b
        75c59a61 USP10!ScriptCheckCache+0x0000005c
        75c59d04 USP10!ScriptStringAnalyse+0x0000012a
        7711140f LPK!LpkStringAnalyse+0x00000114
        7711159e LPK!LpkCharsetDraw+0x00000302
        77111488 LPK!LpkDrawTextEx+0x00000044
        76a4beb3 USER32!DT_DrawStr+0x0000013a
        76a4be45 USER32!DT_DrawJustifiedLine+0x0000005f
        76a49d68 USER32!AddEllipsisAndDrawLine+0x00000186
        76a4bc31 USER32!DrawTextExWorker+0x000001b1
        76a4bedc USER32!DrawTextExW+0x0000001e
        746051d8 uxtheme!CTextDraw::GetTextExtent+0x000000be
        7460515a uxtheme!GetThemeTextExtent+0x00000065
        74611ed4 uxtheme!CThemeMenuBar::MeasureItem+0x00000124
        746119c1 uxtheme!CThemeMenu::OnMeasureItem+0x0000003f
        74611978 uxtheme!CThemeWnd::_PreDefWindowProc+0x00000117
        74601ea5 uxtheme!_ThemeDefWindowProc+0x00000090
        74601f61 uxtheme!ThemeDefWindowProcW+0x00000018
        76a4a09e USER32!DefWindowProcW+0x00000068
        931406 notepad!NPWndProc+0x00000084
        76a51a10 USER32!InternalCallWinProc+0x00000023
        76a51ae8 USER32!UserCallWinProcCheckWow+0x0000014b
        76a51c03 USER32!DispatchClientMessage+0x000000da
        76a3bc24 USER32!__fnINOUTLPUAHMEASUREMENUITEM+0x00000027
        77040e6e ntdll!KiUserCallbackDispatcher+0x0000002e
        76a51d87 USER32!RealDefWindowProcW+0x00000047
        74601f2f uxtheme!_ThemeDefWindowProc+0x000001b8

If we want to dump all heap entries with their corresponding stack traces we can use !heap -k -h <heap address> command.

Note: sometimes all these commands don’t work. In such cases we can use old Windows 2000 extension.

Some prefer to use umdh.exe and get text file logs but the advantage of embedding heap allocation stack traces in a dump is that we are not concerned with sending and configuring symbol files at a customer side.

- Dmitry Vostokov @ DumpAnalysis.org -