記一次 .NET 醫院CIS系統 記憶體溢位分析

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

一:背景

1. 講故事

前幾天有位朋友加wx求助說他的程式最近總是出現記憶體溢位,很崩潰,如下圖:

和這位朋友聊下來,發現他也是搞醫療的,哈哈,.NET 在醫療方面還是很有市場的???,不過對於記憶體方面出的問題,我得先祈禱一下千萬不要是非託管。。。

廢話不多說,上 windbg,看能不能先救個急。

二: windbg 分析

1. 找出異常物件

如果記憶體溢位了,大家應該知道 C# 會拋一個 OutOfMemoryException 異常,而且還會附加到那個執行執行緒上,所以先用 !t 命令調出當前的所有託管執行緒。


0:000> !t
ThreadCount:      17
UnstartedThread:  0
BackgroundThread: 12
PendingThread:    0
DeadThread:       4
Hosted Runtime:   no
                                                                         Lock  
       ID OSID ThreadOBJ    State GC Mode     GC Alloc Context  Domain   Count Apt Exception
   0    1 16b0 007da908     26020 Preemptive  64EDD188:00000000 00823830 1     STA System.OutOfMemoryException 57b53d90
   2    2  af8 007e9dc8     2b220 Preemptive  00000000:00000000 007d4838 0     MTA (Finalizer) 
   3    3 1d94 0081af28     21220 Preemptive  00000000:00000000 007d4838 0     Ukn 
   5    6 246c 0772b960   102a220 Preemptive  00000000:00000000 007d4838 0     MTA (Threadpool Worker) 
   8   47 277c 2eebf038   8029220 Preemptive  00000000:00000000 007d4838 0     MTA (Threadpool Completion Port) 
XXXX   41    0 2eebf580   1039820 Preemptive  00000000:00000000 007d4838 0     Ukn (Threadpool Worker)

可以清楚的看到,0號 執行緒果然帶了一個 System.OutOfMemoryException,接下來用 !pe 查查這個異常的呼叫棧資訊。


0:000> !pe 57b53d90
Exception object: 57b53d90
Exception type:   System.OutOfMemoryException
Message:          沒有足夠的記憶體繼續執行程式。
InnerException:   <none>
StackTrace (generated):
    SP       IP       Function
    00482C80 6450BD46 mscorlib_ni!System.Runtime.InteropServices.Marshal.AllocHGlobal(IntPtr)+0xc2fdf6
    00482CB0 198DCEF2 UNKNOWN!FastReport.Export.TTF.TrueTypeCollection..ctor(System.Drawing.Font)+0xe2
    00482D00 198DCC0F UNKNOWN!FastReport.Export.TTF.ExportTTFFont.GetFontData()+0x47
    00482D58 198DAD54 UNKNOWN!FastReport.Export.Pdf.PDFExport.WriteFont(FastReport.Export.TTF.ExportTTFFont)+0xa4
    00483A7C 198D9CD5 UNKNOWN!FastReport.Export.Pdf.PDFExport.AddPDFFooter()+0x8d
    00483C38 198D9B53 UNKNOWN!FastReport.Export.Pdf.PDFExport.Finish()+0x23
    00483C80 19938119 UNKNOWN!FastReport.Export.ExportBase.Export(FastReport.Report, System.IO.Stream)+0x229
    00483CD8 19937A9D UNKNOWN!FastReport.Export.ExportBase.Export(FastReport.Report, System.String)+0x4d
    00483D08 19937A3D UNKNOWN!FastReport.Report.Export(FastReport.Export.ExportBase, System.String)+0xd
    00483D10 15D9FA39 UNKNOWN!xxxx.xxx.FormPrint.PrintPdf(Boolean, System.String, xxxx.DAL.xxx.DataObject.IPatinfoBase, Boolean, System.String)+0x359
    00483DF0 137B265A UNKNOWN!xxxx.UI.xxx.PrintOrdert2PDF.Handle(System.Object[])+0x3ca
    00483EB4 1178B36C xxx_PrintOrder2Pdf!xxxx.xxx.PrintOrder2Pdf.Form1.timer1_Tick(System.Object, System.EventArgs)+0xca4
    0048414C 117884DD UNKNOWN!System.Windows.Forms.Timer.OnTick(System.EventArgs)+0x15
    00484154 117883A0 UNKNOWN!System.Windows.Forms.Timer+TimerNativeWindow.WndProc(System.Windows.Forms.Message ByRef)+0x38
    00484160 07C939B7 UNKNOWN!System.Windows.Forms.NativeWindow.Callback(IntPtr, Int32, IntPtr, IntPtr)+0x5f

從上面的呼叫棧可以看出,貌似程式是在做一個 pdf 列印,最後在 Marshal.AllocHGlobal 上拋了異常,熟悉這個方法的朋友應該知道,它就是用來分配 非託管記憶體 的。。。 情況貌似有點不妙。???

接下來用 ILSpy 查一下 AllocHGlobal 方法的原始碼,看看有什麼可挖掘的地方。

從圖中原始碼邏輯可以看出,一旦非託管記憶體分配失敗,託管層上手工丟擲 OutOfMemoryException 異常,我去,這難道是非託管記憶體溢位啦???

2. 真的是非託管溢位了嗎?

要鑑別是否為非託管堆出的問題,還是用那個老辦法,看看 MEM_COMMIT Size ≈ GC Heap Size 即可。

  • !address -summary 檢視程式的記憶體使用量

