前几天有位朋友找到我,说他的程序出现了偶发性崩溃,已经抓到了dump文件,Windows事件日志显示的崩溃点在 clr.dll 中,让我帮忙看下是怎么回事,那到底怎么回事呢? 上 WinDbg 说话。
如果是托管代码引发的崩溃,在线程列表上会有一个异常信息,可以用 !t
来验证下。
0:000> !t
ThreadCount: 7
UnstartedThread: 0
BackgroundThread: 6
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
Lock
ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception
0 1 cb4 000000000077fbd0 26020 Preemptive 0000000000000000:0000000000000000 0000000000734050 0 STA (GC) System.ExecutionEngineException 00000000028a11f8
2 2 890 0000000000782ea0 2b220 Preemptive 0000000000000000:0000000000000000 0000000000734050 0 MTA (Finalizer)
5 3 f6c 0000000021301f50 1029220 Preemptive 0000000000000000:0000000000000000 0000000000734050 0 Ukn (Threadpool Worker)
12 5 a38 00000000213dc090 2b220 Preemptive 0000000000000000:0000000000000000 0000000000734050 0 MTA
15 6 cb8 0000000021430740 2b220 Preemptive 0000000000000000:0000000000000000 0000000000734050 0 MTA
16 7 ce4 00000000318421c0 2b220 Preemptive 0000000000000000:0000000000000000 0000000000734050 0 MTA
17 4 f1c 00000000370edab0 102a220 Preemptive 0000000000000000:0000000000000000 0000000000734050 0 MTA (Threadpool Worker)
...
从卦中看,主线程正在触发 GC,并且抛出了一个 System.ExecutionEngineException
异常,这个异常属于灾难性的,表示 CLR 自己出问题了,那 CLR 在哪里出问题了呢?我们观察下主线程的非托管栈。
0:000> ~0s
clr!WKS::gc_heap::find_first_object+0xea:
000007fe`ea17644b 833800 cmp dword ptr [rax],0 ds:000007fe`00000000=????????
0:000> r
rax=000007fe00000000 rbx=000000000051a830 rcx=0000000000000018
rdx=000000000303f160 rsi=0000000000000000 rdi=000000000051a340
rip=000007feea17644b rsp=000000000051aa58 rbp=00000000000028a1
r8=0000000000000001 r9=000000000303f160 r10=0000000003040000
r11=000000000000303f r12=0000000000000001 r13=000000000051c860
r14=00000000033b8c59 r15=00000000033b8c58
iopl=0 nv up ei pl nz na po nc
cs=0033 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00010204
clr!WKS::gc_heap::find_first_object+0xea:
000007fe`ea17644b 833800 cmp dword ptr [rax],0 ds:000007fe`00000000=????????
0:000> k 10
# Child-SP RetAddr Call Site
00 00000000`0051aa58 000007fe`ea175d7b clr!WKS::gc_heap::find_first_object+0xea
01 00000000`0051aa70 000007fe`ea1040d4 clr!WKS::GCHeap::Promote+0xc7
02 00000000`0051aae0 000007fe`ea1001b8 clr!GcInfoDecoder::EnumerateLiveSlots+0x103a
03 00000000`0051af50 000007fe`ea100e16 clr!GcStackCrawlCallBack+0x2bd
04 00000000`0051b370 000007fe`ea16e35c clr!GCToEEInterface::GcScanRoots+0x4d6
05 00000000`0051c830 000007fe`ea16ee9b clr!WKS::gc_heap::mark_phase+0x17f
06 00000000`0051c8d0 000007fe`ea16edaf clr!WKS::gc_heap::gc1+0xa3
07 00000000`0051c920 000007fe`ea170c0f clr!WKS::gc_heap::garbage_collect+0x193
08 00000000`0051c960 000007fe`ea173be6 clr!WKS::GCHeap::GarbageCollectGeneration+0xef
09 00000000`0051c9b0 000007fe`ea1d5ccf clr!AllocateArrayEx+0x69c
0a 00000000`0051cb40 000007fe`ea24c480 clr!FieldMarshaler_FixedArray::UpdateCLRImpl+0x40
0b 00000000`0051cb80 000007fe`ea24c3ac clr!FieldMarshaler::UpdateCLR+0x68
0c 00000000`0051cca0 000007fe`ea24c74c clr!LayoutUpdateCLR+0x213
0d 00000000`0051cd80 000007fe`ea24c6aa clr!FmtValueTypeUpdateCLR+0x50
0e 00000000`0051cdb0 000007fe`e2c88134 clr!StubHelpers::ValueClassMarshaler__ConvertToManaged+0x9a
0f 00000000`0051cf20 000007fe`e2c7e335 System_Drawing_ni+0x78134
从卦中的线程栈上看,GC 处于三阶段中的 标记阶段
,正在各个线程栈上寻找用户根遇到了一个异常地址 000007fe00000000
,最后抛出异常了,那这个地址属于什么内存属性呢?可以用 !address 000007fe00000000
观察一下。
0:000> !address 000007fe00000000
Usage: Free
Base Address: 00000001`801d3000
End Address: 000007fe`8a9f0000
Region Size: 000007fd`0a81d000 ( 7.988 TB)
State: 00010000 MEM_FREE
Protect: 00000001 PAGE_NOACCESS
Type: <info not present at the target>
Content source: 0 (invalid), length: 8a9f0000
从卦中可以看到,在这个地址是 PAGE_NOACCESS
的,理所当然会抛出访问违例,既然 gc 在托管堆上用 find_first_object
遇到了一个异常地址,说明这块内存被破坏了,可以用 !VerifyHeap
去验证下托管堆。
0:000> !VerifyHeap
Could not request method table data for object 000000000303F160 (MethodTable: 000007FE00000000).
Last good object: 000000000303F140.
从卦中可以清晰的看到,地址 000000000303F160
上的方法表地址 000007FE00000000
被破坏了,这个地址刚好就是汇编代码显示的这个。
一般来说这个损坏是在崩溃前的某一次 托管和非托管
交互时产生的,在后续的某个时候 GC 在清洗托管堆时才发现家里被偷继而报警,但此时已经错过了第一时间,画个图大概是这样。
由于 dump 只是一个快照,无法追踪曾经发生了什么事?只能死马当活马医,看看目前的破坏现场,可以用 !lno 000000000303F160
观察破坏对象的前后对象和附近内存。
0:000> !lno 000000000303F160
Before: 000000000303f140 32 (0x20) System.Byte[]
After: 000000000303f198 24 (0x18) System.Int32
Heap local consistency not confirmed.
0:000> dp 000000000303F160 - 0n144 L20
00000000`0303f0d0 00000000`00000000 000007fe`e794aaa0
00000000`0303f0e0 00000000`0000000e 33313231`32323032
00000000`0303f0f0 00003835`34323131 00000000`00000000
00000000`0303f100 000007fe`e794aaa0 00000000`00000001
00000000`0303f110 00000000`00000000 00000000`00000000
00000000`0303f120 000007fe`e794aaa0 00000000`00000001
00000000`0303f130 00000000`00000000 00000000`00000000
00000000`0303f140 000007fe`e794aaa0 00000000`00000001
00000000`0303f150 39353932`30303038 00000000`36373135
00000000`0303f160 000007fe`00000000 00700055`0000000e
00000000`0303f170 00640061`006f006c 00750073`00650052
00000000`0303f180 0050003a`0074006c 00000000`00000000
00000000`0303f190 00000000`00000000 000007fe`e79485a0
00000000`0303f1a0 00000000`00000004 00000000`00000000
00000000`0303f1b0 000007fe`e79459c0 00000034`00000001
00000000`0303f1c0 00000000`00000000 00000000`00000000
仔细观察 000000000303f160
处的内存布局,很明显这是一个 string 类型, 地址 007000550000000e
上的低八位的 0xe = 0n13
表示 string 的长度,但 string 的高八位 00700055
理应是对齐的 00000000
,看样子被非托管代码
纂改了,并且把原来正确的方法表地址 000007fee79459c0
的低八位给覆盖成了 000007fe00000000
,导致最后的崩溃。
如果再仔细观察,你会发现 000000000303f150
处也是一个 unicode 字符,但它不属于 000000000303f140
处的 byte[]
对象,可以用 !do
验证。
0:000> !do 000000000303f140
Name: System.Byte[]
MethodTable: 000007fee794aaa0
EEClass: 000007fee7ab6c78
Size: 25(0x19) bytes
Array: Rank 1, Number of elements 1, Type Byte (Print Array)
Content: 8
Fields:
None
这也就说明 000000000303f150 ~ 000000000303f170
附近的内存全部被破坏了,不过庆幸的是:这些看起来都是一些字符,接下来用 db
显示一下。
0:000> db 000000000303f150
00000000`0303f150 38 30 30 30 32 39 35 39-35 31 37 36 00 00 00 00 800029595176....
00000000`0303f160 00 00 00 00 fe 07 00 00-0e 00 00 00 55 00 70 00 ............U.p.
00000000`0303f170 6c 00 6f 00 61 00 64 00-52 00 65 00 73 00 75 00 l.o.a.d.R.e.s.u.
00000000`0303f180 6c 00 74 00 3a 00 50 00-00 00 00 00 00 00 00 00 l.t.:.P.........
00000000`0303f190 00 00 00 00 00 00 00 00-a0 85 94 e7 fe 07 00 00 ................
00000000`0303f1a0 04 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00 ................
00000000`0303f1b0 c0 59 94 e7 fe 07 00 00-01 00 00 00 34 00 00 00 .Y..........4...
00000000`0303f1c0 00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00 ................
从卦中的 UploadResult:P
来看,貌似是一个上传结果,在结合 !lno
显示的前后对象分别是 Byte[]
和 Int32
,应该是 朋友用 class 的方式实现 C# 和 C++ 的交互,C++ 在操作 class 下的某一个 string 时 指针溢出, 破坏了托管堆的 string 对象。
将这些信息告诉朋友后,朋友说也已经定位到这里了,正和对方的工程师做对接,对方反馈过来是托管层要自己预留足够的长度。
其实崩溃类的 dump 最能考验基本功,需要你对 C# 对象的内存布局有一个深度的理解,否则也很难发现出端倪,当然本篇还属于崩溃类中较容易的。
相信有朋友肯定要问,如何找到破坏的第一现场,这当然是可以的,需要借助微软的 MDA
助手, 配置 gcManagedToUnmanaged
和 gcUnmanagedToManaged
两项,让双方交互之后立即触发 GC,具体参见: https://learn.microsoft.com/zh-cn/dotnet/framework/debug-trace-profile/gcunmanagedtomanaged-mda