一次程序崩溃Dump文件的分析

程序崩溃表示程序已经运行不下去了,不得不停下来。一般来说,造成程序崩溃的原因主要有以下几种:除零异常,访问越界,访问空指针,缓冲区溢出,无效指针,堆栈溢出(以后有时间会专门写一篇文章介绍这几种崩溃的表现形式和调试方法,敬请期待)。Windows平台下在程序崩溃的时候弹出的是程序停止运行的对话框。如右图所示:

本文主要介绍下本人遇到的一次比较诡异的程序崩溃(为方便分析及保密需要,简化了各种名称,模块名称为xxxmodule、类名称为xxxclass(n)、函数名称为xxxclass(n)func(n)或xxxfunc(n))。我并没有亲自看到程序崩溃现场,遥记当时,老大只是给了我个Dump文件让我分析。

废话不多说,马上请上我们的调试工具WinDbg。本文假设大家对WinDbg的使用方法有基本的了解,如果没有了解,可以看下思路,在其它平台,使用其它工具分析问题思路都是相通的。

打开WindDbg后,使用Ctrl+D快捷键打开需要分析的Dump文件,这里是test.dmp,可看到如下的信息,可以看到其中表明我使用的是WinDbg的版本号是10.0.15063.137,Dump文件的路径是 C:\Users\zhouqingshan\Desktop\test.dmp,是一个MiniDump文件,生成时间是17年的4月21号,最后面的lastevent信息表明此次崩溃是由一个中断异常(breakpoint exception)引起的,这信息没甚用。

Microsoft (R) Windows Debugger Version 10.0.15063.137 AMD64
Copyright (c) Microsoft Corporation. All rights reserved.


Loading Dump File [C:\Users\zhouqingshan\Desktop\test.dmp]
User Mini Dump File with Full Memory: Only application data is available

...... 省略无用一万字
Windows 7 Version 7601 (Service Pack 1) MP (2 procs) Free x86 compatible
Product: WinNt, suite: SingleUserTS
Machine Name:
Debug session time: Fri Apr 21 16:00:45.000 2017 (UTC + 8:00)
System Uptime: 1 days 7:43:33.023
Process Uptime: 0 days 5:10:09.000
................................................................
................................................................
...........
Loading unloaded module list
.......................以下是LASTEVENT信息............................
This dump file has a breakpoint exception stored in it.
The stored exception information can be accessed via .ecxr.
eax=7ff7c000 ebx=00000000 ecx=00000000 edx=76e5ec4b esi=00000000 edi=00000000
eip=76df3c8c esp=0a90fe3c ebp=0a90fe68 iopl=0         nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000246
ntdll!DbgBreakPoint:
76df3c8c cc              int     3

接下来我们可以使用 ~*k 命令查看所有的线程的堆栈,看是否可从其中找出有用信息。由于这个Dump文件所属的进程的线程较多,有47个,无法将所有的堆栈信息贴出来。这里给个小技巧:如果是程序崩溃,在使用 ~*k  命令将所有的线程堆栈转储出来后,可以使用 Ctrl+F搜索下exception关键字,因为一般的程序崩溃最直接的表现就是有未经处理的异常通过UnhandledExceptionFilterRaiseExceptionRtlDispatchExceptionExecuteHandler等函数表现出来。根据这个方法,果不其然,我们找到了崩溃的41号线程,其堆栈如下所示(篇幅所限,省略了一些无用的函数堆栈):

0:041> k
 # ChildEBP RetAddr  
...
10 09f6f414 76dde3a4 ntdll!__RtlUserThreadStart+0x62
11 09f6f428 76dde234 ntdll!_EH4_CallFilterFunc+0x12
12 09f6f450 76e06d79 ntdll!_except_handler4+0x8e
13 09f6f474 76e06d4b ntdll!ExecuteHandler2+0x26
14 09f6f498 76ddfa17 ntdll!ExecuteHandler+0x24
15 09f6f524 76e06bd7 ntdll!RtlDispatchException+0x127
16 09f6f524 74d180d7 ntdll!KiUserExceptionDispatcher+0xf
17 09f6f9f8 60361a93 KERNELBASE!RaiseException+0x58
18 09f6fa30 60331017 xxxmodule!_CxxThrowException+0x48 
19 09f6fa3c 60349b12 xxxmodule!ATL::AtlThrowImpl+0x17
1a 09f6fa70 60349bfc xxxmodule!ATL::CTime::CTime+0x32  
1b 09f6fa9c 60348cbd xxxmodule!ATL::CTime::CTime+0x4c 
1c 09f6fab8 60349358 xxxmodule!xxxfunc1+0xd 
1d 09f6fb28 60336f62 xxxmodule!xxxclass2::xxxclass2func1+0x118 
1e 09f6fed4 60334f20 xxxmodule!xxxclass1::xxxclass1func3+0x4e2 
1f 09f6fef4 60334e8b xxxmodule!xxxclass1::xxxclass1func2+0x80 
20 09f6fef8 603606a7 xxxmodule!xxxclass1::xxxclass1func1+0x1b 
21 09f6ff30 6036074f xxxmodule!_callthreadstartex+0x1b 
22 09f6ff3c 7533ef1c xxxmodule!_threadstartex+0x82
23 09f6ff48 76e2367a kernel32!BaseThreadInitThunk+0xe
24 09f6ff88 76e2364d ntdll!__RtlUserThreadStart+0x70
25 09f6ffa0 00000000 ntdll!_RtlUserThreadStart+0x1b

