记一次 .NET 某电力系统 内存暴涨分析
一：背景
1. 讲故事
前些天有位朋友找到我，说他生产上的程序有内存暴涨情况，让我帮忙看下怎么回事，最简单粗暴的方法就是让朋友在内存暴涨的时候抓一个dump下来，看一看大概就知道咋回事了。
二：Windbg 分析
1. 到底是谁吃了内存
这个问题说的再多也不为过，一定要看清楚这个程序是如何个性化发展的，可以使用 !address -summary 命令。
0:000> !address -summary
--- Usage Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
Free 255 7dfb`064e1000 ( 125.981 TB) 98.42%
<unknown> 529 204`d53ac000 ( 2.019 TB) 99.97% 1.58%
Heap 889 0`170f0000 ( 368.938 MB) 0.02% 0.00%
Image 1214 0`07a9a000 ( 122.602 MB) 0.01% 0.00%
Stack 192 0`05980000 ( 89.500 MB) 0.00% 0.00%
Other 10 0`001d8000 ( 1.844 MB) 0.00% 0.00%
TEB 64 0`00080000 ( 512.000 kB) 0.00% 0.00%
PEB 1 0`00001000 ( 4.000 kB) 0.00% 0.00%
--- State Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_FREE 255 7dfb`064e1000 ( 125.981 TB) 98.42%
MEM_RESERVE 709 204`43eab000 ( 2.017 TB) 99.86% 1.58%
MEM_COMMIT 2190 0`b5c64000 ( 2.840 GB) 0.14% 0.00%
从卦象看进程内存也才 2.84G，严格来说也不算多，可能朋友抓的有点心急，从上面的 unknown 指标看大概率是托管堆的暴涨，继续使用 !eeheap -gc 观察下托管堆。
0:000> !eeheap -gc
========================================
Number of GC Heaps: 4
----------------------------------------
Heap 0 (000001d0adf50a20)
generation 0 starts at 1d0b3fad350
generation 1 starts at 1d0b3f9be88
generation 2 starts at 1d0ae5d1000
ephemeral segment allocation context: none
Small object heap
segment begin allocated committed allocated size committed size
01d0ae5d0000 01d0ae5d1000 01d0b4046258 01d0b48ac000 0x5a75258 (94851672) 0x62dc000 (103661568)
Large object heap starts at 1d4ae5d1000
segment begin allocated committed allocated size committed size
01d4ae5d0000 01d4ae5d1000 01d4b6d0c4e8 01d4b6d2d000 0x873b4e8 (141800680) 0x875d000 (141938688)
Pinned object heap starts at 1d4ee5d1000
segment begin allocated committed allocated size committed size
01d4ee5d0000 01d4ee5d1000 01d4ee5e4f08 01d4ee5f2000 0x13f08 (81672) 0x22000 (139264)
------------------------------
...
Heap 3 (000001d0ae4fd000)
generation 0 starts at 1d3b26929e0
generation 1 starts at 1d3b2687ad8
generation 2 starts at 1d3ae5d1000
ephemeral segment allocation context: none
Small object heap
segment begin allocated committed allocated size committed size
01d3ae5d0000 01d3ae5d1000 01d4179a5980 01d418021000 0x693d4980 (1765624192) 0x69a51000 (1772425216)
Large object heap starts at 1d4de5d1000
segment begin allocated committed allocated size committed size
01d4de5d0000 01d4de5d1000 01d4df8836d8 01d4df884000 0x12b26d8 (19605208) 0x12b4000 (19611648)
Pinned object heap starts at 1d51e5d1000
segment begin allocated committed allocated size committed size
01d51e5d0000 01d51e5d1000 01d51e5dd7e0 01d51e5e2000 0xc7e0 (51168) 0x12000 (73728)
------------------------------
GC Allocated Heap Size: Size: 0x8a6b9060 (2322305120) bytes.
GC Committed Heap Size: Size: 0x8c6b1000 (2355826688) bytes.
从GC堆看果然是托管层的问题，继续使用 !dumpheap -stat 观察下托管堆的现状，看看哪一位是罪魁祸首。
0:000> !dumpheap -stat
Statistics:
MT Count TotalSize Class Name
...
7fff32e81db8 43 68,801,032 SmartMeter.Mem.TerminalInfo[]
7fff329f7470 200,000 110,400,000 SmartMeter.Model.MeterInfo_Model
7fff3227d708 2,285,392 116,193,998 System.String
01d0ae46b350 543 1,857,281,320 Free
Total 3,947,969 objects, 2,314,533,332 bytes
Fragmented blocks larger than 0.5 MB:
Address Size Followed By
01d0ae935870 723,384 01d0ae9e6228 System.SByte[]
01d1b41d3cd0 23,081,616 01d1b57d6f60 System.Byte[]
01d3b274eb40 1,696,943,656 01d4179a3968 System.Byte[]
这卦不看不知道，一看吓一跳，这2.3G的内存，居然被一个 1.69G 的Free给侵吞了，不信的话可以用 !do 验证下。
0:000> !do 01d3b274eb40
Free Object
Size: 1696943656(0x65254e28) bytes
2. 为什么会有这么大的Free
这是一个值得思考的问题，也决定着我们下一步分析的方向，接下来就是看下这个 free 的落脚点以及周围对象的分布情况，可以使用 !gcwhere 观察。
0:000> !gcwhere 01d3b274eb40
Address Heap Segment Generation Allocated Committed Reserved
01d3b274eb40 3 01d3ae5d0000 0 1d3ae5d1000-1d4179a5980 1d3ae5d0000-1d418021000 1d418021000-1d4ae5d0000
0:000> !dumpheap -segment 1d3ae5d0000
...
01d3b274e948 7fff32468658 96
01d3b274e9a8 7fff3227d708 28
01d3b274e9c8 7fff3227d708 28
01d3b274e9e8 7fff32d0c8d8 80
01d3b274ea38 7fff3227d708 96
01d3b274ea98 7fff32d0aa38 40
01d3b274eac0 01d0ae46b350 128 Free
01d3b274eb40 01d0ae46b350 1,696,943,656 Free
01d4179a3968 7fff323e1638 8,216
从卦象看挺遗憾的，如果 Free 落在segment的最后一个位置，那么 segment 就会 uncommitted 进而内存就下去了，可偏偏最后一个位置是 8216byte 的对象占据着，阻止了内存的回收，有经验的朋友可能知道，这个对象非富即贵，大概率是被 pinned 了，可以用 !gcroot 观察下。
0:000> !gcroot 01d4179a3968
HandleTable:
000001d0ae3927f8 (async pinned handle)
-> 01d3b26706f0 System.Threading.OverlappedData
-> 01d4179a3968 System.Byte[]
Found 1 unique roots.
0:000> !dumpobj /d 1d4179a3968
Name: System.Byte[]
MethodTable: 00007fff323e1638
EEClass: 00007fff323e15b8
Tracked Type: false
Size: 8216(0x2018) bytes
Array: Rank 1, Number of elements 8192, Type Byte (Print Array)
Content: ............L.o.g.\.2.0.2.3.0...
Fields:
None
从上面的 async pinned handle 来看是一个文件监控的回调函数，到这里就可以从表象解释：是这个 8216 的对象导致的内存无法回收。
3. 真的要 8216 来担责吗
如果你真的要让 8216 来担责，那真的只看到了表象，内存的突然暴涨回不去只是恰好遇到了 8216 的阻止，但它不是本质原因，真正要考虑的是为什么GC回收后会产生这么大一个单独 Free，其实隐喻了当前程序出现过短时的 大对象分配，对，就是这个词。
接下来的问题是如何找到这个 大对象分配 呢？ 最好的方法就是用 perfview 的 .NET SampAlloc 去洞察，如果非要用 WinDbg 的话那就只能看看 Free 生前是什么，或许能寻找到答案，可以借助 .writemem 命令观察。
0:000> !do 01d3b274eb40
Free Object
Size: 1696943656(0x65254e28) bytes
0:000> .writemem D:\testdump\1.txt 01d3b274eb40 L?0x65254e28
Writing 65254e28 bytes................
从卦中数据看有大量的计费信息，看样子又是从数据库中短时的捞取了大批量数据在托管堆上折腾导致的，知道了本质原因，解决办法就比较简单了，通常有两种做法。
-
修改 GC 模式，改成 Workstation。
-
大批量数据 改成 小步快跑
三：总结
这起内存暴涨事故，表象上是 8216 的阻挡导致了内存无法被uncommitted所致，本质上还是归于托管堆的 内存黑洞 现象。
