一:背景
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
