5

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

 1 year ago
source link: https://www.cnblogs.com/huangxincheng/p/16415242.html
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.

1. 讲故事

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

0f9197e6df114cb2b676cbf2aea48113~tplv-k3u1fbpfcp-zoom-1.image

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

19922fea60a54c19aad34beb120c2457~tplv-k3u1fbpfcp-zoom-1.image

接下来直接上 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 源码上也能看的出来。

40f98071b637413aa1cf1ba496a75216~tplv-k3u1fbpfcp-zoom-1.image

接下来就进入了 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

根据经验，第一反应应该是 临界区死锁 了，经验归经验，接下来我们依次看下 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 线程持有的资源，截图如下：

92a0ea81525f4f3d84aedc5cba600ccb~tplv-k3u1fbpfcp-zoom-1.image

接下来再看下 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 查查看。

2a7f0bb658884a4587bac49195b1380c~tplv-k3u1fbpfcp-zoom-1.image

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

0f21d164267842d4a54957eb83adef90~tplv-k3u1fbpfcp-zoom-1.image

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

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

图片名称

report

Recommend

About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK