一:背景
1. 讲故事
调试训练营里的一位学员前些天找到我,说他们跑在k8s中的程序崩掉了不知道怎么回事?日志也没有记录到,让我帮他看看,dump也抓到了,既然抓到了那就看看吧。
二:程序为什么会崩溃
1. 崩溃原因
linux 上的崩溃分析没有windows上那么方便,但还是可以分析的,先通过 !t 看下是不是托管层崩溃导致的,输出如下:
0:005> !t ThreadCount: 132 UnstartedThread: 0 BackgroundThread: 129 PendingThread: 0 DeadThread: 2 Hosted Runtime: no Lock DBG ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception 0 1 1 0000557F7C7518B0 2020020 Preemptive 0000000000000000:0000000000000000 0000557f7c71d0c0 -00001 Ukn 5 2 b 0000557F7C6A5020 21222 Cooperative 00007FBB74F57F90:00007FBB74F59DF0 0000557f7c71d0c0 -00001 Ukn (Finalizer) System.NullReferenceException 00007fbb74f05230 6 4 d 0000557F7CB53D40 21220 Preemptive 0000000000000000:0000000000000000 0000557f7c71d0c0 -00001 Ukn 7 6 f 0000557F7CB5C070 3021220 Preemptive 0000000000000000:0000000000000000 0000557f7c71d0c0 -00001 Ukn (Threadpool Worker) ...
从卦中数据来看,原来是终结器线程 抛了 空引用异常,这个还是挺有意思的。。。可遇不可求,赶紧切过去用 !pe 命令观察。
0:005> ~5s libc_so!wait4+0x57: 00007fca`99249c17 483d00f0ffff cmp rax,0FFFFFFFFFFFFF000h 0:005> !pe Exception object: 00007fbb74f05230 Exception type: System.NullReferenceException Message: Object reference not set to an instance of an object. InnerException: <none> StackTrace (generated): SP IP Function 00007FCA968E3690 00007FCA6D8DF4A4 System_Runtime_Caching!System.Runtime.Caching.MemoryCache.OnUnhandledException(System.Object, System.UnhandledExceptionEventArgs)+0x24 StackTraceString: <none> HResult: 80004003 0:005> k # Child-SP RetAddr Call Site 00 00007fca`968e3cb0 00007fca`98ff5635 libc_so!wait4+0x57 01 00007fca`968e3ce0 00007fca`98ff6580 libcoreclr!PROCCreateCrashDump+0x275 [/__w/1/s/src/coreclr/pal/src/thread/process.cpp @ 2307] 02 00007fca`968e3d40 00007fca`98ff422f libcoreclr!PROCCreateCrashDumpIfEnabled+0x770 [/__w/1/s/src/coreclr/pal/src/thread/process.cpp @ 2524] 03 00007fca`968e3dd0 00007fca`98ff4159 (T) libcoreclr!PROCAbort+0x2f [/__w/1/s/src/coreclr/pal/src/thread/process.cpp @ 2555] 04 (Inline Function) --------`-------- libcoreclr!PROCEndProcess+0x7c [/__w/1/s/src/coreclr/pal/src/thread/process.cpp @ 1352] 05 00007fca`968e3df0 00007fca`98cf7121 libcoreclr!TerminateProcess+0x89 06 00007fca`968e3e10 00007fca`98ff81ae libcoreclr!FinalizerThread::FinalizerThreadStart+0xf1 07 00007fca`968e3e30 00007fca`991ff1f5 libcoreclr!CorUnix::CPalThread::ThreadEntry+0x1fe [/__w/1/s/src/coreclr/pal/inc/pal.h @ 1763] 08 00007fca`968e3ee0 00007fca`9927eb00 libc_so!pthread_condattr_setpshared+0x515 09 00007fca`968e3f80 ffffffff`ffffffff libc_so!_clone+0x40 0a 00007fca`968e3f88 00000000`00000000 0xffffffff`ffffffff
从卦象看,应该是微软的 MemoryCache 导致的空引用异常,然后终结器线程进入自爆状态,这个就更有意思了。。。 接下来观察 OnUnhandledException 方法到底发生了什么。
2. OnUnhandledException 怎么啦
要想看到 OnUnhandledException 中的源代码,可以将dll给dump出来,C# 代码如下:
// System.Runtime.Caching, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a // System.Runtime.Caching.MemoryCache private void OnUnhandledException(object sender, UnhandledExceptionEventArgs eventArgs) { if (eventArgs.IsTerminating) { Dispose(); } }
我去,就一个if也能抛异常,这也太狗血了。。。既然抛了空引用异常,从伦理上讲应该就是 eventArgs=null 导致的,那是不是的呢?这个就需要观察崩溃处的汇编代码了,即 !U 00007FCA6D8DF4A4,输出如下:
0:005> !U 00007FCA6D8DF4A4 Normal JIT generated code System.Runtime.Caching.MemoryCache.OnUnhandledException(System.Object, System.UnhandledExceptionEventArgs) ilAddr is 00007FBAD90D54D8 pImport is 000001BA2E289160 Begin 00007FCA6D8DF480, size 43 /_/src/libraries/System.Runtime.Caching/src/System/Runtime/Caching/MemoryCache.cs @ 247: 00007fca`6d8df480 55 push rbp 00007fca`6d8df481 4883ec20 sub rsp,20h 00007fca`6d8df485 488d6c2420 lea rbp,[rsp+20h] 00007fca`6d8df48a 48897df8 mov qword ptr [rbp-8],rdi 00007fca`6d8df48e 488975f0 mov qword ptr [rbp-10h],rsi 00007fca`6d8df492 488955e8 mov qword ptr [rbp-18h],rdx 00007fca`6d8df496 488b7de8 mov rdi,qword ptr [rbp-18h] 00007fca`6d8df49a 48b888451023ca7f0000 mov rax,7FCA23104588h >>> 00007fca`6d8df4a4 393f cmp dword ptr [rdi],edi 00007fca`6d8df4a6 ff10 call qword ptr [rax] 00007fca`6d8df4a8 85c0 test eax,eax 00007fca`6d8df4aa 7410 je 00007fca`6d8df4bc /_/src/libraries/System.Runtime.Caching/src/System/Runtime/Caching/MemoryCache.cs @ 249: 00007fca`6d8df4ac 488b7df8 mov rdi,qword ptr [rbp-8] 00007fca`6d8df4b0 48b810890d23ca7f0000 mov rax,7FCA230D8910h 00007fca`6d8df4ba ff10 call qword ptr [rax] /_/src/libraries/System.Runtime.Caching/src/System/Runtime/Caching/MemoryCache.cs @ 251: 00007fca`6d8df4bc 90 nop 00007fca`6d8df4bd 4883c420 add rsp,20h 00007fca`6d8df4c1 5d pop rbp 00007fca`6d8df4c2 c3 ret
从卦中的 >>> 可以看出,此处即为崩溃的汇编代码 cmp dword ptr [rdi],edi,经常看 C# 汇编的朋友应该非常熟悉,这是 JIT 生成的一段 可空判断的保护代码,如果你还想更进一步确认的话,刚好上周在训练营里讲到了 linux 的 x64 调用协定,即 linux 会用 6个寄存器 rdi, rsi, rdx, rcx, r8, r9 来传送方法的前六个参数,根据刚才汇编可以看到,rdi 来源于 rdx,这个参数就是 this 指针,也就完美的佐证了。
接下来我们观察下 OnUnhandledException 方法来自于何处,分析代码之后,发现是 MemoryCache 类下的初始化方法 InitDisposableMembers 中处理的,将其注册到 AppDomain 全局异常兜底中,截图如下:

问题到此就真相大白了,如何处理呢?
3. 我该如何解决
很难想到 MemoryCache 还会存在这种新级bug,既然是第三方的,我们也不好直接修改源代码,能做的就是升级升级再升级,我们将 Version=4.0.0.0 直接干到最新的 Version=9.0.6,再次观察,结果发现已经 物是人非 了,OnUnhandledException 也没有了,InitDisposableMembers 也重构了,截图如下:

这个问题虽然解决了,但可能有些朋友会有一个疑问,为什么是终结器线程走这段逻辑,这块其实就是考验你的C# 知识,哈哈,我当年是从 CLR Via C# 中学到的。
大概是这样的,如果一个 Task 中包含了一个隐含的未处理异常,最后当终结器被析构时会抛出未处理异常,这个异常就会被全局的 AppDomain.UnhandledException 拦截,在 UnhandledException 处理的过程中又不幸再次抛出异常,最终导致程序的崩溃。
三:总结
这次生产事故是由于微软的 MemoryCache 类下的一个新手级bug导致,确实有点让人震惊,所以这个世界或许还真是一个巨大的草台班子。。。
