关闭

How to handle crash problem? (1.结合Dr.Watson系统日志和Vc6来定位多线程环境下程序异常退出的错误)

484人阅读 评论(0) 收藏 举报

本文转载,实战:结合Dr.Watson系统日志和Vc6来定位多线程环境下程序异常退出的错误

www.firnow.com    时间 : 2008-10-08  作者:佚名 编辑:本站 点击:  830 [ 评论 ]

当开发的软件发布以后,在客户那运行时可能会因为各种原因导致程序退出。这种情况很尴尬,很明显我们无法在客户机器上装个Visual Studio调试,所以必须有机制来收集出错的信息。软件本身的运行日志能提供部分信息,但是可能还不够。Windows系统为此提供了解决方案:Dr.Watson工具。Dr.Watson也算是一个小巧的调试器,32位的版本名字是drwtsn32.exe。可用于当系统中有进程发生异常崩溃时采集信息。下面结合一个例子看一下其用法。

先把测试代码贴一下:

1. /********************************************************************/

2. /* 程序:lesson_2, 结合Dr.Watson与工程map文件定位错误                                  */

3. /* 功能:多线程环境中利用除0错误使程序产生异常,被Dr.Watson捕获之       */

4. /* 作者:coding (http://blog.csdn.net/coding_hello)                                                     */

5. /* 日期:2008-09-29                                                                                                    */

6. /********************************************************************/

7.

8. #include

9. #include

10. #include

11.

12. const int cnThreadnum = 4;

13.

14. UINT WINAPI Worker(LPVOID lpParam)

15. {

16.     srand((DWORD)lpParam);

17.

18. DWORD dwTid = GetCurrentThreadId();

19. int k=100;

20. while(k–)

21.     {

22.         printf("tid[%u] tmp = %dn", dwTid, RAND_MAX/(rand()%cnThreadnum));

23.         Sleep(10);

24.     }

25. return 0;

26. }

27.

28. int main(int argc, char* argv[])

