Dump Analysis - Debugging a Multi-Process Hang
This article walks through the analysis of an application hang caused by a chain of RPC calls. The first part of the article discusses the manually generated application memory dump (user mode dump) and the second part focuses on the manually generated kernel mode dump (complete memory dump).
Please note that some of the debugger output shown in this article has been truncated for readability.
Application Dump Analysis
The user observed sporadic hangs in a particular application and was instructed by technical support engineers to capture an application memory dump using the SysInternals tool procdump with the command line "procdump -ma HungApplication.exe".
Upon loading up the application dump in WinDBG, it displays the following output:
Microsoft (R) Windows Debugger Version 6.12.0002.633 X86
Copyright (c) Microsoft Corporation. All rights reserved.
Loading Dump File [Application.dmp]
User Mini Dump File with Full Memory: Only application data is available
Symbol search path is: SRV*c:\symsrv*http://msdl.microsoft.com/download/symbols
Executable search path is:
Windows XP Version 2600 (Service Pack 3) UP Free x86 compatible
Product: WinNt, suite: SingleUserTS
Machine Name:
Debug session time: Mon Dec 7 18:28:30.000 2009 (UTC - 7:00)
System Uptime: 0 days 0:05:22.718
Process Uptime: 0 days 0:00:21.000
.......................................
eax=0c98fac6 ebx=00171a08 ecx=0012fd88 edx=00172078 esi=00171a54 edi=001665c8
eip=7c90e514 esp=0012f61c ebp=0012f668 iopl=0 nv up ei pl nz na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000206
ntdll!KiFastSystemCallRet:
7c90e514 c3 ret
It is important to note that the application was running on a Windows XP SP3 system.
Run the debugger's automated crash/hang analyzer.
"!analyze -v" is always a good starting point for both user mode and kernel mode memory dumps.
0:000> !analyze -v
*******************************************************************************
* *
* Exception Analysis *
* *
*******************************************************************************
EXCEPTION_RECORD: ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 00000000
ExceptionCode: 80000003 (Break instruction exception)
ExceptionFlags: 00000000
NumberParameters: 0
FAULTING_THREAD: 000000c8
DEFAULT_BUCKET_ID: STATUS_BREAKPOINT
PROCESS_NAME: HungApplication.exe
ERROR_CODE: (NTSTATUS) 0x80000003 - {EXCEPTION} Breakpoint A breakpoint has been reached.
EXCEPTION_CODE: (HRESULT) 0x80000003 (2147483651) - One or more arguments are invalid
MOD_LIST: <ANALYSIS/>
NTGLOBALFLAG: 83040
APPLICATION_VERIFIER_FLAGS: 0
LAST_CONTROL_TRANSFER: from 7c90daea to 7c90e514
PRIMARY_PROBLEM_CLASS: STATUS_BREAKPOINT
BUGCHECK_STR: APPLICATION_FAULT_STATUS_BREAKPOINT
STACK_TEXT:
0012f618 7c90daea 77e7cac1 00000678 001633b8 ntdll!KiFastSystemCallRet
0012f61c 77e7cac1 00000678 001633b8 001633b8 ntdll!ZwRequestWaitReplyPort+0xc
0012f668 77e7a33e 001633f0 0012f690 776016bb rpcrt4!LRPC_CCALL::SendReceive+0x228
0012f674 776016bb 001665c8 00172488 0012f774 rpcrt4!I_RpcSendReceive+0x24
0012f690 776011a6 00000000 00000000 00000000 ole32!ThreadSendReceive+0xf5
0012f6ac 7760108a 0012f774 0012f884 00172488 ole32!CRpcChannelBuffer::SwitchAptAndDispatchCall+0x13d
0012f78c 7752ce1a 00172488 0012f884 0012f874 ole32!CRpcChannelBuffer::SendReceive2+0xc8
0012f7f8 7752cdb2 00172488 0012f884 0012f874 ole32!CAptRpcChnl::SendReceive+0xab
0012f84c 77ef4db5 00172488 0012f884 0012f874 ole32!CCtxComChnl::SendReceive+0x113
0012f868 77ef4ead 0017237c 0012f8b0 0600015b rpcrt4!NdrProxySendReceive+0x43
0012fc44 77ef4e42 76402940 7640362e 0012fc7c rpcrt4!NdrClientCall2+0x1fa
0012fc64 77e8a83b 00000008 00000004 0012fe78 rpcrt4!ObjectStublessClient+0x8b
0012fc74 004118ce 0017237c 8d7c5687 0012ff68 rpcrt4!ObjectStubless+0xf
WARNING: Stack unwind information not available. Following frames may be wrong.
0012fe78 00411d93 00000000 00000044 00000038 HungApplication+0x118ce
0012ff68 00412418 00000002 00385978 00383078 HungApplication+0x11d93
0012ffb8 0041225f 0012fff0 7c817077 00000044 HungApplication+0x12418
0012ffc0 7c817077 00000044 00000038 7ffdd000 HungApplication+0x1225f
0012fff0 00000000 00411136 00000000 78746341 kernel32!BaseProcessStart+0x23
FOLLOWUP_IP:
HungApplication+118ce
004118ce 3bf4 cmp esi,esp
SYMBOL_STACK_INDEX: d
SYMBOL_NAME: HungApplication+118ce
FOLLOWUP_NAME: MachineOwner
MODULE_NAME: HungApplication
IMAGE_NAME: HungApplication.exe
DEBUG_FLR_IMAGE_TIMESTAMP: 4b1d742f
STACK_COMMAND: .cxr 00000000 ; kb ; ~0s; .ecxr ; kb
FAILURE_BUCKET_ID: STATUS_BREAKPOINT_80000003_HungApplication.exe!Unknown
BUCKET_ID: APPLICATION_FAULT_STATUS_BREAKPOINT_HungApplication+118ce
Followup: MachineOwner
---------
If the exception code is either 0x80000007 or 0x80000003, it is an indication of a manually generated application dump as opposed to an application crash dump.
Find the number of threads in this process
0:000> ~ . 0 Id: d0.c8 Suspend: 1 Teb: 7ffdf000 Unfrozen 1 Id: d0.560 Suspend: 1 Teb: 7ffde000 Unfrozen 2 Id: d0.590 Suspend: 1 Teb: 7ffdc000 Unfrozen 3 Id: d0.5a4 Suspend: 1 Teb: 7ffdb000 Unfrozen
There are very few threads so it will be beneficial to obtain the call stacks of all the threads in this process.
Obtain the call stacks of these threads and find threads that may be potentially stuck.
0:000> ~*kn . 0 Id: d0.c8 Suspend: 1 Teb: 7ffdf000 Unfrozen # ChildEBP RetAddr 00 0012f618 7c90daea ntdll!KiFastSystemCallRet 01 0012f61c 77e7cac1 ntdll!ZwRequestWaitReplyPort+0xc 02 0012f668 77e7a33e rpcrt4!LRPC_CCALL::SendReceive+0x228 03 0012f674 776016bb rpcrt4!I_RpcSendReceive+0x24 04 0012f690 776011a6 ole32!ThreadSendReceive+0xf5 05 0012f6ac 7760108a ole32!CRpcChannelBuffer::SwitchAptAndDispatchCall+0x13d 06 0012f78c 7752ce1a ole32!CRpcChannelBuffer::SendReceive2+0xc8 07 0012f7f8 7752cdb2 ole32!CAptRpcChnl::SendReceive+0xab 08 0012f84c 77ef4db5 ole32!CCtxComChnl::SendReceive+0x113 09 0012f868 77ef4ead rpcrt4!NdrProxySendReceive+0x43 0a 0012fc44 77ef4e42 rpcrt4!NdrClientCall2+0x1fa 0b 0012fc64 77e8a83b rpcrt4!ObjectStublessClient+0x8b 0c 0012fc74 004118ce rpcrt4!ObjectStubless+0xf WARNING: Stack unwind information not available. Following frames may be wrong. 0d 0012fe78 00411d93 HungApplication+0x118ce 0e 0012ff68 00412418 HungApplication+0x11d93 0f 0012ffb8 0041225f HungApplication+0x12418 10 0012ffc0 7c817077 HungApplication+0x1225f 11 0012fff0 00000000 kernel32!BaseProcessStart+0x23 1 Id: d0.560 Suspend: 1 Teb: 7ffde000 Unfrozen # ChildEBP RetAddr 00 01ccfe14 7c90daaa ntdll!KiFastSystemCallRet 01 01ccfe18 77e765e3 ntdll!NtReplyWaitReceivePortEx+0xc 02 01ccff80 77e76caf rpcrt4!LRPC_ADDRESS::ReceiveLotsaCalls+0x12a 03 01ccff88 77e76ad1 rpcrt4!RecvLotsaCallsWrapper+0xd 04 01ccffa8 77e76c97 rpcrt4!BaseCachedThreadRoutine+0x79 05 01ccffb4 7c80b729 rpcrt4!ThreadStartRoutine+0x1a 06 01ccffec 00000000 kernel32!BaseThreadStart+0x37 2 Id: d0.590 Suspend: 1 Teb: 7ffdc000 Unfrozen # ChildEBP RetAddr 00 01dcff1c 7c90d21a ntdll!KiFastSystemCallRet 01 01dcff20 7c8023f1 ntdll!NtDelayExecution+0xc 02 01dcff78 7c802455 kernel32!SleepEx+0x61 03 01dcff88 774fe32f kernel32!Sleep+0xf 04 01dcff94 774fe3ee ole32!CROIDTable::WorkerThreadLoop+0x14 05 01dcffa8 774fe456 ole32!CRpcThread::WorkerLoop+0x1e 06 01dcffb4 7c80b729 ole32!CRpcThreadCache::RpcWorkerThreadEntry+0x1b 07 01dcffec 00000000 kernel32!BaseThreadStart+0x37 3 Id: d0.5a4 Suspend: 1 Teb: 7ffdb000 Unfrozen # ChildEBP RetAddr 00 0240fea4 7c90df4a ntdll!KiFastSystemCallRet 01 0240fea8 7c809590 ntdll!ZwWaitForMultipleObjects+0xc 02 0240ff44 77df8631 kernel32!WaitForMultipleObjectsEx+0x12c 03 0240ffb4 7c80b729 advapi32!HungApplicationpEventPump+0x230 04 0240ffec 00000000 kernel32!BaseThreadStart+0x37
The thread with TID 0xc8 is an RPC client thread as identified by the presence of the function rpcrt4!NdrClientCall2(). Please make a note of the thread ID, this will be needed later.
All the other threads in this process are in "benign" wait states. Threads can be classified as being in "benign" wait states by observing their call stacks and matching them to stack patterns of threads in other processes that are known to be in a good (non-deadlocked) state.
Remote Procedure Call (RPC) mechanism uses a kernel provided transport to perform the inter-process communication (IPC) between multiple processes. In this particular case the transport is LPC (Local Inter-process Communication) mechanism as can be observed by the presence of the function ntdll!ZwRequestWaitReplyPort().
The presence of the call to ntdll!ZwRequestWaitReplyPort() indicates that caller has sent a request to a LPC server and is waiting for the server to respond. In order to analyze this further one needs to find out which process and thread is responsible for replying to this LPC message.
Since LPC is implemented in the Windows kernel, to perform any further analysis involving this LPC call requires a kernel mode dump of this system. The next section describes the steps for analyzing a complete memory dump of this system. Note that in more recent version of Windows (i.e. Vista+) the LPC mechanism has been superseded by the Advanced Local Inter-process Communication (ALPC) mechanism.
All the other threads in the application dump have normal call stacks and hence they are ignored for this analysis.
Kernel Dump Analysis
Since the application dump analysis was inconclusive and the support engineer was unable to attribute the hang to a particular component, the engineer requested the user to generate a complete memory dump of the entire system to be able to debug at the kernel level. This required the system to be configured to generate a complete memory dump via command line "wmic recoveros set DebugInfoType = 1". It also required the system to be configured to crash when the user pressed the keyboard combination Right-Ctrl + Scroll-Lock + Scroll-Lock as described in Microsoft Knowledge Base Article KB244139. Fortunately the system on which the HungApplication.exe was running was already configured for both these options from a past technical support incident. So the user was able to bug-check the system manually, reboot the system and obtain the complete kernel dump from c:\Windows\Memory.dmp.
Upon loading the dump in WinDBG, it displays the following output:
Microsoft (R) Windows Debugger Version 6.12.0002.633 AMD64
Copyright (c) Microsoft Corporation. All rights reserved.
Loading Dump File [Kernel.DMP]
Kernel Complete Dump File: Full address space is available
Symbol search path is: SRV*c:\symsrv*http://msdl.microsoft.com/download/symbols
Executable search path is:
Windows XP Kernel Version 2600 (Service Pack 3) UP Free x86 compatible
Product: WinNt, suite: TerminalServer SingleUserTS
Built by: 2600.xpsp_sp3_gdr.090804-1435
Machine Name:
Kernel base = 0x804d7000 PsLoadedModuleList = 0x80554040
Debug session time: Mon Dec 7 18:29:04.279 2009 (UTC - 7:00)
System Uptime: 0 days 0:05:52.781
Loading Kernel Symbols
...............................................................
............................................................
Loading User Symbols
Loading unloaded module list
........
*** ERROR: Module load completed but symbols could not be loaded for BANG.SYS
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************
Use !analyze -v to get detailed debugging information.
BugCheck E2, {0, 0, 0, 0}
Probably caused by : i8042prt.sys ( i8042prt!I8xProcessCrashDump+235 )
Followup: MachineOwner
---------
Run the debuggers automated crash/hang analyzer.
kd> !analyze -v
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************
MANUALLY_INITIATED_CRASH (e2)
The user manually initiated this crash dump.
Arguments:
Arg1: 00000000
Arg2: 00000000
Arg3: 00000000
Arg4: 00000000
Debugging Details:
------------------
.
.
.
The output of "!analyze -v" shows that this is a manually generated dump. To start the analysis obtain the call stack of the thread that was identified in the user mode dump analysis i.e. thread (TID=0xc8).
Obtain details about the thread in the process HungApplication.exe that is stuck on the RPC call.
kd> !thread -t c8 1e Cid handle table at e1005000 with 364 entries in use THREAD 8559f960 Cid 00d0.00c8 Teb: 7ffdf000 Win32Thread: e10ac2e0 WAIT: (WrLpcReply) UserMode Non-Alertable 8559fb54 Semaphore Limit 0x1 Waiting for reply to LPC MessageId 0000235a: Current LPC port e1d8d850 Not impersonating DeviceMap e1ba4fa0 Owning Process 0 Image: <Unknown> Attached Process 85c45020 Image: HungApplication.exe Wait Start TickCount 21057 Ticks: 1521 (0:00:00:23.765) Context Switch Count 189 LargeStack UserTime 00:00:00.000 KernelTime 00:00:00.078 *** WARNING: Unable to verify checksum for HungApplication.exe *** ERROR: Module load completed but symbols could not be loaded for HungApplication.exe Win32 Start Address HungApplication (0x00411136) Start Address kernel32!BaseProcessStartThunk (0x7c810705) Stack Init f4be2000 Current f4be1c50 Base f4be2000 Limit f4bde000 Call 0 Priority 11 BasePriority 8 PriorityDecrement 2 DecrementCount 16 ChildEBP RetAddr f4be1c68 80500ce6 nt!KiSwapContext+0x2e (FPO: [Uses EBP] [0,0,4]) f4be1c74 804f9d72 nt!KiSwapThread+0x46 (FPO: [0,0,0]) f4be1c9c 8059874b nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo]) f4be1d50 8053d648 nt!NtRequestWaitReplyPort+0x63d (FPO: [Non-Fpo]) f4be1d50 7c90e514 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f4be1d64) 0012f618 7c90daea ntdll!KiFastSystemCallRet (FPO: [0,0,0]) 0012f61c 77e7cac1 ntdll!ZwRequestWaitReplyPort+0xc (FPO: [3,0,0]) 0012f668 77e7a33e RPCRT4!LRPC_CCALL::SendReceive+0x228 (FPO: [Non-Fpo]) 0012f674 776016bb RPCRT4!I_RpcSendReceive+0x24 (FPO: [Non-Fpo]) 0012f690 776011a6 ole32!ThreadSendReceive+0xf5 (FPO: [Non-Fpo]) 0012f6ac 7760108a ole32!CRpcChannelBuffer::SwitchAptAndDispatchCall+0x13d (FPO: [Non-Fpo]) 0012f78c 7752ce1a ole32!CRpcChannelBuffer::SendReceive2+0xc8 (FPO: [Non-Fpo]) 0012f7f8 7752cdb2 ole32!CAptRpcChnl::SendReceive+0xab (FPO: [Non-Fpo]) 0012f84c 77ef4db5 ole32!CCtxComChnl::SendReceive+0x113 (FPO: [Non-Fpo]) 0012f868 77ef4ead RPCRT4!NdrProxySendReceive+0x43 (FPO: [Non-Fpo]) 0012fc44 77ef4e42 RPCRT4!NdrClientCall2+0x1fa (FPO: [Non-Fpo]) 0012fc64 77e8a83b RPCRT4!ObjectStublessClient+0x8b (FPO: [Non-Fpo]) 0012fc74 004118ce RPCRT4!ObjectStubless+0xf WARNING: Stack unwind information not available. Following frames may be wrong. 0012fe78 00411d93 HungApplication+0x118ce 0012ff68 00412418 HungApplication+0x11d93 0012ffb8 0041225f HungApplication+0x12418 0012ffc0 7c817077 HungApplication+0x1225f 0012fff0 00000000 kernel32!BaseProcessStart+0x23 (FPO: [Non-Fpo])
The above output indicates that the thread (TID=c8) is blocked on the receiving response on the LPC message ID 0000235a.
Obtain the RPC server thread that is processing this LPC Message (ID=235a).
kd> !lpc message 235a
Searching message 235a in threads ...
Server thread 85c13580 is working on message 235a
Client thread 8559f960 waiting a reply from 235a
Searching thread 8559f960 in port rundown queues ...
Server communication port 0xe10e19d0
Handles: 1 References: 1
The LpcDataInfoChainHead queue is empty
Connected port: 0xe1d8d850 Server connection port: 0xe1ee2458
Client communication port 0xe1d8d850
Handles: 1 References: 2
The LpcDataInfoChainHead queue is empty
Server connection port e1ee2458 Name: OLEF0AB761E2CF64712827449BB42C7
Handles: 1 References: 19
Server process : 854c0da0 (svchost.exe)
Queue semaphore : 856327c8
Semaphore state 0 (0x0)
The message queue is empty
The LpcDataInfoChainHead queue is empty
Done.
The above output indicates that server thread 85c13580 is working on message 235a.
Please note that in Windows Vista later versions of Windows threads making RPC calls would use ALPC instead of LPC.The debugger command to display details of an ALPC message is !alpc /m <MessageAddress>.
Obtain the call stack of the above thread and find out what it is doing
kd> !thread 85c13580 1e THREAD 85c13580 Cid 03bc.0644 Teb: 7ffa7000 Win32Thread: e1f7b268 WAIT: (WrLpcReply) UserMode Non-Alertable 85c13774 Semaphore Limit 0x1 Waiting for reply to LPC MessageId 00002384: Current LPC port e1b62f68 IRP List: 8560f748: (0006,0190) Flags: 00000000 Mdl: 00000000 Not impersonating DeviceMap e1006440 Owning Process 0 Image: <Unknown> Attached Process 854c0da0 Image: svchost.exe Wait Start TickCount 19303 Ticks: 3275 (0:00:00:51.171) Context Switch Count 1336 LargeStack UserTime 00:00:02.031 KernelTime 00:00:00.515 Win32 Start Address 0x0000235a LPC Server thread working on message Id 235a Start Address kernel32!BaseThreadStartThunk (0x7c8106f9) Stack Init f4db2000 Current f4db1c50 Base f4db2000 Limit f4dae000 Call 0 Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 16 Kernel stack not resident. ChildEBP RetAddr f4db1c68 80500ce6 nt!KiSwapContext+0x2e (FPO: [Uses EBP] [0,0,4]) f4db1c74 804f9d72 nt!KiSwapThread+0x46 (FPO: [0,0,0]) f4db1c9c 8059874b nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo]) f4db1d50 8053d648 nt!NtRequestWaitReplyPort+0x63d (FPO: [Non-Fpo]) f4db1d50 7c90e514 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f4db1d64) 027ce078 7c90daea ntdll!KiFastSystemCallRet (FPO: [0,0,0]) 027ce07c 77e7cac1 ntdll!ZwRequestWaitReplyPort+0xc (FPO: [3,0,0]) 027ce0c8 77e7a33e RPCRT4!LRPC_CCALL::SendReceive+0x228 (FPO: [Non-Fpo]) 027ce0d4 77e7a36f RPCRT4!I_RpcSendReceive+0x24 (FPO: [Non-Fpo]) 027ce0e8 77ef4675 RPCRT4!NdrSendReceive+0x2b (FPO: [Non-Fpo]) 027ce4c4 779993a7 RPCRT4!NdrClientCall2+0x222 (FPO: [Non-Fpo]) 027ce4d8 77998b3d SETUPAPI!PNP_HwProfFlags+0x1b (FPO: [Non-Fpo]) 027ce870 779522cd SETUPAPI!CM_Set_HW_Prof_Flags_ExW+0x158 (FPO: [Non-Fpo]) 027cef48 77948de2 SETUPAPI!SetupDiChangeState+0x698 (FPO: [Non-Fpo]) 027cf2c4 7794997e SETUPAPI!_SetupDiCallClassInstaller+0x934 (FPO: [Non-Fpo]) 027cf2dc 77d2841c SETUPAPI!SetupDiCallClassInstaller+0x15 (FPO: [Non-Fpo]) 027cf2f4 77d285f2 netman!HrSetupDiCallClassInstaller+0x17 (FPO: [Non-Fpo]) 027cf558 77d20249 netman!HrSetupDiSendPropertyChangeNotification+0xa6 (FPO: [Non-Fpo]) 027cf584 77d202f7 netman!CLanConnection::HrConnectOrDisconnect+0x54 (FPO: [Non-Fpo]) 027cf590 77e799f4 netman!CLanConnection::Disconnect+0xf (FPO: [Non-Fpo]) 027cf5a8 77ef421a RPCRT4!Invoke+0x30 027cf9a8 77ef4bf3 RPCRT4!NdrStubCall2+0x297 (FPO: [Non-Fpo]) 027cfa00 77600c15 RPCRT4!CStdStubBuffer_Invoke+0xc6 (FPO: [Non-Fpo]) 027cfa40 77600bbf ole32!SyncStubInvoke+0x33 (FPO: [Non-Fpo]) 027cfa88 7752ad31 ole32!StubInvoke+0xa7 (FPO: [Non-Fpo]) 027cfb60 7752ac56 ole32!CCtxComChnl::ContextInvoke+0xe3 (FPO: [Non-Fpo]) 027cfb7c 776007f5 ole32!MTAInvoke+0x1a (FPO: [Non-Fpo]) 027cfbac 77602df3 ole32!AppInvoke+0x9c (FPO: [Non-Fpo]) 027cfc80 77600715 ole32!ComInvokeWithLockAndIPID+0x2c2 (FPO: [Non-Fpo]) 027cfccc 77e794bd ole32!ThreadInvoke+0x1cd (FPO: [Non-Fpo]) 027cfd00 77e79422 RPCRT4!DispatchToStubInC+0x38 (FPO: [Non-Fpo]) 027cfd54 77e7934e RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0x113 (FPO: [Non-Fpo]) 027cfd78 77e8a384 RPCRT4!RPC_INTERFACE::DispatchToStub+0x84 (FPO: [Non-Fpo]) 027cfdb8 77e8a3c5 RPCRT4!RPC_INTERFACE::DispatchToStubWithObject+0xc0 (FPO: [Non-Fpo]) 027cfdf8 77e7bcc1 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0x2cd (FPO: [Non-Fpo]) 027cfe1c 77e7bc05 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0x16d (FPO: [Non-Fpo]) 027cff80 77e76caf RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0x310 (FPO: [Non-Fpo]) 027cff88 77e76ad1 RPCRT4!RecvLotsaCallsWrapper+0xd (FPO: [Non-Fpo]) 027cffa8 77e76c97 RPCRT4!BaseCachedThreadRoutine+0x79 (FPO: [Non-Fpo]) 027cffb4 7c80b729 RPCRT4!ThreadStartRoutine+0x1a (FPO: [Non-Fpo])
The above output indicates that the thread (TID=644) is blocked on the receiving response on the LPC message ID 2384.
Obtain the RPC server thread that is processing this LPC Message (ID=2384).
kd> !lpc message 00002384
Searching message 2384 in threads ...
Server thread 855cbc18 is working on message 2384
Client thread 85c13580 waiting a reply from 2384
Searching thread 85c13580 in port rundown queues ...
Server communication port 0xe1b1d1b8
Handles: 1 References: 1
The LpcDataInfoChainHead queue is empty
Connected port: 0xe1b62f68 Server connection port: 0xe1aed350
Client communication port 0xe1b62f68
Handles: 1 References: 2
The LpcDataInfoChainHead queue is empty
Server connection port e1aed350 Name: ntsvcs
Handles: 1 References: 52
Server process : 855ff020 (services.exe)
Queue semaphore : 857d7750
Semaphore state 0 (0x0)
The message queue is empty
The LpcDataInfoChainHead queue is empty
Done.
The above output indicates that server thread 855cbc18 is working on LPC message ID=2384.
Obtain the call stack of the above thread and find out what it is doing
kd> !thread 855cbc18 1e THREAD 855cbc18 Cid 0280.0628 Teb: 7ffab000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable f4de5cd4 NotificationEvent Not impersonating DeviceMap e1006440 Owning Process 0 Image: <Unknown> Attached Process 855ff020 Image: services.exe Wait Start TickCount 19302 Ticks: 3276 (0:00:00:51.187) Context Switch Count 1476 UserTime 00:00:00.031 KernelTime 00:00:00.187 Win32 Start Address 0x00002384 LPC Server thread working on message Id 2384 Start Address kernel32!BaseThreadStartThunk (0x7c8106f9) Stack Init f4de6000 Current f4de5c64 Base f4de6000 Limit f4de3000 Call 0 Priority 9 BasePriority 9 PriorityDecrement 0 DecrementCount 16 ChildEBP RetAddr f4de5c7c 80500ce6 nt!KiSwapContext+0x2e (FPO: [Uses EBP] [0,0,4]) f4de5c88 804f9d72 nt!KiSwapThread+0x46 (FPO: [0,0,0]) f4de5cb0 8063a893 nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo]) f4de5cf4 8063b048 nt!PiQueueQueryAndRemoveEvent+0xf7 (FPO: [Non-Fpo]) f4de5d28 8063bde6 nt!PiControlQueryAndRemoveDevice+0x8c (FPO: [Non-Fpo]) f4de5d50 8053d648 nt!NtPlugPlayControl+0xc2 (FPO: [Non-Fpo]) f4de5d50 7c90e514 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f4de5d64) 00c2f2ac 7c90d6aa ntdll!KiFastSystemCallRet (FPO: [0,0,0]) 00c2f2b0 7dbac060 ntdll!NtPlugPlayControl+0xc (FPO: [3,0,0]) 00c2f2ec 7dbacef5 umpnpmgr!QueryAndRemoveSubTree+0x5f (FPO: [Non-Fpo]) 00c2f558 7dbaa4e1 umpnpmgr!DisableDevInst+0x13a (FPO: [Non-Fpo]) 00c2f89c 77e799f4 umpnpmgr!PNP_HwProfFlags+0x2f3 (FPO: [Non-Fpo]) 00c2f8d4 77ef421a RPCRT4!Invoke+0x30 00c2fcf4 77ef46ee RPCRT4!NdrStubCall2+0x297 (FPO: [Non-Fpo]) 00c2fd10 77e794bd RPCRT4!NdrServerCall2+0x19 (FPO: [Non-Fpo]) 00c2fd44 77e79422 RPCRT4!DispatchToStubInC+0x38 (FPO: [Non-Fpo]) 00c2fd98 77e7934e RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0x113 (FPO: [Non-Fpo]) 00c2fdbc 77e7be64 RPCRT4!RPC_INTERFACE::DispatchToStub+0x84 (FPO: [Non-Fpo]) 00c2fdf8 77e7bcc1 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0x2db (FPO: [Non-Fpo]) 00c2fe1c 77e7bc05 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0x16d (FPO: [Non-Fpo]) 00c2ff80 77e76caf RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0x310 (FPO: [Non-Fpo]) 00c2ff88 77e76ad1 RPCRT4!RecvLotsaCallsWrapper+0xd (FPO: [Non-Fpo]) 00c2ffa8 77e76c97 RPCRT4!BaseCachedThreadRoutine+0x79 (FPO: [Non-Fpo]) 00c2ffb4 7c80b729 RPCRT4!ThreadStartRoutine+0x1a (FPO: [Non-Fpo]) 00c2ffec 00000000 kernel32!BaseThreadStart+0x37 (FPO: [Non-Fpo])
The above thread (TID=0628) is performing a Plug and Play operation as indicated by the function ntdll!NtPlugPlayControl(). The PNP operation that is blocking the thread is a Query-Remove as indicated by the function nt!PiQueueQueryAndRemoveEvent().
Find any other threads that may be involved in processing PnP operations.
The kernel debugger extension command "!stacks 2 pnp" displays the kernel mode call stacks of all threads that have the pattern "pnp" in them, as shown below.
kd> !stacks 2 pnp
Proc.Thread .Thread Ticks ThreadState Blocker
[85dc6830 System]
4.00003c 85dc3020 0000c8b Blocked nt!KiSwapContext+0x2e
nt!KiSwapThread+0x46
nt!KeWaitForSingleObject+0x1c2
tcpip!TCPCleanup+0xce
tcpip!TCPDispatch+0x91
nt!IopfCallDriver+0x31
nt!IopCloseFile+0x27c
nt!ObpDecrementHandleCount+0xd4
nt!ObpCloseHandleTableEntry+0x14d
nt!ObpCloseHandle+0x87
nt!NtClose+0x1d
nt!KiFastCallEntry+0xf8
nt!ZwClose+0x11
netbt!DelayedNbtCloseFileHandles+0x47
netbt!CloseAddressesWithTransport+0xc9
netbt!NbtNewDhcpAddress+0x39
netbt!TdiAddressDeletion+0x5f
TDI!TdiNotifyPnpClientList+0x12d
TDI!TdiExecuteRequest+0x19b
TDI!TdiHandleSerializedRequest+0x1c4
TDI!TdiDeregisterNetAddress+0xf
tcpip!NotifyAddrChange+0x116
tcpip!IPpSetNTEAddr+0xe0
tcpip!IPDelNTE+0x3b
tcpip!IPDelInterface+0xd2
tcpip!ARPUnbindAdapter+0x72
NDIS!ndisUnbindProtocol+0x157
NDIS!ndisCloseMiniportBindings+0x1f7
NDIS!ndisPnPRemoveDevice+0x142
NDIS!NdisIMDeInitializeDeviceInstance+0x44
psched!ClUnbindFromLowerMp+0xc9
NDIS!ndisUnbindProtocol+0x157
NDIS!ndisCloseMiniportBindings+0x1f7
NDIS!ndisPnPRemoveDevice+0x142
NDIS!ndisPnPDispatch+0x15d
nt!IopfCallDriver+0x31
nt!IopSynchronousCall+0xb7
nt!IopRemoveDevice+0x93
nt!IopRemoveLockedDeviceNode+0x160
nt!IopDeleteLockedDeviceNode+0x34
.
.
.
From the above output, the thread (TID=3c) is processing a PnP Remove Device operation and is waiting on NETBT.sys which is attempting to close a handle.
In the above analysis there are bunch of threads that are waiting in a chain for this operation to complete. This last thread in this chain is the RPC client thread in the application HungApplication.exe. From the information obtained so far, one can conclude that the network stack is preventing the application HungApplication.exe from making forward progress and hence it is responsible for the hang.
The following diagram displays the chain of RPC calls that result in the application hang.
