如何debug出unmanaged程序中的deadlock?

在多线程程序开发中，经常会不可预期的出现程序hang。本文介绍了通过windbg找出因为deadlock而造成程序的hang的过程。用于测试的源代码如下：

// deadlock.cpp : Defines the entry point for the console application.
//

#include "stdafx.h"
#include "windows.h"

CRITICAL_SECTION g_reader;
CRITICAL_SECTION g_writer;
int x=2;

DWORD WINAPI ThreadProc1(LPVOID lpparameter)
{
    
    EnterCriticalSection(&g_reader);
    printf("get reader of proc1\n");
    Sleep(1000);

    EnterCriticalSection(&g_writer);
    printf("get writer of proc1\n");
    
    x++;
    printf("this is thread 1,and the result is %d\n",x);

    LeaveCriticalSection(&g_reader);
    LeaveCriticalSection(&g_writer);
    return 0;
}



DWORD WINAPI ThreadProc2(LPVOID lpparameter)
{
    EnterCriticalSection(&g_writer);
    printf("get writer of proc2\n");
    Sleep(1000);

    EnterCriticalSection(&g_reader);
    printf("get reader of proc2\n");

    x++;
    printf("this is thread 2,and the result is %d\n",x);
    LeaveCriticalSection(&g_reader);
    LeaveCriticalSection(&g_writer);
    return 0;
    
}

int main(int argc, char* argv[])
{
    InitializeCriticalSection(&g_reader);
    InitializeCriticalSection(&g_writer);
    DWORD id;
    int i=0;
    while(i++<4)
    {
    CreateThread(NULL,NULL,ThreadProc1,NULL,NULL,&id);
    //Sleep(500);
    CreateThread(NULL,NULL,ThreadProc2,NULL,NULL,&id);
    }
    getchar();
    return 0;
}

程序运行后就会hang住不动了。

假设没有源码的情况下，如何知道程序为什么会hang呢？

首先我们抓取hang dump,键入如下adplus command:

cscript.exe -hang -pn deadlockdemo -o c:\deaklockdump -quiet

