记一次 .NET 某物管后台服务 卡死分析

一:背景

1. 讲故事

这几个月经常被朋友问,为什么不更新这个系列了,哈哈,确实停了好久,主要还是打基础去了,分析 dump 的能力不在于会灵活使用 windbg,而是对底层知识有一个深厚的理解,比如:汇编,C, C++,Win32 Api,虚拟内存,Windows 用户态和内核态,这是我今年看的书给大家分享一下。

记一次 .NET 某物管后台服务 卡死分析

前段时候微信上有位朋友说他的程序出现了卡死,所有线程都不工作了,听起来还挺吓人的,截图如下:

记一次 .NET 某物管后台服务 卡死分析

接下来直接上 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_work1ssrcvmthreadsuspend.cpp @ 466]  07 00000028`d420d350 00007ffa`79e13905     coreclr!ThreadSuspend::SuspendRuntime+0x17a [d:a_work1ssrcvmthreadsuspend.cpp @ 4046]  08 00000028`d420d420 00007ffa`79db61cf     coreclr!ThreadSuspend::SuspendEE+0x16d [d:a_work1ssrcvmthreadsuspend.cpp @ 6517]  09 (Inline Function) --------`--------     coreclr!GCToEEInterface::SuspendEE+0x21 [d:a_work1ssrcvmgcenv.ee.cpp @ 25]  0a 00000028`d420d5c0 00007ffa`79e325be     coreclr!WKS::GCHeap::GarbageCollectGeneration+0xff [d:a_work1ssrcgcgc.cpp @ 36545]  0b (Inline Function) --------`--------     coreclr!WKS::gc_heap::trigger_gc_for_alloc+0x12 [d:a_work1ssrcgcgc.cpp @ 13832]  0c 00000028`d420d610 00007ffa`79e35118     coreclr!WKS::gc_heap::try_allocate_more_space+0x24e [d:a_work1ssrcgcgc.cpp @ 13934]  0d (Inline Function) --------`--------     coreclr!WKS::gc_heap::allocate_more_space+0x11 [d:a_work1ssrcgcgc.cpp @ 14369]  0e (Inline Function) --------`--------     coreclr!WKS::gc_heap::allocate+0x58 [d:a_work1ssrcgcgc.cpp @ 14400]  0f 00000028`d420d690 00007ffa`79dcda8e     coreclr!WKS::GCHeap::Alloc+0x88 [d:a_work1ssrcgcgc.cpp @ 35827]   

从线程栈看,流程大概是: C# 分配一个对象,触发了 GC,然后暂停了所有托管线程,然后又恢复了其中一个线程,应该是此线程没有停留在 gc 安全点上,重启是为了让它在安全点暂停,在 coreclr 源码上也能看的出来。

记一次 .NET 某物管后台服务 卡死分析

接下来就进入了 WiseVectorHelperOne_X64 类库 ,很陌生的一个 dll,最后进入了 临界区 CriticalSection ,所谓的 临界区 是一个 win32 函数,用法和我们的 lock 差不多,最后就停留在 临界区,其实到这里现象就很明朗了,所有的托管线程都暂停了,也符合朋友说的程序卡死,接下来就要分析为什么程序退不出 临界区

2. 为啥退不出 CriticalSection

要想寻找这个答案,可以用 !locks 来观察当前处于 临界区 的线程,输出如下:

 0:000> !locks  CritSec +63218af0 at 0000002863218af0 WaiterWoken        No LockCount          0 RecursionCount     1 OwningThread       3198 EntryCount         0 ContentionCount    16d *** Locked  CritSec WiseVectorHelperOne_X64+6a9a8 at 000000018006a9a8 WaiterWoken        No LockCount          1 RecursionCount     1 OwningThread       3090 EntryCount         0 ContentionCount    1 *** Locked  Scanned 64 critical sections  

