windbg分析临界区死锁

发表于 | 更新于 | 分类于 | 评论数： | 阅读次数：

介绍

多线程编程中，对于资源同步导致的死锁问题，应该是开发过程中经常碰到的，同时在问题定位过程中也会花费大量的时间，这里就介绍下如何通过windbg来分析死锁问题。

资源同步

windows下资源同步的方法主要是

  • 原子访问
  • 临界区
  • 读写锁
  • 旋转锁
  • 等待函数
  • 事件
  • 信号量
  • 互斥量

其中最常用的应该是临界区了（性能开销小），所以我也是拿临界区作为分析对象，其他资源同步不在此讨论。

临界区

保证在某一时刻只有一个线程能访问数据的简便办法。在任意时刻只允许一个线程对共享资源进行访问。如果有多个线程试图同时访问临界区，那么 在有一个线程进入后其他所有试图访问此临界区的线程将被挂起，并一直持续到进入临界区的线程离开。临界区在被释放后，其他线程可以继续抢占，并以此达到用原子方式操 作共享资源的目的。
临界区包含两个操作原语：
EnterCriticalSection（） 进入临界区
LeaveCriticalSection（） 离开临界区
EnterCriticalSection（） 语句执行后代码将进入临界区以后无论发生什么，必须确保与之匹配的 LeaveCriticalSection（）都能够被执行到。否则临界区保护的共享资源将永远不会被释放。虽然临界区同步速度很快，但却只能用来同步本 进程内的线程，而不可用来同步多个进程中的线程。

结构体定义

1
2
3
4
5
6
7
8
typedef struct _RTL_CRITICAL_SECTION {
	PRTL_CRITICAL_SECTION_DEBUG DebugInfo;
	LONG LockCount;
	LONG RecursionCount;
	HANDLE OwningThread;
	HANDLE LockSemaphore;
	ULONG_PTR SpinCount;
} RTL_CRITICAL_SECTION, *PRTL_CRITICAL_SECTION;

各个参数的解释如下：
第一个参数：PRTL_CRITICAL_SECTION_DEBUG DebugInfo;//调试用的
第二个参数：LONG LockCount;//初始化为-1，n表示有n个线程在等待
第三个参数：LONG RecursionCount;//表示该临界区的拥有线程对此资源获得临界区次数，初为0
第四个参数：HANDLE OwningThread;//即拥有该临界区的线程句柄
第五个参数：HANDLE LockSemaphore;//实际上是一个自复位事件
第六个参数：DWORD SpinCount;//旋转锁的设置，单CPU下忽略

由这个结构可以知道：临界区会记录拥有该临界区的线程句柄，即临界区是有“线程所有权”概念的。事实上它会用第四个参数OwningThread来记录获准进入临界区的线程句柄，如果这个线程再次进入，EnterCriticalSection()会更新第三个参数RecursionCount以记录该线程进入的次数并立即返回让该线程进入。其它线程调用EnterCriticalSection()则会被切换到等待状态，一旦拥有线程所有权的线程调用LeaveCriticalSection()使其进入的次数为0时，系统会自动更新临界区并将等待中的线程换回可调度状态。

问题出现

服务器工作线程每5s会定时上报当前还有多少消息堆积未处理，正常情况应该都是<=10左右。如果出现cpu不足、io、死锁、假死等问题导致工作线程无法正常消费，那么消息堆积数量会逐渐上升。某天在告警群里面提示某服务的消息堆积从100、400、1000、3000、5000 逐渐上升，第一感觉就是服务出问题了，立刻让运维查看服务器cpu、内存、io，均正常，而且同物理主机的其他服务正常运行，所以问题应该是该服务程序出现了某些状况，可能是死锁、也可能是死循环、也可能是长时间sleep….. 立刻保存fulldump，然后重启服务，先恢复线上服务，以免给客户带来更大损失。

分析过程

下载dump

下载地址(提取码：33lg)

步骤1

使用windbg 打开dump，并设置好pdb、操作系统pdb；
使用命令 “~*kv” 显示所有线程当前的函数调用栈，效果如下（大部分省略）

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
0:021> ~*kv

   0  Id: 173c.16d8 Suspend: 3 Teb: 7efdd000 Unfrozen