然后对获取后的dump进行分析，以下是debug过程：

  1 Opened log file 'c:\deadlockdump\debugprocess.log'
  2 0:000> .sympath + D:\study\deadlock\Debug
  3 Symbol search path is: + D:\study\deadlock\Debug
  4 WARNING: Inaccessible path: '+ D:\study\deadlock\Debug'
  5 0:000> .sympath+ D:\study\deadlock\Debug
  6 Symbol search path is: + D:\study\deadlock\Debug;D:\study\deadlock\Debug
  7 WARNING: Inaccessible path: '+ D:\study\deadlock\Debug'
  8 0:000> !runaway
  9  User Mode Time
 10   Thread       Time
 11    8:8eb8      0 days 0:00:00.000
 12    7:8eb4      0 days 0:00:00.000
 13    6:8eb0      0 days 0:00:00.000
 14    5:8eac      0 days 0:00:00.000
 15    4:8ea8      0 days 0:00:00.000
 16    3:8ea4      0 days 0:00:00.000
 17    2:8ea0      0 days 0:00:00.000
 18    1:8e9c      0 days 0:00:00.000
 19    0:8e98      0 days 0:00:00.000
 20 0:000> ~*
 21 .  0  Id: 8e94.8e98 Suspend: 1 Teb: 7ffdf000 Unfrozen
 22       Start: *** WARNING: Unable to verify checksum for deadlock.exe
 23 deadlock!mainCRTStartup (00401780) 
 24       Priority: 0  Priority class: 32  Affinity: 1
 25    1  Id: 8e94.8e9c Suspend: 1 Teb: 7ffde000 Unfrozen
 26       Start: deadlock!ILT+0(?ThreadProc1YGKPAXZ) (00401005) 
 27       Priority: 0  Priority class: 32  Affinity: 1
 28    2  Id: 8e94.8ea0 Suspend: 1 Teb: 7ffdd000 Unfrozen
 29       Start: deadlock!ILT+5(?ThreadProc2YGKPAXZ) (0040100a) 
 30       Priority: 0  Priority class: 32  Affinity: 1
 31    3  Id: 8e94.8ea4 Suspend: 1 Teb: 7ffdc000 Unfrozen
 32       Start: deadlock!ILT+0(?ThreadProc1YGKPAXZ) (00401005) 
 33       Priority: 0  Priority class: 32  Affinity: 1
 34    4  Id: 8e94.8ea8 Suspend: 1 Teb: 7ffdb000 Unfrozen
 35       Start: deadlock!ILT+5(?ThreadProc2YGKPAXZ) (0040100a) 
 36       Priority: 0  Priority class: 32  Affinity: 1
 37    5  Id: 8e94.8eac Suspend: 1 Teb: 7ffd9000 Unfrozen
 38       Start: deadlock!ILT+0(?ThreadProc1YGKPAXZ) (00401005) 
 39       Priority: 0  Priority class: 32  Affinity: 1
 40    6  Id: 8e94.8eb0 Suspend: 1 Teb: 7ffd8000 Unfrozen
 41       Start: deadlock!ILT+5(?ThreadProc2YGKPAXZ) (0040100a) 
 42       Priority: 0  Priority class: 32  Affinity: 1
 43    7  Id: 8e94.8eb4 Suspend: 1 Teb: 7ffd7000 Unfrozen
 44       Start: deadlock!ILT+0(?ThreadProc1YGKPAXZ) (00401005) 
 45       Priority: 0  Priority class: 32  Affinity: 1
 46    8  Id: 8e94.8eb8 Suspend: 1 Teb: 7ffd6000 Unfrozen
 47       Start: deadlock!ILT+5(?ThreadProc2YGKPAXZ) (0040100a) 
 48       Priority: 0  Priority class: 32  Affinity: 1
 49 0:000> ~*kb
 50 
 51 .  0  Id: 8e94.8e98 Suspend: 1 Teb: 7ffdf000 Unfrozen
 52 ChildEBP RetAddr  Args to Child              
 53 0012fcbc 7c82787b 7c82ec2a 00000024 0012fd1c ntdll!KiFastSystemCallRet
 54 0012fcc0 7c82ec2a 00000024 0012fd1c 0012fd1c ntdll!NtRequestWaitReplyPort+0xc
 55 *** ERROR: Symbol file could not be found.  Defaulted to export symbols for kernel32.dll - 
 56 0012fce0 77e4cf7c 00000000 00340688 0002021d ntdll!CsrClientCallServer+0x8c
 57 WARNING: Stack unwind information not available. Following frames may be wrong.
 58 0012fdd8 77eb27cc 00000003 00423fa0 00001000 kernel32!ReadConsoleW+0x19b
 59 0012fe60 77e418f0 00000003 00423fa0 00001000 kernel32!ReadConsoleA+0x3b
 60 0012feb8 0040362b 00000003 00423fa0 00001000 kernel32!ReadFile+0xa5
 61 0012fef4 00401520 00000000 00423fa0 00001000 deadlock!_read+0x13b [read.c @ 146]
 62 0012ff1c 0040130e 00422a38 00000000 00000000 deadlock!_filbuf+0xd0 [_filbuf.c @ 127]
 63 0012ff80 00401869 00000001 015d0e90 015d0dc0 deadlock!main+0xde [D:\study\deadlock\deadlock.cpp @ 60]
 64 0012ffc0 77e6f23b 00000000 00000000 7ffda000 deadlock!mainCRTStartup+0xe9 [crt0.c @ 206]
 65 0012fff0 00000000 00401780 00000000 78746341 kernel32!ProcessIdToSessionId+0x209
 66 
 67    1  Id: 8e94.8e9c Suspend: 1 Teb: 7ffde000 Unfrozen
 68 ChildEBP RetAddr  Args to Child              
 69 017cff00 7c827d0b 7c83d236 00000050 00000000 ntdll!KiFastSystemCallRet
 70 017cff04 7c83d236 00000050 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
 71 017cff40 7c83d281 00000050 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x1a3
 72 017cff60 0040108a 004235c8 00000000 00000000 ntdll!RtlEnterCriticalSection+0xa8
 73 017cffb8 77e64829 00000000 00000000 00000000 deadlock!ThreadProc1+0x5a [D:\study\deadlock\deadlock.cpp @ 18]
 74 WARNING: Stack unwind information not available. Following frames may be wrong.
 75 017cffec 00000000 00401005 00000000 00000000 kernel32!GetModuleHandleA+0xdf
 76 
 77    2  Id: 8e94.8ea0 Suspend: 1 Teb: 7ffdd000 Unfrozen
 78 ChildEBP RetAddr  Args to Child              
 79 018cff00 7c827d0b 7c83d236 0000004c 00000000 ntdll!KiFastSystemCallRet
 80 018cff04 7c83d236 0000004c 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
 81 018cff40 7c83d281 0000004c 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x1a3
 82 018cff60 0040118a 004235e0 00000000 00000000 ntdll!RtlEnterCriticalSection+0xa8
 83 018cffb8 77e64829 00000000 00000000 00000000 deadlock!ThreadProc2+0x5a [D:\study\deadlock\deadlock.cpp @ 37]
 84 WARNING: Stack unwind information not available. Following frames may be wrong.
 85 018cffec 00000000 0040100a 00000000 00000000 kernel32!GetModuleHandleA+0xdf
 86 
 87    3  Id: 8e94.8ea4 Suspend: 1 Teb: 7ffdc000 Unfrozen
 88 ChildEBP RetAddr  Args to Child              
 89 019cff00 7c827d0b 7c83d236 0000004c 00000000 ntdll!KiFastSystemCallRet
 90 019cff04 7c83d236 0000004c 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
 91 019cff40 7c83d281 0000004c 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x1a3
 92 019cff60 00401055 004235e0 00000000 00000000 ntdll!RtlEnterCriticalSection+0xa8
 93 019cffb8 77e64829 00000000 00000000 00000000 deadlock!ThreadProc1+0x25 [D:\study\deadlock\deadlock.cpp @ 14]
 94 WARNING: Stack unwind information not available. Following frames may be wrong.
 95 019cffec 00000000 00401005 00000000 00000000 kernel32!GetModuleHandleA+0xdf
 96 
 97    4  Id: 8e94.8ea8 Suspend: 1 Teb: 7ffdb000 Unfrozen
 98 ChildEBP RetAddr  Args to Child              
 99 01acff00 7c827d0b 7c83d236 00000050 00000000 ntdll!KiFastSystemCallRet
