記一次 .NET 某物管后臺服務卡死分析

一：背景

1. 講故事

這幾個月經常被朋友問，為什么不更新這個系列了，哈哈，確實停了好久，主要還是打基礎去了，分析 dump 的能力不在于會靈活使用 windbg，而是對底層知識有一個深厚的理解，比如：匯編，C， C++，Win32 Api，虛擬內存，Windows 用戶態和內核態，這是我今年看的書給大家分享一下。

前段時候微信上有位朋友說他的程序出現了卡死，所有線程都不工作了，聽起來還挺嚇人的，截圖如下：

接下來直接上 WinDbg 分析吧。

二：Windbg 分析

1. 卡死分析

既然說程序所有線程都不工作了，大概率應該是此時 GC 觸發了，曾經看過一個dump中 GC 在創建 background thread 時，由于 dllmain 的死鎖造成了 background thread 無法生成引發的死鎖問題。

有了這個思路，接下來用 ~* k 看一下所有的線程棧，是否有GarbageCollectGeneration 函數，因為它是 GC 觸發入口點, 果然不出所料，46號線程觸發了 GC 操作。

46??Id:?396c.3198?Suspend:?0?Teb:?00007ff6`22646000?Unfrozen#?Child-SP??????????RetAddr???????????????Call?Site
00?00000028`d420bc18?00007ffa`8b6b8b61?????ntdll!NtWaitForSingleObject+0xa
01?00000028`d420bc20?00007ffa`8b6b7124?????ntdll!RtlpWaitOnCriticalSection+0xe1
02?00000028`d420bcf0?00000001`8000a725?????ntdll!RtlpEnterCriticalSectionContended+0xa4
03?00000028`d420bd30?00000001`80011773?????WiseVectorHelperOne_X64+0xa725
04?00000028`d420bd90?00007ffa`888faf8f?????WiseVectorHelperOne_X64+0x11773
05?00000028`d420d2d0?00007ffa`79db4d45?????KERNELBASE!ResumeThread+0xf
06?00000028`d420d300?00007ffa`79db8bee?????coreclr!Thread::ResumeThread+0x29?[d:\a\_work\1\s\src\vm\threadsuspend.cpp?@?466]?
07?00000028`d420d350?00007ffa`79e13905?????coreclr!ThreadSuspend::SuspendRuntime+0x17a?[d:\a\_work\1\s\src\vm\threadsuspend.cpp?@?4046]?
08?00000028`d420d420?00007ffa`79db61cf?????coreclr!ThreadSuspend::SuspendEE+0x16d?[d:\a\_work\1\s\src\vm\threadsuspend.cpp?@?6517]?
09?(Inline?Function)?--------`--------?????coreclr!GCToEEInterface::SuspendEE+0x21?[d:\a\_work\1\s\src\vm\gcenv.ee.cpp?@?25]?
0a?00000028`d420d5c0?00007ffa`79e325be?????coreclr!WKS::GCHeap::GarbageCollectGeneration+0xff?[d:\a\_work\1\s\src\gc\gc.cpp?@?36545]?
0b?(Inline?Function)?--------`--------?????coreclr!WKS::gc_heap::trigger_gc_for_alloc+0x12?[d:\a\_work\1\s\src\gc\gc.cpp?@?13832]?
0c?00000028`d420d610?00007ffa`79e35118?????coreclr!WKS::gc_heap::try_allocate_more_space+0x24e?[d:\a\_work\1\s\src\gc\gc.cpp?@?13934]?
0d?(Inline?Function)?--------`--------?????coreclr!WKS::gc_heap::allocate_more_space+0x11?[d:\a\_work\1\s\src\gc\gc.cpp?@?14369]?
0e?(Inline?Function)?--------`--------?????coreclr!WKS::gc_heap::allocate+0x58?[d:\a\_work\1\s\src\gc\gc.cpp?@?14400]?
0f?00000028`d420d690?00007ffa`79dcda8e?????coreclr!WKS::GCHeap::Alloc+0x88?[d:\a\_work\1\s\src\gc\gc.cpp?@?35827]

從線程棧看，流程大概是：C# 分配一個對象，觸發了 GC，然后暫停了所有托管線程，然后又恢復了其中一個線程，應該是此線程沒有停留在 gc 安全點上，重啟是為了讓它在安全點暫停，在 coreclr 源碼上也能看的出來。

接下來就進入了 WiseVectorHelperOne_X64 類庫，很陌生的一個 dll，最后進入了 臨界區 CriticalSection ，所謂的 臨界區 是一個 win32 函數，用法和我們的 lock 差不多，最后就停留在臨界區，其實到這里現象就很明朗了，所有的托管線程都暫停了，也符合朋友說的程序卡死，接下來就要分析為什么程序退不出 臨界區 ？

2. 為啥退不出 CriticalSection

要想尋找這個答案，可以用 !locks 來觀察當前處于 臨界區 的線程，輸出如下：

0:000>?!locksCritSec?+63218af0?at?0000002863218af0
WaiterWoken????????No
LockCount??????????0
RecursionCount?????1
OwningThread???????3198
EntryCount?????????0
ContentionCount????16d
***?LockedCritSec?WiseVectorHelperOne_X64+6a9a8?at?000000018006a9a8
WaiterWoken????????No
LockCount??????????1
RecursionCount?????1
OwningThread???????3090
EntryCount?????????0
ContentionCount????1
***?LockedScanned?64?critical?sections

根據經驗，第一反應應該是 臨界區死鎖 了，經驗歸經驗，接下來我們依次看下 ?3198 和 3090 各自都在等什么？

3. 真的是臨界區死鎖嗎

首先用命令切到 3198 線程，看看它正在等待什么資源？

0:038>??~~[3198]s
ntdll!NtWaitForSingleObject+0xa:
00007ffa`8b710c8a?c3??????????????ret
0:046>?kb#?RetAddr???????????????:?Args?to?Child???????????????????????????????????????????????????????????:?Call?Site
00?00007ffa`8b6b8b61?????:?00000001`8006a9a8?00000000`00000000?00000000`00000000?00000000`00000000?:?ntdll!NtWaitForSingleObject+0xa
01?00007ffa`8b6b7124?????:?00000000`00000000?00000000`00000000?00000001`8006a9a8?00000000`00000000?:?ntdll!RtlpWaitOnCriticalSection+0xe1
02?00000001`8000a725?????:?00000028`00668230?00000000`00000000?00000028`7fc9d9b0?00000028`00668230?:?ntdll!RtlpEnterCriticalSectionContended+0xa4
03?00000001`80011773?????:?00000001`00000aa8?00000000`00000000?00000000`00000000?00000000`00000000?:?WiseVectorHelperOne_X64+0xa725
04?00007ffa`888faf8f?????:?00000000`00000aa8?00000028`d420d308?00000000`00000000?00000000`00000000?:?WiseVectorHelperOne_X64+0x11773
05?00007ffa`79db4d45?????:?00000000`00000000?00000000`00000000?00000028`04dec6e0?00000001`8000cc3a?:?KERNELBASE!ResumeThread+0xf
06?00007ffa`79db8bee?????:?00000028`00668230?00000000`00000040?00000000`00000001?00000000`00000000?:?coreclr!Thread::ResumeThread+0x29?[d:\a\_work\1\s\src\vm\threadsuspend.cpp?@?466]?
07?00007ffa`79e13905?????:?00000000`00000003?00000000`00000001?00000000`00000001?00000000`00000000?:?coreclr!ThreadSuspend::SuspendRuntime+0x17a?[d:\a\_work\1\s\src\vm\threadsuspend.cpp?@?4046]?
08?00007ffa`79db61cf?????:?00000000`00001e73?00000000`00001e01?00000028`7f9f6698?00000000`00000000?:?coreclr!ThreadSuspend::SuspendEE+0x16d?[d:\a\_work\1\s\src\vm\threadsuspend.cpp?@?6517]?
09?(Inline?Function)?????:?--------`--------?--------`--------?--------`--------?--------`--------?:?coreclr!GCToEEInterface::SuspendEE+0x21?[d:\a\_work\1\s\src\vm\gcenv.ee.cpp?@?25]?
0a?00007ffa`79e325be?????:?a2098c12`cdff0000?00007ffa`79e35118?00007ffa`7a28c668?00000000`00000000?:?coreclr!WKS::GCHeap::GarbageCollectGeneration+0xff?[d:\a\_work\1\s\src\gc\gc.cpp?@?36545]?
0b?(Inline?Function)?????:?--------`--------?--------`--------?--------`--------?--------`--------?:?coreclr!WKS::gc_heap::trigger_gc_for_alloc+0x12?[d:\a\_work\1\s\src\gc\gc.cpp?@?13832]?
0c?00007ffa`79e35118?????:?00000028`7fc9da08?00000028`12bba6d8?00000000`00000002?00007ffa`79dbfc9f?:?coreclr!WKS::gc_heap::try_allocate_more_space+0x24e?[d:\a\_work\1\s\src\gc\gc.cpp?@?13934]?
0d?(Inline?Function)?????:?--------`--------?--------`--------?--------`--------?--------`--------?:?coreclr!WKS::gc_heap::allocate_more_space+0x11?[d:\a\_work\1\s\src\gc\gc.cpp?@?14369]?
0e?(Inline?Function)?????:?--------`--------?--------`--------?--------`--------?--------`--------?:?coreclr!WKS::gc_heap::allocate+0x58?[d:\a\_work\1\s\src\gc\gc.cpp?@?14400]?
0f?00007ffa`79dcda8e?????:?00000000`00000000?00000028`d420daa0?00007ffa`1a908888?00000028`7fc9da08?:?coreclr!WKS::GCHeap::Alloc+0x88?[d:\a\_work\1\s\src\gc\gc.cpp?@?35827]?
10?(Inline?Function)?????:?--------`--------?--------`--------?--------`--------?--------`--------?:?coreclr!Alloc+0x18b?[d:\a\_work\1\s\src\vm\gchelpers.cpp?@?240]?
11?(Inline?Function)?????:?--------`--------?--------`--------?--------`--------?--------`--------?:?coreclr!AllocateObject+0x22d?[d:\a\_work\1\s\src\vm\gchelpers.cpp?@?1209]?
12?00007ffa`1b3337e2?????:?00007ffa`1a908888?00000028`84d75cc0?00000028`12bb9ce0?00000028`64df1360?:?coreclr!JIT_New+0x31e?[d:\a\_work\1\s\src\vm\jithelpers.cpp?@?2724]?
....

從輸出信息看: NtWaitForSingleObject 正在等待 000000018006a9a8 臨界區資源，而這個正好是 !locks 的 3090 線程持有的資源，截圖如下：

接下來再看下 3090 線程正在干什么。

0:038>?~~[3090]s
WiseVectorHelperOne_X64+0xcc3a:
00000001`8000cc3a?4889442408??????mov?????qword?ptr?[rsp+8],rax?ss:00000028`04dec6e8=0000000000000000
0:038>?k#?Child-SP??????????RetAddr???????????????Call?Site
00?00000028`04dec6e0?00000001`8000f1cb?????WiseVectorHelperOne_X64+0xcc3a
01?00000028`04dec710?00000001`8000a751?????WiseVectorHelperOne_X64+0xf1cb
02?00000028`04dec7a0?00000001`80011773?????WiseVectorHelperOne_X64+0xa751
03?00000028`04dec800?00007ffa`888faf8f?????WiseVectorHelperOne_X64+0x11773
04?00000028`04dedd40?00007ffa`79e19796?????KERNELBASE!ResumeThread+0xf
05?(Inline?Function)?--------`--------?????coreclr!Thread::StartThread+0x15?[d:\a\_work\1\s\src\vm\threads.cpp?@?528]?
06?00000028`04dedd70?00007ffa`79eaacea?????coreclr!ThreadNative::StartInner+0x35a?[d:\a\_work\1\s\src\vm\comsynchronizable.cpp?@?501]?
07?00000028`04dee010?00007ffa`1b3afc02?????coreclr!ThreadNative::Start+0x8a?[d:\a\_work\1\s\src\vm\comsynchronizable.cpp?@?387]?
08?00000028`04dee160?00007ffa`1b3cb018?????System_Private_CoreLib!System.Threading.Tasks.Task.ScheduleAndStart+0x102
09?00000028`04dee1b0?00007ffa`1b40005a?????System_Private_CoreLib!System.Threading.Tasks.Task.InternalStartNew+0x78
0a?00000028`04dee230?00007ffa`1b41f181?????System_Private_CoreLib!System.Threading.Tasks.TaskFactory.StartNew+0x5a
...

