记一次.net某医疗住院系统崩溃分析(代码片段)

一线码农 一线码农     2023-04-01     551

关键词:

一:背景

1. 讲故事

最近收到了两起程序崩溃的dump,查了下都是经典的 double free 造成的,蛮有意思,这里就抽一篇出来分享一下经验供后面的学习者避坑吧。

二:WinDbg 分析

1. 崩溃点在哪里

windbg 带了一个自动化分析命令 !analyze -v 可以帮助我们找到崩溃时的程序指令地址以及崩溃的代码,这对我们分析问题非常有帮助。


0:090> !analyze -v
*******************************************************************************
*                                                                             *
*                        Exception Analysis                                   *
*                                                                             *
*******************************************************************************
CONTEXT:  (.ecxr)
rax=00007ffec265d6e0 rbx=00000000c0000374 rcx=00000053653fe4f0
rdx=00007ffec1d3e9a0 rsi=0000000000000001 rdi=00007ffed7b827f0
rip=00007ffed7b1b349 rsp=00000053653fed10 rbp=000001c14fd20000
 r8=000001c11957d9a0  r9=0000000000000033 r10=000001c453dbc7f0
r11=00007ffeb94db004 r12=0000000000000001 r13=000001c12e8526d0
r14=0000000000000000 r15=000001ce25531c60
iopl=0         nv up ei pl nz na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000206
ntdll!RtlReportFatalFailure+0x9:
00007ffe`d7b1b349 eb00            jmp     ntdll!RtlReportFatalFailure+0xb (00007ffe`d7b1b34b)
Resetting default scope

EXCEPTION_RECORD:  (.exr -1)
ExceptionAddress: 00007ffed7b1b349 (ntdll!RtlReportFatalFailure+0x0000000000000009)
   ExceptionCode: c0000374
  ExceptionFlags: 00000001
NumberParameters: 1
   Parameter[0]: 00007ffed7b827f0

PROCESS_NAME:  w3wp.exe
...

熟悉 windows ntheap 的朋友应该知道,ExceptionCode: c0000374 是经典的 堆破坏 状态码,那到底是谁破坏了呢?

2. 到底是谁破坏了NT堆

windows 给了 ntheap 强大的调试支持,默认开启了 Termination on corruption 破坏检测,也就是说当你使用 !heap -s 的时候会显示具体破坏的详情记录,输出如下:


0:090> !heap -s


************************************************************************************************************************
                                              NT HEAP STATS BELOW
************************************************************************************************************************
**************************************************************
*                                                            *
*                  HEAP ERROR DETECTED                       *
*                                                            *
**************************************************************

Details:

Heap address:  000001c14fd20000
Error address: 000001ce25531c50
Error type: HEAP_FAILURE_BLOCK_NOT_BUSY
Details:    The caller performed an operation (such as a free
            or a size check) that is illegal on a free block.
Follow-up:  Check the error's stack trace to find the culprit.


Stack trace:
Stack trace at 0x00007ffed7b82848
    00007ffed7abe109: ntdll!RtlpLogHeapFailure+0x45
    00007ffed7acbb0e: ntdll!RtlFreeHeap+0x9d3ce
    00007ffeb093276f: OraOps12!ssmem_free+0xf
    00007ffeb0943077: OraOps12!OpsMetFreeValCtx+0xd7
    00007ffeb093cdd8: OraOps12!OpsDacDispose+0x2b8
    00007ffe655e4374: +0x655e4374

LFH Key                   : 0x5baf44f8068da60f
Termination on corruption : ENABLED
          Heap     Flags   Reserv  Commit  Virt   Free  List   UCR  Virt  Lock  Fast 
                            (k)     (k)    (k)     (k) length      blocks cont. heap 
-------------------------------------------------------------------------------------
000001c14fd20000 00000002 1021576 964388 1020020  19222  6063   166    2    82f   LFH
000001c14fc70000 00008000      64      4     64      2     1     1    0      0      
...

上面的 Error type: HEAP_FAILURE_BLOCK_NOT_BUSY 表示是一个 double free,从 Stack trace 看是 OpsDacDispose 方法造成的,应该和 Oracle 相关,这就比较迷了。。。

