記一次 .NET某醫療器械清洗系統 卡死分析

2023-04-18 09:00:35

一:背景

1. 講故事

前段時間協助訓練營裡的一位朋友分析了一個程式卡死的問題,回過頭來看這個案例比較經典,這篇稍微整理一下供後來者少踩坑吧。

二:WinDbg 分析

1. 為什麼會卡死

因為是表單程式,理所當然就是看主執行緒此時正在做什麼? 可以用 ~0s ; k 看一下便知。


0:000> k
 # ChildEBP RetAddr      
00 00aff168 75e3bb0a     win32u!NtUserPeekMessage+0xc
01 00aff168 75e3ba7e     USER32!_PeekMessage+0x2a
02 00aff1a4 6a5d711c     USER32!PeekMessageW+0x16e
03 00aff1f0 6a5841a6     System_Windows_Forms_ni+0x23711c
...
17 00afffbc 00000000     ntdll!_RtlUserThreadStart+0x1b

從執行緒棧來看,當前的方法卡在 win32u!NtUserPeekMessage 上, 熟悉 Windows 表單訊息的朋友都知道這是提取 訊息佇列 的常規邏輯,這個方法的下一步就是通過 Wow64SystemServiceCall 進入到 Windows核心態,可以用 u 命令驗證一下。


0:000> ub win32u!NtUserPeekMessage+0xc
761d1010 b801100000      mov     eax,1001h
761d1015 ba10631d76      mov     edx,offset win32u!Wow64SystemServiceCall (761d6310)
761d101a ffd2            call    edx

朋友也給我截了圖,確實出現了卡死,那接下來的問題就是看下當前執行緒在 核心態 到底在做什麼?

2. 真的卡在核心態嗎

幸好朋友可以在卡死的機器上安裝 windbg,讓朋友在卡死的時候使用 Attch to kernel 的方式觀察核心態,截圖如下:

附加成功後,可以用 !process 0 f xxxx.exe 看到主執行緒的執行緒棧。


lkd> !process 0 f xxxx.exe
PROCESS ffffab8ebea75080
    SessionId: 1  Cid: 0f78    Peb: 009f1000  ParentCid: 1134
        ...
        THREAD ffffab8ecad14540  Cid 0f78.38f8  Teb: 00000000009f3000 Win32Thread: ffffab8ecd5dabc0 WAIT: (WrUserRequest) UserMode Non-Alertable
            ffffab8ecb31bcc0  QueueObject
        IRP List:
            ffffab8ecad82b20: (0006,0478) Flags: 00060000  Mdl: 00000000
        Not impersonating
        DeviceMap                 ffffd400aa7eed50
        Owning Process            ffffab8ebea75080       Image:         xxxx.exe
        Attached Process          N/A            Image:         N/A
        Wait Start TickCount      1117311        Ticks: 9265 (0:00:02:24.765)
        Context Switch Count      60628          IdealProcessor: 2  NoStackSwap
        UserTime                  00:00:10.796
        KernelTime                00:00:06.593
        Win32 Start Address 0x00000000006e16aa
        Stack Init ffffa88b5b18fb90 Current ffffa88b5b18e780
        Base ffffa88b5b190000 Limit ffffa88b5b189000 Call 0000000000000000
        Priority 10 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
        Child-SP          RetAddr               Call Site
        ffffa88b`5b18e7c0 fffff806`6627e370     nt!KiSwapContext+0x76
        ffffa88b`5b18e900 fffff806`6627d89f     nt!KiSwapThread+0x500
        ffffa88b`5b18e9b0 fffff806`6627d143     nt!KiCommitThreadWait+0x14f
        ffffa88b`5b18ea50 fffff806`6628679b     nt!KeWaitForSingleObject+0x233
        ffffa88b`5b18eb40 ffffa9d4`bdd32b12     nt!KeWaitForMultipleObjects+0x45b
        ffffa88b`5b18ec50 ffffa9d4`bdd352d9     win32kfull!xxxRealSleepThread+0x362
        ffffa88b`5b18ed70 ffffa9d4`bdd33f8a     win32kfull!xxxInterSendMsgEx+0xdd9
        ffffa88b`5b18eee0 ffffa9d4`bdd37870     win32kfull!xxxSendTransformableMessageTimeout+0x3ea
        ffffa88b`5b18f030 ffffa9d4`bdf1e088     win32kfull!xxxSendMessage+0x2c
        ffffa88b`5b18f090 ffffa9d4`bdf1e0e9     win32kfull!xxxCompositedTraverse+0x40
        ffffa88b`5b18f0e0 ffffa9d4`bdf1e0e9     win32kfull!xxxCompositedTraverse+0xa1
        ffffa88b`5b18f130 ffffa9d4`bdf1e0e9     win32kfull!xxxCompositedTraverse+0xa1
        ffffa88b`5b18f180 ffffa9d4`bdf1e0e9     win32kfull!xxxCompositedTraverse+0xa1
        ffffa88b`5b18f1d0 ffffa9d4`bdf1e2a7     win32kfull!xxxCompositedTraverse+0xa1
        ffffa88b`5b18f220 ffffa9d4`bde5a013     win32kfull!xxxCompositedPaint+0x37
        ffffa88b`5b18f2b0 ffffa9d4`bdd2e438     win32kfull!xxxInternalDoPaint+0x12bce3
        ffffa88b`5b18f300 ffffa9d4`bdd2e03a     win32kfull!xxxInternalDoPaint+0x108
        ffffa88b`5b18f350 ffffa9d4`bdd30f1c     win32kfull!xxxDoPaint+0x52
        ffffa88b`5b18f3b0 ffffa9d4`bdd2ff08     win32kfull!xxxRealInternalGetMessage+0xfac
        ffffa88b`5b18f880 ffffa9d4`be1871ce     win32kfull!NtUserPeekMessage+0x158
        ffffa88b`5b18f940 fffff806`6640d8f5     win32k!NtUserPeekMessage+0x2a
        ffffa88b`5b18f990 00007ffe`1816ff74     nt!KiSystemServiceCopyEnd+0x25 (TrapFrame @ ffffa88b`5b18fa00)
        00000000`0077e558 00000000`00000000     0x00007ffe`1816ff74

如果執行緒資訊很少的話,可以用 .process 將此程序作為當前上下文,然後載入使用者符號,輸出如下:


lkd> .process ffffab8ebea75080
Implicit process is now ffffab8e`bea75080
lkd> .reload
Connected to Windows 10 19041 x64 target at (Tue Mar 21 13:21:21.213 2023 (UTC + 8:00)), ptr64 TRUE
Loading Kernel Symbols
...............................................................
................................................................
................................................................
.................
Loading User Symbols
PEB is paged out (Peb.Ldr = 00000000`009f1018).  Type ".hh dbgerr001" for details
Loading unloaded module list

