記一次 .NET 某三甲醫院HIS系統 內存暴漲分析


一:背景

1. 講故事

前幾天有位朋友加wx說他的程序遭遇了內存暴漲,求助如何分析?

和這位朋友聊下來,這個dump也是取自一個HIS系統,如朋友所說我這真的是和醫院杠上了🤣🤣🤣,這樣也好,給自己攢點資源😁😁😁,好了,不扯了,上windbg說話。

二: windbg 分析

1. 托管還是非托管?

既然是內存暴漲,那就看看當前進程的 commit 內存有多大?


0:000> !address -summary

--- State Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_FREE                                174     7ffe`baac0000 ( 127.995 TB)          100.00%
MEM_COMMIT                             1153        1`33bd3000 (   4.808 GB)  94.59%    0.00%
MEM_RESERVE                             221        0`1195d000 ( 281.363 MB)   5.41%    0.00%

可以看出大概占了 4.8G,接下來再看看托管堆內存。


0:000> !eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0x00000207a4fc48c8
generation 1 starts at 0x00000207a3dc3138
generation 2 starts at 0x0000020697fc1000
ephemeral segment allocation context: none
------------------------------
GC Heap Size:            Size: 0x1241b3858 (4900730968) bytes.

從最后一行可以看出托管堆占用 4900730968/1024/1024/1024=4.5G,兩個指標一比對,原來是托管內存出問題了,這下好辦了。。。

2. 查看托管堆

既然內存是被托管堆吃掉了,那就看看托管堆上到底都有些什么東西???


0:000> !dumpheap -stat
Statistics:
              MT    Count    TotalSize Class Name
...
00007ffd00397b98  1065873    102323808 System.Data.DataRow
00000206978b8250  1507805    223310768      Free
00007ffd20d216b8  4668930    364025578 System.String
00007ffd20d22aa8      797    403971664 System.String[]
00007ffd20d193d0   406282   3399800382 System.Byte[]
Total 9442152 objects

不看不知道,一看嚇一跳,System.Byte[] 差不多占用了 3.3 G 內存,也就是說 gc 堆差不多都被它吃掉了,根據經驗肯定是有個什么大對象,那接下來怎么分析呢?除了用腳本對 byte[] 進行暴力分組統計之外,純人肉還有其他的技巧嗎? 當然有,可以用 !heapstat 觀察下這些對象在托管堆上的代信息。


0:000> !heapstat
Heap             Gen0         Gen1         Gen2          LOH
Heap0         2252000     18880400   3968704192    910894376

Free space:                                                 Percentage
Heap0           43128       770160    185203264     39849984SOH:  4% LOH:  4%

從圖中可以看出,當前的大頭在 Gen2 上,接下來可以用 eeheap -gc 去找 Gen2 的段地址區間,從而最小化的顯示heap上內容。


0:000> !eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0x00000207a4fc48c8
generation 1 starts at 0x00000207a3dc3138
generation 2 starts at 0x0000020697fc1000
ephemeral segment allocation context: none
         segment             begin         allocated              size
0000020697fc0000  0000020697fc1000  00000206a7fbec48  0xfffdc48(268426312)
00000206bbeb0000  00000206bbeb1000  00000206cbeaef50  0xfffdf50(268427088)
00000206ccc40000  00000206ccc41000  00000206dcc3f668  0xfffe668(268428904)
00000206dcc40000  00000206dcc41000  00000206ecc3f098  0xfffe098(268427416)
0000020680000000  0000020680001000  000002068ffff8c0  0xfffe8c0(268429504)
00000206ff4d0000  00000206ff4d1000  000002070f4cf588  0xfffe588(268428680)
000002070f4d0000  000002070f4d1000  000002071f4cf9f0  0xfffe9f0(268429808)
000002071f4d0000  000002071f4d1000  000002072f4cfef0  0xfffeef0(268431088)
000002072f4d0000  000002072f4d1000  000002073f4cf748  0xfffe748(268429128)
000002073f4d0000  000002073f4d1000  000002074f4ce900  0xfffd900(268425472)
00000207574d0000  00000207574d1000  00000207674cfe70  0xfffee70(268430960)
00000207674d0000  00000207674d1000  00000207774ceaf8  0xfffdaf8(268425976)
00000207774d0000  00000207774d1000  00000207874cf270  0xfffe270(268427888)
00000207874d0000  00000207874d1000  00000207974cf7a8  0xfffe7a8(268429224)
00000207974d0000  00000207974d1000  00000207a51ea5a8  0xdd195a8(231839144)

一般來說,第一個 segment 是給 gen0 + gen1 的,后續的 segment 就是 gen2,接下來我就選 segment: 00000206dcc41000 - 00000206ecc3f098 ,然后使用 !dumpheap 導出該區間的所有對象。


0:000> !dumpheap -stat 00000206dcc41000 00000206ecc3f098
Statistics:
              MT    Count    TotalSize Class Name
00007ffd00397b98   191803     18413088 System.Data.DataRow
00007ffd20d216b8   662179     37834152 System.String
00007ffd20d193d0    23115    187896401 System.Byte[]

從這個內存段上看,Byte[] 有 2.3w 個,還不算多,全部dump出來看看有什么特征。


0:000> !dumpheap -mt 00007ffd20d193d0 00000206dcc41000 00000206ecc3f098
         Address               MT     Size
00000206dcc410e8 00007ffd20d193d0     8232     
00000206dcc43588 00007ffd20d193d0     8232     
00000206dcc45a48 00007ffd20d193d0     8232     
00000206dcc47d78 00007ffd20d193d0     8232     
00000206dcc4a028 00007ffd20d193d0     8232     
00000206dcc4c4b0 00007ffd20d193d0     8232     
00000206dcc4eb08 00007ffd20d193d0     8232     
00000206dcc50e88 00007ffd20d193d0     8232     
00000206dcc535b0 00007ffd20d193d0     8232     
00000206dcc575d8 00007ffd20d193d0     8232     
00000206dcc5a5a8 00007ffd20d193d0     8232     
00000206dcc5cbf8 00007ffd20d193d0     8232     
00000206dcc5eef8 00007ffd20d193d0     8232     
00000206dcc611f8 00007ffd20d193d0     8232     
00000206dcc634e8 00007ffd20d193d0     8232     
00000206dcc657f0 00007ffd20d193d0     8232     
00000206dcc67af8 00007ffd20d193d0     8232     
00000206dcc69e00 00007ffd20d193d0     8232   
...

我去,99% 都是 8232byte,原來都是些 8k 的byte數組,那到底誰在使用它,用 !gcroot 查一下引用根。


0:000> !gcroot 00000206dcc410e8
Thread 8c1c:
        rsi: 
            ->  00000206983d5730 System.ServiceProcess.ServiceBase[]
                ...
            ->  000002069dcb6d38 OracleInternal.ConnectionPool.OraclePool
                ...
            ->  000002069dc949c0 OracleInternal.TTC.OraBufReader
            ->  000002069dc94a70 System.Collections.Generic.List`1[[OracleInternal.Network.OraBuf, Oracle.ManagedDataAccess]]
            ->  00000206ab8c2200 OracleInternal.Network.OraBuf[]
            ->  00000206dcc41018 OracleInternal.Network.OraBuf
            ->  00000206dcc410e8 System.Byte[]

