记一次 .NET 某餐饮小程序 内存暴涨分析
一:背景1. 讲故事
前些天有位朋友找到我,说他的程序内存异常高,用 vs诊断工具 加载时间又太久,让我帮忙看一下到底咋回事,截图如下:
确实,如果dump文件超过 10G 之后,市面上那些可视化工具分析起来会让你崩溃的,除了时间久之外这些工具大多也不是用懒加载的方式,比如 dotmemory 会把数据全部灌入内存,针对这种dump,你没个32G内存就不要分析了,这也是 windbg 在此类场景下的用武之地。
闲话不多说,朋友的dump到了,赶紧分析一波。
2. 到底是谁吃了内存
还是那句话,用 !address -summary 看下是托管内存还是非托管内存的问题。
0:000> !address -summary
--- Usage Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
Free 366 7dbf`3e6cb000 ( 125.747 TB) 98.24%
<unknown> 5970 240`99b78000 ( 2.252 TB)99.97% 1.76%
Stack 159 0`136a0000 ( 310.625 MB) 0.01% 0.00%
Image 1943 0`0a2e8000 ( 162.906 MB) 0.01% 0.00%
Heap 89 0`0a1e0000 ( 161.875 MB) 0.01% 0.00%
Other 12 0`001da000 ( 1.852 MB) 0.00% 0.00%
TEB 53 0`0006a000 ( 424.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 366 7dbf`3e6cb000 ( 125.747 TB) 98.24%
MEM_RESERVE 608 23d`fda87000 ( 2.242 TB)99.52% 1.75%
MEM_COMMIT 7619 2`c3e9e000 (11.061 GB) 0.48% 0.01%从卦中看 ntheap=161M,看样子是托管堆的问题了,继续使用 !eeheap -gc 看下托管堆。
0:000> !eeheap -gc
Number of GC Heaps: 8
------------------------------
Heap 0 (00000277134AD330)
Small object heap
segment begin allocated committed allocated size committed size
generation 0:
000002B727864BB000000279A400002000000279A43FFFD000000279A44000000x3fffb0(4194224)0x400000(4194304)
000002B72786950000000279BD80002000000279BDBFFF7000000279BDC000000x3fff50(4194128)0x400000(4194304)
...
000002B727852950000002793F000020000002793F3FFFA0000002793F4000000x3fff80(4194176)0x400000(4194304)
000002B727853080000002794180002000000279419B6FA000000279419C10000x1b6f80(1798016)0x1c1000(1839104)
Frozen object heap
segment begin allocated committed allocated size committed size
Large object heap
segment begin allocated committed allocated size committed size
000002B7277F53C0000002773780002000000277378580A800000277378790000x58088(360584)0x79000(495616)
Pinned object heap
segment begin allocated committed allocated size committed size
000002B7277F148000000277218000200000027721833A8000000277218410000x33a60(211552)0x41000(266240)
Allocated Heap Size: Size: 0x4e17d578 (1310184824) bytes.
Committed Heap Size: Size: 0x4effd000 (1325387776) bytes.
------------------------------
GC Allocated Heap Size: Size: 0x280020b18 (10737552152) bytes.
GC Committed Heap Size: Size: 0x28835f000 (10875170816) bytes.我去,一下子刷了好几屏,从卦中可以看到内存占用高达 10G+, 往细处看都是 Small object heap 给吃掉了,既然是SOH堆,看样子都是热和着呢,潜台词就是他们的根很可能在线程栈里,经验之谈哈。
有了这些猜测,接下来观察下托管堆,看看谁的占比最大,使用 !dumpheap -stat 即可。
0:000> !dumpheap -stat
Statistics:
MT Count TotalSize Class Name
...
00007ffc41beaa68 4894 1732200 System.Object[]
00007ffc41fc0468 7058 2368001 System.Byte[]
00007ffc41dbf7b8 24209 2517736 System.Reflection.RuntimeMethodInfo
00007ffc43429178 3 536870984 xxxLogEntity[]
000002771340e900 46106634 1866065488 Free
00007ffc41c6fd10 55920839 2125832534 System.String
00007ffc42ddc0b8 50634021 6076082520 xxxxxxxLogEntity不看不知道,一看吓一跳,这 xxxxxxLogEntity 对象居然高达 5063w,占据着 6G 的内存,那为什么会有这么多的对象呢?用 !gcroot 抽几个看看便知。
0:000> !dumpheap -mt 00007ffc42ddc0b8
Address MT Size
00000279a405b010 00007ffc42ddc0b8 120
...
00000279c31648a0 00007ffc42ddc0b8 120
00000279c3164968 00007ffc42ddc0b8 120
00000279c3164a30 00007ffc42ddc0b8 120
00000279c3164af8 00007ffc42ddc0b8 120
00000279c3164bc0 00007ffc42ddc0b8 120
00000279c3164c88 00007ffc42ddc0b8 120
00000279c3164d50 00007ffc42ddc0b8 120
0:000> !gcroot 00000279c3164d50
Thread a65c:
0000009BA592BD80 00007FFC458F99C8 xxx+<xxx>d__14.MoveNext()
rbx:
->0000027723C9B8F8 System.Collections.Generic.List`1[]
->00000278F2000040 xxxxxxLogEntity[]
->00000279C3164D50 xxxxxxLogEntity
Found 1 unique roots (run '!gcroot -all' to see all roots).
0:000> !do 0000027723C9B8F8
Name: System.Collections.Generic.List`1[]
MethodTable: 00007ffc43024ec0
EEClass: 00007ffc41d956b0
Tracked Type: false
Size: 32(0x20) bytes
File: C:\Program Files\dotnet\shared\Microsoft.NETCore.App\7.0.4\System.Private.CoreLib.dll
Fields:
MT Field Offset Type VT Attr Value Name
00007ffc420fac804002149 8 System.__Canon[]0 instance 00000278f2000040 _items
00007ffc41bee8d0400214a 10 System.Int321 instance 50634020 _size
00007ffc41bee8d0400214b 14 System.Int321 instance 50634020 _version
00007ffc420fac80400214c 8 System.__Canon[]0 static dynamic statics NYI 从卦象中可以看到,这 5063w 个对象都被这个 list 持有,更有意思的是果然被我猜到了,这个list的根在 a65c 这个线程里,接下来的问题是这个线程正在做什么?
3. a65c 线程正在做什么
要想看这个神秘线程正在做什么,可以用 ~ 命令切过去看看线程栈,看看哪一个方法在引用这个 list。
0:036> ~~s
00007ffc`451fefe6 482bc2 sub rax,rdx
0:036> !clrstack -a
OS Thread Id: 0xa65c (36)
0000009BA592BD80 00007ffc458f99c8 xxxxBase+d__14.MoveNext()
PARAMETERS:
this (<CLR reg>) = 0x0000027723c515b8
LOCALS:
<no data>
<CLR reg> = 0x00000277287cd6d8
<no data>
<no data>
...
<no data>
<CLR reg> = 0x0000027723c9b8f8
<no data>找到了是 xxxxBase+d__14.MoveNext 方法之后,接下来就需要仔细研读代码,终于找到了,写了一个死循环,真是无语了,截图如下:
终于真相大白,程序员误以为使用dateTime.AddDays(1.0); 就可以修改 dateTime 的时间,犯了一个低级错误呀。
改成dateTime=dateTime.AddDays(1.0); 即可。
三:总结
这次内存暴涨把生产服务器弄崩了,就是因为这么个 低级错误导致实属不应该,本以为程序员不会写出什么死循环,还真的遇到了,提高开发人员的代码敏感性迫在眉睫。
来源:https://www.cnblogs.com/huangxincheng/archive/2023/09/21/17719366.html
免责声明:由于采集信息均来自互联网,如果侵犯了您的权益,请联系我们【E-Mail:cb@itdo.tech】 我们会及时删除侵权内容,谢谢合作!
页:
[1]