2

记一次 .NET某炉膛锅炉检测系统 崩溃分析

 3 weeks ago
source link: https://www.cnblogs.com/huangxincheng/p/18140261
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.

1. 讲故事

上个月有个朋友在微信上找到我，说他们的软件在客户那边隔几天就要崩溃一次，一直都没有找到原因，让我帮忙看下怎么回事，确实工控类的软件环境复杂难搞，朋友手上有一个崩溃的dump，刚好丢给我来分析一下。

二：WinDbg分析

1. 程序为什么会崩溃

windbg 有一个厉害之处在于双击之后可以帮你自动定位到崩溃处，输出如下：


................................................................
................................................................
.......................................................
This dump file has an exception of interest stored in it.
The stored exception information can be accessed via .ecxr.
(1418.89c): Access violation - code c0000005 (first/second chance not available)
For analysis of this file, run !analyze -v
clr!WKS::gc_heap::background_mark_simple1+0x5a1:
000007fe`f5316d40 41f70300000080  test    dword ptr [r11],80000000h ds:00000000`00000000=????????

从卦中信息看，这不是一件好事情，崩溃居然落在bgc线程上，此时bgc线程正在做后台对象标记，依据过往经验有可能是托管堆损坏了，可以用 !verifyheap 命令来验证下。


0:038> !verifyheap 
Object 000000000476a0a8 has an invalid method table.
Last good object: 000000000476A058.

0:038> !lno 000000000476a0a8
Before:  000000000476a058           80 (0x50)	System.Text.RegularExpressions.RegexWriter
After:   000000000476a0c0          152 (0x98)	System.Int32[]

0:038> dp 000000000476a058
00000000`0476a058  000007fe`f0e47390 00000000`0476a0c0
00000000`0476a068  00000000`0476a1d0 00000000`0476a158
00000000`0476a078  00000000`0476a1a8 00000000`00000000
00000000`0476a088  0000001a`00000000 00000006`0000001a
00000000`0476a098  00000000`00000000 00000000`00000018
00000000`0476a0a8  00000000`00000000 00000000`00000000
00000000`0476a0b8  00000000`00000000 000007fe`f2ce9250
00000000`0476a0c8  00000000`00000020 00000004`00000000

从卦中看确实有一个对象处于有损状态，它的 mt=0 ,objheader=0x18，这个信息还是蛮奇怪的，接下来观察下内存地址的布局，找出有损地址空间，截图如下：

214741-20240417115449228-808920181.png

上面圈出来的地址段也不像是 C++ 故意改的，那到底是真破坏还是假破坏呢？因为这一点确实可以决定后续的分析方向。

2. 托管堆真假破坏之谜

熟悉 bgc 运转逻辑的朋友都知道会有三个阶段，分别为 初始标记,并发标记,最终标记，所以接下来的问题是当前这个程序处于什么阶段呢? 这个观察手段比较多，除了看bgc流程也可以 !t -special 看看 SuspendEE 标记。


0:038> !t -special
ThreadCount:      40
       ID OSID ThreadOBJ           State GC Mode     GC Alloc Context                  Domain           Count Apt Exception
   24   12 174c 000000001e71c210  1029220 Cooperative 0000000000000000:0000000000000000 000000000027ba40 2     MTA (GC) (Threadpool Worker) 
   ...
   38   13  89c 000000001e529130    21220 Preemptive  0000000000000000:0000000000000000 000000000027ba40 0     Ukn System.ExecutionEngineException 00000000022f1228

          OSID Special thread type
        24 174c SuspendEE ThreadpoolWorker

从卦中可以清晰的看到24号线程触发了一个前台GC，同时38号的 bgc抛了执行引擎异常，这个灾难性的异常也是程序崩溃的原因，接下来观察下 24号正在做什么。


0:024> k 10
 # Child-SP          RetAddr               Call Site
00 00000000`205ebcf0 000007fe`f52fb444     clr!GcInfoDecoder::EnumerateLiveSlots+0x4df
01 00000000`205ec140 000007fe`f52fbd81     clr!EECodeManager::EnumGcRefs+0xc4
02 00000000`205ec2a0 000007fe`f5380aee     clr!GcStackCrawlCallBack+0x171
03 00000000`205ec3a0 000007fe`f52fbc28     clr!Thread::StackWalkFrames+0x172
04 00000000`205ed820 000007fe`f53141f0     clr!CNameSpace::GcScanRoots+0x144
05 00000000`205ed8c0 000007fe`f5310a8e     clr!WKS::gc_heap::relocate_phase+0x40
06 00000000`205ed930 000007fe`f5310fd0     clr!WKS::gc_heap::plan_phase+0xa01
07 00000000`205edb90 000007fe`f530df61     clr!WKS::gc_heap::gc1+0x9f
08 00000000`205edbe0 000007fe`f530dccd     clr!WKS::gc_heap::garbage_collect+0x222
09 00000000`205edc70 000007fe`f530e220     clr!WKS::GCHeap::GarbageCollectGeneration+0xdd
0a 00000000`205edcc0 000007fe`f516ae69     clr!WKS::GCHeap::Alloc+0x29d
0b 00000000`205edd10 000007fe`f2b2ab2a     clr!FramedAllocateString+0x139
...

从卦中可以清晰的看到此时的GC正在 relocate_phase 重定位阶段，重定位阶段通俗来说就是 兵马未动，粮草先行，这是一种非原子性的操作，简单来说bgc拿到的可能是移动后的新地址（粮草），但对象（兵马）还是在老地方，所以刚才看到的托管堆那块空间是初始化状态，同时对象头的 0x18 应该是一种中间状态的对象标记，这个暂时不去深挖了，但不管怎么说，此时的托管堆大概率是没有问题的。