0:000> !address -summary

--- Usage Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
<unknown>                             16334          460bb000 (   1.094 GB)  78.00%   54.72%
Free                                  11177          26319000 ( 611.098 MB)           29.84%
Image                                   831           e48e000 ( 228.555 MB)  15.91%   11.16%
Heap                                    184           4547000 (  69.277 MB)   4.82%    3.38%
Stack                                    61           11c0000 (  17.750 MB)   1.24%    0.87%
Other                                    10             60000 ( 384.000 kB)   0.03%    0.02%
TEB                                      20             24000 ( 144.000 kB)   0.01%    0.01%
PEB                                       1              3000 (  12.000 kB)   0.00%    0.00%

--- State Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_COMMIT                            16213          521bd000 (   1.283 GB)  91.43%   64.15%
MEM_FREE                              11177          26319000 ( 611.098 MB)           29.84%
MEM_RESERVE                            1228           7b1a000 ( 123.102 MB)   8.57%    6.01%

從上面的 MEM_COMMIT 指標可以看出記憶體使用量為 1.28 G

  • !gcheap -gc 看看託管堆的大小

0:000> !eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0x64c534f8
generation 1 starts at 0x64bccb84
generation 2 starts at 0x02531000
ephemeral segment allocation context: none

GC Heap Size:    Size: 0x195be7b0 (425453488) bytes.

從最後一行可以看出託管堆佔用了 425453488/1024/1024 = 405M

也就是說大概 800M 不知道哪裡去了,看似有點嚇人,其實算算也還可以,這裡我稍微補充一下,看下面的公式:

MEM_COMMIT (1.28G) = Image (228M) + Heap (69M) + Stack (18M) + GCHeap(450M) + GCLoader (153M) + else = 918M

從上面列出來的資訊可以看出,最後累積出的 918M 和 記憶體使用量 1.28G 差不了多少,有些朋友可能要問, 這個 GCLoader 怎麼算出來的,很簡單,它是 CLR 的載入堆,使用 !eeheap -loader 即可。


0:000> !eeheap -loader
--------------------------------------
Total LoaderHeap size:   Size: 0x995a000 (160800768) bytes total, 0x13e000 (1302528) bytes wasted.
=======================================

到這裡,我陷入了僵局???,才 1.28G 的記憶體佔用,怎麼就會把程式給弄溢位了? 既然記憶體上看不出問題,那就從執行緒上入手吧,看看他們都在做什麼?

3. 檢視每個執行緒都在做什麼?

要想看執行緒,可以用 ~*e !clrstack 調出所有執行緒的託管棧,突然我發現主執行緒有點奇怪,呼叫棧特別深,不信我截圖跟你看。

從圖中可以看到,xxx.xxx.PrintOrder2Pdf.Form1.timer1_Tick 高達 133 個,這說明 Form 窗體上有一個 timer 沒有控制好,出現重複執行的情況了,不管怎麼說,這個地方肯定有問題,接下來要做的就是把這個 timer1_Tick 原始碼匯出來看看怎麼寫的,還是用那個 !name2ee + !savemodule 老命令匯出,程式碼簡化如下。


private void timer1_Tick(object sender, EventArgs e)
{
	if (!IsContinue)
	{
		PrintMsg("等待上一掃描執行完畢");
		IsContinue = true;
		return;
	}
	IsContinue = false;
	GetPatList();
	if (PatList == null || PatList.Rows.Count == 0)
	{
		timer1.Interval = 600000;
		PrintMsg("xxxx");
		IsContinue = true;
		return;
	}
	for (int i = 0; i < PatList.Rows.Count; i++)
        {
          xxx
        }
    IsContinue=true;
}

從程式碼中可以看出,這個方法用了很多的 IsContinue 來踢掉重複請求,但最終還是出了bug,導致無限量遞迴,跟朋友溝通後建議用 Stop()Start() 來處理,參考如下程式碼:


        private void button1_Click(object sender, EventArgs e)
        {
            timer1.Interval = 2000;

            timer1.Tick += Timer1_Tick;

            timer1.Start();
        }

        private void Timer1_Tick(object sender, EventArgs e)
        {
            timer1.Stop();
            MessageBox.Show("hello");
            timer1.Start();
        }

起碼這種 停止啟動 的方式肯定能規避timer的重複執行,先把這個改了再說,給醫院那邊先部署上,再觀後效。。。

三:總結

朋友在五一節後,也就是前天給醫院部署上了,昨天反饋沒有再出現問題,截一張圖證明一下???。

大家應該也看的出來,其實我心裡是沒底的。。。後續和朋友再溝通,發現了三點資訊:

  • 醫生的電腦配置為 8G or 12G

  • 有時候為了一些便利,醫生會開雙程式

  • 還有更多其他模組的記憶體溢位案例

看了下程式是採用外掛式程式設計,而且還用了 DevExpress + FastReport 這些重量級的元件,再搭配上醫生開的雙程式讓電腦餘下的貧瘠記憶體更加吃緊,可能這才是程式在 1.2G 就分配不到非託管記憶體的深層原因,現場情況應該更復雜,只能先到這裡了。

建議措施如下,很簡單。

  • 增加電腦的配置,up 到 16G 最好了,畢竟甲方都不差錢 ???

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

相關文章