記一次 .NET 某新能源材料檢測系統崩潰分析

一：背景

1. 講故事

上週有位朋友找到我，說他的程式經常會偶發性崩潰，一直沒找到原因，自己也抓了dump 也沒分析出個所以然，讓我幫忙看下怎麼回事，那既然有 dump，那就開始分析唄。

二：Windbg 分析

1. 到底是哪裡的崩潰

一直跟蹤我這個系列的朋友應該知道分析崩潰第一個命令就是 !analyze -v ，讓windbg幫我們自動化異常分析。


0:033> !analyze -v
CONTEXT:  (.ecxr)
rax=00000039cccff2d7 rbx=00000039c85fc2b0 rcx=00000039cccff2d8
rdx=0000000000000000 rsi=0000000000000000 rdi=00000039c85fbdc0
rip=00007ffb934b1199 rsp=00000039c85fc550 rbp=00000039c85fc5b8
 r8=0000000000000000  r9=00000039c85fce90 r10=0000000000000009
r11=0000000000000080 r12=0000000000000000 r13=00000039c85fdaf0
r14=00007ffb933d12b0 r15=0000022939e68440
iopl=0         nv up ei pl nz ac pe cy
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010211
clr!Frame::HasValidVTablePtr+0x2a:
00007ffb`934b1199 488b39          mov     rdi,qword ptr [rcx] ds:00000039`cccff2d8=????????????????
Resetting default scope

STACK_TEXT:  
00000039`c85fc550 00007ffb`934b7107     : 00007ffb`933140d0 00007ffb`933140d0 00000000`00000000 00000000`00000000 : clr!Frame::HasValidVTablePtr+0x2a
00000039`c85fc600 00007ffb`933d3427     : 00000000`00000000 00000000`00000000 00007ffb`93c641e0 00007ffb`93c64c48 : clr!GCToEEInterface::GcScanRoots+0x2f2
00000039`c85fdac0 00007ffb`933d1843     : 00000000`00000000 00007ffb`00000000 00000000`00000000 00000000`00000001 : clr!WKS::gc_heap::mark_phase+0x197
00000039`c85fdb70 00007ffb`933d1762     : 00000000`00000001 00000039`00000000 00000000`00000000 00000000`00000001 : clr!WKS::gc_heap::gc1+0xa3
00000039`c85fdbd0 00007ffb`933d1539     : 00000000`00000001 00000000`00000000 00000229`00af0f88 00000000`00000000 : clr!WKS::gc_heap::garbage_collect+0x54c
00000039`c85fdc50 00007ffb`933d5f51     : 00000000`00000578 00007ffb`00000000 00000229`01ee5200 00000039`c85fdca0 : clr!WKS::GCHeap::GarbageCollectGeneration+0x10d
00000039`c85fdcb0 00007ffb`933d838c     : 00000229`01ee5288 00000000`00000030 00000229`2328ff18 00000229`2328ff18 : clr!WKS::gc_heap::trigger_gc_for_alloc+0x2d
00000039`c85fdcf0 00007ffb`9333a88b     : 00000000`00000030 00000000`00000008 00000000`00000000 00007ffb`00000000 : clr!WKS::GCHeap::Alloc+0x2a9
00000039`c85fdd50 00007ffb`9333a465     : ffffffc6`37a021c8 00000039`c85fded0 00000039`c85fde20 00000039`c85fdf00 : clr!SlowAllocateString+0x8b
...

從卦中的呼叫棧來看，有如下兩點資訊：

GC 觸發了

上面的mark_phase表示當前 GC 正在標記階段，後面的GcScanRoots表示 GC正線上程棧上尋找根物件。

崩潰點在 clr 中

看到崩潰在clr的 clr!Frame::HasValidVTablePtr 方法中真的有點不敢相信，從崩潰點的組合程式碼 rdi,qword ptr [rcx] 來看，貌似 rcx 沒有分配到實體記憶體，可以用 !address rcx 驗證下。


0:033> !address rcx