100 01acff04 7c83d236 00000050 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
101 01acff40 7c83d281 00000050 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x1a3
102 01acff60 00401155 004235c8 00000000 00000000 ntdll!RtlEnterCriticalSection+0xa8
103 01acffb8 77e64829 00000000 00000000 00000000 deadlock!ThreadProc2+0x25 [D:\study\deadlock\deadlock.cpp @ 33]
104 WARNING: Stack unwind information not available. Following frames may be wrong.
105 01acffec 00000000 0040100a 00000000 00000000 kernel32!GetModuleHandleA+0xdf
106 
107    5  Id: 8e94.8eac Suspend: 1 Teb: 7ffd9000 Unfrozen
108 ChildEBP RetAddr  Args to Child              
109 01bcff00 7c827d0b 7c83d236 0000004c 00000000 ntdll!KiFastSystemCallRet
110 01bcff04 7c83d236 0000004c 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
111 01bcff40 7c83d281 0000004c 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x1a3
112 01bcff60 00401055 004235e0 00000000 00000000 ntdll!RtlEnterCriticalSection+0xa8
113 01bcffb8 77e64829 00000000 00000000 00000000 deadlock!ThreadProc1+0x25 [D:\study\deadlock\deadlock.cpp @ 14]
114 WARNING: Stack unwind information not available. Following frames may be wrong.
115 01bcffec 00000000 00401005 00000000 00000000 kernel32!GetModuleHandleA+0xdf
116 
117    6  Id: 8e94.8eb0 Suspend: 1 Teb: 7ffd8000 Unfrozen
118 ChildEBP RetAddr  Args to Child              
119 01ccff00 7c827d0b 7c83d236 00000050 00000000 ntdll!KiFastSystemCallRet
120 01ccff04 7c83d236 00000050 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
121 01ccff40 7c83d281 00000050 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x1a3
122 01ccff60 00401155 004235c8 00000000 00000000 ntdll!RtlEnterCriticalSection+0xa8
123 01ccffb8 77e64829 00000000 00000000 00000000 deadlock!ThreadProc2+0x25 [D:\study\deadlock\deadlock.cpp @ 33]
124 WARNING: Stack unwind information not available. Following frames may be wrong.
125 01ccffec 00000000 0040100a 00000000 00000000 kernel32!GetModuleHandleA+0xdf
126 
127    7  Id: 8e94.8eb4 Suspend: 1 Teb: 7ffd7000 Unfrozen
128 ChildEBP RetAddr  Args to Child              
129 01dcff00 7c827d0b 7c83d236 0000004c 00000000 ntdll!KiFastSystemCallRet
130 01dcff04 7c83d236 0000004c 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
131 01dcff40 7c83d281 0000004c 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x1a3
132 01dcff60 00401055 004235e0 00000000 00000000 ntdll!RtlEnterCriticalSection+0xa8
133 01dcffb8 77e64829 00000000 00000000 00000000 deadlock!ThreadProc1+0x25 [D:\study\deadlock\deadlock.cpp @ 14]
134 WARNING: Stack unwind information not available. Following frames may be wrong.
135 01dcffec 00000000 00401005 00000000 00000000 kernel32!GetModuleHandleA+0xdf
136 
137    8  Id: 8e94.8eb8 Suspend: 1 Teb: 7ffd6000 Unfrozen
138 ChildEBP RetAddr  Args to Child              
139 01ecff00 7c827d0b 7c83d236 00000050 00000000 ntdll!KiFastSystemCallRet
140 01ecff04 7c83d236 00000050 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
141 01ecff40 7c83d281 00000050 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x1a3
142 01ecff60 00401155 004235c8 00000000 00000000 ntdll!RtlEnterCriticalSection+0xa8
143 01ecffb8 77e64829 00000000 00000000 00000000 deadlock!ThreadProc2+0x25 [D:\study\deadlock\deadlock.cpp @ 33]
144 WARNING: Stack unwind information not available. Following frames may be wrong.
145 01ecffec 00000000 0040100a 00000000 00000000 kernel32!GetModuleHandleA+0xdf
146 0:000> !cs 004235c8 /*找出该criticalSection的相关信息*/
147 -----------------------------------------
148 Critical section   = 0x004235c8 (deadlock!g_writer+0x0)
149 DebugInfo          = 0x7c887f40
150 LOCKED
151 LockCount          = 0x4
152 WaiterWoken        = No
153 OwningThread       = 0x00008ea0
154 RecursionCount     = 0x1
155 LockSemaphore      = 0x50
156 SpinCount          = 0x00000000
157 0:000> ~~[0x00008ea0]//找出thread ID相对应的thread详细信息，主要是thread No,如下面是 2
158    2  Id: 8e94.8ea0 Suspend: 1 Teb: 7ffdd000 Unfrozen
159       Start: deadlock!ILT+5(?ThreadProc2YGKPAXZ) (0040100a) 
160       Priority: 0  Priority class: 32  Affinity: 1
161 0:000> !cs 004235e0 
162 -----------------------------------------
163 Critical section   = 0x004235e0 (deadlock!g_reader+0x0)
164 DebugInfo          = 0x7c887f20
165 LOCKED
166 LockCount          = 0x4
167 WaiterWoken        = No
168 OwningThread       = 0x00008e9c
169 RecursionCount     = 0x1
170 LockSemaphore      = 0x4C
171 SpinCount          = 0x00000000
172 0:000> ~~[0x00008e9c]
173    1  Id: 8e94.8e9c Suspend: 1 Teb: 7ffde000 Unfrozen
174       Start: deadlock!ILT+0(?ThreadProc1YGKPAXZ) (00401005) 
175       Priority: 0  Priority class: 32  Affinity: 1
176 0:000> !cs 004235e0 
177 -----------------------------------------
178 Critical section   = 0x004235e0 (deadlock!g_reader+0x0)
179 DebugInfo          = 0x7c887f20
180 LOCKED
181 LockCount          = 0x4
182 WaiterWoken        = No
183 OwningThread       = 0x00008e9c
184 RecursionCount     = 0x1
185 LockSemaphore      = 0x4C
186 SpinCount          = 0x00000000
187 0:000> ~~[0x00008e9c]
188    1  Id: 8e94.8e9c Suspend: 1 Teb: 7ffde000 Unfrozen
189       Start: deadlock!ILT+0(?ThreadProc1YGKPAXZ) (00401005) 
190       Priority: 0  Priority class: 32  Affinity: 1
191 0:000> !cs 004235c8 
192 -----------------------------------------
193 Critical section   = 0x004235c8 (deadlock!g_writer+0x0)
194 DebugInfo          = 0x7c887f40
195 LOCKED
196 LockCount          = 0x4
197 WaiterWoken        = No
198 OwningThread       = 0x00008ea0
199 RecursionCount     = 0x1
200 LockSemaphore      = 0x50
201 SpinCount          = 0x00000000
202 0:000> ~~[0x00008ea0]
203    2  Id: 8e94.8ea0 Suspend: 1 Teb: 7ffdd000 Unfrozen
204       Start: deadlock!ILT+5(?ThreadProc2YGKPAXZ) (0040100a) 
205       Priority: 0  Priority class: 32  Affinity: 1
206 0:000> .logclose
207 Closing open log file c:\deadlockdump\debugprocess.log
208 

通过以上分析，可以看出thread 1请求g_write,但是g_writer分配给thread2.同时，thread2请求g_reader,而g_reader分配给thread1,从而造成了死锁。而其他的thread,包括thread3,thread4,thread5,thread6,thread7,thread8都在请求g_writer或者g_reader而进入到等待状态。

以上就是在unmanaged code下寻找deadlock的过程。

 

posted on 2008-11-18 15:24  飞天舞者  阅读(1153)  评论(0)  编辑  收藏  举报

导航

For more information about me, feel free email to me winston.he@hotmail.com