記一次 .NET 某工控MES程式 崩潰分析

一線碼農發表於2022-12-16

一：背景

1.講故事

前幾天有位朋友找到我，說他的程式出現了偶發性崩潰，已經抓到了dump檔案，Windows事件日誌顯示的崩潰點在 clr.dll 中，讓我幫忙看下是怎麼回事，那到底怎麼回事呢? 上 WinDbg 說話。

二：WinDbg 分析

1. 崩潰點在哪裡

如果是託管程式碼引發的崩潰，線上程列表上會有一個異常資訊，可以用 !t 來驗證下。


0:000> !t
ThreadCount:      7
UnstartedThread:  0
BackgroundThread: 6
PendingThread:    0
DeadThread:       0
Hosted Runtime:   no
                                                                                                        Lock  
       ID OSID ThreadOBJ           State GC Mode     GC Alloc Context                  Domain           Count Apt Exception
   0    1  cb4 000000000077fbd0    26020 Preemptive  0000000000000000:0000000000000000 0000000000734050 0     STA (GC) System.ExecutionEngineException 00000000028a11f8
   2    2  890 0000000000782ea0    2b220 Preemptive  0000000000000000:0000000000000000 0000000000734050 0     MTA (Finalizer) 
   5    3  f6c 0000000021301f50  1029220 Preemptive  0000000000000000:0000000000000000 0000000000734050 0     Ukn (Threadpool Worker) 
  12    5  a38 00000000213dc090    2b220 Preemptive  0000000000000000:0000000000000000 0000000000734050 0     MTA 
  15    6  cb8 0000000021430740    2b220 Preemptive  0000000000000000:0000000000000000 0000000000734050 0     MTA 
  16    7  ce4 00000000318421c0    2b220 Preemptive  0000000000000000:0000000000000000 0000000000734050 0     MTA 
  17    4  f1c 00000000370edab0  102a220 Preemptive  0000000000000000:0000000000000000 0000000000734050 0     MTA (Threadpool Worker) 
...

從卦中看，主執行緒正在觸發 GC，並且丟擲了一個 System.ExecutionEngineException 異常，這個異常屬於災難性的，表示 CLR 自己出問題了，那 CLR 在哪裡出問題了呢？我們觀察下主執行緒的非託管棧。


0:000> ~0s
clr!WKS::gc_heap::find_first_object+0xea:
000007fe`ea17644b 833800          cmp     dword ptr [rax],0 ds:000007fe`00000000=????????

0:000> r
rax=000007fe00000000 rbx=000000000051a830 rcx=0000000000000018
rdx=000000000303f160 rsi=0000000000000000 rdi=000000000051a340
rip=000007feea17644b rsp=000000000051aa58 rbp=00000000000028a1
 r8=0000000000000001  r9=000000000303f160 r10=0000000003040000
r11=000000000000303f r12=0000000000000001 r13=000000000051c860
r14=00000000033b8c59 r15=00000000033b8c58
iopl=0         nv up ei pl nz na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010204
clr!WKS::gc_heap::find_first_object+0xea:
000007fe`ea17644b 833800          cmp     dword ptr [rax],0 ds:000007fe`00000000=????????

0:000> k 10
 # Child-SP          RetAddr               Call Site
00 00000000`0051aa58 000007fe`ea175d7b     clr!WKS::gc_heap::find_first_object+0xea
01 00000000`0051aa70 000007fe`ea1040d4     clr!WKS::GCHeap::Promote+0xc7
02 00000000`0051aae0 000007fe`ea1001b8     clr!GcInfoDecoder::EnumerateLiveSlots+0x103a
03 00000000`0051af50 000007fe`ea100e16     clr!GcStackCrawlCallBack+0x2bd
04 00000000`0051b370 000007fe`ea16e35c     clr!GCToEEInterface::GcScanRoots+0x4d6
05 00000000`0051c830 000007fe`ea16ee9b     clr!WKS::gc_heap::mark_phase+0x17f
06 00000000`0051c8d0 000007fe`ea16edaf     clr!WKS::gc_heap::gc1+0xa3
07 00000000`0051c920 000007fe`ea170c0f     clr!WKS::gc_heap::garbage_collect+0x193
08 00000000`0051c960 000007fe`ea173be6     clr!WKS::GCHeap::GarbageCollectGeneration+0xef
09 00000000`0051c9b0 000007fe`ea1d5ccf     clr!AllocateArrayEx+0x69c
0a 00000000`0051cb40 000007fe`ea24c480     clr!FieldMarshaler_FixedArray::UpdateCLRImpl+0x40
0b 00000000`0051cb80 000007fe`ea24c3ac     clr!FieldMarshaler::UpdateCLR+0x68
0c 00000000`0051cca0 000007fe`ea24c74c     clr!LayoutUpdateCLR+0x213
0d 00000000`0051cd80 000007fe`ea24c6aa     clr!FmtValueTypeUpdateCLR+0x50
0e 00000000`0051cdb0 000007fe`e2c88134     clr!StubHelpers::ValueClassMarshaler__ConvertToManaged+0x9a
0f 00000000`0051cf20 000007fe`e2c7e335     System_Drawing_ni+0x78134

從卦中的執行緒棧上看，GC 處於三階段中的 標記階段，正在各個執行緒棧上尋找使用者根遇到了一個異常地址 000007fe00000000，最後丟擲異常了，那這個地址屬於什麼記憶體屬性呢？可以用 !address 000007fe00000000 觀察一下。


0:000> !address 000007fe00000000

