1. 调试Bug的神兵利器:通过WinDbg条件断点收集Log
原文地址:http://blogs.msdn.com/yizhang/archive/2009/03/30/bug-windbg-log.aspx
调试Bug的神兵利器:通过WinDbg条件断点收集Log
前段时间花了几天一直在用WinDbg调试一个比较棘手的Bug。这个Bug是C# Team那边发现的,他们的Testcase跑大概10分钟左右会出一个在CLR内部的ASSERT。比较难调试的主要原因在于ASSERT表明一个全局的数据结构出现了问题,本来不应该用完的数组却已经用完了(因为按照设计,这个数组是边使用边清理的,是不会用完的)。初步想到的有下面几种方案来调试:
1. 设置数据断点
2. 一步一步调试
3. 添加Log代码
设置数据断点的主要问题是不太好确定到底是因为什么原因导致的数据结构问题,而且因为是数组被用完,很难将是到底是哪一个数组元素的加入导致了数组被全部占用,因此无法通过设置数据断点的方法来调试。一步一步的调试显然也没法解决问题,因为这个Testcase本身要跑十分钟,可以想象单步调试运行十分钟的程序会花费多长时间。因此两个方案都被我否决。添加Log代码其实是可以的,只是需要修改代码,每次修改之后需要重新编译代码,然后需要在目标机器上安装,而且C#使用的CLR的Branch并非我们正在开发的Branch,需要重新下载源代码,相对比较麻烦。最后为了解决这个问题,我采取的方法是使用WinDbg的条件断点+Log的方式。大致的方法如下:
第一步:在一个或者多个可疑处设置断点
bu address “command”
bu是WinDbg中的设置Unresolved Breakpoints命令,用起来比较方便,我比较喜欢用。address就是你所要断的代码地址,可以是函数开始,也可以是某一行。Command非常重要,它表示了WinDbg在每次断到address的时候都要执行的命令,不同命令用分号隔开,如:
.echo [Function A]; dv this; kb; g
这几条命令意思是:打印[Function A],打印this指针的值,打印当前调用栈,然后继续执行。大家可以根据实际情况添加一些其他命令打印一些自己所需要的信息。通过上面这套命令打印的内容大致如下:
[FunctionA]
this = 0xABCDEFG
module!FuncA
module!FuncB
module!FuncC
…
可以看出,这条断点如果反复被断,那么在WinDbg的命令窗口中便会把每次断点被Hit的相关信息通过刚才定义的命令打印出来。如果定义了很多这样的断点,那么在命令窗口中就会把整个程序执行的情况打印出来,起到Log的作用,而且可以显示调用栈等信息,比一般的Log要强大许多。
第二步:设置Log
缺省情况下,WinDbg的Buffer大小是有限的,如果程序运行时间比较长,那么Buffer可能会不够,我们通过条件断点打出的信息会被截断。幸好,WinDbg提供了将命令窗口的内容输出到Log中的功能。选择Edit->Open/Close Log File菜单项,WinDbg会显示如下对话框:
在这个对话框里面输入你想要保存的Log文件名即可。如果是添加新的内容而不是覆盖原有的,则勾上Append。
第三步:分析Log
当获得了Log信息之后,下一步就需要分析Log的内容了,这是一件需要耐心、对数据的敏感、以及一点点运气的事情。分析的时候可能发现Log的信息不足,这时就需要添加新的断点或者修改打印的信息,重新收集Log,再加以分析,直到Log信息足够为止。这时WinDbg设置条件断点的优势就出来了,因为不需要修改代码,编译代码,部署代码这样的一个过程,而是只需要键入不同的命令而已。经过几次调整断点位置和打印的信息并重新收集Log,我最终通过分析发现这个Bug是只有可能在特定情况下RCW没有被GC,并且创建线程退出的时候才会出现,具体的内容因为涉及到.NET 4.0中还没有发布的新功能,这里就不多说了。可以看到,如果采用常规的方法,对于这种在特定的条件下才会重现的问题是很难发现的。
总之,使用WinDbg来设置条件断点,打印相关信息,并且输出到Log文件是一种非常强大的调试方法,可以调试一些非常复杂的Bug,而且具有不需要修改代码的灵活性,可以自由定义自己想需要打印的信息和断点设置的位置,主要的缺点是方法稍显复杂,不过如果适应了之后还是很方便的。我强烈推荐大家在遇到比较复杂的Bug的时候,可以尝试使用一下这种方法,可能具有意想不到的效果哦。
如果一个程序跑10000次只失败一次,你会怎么调试?
原址:http://blogs.msdn.com/yizhang/archive/2009/08/28/9887951.aspx
CLR小组中存在着大量的回归测试,这些回归测试会定期执行来发现CLR中的Bug,Developer在Checkin之前,也需要执行这些测试的一部分(大概是10小时左右,如果全部跑的话估计要好几天)。这些测试对于保证CLR的质量是至关重要的。有时候,这些测试会偶尔失败,比如跑100次失败大概一到两次,有些极端的例子甚至是10000次才失败一次。像这种问题通常是很难调试的。在前面调试Bug的神兵利器:通过WinDbg条件断点收集Log这篇文章中,我讲到了如何通过条件断点收集各种信息来判断Bug究竟出在哪里。但是,这个方法还是不太管用,因为它不能够反复执行某个程序。下面我要讲一种技巧可以用来调试类似这样的问题,这种技巧主要适用于下面几种情况:
- 在程序出错的时候,某些信息、状态已经丢失,无法通过当前出错时候的状态推断出之前的状态。说的稍微具体一点就是,比如某个变量变成了NULL导致Access Violation,但是很难直接推断出为什么这个变量变成了NULL
- 程序运行时间较长,很难直接单步调试
- 程序较难修改加入打印代码(比如加入新代码并编译非常花时间,或者该程序没有源代码
- 该程序运行次数较多的时候才能发现问题,也就是说问题不是每次都出现
#2和#4决定了一步步调试基本上是不可能的。#1和#3则意味着我们必须得使用条件断点来收集信息来判断代码的错误,因为直接调试出错的位置是不可行的。下面了我来讲一下如何用CDB(其实就是WinDbg的无UI版本,WinDbg=CDB+UI)来做到:
- 反复执行程序
- 当程序出错的时候自动暂停
- 通过条件断点收集信息,只保留出错时候的那一次Log
我们先假设我们需要调试的程序叫做Hello.exe,每次出问题的现象是,调用某个函数Hello!Func()的时候,其参数arg为NULL。Arg这个变量是由某个全局变量g_arg传入而来。我们可以通过硬件的数据断点来查看每次将g_arg赋值为NULL的情况(当然了,赋值为NULL并不代表是错误,只有传入Hello!Func的时候为NULL才是错误)。程序一般要跑10000次才可能发现问题。使用下面的命令行可以做到反复收集Func1(Func2、Func3因为类似,这里就不列出了)执行时候的g_arg的值并放入Log文件中,并且如果发现调用Hello!Func的时候arg参数为NULL,则停止程序:
for /L %i in (1, 1, 10000) DO CDB.exe -c "bu Hello!Func \".echo Inside Hello!Func; dv; .if (poi(arg)!=0) { g } \"; ba w4 Hello!g_arg \“.if (poi(Hello!g_arg)==0) { .echo g_arg changes to NULL; kb; }\”; g" -G -logo debug.log Hello.exe
我们来简单分析一下:
- 一开头的For语句用于执行CDB命令10000次,也就是调试Hello.exe一万次
- -c命令指定让CDB在程序开始的时候执行下面的命令
- bu Hello!Func “.echo Inside Hello!Func; dv; .if (poi(arg)!=0) { g }意思是每次Hello!Func被执行的时候,打印Inside Hello!Func,之后打印所有局部变量和参数(包括arg),如果发现arg!=NULL,则继续。注意上面命令中的\”是转义符,代表真正的引号,避免冲突。
- ba w4 Hello!g_arg “.if (poi(Hello!g_arg)==0) { .echo g_arg changes to NULL; kb; }”意思是每次如果g_arg被修改成NULL,打印出Callstack
- g命令表示让程序开始执行
- -G:表示让CDB忽略程序结束的时候的Breakpoint,避免CDB在运行结束的时候停下,保证CDB可以持续执行不需要人工干预
- -logo debug.log:表示让CDB把每次输出的结果放入Debug.log中,并且每次都新建立文件,也就是说,会把上一次覆盖。这正好是我们需要的,因为我们设置了一旦程序错误则停止,那么这一次的Debug.log才是需要保留的
除了用-c指定初始的命令之外,也可以使用-cf来指定一个文件包含任意条CDB命令,如果CDB命令较多,可以采用这种方法。
本文说道的方法是比较有效的,我自己曾经使用过这种方法解决过不少比较棘手的问题。如果碰到了此种需要运行10000次才能重现问题的Bug,不妨试一下本文的方法。