29. {

30. HANDLE hThd[cnThreadnum] = {0};

31. for(DWORD i=0; i

32.     {

33.         hThd[i] = (HANDLE)_beginthreadex(NULL, 0, Worker, (LPVOID)i, 0, NULL);

34.     }

35.

36.     printf("Wait…n");

37.     WaitForMultipleObjects(cnThreadnum, hThd, TRUE, INFINITE);

38.

39. for(int k=0; k

40.     {

41.         CloseHandle(hThd[k]);

42.     }

43.

44.     printf("Finish!n");

45.     system("pause");

46. return 0;

47. }

程序已开始就启动了4个线程,然后主线程等待所有的线程结束。线程函数中可能会因为RAND_MAX/(rand()%10)导致出现除0的错误。这里注意,编译的时候选择Link页,把"Generate mapfile"前面勾上。一般来说我就这样用了。但是还可以让map信息更详细一些,在最下面的"Project Options"的最后面手工敲入:"/mapinfo:lines",注意,跟前面内容要用空格隔开。然后再编译。

因为是要演示Dr.Waston,所以我们在命令行先用drwtsn32 -i的命令注册Dr.Watson为默认调试器(下次启动VC6的时候,在菜单option–>debug里面确认just-in-time debugging选中,就会把VC6恢复为默认调试器的)。注册完以后,我们看看注册表是否满足需要了。

clip_image001

看看注册表中HKEY_LOCAL_MACHINESOFTWAREMicrosoftWindows NTCurrentVersionAeDebug,其中的Auto键的值如果是0的话,程序出错后还会弹出错误提示。我们需要的是出错后安静的处理掉,客户知道了多不好~所以,改成1。下面的Debugger已经是drwtsn32了,很好。最后的UserDebuggerHotKey是调试器的热键,我们不需要。接下来,还是在命令行敲Drwtsn32,回车,终于看到Drwtsn32的庐山真面目了:

clip_image002

上面是日志文件和dump文件的保存路径。这次我们要看的是日志,dump文件下次再说。符号表我一般都勾上了,有的话就更好不是~ 重点是下面的应用程序错误(&R)这里,如果日志中有信息,就会在下面一条一条以纪录的形式显示出来。如果你的Drwatson中确实有日志的话,可以点清除把以前的都删掉。既然已经见过面了,那就把它关掉吧,需要时再打开,反正它自己也不会实施刷新。

好,现在一切就绪了!运行一下程序~ 只见嗖的一下,程序就停了。赶紧再把Dr.Watson请出来看看~

clip_image003

这次我们看到应用程序错误那里有了一条记录,把它选中变蓝后点上面的查看按钮。于是又出来一个对话框,显示“发生应用程序意外错误:”云云,内容很长,信息相当多。嗯,很好,很强大,这就是我们要的。考虑到这个框小了点,可以Ctrl+Shift+END全选后copy出来,用记事本看哈。在记事本中查找"错误 ->",然后就会看到个这:

错误 ->00401087 f7f9            idiv    eax,ecx

没错,这就是错误的位置。仔细看看上下文,分析分析。由于是一个多线程的程序,所以这里把出错的线程单独剥离出来。如下所示,每个线程的信息分为几个部分:一开始是错误发生时寄存器的信息;然后是当前发生错误的指令的前后各10条指令(什么是10条,不是20条或者2条?因为Dr.Watson里面默认设置的就是10条呀~,你刚才又没改);接下来是堆栈反向跟踪信息,也就是函数的逆向调用序列;最后是原始堆栈信息,可以获得参数,返回地址,局部变量之类的信息。

*—-> 线程 ID 0×2714 的状态转储 <—-*

eax=00007fff ebx=003724b8 ecx=00000000 edx=00000000 esi=0063ff2c edi=0063ff80

eip=00401087 esp=0063ff2c ebp=0063ff80 iopl=0 nv up ei pl zr na pe nc

cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00010246

函数: lesson_2!Worker

0040106b 7441 je lesson_2!Worker+0x8e (004010ae)

0040106d e86e020000 call lesson_2!rand (004012e0)

00401072 8bc8 mov ecx,eax

00401074 81e103000080 and ecx,80000003h

0040107a 7905 jns lesson_2!Worker+0×61 (00401081)

0040107c 49 dec ecx

0040107d 83c9fc or ecx,0FFFFFFFCh

00401080 41 inc ecx

00401081 b8ff7f0000 mov eax,7FFFh

00401086 99 cdq

错误 ->00401087 f7f9 idiv eax,ecx

00401089 50 push eax

0040108a 8b55fc mov edx,dword ptr [ebp-4]

0040108d 52 push edx

0040108e 681cd04200 push offset lesson_2!`string’ (0042d01c)

00401093 e898010000 call lesson_2!printf (00401230)

00401098 83c40c add esp,0Ch

0040109b 8bf4 mov esi,esp

0040109d 6a0a push 0Ah

0040109f ff15d8714300 call dword ptr [lesson_2!_imp__Sleep (004371d8)]

004010a5 3bf4 cmp esi,esp

*—-> 堆栈反向跟踪 <—*

ChildEBP RetAddr Args to Child

0063ff80 004015e2 00000001 00000000 00000000 lesson_2!Worker+0×67

0063ffb8 7c824829 003724b8 00000000 00000000 lesson_2!_threadstartex+0xb2

WARNING: Stack unwind information not available. Following frames may be wrong.

0063ffec 00000000 00401530 003724b8 00000000 kernel32!GetModuleHandleA+0xdf

*—-> 原始堆栈转储 <—-*

· 000000000063ff2c 00 00 00 00 00 00 00 00 – b8 24 37 00  cc  cc  cc  cc  ………$7…..

· 000000000063ff3c   cc  cc cc  cc  cc  cc cc  cc – cc  cc  cc  cc  cc  cc  cc  cc  …………….

· 000000000063ff4c   cc  cc cc  cc  cc  cc cc  cc – cc  cc  cc  cc  cc  cc  cc  cc  …………….

· 000000000063ff5c   cc  cc cc  cc  cc  cc  cc cc – cc  cc  cc  cc  cc  cc  cc  cc  …………….

· 000000000063ff6c   cc  cc cc  cc  cc  cc  cc cc – cc  cc  cc  cc  06 00 00  00  …………….

· 000000000063ff7c   14 27 00 00 b8 ff  63 00 – e2 15 40  00  01 00 00  00  .’….c…@…..

· 000000000063ff8c   00 00 00 00 00 00 00 00 – b8 24 37 00  94 00  00 c0  ………$7…..

· 000000000063ff9c   00 00 00 00 8c ff   63 00 – 60 fb 63 00  dc  ff   63 00  ……c.`.c…c.

· 000000000063ffac    b4 65 40 00 b0 d1 42 00 – 00 00 00 00 ec  ff   63 00  .e@…B…….c.

· 000000000063ffbc   29 48  82 7c b8 24 37 00 – 00 00 00 00 00 00  00 00  )H.|.$7………

· 000000000063ffcc    b8 24 37 00 94 00 00 c0 – c4  ff  63 00 60 fb  63  00  .$7…….c.`.c.

· 000000000063ffdc    ff   ff  ff  ff  60 1a  82 7c – 30 48 82 7c 00 00 00  00  ….`..|0H.|….

· 000000000063ffec    00 00 00 00 00 00 00 00 – 30 15 40 00 b8 24 37  00  ……..0.@..$7.

· 000000000063fffc    00 00 00 00 00 00 00 00 – 00 00 00 00 00  00 00 00  …………….

· 000000000064000c  00 00 00 00 00 00 00 00 – 00 00 00 00 00  00 00 00  …………….

· 000000000064001c  00 00 00 00 00 00 00 00 – 00 00 00 00 00  00 00 00  …………….

· 000000000064002c  00 00 00 00 00 00 00 00 – 00 00 00 00 00  00 00 00  …………….

· 000000000064003c  00 00 00 00 00 00 00 00 – 00 00 00 00 00  00 00 00  …………….

· 000000000064004c  00 00 00 00 00 00 00 00 – 00 00 00 00 00  00 00 00  …………….

· 000000000064005c  00 00 00 00 00 00 00 00 – 00 00 00 00 00  00 00 00  …………….

尽管这里可以简单的利用错误处指出的地址0×401087直接定位,那是因为这是很简单的情况。所以我决定还是简单讲一下在实际的复杂得多的环境中如何分析这些数据。

1.定位出错的模块。

我们看到错误的地址是0×401087,应该先确认这个地址是在哪个模块中。在错误日志中查找“模块清单”,能找到以下内容:

*—-> 模块清单 <—-*

0000000000400000 – 000000000043a000: D:DebugEasylesson_2Debuglesson_2.exe

0000000074ae0000 – 0000000074b45000: C:windowssystem32USP10.dll

0000000076180000 – 000000007619d000: C:windowssystem32IMM32.DLL

0000000076eb0000 – 0000000076ec3000: C:windowssystem32Secur32.dll

0000000077bd0000 – 0000000077c18000: C:windowssystem32GDI32.dll

0000000077c20000 – 0000000077cbf000: C:windowssystem32RPCRT4.dll

0000000077e10000 – 0000000077ea0000: C:windowssystem32USER32.dll

0000000077f30000 – 0000000077fdb000: C:windowssystem32ADVAPI32.dll

000000007c800000 – 000000007c92b000: C:windowssystem32kernel32.dll

000000007c930000 – 000000007ca00000: C:windowssystem32ntdll.dll

000000007f000000 – 000000007f009000: C:windowssystem32LPK.DLL

这里清楚的指出0000000000400000 – 0000000000439000这个范围的地址是系统分配给lesson_2.exe的。我们得到的错误地址是0×401087,所以可以确定错误就是发生的lesson_2.exe模块。实际上很多应用都还有些自己的动态库之类的,定位到具体的模块后才能更具体的结合代码分析。有时候出错的地址是属于kernel32,ntdll.dll之类的系统函数,这种情况下需要分析堆栈信息来确定错误模块。

2.分析当前发生错误的直接原因

我们看到错误的指令是:idiv eax,ecx。基本上访问eax和ecx都不会有问题,不然就是cpu有问题了。所以应该是除法指令出错。看看前面的寄存器的信息,eax=00007fff,也就是RAND_MAX,ecx=00000000,除0错误。对于我们这个例子,有了这个信息就足够定位到问题了。不过还是看看我们还能收集到些什么信息,毕竟实际环境可不会这么简单。

3.分析当前线程的调用堆栈。

ChildEBP   RetAddr    Args to Child            
0063ff80    004015e2    00000001  00000000 00000000 lesson_2!Worker+0×67
0063ffb8    7c824829    003724b8  00000000 00000000 lesson_2!_threadstartex+0xb2

在堆栈反向跟踪部分,这个信息很清晰。_threadstartex系统函数调用了我们的线程函数Worker。当前函数的返回地址是0x4015e2,接着是3个参数(注意:不一定都有效,显然不是所有的函数都有3个参数。实际上通过分析其dump文件能看到我们的例子中只有第一个参数有效,即1,是作为线程参数传入的lpParam)。这里我们结合map文件看看是不是跟这里记录的一样。在工程的debug目录里,有个扩展名为map的文件,用一般的文本编辑器就能打开。这文件太长了,节选一部分看看:

bsp;lesson_2

·  Timestamp is 48e0197a (Mon Sep 29 06:50:11 2008)

·

·  Preferred load address is 00400000

·

·  Start                      Length     Name                   Class

·

·  0001:00000000 0001bae7H .text                    CODE

·  0001:0001bae7 00010009H .textbss               CODE

·  0002:00000000 00002207H .rdata                  DATA

·  0002:00002207 00000000H .edata                  DATA

·  0003:00000000 00000104H .CRT$XCA        DATA

·  0003:00000104 00000104H .CRT$XCZ        DATA

·  0003:00000208 00000104H .CRT$XIA         DATA

·  0003:0000030c 00000109H .CRT$XIC          DATA

·  0003:00000418 00000104H .CRT$XIZ          DATA

·  0003:0000051c 00000104H .CRT$XPA         DATA

·  0003:00000620 00000104H .CRT$XPX         DATA

·  0003:00000724 00000104H .CRT$XPZ         DATA

·  0003:00000828 00000104H .CRT$XTA        DATA

·  0003:0000092c 00000104H .CRT$XTZ         DATA

·  0003:00000a30 0000407cH .data                     DATA

·  0003:00004ab0 00001b94H .bss                      DATA

·  0004:00000000 00000014H .idata$2                DATA

·  0004:00000014 00000014H .idata$3                DATA

·  0004:00000028 000001b0H .idata$4                DATA

·  0004:000001d8 000001b0H .idata$5                DATA

·  0004:00000388 0000076bH .idata$6                DATA

· ·   Address         Publics by Value              Rva+Base     Lib:Object

· ·  0001:00000020       ?Worker@@YGIPAX@Z          00401020 f   lesson_2.obj

·  0001:000000f0       _main                                            004010f0 f   lesson_2.obj

·  0001:00000212       _Sleep@4                                     00401212 f   kernel32:KERNEL32.dll

·  0001:00000218       _GetCurrentThreadId@0             00401218 f   kernel32:KERNEL32.dll

·  0001:0000021e       _CloseHandle@4                          0040121e f   kernel32:KERNEL32.dll

·  0001:00000224           00401224 f   kernel32:KERNEL32.dll

·  0001:00000230       _printf                                          00401230 f   LIBCMTD:printf.obj

·  0001:000002d0       _srand                                           004012d0 f   LIBCMTD:rand.obj

·  0001:000002e0       _rand                                             004012e0 f   LIBCMTD:rand.obj

·  0001:00000320       __chkesp                                      00401320 f   LIBCMTD:chkesp.obj

·  0001:00000360       _system                                        00401360 f   LIBCMTD:system.obj

·  0001:00000470       __beginthreadex            &

· nbsp;               00401470 f   LIBCMTD:threadex.obj

·  0001:00000630       __endthreadex                               00401630 f   LIBCMTD:threadex.obj

·  0001:00000680       _mainCRTStartup                        00401680 f   LIBCMTD:crt0.obj

·  0001:000007d0       __amsg_exit                                  004017d0 f   LIBCMTD:crt0.obj

· · 。。。。。。省略若干。。。。。

· · Line numbers for .Debuglesson_2.obj(d:debugeasylesson_2lesson_2.cpp) segment .text

· ·     18 0001:00000020    19 0001:00000038    21 0001:00000044    22 0001:00000056

·     23 0001:0000005d    25 0001:0000006d    26 0001:0000009b    27 0001:000000ac

·     28 0001:000000ae    29 0001:000000b0    32 0001:000000f0    33 0001:00000108

·     34 0001:0000011a    36 0001:00000132    37 0001:00000152    39 0001:00000154

·     40 0001:00000161    42 0001:0000017a    44 0001:00000192    45 0001:000001a9

·     47 0001:000001ab    48 0001:000001b8    49 0001:000001c5    50 0001:000001c7

· 其中显示了程序名,程序的时间戳,程序中的代码分布,预定的加载地址,各个函数的起始地址,包括相对虚拟地址(RVA)以及文件行与RVA的对应关系等信息。我们看到预定的加载地址和我们在模块清单中看到的加载地址相同。很好,省得计算相对位置。一般来说Exe总是加载到0×400000,并且总是能得到这个位置的。而动态库的话,墨认是0×10000000,显然如果有2个动态库就没法都加载到同一个地址,需要计算RVA。

其中显示了程序名,程序的时间戳,程序中的代码分布,预定的加载地址,各个函数的起始地址,包括相对虚拟地址(RVA)以及文件行与RVA的对应关系等信息。我们看到预定的加载地址和我们在模块清单中看到的加载地址相同。很好,省得计算相对位置。一般来说Exe总是加载到0×400000,并且总是能得到这个位置的。而动态库的话,墨认是0×10000000,显然如果有2个动态库就没法都加载到同一个地址,需要计算RVA。

刚才从堆栈反向跟踪信息中我们看到当前Worker函数的返回地址为0x401e52,在map文件中找找。很快就能看到__beginthreadex函数是从0×401470开始,到0×401630结束。那就说明地址0x401e52就在__beginthreadex函数中。这就对了,因为我们就是用__beginthreadex函数启动的线程函数Worker,是吧~。顺手看一下刚才出错的地址0×401087,看看是在哪。再看看map文件,第一个函数就是,地址是0×00401020至0x4010f0(main函数),所以0×401087就是在执行Worker函数中的指令。那么具体在哪一行呢?因为出错的函数Worker在文件lesson_2.cpp中,所以我们查找lesson_2.cpp,就找到了下面的信息:

Line numbers for .Debuglesson_2.obj(d:debugeasylesson_2lesson_2.cpp) segment .text

15 0001:00000020 16 0001:00000038 18 0001:00000044 19 0001:00000056

20 0001:0000005d 22 0001:0000006d 23 0001:0000009b 24 0001:000000ac

25 0001:000000ae 26 0001:000000b0 29 0001:000000f0 30 0001:00000108

31 0001:0000011a 33 0001:00000132 34 0001:00000152 46 0001:00000154

37 0001:00000161 39 0001:0000017a 41 0001:00000192 42 0001:000001a9

44 0001:000001ab 45 0001:000001b8 46 0001:000001c5 47 0001:000001c7

我们看到前面是个数字,18、19、21啥的,后面是0001:00000020之类。前面的就是cpp文件中的行号,后面是相对虚拟地址,我们的0×401087在哪呢?又回到刚才说的默认加载地址了。map中看到默认加载地址是0×400000,而我们的exe在内存中也是加载到0×400000,所以相对位置就是RVA = 0×401087(错误地址) – 0×400000(模块在内存中实际加载的地址) = 0×1067。不对啊,这里最大才到0x1c7,这是怎~么个情况?因为每个PE模块之前都有0×1000字节的dos stub和PE格式信息。所以0×1087还要减掉0×1000,就剩下0×87了。再看看,大于0x5d,小于0x6d,所以就是第22行。看看代码中的22行,printf("tid[%u] tmp = %dn", dwTid, RAND_MAX/(rand()%cnThreadnum));没错,就是在这里RAND_MAX/0了~。说明前面根据Dr.Watson的日志分析的结果都是正确的,没骗你噢~

有时候堆栈反向跟踪的信息并不准确,多半是因为函数中的局部变量在memcpy,strcpy之类的函数复制的数据过长,导致堆栈访问越界。这种情况下,要仔细分析原始堆栈转储,以后再说。

在实际工作中,利用Dr.Watson辅助生成错误日志,对于开发人员确实是很有帮助的。有需要的朋友,可以考虑这么试试。

那今天就写到这吧~ 天亮啦,饭去~

0
0

查看评论
* 以上用户言论只代表其个人观点,不代表CSDN网站的观点或立场
    个人资料
    • 访问:55142次
    • 积分:1374
    • 等级:
    • 排名:千里之外
    • 原创:94篇
    • 转载:1篇
    • 译文:0篇
    • 评论:5条
    最新评论