記一次 .NET 某流媒體獨角獸 API 控制程式碼洩漏分析

一線碼農發表於2021-08-30

一:背景

1. 講故事

上上週有位朋友找到我,說他的程式CPU和控制程式碼都在不斷的增長,無回頭趨勢,查了好些天也沒什麼進展,特加wx尋求幫助,截圖如下:


看的出來這位朋友也是非常鬱悶,出問題還出兩個,氣人哈,關於 cpu 爆高的問題我準備單獨用一篇文章去偵讀,這篇就先聊聊 控制程式碼洩漏 的問題,畢竟寫了20多篇,也是第一次聊到 handle 洩露,有點意思哈。

2. 什麼是控制程式碼

我個人理解的控制程式碼:就是在託管層持有了一個對非託管層資源的引用,有了這個引用,我們就可以強制回收非託管資源,那什麼是非託管資源? 我個人的理解是 gc 管不到的地方都是 非託管資源

通常包含這種控制程式碼的類有: FileStream, Socket 等,如果大家有這個前置基礎,接下來就可以用 windbg 去分析啦!

二: windbg 分析

1. 看問題表象

朋友從 工作管理員 中看到 handle =8770,那就說明程式中有 8770 個對非託管資源持有控制程式碼,那怎麼去看呢? 在說這個之前,大家有沒有遇到這種現象,就是不管程式怎麼洩漏,只要我們退出exe,那麼所有的資源都會被神奇的 釋放, 不管是託管資源還是非託管資源,這樣說相信有很有朋友好奇這是怎麼實現的??? 大家可以先想 10s。

揭曉答案啦! 簡單的說, CLR 在內部維護了一張控制程式碼表,當程式關閉時,CLR會強制釋放控制程式碼表中的所有控制程式碼,那問題就簡單了,既然 CLR 能觸達,我相信通過 windbg 也能做到,對,就是通過 !gchandles 命令。

2. 檢視控制程式碼表

這裡提醒一下,!gchandles 的作用域是 AppDomain,而不是 Process,接下來看一下命令輸出:


0:000> !gchandles -stat
Statistics:
              MT    Count    TotalSize Class Name
...
00007ffccc1d2360        3       262280 System.Byte[]
00007ffccc116610       72       313224 System.Object[]
00007ffccc3814a0     8246       593712 System.Threading.OverlappedData
Total 10738 objects

Handles:
    Strong Handles:       312
    Pinned Handles:       18
    Async Pinned Handles: 8246
    Ref Count Handles:    1
    Weak Long Handles:    2080
    Weak Short Handles:   59
    Dependent Handles:    22

從輸出看,有一組資料特別刺眼,那就是: Async Pinned Handles = 8246 [System.Threading.OverlappedData],這是什麼意思呢? 從英文名就能看出這是一個和 非同步IO 相關的控制程式碼,有些朋友應該知道,在非同步IO的過程中,會有一個 byte[] 被 pinned 住,同時還有一個非同步IO的上下文物件 OverlappedData

接下來的一個問題是:既然是非同步IO,那它的 handle 是什麼型別,如前面所說是 FileStream 還是 Socket ? 要想找出答案,就需要深挖 OverlappedData 物件,相關的命令是: !dumpheap -mt xxx & !do ... ,參考如下:


0:000> !DumpHeap /d -mt 00007ffccc3814a0
         Address               MT     Size
000001aa2acb39c8 00007ffccc3814a0       72     
000001aa2acb3fd8 00007ffccc3814a0       72     
000001aa2ad323d0 00007ffccc3814a0       72     
...
0:000> !do 000001aa2acb39c8
Name:        System.Threading.OverlappedData
MethodTable: 00007ffccc3814a0
EEClass:     00007ffccc37ca18
Size:        72(0x48) bytes
File:        C:\xxx\xxx\vms_210819\System.Private.CoreLib.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ffccc21f508  40006b2        8  System.IAsyncResult  0 instance 0000000000000000 _asyncResult
00007ffccc110ae8  40006b3       10        System.Object  0 instance 000001aa2acb4020 _callback
00007ffccc381150  40006b4       18 ...eading.Overlapped  0 instance 000001aa2acb3980 _overlapped
00007ffccc110ae8  40006b5       20        System.Object  0 instance 000001aa2acb9fe8 _userObject
00007ffccc11f130  40006b6       28                  PTR  0 instance 000001aa2a9bd830 _pNativeOverlapped
00007ffccc11ecc0  40006b7       30        System.IntPtr  1 instance 0000000000000000 _eventHandle
0:000> !DumpObj /d 000001aa2acb3980
Name:        System.Threading.ThreadPoolBoundHandleOverlapped
MethodTable: 00007ffccc3812a0
EEClass:     00007ffccc37c9a0
Size:        72(0x48) bytes
File:        C:\xxx\xxx\vms_210819\System.Private.CoreLib.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ffccc3814a0  40006ba        8 ...ng.OverlappedData  0 instance 000001aa2acb39c8 _overlappedData
00007ffccc34fcd0  40006a4       10 ...ompletionCallback  0 instance 000001aa2acb3920 _userCallback
00007ffccc110ae8  40006a5       18        System.Object  0 instance 000001aa2acb38c8 _userState
00007ffccc380120  40006a6       20 ...locatedOverlapped  0 instance 000001aa2acb3960 _preAllocated
00007ffccc11f130  40006a7       30                  PTR  0 instance 000001aa2a9bd830 _nativeOverlapped
00007ffccc380eb8  40006a8       28 ...adPoolBoundHandle  0 instance 000001aa2acb3900 _boundHandle
00007ffccc1171c8  40006a9       38       System.Boolean  1 instance                0 _completed
00007ffccc34fcd0  40006a3      458 ...ompletionCallback  0   static 000001aa2acb4020 s_completionCallback
0:000> !DumpObj /d 000001aa2acb3900
Name:        System.Threading.ThreadPoolBoundHandle
MethodTable: 00007ffccc380eb8
EEClass:     00007ffccc37c870
Size:        32(0x20) bytes
File:        C:\xxx\xxx\vms_210819\System.Private.CoreLib.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ffccc1d76b0  40006a1        8 ...rvices.SafeHandle  0 instance 000001aa2acb1d30 _handle
00007ffccc1171c8  40006a2       10       System.Boolean  1 instance                0 _isDisposed