从中可以看出,崩溃的第一现场为xxxmodule!ATL::CTime::CTime+0x32 ,xxxmodule是DLL模块的名称。第一现场的位置在CTime构造函数的 0x32偏移处,距离CTime构造函数开始处没多远。CTime是微软ATL(or MFC)类库中的一个函数,理论上讲这里不可能是崩溃的原因所在。我们再往堆栈下面寻找我们的模块函数,看看模块函数里是怎么调用CTime构造函数的,很快我们就发现了 xxxmodule!xxxfunc1函数,这是我们模块里的函数,我们应该着重分析下该函数里面所使用的局部变量,看是否有可疑之处:

通过kP命令可以看到xxxfunc1函数有两个SYSTEMTIME 参数,

1c 09f6fab8 60349358 xxxmodule!xxxfunc1(
            struct _SYSTEMTIME * IrBeginTime = 0x09f6f9a8, 
            struct _SYSTEMTIME * IrEndTime = <Memory access error>)+0xd

然后,使用uf命令转储下该函数的内容,可以看出函数内部的确两次调用了CTime的构造函数。而这两个构造函数的参数都来源于函数的参数[esp+10h]、[esp+8]

0:041> uf xxxmodule!xxxfunc1
xxxmodule!xxxfunc1
  135 60348cb0 83ec14          sub     esp,14h
  135 60348cb3 56              push    esi
  136 60348cb4 8d742410        lea     esi,[esp+10h]
  136 60348cb8 e8f30e0000      call    xxxmodule!ATL::CTime::CTime (60349bb0)
  137 60348cbd 8b44241c        mov     eax,dword ptr [esp+1Ch]
  137 60348cc1 8d742408        lea     esi,[esp+8]
  137 60348cc5 e8e60e0000      call    xxxmodule!ATL::CTime::CTime (60349bb0)
  138 60348cca 8b442408        mov     eax,dword ptr [esp+8]
  138 60348cce 2b442410        sub     eax,dword ptr [esp+10h]
  138 60348cd2 8b4c240c        mov     ecx,dword ptr [esp+0Ch]
  138 60348cd6 1b4c2414        sbb     ecx,dword ptr [esp+14h]
  139 60348cda 6a00            push    0
  139 60348cdc 6880510100      push    15180h
  139 60348ce1 51              push    ecx
  139 60348ce2 50              push    eax
  139 60348ce3 e8184f0200      call    xxxmodule!_alldiv (6036dc00)
  140 60348ce8 5e              pop     esi
  140 60348ce9 83c414          add     esp,14h
  140 60348cec c3              ret

因此,我们来看下这两个参数的信息。首先使用 .frame 1c命令切换到1c栈帧;然后使用 dv 命令显示该栈帧内的局部变量,最后显示局部变量0x09f6f9a8处的内容。可以看到0x09f6f9a8处的SYSTEMTIME的年份和月份明显不对,同时IrEndTime又显示<Memory access error>,因此这个栈帧里面显示的信息应该是有问题的。

0:041> .frame 1c
1c 09f6fab8 60349358 xxxmodule!xxxfunc1+0xd 
0:041> dv /t /v
@eax              struct _SYSTEMTIME * IrBeginTime = 0x09f6f9a8
00000004          struct _SYSTEMTIME * IrEndTime = <Memory access error>
fffffff8          class ATL::CTime beginTime = class ATL::CTime
fffffff0          class ATL::CTime endTime = class ATL::CTime
0:041> dt _SYSTEMTIME 0x09f6f9a8
xxxmodule!_SYSTEMTIME
   +0x000 wYear            : 0x7363
   +0x002 wMonth           : 0xe06d
   +0x004 wDayOfWeek       : 1
   +0x006 wDay             : 0
   +0x008 wHour            : 0
   +0x00a wMinute          : 0
   +0x00c wSecond          : 0x80d7
   +0x00e wMilliseconds    : 0x74d1