從引用鏈來看,貌似是被 OracleInternal.Network.OraBuf[] 持有着,這就很疑惑了,難道是 Oracle Sdk 出的bug把內存給搞崩了? 好奇心來了,看一下元素個數和size各是多少?


0:000> !do 00000206ab8c2200
Name:        OracleInternal.Network.OraBuf[]
MethodTable: 00007ffcc7833c68
EEClass:     00007ffd20757728
Size:        4194328(0x400018) bytes
Array:       Rank 1, Number of elements 524288, Type CLASS (Print Array)
Fields:
None

0:000> !objsize 00000206ab8c2200
sizeof(00000206ab8c2200) = -1086824024 (0xbf3861a8) bytes (OracleInternal.Network.OraBuf[])

當前數組有 52w ,totalsize直接負數了😓。

3. 尋找問題代碼

知道現象之后,接下來用 ILSpy 把 Oracle SDK 反編譯看看,最終一比對,如下圖所示:

原來m_tempOBList是內存暴漲的罪魁禍首,這就很尷尬了,它為什么會暴漲? 為什么不釋放? 由於我對 Oracle 也不熟悉,只能求助於神奇的 StackOverflow,我去,還真有天涯淪落人,Huge managed memory allocation when reading (iterating) data with DbDataReader

大概是說這種現象是 Oracle SDK 在讀取 Clob 類型的字段有一個bug,解決辦法也很簡單,用完后就釋放,詳情參見如下圖:

4. 尋找真相

既然帖子上是說讀取 Clob 類型出的問題,那就把所有線程棧都調出來,看看此時的線程棧中是否有 Clob 的蹤影?

從線程棧上看,代碼是通過 ToDataTable 方法將 IDataReader 轉成 DataTable,在轉換過程中讀取了大字段,自然就有了 GetCompleteClobData,也就是說完美命中帖子所說,為了讓結論更准確,我就去挖一下當前的 DataReader 已經讀了多少行了?


0:028> !clrstack -a
OS Thread Id: 0xbab0 (28)
000000e78ef7d520 00007ffd00724458 System.Data.DataTable.Load(System.Data.IDataReader, System.Data.LoadOption, System.Data.FillErrorEventHandler)
    PARAMETERS:
        this = <no data>
        reader (<CLR reg>) = 0x00000206a530ac20
        loadOption = <no data>
        errorHandler = <no data>
0:028> !do 0x00000206a530ac20
Name:        Oracle.ManagedDataAccess.Client.OracleDataReader
MethodTable: 00007ffcc7933b10
EEClass:     00007ffcc78efd30
Size:        256(0x100) bytes
File:        D:\xxx.dll
Fields:
00007ffd20d23e98  4000337       d0         System.Int32  1 instance          1061652 m_RowNumber

從 m_RowNumber 看,已經讀取了 106w 行,一次性讀取100w+的記錄不常見,如果還有大字段的話,那也是🐂👃了。

三:總結

綜合來看這次事故是因為一次性讀取含有大字段的百萬級數據到DataTable引發,解決方案很簡單,自己通過 for 讀取 DataReader,在處理完 OracleClob 類型之后馬上釋放,參考帖子代碼:


var item = oracleDataReader.GetOracleValue(columnIndex);

if (item is OracleClob clob)
{
    if (clob != null)
    {
        // use clob.Value ...

        clob.Close();
    }
}

更多高質量干貨:參見我的 GitHub: dotnetfly

圖片名稱


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM