While fighting the flu last week I forgot that on 26th of March, 2006 I registered this domain. My excitement was so great that I couldn’t sleep the following night. I originally thought of domain names like crashdumpanalysis or memorydumpanalysis but was convinced by one of my colleagues that the shorter dumpanalysis is better.
- Dmitry Vostokov @ DumpAnalysis.org -
I was a big fan of Kitaro music for many years during 90s. Today I started re-listening to some of his albums and recommend
Heaven & Earth: Music From The Motion Picture Soundtrack
to listen to when analyzing complete memory dumps from complex issues, looking at user (Earth) and kernel (Heaven) spaces and trying to figure out which module started the conflict.
- Dmitry Vostokov @ DumpAnalysis.org -
In this part we start our discussion of Urstoff (Ger.), the primitive, primordial and basic element of everything and relation of memoidealism to Ionian school. In memoidealism, Memory serves the role of Urstoff as permanent primary element behind the process of state transition changes (technically speaking). In contrast, Ionians considered Urstoff to be of a material nature, for example, air (Anaximenes), fire (Heraclitus) or water (Thales). This abstraction (abstract materialism) of material elements parallels memory abstraction in memoidealism. Another parallel is the unity of science and philosophy.
- Dmitry Vostokov @ DumpAnalysis.org -
Just recently got news about a Microsoft security WinDbg extension released as open source:
http://www.microsoft.com/security/msec/default.mspx
http://www.codeplex.com/msecdbg
- Dmitry Vostokov @ DumpAnalysis.org -
One day, last week, Dmitry was walking in Malahide Woods and thinking through his dangerous ideas about universal memory dumps and how to reconcile man-made PDB files with empirically discovered science files. Upon finding a problem resolution, Dmitry sat firmly on the ground and remained there happily for some time.
- Dmitry Vostokov @ DumpAnalysis.org -
Sometimes a problem like a crash or a hang never happens again, the so called a unique computational event, like the extinction of dinosaurs if we apply biological metaphors. Biology science copes with such events via constructing historical narratives and multiple probabilistic explanations with cross data examinations. The same is true for memory dump analysis where we construct possible explanations based on evidence and collected supporting data. Like Ernst Mayr pointed, we try to answer both questions: “How?” and “Why?”. Usually the answer to the first question is very simple and straightforward, like NULL pointer access (proximate, functional causation) and the answer to the second question is provided by testing various possible historical narratives (ultimate or evolutionary causation) possibly involving an animate agent (a human user of a system).
- Dmitry Vostokov @ DumpAnalysis.org -
In Windows Vista and Server 2008 LPC is implemented using undocumented Advanced Local Procedure Calls (ALPC) and the new formatting of the !process 0 ff output shows the owner of the port:
THREAD fffffa801afae6f0 Cid 033c.3c40 Teb: 000007fffffa0000 Win32Thread: 0000000000000000 WAIT: (WrLpcReply) UserMode Non-Alertable
fffffa801afaea80 Semaphore Limit 0x1
Waiting for reply to ALPC Message fffff8800f4cc950 : queued at port fffffa8017dbb060 : owned by process fffffa801807b8f0
Instead of !lpc we should use !alpc extension command:
0: kd> !lpc message fffff8800f4cc950
LPC is now emulated over ALPC. Use !alpc
Arguments:
/? - Print help
/P [/V] PortAddress - Dump the ALPC port information
/M [/V] MsgAddress - Searches the message and dumps the message information
/R [/V] ResAddress - Dumps the information regarding resources
/G [/V] - Dumps the global information
0: kd> !alpc /M fffff8800f4cc950
Message @ fffff8800f4cc950
MessageID : 0x0BFC (3068)
CallbackID : 0x1FEF27 (2092839)
SequenceNumber : 0x0004D4D4 (316628)
Type : LPC_REQUEST
DataLength : 0x0068 (104)
TotalLength : 0x0090 (144)
Canceled : No
Release : No
ReplyWaitReply : No
Continuation : Yes
OwnerPort : fffffa8018a95e60 [ALPC_CLIENT_COMMUNICATION_PORT]
WaitingThread : fffffa801afae6f0
QueueType : ALPC_MSGQUEUE_PENDING
QueuePort : fffffa8017dbb060 [ALPC_CONNECTION_PORT]
QueuePortOwnerProcess : fffffa801807b8f0 (svchost.exe)
ServerThread : fffffa801aeec060
QuotaCharged : No
CancelQueuePort : 0000000000000000
CancelSequencePort : 0000000000000000
CancelSequenceNumber : 0×00000000 (0)
ClientContext : 00000000025599e0
ServerContext : 0000000000000000
PortContext : 000000000030d640
CancelPortContext : 0000000000000000
SecurityData : 0000000000000000
View : 0000000000000000
- Dmitry Vostokov @ DumpAnalysis.org -
Looking at one kernel memory dump from x64 Windows Server 2008 I noticed this API call (shown in blue):
0: kd> kL 100
Child-SP RetAddr Call Site
fffffa60`138f4720 fffff800`01875f8a nt!KiSwapContext+0x7f
fffffa60`138f4860 fffff800`0187776a nt!KiSwapThread+0x2fa
fffffa60`138f48d0 fffff800`01ab16d6 nt!KeWaitForSingleObject+0x2da
fffffa60`138f4960 fffff800`01ab1667 nt!FsRtlCancellableWaitForMultipleObjects+0x62
fffffa60`138f49c0 fffffa60`06c515e0 nt!FsRtlCancellableWaitForSingleObject+0x27
fffffa60`138f4a00 fffffa60`06c611dc rdbss!RxWaitForStableCondition+0x11c
fffffa60`138f4a40 fffffa60`06c61c07 rdbss!RxFindOrCreateConnections+0x44c
fffffa60`138f4b20 fffffa60`06c56840 rdbss!RxConstructVirtualNetRoot+0xb7
fffffa60`138f4bc0 fffffa60`06c6381a rdbss!RxFindOrConstructVirtualNetRoot+0x594
fffffa60`138f4d30 fffffa60`06c54c42 rdbss!RxCreateTreeConnect+0x13e
fffffa60`138f4dc0 fffffa60`06c2fbf6 rdbss!RxCommonCreate+0x20a
fffffa60`138f4e80 fffffa60`06c5191a rdbss!RxFsdCommonDispatch+0x786
fffffa60`138f4f70 fffffa60`07e4f21f rdbss!RxFsdDispatch+0x21a
fffffa60`138f4fe0 fffffa60`011e05f5 mrxsmb!MRxSmbFsdDispatch+0xbf
fffffa60`138f5020 fffffa60`011e0130 mup!MupiCallUncProvider+0x159
fffffa60`138f5090 fffffa60`011e17af mup!MupStateMachine+0x120
fffffa60`138f50e0 fffffa60`00d200b4 mup!MupCreate+0x2c3
fffffa60`138f5160 fffffa60`06d332d6 fltmgr!FltpCreate+0xa4
[...]
3rd party filter drivers
[...]
fffffa60`138f55a0 fffff800`01aefa59 nt!IopParseDevice+0x5e3
fffffa60`138f5740 fffff800`01af3944 nt!ObpLookupObjectName+0x5eb
fffffa60`138f5850 fffff800`01affee0 nt!ObOpenObjectByName+0x2f4
fffffa60`138f5920 fffff800`01b00a0c nt!IopCreateFile+0x290
fffffa60`138f59c0 fffff800`0186fdf3 nt!NtCreateFile+0x78
fffffa60`138f5a50 fffff800`01870300 nt!KiSystemServiceCopyEnd+0x13
fffffa60`138f5c58 fffffa60`06c91a5e nt!KiServiceLinkage
fffffa60`138f5c60 fffff800`018913d1 dfsc!DfscConnOpenIpcConnectionCallout+0xbe
fffffa60`138f5d20 fffffa60`06c91d08 nt!KeExpandKernelStackAndCalloutEx+0×2e1
fffffa60`138f5db0 fffffa60`06c9bbcc dfsc!DfscGetIpcConnection+0×1f0
fffffa60`138f5e30 fffffa60`06c9bb21 dfsc!DfscRmGetReferral+0×78
fffffa60`138f5ea0 fffffa60`06c91470 dfsc!DfscGetDomainDCReferral+0×31
fffffa60`138f5ef0 fffffa60`06c917ec dfsc!DfscRmValidateDomainIterate+0×5c
fffffa60`138f5f40 fffffa60`06c915f5 dfsc!DfscValidateReferral+0xa0
fffffa60`138f5fb0 fffffa60`06c917ec dfsc!DfscRmValidateRootGetParent+0×75
fffffa60`138f5fe0 fffffa60`06c90825 dfsc!DfscValidateReferral+0xa0
fffffa60`138f6050 fffffa60`06c93905 dfsc!DfscCmValidateState+0×79
fffffa60`138f6090 fffffa60`06c9e759 dfsc!DfscSurrogateCreate+0×7d
fffffa60`138f6100 fffffa60`011e03ab dfsc!DfscSurrogatePreProcess+0xb9
fffffa60`138f6130 fffffa60`011e014f mup!MupCallSurrogatePrePost+0×10b
fffffa60`138f6190 fffffa60`011e17af mup!MupStateMachine+0×13f
fffffa60`138f61e0 fffffa60`00d200b4 mup!MupCreate+0×2c3
fffffa60`138f6260 fffffa60`06d332d6 fltmgr!FltpCreate+0xa4
[…]
3rd party filter drivers
[…]
fffffa60`138f6610 fffff800`01aefa59 nt!IopParseDevice+0×5e3
fffffa60`138f67b0 fffff800`01af3944 nt!ObpLookupObjectName+0×5eb
fffffa60`138f68c0 fffff800`01ac22f1 nt!ObOpenObjectByName+0×2f4
fffffa60`138f6990 fffff800`0186fdf3 nt!NtQueryAttributesFile+0×134
fffffa60`138f6c20 00000000`77285e4a nt!KiSystemServiceCopyEnd+0×13
This API is mentioned in the following presentation and document and can also be found in WDK:
PPT: Windows Memory Management Advances
DOC: Advances in Memory Management
Its 3rd parameter is the stack size and we can see it used in disassembly where r8d register is used for 3rd parameter according to x64 calling convention and rcx is used for the first parameter, a function procedure to be executed with a guaranteed kernel stack size:
0: kd> kv 100
Child-SP RetAddr : Args to Child : Call Site
[...]
fffffa60`138f5c60 fffff800`018913d1 : 00000000`00000000 fffff880`10d6d3f8 00000000`00000000 00000000`00000000 : dfsc!DfscConnOpenIpcConnectionCallout+0xbe
fffffa60`138f5d20 fffffa60`06c91d08 : fffffa60`06c919a0 fffffa60`138f5df0 fffff880`102128d0 fffffa60`138f5f10 : nt!KeExpandKernelStackAndCalloutEx+0×2e1
fffffa60`138f5db0 fffffa60`06c9bbcc : 00000000`00000000 fffff880`10d6d3f8 00000000`00000000 fffff880`10d6d460 : dfsc!DfscGetIpcConnection+0×1f0
[…]
0: kd> ub fffffa60`06c91d08
dfsc!DfscGetIpcConnection+0×1c6:
fffffa60`06c91cde xor r9d,r9d
fffffa60`06c91ce1 mov qword ptr [rsp+50h],rax
fffffa60`06c91ce6 mov rax,qword ptr [dfsc!DfscGlobalData+0×138 (fffffa60`06c8d758)]
fffffa60`06c91ced mov r8d,6000h
fffffa60`06c91cf3 mov qword ptr [rsp+40h],rdi
fffffa60`06c91cf8 mov byte ptr [rsp+58h],r11b
fffffa60`06c91cfd mov qword ptr [rsp+20h],rax
fffffa60`06c91d02 call qword ptr [dfsc!_imp_KeExpandKernelStackAndCalloutEx (fffffa60`06c8b0d0)]
0: kd> ub fffffa60`06c91cde
dfsc!DfscGetIpcConnection+0x199:
fffffa60`06c91cb1 488b88b8000000 mov rcx,qword ptr [rax+0B8h]
fffffa60`06c91cb8 0fba61100a bt dword ptr [rcx+10h],0Ah
fffffa60`06c91cbd 450f42df cmovb r11d,r15d
fffffa60`06c91cc1 488b4338 mov rax,qword ptr [rbx+38h]
fffffa60`06c91cc5 488d542440 lea rdx,[rsp+40h]
fffffa60`06c91cca 488d0dcffcffff lea rcx,[dfsc!DfscConnOpenIpcConnectionCallout (fffffa60`06c919a0)]
fffffa60`06c91cd1 4889442448 mov qword ptr [rsp+48h],rax
fffffa60`06c91cd6 488d842490000000 lea rax,[rsp+90h]
It is good sign to see it used in file system stacks because in the past the fixed kernel stacks resulted in stack overflows and double faults:
Stack Overflow Pattern (kernel mode)
- Dmitry Vostokov @ DumpAnalysis.org -
Long time ago a professor of mathematical analysis told me a joke about reading comprehension levels:
Level 1: You feel good while reading
Level 2: You can repeat what you’ve read
Level 3: You can refute what you’ve read
After looking at some books on my shelves that I bought last month including 11 volume history of philosophy I would like to add
Level 0: You feel good before reading
- Dmitry Vostokov @ DumpAnalysis.org -
Yesterday I submitted the magazine to print and distribution world-wide. If everything is right it should be available by the end of this month. This first issue features 12 page WinDbg command supplement to pattern-driven memory dump analysis methodology, an overview of Win32dd complete memory dumper and PowerDbg enhancements to debug ASP.NET code. The magazine will only be available in print.
- Dmitry Vostokov @ DumpAnalysis.org -
For one manual user dump of a hanging service neither !analyze -v nor !analyze -v -hang command found the problem:
Loading Dump File [ServiceA.dmp]
User Mini Dump File with Full Memory: Only application data is available
Comment: 'Userdump generated complete user-mode minidump with Standalone function on COMPUTER'
0:000> !analyze -v -hang
DERIVED_WAIT_CHAIN:
Dl Eid Cid WaitType
-- --- ------- --------------------------
0 678.67c File IO
WAIT_CHAIN_COMMAND: ~0s;k;;
BLOCKING_THREAD: 0000067c
DEFAULT_BUCKET_ID: APPLICATION_HANG_BlockedOn_FileIO
PRIMARY_PROBLEM_CLASS: APPLICATION_HANG_BlockedOn_FileIO
LAST_CONTROL_TRANSFER: from 7c82776b to 7c8285ec
STACK_TEXT:
0012fbc8 7c82776b ntdll!KiFastSystemCallRet
0012fbcc 77e218b2 ntdll!NtReadFile+0xc
0012fc34 77d85edb kernel32!ReadFile+0x16c
0012fc60 77d85f82 advapi32!ScGetPipeInput+0x2a
0012fcd4 77d71ed9 advapi32!ScDispatcherLoop+0x51
0012ff38 004025e0 advapi32!StartServiceCtrlDispatcherW+0xe3
0012ff60 0042c8fd ServiceA!main+0x110
0012ffc0 77e4f23b ServiceA!mainCRTStartup+0x143
0012fff0 00000000 kernel32!BaseProcessStart+0x23
As usual the critical section list was checked for any locked sections and to find wait chains:
0:000> !cs -l -o -s
-----------------------------------------
DebugInfo = 0x7c8877c0
Critical section = 0×7c8877a0 (ntdll!LdrpLoaderLock+0×0)
LOCKED
LockCount = 0xA2
WaiterWoken = No
OwningThread = 0×00011f64
RecursionCount = 0×1
LockSemaphore = 0×188
SpinCount = 0×00000000
OwningThread DbgId = ~20s
OwningThread Stack =
ChildEBP RetAddr Args to Child
0327f91c 7c827d0b 7c83d236 00000754 00000000 ntdll!KiFastSystemCallRet
0327f920 7c83d236 00000754 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
0327f95c 7c83d281 00000754 00000004 00370000 ntdll!RtlpWaitOnCriticalSection+0×1a3
0327f97c 7c82a264 00370608 00000000 0000008c ntdll!RtlEnterCriticalSection+0xa8
0327fba4 7c3423aa 00370000 00000008 0000008c ntdll!RtlAllocateHeap+0×313
0327fbe4 7c3422cb 00000001 0000008c 00000000 msvcr71!calloc+0xe6
0327fbfc 7c81a352 7c340000 00000002 00000000 msvcr71!_CRTDLL_INIT+0×138
0327fc1c 7c82ed97 7c34229f 7c340000 00000002 ntdll!LdrpCallInitRoutine+0×14
0327fcb8 7c82ec9f 0327fd28 0327fd28 00000000 ntdll!LdrpInitializeThread+0×10d
0327fd14 7c8284c5 0327fd28 7c800000 00000000 ntdll!_LdrpInitialize+0×16f
00000000 00000000 00000000 00000000 00000000 ntdll!KiUserApcDispatcher+0×25
ntdll!RtlpStackTraceDataBase is NULL. Probably the stack traces are not enabled.
[…]
DebugInfo = 0×7c887e20
Critical section = 0×00370608 (+0×370608)
LOCKED
LockCount = 0×7
WaiterWoken = No
OwningThread = 0×000027ac
RecursionCount = 0×1
LockSemaphore = 0×754
SpinCount = 0×00000fa0
OwningThread DbgId = ~17s
OwningThread Stack =
ChildEBP RetAddr Args to Child
0170ebe0 7c82775b 77e62610 d0000144 00000004 ntdll!KiFastSystemCallRet
0170ebe4 77e62610 d0000144 00000004 00000000 ntdll!NtRaiseHardError+0xc
0170ee50 77e592a3 0170ee78 77e41ac1 0170ee80 kernel32!UnhandledExceptionFilter+0×51a
0170ee58 77e41ac1 0170ee80 00000000 0170ee80 kernel32!BaseThreadStart+0×4a
0170ee80 7c828752 0170ef64 0170ffdc 0170ef80 kernel32!_except_handler3+0×61
0170eea4 7c828723 0170ef64 0170ffdc 0170ef80 ntdll!ExecuteHandler2+0×26
0170ef4c 7c82855e 0170d000 0170ef80 0170ef64 ntdll!ExecuteHandler+0×24
0170ef4c 7c82a754 0170d000 0170ef80 0170ef64 ntdll!KiUserExceptionDispatcher+0xe (CONTEXT @ 0170ef80)
0170f258 7c82a82b 0185d6a8 00690043 0170f320 ntdll!RtlpCoalesceFreeBlocks+0×36e
0170f340 7c34218a 00370000 00000000 0185bad8 ntdll!RtlFreeHeap+0×38e
0170f388 004288df 0185bad8 05afd9c4 00000000 msvcr71!free+0xc3
0170f3b4 00428a16 05afd9c4 00001bc4 0185bad8 ServiceA!SetData+0×4df
ntdll!RtlpStackTraceDataBase is NULL. Probably the stack traces are not enabled.
[…]
We see that 162 threads (0xA2) are waiting for 0×7c8877a0 locked critical section whose owner thread #20 is waiting for the critical section 00370608 owned by the thread #17. The latter thread is blocked in an unhandled exception filter raising a hard error message box. Applying the new exception context we confirm heap corruption problem:
0:000> .cxr 0170ef80
eax=0185d6a8 ebx=00370000 ecx=00690043 edx=00000001 esi=0185d6a0 edi=01858030
eip=7c82a754 esp=0170f24c ebp=0170f258 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00010246
ntdll!RtlpCoalesceFreeBlocks+0×36e:
7c82a754 8b09 mov ecx,dword ptr [ecx] ds:0023:00690043=????????
0:000> kL
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr
0170f258 7c82a82b ntdll!RtlpCoalesceFreeBlocks+0×36e
0170f340 7c34218a ntdll!RtlFreeHeap+0×38e
0170f388 004288df msvcr71!free+0xc3
0170f3b4 00428a16 ServiceA!SetData+0×4df
[…]
0170ffec 00000000 kernel32!BaseThreadStart+0×34
Therefore we suggest to enable full page heap either by using gflags or application verifier. Looking further at other locked critical sections omitted above we notice that one is inaccessible and from an unloaded module:
Cannot read structure field value at 0x5531953c, error 0
Cannot determine if the critical section is locked or not.
-----------------------------------------
Critical section = 0x55319538 (<Unloaded_DetouredA.DLL>+0×29538)
DebugInfo = 0×00147108
ntdll!RtlpStackTraceDataBase is NULL. Probably the stack traces are not enabled.
We see this execution residue in the list of unloaded modules too:
0:000> lmt
[...]
Unloaded modules:
[...]
697b0000 697c7000 faultrep.dll
Timestamp: Sat Feb 17 15:12:57 2007 (45D71B79)
Checksum: 0001D340
[...]
552f0000 55320000 DetouredA.DLL
Timestamp: Wed Dec 19 09:38:46 2007 (4768E6A6)
Checksum: 00030564
Recalling that this hooksware had problems before we also suggest to remove software package that injects DetouredA module to test the stability of the system.
- Dmitry Vostokov @ DumpAnalysis.org -
During the last week of March I’m planning to take a break to write a mini-treatise explaining my dangerous idea in detail:
Parameterized Science: Universal Memory Dumps and the Grand Unification (ISBN: 978-1906717650)
This full color small publication should appear in print by the end of April and start an iterative and incremental publishing thread in philosophy.
- Dmitry Vostokov @ DumpAnalysis.org -
Today I found this book in a local bookshop but didn’t buy it because I couldn’t find enough dangerous ideas in it:
What Is Your Dangerous Idea?: Today’s Leading Thinkers on the Unthinkable
So I give my own dangerous idea in return: in the future, all sciences, engineering and technology will be ultimately fused and concerned with universal memory dumps of empirical data where appropriate symbol files will be used for every science as we know today, these files called science files. The set of science files can be considered as a parameter, hence the name of this idea. In another words, there will be one Science of memory dump analysis and many sciences. All sciences will be finally unified.
Now the question. Would it be also possible to discover new sciences by finding a suitable set of science files corresponding to a collected dump of empirical data?
- Dmitry Vostokov @ DumpAnalysis.org -
American equivalent of a British bloke:
a pal - a panic alarm
Examples: I see a pal. I got this company’s pal.
- Dmitry Vostokov @ DumpAnalysis.org -
I was passing by a local bookstore on my way to the office a few days ago and bought this book:
Hitler’s Private Library: The Books That Shaped His Life
The title of the book prompted me to think about books that shaped my life and thought. Here is the list of 9 books:
Before school:
1. The Hobbit
At school before university:
2. The Feynman Lectures on Physics
3. A short book with the title if translated to English: ”Electron through the Eyes of a Chemist: Essays on Modern Quantum Chemistry” by I. Dmitriev. Seems not available in English.
4. Mathematics: The Loss of Certainty
At university:
5. C Programming Language
After university but before moving to Ireland:
6. Advanced CORBA Programming with C++
7. UML Distilled: A Brief Guide to the Standard Object Modeling Language
Last 3-4 years:
8. Becoming a Technical Leader: An Organic Problem-Solving Approach
9. Life Itself: A Comprehensive Inquiry into the Nature, Origin, and Fabrication of Life
- Dmitry Vostokov @ DumpAnalysis.org -
Let’s look at one complete memory dump from a hanging system. It was reported that an application was hanging when trying to create a printer. In its process we can identify this blocked thread that was processing an LPC request and waiting for an LPC reply from a coupled process, a spooler service:
0: kd> !thread 88db89a8 1f
THREAD 88db89a8 Cid 0764.31b8 Teb: 7ffdc000 Win32Thread: bc2dc980 WAIT: (Unknown) UserMode Non-Alertable
88db8b94 Semaphore Limit 0x1
Waiting for reply to LPC MessageId 0016346d:
Current LPC port e179d780
Not impersonating
DeviceMap e157b068
Owning Process 8a95f690 Image: ApplicationA.exe
Attached Process N/A Image: N/A
Wait Start TickCount 2750643 Ticks: 153453 (0:00:39:57.703)
Context Switch Count 2120 LargeStack
UserTime 00:00:00.031
KernelTime 00:00:00.078
Win32 Start Address 0×0015b4fd
LPC Server thread working on message Id 15b4fd
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b7848000 Current b7847c08 Base b7848000 Limit b7845000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr
b7847c20 80833ec5 nt!KiSwapContext+0×26
b7847c4c 80829bc0 nt!KiSwapThread+0×2e5
b7847c94 80920f28 nt!KeWaitForSingleObject+0×346
b7847d50 8088ad3c nt!NtRequestWaitReplyPort+0×776
b7847d50 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ b7847d64)
00e6e150 7c82787b ntdll!KiFastSystemCallRet
00e6e154 77c80a6e ntdll!NtRequestWaitReplyPort+0xc
00e6e1a8 77c7fcf0 RPCRT4!LRPC_CCALL::SendReceive+0×230
00e6e1b4 77c80673 RPCRT4!I_RpcSendReceive+0×24
00e6e1c8 77ce315a RPCRT4!NdrSendReceive+0×2b
00e6e5b0 7307ca61 RPCRT4!NdrClientCall2+0×22e
00e6e5c8 73082e15 WINSPOOL!RpcAddPrinter+0×1c
00e6ea50 0040dd93 WINSPOOL!AddPrinterW+0×102
00e6ef40 0040f535 ApplicationA!CreatePrinter+0×8d9
[…]
00e6f8b4 77ce33e1 RPCRT4!Invoke+0×30
00e6fcb4 77ce35c4 RPCRT4!NdrStubCall2+0×299
00e6fcd0 77c7ff7a RPCRT4!NdrServerCall2+0×19
00e6fd04 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
00e6fd58 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
00e6fd7c 77c7e0d4 RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
00e6fdbc 77c7e080 RPCRT4!RPC_INTERFACE::DispatchToStubWithObject+0xc0
00e6fdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×41e
00e6fe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
00e6ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
00e6ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
00e6ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
00e6ffb8 77e64829 RPCRT4!ThreadStartRoutine+0×1b
We follow an LPC wait chain and see a thread blocked by a message box:
0: kd> !lpc message 0016346d
Searching message 16346d in threads …
Server thread 891e9db0 is working on message 16346d
Client thread 88db89a8 waiting a reply from 16346d
Searching thread 88db89a8 in port rundown queues …
0: kd> !thread 891e9db0 1f
THREAD 891e9db0 Cid 045c.3b3c Teb: 7ffa7000 Win32Thread: bc2d4ea8 WAIT: (Unknown) UserMode Non-Alertable
88f5c850 SynchronizationEvent
Impersonation token: e76f5030 (Level Impersonation)
DeviceMap e157b068
Owning Process 8ab10460 Image: spoolsv.exe
Attached Process N/A Image: N/A
Wait Start TickCount 2414962 Ticks: 489134 (0:02:07:22.718)
Context Switch Count 6797 LargeStack
UserTime 00:00:00.359
KernelTime 00:00:01.437
Win32 Start Address 0×0016346d
LPC Server thread working on message Id 16346d
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b6aaa000 Current b6aa9c50 Base b6aaa000 Limit b6aa6000 Call 0
Priority 11 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr
b6aa9c68 80833ec5 nt!KiSwapContext+0×26
b6aa9c94 80829bc0 nt!KiSwapThread+0×2e5
b6aa9cdc bf89aacc nt!KeWaitForSingleObject+0×346
b6aa9d38 bf89d952 win32k!xxxSleepThread+0×1be
b6aa9d4c bf89e310 win32k!xxxRealWaitMessageEx+0×12
b6aa9d5c 8088ad3c win32k!NtUserWaitMessage+0×14
b6aa9d5c 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ b6aa9d64)
021267bc 7739bf53 ntdll!KiFastSystemCallRet
021267f4 7738965e USER32!NtUserWaitMessage+0xc
0212681c 7739f762 USER32!InternalDialogBox+0xd0
02126adc 7739f047 USER32!SoftModalMessageBox+0×94b
02126c2c 7739eec9 USER32!MessageBoxWorker+0×2ba
02126c84 773d7d0d USER32!MessageBoxTimeoutW+0×7a
02126cb8 773c42c8 USER32!MessageBoxTimeoutA+0×9c
02126cd8 773c42a4 USER32!MessageBoxExA+0×1b
02126cf4 6dfcf8c2 USER32!MessageBoxA+0×45
WARNING: Frame IP not in any known module. Following frames may be wrong.
02126d98 530a2935 0×6dfcf8c2
02126d9c 20656d6f 0×530a2935
[…]
Looking at this thread waiting time we see the problem happened about 1 hour 20 minutes before our hanging application attempted to print. We want to see other threads in the spooler but most of them are paged out:
0: kd> !process 8ab10460 1f
[...]
THREAD 8a6aedb0 Cid 045c.1090 Teb: 7ffab000 Win32Thread: bc33bbe8 WAIT: (Unknown) UserMode Non-Alertable
8abb2f40 SynchronizationEvent
IRP List:
8a0a2ed0: (0006,0094) Flags: 00000800 Mdl: 00000000
Impersonation token: e7c94760 (Level Impersonation)
DeviceMap e9194e68
Owning Process 8ab10460 Image: spoolsv.exe
Attached Process N/A Image: N/A
Wait Start TickCount 1897118 Ticks: 1006978 (0:04:22:14.031)
Context Switch Count 9711 LargeStack
UserTime 00:00:00.343
KernelTime 00:00:02.812
Win32 Start Address 0x00165a40
LPC Server thread working on message Id 165a40
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init b7c28000 Current b7c27c60 Base b7c28000 Limit b7c24000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
[...]
Coming back to our message box thread we inspect MessageBox parameters to see the message:
0: kd> .process /r /p 8ab10460
Implicit process is now 8ab10460
Loading User Symbols
0: kd> !thread 891e9db0
[...]
ChildEBP RetAddr Args to Child
[...]
02126cf4 6dfcf8c2 00000000 02126d4c 02126d2c USER32!MessageBoxA+0×45
[…]
0: kd> da /c 100 02126d4c
02126d4c "Function address 0×77e63ce4 caused a protection fault. (exception code 0xc0000005).
0: kd> ln 0x77e63ce4
(77e63c87) kernel32!GetModuleFileNameW+0×83 | (77e63d7a) kernel32!GetProcAddress
We see that the thread experienced an access violation in GetModuleFileName API call.
We also see that stack trace is incorrect and we try to reconstruct the point of exception by looking at thread raw stack and searching for any hidden exception:
0: kd> .thread 891e9db0
Implicit thread is now 891e9db0
0: kd> !teb
TEB at 7ffa7000
ExceptionList: 0212757c
StackBase: 02130000
StackLimit: 02123000
SubSystemTib: 00000000
FiberData: 00001e00
ArbitraryUserPointer: 00000000
Self: 7ffa7000
EnvironmentPointer: 00000000
ClientId: 0000045c . 00003b3c
RpcHandle: 00000000
Tls Storage: 00000000
PEB Address: 7ffde000
LastErrorValue: 0
LastStatusValue: c0000034
Count Owned Locks: 0
HardErrorMode: 0
0: kd> dds 02123000 02130000
02123000 00000000
02123004 00000000
02123008 00000000
0212300c 00000000
[...]
021275a8 02127648
021275ac 0212aa0c
021275b0 7c8315c2 ntdll!RtlDispatchException+0×91
021275b4 02127648
021275b8 0212aa0c
021275bc 02127664
021275c0 02127624
021275c4 6dfd0a54
021275c8 063b0000
021275cc 02127648
021275d0 7c8877ec ntdll!PebLdr+0xc
021275d4 77e61a60 kernel32!_except_handler3
021275d8 77e69cf8 kernel32!`string’+0xc
021275dc ffffffff
021275e0 00080000
021275e4 00089878
021275e8 77b92e40 VERSION!`string’
021275ec 00000000
021275f0 00000000
021275f4 00017608
021275f8 02127540
021275fc 77b92e40 VERSION!`string’
02127600 02127648
02127604 7c828270 ntdll!_except_handler3
02127608 7c829f60 ntdll!CheckHeapFillPattern+0×64
0212760c ffffffff
02127610 7c829f59 ntdll!RtlFreeHeap+0×70f
02127614 77e62444 kernel32!LocalFree+0×27
02127618 00080000
0212761c 00000000
02127620 77e62457 kernel32!LocalFree+0×108
02127624 5dff1510
02127628 02130000
0212762c 00000000
02127630 0212797c
02127634 7c82855e ntdll!KiUserExceptionDispatcher+0xe
02127638 02123000
0212763c 02127664
02127640 02127648
02127644 02127664
02127648 c0000005
0212764c 00000000
02127650 00000000
02127654 77e63ce4 kernel32!GetModuleFileNameW+0×83
02127658 00000002
0212765c 00000000
02127660 00000018
02127664 0001003f
02127668 00000000
0212766c 00000000
02127670 00000000
[…]
0: kd> .cxr 02127664
eax=00000000 ebx=00000000 ecx=7c82d279 edx=7c8877a0 esi=7c8877ec edi=063b0000
eip=77e63ce4 esp=02127930 ebp=0212797c iopl=0 nv up ei ng nz ac pe cy
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00010297
kernel32!GetModuleFileNameW+0x83:
001b:77e63ce4 3b7818 cmp edi,dword ptr [eax+18h] ds:0023:00000018=????????
0: kd> kv
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr Args to Child
0212797c 77390f3d 063b0000 021279d0 00000104 kernel32!GetModuleFileNameW+0x83
02127990 77390f13 063b0000 021279d0 00000104 USER32!WowGetModuleFileName+0x14
02127bdc 7738bcbd 063b0000 00000097 00000003 USER32!LoadIcoCur+0x76
02127bfc 06425db5 063b0000 00000097 02127d28 USER32!LoadIconW+0×1b
WARNING: Frame IP not in any known module. Following frames may be wrong.
02127c38 7c82cefe 00000704 00001f10 02127c58 0×6425db5
02127c4c 7c82ceb0 00001f10 00002614 00000704 ntdll!ARRAY_FITS+0×29
02127c8c c0150008 00000000 03923f68 0000001d ntdll!RtlpLocateActivationContextSection+0×1da
02127d20 7c82e0ef 00000000 00000000 00071f10 0xc0150008
What we see is the fact that the thread tried to load an icon from 063b0000 module not listed in lmv command output list perhaps because it was not fully loaded yet. We see that the thread also holds a loader critical section:
0: kd> !cs -l -o -s
-----------------------------------------
DebugInfo = 0x7c8877c0
Critical section = 0×7c8877a0 (ntdll!LdrpLoaderLock+0×0)
LOCKED
LockCount = 0xC
WaiterWoken = No
OwningThread = 0×00003b3c
RecursionCount = 0×1
LockSemaphore = 0×108
SpinCount = 0×00000000
OwningThread = .thread 891e9db0
ntdll!RtlpStackTraceDataBase is NULL. Probably the stack traces are not enabled.
However we can inspect the unknown module PE headers left in memory:
0: kd> !dh 063b0000
File Type: DLL
FILE HEADER VALUES
14C machine (i386)
4 number of sections
42B9172C time date stamp Wed Jun 22 08:45:48 2005
0 file pointer to symbol table
0 number of symbols
E0 size of optional header
210E characteristics
Executable
Line numbers stripped
Symbols stripped
32 bit word machine
DLL
[...]
Debug Directories(1)
Type Size Address Pointer
cv 16 10198 f598 Format: NB10, 42b9172c, 1, c:\printerdriver123UI.pdb
[...]
We see that the module name is printerdriver123UI. So we should recommend to check the printer driver package containing this component. lmv command lists many printer drivers with the similar name prefix and we look at thread execution residue to get better stack trace and find the corresponding printer. We know that the application called AddPrinter API and therefore we try to find the corresponding call on the raw stack that we examined for hidden exceptions before:
[...]
0212ef2c 01f20390
0212ef30 0212f3f8
0212ef34 76144799 localspl!SplAddPrinter+0×5f3
0212ef38 01efb730
0212ef3c 00000003
[…]
0212f3f8 0212f424
0212f3fc 76144ab2 localspl!LocalAddPrinterEx+0×2e
0212f400 00000000
[…]
0212f424 0212f874
0212f428 7407018b SPOOLSS!AddPrinterExW+0×151
0212f42c 00000000
[…]
0212f874 0212f890
0212f878 74070254 SPOOLSS!AddPrinterW+0×17
0212f87c 00000000
[…]
0: kd> kv L=0212ef30
ChildEBP RetAddr Args to Child
0212ef30 76144799 01efb730 00000003 00000000 kernel32!GetModuleFileNameW+0x83
0212f3f8 76144ab2 00000000 00000002 011116e0 localspl!SplAddPrinter+0x5f3
0212f424 7407018b 00000000 00000002 011116e0 localspl!LocalAddPrinterEx+0x2e
0212f874 74070254 00000000 00000002 011116e0 SPOOLSS!AddPrinterExW+0x151
0212f890 0100792d 00000000 00000002 011116e0 SPOOLSS!AddPrinterW+0×17
0212f8ac 01006762 00000000 0118f968 00159180 spoolsv!YAddPrinter+0×75
0212f8d0 77c80193 00000000 0118f968 00159180 spoolsv!RpcAddPrinter+0×37
0212f8f8 77ce33e1 0100672b 0212fae0 00000005 RPCRT4!Invoke+0×30
0212fcf8 77ce35c4 00000000 00000000 000cefbc RPCRT4!NdrStubCall2+0×299
0212fd14 77c7ff7a 000cefbc 000bbd20 000cefbc RPCRT4!NdrServerCall2+0×19
0212fd48 77c8042d 01002c47 000cefbc 0212fdec RPCRT4!DispatchToStubInCNoAvrf+0×38
0212fd9c 77c80353 00000005 00000000 0100d228 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
0212fdc0 77c811dc 000cefbc 00000000 0100d228 RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
0212fdfc 77c812f0 000c9e80 000a7af0 0014ce70 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×42c
0212fe20 77c88678 000a7b28 0212fe38 000c9e80 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
0212ff84 77c88792 0212ffac 77c8872d 000a7af0 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
0212ff8c 77c8872d 000a7af0 00000000 00000000 RPCRT4!RecvLotsaCallsWrapper+0xd
0212ffac 77c7b110 000885d8 0212ffec 77e64829 RPCRT4!BaseCachedThreadRoutine+0×9d
0212ffb8 77e64829 000a3750 00000000 00000000 RPCRT4!ThreadStartRoutine+0×1b
0212ffec 00000000 77c7b0f5 000a3750 00000000 kernel32!BaseThreadStart+0×34
Examination of the server-side AddPrinter arguments reveals the printer name:
0: kd> dpu 011116e0 l5
011116e0 00000000
011116e4 00158f48
011116e8 00000000
011116ec 00158fe4
011116f0 00159040 "PRINTER NAME ABCDEF“
- Dmitry Vostokov @ DumpAnalysis.org -
a bloke - a blown kernel
Examples: I see a bloke. I got this company’s bloke.
- Dmitry Vostokov @ DumpAnalysis.org -
One pattern I recently discovered is the partitioning of anomalous debugger output from debugging commands into several disjoint or weakly linked classes. I call the pattern Semantic Split. It is better characterized as a partition of the memory analysis pattern, for example, Blocked Thread, into classes with different semantics, for example, blocked display threads and blocked remote share threads. Here is one short example of it found in the output of !locks and !process 0 ff WinDbg commands from a complete memory dump forced on a hanging server. The output shows several blocked threads and wait chains of executive resources (some shared locks have been removed for clarity):
0: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
Resource @ 0×88eeeaf0 Exclusively owned
Contention Count = 809254
NumberOfExclusiveWaiters = 4
Threads: 88a26db0-01<*>
Threads Waiting On Exclusive Access:
88c6b6d0 8877b020 88a7e020 88938db0
Resource @ 0×88badb20 Exclusively owned
Contention Count = 9195
NumberOfExclusiveWaiters = 4
Threads: 88842020-02<*>
Threads Waiting On Exclusive Access:
88a8b170 89069450 88c4d020 88a26db0
Resource @ 0x88859cc0 Exclusively owned
Contention Count = 51021
NumberOfExclusiveWaiters = 8
Threads: 886f1c50-01<*>
Threads Waiting On Exclusive Access:
88e04db0 886785c0 8851edb0 896ee890
8869fb50 886d6498 889aa918 88c2da38
Resource @ 0x881cc138 Exclusively owned
Contention Count = 173698
NumberOfExclusiveWaiters = 4
Threads: 87e72598-01<*>
Threads Waiting On Exclusive Access:
88392020 8918c8d8 88423020 880eba50
Resource @ 0x884ffab0 Exclusively owned
Contention Count = 3363
NumberOfExclusiveWaiters = 2
Threads: 8807c5b8-02<*>
Threads Waiting On Exclusive Access:
87e72598 881c12a8
Resource @ 0x87cd6d48 Exclusively owned
Contention Count = 242361
NumberOfExclusiveWaiters = 5
Threads: 87540718-01<*>
Threads Waiting On Exclusive Access:
878ceaf0 8785ac50 8884a7b8 87c4ca28
89ab5db0
Resource @ 0x87c44d08 Exclusively owned
Contention Count = 2560
NumberOfExclusiveWaiters = 1
Threads: 87540718-01<*>
Threads Waiting On Exclusive Access:
87c4e468
Resource @ 0×87bf51d8 Exclusively owned
Contention Count = 3
NumberOfSharedWaiters = 3
Threads: 89e76db0-01<*> 8739ac50-01 86f5d1c8-01 870f4db0-01
Resource @ 0×888bfc38 Exclusively owned
Contention Count = 3
NumberOfSharedWaiters = 3
Threads: 88a10db0-01<*> 86c94198-01 86dac598-01 86d85c50-01
The first group of locks (one of them shown in blue) shows various problems with ComponentA module:
0: kd> !thread 88842020 1f
THREAD 88842020 Cid 1cf8.1b28 Teb: 7ffdb000 Win32Thread: bc25e8c0 WAIT: (Unknown) KernelMode Non-Alertable
88842098 NotificationTimer
Not impersonating
DeviceMap e3813fd0
Owning Process 888c5d88 Image: ApplicationA.exe
Attached Process N/A Image: N/A
Wait Start TickCount 1163714 Ticks: 0
Context Switch Count 35781 LargeStack
UserTime 00:00:00.453
KernelTime 00:00:01.109
Win32 Start Address 0x77ec3ea5
Start Address kernel32!BaseThreadStartThunk (0x7c8217ec)
Stack Init b5cc4bd0 Current b5cc4614 Base b5cc5000 Limit b5cbf000 Call b5cc4bd8
Priority 9 BasePriority 9 PriorityDecrement 0
ChildEBP RetAddr
b5cc462c 80833ec5 nt!KiSwapContext+0x26
b5cc4658 80829069 nt!KiSwapThread+0x2e5
b5cc46a0 bf8981b3 nt!KeDelayExecutionThread+0x2ab
b5cc46c4 bf898422 ComponentA!LockGUIHandle+0×6d
[…]
b5cc49e8 80a63456 nt!KiFastCallEntry+0xcd
[…]
The second group of locks (shown in red) shows the problem with ComponentB module:
0: kd> !thread 89e76db0 1f
THREAD 89e76db0 Cid 0004.0624 Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Alertable
89e76e28 NotificationTimer
Not impersonating
DeviceMap e1006e10
Owning Process 8b581648 Image: System
Attached Process N/A Image: N/A
Wait Start TickCount 1163714 Ticks: 0
Context Switch Count 545
UserTime 00:00:00.000
KernelTime 00:00:00.015
Start Address 0xb9003c20
Stack Init b9148000 Current b9147abc Base b9148000 Limit b9145000 Call 0
Priority 16 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr
b9147ad4 80833ec5 nt!KiSwapContext+0x26
b9147b00 80829069 nt!KiSwapThread+0x2e5
b9147b48 b8fc9353 nt!KeDelayExecutionThread+0x2ab
b9147b74 b8ff9460 ComponentB!DeleteShareConnection+0×203
[…]
b9147ddc 8088f61e nt!PspSystemThreadStartup+0×2e
00000000 00000000 nt!KiThreadStartup+0×16
Looking at the list of all threads we see another classes of blocked threads, one is involving ComponentC module in user space:
0: kd> !thread 86c21db0 1f
THREAD 86c21db0 Cid 0fac.5260 Teb: 7ff6a000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
869f2f68 SynchronizationEvent
IRP List:
87fe3148: (0006,0220) Flags: 00000830 Mdl: 00000000
Not impersonating
DeviceMap e1006e10
Owning Process 896ccc28 Image: ServiceA.exe
Attached Process N/A Image: N/A
Wait Start TickCount 1163714 Ticks: 0
Context Switch Count 22
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0×005c1de0
LPC Server thread working on message Id 5c1de0
Start Address kernel32!BaseThreadStartThunk (0×7c8217ec)
Stack Init b9787000 Current b9786c60 Base b9787000 Limit b9784000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr
b9786c78 80833ec5 nt!KiSwapContext+0×26
b9786ca4 80829bc0 nt!KiSwapThread+0×2e5
b9786cec 8093b034 nt!KeWaitForSingleObject+0×346
b9786d50 8088ad3c nt!NtWaitForSingleObject+0×9a
b9786d50 7c9485ec nt!KiFastCallEntry+0xfc
03f8f984 7c821c8d ntdll!KiFastSystemCallRet
03f8f998 10097728 kernel32!WaitForSingleObject+0×12
03f8f9bc 10008164 ComponentC!ComponentB_Control+0×68
[…]
03f8ffec 00000000 kernel32!BaseThreadStart+0×34
This thread holds a mutant and blocks a dozen of other threads in ServiceA.exe, for example:
THREAD 8aa7cb40 Cid 0fac.0110 Teb: 7ffad000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
87764550 Mutant - owning thread 86c21db0
From the function name we can infer that ComponentC controls ComponentB and this makes both blocked threads weakly connected.
Another thread in ServiceB involves DriverA module and blocks a thread ServiceA:
0: kd> !thread 8899e778 1f
THREAD 8899e778 Cid 01b0.13e0 Teb: 7ffdc000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
8aadb6e0 SynchronizationEvent
8899e7f0 NotificationTimer
IRP List:
86f21de0: (0006,0220) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap e1006e10
Owning Process 8ab3d020 Image: ServiceB.exe
Attached Process N/A Image: N/A
Wait Start TickCount 1163714 Ticks: 0
Context Switch Count 2
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0x005c1a3c
LPC Server thread working on message Id 5c1a3c
Start Address 0x48589bb3
Stack Init aecee000 Current aeced768 Base aecee000 Limit aeceb000 Call 0
Priority 12 BasePriority 11 PriorityDecrement 0
ChildEBP RetAddr
aeced780 80833ec5 nt!KiSwapContext+0x26
aeced7ac 80829bc0 nt!KiSwapThread+0x2e5
aeced7f4 badffece nt!KeWaitForSingleObject+0x346
WARNING: Stack unwind information not available. Following frames may be wrong.
aeced824 bae00208 DriverA+0×1ece
aeced868 bae0e45a DriverA+0×2208
aeced8a0 8081e095 DriverA+0×1045a
aeced8b4 b946673b nt!IofCallDriver+0×45
[…]
0: kd> !thread 8776c220 1f
THREAD 8776c220 Cid 0fac.5714 Teb: 7ff66000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
8776c40c Semaphore Limit 0x1
Waiting for reply to LPC MessageId 005c1a3c:
Current LPC port e213b0c8
Not impersonating
DeviceMap e1006e10
Owning Process 896ccc28 Image: ServiceA.exe
Attached Process N/A Image: N/A
Wait Start TickCount 1163714 Ticks: 0
Context Switch Count 12
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0x75fddd73
Start Address kernel32!BaseThreadStartThunk (0x7c8217ec)
Stack Init aecf2000 Current aecf1c08 Base aecf2000 Limit aecef000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr
aecf1c20 80833ec5 nt!KiSwapContext+0x26
aecf1c4c 80829bc0 nt!KiSwapThread+0x2e5
aecf1c94 80920f28 nt!KeWaitForSingleObject+0x346
aecf1d50 8088ad3c nt!NtRequestWaitReplyPort+0x776
aecf1d50 7c9485ec nt!KiFastCallEntry+0xfc
0408f594 75fde6b5 ntdll!KiFastSystemCallRet
0408f5fc 75fdd65e ComponentD!ServiceB_Request+0×1ae
[…]
0408ffec 00000000 kernel32!BaseThreadStart+0×34
In ServiceA we can also find several threads blocked by a RPC request to ServiceC:
0: kd> !thread 87397020 1f
THREAD 87397020 Cid 0fac.38cc Teb: 7ff80000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
87397098 NotificationTimer
Not impersonating
DeviceMap e1006e10
Owning Process 896ccc28 Image: ServiceA.exe
Attached Process N/A Image: N/A
Wait Start TickCount 1163714 Ticks: 0
Context Switch Count 7807
UserTime 00:00:00.125
KernelTime 00:00:00.109
Win32 Start Address 0x005c21a8
LPC Server thread working on message Id 5c21a8
Start Address kernel32!BaseThreadStartThunk (0x7c8217ec)
Stack Init b4ecf000 Current b4ecec80 Base b4ecf000 Limit b4ecc000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr
b4ecec98 80833ec5 nt!KiSwapContext+0x26
b4ececc4 80829069 nt!KiSwapThread+0x2e5
b4eced0c 80996d8a nt!KeDelayExecutionThread+0x2ab
b4eced54 8088ad3c nt!NtDelayExecution+0x84
b4eced54 7c9485ec nt!KiFastCallEntry+0xfc
03a1f178 7c8024ed ntdll!KiFastSystemCallRet
03a1f188 77c5e51a kernel32!Sleep+0xf
03a1f198 77c36a44 RPCRT4!OSF_BINDING_HANDLE::Unbind+0x3a
03a1f1b0 77c36a08 RPCRT4!OSF_BINDING_HANDLE::~OSF_BINDING_HANDLE+0x32
03a1f1bc 77c369f1 RPCRT4!OSF_BINDING_HANDLE::`scalar deleting destructor'+0xd
03a1f1cc 77c5250a RPCRT4!OSF_BINDING_HANDLE::BindingFree+0x30
03a1f1dc 77f48c00 RPCRT4!RpcBindingFree+0x4e
03a1f1e8 77f48be2 ADVAPI32!RpcpUnbindRpc+0x15
03a1f1f4 77c3688e ADVAPI32!PLSAPR_SERVER_NAME_unbind+0xd
03a1f21c 77c369bb RPCRT4!GenericHandleMgr+0xca
03a1f23c 77c36983 RPCRT4!GenericHandleUnbind+0x31
03a1f260 77cb31b2 RPCRT4!NdrpClientFinally+0x5b
03a1f26c 77cb317a RPCRT4!NdrClientCall2+0x324
03a1f64c 77f4a0a1 RPCRT4!NdrClientCall2+0x2ea
03a1f664 77f4a022 ComponentD!ServiceC_Request+0×1c
[…]
03a1f8f8 77cb33e1 RPCRT4!Invoke+0×30
03a1fcf8 77cb35c4 RPCRT4!NdrStubCall2+0×299
03a1fd14 77c4ff7a RPCRT4!NdrServerCall2+0×19
03a1fd48 77c5042d RPCRT4!DispatchToStubInCNoAvrf+0×38
03a1fd9c 77c50353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
03a1fdc0 77c511dc RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
03a1fdfc 77c512f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×42c
03a1fe20 77c58678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
03a1ff84 77c58792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
03a1ff8c 77c5872d RPCRT4!RecvLotsaCallsWrapper+0xd
03a1ffac 77c4b110 RPCRT4!BaseCachedThreadRoutine+0×9d
03a1ffb8 7c824829 RPCRT4!ThreadStartRoutine+0×1b
03a1ffec 00000000 kernel32!BaseThreadStart+0×34
In ServiceC we see several RPC processing threads blocked by ComponentE:
0: kd> !thread 873acb40 1f
THREAD 873acb40 Cid 023c.3a00 Teb: 7ff93000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
89f0aeb0 Semaphore Limit 0x1
873acbb8 NotificationTimer
IRP List:
89838a00: (0006,0094) Flags: 00000900 Mdl: 00000000
8705d4a0: (0006,0094) Flags: 00000800 Mdl: 00000000
88bc9440: (0006,0094) Flags: 00000900 Mdl: 00000000
87674af8: (0006,0094) Flags: 00000900 Mdl: 00000000
86f2aa48: (0006,0094) Flags: 00000900 Mdl: 00000000
87551290: (0006,0094) Flags: 00000900 Mdl: 00000000
Not impersonating
DeviceMap e1006e10
Owning Process 89dc0508 Image: ServiceC.exe
Attached Process N/A Image: N/A
Wait Start TickCount 1163714 Ticks: 0
Context Switch Count 16571
UserTime 00:00:00.250
KernelTime 00:00:00.703
Win32 Start Address RPCRT4!ThreadStartRoutine (0x77c4b0f5)
Start Address kernel32!BaseThreadStartThunk (0x7c8217ec)
Stack Init b2a9b000 Current b2a9ac60 Base b2a9b000 Limit b2a98000 Call 0
Priority 13 BasePriority 9 PriorityDecrement 0
ChildEBP RetAddr
b2a9ac78 80833ec5 nt!KiSwapContext+0x26
b2a9aca4 80829bc0 nt!KiSwapThread+0x2e5
b2a9acec 8093b034 nt!KeWaitForSingleObject+0x346
b2a9ad50 8088ad3c nt!NtWaitForSingleObject+0x9a
b2a9ad50 7c9485ec nt!KiFastCallEntry+0xfc
022cf8d0 7c821c8d ntdll!KiFastSystemCallRet
022cf8e4 741269e5 kernel32!WaitForSingleObject+0x12
022cf8f8 7412cdca ComponentE!Enumerate+0×37
[…]
022cf944 77cb33e1 RPCRT4!Invoke+0×30
022cfd44 77cb35c4 RPCRT4!NdrStubCall2+0×299
022cfd60 77c4ff7a RPCRT4!NdrServerCall2+0×19
022cfd94 77c5042d RPCRT4!DispatchToStubInCNoAvrf+0×38
022cfde8 77c50353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
022cfe0c 77c38e0d RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
022cfe40 77c38cb3 RPCRT4!OSF_SCALL::DispatchHelper+0×149
022cfe54 77c38c2b RPCRT4!OSF_SCALL::DispatchRPCCall+0×10d
022cfe84 77c38b5e RPCRT4!OSF_SCALL::ProcessReceivedPDU+0×57f
022cfea4 77c3e8db RPCRT4!OSF_SCALL::BeginRpcCall+0×194
022cff04 77c3e7b4 RPCRT4!OSF_SCONNECTION::ProcessReceiveComplete+0×435
022cff18 77c4b799 RPCRT4!ProcessConnectionServerReceivedEvent+0×21
022cff84 77c4b9b5 RPCRT4!LOADABLE_TRANSPORT::ProcessIOEvents+0×1b8
022cff8c 77c5872d RPCRT4!ProcessIOEventsWrapper+0xd
022cffac 77c4b110 RPCRT4!BaseCachedThreadRoutine+0×9d
022cffb8 7c824829 RPCRT4!ThreadStartRoutine+0×1b
022cffec 00000000 kernel32!BaseThreadStart+0×34
Therefore we have 4 main groups of wait chain endpoints involving semantically disjoint ComponentA, ComponentB, ComponentE and DriverA modules. Although their module names do not infer disjointedness this example was abstracted from the real incident where respective modules were having different system functions and were even from different software vendors.
- Dmitry Vostokov @ DumpAnalysis.org -