Usage:                  Free
Base Address:           00000039`ccb00000
End Address:            00000039`cce00000
Region Size:            00000000`00300000 (   3.000 MB)
State:                  00010000          MEM_FREE
Protect:                00000001          PAGE_NOACCESS
Type:                   <info not present at the target>


Content source: 0 (invalid), length: 1fbd28

尼瑪，真的好無語，這個rcx=00000039cccff2d8 所處的記憶體居然是一個 MEM_FREE，存取它自然會拋異常，現在很迷茫的是這玩意是 GC 的內部邏輯，按理說不會有這種異常，難道是 CLR 自己的 bug 嗎？

三：真的是 CLR 的 bug 嗎

1. 分析 CLR 原始碼

要想尋找真相，就必須要理解崩潰處的 CLR 原始碼了，這裡拿coreclr做參考，首先從 clr!Frame::HasValidVTablePtr+2a 處說起，這個方法大概就是用來判斷 Frame 類的虛方法表指標是否有效，簡化後的程式碼如下：


// static
bool Frame::HasValidVTablePtr(Frame * pFrame)
{
    TADDR vptr = pFrame->GetVTablePtr();
    if (vptr == HelperMethodFrame::GetMethodFrameVPtr())
        return true;

    if (vptr == DebuggerSecurityCodeMarkFrame::GetMethodFrameVPtr())
        return true;
    if (s_pFrameVTables->LookupValue(vptr, (LPVOID) vptr) == (LPVOID) INVALIDENTRY)
        return false;

    return true;
}

這裡簡單說下什麼是虛方法表，如果一個類通過各種渠道擁有了虛方法後，那這個類的第一個欄位就是 虛方法表指標，這個指標所指向的虛方法表中存放著每個虛方法的入口地址，畫個圖大概是這樣。

有了這張圖再讓chatgpt寫一段C++程式碼驗證下。


#include <iostream>

using namespace std;

// 父類別
class Animal {
private:
	int age;
public:
	virtual void makeSound() {
		cout << "The animal makes a sound" << endl;
	}
};

// 子類
class Cat : public Animal {
public:
	void makeSound() override {
		cout << "The cat meows" << endl;
	}
};

int main() {

	// 使用父類別指標指向子類物件，呼叫子類重寫的方法
	Animal* animal = new Cat();
	animal->makeSound(); // 輸出 "The cat meows"
	return 0;
}

上圖中的00219b60就是虛方法表指標，後面的0021100a就是虛方法地址了。

有了這些鋪墊之後，可以得知是在提取frame虛方法指標的時候，這個地址已被釋放導致崩潰的。

2. frame來自於哪裡

通過在 coreclr 原始碼中一頓梳理，發現它是 Thread 類的第四個欄位，偏移是0x10，參考程式碼如下：


PTR_GSCookie Frame::SafeGetGSCookiePtr(Frame* pFrame)
{
	Frame::HasValidVTablePtr(pFrame)
}

BOOL StackFrameIterator::Init(Thread* pThread,
	PTR_Frame   pFrame,
	PREGDISPLAY pRegDisp,
	ULONG32     flags)
{
	m_crawl.pFrame = m_pThread->GetFrame();
	m_crawl.SetCurGSCookie(Frame::SafeGetGSCookiePtr(m_crawl.pFrame));
}

0:008> dt coreclr!Thread
   +0x000 m_stackLocalAllocator : Ptr64 StackingAllocator
   +0x008 m_State          : Volatile<enum Thread::ThreadState>
   +0x00c m_fPreemptiveGCDisabled : Volatile<unsigned long>
   +0x010 m_pFrame         : Ptr64 Frame

觀察原始碼大概就知道了 Frame 是棧幀的表示，標記階段要在每個執行緒中通過 m_pThread->GetFrame 方法來獲取爬棧的起始點。

到這裡我們知道了 m_pFrame 有問題，那它到底屬於哪個執行緒呢？

3. 尋找問題 Thread

要想尋找問題執行緒，可以自己寫個指令碼，判斷下 ThreadOBJ-0x10 = rcx(00000039cccff2d8) 即可。


function invokeScript() {

    var lines = exec("!t").Skip(8);

    for (var line of lines) {
        var t_addr = line.substr(15, 16);

        var commandText = "dp " + t_addr + " L8";
        log(commandText);

        var output = exec(commandText);

        for (var line2 of output) {
            log(line2);
        }

        log("--------------------------------------")
    }
}

從卦中資料看終於給找到了，原來是有一個OSID=744的執行緒意外退出導致棧空間被釋放引發的，真的無語了。

接下來的問題是這個執行緒是用來幹嘛的，它做了什麼？

4. 778號執行緒是何方神聖

到這裡要給大家一點遺憾了，778號執行緒已經退出了，棧空間都被釋放了，在dump中不可能找到它生前做了什麼，不過最起碼我們知道如下幾點資訊：

它是一個由 C# 建立的託管執行緒
它是一個非執行緒池執行緒
它肯定是某種原因意外退出的

要想知道這個執行緒生前做了什麼，最好的辦法就是用 perfview 捕獲執行緒建立和退出的 ETW 事件，到那一天定會水落石出！！！

四：總結

這次生產事故，我感覺使用者和CLR都有責任，託管執行緒的棧空間都釋放了，為什麼 CLR 在觸發 GC 時還要去爬它的棧導致崩潰的發生，這真的是一個很有意思的dump。

記一次 .NET 某新能源材料檢測系統 崩潰分析