記一次 .NET 某電廠Web系統 記憶體漏失分析

2022-07-14 09:00:26

一:背景

1. 講故事

前段時間有位朋友找到我,說他的程式記憶體佔用比較大,尋求如何解決,截圖就不發了,分析下來我感覺除了程式本身的問題之外,.NET5 在記憶體管理方面做的也不夠好,所以有必要給大家分享一下。

二:WinDbg 分析

1. 託管還是非託管洩漏

這個還是老規矩 !address -summary!eeheap -gc 組合命令排查一下。


0:000> !address -summary

                                     
Mapping file section regions...
Mapping module regions...
Mapping PEB regions...
Mapping TEB and stack regions...
Mapping heap regions...
Mapping page heap regions...
Mapping other regions...
Mapping stack trace database regions...
Mapping activation context regions...
--- State Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_FREE                                426     7df8`af1ce000 ( 125.971 TB)           98.42%
MEM_RESERVE                             619      206`01b9c000 (   2.023 TB)  99.75%    1.58%
MEM_COMMIT                             3096        1`4f286000 (   5.237 GB)   0.25%    0.00%

0:000> !eeheap -gc
Number of GC Heaps: 16
------------------------------
...
Heap 15 (0000024AF6BAA2E0)
generation 0 starts at 0x000002509729B538
generation 1 starts at 0x000002509720B638
generation 2 starts at 0x0000025096F91000
ephemeral segment allocation context: none
         segment             begin         allocated         committed    allocated size    committed size
0000025096F90000  0000025096F91000  000002509B5AFB40  000002509DFE9000  0x461eb40(73526080)  0x7058000(117800960)
Large object heap starts at 0x00000250D6F91000
         segment             begin         allocated         committed    allocated size    committed size
00000250D6F90000  00000250D6F91000  00000250DEB6AC60  00000250DEB6B000  0x7bd9c60(129866848)  0x7bda000(129867776)
Pinned object heap starts at 0x00000250E6F91000
00000250E6F90000  00000250E6F91000  00000250E75D94E0  00000250E75DA000  0x6484e0(6587616)  0x649000(6590464)
Allocated Heap Size:       Size: 0xc840c80 (209980544) bytes.
Committed Heap Size:       Size: 0xec32000 (247668736) bytes.
------------------------------
GC Allocated Heap Size:    Size: 0xd6904dd8 (3599781336) bytes.
GC Committed Heap Size:    Size: 0x11884b000 (4706316288) bytes.

從卦中指標看:5.2G4.7G ,很明顯問題出在了託管層,但如果你細心的話,你會發現這 4.7G 是 commit 記憶體,其實真正佔用的只有 3.5G,言外之意有 1.2G 的空間其實屬於 Commit 區,也就是為了少向 OS 申請記憶體而虛佔的一部分空間,畫個簡圖就像下面這樣:

這也是我第一次看到 AllocCommit 差距有這麼大。

2. 探究託管記憶體佔用

首先看下 3.5G 記憶體這塊,這個分析比較簡單,直接看託管堆就好了。


0:000> !dumpheap -stat
Statistics:
              MT    Count    TotalSize Class Name
...
00007ffa19e64808    25804     36125600 xxxx.MongoDB.Entity.GeneratorMongodb
0000024af68aa2c0    20517    630474976      Free
00007ffa1947bf30    52477    654558722 System.Byte[]
00007ffa194847f0     1921   1044818774 System.Char[]
00007ffa19437a90   673850   1116597742 System.String

從輸出資訊看,主要還是被 String,Char[],Byte[] 佔用了,根據經驗,這三個組合在一塊,大多是存了什麼位元組流在記憶體中,比如 PdfImage ,然後在記憶體中倒來倒去就成這個樣子了。

接下來在 char[] 中抽一些 obj 看一下,果然大多是 jpg


0:000> !DumpObj /d 00000250da9d3618
Name:        System.Char[]
MethodTable: 00007ffa194847f0
EEClass:     00007ffa19484770
Size:        11990052(0xb6f424) bytes
Array:       Rank 1, Number of elements 5995014, Type Char (Print Array)
Content:     data:image/jpeg;base64,iVBORw0KGgoAAAANSUhEUgAAA4QAAASwCAYAAACjAoQOAAAAAXNSR0IArs4c6QAAAARnQU1BAACxjwv8YQUAAAAJcEhZcwAADsMAAA7DA
Fields:
None
0:000> !DumpObj /d 00000250db542a60
Name:        System.Char[]
MethodTable: 00007ffa194847f0
EEClass:     00007ffa19484770
Size:        15667860(0xef1294) bytes
Array:       Rank 1, Number of elements 7833918, Type Char (Print Array)
Content:     data:image/jpeg;base64,iVBORw0KGgoAAAANSUhEUgAAA4QAAASwCAYAAACjAoQOAAAAAXNSR0IArs4c6QAAAARnQU1BAACxjwv8YQUAAAAJcEhZcwAADsMAAA7DA
Fields:
None

可以看到,3.2G 的記憶體大多是被 圖片 所佔用,朋友反饋是把 圖片 存到資料庫所致,好了,這一塊就分析到這裡,分析思路也很明顯,接下來探究下 alloc 和 commit 的問題。

3. 為什麼 alloc 和 commit 差距這麼大

一般而言,差距大有以下幾點誘因所致。

  1. segment 越大,commit 預設的區域就越大

根據官方檔案的定義,segment 的大小取決於 cpu核數 和 程式的位數,截圖如下:

有了這個指標,怎麼到 dump去找各自資料呢,用 !eeversion 看下 heap 的個數以及觀察下記憶體地址的長度就好啦。


0:000> !eeversion
5.0.621.22011 free
5,0,621,22011 @Commit: 478b2f8c0e480665f6c52c95cd57830784dc9560
Server mode with 16 gc heaps
SOS Version: 6.0.5.7301 retail build

可以看到,這個程式是用 64bit 跑在 16 核機器上,segment 上限為 1G

  1. segment 越多,alloc 和 commit 累計差距就會越大

每個 segment 都差一點,那多個 segment 自然就累計出來了,接下來就找一下那些差距比較大的 segment。


Heap 0 (0000024AF685A500)
         segment             begin         allocated         committed    allocated size    committed size
0000024AF6F90000  0000024AF6F91000  0000024AF83B6D28  0000024AFEB42000  0x1425d28(21126440)  0x7bb1000(129699840)
------------------------------
Heap 1 (0000024AF68819A0)
         segment             begin         allocated         committed    allocated size    committed size
0000024B56F90000  0000024B56F91000  0000024B58507410  0000024B5D2E5000  0x1576410(22504464)  0x6354000(104153088)
------------------------------
Heap 4 (0000024AF688F770)
         segment             begin         allocated         committed    allocated size    committed size
0000024C76F90000  0000024C76F91000  0000024C783BDBE8  0000024C7ECF7000  0x142cbe8(21154792)  0x7d66000(131489792)
------------------------------
Heap 6 (0000024AF68980A0)
         segment             begin         allocated         committed    allocated size    committed size
0000024D36F90000  0000024D36F91000  0000024D38B87E78  0000024D3F881000  0x1bf6e78(29322872)  0x88f0000(143589376)
...

從輸出資訊看,差距最大的是 Heap6,高達 110M,那這 110M 差距是否合理呢?其實仔細想想也不太離譜,畢竟命中了上面提到的兩點,但我覺得這裡的空間是不是還可以再智慧的優化一下,再縮小一點?

4. Commit區能不能再小點?

能不能縮的再小一點,其實這是一種 CLR 智慧演演算法的抉擇,Commit 區越大,申請物件的速度就越快,向 OS 申請記憶體的頻率就越低,反之 Commit 區越小,向 OS 再次申請記憶體的概率就越大,段的模型圖大概是這個樣子:

後來仔細想了下,既然 Commit 區多保留了 110M,那曾經肯定是某一個時刻突破過,後來因為成了垃圾物件,被 GC 回收了,但記憶體區域被GC私藏下來,所以程式肯定出現過 快出快進 的現象,接下來的想法就是用 writemem 把 alloc ~ commit 的記憶體區間給匯出來看下,是不是有什麼新發現。


0:000> .writemem D:\dumps\dump1\1.txt 0000024AF83B6D28 L?0x0678b2d8 
Writing 678b2d8 bytes.............

發現了很多類似這樣的資訊,把這個資訊提供給朋友後,朋友說他找到這塊問題了,是網站上用 NPOI 資料匯出 功能所致。

三:總結

其實這個 dump 給了我們兩方面的教訓。

  1. 不要將 image 放到 sqlserver 裡,不僅佔用sql的資源,讓程式也不堪重負,畢竟讀出去都是 byte[] ...

  2. coreclr 雖然有自己的抉擇演演算法,如果再智慧一點就好了,讓 commit ~ alloc 之間的差距更合理一點。

圖片名稱