DumpAnalysis.org wishes a Merry Christmas via a virtual postcard from Narasimha Vedala, the author of Dumps, Bugs and Debugging Forensics book!
http://www.dumpanalysis.org/Merry+Christmas+2008
- Dmitry Vostokov @ DumpAnalysis.org -
The following book is planned for publication during the 1st quarter of 2009:
Title: Reference Stack Traces: Windows Server® 2008 and Windows Vista™
ISBN-13: 978-1-906717-23-0
It features visual separation between kernel and user space in thread stack traces and useful footnotes for IRP and modules. Its publishing was delayed by a few months but fortunately my editing just got new breath by introducing thread stackprint images for kernel stacks (12Kb bitmaps):
Thread stackprints were generated from a complete memory dump using WinDbg scripts and Dump2Picture.
- Dmitry Vostokov @ DumpAnalysis.org -
Thanks to the wonderful real-time memory visualization package from Jamie Fenton developed initially as a FreeFrame plugin for FrameLab (a general FreeFrame host adaptor for DirectShow) and now with its own real-time memory viewer GUI front-end I was able to find the evidence for cosmic rays in computer memory! You can see them on this screenshot where the left panel is a condensed virtual memory map of IE process and the right panel is specific page(s) view (I found rays on pages starting from 0×3B4000 address):
- Dmitry Vostokov @ DumpAnalysis.org -
Previously announced Salary Figures book is on sale:
Salary Figures: A Codebook of Expectations
Front cover:
Back cover:
- Dmitry Vostokov @ DumpAnalysis.org -
A bug “is part of this” computation “and not of the next.”
- Dmitry Vostokov @ DumpAnalysis.org -
Nothing was lost and never be. Everything has been saved, now and will be.
- Dmitry Vostokov @ Memory Religion Portal -
Just noticed today that the number of posts in crash dump category became 512:
Of course, with this post, it is now 513.
- Dmitry Vostokov @ DumpAnalysis.org -
In one system even Task Manager was hanging and forced complete memory dump reveals a blocked GUI dialog thread waiting for an LPC reply:
THREAD fffffade69e36310 Cid 4b30.4f34 Teb: 000007fffffde000 Win32Thread: fffff97ff3f97620 WAIT: (Unknown) UserMode Non-Alertable
fffffade69e36678 Semaphore Limit 0x1
Waiting for reply to LPC MessageId a7531ec4:
Current LPC port fffffa8007118190
Not impersonating
DeviceMap fffffa80021c6240
Owning Process fffffadee0332040 Image: taskmgr.exe
Wait Start TickCount 80209499 Ticks: 5596 (0:00:01:27.437)
Context Switch Count 173 LargeStack
UserTime 00:00:00.000
KernelTime 00:00:00.031
Win32 Start Address taskmgr!wWinMainCRTStartup (0×000000010001bfe0)
Start Address kernel32!BaseProcessStart (0×0000000077d59620)
Stack Init fffffad7c6e5ae00 Current fffffad7c6e5a8e0
Base fffffad7c6e5b000 Limit fffffad7c6e52000 Call 0
Priority 14 BasePriority 13 PriorityDecrement 0
Child-SP RetAddr Call Site
fffffad7`c6e5a920 fffff800`01027752 nt!KiSwapContext+0×85
fffffad7`c6e5aaa0 fffff800`0102835e nt!KiSwapThread+0×3c9
fffffad7`c6e5ab00 fffff800`01283ebb nt!KeWaitForSingleObject+0×5a6
fffffad7`c6e5ab80 fffff800`0102e3fd nt!NtRequestWaitReplyPort+0xa60
fffffad7`c6e5ac70 00000000`77ef0c0a nt!KiSystemServiceCopyEnd+0×3 (TrapFrame @ fffffad7`c6e5ac70)
00000000`000adef8 000007ff`7fd6df46 ntdll!ZwRequestWaitReplyPort+0xa
00000000`000adf00 000007ff`7fd6e17f RPCRT4!LRPC_CCALL::SendReceive+0×447
00000000`000adfe0 000007ff`7fe974c8 RPCRT4!NdrSendReceive+0xf6
00000000`000ae010 000007ff`7fe975bd RPCRT4!NdrpClientCall2+0×7e2
00000000`000ae5f0 000007ff`7d4d8a0d RPCRT4!NdrClientCall2+0×1d
00000000`000ae620 00000001`00011029 WINSTA!WinStationGetProcessSid+0xfd
00000000`000ae6a0 00000001`00010e3b taskmgr!CProcInfo::SetProcessUsername+0×189
00000000`000ae930 00000001`000118e9 taskmgr!CProcInfo::SetData+0×53b
00000000`000aebb0 00000001`000122f4 taskmgr!CProcPage::UpdateProcInfoArray+0×449
00000000`000aee70 00000001`00013eab taskmgr!CProcPage::TimerEvent+0×14
00000000`000aeea0 00000001`00004e8f taskmgr!CProcPage::Initialize+0×29b
00000000`000af320 00000001`000070e8 taskmgr!MainWnd_OnInitDialog+0×2ff
00000000`000af620 00000000`77c34582 taskmgr!MainWindowProc+0×3f8
00000000`000af680 00000000`77c34bf2 USER32!UserCallDlgProcCheckWow+0×210
00000000`000af760 00000000`77c2ff5f USER32!DefDlgProcWorker+0xf6
00000000`000af7f0 00000000`77c29beb USER32!InternalCreateDialog+0×16a7
00000000`000af980 00000001`00007c97 USER32!CreateDialogParamW+0xab
00000000`000afa00 00000001`0001c24b taskmgr!wWinMain+0×5f7
00000000`000afed0 00000000`77d5964c taskmgr!wWinMainCRTStartup+0×26b
00000000`000aff80 00000000`00000000 kernel32!BaseProcessStart+0×29
We search for that LPC message:
6: kd> !lpc message a7531ec4
Searching message a7531ec4 in threads ...
Server thread fffffade6b8cf7a0 is working on message a7531ec4
Client thread fffffade69e36310 waiting a reply from a7531ec4
[…]
and then examine the corresponding server thread (for visual clarity only 1 argument is shown for each function call):
6: kd> !thread fffffade6b8cf7a0 16
THREAD fffffade6b8cf7a0 Cid 0238.8ff4 Teb: 000007fffff48000 Win32Thread: 0000000000000000 WAIT: (Unknown) UserMode Non-Alertable
fffffade6f2e93c0 SynchronizationEvent
Impersonation token: fffffa8013a17700 (Level Impersonation)
DeviceMap fffffa80021c6240
Owning Process fffffade6f337040 Image: svchost.exe
Wait Start TickCount 80209499 Ticks: 5596 (0:00:01:27.437)
Context Switch Count 40138
UserTime 00:00:00.140
KernelTime 00:00:00.312
Win32 Start Address 0×00000000a7531ec4
LPC Server thread working on message Id a7531ec4
Start Address kernel32!BaseThreadStart (0×0000000077d6b6a0)
Stack Init fffffad867f5ae00 Current fffffad867f5a950
Base fffffad867f5b000 Limit fffffad867f55000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 0
Child-SP RetAddr : Args to Child : Call Site
fffffad8`67f5a990 fffff800`01027752 : fffffa80`071181f0 : nt!KiSwapContext+0×85
fffffad8`67f5ab10 fffff800`0102835e : 00000000`00000000 : nt!KiSwapThread+0×3c9
fffffad8`67f5ab70 fffff800`0127f03f : 00000000`00000000 : nt!KeWaitForSingleObject+0×5a6
fffffad8`67f5abf0 fffff800`0102e3fd : fffffade`6b8cf7a0 : nt!NtWaitForSingleObject+0xc1
fffffad8`67f5ac70 00000000`77ef0a2a : 00000000`77efb9a6 : nt!KiSystemServiceCopyEnd+0×3 (TrapFrame @ fffffad8`67f5ac70)
00000000`04d0f098 00000000`77efb9a6 : 00000000`00000000 : ntdll!NtWaitForSingleObject+0xa
00000000`04d0f0a0 00000000`77efba10 : 000007ff`7b8c3500 : ntdll!RtlpWaitOnCriticalSection+0×240
00000000`04d0f120 000007ff`7b887042 : 00000000`04d0f300 : ntdll!RtlEnterCriticalSection+0xa9
[…]
00000000`04d0f190 000007ff`7fe96cc9 : 00000000`00000048 : RPCRT4!Invoke+0×65
00000000`04d0f210 000007ff`7fe9758d : 00000000`04d0f8f0 : RPCRT4!NdrStubCall2+0×54d
00000000`04d0f7d0 000007ff`7fd697b4 : 00000000`0450a8fd : RPCRT4!NdrServerCall2+0×1d
00000000`04d0f800 000007ff`7fd6990d : 00000000`00377aa0 : RPCRT4!DispatchToStubInCNoAvrf+0×14
00000000`04d0f830 000007ff`7fd69766 : 00000000`00000001 : RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×50d
00000000`04d0f9a0 000007ff`7fd6b214 : 00000000`06c18ba0 : RPCRT4!RPC_INTERFACE::DispatchToStub+0×2ec
00000000`04d0fa20 000007ff`7fd6b9e3 : 00000000`06c18ba0 : RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×63b
00000000`04d0fae0 000007ff`7fd7007c : 00000000`048348a0 : RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×3bf
00000000`04d0fba0 000007ff`7fd45369 : 00000000`0525fd30 : RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×710
00000000`04d0feb0 000007ff`7fd65996 : 00000000`00000000 : RPCRT4!RecvLotsaCallsWrapper+0×9
00000000`04d0fee0 000007ff`7fd65d51 : 00000000`0492de90 : RPCRT4!BaseCachedThreadRoutine+0xde
00000000`04d0ff50 00000000`77d6b6da : 00000000`77d6b6a0 : RPCRT4!ThreadStartRoutine+0×21
00000000`04d0ff80 00000000`00000000 : 00000000`00000000 : kernel32!BaseThreadStart+0×3a
We see the thread above is waiting for a critical section and we examine it using !cs WinDbg extension command after switching to the process context of that thread:
6: kd> .process /r /p fffffade6f337040
Implicit process is now fffffade`6f337040
Loading User Symbols
6: kd> !cs 000007ff`7b8c3500
Critical section = 0×000007ff7b8c3500 (DllA!Lock+0×0)
DebugInfo = 0×00000000000ffea0
LOCKED
LockCount = 0×8
WaiterWoken = No
OwningThread = 0×0000000000004100
RecursionCount = 0×1
LockSemaphore = 0×8E0
SpinCount = 0×0000000000000000
From the output we know the critical section owner thread and examine it too (function call arguments are not shown for visual clarity):
6: kd> !thread -t 4100 16
Looking for thread Cid = 4100 …
THREAD fffffade6b9df4f0 Cid 0238.4100 Teb: 000007fffff58000 Win32Thread: 0000000000000000 WAIT: (Unknown) UserMode Non-Alertable
fffffadff5edadc0 Mutant - owning thread fffffadfe2486bf0
Impersonation token: fffffa8010197250 (Level Impersonation)
Owning Process fffffade6f337040 Image: svchost.exe
Wait Start TickCount 79672315 Ticks: 542780 (0:02:21:20.937)
Context Switch Count 174
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0×00000000a75007ac
LPC Server thread working on message Id a75007ac
Start Address kernel32!BaseThreadStart (0×0000000077d6b6a0)
Stack Init fffffad83a94ee00 Current fffffad83a94e950
Base fffffad83a94f000 Limit fffffad83a949000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
Child-SP RetAddr : Call Site
fffffad8`3a94e990 fffff800`01027752 : nt!KiSwapContext+0×85
fffffad8`3a94eb10 fffff800`0102835e : nt!KiSwapThread+0×3c9
fffffad8`3a94eb70 fffff800`0127f03f : nt!KeWaitForSingleObject+0×5a6
fffffad8`3a94ebf0 fffff800`0102e3fd : nt!NtWaitForSingleObject+0xc1
fffffad8`3a94ec70 00000000`77ef0a2a : nt!KiSystemServiceCopyEnd+0×3 (TrapFrame @ fffffad8`3a94ec70)
00000000`03c8efa8 000007ff`7b880427 : ntdll!NtWaitForSingleObject+0xa
[…]
00000000`03c8f1a0 000007ff`7fe96cc9 : RPCRT4!Invoke+0×65
00000000`03c8f210 000007ff`7fe9758d : RPCRT4!NdrStubCall2+0×54d
00000000`03c8f7d0 000007ff`7fd697b4 : RPCRT4!NdrServerCall2+0×1d
00000000`03c8f800 000007ff`7fd6990d : RPCRT4!DispatchToStubInCNoAvrf+0×14
00000000`03c8f830 000007ff`7fd69766 : RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×50d
00000000`03c8f9a0 000007ff`7fd6b214 : RPCRT4!RPC_INTERFACE::DispatchToStub+0×2ec
00000000`03c8fa20 000007ff`7fd6b9e3 : RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×63b
00000000`03c8fae0 000007ff`7fd7007c : RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×3bf
00000000`03c8fba0 000007ff`7fd45369 : RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×710
00000000`03c8feb0 000007ff`7fd65996 : RPCRT4!RecvLotsaCallsWrapper+0×9
00000000`03c8fee0 000007ff`7fd65d51 : RPCRT4!BaseCachedThreadRoutine+0xde
00000000`03c8ff50 00000000`77d6b6da : RPCRT4!ThreadStartRoutine+0×21
00000000`03c8ff80 00000000`00000000 : kernel32!BaseThreadStart+0×3a
We see that it is waiting for a mutant and examine its owner thread:
6: kd> !thread fffffadfe2486bf0 16
THREAD fffffadfe2486bf0 Cid 0238.7010 Teb: 000007fffff5e000 Win32Thread: 0000000000000000 WAIT: (Unknown) UserMode Non-Alertable
fffffadfe2486f58 Semaphore Limit 0x1
Waiting for reply to LPC MessageId a7507485:
Current LPC port fffffa8006822c80
Not impersonating
DeviceMap fffffa8000003790
Owning Process fffffade6f337040 Image: svchost.exe
Wait Start TickCount 79744596 Ticks: 470499 (0:02:02:31.546)
Context Switch Count 29636
UserTime 00:00:00.062
KernelTime 00:00:00.156
Win32 Start Address 0×00000000a74ff6e4
LPC Server thread working on message Id a74ff6e4
Start Address kernel32!BaseThreadStart (0×0000000077d6b6a0)
Stack Init fffffad7d98a0e00 Current fffffad7d98a08e0
Base fffffad7d98a1000 Limit fffffad7d989b000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
Child-SP RetAddr : Call Site
fffffad7`d98a0920 fffff800`01027752 : nt!KiSwapContext+0×85
fffffad7`d98a0aa0 fffff800`0102835e : nt!KiSwapThread+0×3c9
fffffad7`d98a0b00 fffff800`01283ebb : nt!KeWaitForSingleObject+0×5a6
fffffad7`d98a0b80 fffff800`0102e3fd : nt!NtRequestWaitReplyPort+0xa60
fffffad7`d98a0c70 00000000`77ef0c0a : nt!KiSystemServiceCopyEnd+0×3 (TrapFrame @ fffffad7`d98a0c70)
00000000`0430dc18 000007ff`7fd6df46 : ntdll!ZwRequestWaitReplyPort+0xa
00000000`0430dc20 000007ff`7fd6e17f : RPCRT4!LRPC_CCALL::SendReceive+0×447
00000000`0430dd10 000007ff`7fe974c8 : RPCRT4!NdrSendReceive+0xf6
00000000`0430dd40 000007ff`7fe975bd : RPCRT4!NdrpClientCall2+0×7e2
00000000`0430e320 00000000`676b1dd7 : RPCRT4!NdrClientCall2+0×1d
[…]
The thread above is waiting for an LPC message and we examine its corresponding server thread:
6: kd> !lpc message a7507485
Searching message a7507485 in threads ...
Client thread fffffadfe2486bf0 waiting a reply from a7507485
Server thread fffffade6f3c9720 is working on message a7507485
[...]
6: kd> !thread fffffade6f3c9720 16
THREAD fffffade6f3c9720 Cid 6308.a1c8 Teb: 000000007ef24000 Win32Thread: 0000000000000000 WAIT: (Unknown) UserMode Non-Alertable
fffffade68d31a40 SynchronizationEvent
Not impersonating
DeviceMap fffffa80016ce1b0
Owning Process fffffade69c29430 Image: AppA.exe
Wait Start TickCount 79744596 Ticks: 470499 (0:02:02:31.546)
Context Switch Count 7230
UserTime 00:00:00.218
KernelTime 00:00:00.109
Win32 Start Address 0×00000000a7507485
LPC Server thread working on message Id a7507485
Start Address kernel32!BaseThreadStartThunk (0×000000007d4d1504)
Stack Init fffffad83f7e4e00 Current fffffad83f7e4950
Base fffffad83f7e5000 Limit fffffad83f7df000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
Child-SP RetAddr : Call Site
fffffad8`3f7e4990 fffff800`01027752 : nt!KiSwapContext+0×85
fffffad8`3f7e4b10 fffff800`0102835e : nt!KiSwapThread+0×3c9
fffffad8`3f7e4b70 fffff800`0127f03f : nt!KeWaitForSingleObject+0×5a6
fffffad8`3f7e4bf0 fffff800`0102e3fd : nt!NtWaitForSingleObject+0xc1
fffffad8`3f7e4c70 00000000`78b842d9 : nt!KiSystemServiceCopyEnd+0×3 (TrapFrame @ fffffad8`3f7e4c70)
00000000`0257f108 00000000`78b840e5 : wow64cpu!CpupSyscallStub+0×9
00000000`0257f110 00000000`6b006a5a : wow64cpu!Thunk0ArgReloadState+0×1a
00000000`0257f180 00000000`6b005e0d : wow64!RunCpuSimulation+0xa
00000000`0257f1b0 00000000`77f109f0 : wow64!Wow64LdrpInitialize+0×2ed
00000000`0257f6f0 00000000`77ef30a5 : ntdll!LdrpInitialize+0×2aa
00000000`0257f7d0 00000000`7d4d1504 : ntdll!KiUserApcDispatcher+0×15 (TrapFrame @ 00000000`0257fb38)
00000000`0257fcc8 00000000`00000000 : kernel32!BaseThreadStartThunk
We see the thread belongs to a virtualized WOW64 process and presently I’m not aware of how to get its 32-bit stacks from complete memory dumps. WOW64 extensions seems only working in process user dumps. Therefore I recommended to get a userdump of AppA process using 32-bit version of userdump.exe as soon as the same condition starts surfacing again.
- Dmitry Vostokov @ DumpAnalysis.org -
Some people asked about OpenTask publishing terms:
It is a well-known fact that average book is sold in no more than 100 copies. It is considered good if a book is sold in 300 copies per year which should break even with offset printing costs for several thousand copies. Print on demand is more economic but still there are costs to allocate an ISBN number and set up a title (about 100 USD), annual catalog maintenance fee of 10 - 15 USD per year, Ingram catalog advertisement fee of 50 USD, and a legal deposit book copy to British Library. Any title revision amounts to another 50 - 100 USD. A proof copy costs 20 - 50 USD. Therefore initial setup costs amount to 150 - 200 USD. Because OpenTask publisher is growing and wants to attract authors it offers the best possible terms for accepted book proposals that also balance publisher’s risks. After setup costs and annual catalog maintenance fee are covered by book sales an author gets 90% of the following sum - VAT: retail price - wholesale discount - printing costs (*). In return for 10% OpenTask offers extensive advertisment on affiliated books, magazines, blogs and portals. An author retains all copyright and OpenTask gets non-exclusive publishing rights. OpenTask accepts book proposals in various forms from initial conception without a sample chapter to complete manuscripts but at this time most of editing, proofreading and cover design must be done by authors unless a title has potential market opportunities and OpenTask helps with interior editing, formatting, proofreading and cover design and then bills them from future book sales. OpenTask works with leading industry distributors to make books available on Amazon, Barnes&Noble and other booksellers worldwide. If authors want to order copies of the book for independent distribution or give away signed copies they only pay printing, delivery and handling fees from a factory (**).
(*) Example: 6 x 9 (15.2 x 22.9) B&W perfect paperback book of 256 pages with full color cover costs 4.23 USD to print. If a retail price is 20 USD and standard industry distributor discount is 55%, then the author’s compensation per sale is 4.29 USD. If VAT is 20% the author gets 3.43 USD. Assuming that the title setup, annual maintenance fee and proof copy costs are 175 USD the auther receive his compensation after 40 book sales.
(**) Assuming that the cost of printing a book is 4.23 USD (*) and the author wants to order 25 books for independent distrubution the cost is 25*4.23 + delivery and handling fees (standard or express post rates apply).
Source: http://www.opentask.com/publishing-terms
- Dmitry Vostokov @ DumpAnalysis.org -
Now its time to write about wait chains involving LPC calls. These chains are easily identified by searching for “Waiting for reply to LPC MessageId” in the output of !process 0 ff command or if we know that some specific process is hanging and see that message in its thread information output. For example, in one kernel memory dump taken when AppA was hanging we see this example of Blocked Thread pattern:
7: kd> !process 88556778 ff
PROCESS 88556778 SessionId: 0 Cid: 1f88 Peb: 7ffdc000 ParentCid: 0f74
DirBase: 96460000 ObjectTable: e65a5348 HandleCount: 80.
Image: AppA.exe
VadRoot 870d2208 Vads 54 Clone 0 Private 234. Modified 0. Locked 0.
DeviceMap e22ba7c0
Token e5e47cf0
ElapsedTime 00:04:44.017
UserTime 00:00:00.000
KernelTime 00:00:00.000
QuotaPoolUsage[PagedPool] 20092
QuotaPoolUsage[NonPagedPool] 2160
Working Set Sizes (now,min,max) (748, 50, 345) (2992KB, 200KB, 1380KB)
PeakWorkingSetSize 748
VirtualSize 16 Mb
PeakVirtualSize 16 Mb
PageFaultCount 810
MemoryPriority BACKGROUND
BasePriority 8
CommitCharge 252
PEB NULL...
THREAD 8861aab8 Cid 1f88.1bd4 Teb: 7ffdf000 Win32Thread: bc161ea8 WAIT: (Unknown) UserMode Non-Alertable
8861aca4 Semaphore Limit 0x1
Waiting for reply to LPC MessageId 00037bb2:
Current LPC port e625bbd0
Not impersonating
DeviceMap e22ba7c0
Owning Process 88556778 Image: AppA.exe
Wait Start TickCount 426549 Ticks: 18176 (0:00:04:44.000)
Context Switch Count 76 LargeStack
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0×010043ab
Start Address 0×77e617f8
Stack Init bab4b000 Current bab4ac08 Base bab4b000 Limit bab47000 Call 0
Priority 11 BasePriority 8 PriorityDecrement 2
Kernel stack not resident.
ChildEBP RetAddr
bab4ac20 8083d5b1 nt!KiSwapContext+0×26
bab4ac4c 8083df9e nt!KiSwapThread+0×2e5
bab4ac94 8093eda1 nt!KeWaitForSingleObject+0×346
bab4ad50 80833bef nt!NtRequestWaitReplyPort+0×776
bab4ad50 7c8285ec nt!KiFastCallEntry+0xfc
Now we look for a server thread processing the message 00037bb2:
7: kd> !lpc message 00037bb2
Searching message 37bb2 in threads ...
Server thread 89815db0 is working on message 37bb2
Client thread 8861aab8 waiting a reply from 37bb2
Searching thread 8861aab8 in port rundown queues …
Server communication port 0xe1216be8
Handles: 1 References: 1
The LpcDataInfoChainHead queue is empty
Connected port: 0xe625bbd0 Server connection port: 0xe1323f68
Client communication port 0xe625bbd0
Handles: 1 References: 2
The LpcDataInfoChainHead queue is empty
Server connection port e1323f68 Name: ApiABC
Handles: 1 References: 43
Server process : 887d32d0 (svchost.exe)
Queue semaphore : 884df210
Semaphore state 0 (0x0)
The message queue is empty
Messages in LpcDataInfoChainHead:
0000 e6067418 - Busy Id=00020695 From: 0224.134c Context=80050003 [e1323fe8 . e65fa5a8]
Length=0044002c Type=00380001 (LPC_REQUEST)
Data: 00000001 00050242 00000000 00000000 00000000 00000000
0000 e65fa5a8 - Busy Id=0002e1dd From: 0fd8.0fe0 Context=80110002 [e6067418 . e5f6a360]
Length=0044002c Type=00380001 (LPC_REQUEST)
Data: 00000001 00050242 c03007fc c01fff7c 00000000 80a84456
0000 e5f6a360 - Busy Id=00037bb2 From: 1f88.1bd4 Context=8017000f [e65fa5a8 . e1323fe8]
Length=0044002c Type=00380001 (LPC_REQUEST)
Data: 00000001 00050242 88572278 88572290 8a386990 000015e7
The LpcDataInfoChainHead queue contains 3 messages
Threads in RunDown queue : 0xe6067258 0xe65fa3e8 0xe5f6a1a0
Done.
7: kd> !thread 89815db0
THREAD 89815db0 Cid 1218.0c00 Teb: 7ff8f000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
88603e40 Mutant - owning thread 884d7db0
Not impersonating
DeviceMap e10018b8
Owning Process 887d32d0 Image: svchost.exe
Wait Start TickCount 426549 Ticks: 18176 (0:00:04:44.000)
Context Switch Count 42
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0×00037bb2
LPC Server thread working on message Id 37bb2
Start Address 0×77e617ec
Stack Init f60e0000 Current f60dfc60 Base f60e0000 Limit f60dd000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr Args to Child
f60dfc78 8083d5b1 89815db0 89815e58 00000006 nt!KiSwapContext+0×26
f60dfca4 8083df9e 00000000 00000000 00000000 nt!KiSwapThread+0×2e5
f60dfcec 8092ae57 88603e40 00000006 00000001 nt!KeWaitForSingleObject+0×346
f60dfd50 80833bef 000004fc 00000000 00000000 nt!NtWaitForSingleObject+0×9a
f60dfd50 7c8285ec 000004fc 00000000 00000000 nt!KiFastCallEntry+0xfc
We see that it is blocked waiting for a synchronization object (mutant, shown in magenta above) and we check the thread 884d7db0 that owns it:
7: kd> !thread 884d7db0
THREAD 884d7db0 Cid 1218.12ec Teb: 7ffdd000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
884d7f9c Semaphore Limit 0x1
Waiting for reply to LPC MessageId 0000fa9e:
Current LPC port e121fdb8
Not impersonating
DeviceMap e10018b8
Owning Process 887d32d0 Image: svchost.exe
Wait Start TickCount 11800 Ticks: 432925 (0:01:52:44.453)
Context Switch Count 111
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0×0000fa9b
LPC Server thread working on message Id fa9b
Start Address 0×77e617ec
Stack Init f4598000 Current f4597c08 Base f4598000 Limit f4595000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr Args to Child
f4597c20 8083d5b1 884d7db0 884d7e58 00000007 nt!KiSwapContext+0×26
f4597c4c 8083df9e 884d7f9c 884d7f70 884d7db0 nt!KiSwapThread+0×2e5
f4597c94 8093eda1 884d7f9c 00000011 80930901 nt!KeWaitForSingleObject+0×346
f4597d50 80833bef 00000560 000ebfe0 000ebfe0 nt!NtRequestWaitReplyPort+0×776
f4597d50 7c8285ec 00000560 000ebfe0 000ebfe0 nt!KiFastCallEntry+0xfc
The thread is waiting for the LPC message 0000fa9e and we look for a server thread processing it:
7: kd> !thread 898c6db0
THREAD 898c6db0 Cid 0b38.188c Teb: 7ff4d000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
884362c8 SynchronizationEvent
Not impersonating
DeviceMap e11399e8
Owning Process 88340758 Image: AppB.exe
Wait Start TickCount 11801 Ticks: 432924 (0:01:52:44.437)
Context Switch Count 7
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0x0000fa9e
LPC Server thread working on message Id fa9e
Start Address 0x77e617ec
Stack Init f5138000 Current f5137c60 Base f5138000 Limit f5135000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr Args to Child
f5137c78 8083d5b1 898c6db0 898c6e58 00000006 nt!KiSwapContext+0x26
f5137ca4 8083df9e 00000000 00000000 00000000 nt!KiSwapThread+0x2e5
f5137cec 8092ae57 884362c8 00000006 00000001 nt!KeWaitForSingleObject+0x346
f5137d50 80833bef 0000056c 00000000 00000000 nt!NtWaitForSingleObject+0x9a
f5137d50 7c8285ec 0000056c 00000000 00000000 nt!KiFastCallEntry+0xfc
We also see that the thread 884d7db0 was working on message fa9b (shown in blue above) and therefore we can find its client thread:
7: kd> !lpc message fa9b
Searching message fa9b in threads ...
Server thread 884d7db0 is working on message fa9b
Client thread 871ab9a0 waiting a reply from fa9b
Searching thread 871ab9a0 in port rundown queues …
Server communication port 0xe23f68b8
Handles: 1 References: 1
The LpcDataInfoChainHead queue is empty
Connected port: 0xe1325c10 Server connection port: 0xe1323f68
Client communication port 0xe1325c10
Handles: 1 References: 2
The LpcDataInfoChainHead queue is empty
Server connection port e1323f68 Name: ApiABC
Handles: 1 References: 43
Server process : 887d32d0 (svchost.exe)
Queue semaphore : 884df210
Semaphore state 0 (0x0)
The message queue is empty
Messages in LpcDataInfoChainHead:
0000 e6067418 - Busy Id=00020695 From: 0224.134c Context=80050003 [e1323fe8 . e65fa5a8]
Length=0044002c Type=00380001 (LPC_REQUEST)
Data: 00000001 00050242 00000000 00000000 00000000 00000000
0000 e65fa5a8 - Busy Id=0002e1dd From: 0fd8.0fe0 Context=80110002 [e6067418 . e5f6a360]
Length=0044002c Type=00380001 (LPC_REQUEST)
Data: 00000001 00050242 c03007fc c01fff7c 00000000 80a84456
0000 e5f6a360 - Busy Id=00037bb2 From: 1f88.1bd4 Context=8017000f [e65fa5a8 . e1323fe8]
Length=0044002c Type=00380001 (LPC_REQUEST)
Data: 00000001 00050242 88572278 88572290 8a386990 000015e7
The LpcDataInfoChainHead queue contains 3 messages
Threads in RunDown queue : 0xe6067258 0xe65fa3e8 0xe5f6a1a0
Done.
7: kd> !thread 871ab9a0
THREAD 871ab9a0 Cid 180c.1810 Teb: 7ffdf000 Win32Thread: bc011008 WAIT: (Unknown) UserMode Non-Alertable
871abb8c Semaphore Limit 0x1
Waiting for reply to LPC MessageId 0000fa9b:
Current LPC port e1325c10
Not impersonating
DeviceMap e10018b8
Owning Process 8963c388 Image: AppC.exe
Wait Start TickCount 11796 Ticks: 432929 (0:01:52:44.515)
Context Switch Count 540 LargeStack
UserTime 00:00:00.046
KernelTime 00:00:00.062
Start Address 0x0103e1b0
Stack Init f68a4000 Current f68a3c08 Base f68a4000 Limit f689f000 Call 0
Priority 15 BasePriority 15 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr Args to Child
f68a3c20 8083d5b1 871ab9a0 871aba48 00000004 nt!KiSwapContext+0x26
f68a3c4c 8083df9e 871abb8c 871abb60 871ab9a0 nt!KiSwapThread+0x2e5
f68a3c94 8093eda1 871abb8c 00000011 e24f0401 nt!KeWaitForSingleObject+0x346
f68a3d50 80833bef 00000150 0007fc70 0007fc70 nt!NtRequestWaitReplyPort+0x776
f68a3d50 7c8285ec 00000150 0007fc70 0007fc70 nt!KiFastCallEntry+0xfc
Finally we can draw this wait chain diagram where LPC calls are shown as red arrows:
- Dmitry Vostokov @ DumpAnalysis.org -
Every day a new religion appears on Earth and now my turn to announce Memory Religion with several tentative names:
Memorianism
Memorianity
Memoriandom
One of the attractive features of this religion is eternal immortality through memory of our universe. The current understanding of that employs memoidealistic notion of memuonic memory that comprises the philosophy of memoidealism.
I made a leap of faith yesterday and now consider myself as a true believer! Hope other people will follow soon. As every major religion it also has its testament book to be published:
Title: Memory Religion: A Testament
ISBN-13: 978-1906717476
- Dmitry Vostokov @ DumpAnalysis.org -
Sometimes a memory dump is not useful because of missing memory space, hence the name of this anti-pattern: Missing Space. This usually happens for non-bugcheck type issues like CPU spikes, application or session hangs where user space analysis is needed. Here is an example of Spiking Thread pattern in a kernel memory dump where analysis cannot be done because threads were spiking mostly in user space not included in kernel memory dumps:
Loading Dump File [MEMORY.DMP]
Kernel Summary Dump File: Only kernel address space is available
1: kd> !running
System Processors 3 (affinity mask)
Idle Processors 0
Prcb Current Next
0 ffdff120 88d14b40 ................
1 f7737120 891dddb0 ................
1: kd> !thread 88d14b40
THREAD 88d14b40 Cid 02b0.5298 Teb: 7ff7b000 Win32Thread: 00000000 RUNNING on processor 0
IRP List:
87e3ad50: (0006,0094) Flags: 00000900 Mdl: 00000000
8a8485f8: (0006,0094) Flags: 00000900 Mdl: 00000000
Not impersonating
DeviceMap e1001878
Owning Process 8a9831a8 Image: ApplicationA.exe
Wait Start TickCount 1282379 Ticks: 0
Context Switch Count 2950
UserTime 00:00:15.109
KernelTime 00:00:00.125
Win32 Start Address 0×77c7b0f5
Start Address 0×77e617ec
Stack Init ae302000 Current ae301c38 Base ae302000 Limit ae2ff000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr Args to Child
0269fd6c 00000000 00000000 00000000 00000000 0×77e61684
1: kd> !thread 891dddb0
THREAD 891dddb0 Cid 2de4.3f58 Teb: 7ffd8000 Win32Thread: bc487c18 RUNNING on processor 1
Not impersonating
DeviceMap e6aba8b0
Owning Process 88b50d88 Image: ApplicationB.exe
Wait Start TickCount 1282379 Ticks: 0
Context Switch Count 46241 LargeStack
UserTime 00:00:35.296
KernelTime 00:00:06.656
Win32 Start Address 0×0b80e53c
Start Address 0×77e617ec
Stack Init b234c000 Current b234bd00 Base b234c000 Limit b2346000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr Args to Child
b234bcc8 f65c0532 000000e2 00000000 00000000 nt!KeBugCheckEx+0×1b
b234bcf8 f65bfd2c 00866d40 bbf000c6 00000000 i8042prt!I8xProcessCrashDump+0×256
b234bd40 808395a5 8a107c28 8a866c88 0101000a i8042prt!I8042KeyboardInterruptService+0×225
b234bd40 432de484 8a107c28 8a866c88 0101000a nt!KiInterruptDispatch+0×49
WARNING: Frame IP not in any known module. Following frames may be wrong.
01bbf150 00000000 00000000 00000000 00000000 0×432de484
The solution here is to request either a complete memory dump or user dumps of identified processes. The former was requested already but the crash dump type in Control Panel was not checked before forcing the dump of the system via standard keyboard method. Therefore this is also an instance of Wrong Dump anti-pattern.
- Dmitry Vostokov @ DumpAnalysis.org -
Recently I was asked how to measure complexity of technical support cases especially ones that require memory dump analysis. My first response was that it is a subjective qualitative measure based mostly on experience and feeling. However after careful consideration I understood that nothing has changed for the last 5 years: the nature and causes of system or application hangs and crashes still the same regardless of OS types and versions. Therefore the complexity measure shifts from a case description and its artifacts to an analyst, a memory dump reader. Here the number of queries, questions asked or commands executed to gather information for analysis, can be a good approximation to the measure of complexity. For example, 5 years ago I started with a few commands like !analyze -v, kv and dd and progressed to an elaborate checklist. Here the natural logarithm can be used to approximate the measure:
C = ln (Ndc), where Ndc is the number of debugging commands used.
Initially the complexity was ln(3) ≈ 1.1 and now if someone uses 10 commands on average or asks 10 questions the complexity is ln(10) ≈ 2.3. The analysis is more than 2 times complex than it was.
- Dmitry Vostokov @ DumpAnalysis.org -
I noticed that Amazon sells used copies of my Curriculum Vitae:
- Dmitry Vostokov @ DumpAnalysis.org -
OpenTask publishes the following sequel to Resume and CV book:
Title: Salary Figures: A Codebook of Expectations
Author: Dmitry Vostokov
ISBN-13: 978-1906717469
Paperback: 100 pages (1 January 2009)
Product Dimensions: 20.3 x 12.7
Book Annotation: After publishing Curriculum Vitae as a book the author started receiving e-mails asking for his salary expectation. Being shy to discuss such matters openly he devised a codebook of salaries. Now everyone could answer a question about his or her salary expectations by referring to specific page. Also colleagues and friends could say to each other: “I’m still on page X” or “Last month I turned the page Y over”. The last 10 pages of the codebook specify various perks. The response template to the question of salary expectations is: “My salary expectation is on page Z plus benefits listed on pages N and M”. (*) X,Y,Z,N,M are page numbers from 3 to 100. Good luck with job hunting 
Typeset in Chilling font the book is suitable for wide salary ranges, from 1,000 to 1,000,000.
- Dmitry Vostokov @ DumpAnalysis.org -
I’ve written 10 pattern-driven crash dump analysis case studies so far and now put them on one page:
More case studies will be added in the future.
- Dmitry Vostokov @ DumpAnalysis.org -
Once upon a time I was analyzing a memory dump and in the process become upset. I realized that the dump was vacuous and afterwards learnt that the customer forced the dump of a normal system with steady-state computational activities inside. At the same time computational precognition, the ability to see in advance what would happen with the system, always fascinated me from the very beginning of my memory dump analysis work. In computational precognition phrase, the word “computational” refers to computers and “precognition” refers to humans but this should not be the problem as the boundary between these two categories is not sharp and can be shifted in either direction. This is an opening of the new post series about investigation of occult, paranormal and supernatural in the realm of computable. In short, about psi-computation.
- Dmitry Vostokov @ DumpAnalysis.org -
Finally previously announced full-color coffee table book is on sale:
DLL List Landscape: The Art from Computer Memory Space
Memory Dump Analysis Anthology, Volume 1 and Volume 2 have numerous articles related to computer memory visualization techniques using Dump2Picture and Microsoft debugger WinDbg.
I’m also working on Computer Memory Visualization book together with Jamie Fenton that was originally conceived as a coffee table book for general readers but now becomes more software engineering and science oriented the more I work on it. Coffee table status now comes to DLL List Landscape book.
- Dmitry Vostokov @ DumpAnalysis.org -
Crash “must be distinguished from” hang “with which it is often confounded.”
Sydney Smith, A Memoir of the Reverend Sydney Smith by his daughter, Lady Holland, with a Selection from his Letters
- Dmitry Vostokov @ DumpAnalysis.org -
