猫头鹰日记 发表于 2023-9-21 11:28:34

记一次 .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]
查看完整版本: 记一次 .NET 某餐饮小程序 内存暴涨分析