.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

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

Windows服务器撞鬼集

老说Linux的坏话貌似有点不太好，咱搞IT的也要讲究平衡。说心里话，Linux虽然有很多不爽，但爽的时候也有，此时就会挺痛恨Windows里的一些问题。

Windows服务器里面的东西通常都比较傻瓜和简单，但是这也就造就了如下的一些问题：
1、出问题的时候，日志不一定有，或者有了也不够清晰，或者无法调整至更清晰的日志输出级别。相对应的，Linux里面较成熟的应用都很注重这类事情；
2、不开源，导致除了问题要查找非常的困难。如果遇到了文档齐全的还好，要是不齐全或者文档里面没有描述，那就可能需要你通过付费服务来解决了；（这又延伸出来另一个问题：比如说，开Ticket让微软来解决，那我的代码也有只是产权不便提供。可以想象，他们调试起来也会很困难，乃至盲人摸象。）
3、要做到傻瓜，就一定有额外的开销，甚至从设计上就有不同的考虑。除了可能导致占用更多的资源，还有可能会导致某些操作的速度急剧下降。

今天我们就遇到了一个例子，正好三个问题都沾点边。这个问题其实一直都存在：用户说访问好慢啊！只是原来不那么明显，再加上系统结构复杂，CDN、交换机、负载均衡、缓存、Web、数据库、存储，分别需要考察CPU、内存、带宽、硬盘IO等项目，也确实不容易。之前也找到一些有嫌疑的地方，但处理之后却没有太大的改善。今天又找到了另一个嫌犯，貌似它才是元凶：Web上面缓存目录中文件过多，导致读取该目录的文件时，速度非常的慢。

在Web上面做缓存，是为了避免每次都动态生成一些内容，减少后端DB的各种压力和Web端的CPU占用率。理论上来说，由于前端已经有缓存，后端的磁盘IO应当不是问题。比如假设每秒钟有100个链接需要通过缓存文件返回，每个文件平均大小10KB，大概也就1M的数据量。加上可能有很多文件是已经在内存中有缓存的，因此实际的磁盘读取量并不会那么大。

按道理来说这种级别的随机读取应该不是大问题，对吧？但是当一个目录中存在大量的文件时，就可能悲剧了：比如说这个目录下有10000个文件，平均每个文件的文件名为50个字符。这时候整个目录光是文件名的数据量就达到了：10000*50*2（Unicode嘛）=1MB。实际上一个文件名至少还需要对应上该文件所在的位置等信息（具体有哪些没去考究），而实际读取的数量也并非全部的数据。由于NTFS文件系统中记录大目录中的文件名所采用的是B-树的形式存储的，检索一个文件所需要读取的信息量也没有那么大，而实际读取数量取决于你要查找的文件所在的层次。后者则取决于这个目录中文件的数量，一次分配的Extend会有多大，文件增删的情况，以及恢复平衡的策略。（啥是Extent见这里）

这个B-树的层次会是只有2层，还是有多层，目前还没有找到确切的说明。一次分配的Extent会有多少个簇，也还没有找到确切说明，但貌似我看到的情况好像是1个。同时如果一个子树节点包含太多孙节点，检索效率也会明显下降，因此不可能很大。

为了便于理解和计算，假定一个文件会占用100个字节，而B-数的层次是多层，每次分配的Extent均为2个簇。因为MFT节点大小为1K，一个簇4K，我们可以得到：（大约）

• 根节点大约能保存5个文件；
• 每一个（层）子树可以保存8K/100 = 80个文件；

在树平衡的情况下，10000个文件保存的情况大致如下所示：
根：5=5
第一层：400=5*80
第二层：3600=5*80*80
第三层：5995<5*80*80*80=2,560,000

也就是说，比较糟糕的情况下，打开一个文件需要访问到第三层，也就是要访问1+8+8+8=25K的数据。对于平均状况而言，可能需要访问13K。如果我们套用之前的数据计算，每秒100个文件，文件数据大小10K，再加上这13K的目录数据访问量，每秒磁盘读取数量就达到了2.3M每秒了。

呃，好像也不是很大啊。但是当我们用ProcessMonitor来监视的时候，就发现了这样的一个记录：
ReadFile C:\XXX目录\YYY目录 SUCCESS

Offset: 6,664,192, Length: 4,096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O

请注意，这个操作居然是Non-cached的！也就是说，这种操作很可能每次都要从磁盘中读取出来。我们知道，对磁盘的随机访问性能实际上是很低的。一块普通的7200转SATA盘，随机IO能达到1MBps基本上就已经到顶了。即便是1万转的4块盘做RAID10，随机IO能够达到10MBps已经很难了，一般也就维持在5-6MBps之间。按照上面的计算，使用后一种配置的服务器，每秒也就只能够撑大概700个文件的随机访问。（呃，如果你只有那么700个文件的话，那肯定不止这个数，因为文件会被缓存进来，甚至7000个都不成什么问题。但如果你有几十万个文件，并在这堆文件中来回随机访问的话……）

从上面的分析可以看出来，要提升性能，除了提升硬件性能外，还需要注意：
减少一个目录中文件的数量；
减少文件目录的层次；
缩短文件名的长度。


呃，等等，还有一个问题没解决：为什么是Non-cached的呢？是否因为这个原因导致了系统性能不佳呢？目前说实话还没有找到资料，也许是.NET框架的设计原因，也可能是操作系统的设计原因。

这，就是Windows系的一个大问题：很封闭。如果是在Linux世界，大不了直接看各个部分的代码，只要你能看得懂，也愿意看。反正只要花时间，那也一定是可以解决的。但是在Windows世界那就未必了，比如我之前遇到的一个问题，最后就不了了之了，我也无能为力。而在Linux世界里面，squid有个行为和我们想象的不一样，看代码发现有个地方的判断和想象的不一样。对于后者，我们就可以讨论，到底是改让后端用另一种方式输出呢，还是修改Squid。换做Windows系统，大多时候只能干着急，别无他法。比如说我们就遇到StateServer不时地报告连接中断的问题，但就是没有什么特别好的方法进行排查，也没有特别详细的文档去说明这一现象，最后仍然是不了了之。

也许有人说，NTFS资料还是挺多的啊。可是很多时候这些资料是不准确的，比如上面说到的保存目录的方法是B-数，在很多很多的地方都说是B+树，包括微软官方的页面、维基百科的页面等等。但是实际上请仔细看微软官方页面上提到的图二，在看看关于B+树和B-树在维基百科上的定义，你就会发现NTFS采用的显然是B-树。这个错误估计是某个半桶水的无证临时工，在编辑网页资料的时候将工程师写的"B-tree"，私自修改成了"B+tree"造成的。也有可能是画图美工嫌工程师给的图不好看，随手给改成现在看到的图二，结果从B+树变成B-树的形态了。事实是如何的呢？因为没有代码可看，实在不清楚。而MFT内部结构据称也是非公开的，没有官方资料。当年曾经想自己写一个后台不停修复硬盘碎片服务的代码，其中有一步叫做查找碎片，Windows有API可以做但是很慢。我所看的那个帖子中也提到，如果直接通过MFT记录来查找碎片的话，会快很多，可惜这部分内容不公开，网上现有资料无法保证完全准确。

如果你在Windows中遇到的问题跟可能与你无关的部分有关，后续的工作通常很难开展。.NET类库算是一个例外，这也是我为啥这么喜欢这个平台的原因之一。