Usage:                  Free
Base Address:           00000001`801d3000
End Address:            000007fe`8a9f0000
Region Size:            000007fd`0a81d000 (   7.988 TB)
State:                  00010000          MEM_FREE
Protect:                00000001          PAGE_NOACCESS
Type:                   <info not present at the target>

Content source: 0 (invalid), length: 8a9f0000

從卦中可以看到，在這個地址是 PAGE_NOACCESS 的，理所當然會丟擲訪問違例，既然 gc 在託管堆上用 find_first_object 遇到了一個異常地址，說明這塊記憶體被破壞了，可以用 !VerifyHeap 去驗證下託管堆。


0:000> !VerifyHeap
Could not request method table data for object 000000000303F160 (MethodTable: 000007FE00000000).
Last good object: 000000000303F140.

從卦中可以清晰的看到，地址 000000000303F160 上的方法表地址 000007FE00000000 被破壞了，這個地址剛好就是彙編程式碼顯示的這個。

2. 方法表地址為什麼會被損壞

一般來說這個損壞是在崩潰前的某一次 託管和非託管 互動時產生的，在後續的某個時候 GC 在清洗託管堆時才發現家裡被偷繼而報警，但此時已經錯過了第一時間，畫個圖大概是這樣。

由於 dump 只是一個快照，無法追蹤曾經發生了什麼事？只能死馬當活馬醫，看看目前的破壞現場，可以用 !lno 000000000303F160 觀察破壞物件的前後物件和附近記憶體。


0:000> !lno 000000000303F160
Before:  000000000303f140           32 (0x20)	System.Byte[]
After:   000000000303f198           24 (0x18)	System.Int32
Heap local consistency not confirmed.

0:000> dp 000000000303F160 - 0n144 L20
00000000`0303f0d0  00000000`00000000 000007fe`e794aaa0
00000000`0303f0e0  00000000`0000000e 33313231`32323032
00000000`0303f0f0  00003835`34323131 00000000`00000000
00000000`0303f100  000007fe`e794aaa0 00000000`00000001
00000000`0303f110  00000000`00000000 00000000`00000000
00000000`0303f120  000007fe`e794aaa0 00000000`00000001
00000000`0303f130  00000000`00000000 00000000`00000000
00000000`0303f140  000007fe`e794aaa0 00000000`00000001
00000000`0303f150  39353932`30303038 00000000`36373135
00000000`0303f160  000007fe`00000000 00700055`0000000e
00000000`0303f170  00640061`006f006c 00750073`00650052
00000000`0303f180  0050003a`0074006c 00000000`00000000
00000000`0303f190  00000000`00000000 000007fe`e79485a0
00000000`0303f1a0  00000000`00000004 00000000`00000000
00000000`0303f1b0  000007fe`e79459c0 00000034`00000001
00000000`0303f1c0  00000000`00000000 00000000`00000000

仔細觀察 000000000303f160 處的記憶體佈局，很明顯這是一個 string 型別, 地址 007000550000000e 上的低八位的 0xe = 0n13 表示 string 的長度，但 string 的高八位 00700055 理應是對齊的 00000000，看樣子被非託管程式碼纂改了，並且把原來正確的方法表地址 000007fee79459c0 的低八位給覆蓋成了 000007fe00000000，導致最後的崩潰。

如果再仔細觀察，你會發現 000000000303f150 處也是一個 unicode 字元，但它不屬於 000000000303f140 處的 byte[] 物件，可以用 !do 驗證。


0:000> !do 000000000303f140
Name:        System.Byte[]
MethodTable: 000007fee794aaa0
EEClass:     000007fee7ab6c78
Size:        25(0x19) bytes
Array:       Rank 1, Number of elements 1, Type Byte (Print Array)
Content:     8
Fields:
None

這也就說明 000000000303f150 ~ 000000000303f170 附近的記憶體全部被破壞了，不過慶幸的是：這些看起來都是一些字元，接下來用 db 顯示一下。


0:000> db 000000000303f150
00000000`0303f150  38 30 30 30 32 39 35 39-35 31 37 36 00 00 00 00  800029595176....
00000000`0303f160  00 00 00 00 fe 07 00 00-0e 00 00 00 55 00 70 00  ............U.p.
00000000`0303f170  6c 00 6f 00 61 00 64 00-52 00 65 00 73 00 75 00  l.o.a.d.R.e.s.u.
00000000`0303f180  6c 00 74 00 3a 00 50 00-00 00 00 00 00 00 00 00  l.t.:.P.........
00000000`0303f190  00 00 00 00 00 00 00 00-a0 85 94 e7 fe 07 00 00  ................
00000000`0303f1a0  04 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00  ................
00000000`0303f1b0  c0 59 94 e7 fe 07 00 00-01 00 00 00 34 00 00 00  .Y..........4...
00000000`0303f1c0  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00  ................

從卦中的 UploadResult:P 來看，貌似是一個上傳結果，在結合 !lno 顯示的前後物件分別是 Byte[] 和 Int32，應該是 朋友用 class 的方式實現 C# 和 C++ 的互動，C++ 在操作 class 下的某一個 string 時 指標溢位， 破壞了託管堆的 string 物件。

將這些資訊告訴朋友後，朋友說也已經定位到這裡了，正和對方的工程師做對接，對方反饋過來是託管層要自己預留足夠的長度。

三： 總結

其實崩潰類的 dump 最能考驗基本功，需要你對 C# 物件的記憶體佈局有一個深度的理解，否則也很難發現出端倪，當然本篇還屬於崩潰類中較容易的。

相信有朋友肯定要問，如何找到破壞的第一現場，這當然是可以的，需要藉助微軟的 MDA 助手, 配置 gcManagedToUnmanaged 和 gcUnmanagedToManaged 兩項，讓雙方互動之後立即觸發 GC，具體參見： https://learn.microsoft.com/zh-cn/dotnet/framework/debug-trace-profile/gcunmanagedtomanaged-mda

相關文章