既然托管堆没有问题，后面的研究方向就得深挖 bgc 的逻辑了。

3. bgc线程到底怎么了

要知道 bgc 到底怎么了，必须要观察它附近的汇编代码，可以用 ub 命令，输出如下：


0:024> r
Last set context:
rax=000000000001b83b rbx=0000000020e5e5b0 rcx=0000000000370707
rdx=00000000029b78a0 rsi=0000000000000000 rdi=0000000020e5e0c0
rip=000007fef5316d40 rsp=0000000020e5e680 rbp=000000001a30a2fc
 r8=0000000003707670  r9=000007fef2c94438 r10=00000000029b88b0
r11=0000000000000000 r12=0000000000000010 r13=000007fef2c94438
r14=0000000000291808 r15=0000000000001f60
iopl=0         nv up ei pl zr na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010244
clr!WKS::gc_heap::background_mark_simple1+0x5a1:
000007fe`f5316d40 41f70300000080  test    dword ptr [r11],80000000h ds:00000000`00000000=????????

0:024> ub 000007fe`f5316d40
clr!WKS::gc_heap::background_mark_simple1+0x584:
000007fe`f5316d23 48c1e809        shr     rax,9
000007fe`f5316d27 80e11f          and     cl,1Fh
000007fe`f5316d2a 41d3e3          shl     r11d,cl
000007fe`f5316d2d 44855c8500      test    dword ptr [rbp+rax*4],r11d
000007fe`f5316d32 7548            jne     clr!WKS::gc_heap::background_mark_simple1+0x5f3 (000007fe`f5316d7c)
000007fe`f5316d34 44095c8500      or      dword ptr [rbp+rax*4],r11d
000007fe`f5316d39 4d8b18          mov     r11,qword ptr [r8]
000007fe`f5316d3c 4983e3fe        and     r11,0FFFFFFFFFFFFFFFEh

从卦中数据来看，崩溃的原因是 r11=0 导致的，r11 的值又来自于 r8，这里有一个硬编码值 0FFFFFFFFFFFFFFFEh，这个值在代码中应该是 -2 或者是 ~1 这两种情况，接下来观察下 background_mark_simple1() 的方法源码，尼玛。。。 还真给我找到了，简化后如下：


void gc_heap::background_mark_simple1(uint8_t * oo THREAD_NUMBER_DCL)
{
    ...
    uint8_t* start = oo;
    if ((size_t)oo & 1)
    {
        oo = (uint8_t*)((size_t)oo & ~1);
        start = *(--background_mark_stack_tos);
        dprintf(4, ("oo: %Ix, start: %Ix\n", (size_t)oo, (size_t)start));
    }
    ...
}

先简单解释下代码的意思， oo & ~1 是将 oo 对象的 gcmark标记 给去掉，后面的 background_mark_stack_tos 就是深度优先遍历过程中使用的栈结构，再结合汇编代码，我们知道 r8 其实就是 oo，那这个 oo 到底是独立存在还是归属于谁呢？

4. oo 到底是何方神圣

要想知道这个答案，可以用 !lno 命令观察下 r8 附近内存来寻找蛛丝马迹，输出如下：


0:024> r r8
Last set context:
r8=0000000003707670

0:024> !lno 0000000003707670
Before:  0000000003707658           80 (0x50)	xxx.ComponentData
After:   00000000037076a8         1416 (0x588)	Free
Heap local consistency confirmed.

0:024> ? 0000000003707670 - 0000000003707658
Evaluate expression: 24 = 00000000`00000018

0:024> !DumpObj /d 0000000003707658
Name:        xxx.ComponentData
MethodTable: 000007fe95c0b058
EEClass:     000007fe95c2bbb0
Size:        80(0x50) bytes
File:        C:\xxxDriver.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
000007fef2cecf58  400008c       38      System.DateTime  1 instance 0000000003707690 wWfscFiguq
000007fef2cffc90  400008d       18        System.Double  1 instance 0.000000         I9ss25rNyt
000007fe95c0a888  400008e       20         System.Int32  1 instance                9 AxCs5sGCxm
000007fe95c0af00  400008f       24         System.Int32  1 instance                9 fK9sgqZ2qY
...

这个卦看起来就非常奇怪，无语了。。。 我苦苦寻找的 oo 对象居然是一个 int 类型的 fK9sgqZ2qY 字段，这不是乱套了吗？ int 类型在这里也没有装箱，怎么可能会提取出 mt 呢？ 真的是莫名奇怪。

5. int 为什么当 引用类型 了

线索到了这里越来越不可思议了，基本就可以断定这是 BGC 标记的错乱，直白的说就是 BGC 出现了 bug，再看下当前的操作系统和framework的版本,依次是 windows7 和 4.0 。


0:024> vertarget
Windows 7 Version 7601 (Service Pack 1) MP (4 procs) Free x64
Product: WinNt, suite: SingleUserTS
Edition build lab: kernel32.dll version: 6.1.7601.17514 (win7sp1_rtm.101119-1850)

0:024> !eeversion
4.0.30319.18408 free
Workstation mode
In plan phase of garbage collection
SOS Version: 4.0.30319.18408 retail build

综合来说是 bgc 在老环境下做后台标记的时候出现了 bug，这种 bug 非我能力之所及，但我能做的就是把它切除掉，即把 bgc 模式给关掉，不走这个逻辑不就行了吗？ 参考如下：


<configuration>
   <runtime>
      <gcConcurrent enabled="false"/>
   </runtime>
</configuration>

很多时候分析下来发现是CLR内部的bug所致，这种真的很无奈，我能做的也只能是手术切除。

图片名称

report

Recommend

About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK