使用Windbg找出死锁,解决生产环境中运行的软件不响应请求的问题
前言
本文介绍本人的一次使用Windbg分析dump文件找出死锁的过程,并重点介绍如何确定线程所等待的锁及判断是否出现了死锁。
对于如何安装及设置Windbg请参考:《使用Windbg和SoS扩展调试分析.NET程序》http://www.cnblogs.com/shanyou/archive/2006/12/23/601004.html
起因
今天,部署到生产环境中的软件再次发生了不响应请求的问题,看了系统日志与软件本身的log都没发现异常,而在任务管理器中软件占用了1G多的内存,有点偏高(正常是300M左右)。由于本人不在现场,只能通过远程的方式查看,同时故障出现间隔比较长(将近一周),在生产环境中也就无法使用VS进行调试。
无意中在资源监视器的CPU页看到软件的线程数是1.7万个,内存页的提交内存使用也将近18G,同时线程数与提交内存也在缓慢增加。当时就想是不是由于某种原因导致线程无法退出从而在线程数太多的时候致使软件不响应请求(后来的调试也证实是死锁导致的)。
由于故障难以重现(只在生产环境中长时间运行才会出现,在测试环境无法出现),只能对正在运行的软件进行分析。
这时候就请出了大名鼎鼎的Windbg,下面是详细的过程。
过程
一、抓取dump文件
抓取dump的方法,可以参考《抓取user mode dump文件的几重境界》http://www.cnblogs.com/pugang/archive/2013/02/18/2916211.html
我选择的是使用图形化操作的方式,在任务管理器的进程页中,右键需要抓取的程序,选择“创建转储文件”
运行完成后将会弹出成功对话框并提示dump文件的所在
二、在Windbg中加载dump文件与SOS.dll
运行Windbg,在File菜单下选择Open Crash Dump,选择上面抓取的dump文件
在Windbg下侧的命令输入框中输入“.load C:\Windows\Microsoft.NET\Framework64\v4.0.30319\sos”并回车加载SOS.dll。由于我是调试net4.0 64位的软件,所以使用了Framework64\v4.0.30319下的sos,其它版本请选择对应位置的sos进行加载
三、使用Windbg查找死锁
使用“!threads”命令列出所有的线程,发现一共存在17306个线程
使用“~17306s”命令切换到最后一个线程,并使用“!clrstack”命令输出当前线程的调用堆栈,发现存在“System.Threading.Monitor.Enter(System.Object)”,表明线程正在请求一个锁。由于得不到锁,因此线程卡死
切换到其它线程查看调用堆栈,都是因为同样的原因导致线程卡死,这时候可以初步判断这些线程是因为死锁导致执行不下去
使用“!syncblk”命令列出所有正在使用的锁,其中MonitorHeld与Recursion列表示了请求锁的线程数量情况,Info列表示哪个线程拥有了锁,SyncBlock列表示锁对象的地址。如MonitorHeld与Recursion的值为3775与1那行表示第40个线程拥有了这个锁,其它(3775-1)/2=1887个线程在等待锁,锁对象地址为0000000003c812f0。看到如此多的线程在请求同一个锁,就知道情况不正常,看来离死锁的真相又近了一步
接下来的过程就是:找到某个线程(如线程A)请求的锁(如锁J),查看哪个线程(如线程B)拥有这个锁(锁J)及这个线程请求的锁(锁K),接着查看哪个线程(如线程C)拥有这个锁(锁K)及这个线程请求的锁(锁L),重复查看的过程,看最终是否有一个线程(如线程D)请求前面出现的任意一个锁(如线程B拥有的锁J),形成环状,这时即可判断其为死锁
这里从线程17306开始分析,使用“!clrstack -l”命令列出当前线程的调用堆栈及其使用的局部变量
在调用“System.Threading.Monitor.Enter(System.Object)”之前的一个方法内,应该存在作为局部变量的线程请求的锁对象
这里猜测下面的0000000003c812f0就是这个锁对象,通过查找上面的锁列表,确定了这个猜测,同时知道线程40拥有这个锁
使用“~40s”命令切换到线程40,并使用“!clrstack -l”命令列出当前线程的调用堆栈及其使用的局部变量,通过查找锁列表确定000000000317ac10为当前线程请求的锁对象,同时知道线程26拥有这个锁
同样使用“~26s”与“!clrstack -l”命令找到线程26请求的锁对象00000000044a81a8,这个锁对象被线程43拥有
接着使用“~43s”与“!clrstack -l”命令找到线程43请求的锁对象000000000317ac10,这个锁对象被线程26拥有
此时可以发现线程26与线程43之间形成了死锁
结果
终于真相大白了,上面的过程成功找到了死锁
也由此推断由于死锁的存在,导致后面新建的线程由于得不到请求的锁,一直不能执行下去,更不可能释放所占用的内存,从而使得线程数与内存占用在一直升高,直到软件无法响应请求为止
接下来的工作就是查看死锁线程的调用堆栈,结合软件源代码分析死锁形成时软件的运行情况,并更改处理逻辑以避免死锁的产生