0:000> !DumpObj /d 000001aa2acb1d30
Name:        Microsoft.Win32.SafeHandles.SafeFileHandle
MethodTable: 00007ffccc3807c8
EEClass:     00007ffccc37c548
Size:        48(0x30) bytes
File:        C:\xxx\xxx\xxx\System.Private.CoreLib.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ffccc11ecc0  4000bb4        8        System.IntPtr  1 instance 0000000000000428 handle
00007ffccc11b1e8  4000bb5       10         System.Int32  1 instance                4 _state
00007ffccc1171c8  4000bb6       14       System.Boolean  1 instance                1 _ownsHandle
00007ffccc1171c8  4000bb7       15       System.Boolean  1 instance                1 _fullyInitialized
00007ffccc2f1ae0  4001c3d       20 ...Private.CoreLib]]  1 instance 000001aa2acb1d50 _isAsync
00007ffccc380eb8  4001c3e       18 ...adPoolBoundHandle  0 instance 0000000000000000 <ThreadPoolBinding>k__BackingField

上面倒數第五行的 0000000000000428 就是具體的 handle 值,接下來就可以用 !handle 命令檢視其值的具體資訊。


0:000> !handle 0000000000000428 7
Handle 428
  Type         	File
  Attributes   	0
  GrantedAccess	0x100081:
         Synch
         Read/List,ReadAttr
  HandleCount  	2
  PointerCount 	65489

Type:File 可以看出,原來這 8000 多都是檔案控制程式碼哈。。。

寫到這裡貌似就到了死衚衕了???,雖然挖了一些資訊,但這些資訊還不足以讓我找到問題根源,從引用鏈上來說,gchandles 中的這些物件是處於引用鏈的頂端,換句話說,我需要找到這條引用鏈下游的一些資料物件,一個好的入口點就是到 heap 中去挖。

3. 從託管堆找 OverlappedData 的徒孫輩

首先我們用 !dumpheap -stat 檢視下託管堆。


0:000> !dumpheap -stat
Statistics:
              MT    Count    TotalSize Class Name
...

00007ffccc3c5e18   939360     52604160 System.Collections.Generic.SortedSet`1+Node[[System.Collections.Generic.KeyValuePair`2[[System.String, System.Private.CoreLib],[System.String, System.Private.CoreLib]], System.Private.CoreLib]]
00007ffccc1d2360    16492     69081162 System.Byte[]
000001aa2a99af00    10365     76689384      Free
00007ffccc1d1e18  1904987    116290870 System.String

既然是找引用鏈下游,那就從基礎型別 System.String 或者 System.Byte[] 入手,這裡我就選擇前者,寫了一個對 mt 下所有 address 進行分組統計的指令碼,畢竟人肉是不可能的,從指令碼的輸出中我抽了幾個 address 檢視 !gcroot,大概都是類似這樣的內容。


0:000> !gcroot 000001aa47a0c030
HandleTable:
    000001AA4469C090 (async pinned handle)
    -> 000001AA491EB908 System.Threading.OverlappedData
    -> 000001AA491EB8C0 System.Threading.ThreadPoolBoundHandleOverlapped
    -> 000001AA491EB860 System.Threading.IOCompletionCallback
    -> 000001AA491EAF30 System.IO.FileSystemWatcher
    -> 000001AA491EB458 System.IO.FileSystemEventHandler
    ...
    -> 000001AA47A0C030 System.String

0:000> !gcroot 000001aa2d3ea480
HandleTable:
    000001AA28FE9930 (async pinned handle)
    -> 000001AA2DD68220 System.Threading.OverlappedData
    -> 000001AA2DD681D8 System.Threading.ThreadPoolBoundHandleOverlapped
    -> 000001AA2DD68178 System.Threading.IOCompletionCallback
    -> 000001AA2DD67848 System.IO.FileSystemWatcher
    ...
    -> 000001AA2D3EA480 System.String    

從整個引用鏈來看,裡面都有一個 System.IO.FileSystemWatcher ,這和前面分析的 handle= File 是一致的,然後就是匯出這些 string ,發現大部分都是和 appSettings 相關,如下所示:


string: appSettings:RabbitMQLogQueue
string: appSettings:MedicalMediaServerIP
string: appSettings:UseHttps
...

然後用 !strings 命令進行了模糊匹配,發現這樣的string 高達 61w 。。。

到這裡基本就能斷定:appsettings 被 watch 了,但 watch 的方式有問題。。。

4. 尋找最終答案

將調查結果給了朋友之後,讓朋友著重觀察下對 appsetting 進行 watch 的方式是否有問題? 幾個小時後,朋友終於找到了。


大概意思是說:本身已經通過設定 reloadOnChange=true 對 appsetings 進行了監控,但寫碼的人對這一塊不熟悉,又通過每10s一次輪詢對appsettings進行資料感知,問題就出現在這裡。。。

三:總結

其實本次事故的主要原因還是在於對如何實時感知 appsettings 中最新資料的玩法不熟悉,一邊用了 .netcore 自帶的 reloadOnChange 監控,一邊還用輪詢的方式進行資料感知,所以說基礎還是很重要的,不要想當然的去寫! ???

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

圖片名稱

相關文章