2012年4月9日星期一

.NET应用非托管内存异常的简单排查

我们知道.NET应用如果出现问题,在Windows操作系统上面可以使用Windbg来查找问题所在。通常来说,.NET应用的问题会出现在托管部分。此时,只要我们的WinDbg在加载完CrashDump,或者附加上进程之后,就可以使用以下命令开始查找问题:
>.loadby sos clr
或者
>.loadby sos mscorwks
或者
>.loadby sos coreclr

其中第一个是.NET 4.0版本所使用的命令,而之前的其它桌面版需要使用第二个,最后一个是SilverLight 3/4所使用的版本。然后,我们就可以使用!eeheap/!dumpheap/!dumpobj之类的命令来进行内存问题的排查。

但是,有的时候问题并非在托管部分出问题。比如说,当我们输入:
>!eeheap -gc
之后显示:

……
------------------------------
GC Heap Size:    Size: 0xa0ec288 (168739464) bytes.

而这个Dump显然有大几百兆甚至1GB以上,此时就需要考虑非托管部分的问题了。首先,你需要输入:
>!address -summary
这一个命令可以给出地址空间的使用情况,这时候可能你会发现地址空间被字体占用光了,或者如这里所显示的那样,可能被非托管代码所占用了:

--- Usage Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
Free                                    382      7fe`61d74000 (   7.994 Tb)           99.92%
                        2825        1`8c91f000 (   6.196 Gb)  95.75%    0.08%
Image                                  1986        0`103e2000 ( 259.883 Mb)   3.92%    0.00%
Stack                                   174        0`014bd000 (  20.738 Mb)   0.31%    0.00%
TEB                                      58        0`00074000 ( 464.000 kb)   0.01%    0.00%
NlsTables                                 1        0`00033000 ( 204.000 kb)   0.00%    0.00%
ActivationContextData                     5        0`0000d000 (  52.000 kb)   0.00%    0.00%
CsrSharedMemory                           1        0`00009000 (  36.000 kb)   0.00%    0.00%
PEB                                       1        0`00001000 (   4.000 kb)   0.00%    0.00%

--- Type Summary (for busy) ------ RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_PRIVATE                            2290        1`8affa000 (   6.172 Gb)  95.37%    0.08%
MEM_IMAGE                              2716        0`11529000 ( 277.160 Mb)   4.18%    0.00%
MEM_MAPPED                               45        0`01d59000 (  29.348 Mb)   0.44%    0.00%