從剛才的執行緒棧上看,很明顯有一個 win32kfull!xxxSendMessage+0x2c 方法,熟悉 SendMessage 的朋友都知道這個是用來向某個表單發訊息的,那到底是哪一個表單呢?

3. 到底給哪個表單發訊息

要想獲取傳送表單的控制程式碼,需要提取 win32kfull!xxxSendMessage 方法的第一個引數,在 x64 的呼叫協定下,它是用 rcx 傳遞的,需要分析下組合程式碼,如果 rcx 沒有放到棧裡,那就無法提取了。

為了少點麻煩,建議讓朋友看下 32bit 的作業系統上是否也有這個問題?結果反饋說也存在,使用 !thread xxx 切到目標執行緒,使用 kb 提取第一個引數地址上的值,即:00010598,截圖如下:

丟了一個 sdbgext 外掛讓朋友看下錶單控制程式碼資訊,發現是個 64bit 的,其實除了它還可以用 Spy++ 觀察表單控制程式碼,重點就是找到這個神祕表單 是由哪個程序下的執行緒建立的,當把控制程式碼號丟進去後還真給找到了,有點黑暗中尋找到了曙光。截圖如下:

從 Spy++ 看當前表單是由程序號:000016E0下的執行緒號0000109C 建立的,經過比對,這個執行緒就是本程序的某個執行緒號。

分析到這裡其實就很明朗了,是因為這個執行緒 0000109C 建立了一個使用者控制元件,導致核心態 在某種情況下給它發訊息,接下來就是尋找到底是什麼控制元件建立的。

4. 罪魁禍首

關於非主執行緒建立使用者控制元件導致的卡死,我感覺都已經說破嘴皮了,還是有非常多的人犯這個毛病,無語哈,解決辦法就是用 bp 去攔截 System.Windows.Forms.Application+MarshalingControl..ctor 方法,具體方案可參考我的文章:【一個超經典 WinForm 卡死問題的再反思】https://www.cnblogs.com/huangxincheng/p/16868486.html

接下來就是朋友的苦苦偵錯,終於給找到了,截圖如下:

對,就是這麼一句 Intptr handle =this.Handle 程式碼,核心控制程式碼的獲取讓它在這個執行緒上生根了。

三:總結

就是這麼一句程式碼,來來回回兜了好幾圈,花費了朋友個把星期,終於給解決了,也算是一個好結果吧,這個案例需要實時觀察程式的核心態使用者態,看 dump 效果不大,造成了這麼多時間的浪費。

相信這個案例也讓公司老闆對他 刮目相看