3. 是托管层触发的吗

是不是托管层触发的呢?这就需要理解 Windows 独有的 SEH 异常处理机制,也就是说 Windows 的异常都会在 内核态 走一圈,画个图如下:

只要找到 t1 时刻的崩溃点,然后观察线程栈即可,代码如下:


0:090> .ecxr
rax=00007ffec265d6e0 rbx=00000000c0000374 rcx=00000053653fe4f0
rdx=00007ffec1d3e9a0 rsi=0000000000000001 rdi=00007ffed7b827f0
rip=00007ffed7b1b349 rsp=00000053653fed10 rbp=000001c14fd20000
 r8=000001c11957d9a0  r9=0000000000000033 r10=000001c453dbc7f0
r11=00007ffeb94db004 r12=0000000000000001 r13=000001c12e8526d0
r14=0000000000000000 r15=000001ce25531c60
iopl=0         nv up ei pl nz na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000206
ntdll!RtlReportFatalFailure+0x9:
00007ffe`d7b1b349 eb00            jmp     ntdll!RtlReportFatalFailure+0xb (00007ffe`d7b1b34b)
0:090> k
  *** Stack trace for last set context - .thread/.cxr resets it
 # Child-SP          RetAddr               Call Site
00 00000053`653fed10 00007ffe`d7b1b313     ntdll!RtlReportFatalFailure+0x9
01 00000053`653fed60 00007ffe`d7b23b9e     ntdll!RtlReportCriticalFailure+0x97
02 00000053`653fee50 00007ffe`d7b23eaa     ntdll!RtlpHeapHandleError+0x12
03 00000053`653fee80 00007ffe`d7abe109     ntdll!RtlpHpHeapHandleError+0x7a
04 00000053`653feeb0 00007ffe`d7acbb0e     ntdll!RtlpLogHeapFailure+0x45
05 00000053`653feee0 00007ffe`b093276f     ntdll!RtlFreeHeap+0x9d3ce
06 00000053`653fef80 00007ffe`b0943077     OraOps12!ssmem_free+0xf
07 00000053`653fefb0 00007ffe`b093cdd8     OraOps12!OpsMetFreeValCtx+0xd7
08 00000053`653fefe0 00007ffe`655e4374     OraOps12!OpsDacDispose+0x2b8
09 00000053`653ff060 00007ffe`655e31cf     0x00007ffe`655e4374
0a 00000053`653ff150 00007ffe`6a80969d     0x00007ffe`655e31cf
0b 00000053`653ff1f0 00007ffe`c4b96d06     0x00007ffe`6a80969d
0c 00000053`653ff220 00007ffe`c4c30e81     clr!FastCallFinalizeWorker+0x6
0d 00000053`653ff250 00007ffe`c4c30e09     clr!FastCallFinalize+0x55
0e 00000053`653ff2a0 00007ffe`c4c30d3a     clr!MethodTable::CallFinalizer+0xb5
0f 00000053`653ff2f0 00007ffe`c4c30bf5     clr!CallFinalizer+0x5e
10 00000053`653ff330 00007ffe`c4c304dc     clr!FinalizerThread::DoOneFinalization+0x95
11 00000053`653ff410 00007ffe`c4c31777     clr!FinalizerThread::FinalizeAllObjects+0xbf
12 00000053`653ff450 00007ffe`c4b97d01     clr!FinalizerThread::FinalizeAllObjects_Wrapper+0x18
13 00000053`653ff480 00007ffe`c4b97c70     clr!ManagedThreadBase_DispatchInner+0x39
14 00000053`653ff4c0 00007ffe`c4b97bad     clr!ManagedThreadBase_DispatchMiddle+0x6c
15 00000053`653ff5c0 00007ffe`c4b9ac34     clr!ManagedThreadBase_DispatchOuter+0x75
16 00000053`653ff650 00007ffe`c4bf5271     clr!ManagedThreadBase_DispatchInCorrectAD+0x15
17 00000053`653ff680 00007ffe`c4b9ac72     clr!Thread::DoADCallBack+0x109
18 00000053`653ff830 00007ffe`c4c3172a     clr!ManagedThreadBase_DispatchInner+0x82
19 00000053`653ff870 00007ffe`c4c304dc     clr!FinalizerThread::DoOneFinalization+0x1f1
1a 00000053`653ff950 00007ffe`c4c3062b     clr!FinalizerThread::FinalizeAllObjects+0xbf
1b 00000053`653ff990 00007ffe`c4b97d01     clr!FinalizerThread::FinalizerThreadWorker+0xbb
1c 00000053`653ff9d0 00007ffe`c4b97c70     clr!ManagedThreadBase_DispatchInner+0x39
1d 00000053`653ffa10 00007ffe`c4b97bad     clr!ManagedThreadBase_DispatchMiddle+0x6c
1e 00000053`653ffb10 00007ffe`c4cf4d4a     clr!ManagedThreadBase_DispatchOuter+0x75
1f 00000053`653ffba0 00007ffe`c4d5044f     clr!FinalizerThread::FinalizerThreadStart+0x126
20 00000053`653ffc40 00007ffe`d6157e94     clr!Thread::intermediateThreadProc+0x86
21 00000053`653ffd00 00007ffe`d7a87ad1     kernel32!BaseThreadInitThunk+0x14
22 00000053`653ffd30 00000000`00000000     ntdll!RtlUserThreadStart+0x21

0:090> !clrstack 
OS Thread Id: 0x5634 (90)
        Child SP               IP Call Site
00000053653ff0b8 00007ffed7abf0e4 [InlinedCallFrame: 00000053653ff0b8] Oracle.DataAccess.Client.OpsDac.Dispose(IntPtr, IntPtr, IntPtr, IntPtr ByRef, Oracle.DataAccess.Client.OpoMetValCtx*, Oracle.DataAccess.Client.OpoDacValCtx* ByRef, Oracle.DataAccess.Client.OpoSqlValCtx*, Int32, Int32)
00000053653ff0b8 00007ffe655e4374 [InlinedCallFrame: 00000053653ff0b8] Oracle.DataAccess.Client.OpsDac.Dispose(IntPtr, IntPtr, IntPtr, IntPtr ByRef, Oracle.DataAccess.Client.OpoMetValCtx*, Oracle.DataAccess.Client.OpoDacValCtx* ByRef, Oracle.DataAccess.Client.OpoSqlValCtx*, Int32, Int32)
00000053653ff060 00007ffe655e4374 DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr, IntPtr, IntPtr, IntPtr ByRef, Oracle.DataAccess.Client.OpoMetValCtx*, Oracle.DataAccess.Client.OpoDacValCtx* ByRef, Oracle.DataAccess.Client.OpoSqlValCtx*, Int32, Int32)
00000053653ff150 00007ffe655e31cf Oracle.DataAccess.Client.OracleDataReader.Dispose(Boolean)
00000053653ff1f0 00007ffe6a80969d Oracle.DataAccess.Client.OracleDataReader.Finalize()
00000053653ff608 00007ffec4b96d06 [DebuggerU2MCatchHandlerFrame: 00000053653ff608] 
00000053653ff788 00007ffec4b96d06 [ContextTransitionFrame: 00000053653ff788] 
00000053653ff8d0 00007ffec4b96d06 [GCFrame: 00000053653ff8d0] 
00000053653ffb58 00007ffec4b96d06 [DebuggerU2MCatchHandlerFrame: 00000053653ffb58] 

从调用栈来看,原来是 终结器线程 在调用 OracleDataReader.Dispose() 方法的时候抛的异常,这个结果还是挺意外的,也就是说这个问题不是用户代码造成的,真的是 Oracle 这个 OraOps12.dll 造成的。。。

接下来用 lm 观察下这个 dll 的详情信息,输出如下:


0:090> lmDvmOraOps12
Browse full module list
start             end                 module name
00007ffe`b0920000 00007ffe`b098c000   OraOps12 C (export symbols)       OraOps12.dll
    Loaded symbol image file: OraOps12.dll
    Image path: C:\\ODAC\\xxxx\\OraOps12.dll
    Image name: OraOps12.dll
    Browse all global symbols  functions  data
    Timestamp:        Sat Sep 26 23:16:56 2015 (5606B6E8)
    CheckSum:         00000000
    ImageSize:        0006C000
    File version:     2.121.2.0
    Product version:  2.121.2.0
    File flags:       0 (Mask 3F)
    File OS:          4 Unknown Win32
    File type:        2.0 Dll
    File date:        00000000.00000000
    Translations:     0409.04b0
    Information from resource tables:
        CompanyName:      Oracle Corporation
        ProductName:      Oracle Data Provider for .NET
        InternalName:     OraOps
        OriginalFilename: OraOps12.dll
        ProductVersion:   2.121.2.0 ODAC RELEASE 4
        FileVersion:      2.121.2.0
        FileDescription:  Oracle Provider Services
        LegalCopyright:   Copyright © 2014

虽然对 Oracle 不熟,但从 Timestamp: Sat Sep 26 23:16:56 2015 来看应该是一个比较老的 DLL 了,所以给到朋友的建议就是升级 OraOps12.dll

4. 是否有同行者

有时候直接让朋友升级dll有点缺少底气,最好就是找到一些同行者,经过一顿搜索,还真有同行者,又多了一份说服力,网址: https://techcommunity.microsoft.com/t5/iis-support-blog/w3wp-exe-crash-exception-code-0xc0000005/ba-p/334351

[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-cvkAKFpk-1679565236422)(https://huangxincheng.oss-cn-hangzhou.aliyuncs.com/img/20230323172126.png)]

三:总结

在百加dump的分析旅程中,碰到和 Oracle SDK 相关的也有 3+ 起了,可能也许这些 SDK 在对接 .NET 上还不是特别稳健,大家在使用上尽量更新到最新版本吧,且用且珍惜!

记一次.net某制造业mes系统崩溃分析(代码片段)

一:背景1.讲故事前段时间有位朋友微信找到我,说他的程序偶尔会出现内存溢出崩溃,让我帮忙看下是怎么回事,咨询了下程序是x86部署,听到这个词其实心里已经有了数,不管怎么样还是用windbg分析一... 查看详情

记一次.net某工控mes程序崩溃分析(代码片段)

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

记一次.net某企业erp网站系统崩溃分析(代码片段)

一:背景1.讲故事前段时间收到了一个朋友的求助,说他的ERP网站系统会出现偶发性崩溃,找了好久也没找到是什么原因,让我帮忙看下,其实崩溃好说,用procdump自动抓一个就好,拿到dump之后,接下来就是一顿分析了。二:WinD... 查看详情

记一次.net某医疗器械清洗系统卡死分析(代码片段)

一:背景1.讲故事前段时间协助训练营里的一位朋友分析了一个程序卡死的问题,回过头来看这个案例比较经典,这篇稍微整理一下供后来者少踩坑吧。二:WinDbg分析1.为什么会卡死因为是窗体程序,理所当然就是看主线程此时... 查看详情

记一次.net某智能服装智造系统内存泄漏分析(代码片段)

一:背景1.讲故事上个月有位朋友找到我,说他的程序出现了内存泄漏,不知道如何进一步分析,截图如下:朋友这段话已经说的非常言简意赅了,那就上windbg说话吧。二:Windbg分析1.到底是哪一方面的泄漏根据朋友描述,程序... 查看详情

记一次.net某新能源系统线程疯涨分析(代码片段)

一:背景1.讲故事前段时间收到一个朋友的求助,说他的程序线程数疯涨,寻求如何解决。等我分析完之后,我觉得这个问题很有代表性,所以拿出来和大家分享下,还是上老工具WinDbg。二:WinDbg分析1.... 查看详情

记一次.net某工控自动化控制系统卡死分析(代码片段)

一:背景1.讲故事前段时间遇到了好几起关于窗体程序的进程加载锁引发的程序卡死和线程暴涨问题,这种dump分析难度较大,主要涉及到Windows操作系统和C++的基础知识,所以有必要简单整理和大家分享一下&... 查看详情

记一次.net某新能源汽车锂电池检测程序ui挂死分析(代码片段)

一:背景1.讲故事这世间事说来也奇怪,近两个月有三位朋友找到我,让我帮忙分析下他的程序hangon现象,这三个dump分别涉及:医疗,新能源,POS系统。截图如下:那这篇为什么要拿其中的新能源... 查看详情

记一次腾讯会议的意外崩溃分析(代码片段)

一:背景1.讲故事前段时间在用腾讯会议直播的时候,居然意外崩溃了,还好不是在训练营上课,不然又得重录了,崩完之后发现腾讯会议的bugreport组件会自动生成一个minidump,截图如下:作为一个.NET高级调试的技术博主,非.NET... 查看详情

记一次.net某纺织工厂mes系统api挂死分析(代码片段)

一:背景1.讲故事这个月中旬,有位朋友加我wx求助他的程序线程占有率很高,寻求如何解决,截图如下:说实话,和不同行业的程序员聊天还是蛮有意思的,广交朋友,也能扩大自己的圈子,... 查看详情

记一次.net某wms仓储打单系统内存暴涨分析(代码片段)

一:背景1.讲故事七月中旬有一位朋友加wx求助,他的程序在生产上跑着跑着内存就飙起来了,貌似没有回头的趋势,询问如何解决,截图如下:和这位朋友聊下来,感觉像是自己在小县城当了个小老板... 查看详情

记一次.net某电厂web系统内存泄漏分析(代码片段)

一:背景1.讲故事前段时间有位朋友找到我,说他的程序内存占用比较大,寻求如何解决,截图就不发了,分析下来我感觉除了程序本身的问题之外,.NET5在内存管理方面做的也不够好,所以有必要给大... 查看详情

记一次.net某智慧物流wcs系统cpu爆高分析(代码片段)

一:背景1.讲故事哈哈,再次见到物流类软件,上个月有位朋友找到我,说他的程序出现了CPU爆高,让我帮忙看下什么原因,由于那段时间在苦心研究C++,分析和经验分享也就懈怠了,今天就... 查看详情

记一次windows10内存压缩模块崩溃分析(代码片段)

一:背景1.讲故事在给各位朋友免费分析.NET程序各种故障的同时,往往也会收到各种其他类型的dump,比如:Windows崩溃,C++崩溃,Mono崩溃,真的是啥都有,由于基础知识的相对缺乏,分析起来并不是那么的顺利,今天就聊一个Win... 查看详情

记一次.net某手术室行为信息系统内存泄露分析(代码片段)

一:背景1.讲故事昨天有位朋友找到我,说他的程序内存存在泄露导致系统特别卡,大地址也开了,让我帮忙看一下怎么回事?今天上午看了下dump,感觉挺有意思,在我的分析之旅中此类问题也蛮少见,算是完善一下体系吧。二... 查看详情

记一次.net某电厂web系统内存泄漏分析

一:背景1.讲故事前段时间有位朋友找到我,说他的程序内存占用比较大,寻求如何解决,截图就不发了,分析下来我感觉除了程序本身的问题之外,.NET5在内存管理方面做的也不够好,所以有必要给大家分享一下。二:WinDbg分... 查看详情

记一次.net某家装erp系统内存暴涨分析(代码片段)

一:背景1.讲故事前段时间微信上有一位老朋友找到我,说他的程序跑着跑着内存会突然爆高,有时候会下去,有什么会下不去,怀疑是不是某些情况下存在内存泄露,让我帮忙分析一下,其实内存泄露方面的问题还是比较好解... 查看详情

记一次.net某桌面奇侠游戏非托管内存泄漏分析(代码片段)

一:背景1.讲故事说实话,这篇dump我本来是不准备上一篇文章来解读的,但它有两点深深的感动了我。无数次的听说用Unity可做游戏开发,但百闻不如一见。游戏中有很多金庸武侠小说才有的名字,太赏心悦目... 查看详情