--- State Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_FREE                                382      7fe`61d74000 (   7.994 Tb)           99.92%
MEM_RESERVE                            1685        1`4709a000 (   5.110 Gb)  78.96%    0.06%
MEM_COMMIT                             3366        0`571e2000 (   1.361 Gb)  21.04%    0.02%

--- Protect Summary (for commit) - RgnCount ----------- Total Size -------- %ofBusy %ofTotal
PAGE_READWRITE                         1513        0`4427a000 (   1.065 Gb)  16.46%    0.01%
PAGE_EXECUTE_READ                       342        0`0d3e9000 ( 211.910 Mb)   3.20%    0.00%
PAGE_READONLY                           906        0`03837000 (  56.215 Mb)   0.85%    0.00%
PAGE_WRITECOPY                          306        0`01978000 (  25.469 Mb)   0.38%    0.00%
PAGE_EXECUTE_READWRITE                  147        0`006b8000 (   6.719 Mb)   0.10%    0.00%
PAGE_EXECUTE_WRITECOPY                   74        0`0020a000 (   2.039 Mb)   0.03%    0.00%
PAGE_READWRITE|PAGE_GUARD                77        0`0010a000 (   1.039 Mb)   0.02%    0.00%
PAGE_EXECUTE                              1        0`00004000 (  16.000 kb)   0.00%    0.00%

--- Largest Region by Usage ----------- Base Address -------- Region Size ----------
Free                                      5`16fea000      63d`67e66000 (   6.240 Tb)
                           0`80be1000        0`1f40f000 ( 500.059 Mb)
Image                                   644`23535000        0`0125a000 (  18.352 Mb)
Stack                                     0`00a40000        0`0007c000 ( 496.000 kb)
TEB                                     7ff`ffe82000        0`00002000 (   8.000 kb)
NlsTables                               7ff`fffa0000        0`00033000 ( 204.000 kb)
ActivationContextData                     0`000b0000        0`00005000 (  20.000 kb)
CsrSharedMemory                           0`7efe0000        0`00009000 (  36.000 kb)
PEB                                     7ff`fffdb000        0`00001000 (   4.000 kb)

如果怀疑是非托管堆上面的内存泄漏(或者过度占用)问题,则需要继续进一步使用下面的方法来进行排查:
>!heap -stat
该命令将会输出当前存在的堆都有哪些,分别都有多大。比如,你可能会看到:

_HEAP 0000000009040000
     Segments            0000000b
         Reserved  bytes 000000003ff80000
         Committed bytes 000000002f5cb000
     VirtAllocBlocks     00000000
         VirtAlloc bytes 0000000000000000
_HEAP 00000000000c0000
     Segments            00000004
         Reserved  bytes 0000000000800000
         Committed bytes 0000000000706000
     VirtAllocBlocks     00000001
         VirtAlloc bytes 0000000004de0000
……
这样的输出,比如上面黄色高亮的部分,就显示已经提交的内存有794MB之多,显然不是托管堆169MB所能承载的。此时,你就需要进一步进行分析了。

等会儿,刚才的命令是否还有类似这样的输出呢:

*************************************************************************
***                                                                   ***
***                                                                   ***
***    Your debugger is not using the correct symbols                 ***
***                                                                   ***
***    In order for this command to work properly, your symbol path   ***
***    must point to .pdb files that have full type information.      ***
***                                                                   ***
***    Certain .pdb files (such as the public OS symbols) do not      ***
***    contain the required information.  Contact the group that      ***
***    provided you with these symbols if you need this command to    ***
***    work.                                                          ***
***                                                                   ***
***    Type referenced: ntdll!_PEB                                    ***
***                                                                   ***
*************************************************************************
嗯,这时因为WinDbg还没有正确的配置上符号文件的路径。请点击File菜单中的Symbol File Path,并且在弹出框中填写如下路径:
SRV*d:\symbols*http://msdl.microsoft.com/download/symbols
并选择上Reload(或者关掉重开WinDbg),否则你将无法使用Google到的很多命令,比如:
>!heap -a 9040000
(会显示上面那一大段内容,外加“Invalid type information”这样的提示。)

如果你实在不想使用微软的远程Symbol服务器,或者因为网络原因无法使用,也可以在!heap命令后首先添加-p来试试看。比如说,将上面的命令改成:
>!heap -p -a 9040000

具体可以使用那些命令,还是建议大家使用!heap -?来查看。同时,上述临时方法输出的信息格式,与前一条命令的输出格式稍有不同,但基本不影响使用。

在使用上述命令之前,建议先针对较大的堆使用如下的命令进行分析:
>!heap -stat -h 9040000 -grp A

>!heap -stat -h 9040000 -grp B
>!heap -stat -h 9040000 -grp S


这几个命令按照不同的分类方法,对这一个堆进行分析,分别输出:
单次分配最大的几个分配;
哪几个大小的块的分配次数最多;
哪几个大小的块的总分配数量最多。

当你能确定某种大小的分配,其数量或者大小比较不正常,可以用以下命令进行查看:
>!heap -flt s 8000
这就可以打印所有大小为32K的分配情况,包括地址,输出可能类似如下:

……
        0000000009042cd0: 02010 . 07c20 [01] - busy (7c10)
        000000000904a8f0: 07c20 . 07c20 [01] - busy (7c10)

        0000000009061d50: 07c20 . 07c20 [01] - busy (7c10)
        0000000009069970: 07c20 . 07c20 [01] - busy (7c10)
        0000000009071590: 07c20 . 07c20 [01] - busy (7c10)
        00000000090791b0: 07c20 . 07c20 [01] - busy (7c10)
        0000000009080dd0: 07c20 . 07c20 [01] - busy (7c10)
        00000000090889f0: 07c20 . 07c20 [01] - busy (7c10)

……


上述的输出可能会很大,甚至超出了WinDbg命令缓冲区的大小。因此,你可以通过下面的方式,将整个输出写入到一个日志文件当中:
>.logopen "c:\logfile\heap.log"
>!heap -a 9040000
>.logclose



针对怀疑有问题某一个堆上分配,可以使用如下命令查看其内容:
>db 90889f0
……
>d
……

如果这些内容是很容易辨识的文本内容,或者你对於这里面的二进制内容比较熟悉,就可以很容易知道大概会是些什么东西,可能是什么地方出现问题。但是,多数情况下是看不出来的,或者因为内容太多不可能注意筛查出有价值的内容。此时,我们可能需要查看这些堆上内存分配的调用栈情况。

要实现调用栈的分析,首先需要修改系统的一些设置,使得针对你当前这个应用的Dump会包含申请该堆的时候,调用堆栈的情况。也就是说,如果你不做如下的更改,将不知道这些内存是怎么分配出去的。修改的方法有三种:
1、运行命令"gflags.exe /i YourApplication.exe +ust",这个gflags是WinDbg安装附带的工具之一,就在WinDbg所在的目录中;
2、在开始菜单中,WinDbg所在的位置还有另一个应用,就叫做gflag。这时一个图形化界面。在Image File的页面中输入你要调试的应用程序名称,例如YourApplication.exe,并且按一下TAB键。接着在下面的Create user mode stack trace database上面打一个勾,然后确定即可;
3、或者,你可以直接修改注册表。在“HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\”当中添加一个YourApplication.exe的结点,然后在其上添加一个名为GlobalFlag的双字类型的值,值等于0x00001000(4096)。
上面这三种方法可以参见这里以及这里

修改完之后,你需要重新在出现症状时做dump,因为之前dump的时候因为没有以上设置,是不会包含申请Heap时的用户空间堆栈情况的。而当你Dump完之后,记得用上述方法将之前的修改设置恢复原状。(我没有尝试过,不知道对于高负荷的线上系统,是否会造成很大的影响,最好谨慎一些。)

针对新做的dump,你需要再次使用上述方法,找到有问题的堆,再次执行如下的命令:
>!heap -p -a 90889f0

此时的输出可能就会如下所示:
    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


有了这些信息,就基本可以确定这些内存是通过什么样的途径分配出去的了。至于说为什么没有被释放,或者如何才能释放,只能自行查看自己的代码了。







没有评论:

发表评论