記一次 .NET某Hdp智能柜系統(tǒng)卡死分析

作者：一線碼農(nóng)聊技術(shù) 2024-11-29 10:06:59

從源碼看是用一個(gè)死循環(huán)來(lái)強(qiáng)留一個(gè)線程，無(wú)語(yǔ)了，這也疑似導(dǎo)致 GC 因?yàn)檎也坏絪afepoint而長(zhǎng)時(shí)間不能暫停它，這里說(shuō)疑似，是因?yàn)樵赾oreclr中是有支撐的。

一、背景

1. 講故事

停了一個(gè)月時(shí)間沒(méi)有更新博客了，主要是這段時(shí)間有些許事情導(dǎo)致心神不寧，我這個(gè)人也比較浮躁所以無(wú)法潛心修煉，事情如下：

被狗咬了

也不知道是不是出門沒(méi)看黃歷，在小區(qū)門口店里買煙，被店老板家狗來(lái)了個(gè)猝不及防，天降橫禍。讓店老板賠了個(gè)疫苗錢，人生第一次被狗咬，第一次打這種狂犬疫苗，頭兩天總焦慮這輩子是不是要畫一個(gè)句號(hào)了，想著這幾年在社區(qū)里免費(fèi)給人家分析dump，應(yīng)該也積了不少陰德陽(yáng)善，老天不會(huì)在這個(gè)時(shí)候收我的，昨天結(jié)束了四針劑的最后一針，算是放下了心頭事，真是人間好時(shí)節(jié)。

買房

孩子明年就要上一年級(jí)了，所以給孩子上哪所有教育資源的學(xué)校又是一件焦慮的事情，家門口的學(xué)校都是菜小，村小，不想耽誤孩子的前程，在貝殼焦慮著泡了大半個(gè)月加上實(shí)地考察，把這件事情也搞定了。

幼兒跳繩比賽

這個(gè)真的最耽誤我的時(shí)間，孩子參加市級(jí)的跳繩比賽，每天早上6：45集訓(xùn)，每天 6：00 跟著孩子起床，送去集訓(xùn)，全程陪護(hù)，作為程序員晚上12點(diǎn)前下電腦都是對(duì)工作的不尊敬，導(dǎo)致睡眠不足，整天精神狀態(tài)都不是很好。

跟大家簡(jiǎn)單的匯報(bào)了這一個(gè)月的事情，接下來(lái)我們分析個(gè)比較經(jīng)典的dump吧，前段時(shí)間有位朋友找到我，說(shuō)他的程序會(huì)偶發(fā)卡死，自己有一定的分析能力，但還是找不出來(lái)根源在哪里，讓我?guī)兔聪拢吘乖趪?guó)內(nèi)搜索 .NET高級(jí)調(diào)試的文章，最終都會(huì)通向我這邊。

二、WinDbg分析

1. 主線程怎么了

因?yàn)槭侵骶€程的卡死，所以首看主線程的調(diào)用棧來(lái)尋找其中的蛛絲馬跡，輸出如下：

0:000:x86> k
CvRegToMachine(x86) conversion failure for 0x14f
X86MachineInfo::SetVal: unknown register 0 requested
 # ChildEBP RetAddr      