ChildEBP RetAddr  Args to Child              
0035b6b8 775514ab 000000d0 00000000 00000000 ntdll!NtWaitForSingleObject+0x15 (FPO: [3,0,0])
0035b724 77441194 000000d0 ffffffff 00000000 KERNELBASE!WaitForSingleObjectEx+0x98 (FPO: [Non-Fpo])
0035b73c 77441148 000000d0 ffffffff 00000000 kernel32!WaitForSingleObjectExImplementation+0x75 (FPO: [Non-Fpo])
0035b750 75777be6 000000d0 ffffffff 0e9c9dd4 kernel32!WaitForSingleObject+0x12 (FPO: [Non-Fpo])
0035b7f4 75778040 0070b1b8 000000d0 00000000 sechost!ScSendResponseReceiveControls+0xea (FPO: [Non-Fpo])
0035b8a8 75778553 0035b8bc 00000000 00000001 sechost!ScDispatcherLoop+0xc2 (FPO: [Non-Fpo])
*** WARNING: Unable to verify checksum for MatchSvr.exe
0035b8c0 012432cb 0035b8cc 0035b938 012431a0 sechost!StartServiceCtrlDispatcherA+0x68 (FPO: [Non-Fpo])
0035b8dc 01218689 fc7e3c0d 00000000 00000001 MatchSvr!CNTService::StartServiceA+0x2b
0035f928 01253f2a 00000001 00708280 006ff620 MatchSvr!main+0x139 (FPO: [Non-Fpo]) (CONV: cdecl) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\main.cpp @ 190]
0035f968 7744338a 7efde000 0035f9b4 77bf9f72 MatchSvr!__tmainCRTStartup+0xfd (FPO: [Non-Fpo]) (CONV: cdecl) [f:\dd\vctools\crt\crtw32\dllstuff\crtexe.c @ 626]
0035f974 77bf9f72 7efde000 85371315 00000000 kernel32!BaseThreadInitThunk+0xe (FPO: [Non-Fpo])
0035f9b4 77bf9f45 01253f92 7efde000 ffffffff ntdll!__RtlUserThreadStart+0x70 (FPO: [Non-Fpo])
0035f9cc 00000000 01253f92 7efde000 00000000 ntdll!_RtlUserThreadStart+0x1b (FPO: [Non-Fpo])

   1  Id: 173c.290 Suspend: 3 Teb: 7ef9f000 Unfrozen
ChildEBP RetAddr  Args to Child              
02aef948 76fa7c1d 02aef9cc 00000000 00000000 user32!NtUserGetMessage+0x15 (FPO: [4,0,0])
02aef968 0122d9ad 02aef9cc 00000000 00000000 user32!GetMessageA+0xa1 (FPO: [Non-Fpo])
02aef9ec 0124326d 00000000 00712b08 00000000 MatchSvr!CMainService::Run+0x7d (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\service.cpp @ 65]
02aefa0c 757775a8 00000001 00712b18 00000000 MatchSvr!CNTService::ServiceMain+0xcd

步骤2

观察所有线程的函数调用。 这个服务并不复杂，总共只有二十几个线程（以前分析的都是至少100个线程的dump），然后重点查看服务进程的主要工作线程（是因为工作线程不工作才导致消息堆积）。

这个服务的工作线程有4个分别是10、11、12、13， 至于怎么确定的？
1、看日志。良好的编码习惯，程序中的每个线程启动、退出都会在日志中记录
2、对代码逻辑的熟悉

步骤3