由于这里的信息来自它的调用函数,因此我们可以看看它的父函数里面的内容。从前面的栈帧列表中可看到其父函数为:xxmodule!xxxclass2::xxxclass2func1。栈帧序号为 1d,因此我们使用 .frame 1d 命令切换到其父函数栈帧如下所示:

0:041> .frame 1d
1d 09f6fb28 60336f62 xxxmodule!xxxclass2::xxxclass2func1+0x118 
0:041> dv /t /v
...
603994e8          struct _SYSTEMTIME s_regTime = struct _SYSTEMTIME
ffffffb4          struct _SYSTEMTIME sysTime = struct _SYSTEMTIME
...
0:041> dx -r1 ((xxxmodule!_SYSTEMTIME *)0x603994e8)
((xxxmodule!_SYSTEMTIME *)0x603994e8)      : 0x603994e8 [Type: _SYSTEMTIME *]
    [+0x000] wYear            : 0x7e0 [Type: unsigned short]
    [+0x002] wMonth           : 0x0 [Type: unsigned short]
    [+0x004] wDayOfWeek       : 0x0 [Type: unsigned short]
    [+0x006] wDay             : 0x1a [Type: unsigned short]
    [+0x008] wHour            : 0x0 [Type: unsigned short]
    [+0x00a] wMinute          : 0x0 [Type: unsigned short]
    [+0x00c] wSecond          : 0x0 [Type: unsigned short]
    [+0x00e] wMilliseconds    : 0x0 [Type: unsigned short]

从上图所示的信息可以看出,SYSTEMTIME的地址为0x603994e8,使用dx命令解析后发现,wMonth、wHour、wMinute、wSecond、wMilliseconds等全为0,猜测应该是将这些值传递给CTime的构造函数出的问题,我们看下CTime的构造函数:

ATLTIME_INLINE CTime::CTime(int nYear, int nMonth, int nDay, 
    int nHour, int nMin, int nSec, int nDST)
{
#pragma warning (push)
#pragma warning (disable: 4127)  // conditional expression constant

    ATLENSURE( nYear >= 1900 );
    ATLENSURE( nMonth >= 1 && nMonth <= 12 );
    ATLENSURE( nDay >= 1 && nDay <= 31 );
    ATLENSURE( nHour >= 0 && nHour <= 23 );
    ATLENSURE( nMin >= 0 && nMin <= 59 );
    ATLENSURE( nSec >= 0 && nSec <= 59 );

#pragma warning (pop)

    struct tm atm;

    atm.tm_sec = nSec;
    atm.tm_min = nMin;
    atm.tm_hour = nHour;
    atm.tm_mday = nDay;
    atm.tm_mon = nMonth - 1;        // tm_mon is 0 based
    atm.tm_year = nYear - 1900;     // tm_year is 1900 based
    atm.tm_isdst = nDST;

    m_time = _mktime64(&atm);
    ATLASSUME(m_time != -1);       // indicates an illegal input time
    if(m_time == -1)
    {
        AtlThrow(E_INVALIDARG);
    }
}
#ifndef ATLENSURE
#define ATLENSURE(expr) ATLENSURE_THROW(expr, E_FAIL)
#endif // ATLENSURE

可发现当月份不是[1,12]这个闭区间的时候,就会使用ATLENSURE_THROW宏抛出异常,至此问题原因找到,就是month的值为0导致的。

至于为什么为0,后来分析了下代码,发现是从一个整数(类似:20161021)中取月份的时候,存在错误。错误的计算方式为:Month = (Value % 1000) / 100; 这里Value是类似20161021这样的一个数字,很明显,当月份为10,11,12的时候,计算出来的Month为0,1,2。为0就抛出异常,所以程序崩溃了。这就造成了该崩溃只在每年的10月份才出现,及其隐蔽,如果原因未找到会发现该Bug很诡异。


调试总结:

  1. 找出崩溃的线程(WinDbg使用~*kvn列出所有线程的堆栈后,查找exception发生的地方)
  2. 找出线程中崩溃的第一现场(找出抛出exception的函数)
  3. 分析崩溃现场附近的代码(仔细分析抛出exception函数附近的可疑代码)

 




发表评论

电子邮件地址不会被公开。 必填项已用*标注