记一次 .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。