切换到其中任意一个工作线程，比如10号线程
~10s
kv

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
0:010> ~10s
eax=00000000 ebx=03020f70 ecx=00000000 edx=00000000 esi=7fffffff edi=ffffffff
eip=77bdf8d1 esp=03bcf10c ebp=03bcf14c iopl=0         nv up ei pl zr na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
ntdll!NtWaitForSingleObject+0x15:
77bdf8d1 83c404          add     esp,4
0:010> kv
ChildEBP RetAddr  Args to Child              
03bcf10c 74a06f1f 00000330 00000001 03bcf134 ntdll!NtWaitForSingleObject+0x15 (FPO: [3,0,0])
03bcf14c 74a06d40 00000330 000001a4 00000001 mswsock!SockWaitForSingleObject+0x1ba (FPO: [Non-Fpo])
03bcf238 75796a28 000001a5 00000000 03bcf2ec mswsock!WSPSelect+0x3a6 (FPO: [Non-Fpo])
03bcf2b8 744d7787 000001a5 00000000 03bcf2ec ws2_32!select+0x494 (FPO: [Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be wrong.
03bcf3f4 744d75f0 000001a4 00000004 ffffffff rabbitmq_4!amqp_open_socket+0x347
03bcf600 744d76ca 00720ae8 000021e0 ffffffff rabbitmq_4!amqp_open_socket+0x1b0
03bcf620 744d9693 00720ae8 000021e0 00000000 rabbitmq_4!amqp_open_socket+0x28a
03bcf638 744d7e26 0497bdc8 00720ae8 000021e0 rabbitmq_4!amqp_parse_url+0x3c3
03bcf650 01250550 0497bdc8 00720ae8 000021e0 rabbitmq_4!amqp_socket_open+0x16
03bcf728 01250e97 fff73d65 0070b3d8 071ca950 MatchSvr!CRabbitMQ::connect+0xd0
03bcf840 01250870 0071ecf4 0071ecc4 03bcfa28 MatchSvr!CRabbitMQ::_publish_str_+0x187
03bcf8a4 01250100 0071ecf4 0071ecc4 03bcfa28 MatchSvr!CRabbitMQ::sendmsg+0x20
03bcf908 01218d48 0071ecf4 0071ecc4 03bcfa28 MatchSvr!CRabbitmqProc::sendmsg+0x20
03bcf96c 01231fbc 03bcfa28 fff7382d 0070b3d8 MatchSvr!CProducerMQ::RabbitMQPublish_log+0x28 (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\producermq.cpp @ 62]
03bcfd08 0122eb98 071cae70 08c6c368 007022a8 MatchSvr!CSockServer::OnGameUserArenaResult+0xc3c (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\socksvr.cpp @ 1096]
03bcfda4 012392e4 071cae70 08c6c368 0070b3e0 MatchSvr!CSockServer::OnRequest+0x718 (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\socksvr.cpp @ 309]
03bcfdcc 0123d1bb 00000000 00715868 007141b8 MatchSvr!CIocpWorker::DoWorkLoop+0xa4
03bcfde4 0123d18b 03bcfe24 70ffc01d 0070b3d8 MatchSvr!CBaseWorker::WorkerThreadProc+0x2b
03bcfdec 70ffc01d 0070b3d8 0d15d467 00000000 MatchSvr!CBaseWorker::WorkerThreadFunc+0xb
03bcfe24 70ffc001 00000000 03bcfe3c 7744338a msvcr120!_callthreadstartex+0x1b (FPO: [Non-Fpo]) (CONV: cdecl) [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 376]
03bcfe30 7744338a 007141b8 03bcfe7c 77bf9f72 msvcr120!_threadstartex+0x7c (FPO: [Non-Fpo]) (CONV: stdcall) [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 354]
03bcfe3c 77bf9f72 007141b8 86be14dd 00000000 kernel32!BaseThreadInitThunk+0xe (FPO: [Non-Fpo])
03bcfe7c 77bf9f45 70ffbfb4 007141b8 ffffffff ntdll!__RtlUserThreadStart+0x70 (FPO: [Non-Fpo])
03bcfe94 00000000 70ffbfb4 007141b8 00000000 ntdll!_RtlUserThreadStart+0x1b (FPO: [Non-Fpo])

从中，我们看到调用栈并没有什么问题，大概意思就是收到了一个GameUserArenaResult消息，然后通过mq publish出去，然后mq模块正在进行connect。感觉没有问题，接着看11号线程

~11s
kv

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
0:010> ~11s
eax=00000001 ebx=00000000 ecx=00000000 edx=00000000 esi=007124f8 edi=00000000
eip=77bdf8d1 esp=03ccf4cc ebp=03ccf530 iopl=0         nv up ei pl zr na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
ntdll!NtWaitForSingleObject+0x15:
77bdf8d1 83c404          add     esp,4
0:011> kv
ChildEBP RetAddr  Args to Child              
03ccf4cc 77bf8e44 00000e0c 00000000 00000000 ntdll!NtWaitForSingleObject+0x15 (FPO: [3,0,0])
03ccf530 77bf8d28 00000000 00000000 0070b3e0 ntdll!RtlpWaitOnCriticalSection+0x13e (FPO: [Non-Fpo])
03ccf558 01216e48 007124f8 0070b3d8 030c7658 ntdll!RtlEnterCriticalSection+0x150 (FPO: [Non-Fpo])
03ccf5b4 0121525e 0070b3d8 030c7658 0070b3e0 MatchSvr!JMutex::Lock+0x28 (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\jmutex.cpp @ 71]
03ccf60c 01214b6a 007124f8 ff873359 0070b3d8 MatchSvr!JMutexAutoLock::JMutexAutoLock+0x1e (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\jmutexautolock.h @ 39]
03ccf67c 01231c00 03ccf790 ff873f3d 0070b3d8 MatchSvr!CDelaySendMsg::AddMsg+0x3a (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\delaysendmsg.cpp @ 14]
03ccfa18 0122eb98 05ebbe68 088d7790 00702348 MatchSvr!CSockServer::OnGameUserArenaResult+0x880 (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\socksvr.cpp @ 1071]
03ccfab4 012392e4 05ebbe68 088d7790 0070b3e0 MatchSvr!CSockServer::OnRequest+0x718 (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\socksvr.cpp @ 309]
03ccfadc 0123d1bb 00000000 00715ff8 007154a0 MatchSvr!CIocpWorker::DoWorkLoop+0xa4
03ccfaf4 0123d18b 03ccfb34 70ffc01d 0070b3d8 MatchSvr!CBaseWorker::WorkerThreadProc+0x2b
03ccfafc 70ffc01d 0070b3d8 0d65d177 00000000 MatchSvr!CBaseWorker::WorkerThreadFunc+0xb
03ccfb34 70ffc001 00000000 03ccfb4c 7744338a msvcr120!_callthreadstartex+0x1b (FPO: [Non-Fpo]) (CONV: cdecl) [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 376]
03ccfb40 7744338a 007154a0 03ccfb8c 77bf9f72 msvcr120!_threadstartex+0x7c (FPO: [Non-Fpo]) (CONV: stdcall) [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 354]
03ccfb4c 77bf9f72 007154a0 86ce112d 00000000 kernel32!BaseThreadInitThunk+0xe (FPO: [Non-Fpo])
03ccfb8c 77bf9f45 70ffbfb4 007154a0 ffffffff ntdll!__RtlUserThreadStart+0x70 (FPO: [Non-Fpo])
03ccfba4 00000000 70ffbfb4 007154a0 00000000 ntdll!_RtlUserThreadStart+0x1b (FPO: [Non-Fpo])

这个堆栈就有意思了，大概就是收到了OnGameUserArenaResult消息，然后AddMsg，进入一个AutoLock，然后RtlEnterCriticalSection，看到这个说明很可能有死锁问题。我们继续观察这个临界区的具体信息

1
03ccf558 01216e48 007124f8 0070b3d8 030c7658 ntdll!RtlEnterCriticalSection+0x150 (FPO: [Non-Fpo])

注意其中的第三列、第四列、第五列， 分别代表了这个函数的第一个入参、第二个入参、第三个入参， 之前看过临界区的结构体，所以使用以下命令

1
!cs 007124f8

1
2
3
4
5
6
7
8
9
10
11
0:011> !cs 007124f8
-----------------------------------------
Critical section   = 0x007124f8 (+0x7124F8)
DebugInfo          = 0x007184b8
LOCKED
LockCount          = 0x2
WaiterWoken        = No
OwningThread       = 0x00001188
RecursionCount     = 0x1
LockSemaphore      = 0xE0C
SpinCount          = 0x00000000

这个临界区正在被 0x00001188 的线程占用，所以导致11s线程无法进入临界区，那么我们就去 0x00001188 线程在做什么。
通过线程id显示线程号命令
~~[0x00001188]

1
2
3
4
0:011> ~~[0x00001188]
   4  Id: 173c.1188 Suspend: 3 Teb: 7ef96000 Unfrozen
      Start: msvcr120!_threadstartex (70ffbfb4) 
      Priority: 0  Priority class: 32  Affinity: 3

4号线程，然后我们切换
~4s
kv

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
0:004> kv
ChildEBP RetAddr  Args to Child              
02fdf4b0 77bf8e44 00000dcc 00000000 00000000 ntdll!NtWaitForSingleObject+0x15 (FPO: [3,0,0])
02fdf514 77bf8d28 00000000 00000000 00713298 ntdll!RtlpWaitOnCriticalSection+0x13e (FPO: [Non-Fpo])
02fdf53c 01253666 00720b68 00000000 00713df0 ntdll!RtlEnterCriticalSection+0x150 (FPO: [Non-Fpo])
02fdf598 0125232e 00000000 00713df0 00713298 MatchSvr!CJMutex::Lock+0x26
02fdf5f0 01250d6a 00720b68 feb63229 00000000 MatchSvr!CJAutoLock::CJAutoLock+0x1e
02fdf70c 01250870 0071ecf4 0071ecdc 061b729c MatchSvr!CRabbitMQ::_publish_str_+0x5a
02fdf770 01250100 0071ecf4 0071ecdc 061b729c MatchSvr!CRabbitMQ::sendmsg+0x20
02fdf7d4 01218d88 0071ecf4 0071ecdc 061b729c MatchSvr!CRabbitmqProc::sendmsg+0x20
02fdf838 01214ccd 061b729c feb63ded 00000000 MatchSvr!CProducerMQ::RabbitMQPublish_Award+0x28 (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\producermq.cpp @ 72]
02fdf8c8 012172b9 00000000 00713df0 00713298 MatchSvr!CDelaySendMsg::Thread+0x11d (FPO: [Non-Fpo]) (CONV: thiscall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\delaysendmsg.cpp @ 46]
02fdf924 70ffc01d 007124a0 0c54d31f 00000000 MatchSvr!JThread::TheThread+0x39 (FPO: [Non-Fpo]) (CONV: stdcall) [d:\program files (x86)\jenkins\workspace\publish_gamechannel\matchsvr\jthread.cpp @ 175]
02fdf95c 70ffc001 00000000 02fdf974 7744338a msvcr120!_callthreadstartex+0x1b (FPO: [Non-Fpo]) (CONV: cdecl) [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 376]
02fdf968 7744338a 00713298 02fdf9b4 77bf9f72 msvcr120!_threadstartex+0x7c (FPO: [Non-Fpo]) (CONV: stdcall) [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 354]
02fdf974 77bf9f72 00713298 87ff1315 00000000 kernel32!BaseThreadInitThunk+0xe (FPO: [Non-Fpo])
02fdf9b4 77bf9f45 70ffbfb4 00713298 ffffffff ntdll!__RtlUserThreadStart+0x70 (FPO: [Non-Fpo])
02fdf9cc 00000000 70ffbfb4 00713298 00000000 ntdll!_RtlUserThreadStart+0x1b (FPO: [Non-Fpo])

4号线程MQ正在publish一个消息，而这个消息中有一个临界区，这个临界区可能又正在被其他线程占用。 继续查看临界区

1
2
3
4
5
6
7
8
9
10
11
0:004> !cs 00720b68 
-----------------------------------------
Critical section   = 0x00720b68 (+0x720B68)
DebugInfo          = 0x0071e070
LOCKED
LockCount          = 0x3
WaiterWoken        = No
OwningThread       = 0x00001590
RecursionCount     = 0x2
LockSemaphore      = 0xDCC
SpinCount          = 0x00000000

这个临界区正在被0x00001590 线程占用，再看看这个线程号是多少
~~[0x00001590]

1
2
3
4
0:004> ~~[0x00001590]
  10  Id: 173c.1590 Suspend: 3 Teb: 7ef81000 Unfrozen
      Start: msvcr120!_threadstartex (70ffbfb4) 
      Priority: 0  Priority class: 32  Affinity: 3

？？？？ 怎么又回到10号线程了， 再仔细看看10s线程
之前我们看的时候觉的没问题，但这里肯定是有问题的，会不会’connect’ 阻塞了呢? 带着疑问查看了下消息堆积时段的日志，有MQ断开的日志。带着猜测自己重现现场试试看，在本地启动服务，然后重启mq服务，发现问题必现。
解决方法就是使用非阻塞式的connect函数，问题解决。

总结

这里介绍了几个windbg的常用命令，讲解了死锁的一般分析方法，对于这类问题更多的是观察、思考。希望能带给你帮助，如果觉的有用，请帮忙打赏下吧！后续还有一些有意思的dump来分享，比如内存泄漏、死锁+崩溃、踩内存、高cpu等。现在的dump素材没有以前的多了，不然我可以把很多案例都写出来，有些问题没有案例还是挺难讲的。