從線程棧信息看，托管層執行了一個 Task.Start 操作，然后通過 Win32 Api 生成了一個 OS 線程，在準備調度 OS線程 的時候，遇上了 WiseVectorHelperOne_X64 ，最后就在這里無限期等待，tmd的真奇怪，在兩個線程中都看到了這個函數，它到底是干嘛呢？

4. 研究 WiseVectorHelperOne_X64

這個奇怪的 dll，看樣子來者不善，上 baidu 查查看。

我去，原來被一款叫做 智量殺毒軟件 給劫持了。。。具體什么原因被劫持，我也不想研究了，然后拿這個結果和朋友做了一下溝通，嘗試停掉它看看。

三：總結

綜合兩處線程棧的特征，發現都是Win32 Api 在做 Thread::ResumeThread 時被殺毒軟件劫持，一般來說 clr 在內部生成 OS 線程時，會先 Suspended，然后再 Resume，參考源碼：

BOOL?Thread::CreateNewOSThread(SIZE_T?sizeToCommitOrReserve,?LPTHREAD_START_ROUTINE?start,?void*?args)
{HANDLE?h?=?NULL;DWORD?dwCreationFlags?=?CREATE_SUSPENDED;dwCreationFlags?|=?STACK_SIZE_PARAM_IS_A_RESERVATION;h?=?::CreateThread(NULL?????/*=SECURITY_ATTRIBUTES*/,sizeToCommitOrReserve,start,args,dwCreationFlags,&ourId);
}

劫持的原因，這個只能問廠家了，我們能做的就是停掉它 😄，最后朋友太客氣了，發了一個大紅包😁😁😁