根据经验,第一反应应该是 临界区死锁 了,经验归经验,接下来我们依次看下 31983090 各自都在等什么?

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_work1ssrcvmthreadsuspend.cpp @ 466]  07 00007ffa`79e13905     : 00000000`00000003 00000000`00000001 00000000`00000001 00000000`00000000 : coreclr!ThreadSuspend::SuspendRuntime+0x17a [d:a_work1ssrcvmthreadsuspend.cpp @ 4046]  08 00007ffa`79db61cf     : 00000000`00001e73 00000000`00001e01 00000028`7f9f6698 00000000`00000000 : coreclr!ThreadSuspend::SuspendEE+0x16d [d:a_work1ssrcvmthreadsuspend.cpp @ 6517]  09 (Inline Function)     : --------`-------- --------`-------- --------`-------- --------`-------- : coreclr!GCToEEInterface::SuspendEE+0x21 [d:a_work1ssrcvmgcenv.ee.cpp @ 25]  0a 00007ffa`79e325be     : a2098c12`cdff0000 00007ffa`79e35118 00007ffa`7a28c668 00000000`00000000 : coreclr!WKS::GCHeap::GarbageCollectGeneration+0xff [d:a_work1ssrcgcgc.cpp @ 36545]  0b (Inline Function)     : --------`-------- --------`-------- --------`-------- --------`-------- : coreclr!WKS::gc_heap::trigger_gc_for_alloc+0x12 [d:a_work1ssrcgcgc.cpp @ 13832]  0c 00007ffa`79e35118     : 00000028`7fc9da08 00000028`12bba6d8 00000000`00000002 00007ffa`79dbfc9f : coreclr!WKS::gc_heap::try_allocate_more_space+0x24e [d:a_work1ssrcgcgc.cpp @ 13934]  0d (Inline Function)     : --------`-------- --------`-------- --------`-------- --------`-------- : coreclr!WKS::gc_heap::allocate_more_space+0x11 [d:a_work1ssrcgcgc.cpp @ 14369]  0e (Inline Function)     : --------`-------- --------`-------- --------`-------- --------`-------- : coreclr!WKS::gc_heap::allocate+0x58 [d:a_work1ssrcgcgc.cpp @ 14400]  0f 00007ffa`79dcda8e     : 00000000`00000000 00000028`d420daa0 00007ffa`1a908888 00000028`7fc9da08 : coreclr!WKS::GCHeap::Alloc+0x88 [d:a_work1ssrcgcgc.cpp @ 35827]  10 (Inline Function)     : --------`-------- --------`-------- --------`-------- --------`-------- : coreclr!Alloc+0x18b [d:a_work1ssrcvmgchelpers.cpp @ 240]  11 (Inline Function)     : --------`-------- --------`-------- --------`-------- --------`-------- : coreclr!AllocateObject+0x22d [d:a_work1ssrcvmgchelpers.cpp @ 1209]  12 00007ffa`1b3337e2     : 00007ffa`1a908888 00000028`84d75cc0 00000028`12bb9ce0 00000028`64df1360 : coreclr!JIT_New+0x31e [d:a_work1ssrcvmjithelpers.cpp @ 2724]  ....  

从输出信息看: NtWaitForSingleObject 正在等待 000000018006a9a8 临界区资源,而这个正好是 !locks3090 线程持有的资源,截图如下:

记一次 .NET 某物管后台服务 卡死分析

接下来再看下 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_work1ssrcvmthreads.cpp @ 528]  06 00000028`04dedd70 00007ffa`79eaacea     coreclr!ThreadNative::StartInner+0x35a [d:a_work1ssrcvmcomsynchronizable.cpp @ 501]  07 00000028`04dee010 00007ffa`1b3afc02     coreclr!ThreadNative::Start+0x8a [d:a_work1ssrcvmcomsynchronizable.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 查查看。

记一次 .NET 某物管后台服务 卡死分析

我去,原来被一款叫做 智量杀毒软件 给劫持了。。。 具体什么原因被劫持,我也不想研究了,然后拿这个结果和朋友做了一下沟通,尝试停掉它看看。

记一次 .NET 某物管后台服务 卡死分析

三:总结

综合两处线程栈的特征,发现都是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); }  

劫持的原因,这个只能问厂家了,我们能做的就是停掉它 😄,最后朋友太客气了,发了一个大红包😁😁😁

记一次 .NET 某物管后台服务 卡死分析

发表评论

相关文章

  • 0