记一次 .NET 某工控MES程序 崩溃分析

Posted dotNET跨平台

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了记一次 .NET 某工控MES程序 崩溃分析相关的知识,希望对你有一定的参考价值。

一:背景

1.讲故事

前几天有位朋友找到我,说他的程序出现了偶发性崩溃,已经抓到了dump文件,Windows事件日志显示的崩溃点在 clr.dll 中,让我帮忙看下是怎么回事,那到底怎么回事呢? 上 WinDbg 说话。

二:WinDbg 分析

1. 崩溃点在哪里

如果是托管代码引发的崩溃,在线程列表上会有一个异常信息,可以用 !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 被破坏了,这个地址刚好就是汇编代码显示的这个。

2. 方法表地址为什么会被损坏

一般来说这个损坏是在崩溃前的某一次 托管和非托管 交互时产生的,在后续的某个时候 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

以上是关于记一次 .NET 某工控MES程序 崩溃分析的主要内容,如果未能解决你的问题,请参考以下文章

记一次 .NET 某制造业 MES 系统崩溃分析

记一次 .NET 某企业 ERP网站系统 崩溃分析

记一次 .NET 某纺织工厂 MES系统 API 挂死分析

记一次 .NET 某工控自动化控制系统 卡死分析

记一次 .NET 某工控视觉软件 非托管泄漏分析

记一次 .NET 某纺织工厂 MES系统 API 挂死分析