00 0047e8f8 76c41629     ntdll_774f0000!NtWaitForSingleObject+0x15
01 0047e8f8 76d71194     KERNELBASE!WaitForSingleObjectEx+0x98
02 0047e910 58d52bf6     kernel32!WaitForSingleObjectExImplementation+0x75
03 (Inline) --------     coreclr!CLREventWaitHelper2+0x9 [D:\a\_work\1\s\src\coreclr\vm\synch.cpp @ 372] 
04 0047e964 58d52bc4     coreclr!CLREventWaitHelper+0x2d [D:\a\_work\1\s\src\coreclr\vm\synch.cpp @ 397] 
05 0047e974 58d52821     coreclr!CLREventBase::WaitEx+0x49 [D:\a\_work\1\s\src\coreclr\vm\synch.cpp @ 469] 
06 0047e988 58df0848     coreclr!CLREventBase::Wait+0x1a [D:\a\_work\1\s\src\coreclr\vm\synch.cpp @ 413] 
07 (Inline) --------     coreclr!GCEvent::Impl::Wait+0xb [D:\a\_work\1\s\src\coreclr\vm\gcenv.os.cpp @ 1283] 
08 (Inline) --------     coreclr!GCEvent::Wait+0x10 [D:\a\_work\1\s\src\coreclr\vm\gcenv.os.cpp @ 1361] 
09 0047e9a0 58d5222c     coreclr!SVR::GCHeap::WaitUntilGCComplete+0x28 [D:\a\_work\1\s\src\coreclr\gc\gcee.cpp @ 287] 
0a 0047e9fc 58f26769     coreclr!Thread::RareDisablePreemptiveGC+0x1ad [D:\a\_work\1\s\src\coreclr\vm\threadsuspend.cpp @ 2172] 
0b 0047ea08 58df7f88     coreclr!JIT_ReversePInvokeEnterRare2+0xd [D:\a\_work\1\s\src\coreclr\vm\jithelpers.cpp @ 5462] 
0c 0047ea2c 2d8fd592     coreclr!JIT_ReversePInvokeEnterTrackTransitions+0x98 [D:\a\_work\1\s\src\coreclr\vm\jithelpers.cpp @ 5509] 
WARNING: Frame IP not in any known module. Following frames may be wrong.
0d 0047ea90 76f862fa     0x2d8fd592
0e 0047eabc 76f86d3a     user32!InternalCallWinProc+0x23
0f 0047eb34 76f86de8     user32!UserCallWinProcCheckWow+0x109
10 0047eb90 76fae062     user32!DispatchClientMessage+0xd5
11 0047ebf8 7750013a     user32!__fnINDEVICECHANGE+0x2a9
12 0047ec64 76f8790d     ntdll_774f0000!KiUserCallbackDispatcher+0x2e
13 0047ec64 30d6e999     user32!GetMessageW+0x33

從卦中可以看到有一個(gè) WaitUntilGCComplete 函數(shù)，說(shuō)明主線程正在等待GC完成，那到底是哪一個(gè)線程觸發(fā)了GC呢？可以用 ~* k 命令觀察每個(gè)線程的調(diào)用棧，經(jīng)過(guò)一頓搜索，發(fā)現(xiàn)是3號(hào)線程掛了GC相關(guān)函數(shù)SuspendEE，參考輸出如下：

3  Id: ff0.608 Suspend: 0 Teb: fff9a000 Unfrozen
CvRegToMachine(x86) conversion failure for 0x14f
X86MachineInfo::SetVal: unknown register 0 requested
 # ChildEBP RetAddr      
