记一次 .NET 某外贸ERP 内存暴涨分析
Posted
tags:
篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了记一次 .NET 某外贸ERP 内存暴涨分析相关的知识，希望对你有一定的参考价值。
一：背景
1. 讲故事
上周有位朋友找到我，说他的 API 被多次调用后出现了内存暴涨，让我帮忙看下是怎么回事？看样子是有些担心，但也不是特别担心，那既然找到我，就给他分析一下吧。
二：WinDbg 分析
1. 到底是哪里的泄露
这也是我一直在训练营灌输的理念，一定要知道是哪一边的暴涨，否则很可能就南辕北辙了，使用 !address -summary 和 !eeheap -gc 即可。
0:000> !address -summary
--- Usage Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
Free 315 7df9`dbf15000 ( 125.976 TB) 98.42%
<unknown> 1056 206`130ec000 ( 2.024 TB) 99.99% 1.58%
Image 1262 0`091ee000 ( 145.930 MB) 0.01% 0.00%
Heap 258 0`04c19000 ( 76.098 MB) 0.00% 0.00%
Stack 114 0`02fc0000 ( 47.750 MB) 0.00% 0.00%
Other 9 0`001db000 ( 1.855 MB) 0.00% 0.00%
TEB 38 0`0004c000 ( 304.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_MAPPED 260 200`01dbf000 ( 2.000 TB) 98.82% 1.56%
MEM_PRIVATE 1216 6`1912e000 ( 24.392 GB) 1.18% 0.02%
MEM_IMAGE 1262 0`091ee000 ( 145.930 MB) 0.01% 0.00%
--- State Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_FREE 315 7df9`dbf15000 ( 125.976 TB) 98.42%
MEM_RESERVE 492 205`3abc6000 ( 2.020 TB) 99.82% 1.58%
MEM_COMMIT 2246 0`e9515000 ( 3.646 GB) 0.18% 0.00%
....
0:000> !eeheap -gc
Number of GC Heaps: 8
------------------------------
....
------------------------------
GC Allocated Heap Size: Size: 0x74d77d98 (1960279448) bytes.
GC Committed Heap Size: Size: 0xcb7c6000 (3413925888) bytes.
从卦中看，当前提交内存是 3.64G ，托管堆的提交内存是 3.41G，很明显这是一个 托管内存 暴涨，到这里就比较好解决了。
不知道可有朋友注意到了 GC Allocated Heap Size 和 GC Committed Heap Size 相差甚大，高达 1.5G 之多，上次看到这个情况还是 某电厂 的一个 dump，当时还问了下 Maoni ，说是设计如此，既然说到了设计如此，我还看了下 .NET 版本是 .NET5，所以冷不丁的看下来这个程序的.NET版本，输出如下：
0:000> !eeversion
5.0.621.22011 free
5,0,621,22011 @Commit: 478b2f8c0e480665f6c52c95cd57830784dc9560
Server mode with 8 gc heaps
SOS Version: 6.0.5.7301 retail build
我去 .NET5 再现，其实到这里可以这么说， 至少我觉得 .NET5 在这一块还可以再优化优化。
2. 为什么会相距过大
在 电厂 的那个dump中，后来通过非托管分析，发现有大量的统计信息，后来确认是网站上有一段时间的高频导入导出文件造成的暴涨，这句话的意思就是程序曾经出现过短暂的 快进快出，这就意味着有大量短暂的临时对象产生， CLR 为了高效处理，在短暂对象释放后，并没有将内存归还给 操作系统, 而是自己私吞，目的是防未来可能的爆炸性的内存分配，所以你会看到 分配区域 和 提交区域 过大的底层逻辑了。
原理大概就是这么个原理，那这个 ERP 难道也是出现了 快进快出 的现象吗？是不是我们可以挖一下哈，方法就是统计一下 无根对象 占托管堆的一个 百分比，使用 !heapstat -iu 命令。
0:000> !heapstat -iu
Heap Gen0 Gen1 Gen2 LOH POH
Heap0 124129016 105671896 5371520 4063704 795560
Heap1 100102816 109941488 4421800 4719072 452904
Heap2 144913984 105093616 7285888 4325960 1917928
Heap3 125996096 109904696 8612112 4194608 425976
Heap4 124567184 102635432 7450536 3670432 393400
Heap5 122508864 104438848 12821224 4076136 458616
Heap6 124459664 120851840 5901680 6615192 311352
Heap7 131309360 97620536 8585720 8660720 602072
Total 997986984 856158352 60450480 40325824 5357808
Free space: Percentage
Heap0 426616 2332200 3032 393520 264 SOH: 1%
Heap1 380752 2403984 1768 131208 320 SOH: 1%
Heap2 484008 2306424 4328 344 616 SOH: 1%
Heap3 436888 2403000 1168 184 24 SOH: 1%
Heap4 446192 2266944 1936 393512 24 SOH: 1%
Heap5 444176 2302824 5232 131440 24 SOH: 1%
Heap6 429048 2648592 9104 884800 24 SOH: 1%
Heap7 441216 2144136 3272 168992 80 SOH: 1%
Total 3488896 18808104 29840 2104000 1376
Unrooted objects: Percentage
Heap0 121561744 103338800 56592 3145872 0 SOH: 95%
Heap1 99418536 107524544 19800 4456760 0 SOH: 96%
Heap2 144081016 102786776 36920 4325616 0 SOH: 95%
Heap3 124591744 107491216 23832 4194424 0 SOH: 94%
Heap4 123946896 100368288 10400 3145824 88 SOH: 95%
Heap5 121457024 102135728 24032 3539136 0 SOH: 93%
Heap6 123739008 118202552 2288 5243072 0 SOH: 96%
Heap7 130593408 95460992 736 3539136 0 SOH: 95%
Total 989389376 837308896 174600 31589840 88
从卦中看，当前 Unrooted objects 区域占 SOH 的比率都是在 93% 以上，就是说托管堆上几乎都是 无根对象，这也验证了 快进快出 的现象，接下来的问题就是挖下是什么导致了 快进快出。
3. 什么导致了 快进快出
要找到这个答案需要到托管堆看一下，是否有超出预期的对象分配，使用 !dumpheap -stat 即可。
0:000> !dumpheap -stat
Statistics:
MT Count TotalSize Class Name
...
00007ff7bf388fa8 1300147 31203528 System.DateTime
00007ff7c04db260 124 32312064 xxx.UDP_Retention[]
00007ff7bfeb2c00 1239416 317290496 xxx.UDP_Retention
00007ff7c00cfe88 12997664 415925248 FreeSql.Internal.Utils+RowInfo
00007ff7bf107a90 21175792 909769558 System.String
Total 40777517 objects
从卦中看： FreeSql.Internal.Utils+RowInfo 高达 1300w ，同时 xxx.UDP_Retention 对象也高达 123w ， FreeSql 相信国内很多开发者都知道，是一个数据访问的SDK，很显然这个 ERP 应该从数据库中读取了不少数据, FreeSql 在内部为了做映射生成了非常多的临时对象。
那现在的突破点在哪里呢？就是寻找问题 SQL，找下和类名同名的表名 UDP_Retention 即可，写个脚本查一下就好了，结果发现有不少这样的 sql，输出如下：
SELECT *
FROM
(SELECT *
FROM UDP_Retention with(nolock)
WHERE ID NOT IN
(SELECT xxxId
FROM UDP_Retention_Pxxxx with(nolock)) ) a
那这条 sql 会捞出多少数据呢？可以观察下 UDP_Retention[] 即可，然后稍微过滤一下。
0:000> !DumpHeap -mt 00007ff7c04db260 -min 0n1048576
Address MT Size
00000244c3b71188 00007ff7c04db260 1048600
00000244c3c711c0 00007ff7c04db260 1048600
00000244d3bd1120 00007ff7c04db260 1048600
00000244e3a710e0 00007ff7c04db260 1048600
00000244e3cb1230 00007ff7c04db260 1048600
00000244f3a11070 00007ff7c04db260 1048600
00000244f3b910e0 00007ff7c04db260 1048600
00000244f3c91118 00007ff7c04db260 1048600
0000024503a91118 00007ff7c04db260 1048600
0000024503b91150 00007ff7c04db260 1048600
0000024513c74250 00007ff7c04db260 1048600
00000245239c90c8 00007ff7c04db260 1048600
0000024523ac9100 00007ff7c04db260 1048600
0000024523de0048 00007ff7c04db260 1048600
0000024523ee0080 00007ff7c04db260 1048600
00000245339d0f68 00007ff7c04db260 1048600
0000024534013668 00007ff7c04db260 1048600
Statistics:
MT Count TotalSize Class Name
00007ff7c04db260 17 17826200 xxx.UDP_Retention[]
Total 17 objects
0:000> !DumpObj /d 0000024534013668
Name: xxx.UDP_Retention[]
MethodTable: 00007ff7c04db260
EEClass: 00007ff7bf0467c8
Size: 1048600(0x100018) bytes
Array: Rank 1, Number of elements 131072, Type CLASS (Print Array)
Fields:
None
从卦中信息看, 大概有 17 个 13w 的记录，说明这个sql会一次性捞取 10w+ ，用完之后即刻释放，也就表示为什么 SOH 会占用 93% 以上的无根对象。
三：总结
总的来说，这次内存暴涨是因为程序出现了分配的 快进快出 现象导致的，如果你不想管也可以不用管，GC 在下次发兵时会一举歼灭，如果要做优化的话，需要优化下 sql，不要一次性查询出 10w+ 的数据，不过说实话，FreeSql 在映射方面最好也要做些优化，毕竟产生了 1300w 的临时对象，虽然不是它的错。
记一次 .NET某家装ERP 内存暴涨分析
一：背景
1. 讲故事
前段时间微信上有一位老朋友找到我，说他的程序跑着跑着内存会突然爆高，有时候会下去，有什么会下不去，怀疑是不是某些情况下存在内存泄露，让我帮忙分析一下，其实内存泄露方面的问题还是比较好解决的，看过这个dump之后觉得还是有一定的分享价值，拿出来和大家分享一下吧。
二：WinDbg 分析
1. 托管还是非托管泄露
这个首先是一定要确定的，否则就是南辕北辙，强调再多也不为过，可以用 !address -summary 观察一下。
0:000> !address -summary
--- Usage Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
Free 208 7ffb`691cd000 ( 127.982 TB) 99.99%
<unknown> 384 4`898d7000 ( 18.149 GB) 98.87% 0.01%
Image 1015 0`0b053000 ( 176.324 MB) 0.94% 0.00%
Stack 90 0`01700000 ( 23.000 MB) 0.12% 0.00%
Heap 32 0`00bea000 ( 11.914 MB) 0.06% 0.00%
Other 14 0`001e0000 ( 1.875 MB) 0.01% 0.00%
TEB 23 0`0002e000 ( 184.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 336 4`8ab0b000 ( 18.167 GB) 98.96% 0.01%
MEM_IMAGE 1177 0`0b70f000 ( 183.059 MB) 0.97% 0.00%
MEM_MAPPED 46 0`00c09000 ( 12.035 MB) 0.06% 0.00%
--- State Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_FREE 208 7ffb`691cd000 ( 127.982 TB) 99.99%
MEM_COMMIT 1256 3`1f910000 ( 12.493 GB) 68.05% 0.01%
MEM_RESERVE 303 1`77513000 ( 5.864 GB) 31.95% 0.00%从卦中看，当前程序的提交内存占用了 12G，NTHEAP 占用了 11M，基本上就可以断定这是一个托管内存的问题，看到这里还是非常开心的，由于托管层都带有类型数据，分析起来非常简单，接下来使用 !eeheap -gc 观察下托管堆。
0:000> !eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0x00000000e42f26c8
generation 1 starts at 0x00000000e42e85a0
generation 2 starts at 0x0000000001d71000
ephemeral segment allocation context: none
segment begin allocated size
0000000001d70000 0000000001d71000 0000000011961b98 0x000000000fbf0b98(264178584)
000000005e540000 000000005e541000 000000006c2b6408 0x000000000dd75408(232215560)
0000000247ff0000 0000000247ff1000 0000000252d751f8 0x000000000ad841f8(181944824)
00000000e3ff0000 00000000e3ff1000 00000000f1e44850 0x000000000de53850(233125968)
Large object heap starts at 0x0000000011d71000
segment begin allocated size
0000000011d70000 0000000011d71000 0000000019d65098 0x0000000007ff4098(134168728)
000000001dad0000 000000001dad1000 0000000025ac6fd0 0x0000000007ff5fd0(134176720)
0000000028c50000 0000000028c51000 0000000030c318e8 0x0000000007fe08e8(134088936)
0000000030c50000 0000000030c51000 0000000038c35518 0x0000000007fe4518(134104344)
000000003e540000 000000003e541000 0000000046507ff0 0x0000000007fc6ff0(133984240)
0000000046540000 0000000046541000 000000004e5296d0 0x0000000007fe86d0(134121168)
000000004e540000 000000004e541000 000000005652af00 0x0000000007fe9f00(134127360)
0000000056540000 0000000056541000 000000005e50b050 0x0000000007fca050(133996624)
...
000000058fff0000 000000058fff1000 00000005d76c2910 0x00000000476d1910(1198332176)
000000064e820000 000000064e821000 0000000695cbe808 0x000000004749d808(1196021768)
000000013bff0000 000000013bff1000 00000001834c96d8 0x00000000474d86d8(1196263128)
0000000257ff0000 0000000257ff1000 000000029f44e7e0 0x000000004745d7e0(1195759584)
Total Size 0x2dbe1b140(12278935872)
------------------------------
GC Heap Size 0x2dbe1b140(12278935872)从卦中看，托管堆占用了 12G 内存，而且都是被 LOH 给吃掉了，离真相越来越近了，接下来就是用 !dumpheap -stat 观察下托管堆，看下到底是什么类型占的这么大？
0:000> !dumpheap -stat
total 477283 objects
Statistics:
MT Count TotalSize Class Name
0007ffeb28280b0 3516 365664 System.Reflection.RuntimeMethodInfo
00007ffea909df50 62 728528 System.Data.RBTree`1+Node[[System.Data.DataRow, System.Data]][]
00007ffeb285a610 14 804680 System.DateTime[]
00007ffea909c5e8 17061 1637856 System.Data.DataRow
00007ffeb2831180 1555 1978136 System.Int32[]
00007ffeb282d430 1108 6648296 System.Int64[]
00007ffeb2fce9d8 71 12821784 System.Decimal[]
00007ffeb282a060 366739 15054680 System.String
00007ffeb2817e50 7785 23534144 System.Object[]
00000000009a2e60 4084 4772737632 Free
00007ffeb28320a0 17400 7438877632 System.Byte[]
...从卦中看， System.Byte[] 数组只有 1.7W 个，居然占用了 7.4G 的内存，这说明有的 Byte[] 可能会非常大, 接下来就可以检索 >10M 的数组排列情况，输出如下：
0:000> !dumpheap -mt 00007ffeb28320a0 -min 0n10485760
Address MT Size
0000000029051018 00007ffeb28320a0 33554456
000000002d051078 00007ffeb28320a0 33554456
00000003e6a43a10 00007ffeb28320a0 16777240
0000000547ff1000 00007ffeb28320a0 1195710200
000000058fff1000 00007ffeb28320a0 1195710200
000000064e821000 00007ffeb28320a0 1195759552
000000013bff1000 00007ffeb28320a0 1195759552
0000000257ff1000 00007ffeb28320a0 1195759560
total 8 objects
Statistics:
MT Count TotalSize Class Name
00007ffeb28320a0 8 6062585216 System.Byte[]
Total 8 objects从卦中看，居然有 5 个将近 1.2 G 的 Byte[] 数组，有点吓人，抽几个看看吧。
0:000> !gcroot 000000058fff1000
Note: Roots found on stacks may be false positives. Run "!help gcroot" for
more info.
Scan Thread 0 OSTHread 39f4
0:000> !gcroot 0000000547ff1000
Note: Roots found on stacks may be false positives. Run "!help gcroot" for
more info.
Scan Thread 0 OSTHread 39f4
Scan Thread 2 OSTHread 2f6c
Scan Thread 3 OSTHread 3354
Scan Thread 4 OSTHread 3924从卦中看，他们都没有引用根，也就说明是等待 GC 回收的临时对象，有朋友就要问了，GC 为什么不回收呢？
2. GC 为什么不回收
了解 GC 的朋友应该知道，LOH 默认不启用压缩回收，只会做简单的标记清除，清除之后就会存在很多的空洞，只有相邻的空洞才会合并成一个更大的空洞，一旦有分配的对象超过所有的空洞大小，GC 也只能被迫commit更多的新空间给它存放，虽然此时存放不间隔的空闲内存已经足够。
如果大家有点懵，画个图大概就像下面这样。
从图中看，程序要分配 1.3G 的对象， 虽然 LOH 上有 2G 的空闲空间但就是放不下，无奈只能 commit 更多的内存来存放这个对象。
这就是为什么朋友看到的，有时候内存会暴涨，有时候会降下去的底层原理。
3. byte[] 到底是什么
要想查看 byte[] 的内容，可以用 db, dW 观察内存地址，参考如下：
0:000> dW 0000000547ff1000 L100
00000005`47ff1000 20a0 b283 7ffe 0000 16da 4745 0000 0000 . ........EG....
00000005`47ff1010 0100 0000 ff00 ffff 01ff 0000 0000 0000 ................
00000005`47ff1020 0c00 0002 0000 534e 7379 6574 2e6d 6144 ......NSystem.Da
00000005`47ff1030 6174 202c 6556 7372 6f69 3d6e 2e32 2e30 ta, Version=2.0.
00000005`47ff1040 2e30 2c30 4320 6c75 7574 6572 6e3d 7565 0.0, Culture=neu
00000005`47ff1050 7274 6c61 202c 7550 6c62 6369 654b 5479 tral, PublicKeyT
00000005`47ff1060 6b6f 6e65 623d 3737 3561 3563 3136 3339 oken=b77a5c56193
00000005`47ff1070 6534 3830 0539 0001 0000 5315 7379 6574 4e089......Syste
00000005`47ff1080 2e6d 6144 6174 442e 7461 5461 6261 656c m.Data.DataTable
00000005`47ff1090 04d6 0000 4419 7461 5461 6261 656c 522e .....DataTable.R
00000005`47ff10a0 6d65 746f 6e69 5667 7265 6973 6e6f 4418 emotingVersion.D
00000005`47ff10b0 7461 5461 6261 656c 522e 6d65 746f 6e69 ataTable.Remotin
00000005`47ff10c0 4667 726f 616d 1374 6144 6174 6154 6c62 gFormat.DataTabl
00000005`47ff10d0 2e65 6154 6c62 4e65 6d61 1365 6144 6174 e.TableName.Data
00000005`47ff10e0 6154 6c62 2e65 614e 656d 7073 6361 1065 Table.Namespace.
00000005`47ff10f0 6144 6174 6154 6c62 2e65 7250 6665 7869 DataTable.Prefix
00000005`47ff1100 4417 7461 5461 6261 656c 432e 7361 5365 .DataTable.CaseS
00000005`47ff1110 6e65 6973 6974 6576 441e 7461 5461 6261 ensitive.DataTab
00000005`47ff1120 656c 632e 7361 5365 6e65 6973 6974 6576 le.caseSensitive
00000005`47ff1130 6d41 6962 6e65 1474 6144 6174 6154 6c62 Ambient.DataTabl
00000005`47ff1140 2e65 6f4c 6163 656c 434c 4449 4419 7461 e.LocaleLCID.Dat
00000005`47ff1150 5461 6261 656c 4d2e 6e69 6d69 6d75 6143 aTable.MinimumCa
00000005`47ff1160 6170 6963 7974 4419 7461 5461 6261 656c pacity.DataTable
00000005`47ff1170 4e2e 7365 6574 4964 446e 7461 5361 7465 .NestedInDataSet
00000005`47ff1180 4412 7461 5461 6261 656c 542e 7079 4e65 .DataTable.TypeN
00000005`47ff1190 6d61 1b65 6144 6174 6154 6c62 2e65 6552 ame.DataTable.Re
00000005`47ff11a0 6570 7461 6261 656c 6c45 6d65 6e65 1c74 peatableElement.
00000005`47ff11b0 6144 6174 6154 6c62 2e65 7845 6574 646e DataTable.Extend
00000005`47ff11c0 6465 7250 706f 7265 6974 7365 4417 7461 edProperties.Dat
00000005`47ff11d0 5461 6261 656c 432e 6c6f 6d75 736e 432e aTable.Columns.C
00000005`47ff11e0 756f 746e 4421 7461 5461 6261 656c 442e ount!DataTable.D
00000005`47ff11f0 7461 4361 6c6f 6d75 5f6e 2e30 6f43 756c ataColumn_0.Colu
....从 unicode 码来看，貌似是一个 DataTable 的序列化，看样子是序列化一个巨大的 DataTable 导致的内存暴涨，接下来我们到线程栈上找到有么有类似的操作，算是碰碰运气吧。
哈哈，从卦中看还真的有类似操作，用了 BinaryFormatter 做序列化。。。接下来观察下这个 DataTable 的 RowCount。
0:013> !do 0000000002582cb8
Name: System.Data.DataRowCollection+DataRowTree
MethodTable: 00007ffea909d3f0
EEClass: 00007ffea8f1ef68
Size: 64(0x40) bytes
(C:\\Windows\\assembly\\GAC_64\\System.Data\\2.0.0.0__b77a5c561934e089\\System.Data.dll)
Fields:
MT Field Offset Type VT Attr Value Name
0000000000000000 4000765 8 SZARRAY 0 instance 000000000bc79d98 _pageTable
00007ffeb2831180 4000766 10 System.Int32[] 0 instance 000000000bc79fb8 _pageTableMap
00007ffeb28312d0 4000767 18 System.Int32 1 instance 42 _inUsePageCount
00007ffeb28312d0 4000768 1c System.Int32 1 instance 1 nextFreePageLine
00007ffeb28312d0 4000769 20 System.Int32 1 instance 1245312 root
00007ffeb28312d0 400076a 24 System.Int32 1 instance 17054 _version
00007ffeb28312d0 400076b 28 System.Int32 1 instance 17055 _inUseNodeCount
00007ffeb28312d0 400076c 2c System.Int32 1 instance 0 _inUseSatelliteTreeCount
00007ffea957b578 400076d 30 System.Int32 1 instance 2 _accessMethod从卦中看当前的 _inUseNodeCount=1.7W ，这只是捕获到的，相信还有更大的，也算是找到问题原因了。
三：总结
在和朋友沟通之后，朋友也确认了确实有大 DataTable 的情况，目前业务需求没法绕过，不过在这种情况下也还是有办法的，大致如下：
1. 强制 LOH 压缩
虽然 LOH 上的对象移动会产生很大的内存流量，但适当的用一用压缩也不失为一个简单粗暴的办法。
GCSettings.LargeObjectHeapCompactionMode = GCLargeObjectHeapCompactionMode.CompactOnce;
GC.Collect();2. 分批次获取
一次性获取 1.7W 条，可以拆成诸如 2000 条一次，好处很明显，可以充分利用 LOH 上留下来的空洞区。
如果您有任何问题，可以与我联系，微信：ixchuang
以上是关于记一次 .NET 某外贸ERP 内存暴涨分析的主要内容，如果未能解决你的问题，请参考以下文章