00 02c3f5d0 76c41629     ntdll_774f0000!NtWaitForSingleObject+0x15
01 02c3f5d0 76d71194     KERNELBASE!WaitForSingleObjectEx+0x98
02 02c3f5e8 58d52bf6     kernel32!WaitForSingleObjectExImplementation+0x75
03 (Inline) --------     coreclr!CLREventWaitHelper2+0x9 [D:\a\_work\1\s\src\coreclr\vm\synch.cpp @ 372] 
04 02c3f63c 58d52bc4     coreclr!CLREventWaitHelper+0x2d [D:\a\_work\1\s\src\coreclr\vm\synch.cpp @ 397] 
05 02c3f64c 58d52821     coreclr!CLREventBase::WaitEx+0x49 [D:\a\_work\1\s\src\coreclr\vm\synch.cpp @ 469] 
06 02c3f664 58d8947b     coreclr!CLREventBase::Wait+0x1a [D:\a\_work\1\s\src\coreclr\vm\synch.cpp @ 413] 
07 02c3f6e8 58d86aa2     coreclr!ThreadSuspend::SuspendRuntime+0x553 [D:\a\_work\1\s\src\coreclr\vm\threadsuspend.cpp @ 3590] 
08 02c3f790 58d868f0     coreclr!ThreadSuspend::SuspendEE+0xf9 [D:\a\_work\1\s\src\coreclr\vm\threadsuspend.cpp @ 5741] 
09 02c3f7b8 58d95aa5     coreclr!GCToEEInterface::SuspendEE+0x26 [D:\a\_work\1\s\src\coreclr\vm\gcenv.ee.cpp @ 28] 
0a 02c3f7b8 58d96ae8     coreclr!SVR::gc_heap::gc_thread_function+0x11f [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 6680] 
0b 02c3f7e4 58d96ad4     coreclr!SVR::gc_heap::end_space_after_gc [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 39175] 
0c (Inline) --------     coreclr!GCToOSInterface::BoostThreadPriority+0xf [D:\a\_work\1\s\src\coreclr\vm\gcenv.os.cpp @ 699] 
0d 02c3f7e4 58e0c182     coreclr!SVR::gc_heap::gc_thread_stub+0x64 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 31990] 
0e 02c3f7f8 76d7343d     coreclr!<lambda_e12851d373e238e6372df6ec280c8fc6>::operator()+0x42 [D:\a\_work\1\s\src\coreclr\vm\gcenv.ee.cpp @ 1471] 
0f 02c3f804 77529802     kernel32!BaseThreadInitThunk+0xe
10 02c3f844 775297d5     ntdll_774f0000!__RtlUserThreadStart+0x70

從卦中看，GC正處于 SuspendEE 階段，即凍結(jié)執(zhí)行引擎，它的實(shí)現(xiàn)途徑就是通過(guò) while threads 的方式讓每一個(gè)線程暫停，C++參考代碼如下：

void ThreadSuspend::SuspendRuntime(ThreadSuspend::SUSPEND_REASON reason)
{
    while (true)
    {
        Thread* thread = NULL;

        while ((thread = ThreadStore::GetThreadList(thread)) != NULL)
        {
        }
    }
}

所以接下來(lái)的探索方向就是看看當(dāng)前的 SupendEE 到底正在處理哪一個(gè)線程？

2. 如何挖到處理線程

要挖處理線程方法比較多，你可以逆向的分析匯編代碼，第二種就是寫個(gè)腳本在線程棧空間中搜索托管線程地址。這里選擇后者，畢竟簡(jiǎn)單粗暴。

托管線程列表，即下面的 ThreadOBJ 字段。

0:000:x86> !t
ThreadCount:      176
UnstartedThread:  1
BackgroundThread: 26
PendingThread:    0
DeadThread:       148
Hosted Runtime:   no
                                                                             Lock  
 DBG   ID     OSID ThreadOBJ    State GC Mode     GC Alloc Context  Domain   Count Apt Exception
   0    1      fec 023BDF08     26020 Preemptive  0F608E60:0F60A528 023452a8 -00001 Ukn 
   7    2     2c0c 023CAC98     2b220 Preemptive  03230120:03231900 023452a8 -00001 Ukn (Finalizer) 
  11    4     2d48 24738AF0   102b220 Preemptive  0738C3C0:0738DC8C 023452a8 -00001 Ukn (Threadpool Worker) 
  12    5     2d4c 24774BE0   102b220 Preemptive  00000000:00000000 023452a8 -00001 Ukn (Threadpool Worker) 
  16    8     2d68 247C9820     20220 Preemptive  0356A5EC:0356B150 023452a8 -00001 Ukn 
  13    9     2d54 247C1878     20220 Preemptive  0B6A3384:0B6A33AC 023452a8 -00001 Ukn 
XXXX   11        0 247F8B28      1600 Preemptive  00000000:00000000 023452a8 -00001 Ukn 
  28   12     2dbc 24825760     21220 Preemptive  00000000:00000000 023452a8 -00001 Ukn 
  29   13     2dc0 2482D088     21220 Preemptive  00000000:00000000 023452a8 -00001 Ukn 
  ...
  58  156     2910 246714A8   102b222 Cooperative 0F56F618:0F56F884 023452a8 -00001 Ukn (Threadpool Worker) 
  ...

0:000:x86> !address -f:Stack

  BaseAddr EndAddr+1 RgnSize     Type       State                 Protect             Usage
-----------------------------------------------------------------------------------------------
 2bc0000  2c3d000    7d000 MEM_PRIVATE MEM_RESERVE                                    Stack32    [~3; ff0.608]
 2c3d000  2c3e000     1000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE | PAGE_GUARD        Stack32    [~3; ff0.608]
 2c3e000  2c40000     2000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE                     Stack32    [~3; ff0.608]

搜索腳本

腳本的目的是在 2c3e000 ~ 2c40000 中搜索托管線程address。

use strict;          
          
// 32bit          
let arr = [];          
          
function initializeScript() { return [new host.apiVersionSupport(1, 7)]; }          
function log(str) { host.diagnostics.debugLog(str + "\n"); }          
function exec(str) { return host.namespace.Debugger.Utility.Control.ExecuteCommand(str); }          
          
function invokeScript() {          
          
    var output = exec("!t").Skip(8);          
          
    for (var line of output) {          
        if (!line) continue;          
        log(line);          
        var address = line.substr(19, 8);          
        log(address);          
        searchmemory(address);          
    }          
}          
          
          
function searchmemory(address) {          
    var output = exec("s-d 02c3e960 2c40000 " + address);          
          
    for(var line of output){          
        log(line);          
    }          
}

執(zhí)行完之后，發(fā)現(xiàn) SuspendEE 正在處理的是 58號(hào)線程，細(xì)心的朋友會(huì)發(fā)現(xiàn)上面的 !t 輸出的58號(hào)線程正是 Cooperative 狀態(tài)，即協(xié)作狀態(tài)，也就是還沒(méi)有被 SuspendEE 處理。哈哈，馬上就要看到光明頂了，接下來(lái)的方向就是洞察 58號(hào)線程正在做什么？

3. 58號(hào)線程正在做什么

這就比較簡(jiǎn)單了，使用 ~58s 切到該線程查看線程棧即可。

0:000:x86> ~58s
02c52da4 807e3400        cmp     byte ptr [esi+34h],0       ds:002b:0b15cc78=01
0:058:x86> !clrstack
OS Thread Id: 0x2910 (58)
Child SP       IP Call Site
40EAFA0C 02c52da4 xxx.xxx.PlayWavStream(System.IO.Stream, System.String)
40EAFA54 024e4915 xxx.xxx+c__DisplayClass8_0.b__0()
40EAFA94 024c849d System.Threading.Tasks.Task.InnerInvoke() [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs @ 2397]
40EAFAA0 024c2abd System.Threading.Tasks.Task+c.<.cctor>b__272_0(System.Object) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs @ 2376]
40EAFAA8 00536547 System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(System.Threading.Thread, System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs @ 268]
40EAFAD8 024c2852 System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef, System.Threading.Thread) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs @ 2337]
40EAFB3C 39d3925f System.Threading.ThreadPoolWorkQueue.Dispatch()
40EAFB90 00538145 System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart() [/_/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.WorkerThread.cs @ 107]
40EAFB94 00537f5c [InlinedCallFrame: 40eafb94] 
40EAFC38 00537f5c System.Threading.Thread.StartCallback() [/_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 106]
40EAFD8C 58dfd24f [DebuggerU2MCatchHandlerFrame: 40eafd8c]

根據(jù)線程棧上的 PlayWavStream 方法來(lái)檢查源碼，發(fā)現(xiàn)了一個(gè)無(wú)語(yǔ)的寫法，截圖如下：