Archive for the ‘Horrors of Computation’ Category

Crash Dump Analysis Patterns (Part 182)

Tuesday, October 9th, 2012

This is a new pattern that we call Error Reporting Fault. It’s about the faults in error reporting infrastructure. The latter should be guarded against such faults and avoid recursion. Here is a summary example of such a pattern on Windows platforms that involve Windows Error Reporting (WER).

In a complete memory dump we notice thousands of WerFault.exe processes:

0: kd> !process 0 0
[...]
PROCESS fffffa8058010380
SessionId: 2  Cid: 488f0    Peb: 7efdf000  ParentCid: 27cb8
DirBase: 25640c000  ObjectTable: fffff8a06cd2ac50  HandleCount:  54.
Image: WerFault.exe

PROCESS fffffa805bbd5970
SessionId: 2  Cid: 4801c    Peb: 7efdf000  ParentCid: 27cb8
DirBase: 2c3f69000  ObjectTable: fffff8a040563af0  HandleCount:  54.
Image: WerFault.exe

PROCESS fffffa8078aec060
SessionId: 2  Cid: 3feac    Peb: 7efdf000  ParentCid: 488f0
DirBase: abd200000  ObjectTable: fffff8a07851a0a0  HandleCount:  59.
Image: WerFault.exe

PROCESS fffffa805bbe9a10
SessionId: 2  Cid: 3d8b8    Peb: 7efdf000  ParentCid: 4801c
DirBase: 261f91000  ObjectTable: fffff8a02d864d40  HandleCount:  56.
Image: WerFault.exe

PROCESS fffffa805bd29060
SessionId: 2  Cid: 1142c    Peb: 7efdf000  ParentCid: 3feac
DirBase: 429fb3000  ObjectTable: fffff8a0355b42e0  HandleCount:  58.
Image: WerFault.exe

PROCESS fffffa8053d853d0
SessionId: 2  Cid: 1fc4c    Peb: 7efdf000  ParentCid: 3d8b8
DirBase: 714371000  ObjectTable: fffff8a01cb6bba0  HandleCount:  58.
Image: WerFault.exe
[...]

Each process has only one thread running through WOW64 modules so we get its 32-bit stack trace:

0: kd> !process fffffa8075c21b30 ff
[...]
THREAD fffffa807c183b60 Cid 2d3c8.4334c Teb: 000000007efdb000 Win32Thread: fffff900c3f71010 WAIT: (UserRequest) UserMode Non-Alertable
[...]

0: kd> .load wow64exts

0: kd> .process /r /p fffffa8075c21b30
Implicit process is now fffffa80`75c21b30
Loading User Symbols
Loading Wow64 Symbols

0: kd> .thread /w fffffa807c183b60
Implicit thread is now fffffa80`7c183b60
x86 context set

0: kd:x86> k
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP          RetAddr
000bf474 77080bdd ntdll!ZwWaitForMultipleObjects+0x15
000bf510 76bb1a2c KERNELBASE!WaitForMultipleObjectsEx+0x100
000bf558 76bb4208 kernel32!WaitForMultipleObjectsExImplementation+0xe0
000bf574 76bd80a4 kernel32!WaitForMultipleObjects+0x18
000bf5e0 76bd7f63 kernel32!WerpReportFaultInternal+0x186
000bf5f4 76bd7858 kernel32!WerpReportFault+0x70
000bf604 76bd77d7 kernel32!BasepReportFault+0x20
000bf690 776674df kernel32!UnhandledExceptionFilter+0x1af
000bf698 776673bc ntdll!__RtlUserThreadStart+0x62
000bf6ac 77667261 ntdll!_EH4_CallFilterFunc+0x12
000bf6d4 7764b459 ntdll!_except_handler4+0x8e
000bf6f8 7764b42b ntdll!ExecuteHandler2+0x26
000bf71c 7764b3ce ntdll!ExecuteHandler+0x24
000bf7a8 77600133 ntdll!RtlDispatchException+0x127
000bf7b4 000bf7c0 ntdll!KiUserExceptionDispatcher+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
000bfb00 77629ef2 0xbf7c0
[…]

We find exception processing and code on stack (return address belongs to stack range). This thread is waiting for another process and it is WerFault.exe too:

0: kd:x86> .effmach AMD64

0: kd> !process fffffa8075c21b30 ff
[...]
THREAD fffffa807c183b60 Cid 2d3c8.4334c Teb: 000000007efdb000 Win32Thread: fffff900c3f71010 WAIT: (UserRequest) UserMode Non-Alertable
fffffa80809c44e0 ProcessObject
[…]

0: kd> !process fffffa80809c44e0
PROCESS fffffa80809c44e0
SessionId: 2  Cid: 33844    Peb: 7efdf000  ParentCid: 2d3c8
DirBase: 9c53f0000  ObjectTable: fffff8a0423d4170  HandleCount: 978.
Image: WerFault.exe
[...]

We go back to our original WerFault process and in its PEB data we find it was called to report a fault from another process with PID 0n189240:

0: kd> !process fffffa8075c21b30 ff
[...]
CommandLine:  'C:\Windows\SysWOW64\WerFault.exe -u -p 189240 -s 3888′
[…]

And it’s WerFault.exe too:

0: kd> !process 0n189240
Searching for Process with Cid == 2e338

PROCESS fffffa8078b659e0
SessionId: 2  Cid: 2e338    Peb: 7efdf000  ParentCid: 47608
DirBase: 201796000  ObjectTable: fffff8a02e664380  HandleCount: 974.
Image: WerFault.exe
[...]

So we see a chain of WerFault.exe processes each processing a fault in the previous one. So there should be a first fault somewhere which we can find in stack trace collection (32-bit stack traces for this example) unless that exception stack trace was paged out due to insufficient memory occupied by WerFault.exe processes.

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

Computer Memory Monsters (Part 1)

Wednesday, May 11th, 2011

In this series we start with our analysis of monsters in the realm of computer memory, software defects, malware, corrupt software structures and their various behaviour. Some of monsters are based on exaggerated crash dump and software trace patterns, some are based on the accumulated debugging and technical support wisdom. The first monster we present today is called Chimera and it lives in DLL Hell. It is based on a exaggerated pattern called Module Variety. When opening a 64-bit memory dump it shows several pages of modules (lm WinDbg command):

 

As the monster’s creator explained to me they used an experimental way to represent every class object as a loaded component. And it was a word processor where every paragraph, every sentence, every word and every letter was an object implemented in a separate module! The goal was to have any letter literally dance on a screen if necessary.

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

Hot Computation: Memory On Fire

Tuesday, August 17th, 2010

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

Modern Memory Dump and Software Trace Analysis: Volumes 1-3

Sunday, April 18th, 2010

OpenTask to offer first 3 volumes of Memory Dump Analysis Anthology in one set:

The set is available exclusively from OpenTask e-Commerce web site starting from June. Individual volumes are also available from Amazon, Barnes & Noble and other bookstores worldwide.

Product information:

  • Title: Modern Memory Dump and Software Trace Analysis: Volumes 1-3
  • Author: Dmitry Vostokov
  • Language: English
  • Product Dimensions: 22.86 x 15.24
  • Paperback: 1600 pages
  • Publisher: Opentask (31 May 2010)
  • ISBN-13: 978-1-906717-99-5

Information about individual volumes:

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

Forthcoming Memory Dump Analysis Anthology, Volume 4

Thursday, February 11th, 2010

This is a revised, edited, cross-referenced and thematically organized volume of selected DumpAnalysis.org blog posts about crash dump analysis and debugging written in July 2009 - January 2010 for software engineers developing and maintaining products on Windows platforms, quality assurance engineers testing software on Windows platforms and technical support and escalation engineers dealing with complex software issues. The fourth volume features:

- 13 new crash dump analysis patterns
- 13 new pattern interaction case studies
- 10 new trace analysis patterns
- 6 new Debugware patterns and case study
- Workaround patterns
- Updated checklist
- Fully cross-referenced with Volume 1, Volume 2 and Volume 3
- New appendixes

Product information:

  • Title: Memory Dump Analysis Anthology, Volume 4
  • Author: Dmitry Vostokov
  • Language: English
  • Product Dimensions: 22.86 x 15.24
  • Paperback: 410 pages
  • Publisher: Opentask (30 March 2010)
  • ISBN-13: 978-1-906717-86-5
  • Hardcover: 410 pages
  • Publisher: Opentask (30 April 2010)
  • ISBN-13: 978-1-906717-87-2

Back cover features memory space art image: Internal Process Combustion.

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

Memory Dump Analysis Anthology, Volume 3

Sunday, December 20th, 2009

“Memory dumps are facts.”

I’m very excited to announce that Volume 3 is available in paperback, hardcover and digital editions:

Memory Dump Analysis Anthology, Volume 3

Table of Contents

In two weeks paperback edition should also appear on Amazon and other bookstores. Amazon hardcover edition is planned to be available in January 2010.

The amount of information was so voluminous that I had to split the originally planned volume into two. Volume 4 should appear by the middle of February together with Color Supplement for Volumes 1-4. 

- Dmitry Vostokov @ DumpAnalysis.org -

Music for Debugging: The Memory Dump of the Dead

Wednesday, November 25th, 2009

Highly recommended to listen during analysis of a complete memory dump from an isolated dead system to build tension resulting in a problem resolution in 21 minutes:

Rachmaninov: Symphonic Dances & the Isle of the Dead

Buy from Amazon

- Dmitry Vostokov @ DumpAnalysis.org -

Forthcoming Memory Dump Analysis Anthology, Volume 3

Saturday, September 26th, 2009

This is a revised, edited, cross-referenced and thematically organized volume of selected DumpAnalysis.org blog posts about crash dump analysis and debugging written in October 2008 - June 2009 for software engineers developing and maintaining products on Windows platforms, quality assurance engineers testing software on Windows platforms and technical support and escalation engineers dealing with complex software issues. The third volume features:

- 15 new crash dump analysis patterns
- 29 new pattern interaction case studies
- Trace analysis patterns
- Updated checklist
- Fully cross-referenced with Volume 1 and Volume 2
- New appendixes

Product information:

  • Title: Memory Dump Analysis Anthology, Volume 3
  • Author: Dmitry Vostokov
  • Language: English
  • Product Dimensions: 22.86 x 15.24
  • Paperback: 404 pages
  • Publisher: Opentask (20 December 2009)
  • ISBN-13: 978-1-906717-43-8
  • Hardcover: 404 pages
  • Publisher: Opentask (30 January 2010)
  • ISBN-13: 978-1-906717-44-5

Back cover features 3D computer memory visualization image.

- Dmitry Vostokov @ DumpAnalysis.org -

ALPC wait chain, missing threads, message box, zombie and special processes: pattern cooperation

Friday, September 18th, 2009

The purpose of this case study is to show how to choose what to include in a fiber bundle memory dump when x64 complete memory dumps are huge and not an option to deliver:

1: kd> !vm

*** Virtual Memory Usage ***
 Physical Memory:     5880464 (   23521856 Kb)
[…]

The dump we have is a kernel. When we dump all processes and threads and look for “Waiting for ” we find many ALPC wait chains spanning 3 - 4 processes (sometimes semicircular), sometimes originated from processes with missing threads (just one or two present threads when we expect a dozen of them in a normal state):

1: kd> !process fffffa800b834c10
PROCESS fffffa800b834c10
    SessionId: 205  Cid: 13c40    Peb: 7fffffdb000  ParentCid: 133c0
    DirBase: 13b61d000  ObjectTable: fffff8800c2295b0  HandleCount:  58.
    Image: ProcessA.exe
    VadRoot fffffa8007d70c00 Vads 121 Clone 0 Private 497. Modified 0. Locked 0.
    DeviceMap fffff88000007450
    Token                             fffff8800c695560
    ElapsedTime                       00:03:42.083
    UserTime                          00:00:00.000
    KernelTime                        00:00:00.000
    QuotaPoolUsage[PagedPool]         65968
    QuotaPoolUsage[NonPagedPool]      11520
    Working Set Sizes (now,min,max)  (1274, 50, 345) (5096KB, 200KB, 1380KB)
    PeakWorkingSetSize                1278
    VirtualSize                       37 Mb
    PeakVirtualSize                   38 Mb
    PageFaultCount                    1286
    MemoryPriority                    BACKGROUND
    BasePriority                      13
    CommitCharge                      581

THREAD fffffa800b845bb0  Cid 13c40.1332c  Teb: 000007fffffde000 Win32Thread: fffff900c0076010 WAIT: (WrLpcReply) UserMode Non-Alertable
    fffffa800b845f40  Semaphore Limit 0x1
Waiting for reply to ALPC Message fffff88012527770 : queued at port fffffa80055bca60 : owned by process fffffa80054dfc10
Not impersonating
DeviceMap                 fffff88000007450
Owning Process            fffffa800b834c10       Image:         ProcessA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10912787       Ticks: 14208 (0:00:03:42.000)
Context Switch Count      34                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.015
Win32 Start Address 0×00000000fff60260
Stack Init fffffa600e8d5db0 Current fffffa600e8d5670
Base fffffa600e8d6000 Limit fffffa600e8ce000 Call 0
Priority 15 BasePriority 15 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`0e8d56b0 fffff800`016a36fa nt!KiSwapContext+0×7f
fffffa60`0e8d57f0 fffff800`0169835b nt!KiSwapThread+0×13a
fffffa60`0e8d5860 fffff800`016cd4e2 nt!KeWaitForSingleObject+0×2cb
fffffa60`0e8d58f0 fffff800`01916d14 nt!AlpcpSignalAndWait+0×92
fffffa60`0e8d5980 fffff800`019137a6 nt!AlpcpReceiveSynchronousReply+0×44
fffffa60`0e8d59e0 fffff800`0190330f nt!AlpcpProcessSynchronousRequest+0×24f
fffffa60`0e8d5b00 fffff800`016a0ef3 nt!NtAlpcSendWaitReceivePort+0×19f
fffffa60`0e8d5bb0 00000000`774d756a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`0e8d5c20)
00000000`0026f038 00000000`00000000 0×774d756a

1: kd> !alpc /m fffff88012527770

Message @ fffff88012527770
  MessageID             : 0x10E8 (4328)
  CallbackID            : 0xC3416B (12796267)
  SequenceNumber        : 0x00000002 (2)
  Type                  : LPC_REQUEST
  DataLength            : 0x0040 (64)
  TotalLength           : 0x0068 (104)
  Canceled              : No
  Release               : No
  ReplyWaitReply        : No
  Continuation          : Yes
  OwnerPort             : fffffa80076e9660 [ALPC_CLIENT_COMMUNICATION_PORT]
  WaitingThread         : fffffa800b845bb0
  QueueType             : ALPC_MSGQUEUE_PENDING
  QueuePort             : fffffa80055bca60 [ALPC_CONNECTION_PORT]
  QueuePortOwnerProcess : fffffa80054dfc10 (ProcessB.exe)
  ServerThread          : fffffa800b711060
  QuotaCharged          : No
  CancelQueuePort       : 0000000000000000
  CancelSequencePort    : 0000000000000000
  CancelSequenceNumber  : 0×00000000 (0)
  ClientContext         : 00000000003fcf20
  ServerContext         : 0000000000000000
  PortContext           : 00000000029fda00
  CancelPortContext     : 0000000000000000
  SecurityData          : 0000000000000000
  View                  : 0000000000000000

1: kd> !thread fffffa800b711060
THREAD fffffa800b711060  Cid 032c.146e8  Teb: 000007fffff7c000 Win32Thread: 0000000000000000 WAIT: (WrLpcReply) UserMode Non-Alertable
    fffffa800b7113f0  Semaphore Limit 0x1
Waiting for reply to ALPC Message fffff8800e401200 : queued at port fffffa8005a32730 : owned by process fffffa8004c39040
Not impersonating
DeviceMap                 fffff88000007450
Owning Process            fffffa80054dfc10       Image:         ProcessB.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10916800       Ticks: 10195 (0:00:02:39.296)
Context Switch Count      401            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0×000007fefe647780
Stack Init fffffa6001d33db0 Current fffffa6001d33670
Base fffffa6001d34000 Limit fffffa6001d2e000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 1 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Call Site
fffffa60`01d336b0 fffff800`016a36fa : nt!KiSwapContext+0×7f
fffffa60`01d337f0 fffff800`0169835b : nt!KiSwapThread+0×13a
fffffa60`01d33860 fffff800`016cd4e2 : nt!KeWaitForSingleObject+0×2cb
fffffa60`01d338f0 fffff800`01916d14 : nt!AlpcpSignalAndWait+0×92
fffffa60`01d33980 fffff800`019137a6 : nt!AlpcpReceiveSynchronousReply+0×44
fffffa60`01d339e0 fffff800`0190330f : nt!AlpcpProcessSynchronousRequest+0×24f
fffffa60`01d33b00 fffff800`016a0ef3 : nt!NtAlpcSendWaitReceivePort+0×19f
fffffa60`01d33bb0 00000000`774d756a : nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`01d33c20)
00000000`03d8e458 00000000`00000000 : 0×774d756a

1: kd> !alpc /m fffff8800e401200

Message @ fffff8800e401200
  MessageID             : 0x0BA4 (2980)
  CallbackID            : 0xC3E68A (12838538)
  SequenceNumber        : 0x00021911 (137489)
  Type                  : LPC_REQUEST
  DataLength            : 0x00C0 (192)
  TotalLength           : 0x00E8 (232)
  Canceled              : No
  Release               : No
  ReplyWaitReply        : No
  Continuation          : Yes
  OwnerPort             : fffffa8005b119c0 [ALPC_CLIENT_COMMUNICATION_PORT]
  WaitingThread         : fffffa800b711060
  QueueType             : ALPC_MSGQUEUE_PENDING
  QueuePort             : fffffa8005a32730 [ALPC_CONNECTION_PORT]
  QueuePortOwnerProcess : fffffa8004c39040 (ProcessC.exe)
  ServerThread          : fffffa800a843bb0
  QuotaCharged          : No
  CancelQueuePort       : 0000000000000000
  CancelSequencePort    : 0000000000000000
  CancelSequenceNumber  : 0×00000000 (0)
  ClientContext         : 0000000002e2e810
  ServerContext         : 0000000000000000
  PortContext           : 00000000002f3eb0
  CancelPortContext     : 0000000000000000
  SecurityData          : 0000000000000000
  View                  : 0000000000000000

1: kd> !thread fffffa800a843bb0
THREAD fffffa800a843bb0  Cid 048c.fbec  Teb: 000007ffffdaa000 Win32Thread: 0000000000000000 WAIT: (UserRequest) UserMode Non-Alertable
    fffffa8006027d80  Semaphore Limit 0x7fffffff
    fffffa800a843c68  NotificationTimer
Not impersonating
DeviceMap                 fffff88001800ba0
Owning Process            fffffa8004c39040       Image:         ProcessC.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10916801       Ticks: 10194 (0:00:02:39.281)
Context Switch Count      239            
UserTime                  00:00:00.000
KernelTime                00:00:00.015
Win32 Start Address 0×000007fefe647780
Stack Init fffffa601b280db0 Current fffffa601b280940
Base fffffa601b281000 Limit fffffa601b27b000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Call Site
fffffa60`1b280980 fffff800`016a36fa : nt!KiSwapContext+0×7f
fffffa60`1b280ac0 fffff800`0169835b : nt!KiSwapThread+0×13a
fffffa60`1b280b30 fffff800`019013e8 : nt!KeWaitForSingleObject+0×2cb
fffffa60`1b280bc0 fffff800`016a0ef3 : nt!NtWaitForSingleObject+0×98
fffffa60`1b280c20 00000000`774d6d5a : nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`1b280c20)
00000000`10b7e548 00000000`00000000 : 0×774d6d5a

Some processes designed to be non-interactive have threads that wait for UI messages and therefore could be potential message or dialog box threads waiting for a dismissal and blocking other threads:

THREAD fffffa8005a7aa20  Cid 061c.0778  Teb: 000007fffff9e000 Win32Thread: fffff900c079fd50 WAIT: (WrUserRequest) UserMode Non-Alertable
    fffffa8005a7a5a0  SynchronizationEvent
Not impersonating
DeviceMap                 fffff88000007450
Owning Process            fffffa80058f01b0       Image:         ProcessD.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10911798       Ticks: 15197 (0:00:03:57.453)
Context Switch Count      88939                 LargeStack
UserTime                  00:00:00.078
KernelTime                00:00:00.609
Win32 Start Address 0×000007fefa8238a0
Stack Init fffffa60046a8db0 Current fffffa60046a8720
Base fffffa60046a9000 Limit fffffa60046a0000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`046a8760 fffff800`016a36fa nt!KiSwapContext+0×7f
fffffa60`046a88a0 fffff800`0169835b nt!KiSwapThread+0×13a
fffffa60`046a8910 fffff960`0014c053 nt!KeWaitForSingleObject+0×2cb
fffffa60`046a89a0 fffff960`0014c0ea win32k!xxxRealSleepThread+0×25f
fffffa60`046a8a40 fffff960`0014bb3a win32k!xxxSleepThread+0×56
fffffa60`046a8a70 fffff960`0014bc39 win32k!xxxRealInternalGetMessage+0×72e
fffffa60`046a8b50 fffff960`0014d0d9 win32k!xxxInternalGetMessage+0×35
fffffa60`046a8b90 fffff800`016a0ef3 win32k!NtUserGetMessage+0×79

fffffa60`046a8c20 00000000`773dd58a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`046a8c20)
00000000`03d2f7b8 00000000`00000000 0×773dd58a

We also have more than 30,000 zombie processes including some special ones signifying past faults:

1: kd> !vm
[...]
         15714 ProcessE.exe       0 (         0 Kb)
         15650 WerFault.exe       0 (         0 Kb)
         15644 ProcessF.exe       0 (         0 Kb)
         15640 ProcessE.exe       0 (         0 Kb)
         15610 ProcessG.exe       0 (         0 Kb)
         1560c ProcessE.exe       0 (         0 Kb)
         155f8 ProcessH.exe       0 (         0 Kb)
         155e8 ProcessE.exe       0 (         0 Kb)
         155c4 ProcessG.exe       0 (         0 Kb)
         155bc ProcessE.exe       0 (         0 Kb)
         155b8 ProcessH.exe       0 (         0 Kb)
         1559c WerFault.exe       0 (         0 Kb)
         15560 ProcessE.exe       0 (         0 Kb)
[…]

What we recommend here is to save user dumps of processes A, B, C and D and then force a kernel dump next time the problem surfaces. Also to check WER settings for any recorder faults and, because of the fact the the system is W2K8, configure LocalDumps registry keys to capture full user dumps.

- Dmitry Vostokov @ DumpAnalysis.org -

Inconsistent dump, blocked threads, wait chains, incorrect stack trace and process factory: pattern cooperation

Tuesday, June 9th, 2009

The more busy the system is, the more inconsistent are complete memory dumps produced by external physical memory dumpers. On the contrary, quiet systems, with idle existent users and when no one can connect, are more consistent than usual. Here is one example:

Loading Dump File [complete_dump.dmp]
Kernel Complete Dump File: Full address space is available

[...]

WARNING: Process directory table base 00039000 doesn't match CR3 CB759000
[...]

BugCheck 0, {0, 0, 0, 0}

Probably caused by : LiveKdD.SYS ( LiveKdD+12d1 )

In such cases I often dump all processes and threads to look for anomalies and indeed we find plenty of blocked threads in several services. For example, ServiceA.exe has blocked threads waiting for critical sections and LPC requests:

0: kd> !process 0 ff
**** NT ACTIVE PROCESS DUMP ****

[...]

THREAD 86f21118  Cid 07d4.2914  Teb: 7ffa5000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     86f21304  Semaphore Limit 0x1
Waiting for reply to LPC MessageId 00f2b546:
Current LPC port d79c6e00
Impersonation token:  db621028 (Level Impersonation)
DeviceMap                 dca24d50
Owning Process            88948d88       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      14788708       Ticks: 3643121 (0:15:48:43.765)
Context Switch Count      52            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address ServiceA!EventWorkerThread (0×0042e2f8)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b2246000 Current b2245c08 Base b2246000 Limit b2243000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
b2245c10 00000000 0×149c3
[…]

THREAD 8736fdb0  Cid 07d4.3cc4  Teb: 7ff9c000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     8736ff9c  Semaphore Limit 0x1
Waiting for reply to LPC MessageId 00f2b518:
Current LPC port d79c6e00
Impersonation token:  da1b51a8 (Level Impersonation)
DeviceMap                 d9f9e368
Owning Process            88948d88       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      14788707       Ticks: 3643122 (0:15:48:43.781)
Context Switch Count      44            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address ServiceA!EventWorkerThread (0×0042e2f8)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init ae5d3000 Current ae5d2c08 Base ae5d3000 Limit ae5d0000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
WARNING: Frame IP not in any known module. Following frames may be wrong.
ae5d2c10 3fe63bfa 0×73e40763
[…]

THREAD 85e89c80  Cid 07d4.5648  Teb: 7ff6a000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     871d6e80  SynchronizationEvent
Impersonation token:  d7a1c028 (Level Impersonation)
DeviceMap                 d66ef860
Owning Process            88948d88       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      14320472       Ticks: 4111357 (0:17:50:39.953)
Context Switch Count      28            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0x00ebebcc
LPC Server thread working on message Id ebebcc
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init a536b000 Current a536ac60 Base a536b000 Limit a5368000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
a536ac78 8083d5b1 nt!KiSwapContext+0x26
a536aca4 8083df9e nt!KiSwapThread+0x2e5
a536acec 8092ae57 nt!KeWaitForSingleObject+0x346
a536ad50 80833bdf nt!NtWaitForSingleObject+0x9a
a536ad50 7c8285ec nt!KiFastCallEntry+0xfc
05b6f7d0 7c827d0b ntdll!KiFastSystemCallRet
05b6f7d4 7c83d236 ntdll!NtWaitForSingleObject+0xc
05b6f810 7c83d281 ntdll!RtlpWaitOnCriticalSection+0×1a3
05b6f830 0040bb5b ntdll!RtlEnterCriticalSection+0xa8

05b6f874 00415889 ServiceA!OnRequest+0×23
[…]
05b6f8b4 77ce33e1 RPCRT4!Invoke+0×30
05b6fcb4 77ce35c4 RPCRT4!NdrStubCall2+0×299
05b6fcd0 77c7ff7a RPCRT4!NdrServerCall2+0×19
05b6fd04 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
05b6fd58 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
05b6fd7c 77c7e0d4 RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
05b6fdbc 77c7e080 RPCRT4!RPC_INTERFACE::DispatchToStubWithObject+0xc0
05b6fdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×41e
05b6fe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
05b6ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
05b6ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
05b6ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
05b6ffb8 77e64829 RPCRT4!ThreadStartRoutine+0×1b
05b6ffec 00000000 kernel32!BaseThreadStart+0×34

Knowing that ServiceA is crucial for our system functions we examine LPC wait chains. All “Waiting for reply to LPC MessageId <…>” threads depend on another service:

0: kd> !lpc message 00f2b546
Searching message f2b546 in threads ...
Client thread 86f21118 waiting a reply from f2b546                         
    Server thread 860cc9e0 is working on message f2b546
[…]
    Server process  : 87d21698 (svchost.exe)
[…]

We find this thread in svchost.exe hosting ServiceB:

0: kd> !thread 860cc9e0 1f
THREAD 860cc9e0  Cid 1310.4ad8  Teb: 7ff88000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     871d47d0  Mutant - owning thread 867322e0
Not impersonating
DeviceMap                 d64008f8
Owning Process            87d21698       Image:         svchost.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      14788708       Ticks: 3643121 (0:15:48:43.765)
Context Switch Count      1791            
UserTime                  00:00:00.031
KernelTime                00:00:00.046
Win32 Start Address 0×00f2b546
LPC Server thread working on message Id f2b546
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b055e000 Current b055dc60 Base b055e000 Limit b055b000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
b055dc78 8083d5b1 nt!KiSwapContext+0×26
b055dca4 8083df9e nt!KiSwapThread+0×2e5
b055dcec 8092ae57 nt!KeWaitForSingleObject+0×346
b055dd50 80833bdf nt!NtWaitForSingleObject+0×9a
b055dd50 7c8285ec nt!KiFastCallEntry+0xfc
0400f718 7c827d0b ntdll!KiFastSystemCallRet
0400f71c 7654bf59 ntdll!NtWaitForSingleObject+0xc
0400f73c 7654c694 ServiceB!Lock+0×42
0400f754 76558b17 ServiceB!FindObjectById+0×39
0400f8ac 7654fa50 ServiceB!QueryInformation+0×3e
0400f8c8 77c80193 ServiceB!RpcQueryInformation+0×49
0400f8f8 77ce33e1 RPCRT4!Invoke+0×30
0400fcf8 77ce35c4 RPCRT4!NdrStubCall2+0×299
0400fd14 77c7ff7a RPCRT4!NdrServerCall2+0×19
0400fd48 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
0400fd9c 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
0400fdc0 77c811dc RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
0400fdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×42c
0400fe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
0400ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
0400ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
0400ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
0400ffb8 77e64829 RPCRT4!ThreadStartRoutine+0×1b
0400ffec 00000000 kernel32!BaseThreadStart+0×34

We notice that about 45 threads are waiting for the mutant 871d47d0 owned by thread 867322e0, like this one with incorrect stack trace because of inconsistent dump file data:

0: kd> !thread 86cad210 1f
THREAD 86cad210  Cid 1310.31a4  Teb: 7ff15000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     871d47d0  Mutant - owning thread 867322e0
Not impersonating
DeviceMap                 d64008f8
Owning Process            87d21698       Image:         svchost.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      18020896       Ticks: 410933 (0:01:47:00.828)
Context Switch Count      43            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address RPCRT4!ThreadStartRoutine (0×77c7b0f5)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init abb1b000 Current abb1ac60 Base abb1b000 Limit abb18000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
WARNING: Frame IP not in any known module. Following frames may be wrong.
abb1ac68 60203020 0×84
[…]

We inspect the thread 867322e0:

0: kd> !thread 867322e0 1f
THREAD 867322e0  Cid 1310.26dc  Teb: 7ff56000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     869d4020  ProcessObject
     86732358  NotificationTimer
Not impersonating
DeviceMap                 d64008f8
Owning Process            87d21698       Image:         svchost.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      18454684    
Context Switch Count      5172            
UserTime                  00:00:00.000
KernelTime                00:00:00.031
Win32 Start Address 0×0083fd5d
LPC Server thread working on message Id 83fd5d
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init ad350000 Current ad34fc60 Base ad350000 Limit ad34d000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
ad34fc78 8083d5b1 nt!KiSwapContext+0×26
ad34fca4 8083df9e nt!KiSwapThread+0×2e5
ad34fcec 8092ae57 nt!KeWaitForSingleObject+0×346
ad34fd50 80833bdf nt!NtWaitForSingleObject+0×9a
ad34fd50 7c8285ec nt!KiFastCallEntry+0xfc
04f5fbec 7c827d0b ntdll!KiFastSystemCallRet
04f5fbf0 76548721 ntdll!NtWaitForSingleObject+0xc
04f5fc0c 7654c596 ServiceB!WaitForProcess+0×4a

04f5ffb8 77e64829 ServiceB!LpcThread+0×14e
04f5ffec 00000000 kernel32!BaseThreadStart+0×34

We see that it is waiting for the process 869d4020 and we find the latter one with a single thread blocked by DriverA:

0: kd> !process 869d4020 ff
PROCESS 869d4020  SessionId: 18  Cid: 56b8    Peb: 7ffde000  ParentCid: 3608
    DirBase: 758b3000  ObjectTable: dd7083c0  HandleCount:  79.
    Image: rundll32.exe
    VadRoot 869d5228 Vads 107 Clone 0 Private 330. Modified 1706. Locked 0.
    DeviceMap d8d260a8
    Token                             dfa8f028
    ElapsedTime                       1 Day 23:52:06.918
    UserTime                          00:00:00.312
    KernelTime                        00:00:01.484
    QuotaPoolUsage[PagedPool]         34784
    QuotaPoolUsage[NonPagedPool]      5016
    Working Set Sizes (now,min,max)  (810, 50, 345) (3240KB, 200KB, 1380KB)
    PeakWorkingSetSize                2088
    VirtualSize                       37 Mb
    PeakVirtualSize                   47 Mb
    PageFaultCount                    34473
    MemoryPriority                    BACKGROUND
    BasePriority                      10
    CommitCharge                      707
[..]
    CommandLine:  ‘rundll32 C:\WINDOWS\system32\DllA.dll,CheckData /name”PropertyA”‘
[…]

THREAD 86bac020  Cid 56b8.4904  Teb: 7ffdb000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
     8774a930  NotificationEvent
Not impersonating
DeviceMap                 d8d260a8
Owning Process            869d4020       Image:         rundll32.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10113815       Ticks: 8318014 (1:12:06:08.968)
Context Switch Count      188            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0x2b169ecb
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init af12b000 Current af12ac34 Base af12b000 Limit af128000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
af12ac4c 8083d5b1 nt!KiSwapContext+0x26
af12ac78 8083df9e nt!KiSwapThread+0x2e5
af12acc0 b5075a82 nt!KeWaitForSingleObject+0x346
WARNING: Stack unwind information not available. Following frames may be wrong.
af12acf4 b507f989 DriverA+0×3a82
[…]

We also check virtual memory consumption and instantly see hundreds of rundll32.exe processes like in a process factory pattern:

0: kd> !vm
[...]
57f4 rundll32.exe       586 (      2344 Kb)
57d0 rundll32.exe       586 (      2344 Kb)
57b4 rundll32.exe       586 (      2344 Kb)
578c rundll32.exe       586 (      2344 Kb)
5780 rundll32.exe       586 (      2344 Kb)
577c rundll32.exe       586 (      2344 Kb)
5744 rundll32.exe       586 (      2344 Kb)
572c rundll32.exe       586 (      2344 Kb)
5724 rundll32.exe       586 (      2344 Kb)
5708 rundll32.exe       586 (      2344 Kb)
56d4 rundll32.exe       586 (      2344 Kb)
56a4 rundll32.exe       586 (      2344 Kb)
564c rundll32.exe       586 (      2344 Kb)
5630 rundll32.exe       586 (      2344 Kb)
55e0 rundll32.exe       586 (      2344 Kb)
55b8 rundll32.exe       586 (      2344 Kb)
55ac rundll32.exe       586 (      2344 Kb)
558c rundll32.exe       586 (      2344 Kb)
550c rundll32.exe       586 (      2344 Kb)
546c rundll32.exe       586 (      2344 Kb)
5428 rundll32.exe       586 (      2344 Kb)
5418 rundll32.exe       586 (      2344 Kb)
53d0 rundll32.exe       586 (      2344 Kb)
53bc rundll32.exe       586 (      2344 Kb)
53b0 rundll32.exe       586 (      2344 Kb)
53a8 rundll32.exe       586 (      2344 Kb)
530c rundll32.exe       586 (      2344 Kb)
5300 rundll32.exe       586 (      2344 Kb)
52e8 rundll32.exe       586 (      2344 Kb)
52a4 rundll32.exe       586 (      2344 Kb)
5294 rundll32.exe       586 (      2344 Kb)
5228 rundll32.exe       586 (      2344 Kb)
5118 rundll32.exe       586 (      2344 Kb)
50bc rundll32.exe       586 (      2344 Kb)
50a8 rundll32.exe       586 (      2344 Kb)
5080 rundll32.exe       586 (      2344 Kb)
5030 rundll32.exe       586 (      2344 Kb)
4fc8 rundll32.exe       586 (      2344 Kb)
4f88 rundll32.exe       586 (      2344 Kb)
4ef0 rundll32.exe       586 (      2344 Kb)
4e84 rundll32.exe       586 (      2344 Kb)
4e70 rundll32.exe       586 (      2344 Kb)
4e68 rundll32.exe       586 (      2344 Kb)
4e4c rundll32.exe       586 (      2344 Kb)
4e38 rundll32.exe       586 (      2344 Kb)
4df8 rundll32.exe       586 (      2344 Kb)
4df4 rundll32.exe       586 (      2344 Kb)
4d2c rundll32.exe       586 (      2344 Kb)
4d00 rundll32.exe       586 (      2344 Kb)
4cd4 rundll32.exe       586 (      2344 Kb)
4cbc rundll32.exe       586 (      2344 Kb)
4c90 rundll32.exe       586 (      2344 Kb)
4c80 rundll32.exe       586 (      2344 Kb)
4c68 rundll32.exe       586 (      2344 Kb)
4c40 rundll32.exe       586 (      2344 Kb)
[...]

By switching the current process context to 869d4020 (.process /r /p command) and using lmv command we check vendors for DllA and DriverA. It seems that they are different. We also see that DllA module is no longer loaded (not seen in the module list) by the time DriverA is waiting for a notification event. All rundll32.exe processes are waiting for that DriverA kernel module. We therefore decide to contact its vendor.

- Dmitry Vostokov @ DumpAnalysis.org -

Music for Debugging: Horrors of Computation

Wednesday, March 25th, 2009

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

Buy from Amazon

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 -

Insufficient memory, handle leak, process factory, high contention and busy system: pattern cooperation

Monday, February 16th, 2009

It was reported that one system became slower and slower and eventually the complete memory dump was generated for analysis. Usual !vm 4 command shows pool allocation errors and particularly insufficient session pool memory for user session 1:

1: kd> !vm 4

*** Virtual Memory Usage ***
 Physical Memory:     1048503 (   4194012 Kb)
 Page File: \??\C:\pagefile.sys
   Current:   5109760 Kb  Free Space:   3668764 Kb
   Minimum:   5109760 Kb  Maximum:      5109760 Kb
 Available Pages:      409409 (   1637636 Kb)
 ResAvail Pages:       708135 (   2832540 Kb)
 Locked IO Pages:         108 (       432 Kb)
 Free System PTEs:     137566 (    550264 Kb)
 Free NP PTEs:          27288 (    109152 Kb)
 Free Special NP:           0 (         0 Kb)
 Modified Pages:          780 (      3120 Kb)
 Modified PF Pages:       771 (      3084 Kb)
 NonPagedPool Usage:    37587 (    150348 Kb)
 NonPagedPool Max:      65214 (    260856 Kb)

 PagedPool 0 Usage:     21583 (     86332 Kb)
 PagedPool 1 Usage:      3054 (     12216 Kb)
 PagedPool 2 Usage:      3076 (     12304 Kb)
 PagedPool 3 Usage:      3050 (     12200 Kb)
 PagedPool 4 Usage:      3040 (     12160 Kb)
 PagedPool Usage:       33803 (    135212 Kb)
 PagedPool Maximum:     66560 (    266240 Kb)

 ********** 185454 pool allocations have failed **********

 Shared Commit:        123289 (    493156 Kb)
 Special Pool:              0 (         0 Kb)
 Shared Process:       101937 (    407748 Kb)
 PagedPool Commit:      33850 (    135400 Kb)
 Driver Commit:          1697 (      6788 Kb)
 Committed pages:     1159581 (   4638324 Kb)
 Commit limit:        2283111 (   9132444 Kb)

[...]

 Session ID 1 @ af925000:
 Paged Pool Usage:       16868K

 *** 371034 Pool Allocation Failures ***

 Commit Usage:           17960K

 Session ID 2 @ af927000:
 Paged Pool Usage:        2856K
 Commit Usage:            3860K

[...]

The exploration of session 1 processes shows Process Factory pattern (5,000 launched processes) with explorer.exe ran amok:

1: kd> !sprocess 1
Dumping Session 1

_MM_SESSION_SPACE af925000
_MMSESSION        af925d80
PROCESS 87db34a0  SessionId: 1  Cid: 4a68    Peb: 7ffd4000  ParentCid: 01b8
    DirBase: cffb6d20  ObjectTable: e6084268  HandleCount: 11677.
    Image: csrss.exe

PROCESS 86083020  SessionId: 1  Cid: 4560    Peb: 7ffde000  ParentCid: 2978
    DirBase: cffb6f40  ObjectTable: e6c41410  HandleCount:  79.
    Image: AnotherApp.exe

PROCESS 8607c020  SessionId: 1  Cid: 44c8    Peb: 7ffdc000  ParentCid: 4cf8
    DirBase: cffb7080  ObjectTable: e3c9fd38  HandleCount: 25407.
    Image: explorer.exe

[...]

PROCESS 85e94738  SessionId: 1  Cid: 4868    Peb: 7ffde000  ParentCid: 44c8
    DirBase: cffb7c00  ObjectTable: e7038840  HandleCount:  39.
    Image: application.exe

PROCESS 85e5c020  SessionId: 1  Cid: 4668    Peb: 7ffd4000  ParentCid: 4a50
    DirBase: cffb7de0  ObjectTable: e11891d0  HandleCount: 172.
    Image: application.exe

PROCESS 85e51578  SessionId: 1  Cid: 4c9c    Peb: 7ffde000  ParentCid: 44c8
    DirBase: cffb7e40  ObjectTable: e2ee0070  HandleCount:  39.
    Image: application.exe

[...]

PROCESS 85c81020  SessionId: 1  Cid: 53a4    Peb: 7ffd7000  ParentCid: 44c8
    DirBase: cffb89c0  ObjectTable: e6d2f600  HandleCount:  39.
    Image: application.exe

PROCESS 85c6fb18  SessionId: 1  Cid: 53a8    Peb: 7ffd7000  ParentCid: 44c8
    DirBase: cffb89e0  ObjectTable: e54df078  HandleCount:  39.
    Image: application.exe

PROCESS 85c60020  SessionId: 1  Cid: 53bc    Peb: 7ffdf000  ParentCid: 44c8
    DirBase: cffb8a40  ObjectTable: e1214e90  HandleCount:  39.
    Image: application.exe

[...]

We can also see the very big number of handles in both csrss.exe and explorer.exe. If we look at one of 5,000 application.exe processes we would see that it is a GUI application and this explains session pool exhaustion:

1: kd> !process 85c60020 1f
PROCESS 85c60020  SessionId: 1  Cid: 53bc    Peb: 7ffdf000  ParentCid: 44c8
    DirBase: cffb8a40  ObjectTable: e1214e90  HandleCount:  39.
    Image: application.exe
    VadRoot 85c97450 Vads 80 Clone 0 Private 173. Modified 159. Locked 0.
    DeviceMap e3743340
    Token                             e2ead5e0
    ElapsedTime                       00:54:17.218
    UserTime                          00:00:00.015
    KernelTime                        00:00:00.000
    QuotaPoolUsage[PagedPool]         32460
    QuotaPoolUsage[NonPagedPool]      3200
    Working Set Sizes (now,min,max)  (30, 50, 345) (120KB, 200KB, 1380KB)
    PeakWorkingSetSize                778
    VirtualSize                       16 Mb
    PeakVirtualSize                   17 Mb
    PageFaultCount                    829
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      212

THREAD 85c25db0  Cid 53bc.5470  Teb: 7ffde000 Win32Thread: bd1a18a8 WAIT: (Unknown) UserMode Non-Alertable
    85bbf2a8  SynchronizationEvent
Not impersonating
DeviceMap                 e3743340
Owning Process            85c60020       Image:         application.exe
Wait Start TickCount      1121133        Ticks: 206877 (0:00:53:52.453)
Context Switch Count      19355  NoStackSwap    LargeStack
UserTime                  00:00:00.015
KernelTime                00:00:00.000
Win32 Start Address application (0x00402a38)
Start Address kernel32!BaseProcessStartThunk (0x7c8217f8)
Stack Init ad2b8000 Current ad2b7b1c Base ad2b8000 Limit ad2b4000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
ad2b7b34 80833ec5 nt!KiSwapContext+0x26
ad2b7b60 80829bc0 nt!KiSwapThread+0x2e5
ad2b7ba8 bf89aacc nt!KeWaitForSingleObject+0x346
ad2b7c04 bf8c4816 win32k!xxxSleepThread+0×1be
ad2b7ca0 bf8a134f win32k!xxxInterSendMsgEx+0×798
ad2b7cec bf85ae3c win32k!xxxSendMessageTimeout+0×1f3
ad2b7d10 bf8c13dc win32k!xxxWrapSendMessage+0×1b
ad2b7d40 8088ad3c win32k!NtUserMessageCall+0×9d

ad2b7d40 7c9485ec nt!KiFastCallEntry+0xfc (TrapFrame @ ad2b7d64)
0012f814 00000000 ntdll!KiFastSystemCallRet

We also see extremely high executive resource contention and various signs of a busy system like the fact that all processors are busy and very high number of ready threads at normal priority (about 1,000):

1: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****

Resource @ DriverA (0xbae016a0)    Exclusively owned
    Contention Count = 277088870
    NumberOfExclusiveWaiters = 3591
     Threads: 83b46db0-01<*> << Too many exclusive waiters to list>>

1: kd> !running

System Processors ff (affinity mask)
  Idle Processors 0

     Prcb      Current   Next   
  0  ffdff120  86300b40            …………….
  1  f772f120  f77320a0  852fadb0  …………….
  2  f7737120  f773a0a0  861528d0  …………….
  3  f773f120  f77420a0  877a4020  …………….
  4  f7747120  f774a0a0  865909a8  …………….
  5  f774f120  f77520a0  83d62cd0  …………….
  6  f7757120  f775a0a0  841aa020  …………….
  7  f775f120  f77620a0  ffb7b5e0  …………….

1: kd> !ready
Processor 0: No threads in READY state
Processor 1: Ready Threads at priority 10
    THREAD 861b1898  Cid 4860.4894  Teb: 7ffd8000 Win32Thread: bc1669a8 READY
Processor 1: Ready Threads at priority 9
    THREAD 83b46db0  Cid 44c8.a11c  Teb: 7f8f8000 Win32Thread: bcbabb38 READY
Processor 1: Ready Threads at priority 8
    THREAD 851408d0  Cid 6338.6398  Teb: 7ffdf000 Win32Thread: bc9bfbb8 READY
    THREAD 83eb1730  Cid 8f30.9568  Teb: 7ffdf000 Win32Thread: 00000000 READY
    THREAD fd310af8  Cid d53c.b4d8  Teb: 7ffdf000 Win32Thread: 00000000 READY
    THREAD 83bce8d0  Cid abec.6450  Teb: 7ffdd000 Win32Thread: 00000000 READY
    THREAD 83de2388  Cid a618.d79c  Teb: 7ffde000 Win32Thread: 00000000 READY
    THREAD 84197b40  Cid 44c8.6974  Teb: 7fe6a000 Win32Thread: bc662d48 READY
[…]

Processor 1: Ready Threads at priority 7
    THREAD 86d0c890  Cid 3524.365c  Teb: 7ff8e000 Win32Thread: bc403bb0 READY
Processor 2: No threads in READY state
Processor 3: No threads in READY state
Processor 4: No threads in READY state
Processor 5: No threads in READY state
Processor 6: No threads in READY state
Processor 7: No threads in READY state

There is AnotherApp.exe in the session process list that executes a VBS script:  

1: kd> .process /r /p 86083020
Implicit process is now 86083020
Loading User Symbols

1: kd> !process 86083020
[...]

        THREAD 860b0db0  Cid 4560.4e4c  Teb: 7ffdd000 Win32Thread: bc1bf4d0 WAIT: (Unknown) KernelMode Non-Alertable
            860b0e28  NotificationTimer

1: kd> .thread 860b0db0
Implicit thread is now 860b0db0

1: kd> kv 100
ChildEBP RetAddr  Args to Child             
ae7ec76c 80833ec5 860b0db0 860b0ea0 00000000 nt!KiSwapContext+0x26
ae7ec798 80829069 0000001e 00000000 bae016a0 nt!KiSwapThread+0x2e5
ae7ec7e0 badff394 00000000 00000000 ffdff5f0 nt!KeDelayExecutionThread+0x2ab
[...]
0012f6ac 7c8024d5 00000000 00000000 00a43280 kernel32!CreateProcessInternalA+0x28b
0012f6e4 00401b31 00000000 00a43280 00000000 kernel32!CreateProcessA+0×2c
[…]

1: kd> da /c 100 00a43280
00a43280  “wscript.exe C:\Scripts\script.vbs parameters”

The examination of that script showed that it contained a coding error resulted in an infinite loop.

- Dmitry Vostokov @ DumpAnalysis.org -

Swarm of shared locks, blocked threads and waiting time: pattern cooperation

Monday, February 9th, 2009

Here is further analysis of a memory dump used to illustrate Swarm of Shared Locks pattern. In that dump there were also exclusively held locks with many blocked threads:

Resource @ 0x8a04c408    Exclusively owned
    Contention Count = 344875
    NumberOfExclusiveWaiters = 6
     Threads: 87eb3db0-01<*>
     Threads Waiting On Exclusive Access:
              88573db0       87b90378       86a49db0       891f4610      
              8662b020       87127db0
 

Resource @ 0x89678e80    Exclusively owned
    Contention Count = 10261
    NumberOfExclusiveWaiters = 2
     Threads: 87eb3db0-01<*>
     Threads Waiting On Exclusive Access:
              89131bf0       88d12db0 
     

Resource @ 0x88d099d8    Exclusively owned
    Contention Count = 562811
    NumberOfExclusiveWaiters = 4
     Threads: 873611d8-01<*>
     Threads Waiting On Exclusive Access:
              88b8bb88       88a72c50       89359af0       88d865e8      

Resource @ 0x86db9248    Exclusively owned
    Contention Count = 1382269
    NumberOfSharedWaiters = 2
    NumberOfExclusiveWaiters = 11
     Threads: 86ab2020-01<*> 8769cdb0-01    880c77b8-01   
     Threads Waiting On Exclusive Access:
              87bf4020       890dc020       874c01c0       884ef020      
              86913af8       875bab10       88e8a0d8       8923cdb0      
              894eca18       86aa6830       86f293a8     

Resource @ 0x873a88d0    Exclusively owned
    Contention Count = 719758
    NumberOfExclusiveWaiters = 8
     Threads: 88d5f990-01<*>
     Threads Waiting On Exclusive Access:
              8759ea88       871b6db0       88117710       87cb4718      
              883eb638       87239020       881ad020       891b9188      

Resource @ 0x88c379a0    Exclusively owned
    Contention Count = 126686
    NumberOfSharedWaiters = 1
    NumberOfExclusiveWaiters = 8
     Threads: 882b8020-01<*> 88951520-01   
     Threads Waiting On Exclusive Access:
              877d34a8       8939fdb0       87fc5668       8851fdb0      
              86fad850       87f1f450       8a1749f0       876a78d0      

Resource @ 0x88ca9250    Exclusively owned
    Contention Count = 319721
    NumberOfExclusiveWaiters = 4
     Threads: 88607908-01<*>
     Threads Waiting On Exclusive Access:
              86829370       892ae8e8       87205208       87b6d7e0      

Resource @ 0x86a90ef8    Exclusively owned
    Contention Count = 852830
    NumberOfExclusiveWaiters = 12
     Threads: 87571640-01<*>
     Threads Waiting On Exclusive Access:
              88a9c9b0       88a50db0       87117928       890e4c50      
              874ffb30       88b540f8       8705d020       8687edb0      
              87143188       8703e430       885b6aa0       8842bc50      

Resource @ 0x88954538    Exclusively owned
    Contention Count = 40708
    NumberOfExclusiveWaiters = 1
     Threads: 87571640-01<*>
     Threads Waiting On Exclusive Access:
              878ee980      

Resource @ 0x88617eb8    Exclusively owned
    Contention Count = 43531
    NumberOfExclusiveWaiters = 2
     Threads: 87571640-01<*>
     Threads Waiting On Exclusive Access:
              88851db0       87382c50      

Resource @ 0x87288bc8    Exclusively owned
    Contention Count = 644675
    NumberOfExclusiveWaiters = 2
     Threads: 874e4508-01<*>
     Threads Waiting On Exclusive Access:
              88863b08       89479650      

Resource @ 0x87c3d8b0    Exclusively owned
    Contention Count = 335064
    NumberOfExclusiveWaiters = 8
     Threads: 87f44520-01<*>
     Threads Waiting On Exclusive Access:
              88277190       88eceb48       87f0d308       8694d460      
              88461db0       876734a8       871721b0       88c2adb0      

All threads owning various locks exclusively are stuck in processing page fault code, for example:

0: kd> !thread 87eb3db0 1f
THREAD 87eb3db0  Cid 47ac.57c8  Teb: 7ffd7000 Win32Thread: bc151230 WAIT: (Unknown) KernelMode Non-Alertable
    8743e4e0  NotificationEvent
IRP List:
    8660c900: (0006,0094) Flags: 00000900  Mdl: 00000000
Not impersonating
DeviceMap                 e1003890
Owning Process            88e49918       Image:         csrss.exe
Wait Start TickCount      15420972       Ticks: 2527 (0:00:00:39.484)
Context Switch Count      1430991                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:02.734
Start Address 0×75a8e96c
Stack Init a3cf7000 Current a3cf6430 Base a3cf7000 Limit a3cf4000 Call 0
Priority 14 BasePriority 13 PriorityDecrement 0
ChildEBP RetAddr 
a3cf6448 8083d5b1 nt!KiSwapContext+0×26
a3cf6474 8083df9e nt!KiSwapThread+0×2e5
a3cf64bc 8082629e nt!KeWaitForSingleObject+0×346
a3cf64e4 80826480 nt!MiWaitForInPageComplete+0×1f
a3cf656c 8084790e nt!MiDispatchFault+0xda3
a3cf65c8 80836c2a nt!MmAccessFault+0×64a
a3cf65c8 bfa38de0 nt!KiTrap0E+0xdc (TrapFrame @ a3cf65e0)

a3cf6a24 bf854a72 win32k!vSetPointer+0×36f
a3cf6a50 bf8b1b74 win32k!GreSetPointer+0×66
a3cf6a7c bf883183 win32k!zzzUpdateCursorImage+0×1cc
a3cf6a8c bf884b06 win32k!zzzSetFMouseMoved+0xd5
a3cf6ad4 bf81530a win32k!ProcessQueuedMouseEvents+0×1c4
a3cf6d30 bf86fd25 win32k!RawInputThread+0×5b4
a3cf6d40 bf898a52 win32k!xxxCreateSystemThreads+0×60
a3cf6d54 80833bef win32k!NtUserCallOneParam+0×23
a3cf6d54 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ a3cf6d64)

0: kd> !thread 87571640 1f
THREAD 87571640  Cid 49f4.65b4  Teb: 7ffdf000 Win32Thread: bc011680 WAIT: (Unknown) KernelMode Non-Alertable
    8870db90  NotificationEvent
Not impersonating
DeviceMap                 e24f6570
Owning Process            87be4a00       Image:         ApplicationC.EXE
Wait Start TickCount      15420974       Ticks: 2525 (0:00:00:39.453)
Context Switch Count      25640                 LargeStack
UserTime                  00:00:00.921
KernelTime                00:00:03.859
Win32 Start Address 0×30002658
Start Address 0×77e617f8
Stack Init 9a318600 Current 9a317b70 Base 9a319000 Limit 9a314000 Call 9a31860c
Priority 14 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
9a317b88 8083d5b1 nt!KiSwapContext+0×26
9a317bb4 8083df9e nt!KiSwapThread+0×2e5
9a317bfc 8082629e nt!KeWaitForSingleObject+0×346
9a317c24 80826480 nt!MiWaitForInPageComplete+0×1f
9a317cac 8084790e nt!MiDispatchFault+0xda3
9a317d08 80836c2a nt!MmAccessFault+0×64a
9a317d08 bf8b5485 nt!KiTrap0E+0xdc (TrapFrame @ 9a317d20)

9a317db4 bf8b526c win32k!vSolidFillRect1+0xb0
9a317f58 bf8ad7d2 win32k!vDIBSolidBlt+0×102
9a317fc4 bfa285d1 win32k!EngBitBlt+0xe1
9a3180c8 bf899b57 win32k!GrePatBltLockedDC+0×1ea
9a318160 bf8b32bb win32k!GrePolyPatBltInternal+0×17c
9a31819c bf8bd71c win32k!GrePolyPatBlt+0×45
9a31822c bf85e3d5 win32k!DrawEdge+0×23a
9a318274 bf8ae338 win32k!xxxDrawWindowFrame+0×170
9a3182d4 bf8847d1 win32k!xxxRealDefWindowProc+0×7a7
9a3182ec bf884801 win32k!xxxWrapRealDefWindowProc+0×16
9a318308 bf8c1769 win32k!NtUserfnDWORD+0×27
9a318340 80833bef win32k!NtUserMessageCall+0xc0
9a318340 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ 9a318364)

We also see that their waiting time is almost the same, 39 seconds. This means that the problem with paging probably started at that time before the crash dump was forced.

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 79)

Monday, February 9th, 2009

Sometimes there are so many shared locks on the system that it might point to some problems in subsystems that own them. For example, there are two large swarms of them in this memory dump from a system running 90 user sessions:

0: kd> !session
Sessions on machine: 90

0: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks....

Resource @ nt!CmpRegistryLock (0x808ad4c0)    Shared 210 owning threads
    Contention Count = 1432
     Threads: 88bf1590-01<*> 8a78a660-01<*> 8a787660-01<*> 8825a3a8-01<*>
              89003358-01<*> 86723b90-01<*> 865bbb00-01<*> 89634638-01<*>
              888d9508-01<*> 88da6b48-01<*> 87db9db0-01<*> 86a9e610-01<*>
              89ff7410-01<*> 87450db0-01<*> 86bdedb0-01<*> 86d604c8-01<*>
              88d465d8-01<*> 86c3b6a0-01<*> 87c89020-01<*> 88e73db0-01<*>
              865fe5b0-01<*> 88450020-01<*> 86bd9db0-01<*> 8a73e838-01<*>
              88dc3db0-01<*> 88035708-01<*> 8833a2f0-01<*> 88608350-01<*>
              87aca020-01<*> 87e007c0-01<*> 86ec39b8-01<*> 893be1b8-01<*>
              8671ddb0-01<*> 8679a718-01<*> 89fe34c8-01<*> 86ccd720-01<*>
              881b1db0-01<*> 86771b20-01<*> 86d71db0-01<*> 89574db0-01<*>
              87dfac50-01<*> 86597020-01<*> 874b3488-01<*> 873b59b0-01<*>
              88e792f8-01<*> 878d2430-01<*> 8853d480-01<*> 889e2020-01<*>
              88c36db0-01<*> 8824f990-01<*> 8719b830-01<*> 884ba020-01<*>
              88e1d768-01<*> 89523db0-01<*> 896529f8-01<*> 887e2870-01<*>
              8a022db0-01<*> 867253a0-01<*> 865f0448-01<*> 87d35640-01<*>
              8715d968-01<*> 87ce0c50-01<*> 87d44730-01<*> 86d69aa8-01<*>
              88e5b020-01<*> 88734410-01<*> 898f2b40-01<*> 8a00a510-01<*>
              87e69db0-01<*> 8722b860-01<*> 86d8e308-01<*> 87263c50-01<*>
              8706ddb0-01<*> 892136e8-01<*> 8875b020-01<*> 8833ca48-01<*>
              8a100db0-01<*> 86b77590-01<*> 888bc020-01<*> 865c3db0-01<*>
              89fba910-01<*> 8a789660-01<*> 8670b2a8-01<*> 868737a8-01<*>
              868326d0-01<*> 871cdaf0-01<*> 8852edb0-01<*> 882b23b8-01<*>
              877e29e0-01<*> 8774f558-01<*> 876aa020-01<*> 89187518-01<*>
              8664b8e0-01<*> 865b4478-01<*> 88135020-01<*> 8686f020-01<*>
              866a0190-01<*> 87316758-01<*> 894dab18-01<*> 87938560-01<*>
              8658f5f0-01<*> 88e54020-01<*> 867f6350-01<*> 89246af8-01<*>
              86801430-01<*> 86db2af0-01<*> 865cf588-01<*> 86ab64f8-01<*>
              8a4a61e8-01<*> 885f3020-01<*> 86ea9af0-01<*> 8a4a7ba8-01<*>
              8a746b08-01<*> 89fc4790-01<*> 87093b10-01<*> 8659bc50-01<*>
              86681db0-01<*> 87102228-01<*> 866145a0-01<*> 866dddb0-01<*>
              86bda990-01<*> 88257db0-01<*> 8687d590-01<*> 867a9db0-01<*>
              89898848-01<*> 8a49b920-01<*> 86596db0-01<*> 8a0f7db0-01<*>
              866c1b40-01<*> 8754e020-01<*> 87fc1428-01<*> 8658c870-01<*>
              880d6a90-01<*> 88be6c50-01<*> 86bbcdb0-01<*> 8a37b8f8-01<*>
              866a13e0-01<*> 873e33d0-01<*> 87d43db0-01<*> 88a5adb0-01<*>
              884a5440-01<*> 883646f0-01<*> 87128020-01<*> 88e1d020-01<*>
              888e6418-01<*> 875c7c50-01<*> 871dd020-01<*> 890d5838-01<*>
              88d061f0-01<*> 88a09428-01<*> 8972f780-01<*> 87325b08-01<*>
              86deb020-01<*> 878b31b8-01<*> 891ac8a8-01<*> 86b234c0-01<*>
              86dd2190-01<*> 875f9db0-01<*> 87bbf200-01<*> 8a1a9c40-01<*>
              88628020-01<*> 87919020-01<*> 87c2a660-01<*> 877dc7c0-01<*>
              8a08adb0-01<*> 87c0f628-01<*> 87ca9a28-01<*> 8880a210-01<*>
              86ec0020-01<*> 88571020-01<*> 8a01edb0-01<*> 88115db0-01<*>
              87a9adb0-01<*> 879ecdb0-01<*> 8868ddb0-01<*> 872bcb58-01<*>
              884a0100-01<*> 8929f020-01<*> 87087020-01<*> 886e75a8-01<*>
              885a5908-01<*> 8762c020-01<*> 89550db0-01<*> 8a554768-01<*>
              89f10680-01<*> 87b322e8-01<*> 87cc74d0-01<*> 883ee2d0-01<*>
              8956caf8-01<*> 8788f330-01<*> 87d5c320-01<*> 86b99db0-01<*>
              876f42e0-01<*> 88e812d0-01<*> 8687cdb0-01<*> 8677a310-01<*>
              89711b40-01<*> 89b013a8-01<*> 86abcdb0-01<*> 89fd7bb0-01<*>
              877c22b0-01<*> 883fc850-01<*> 889e11f8-01<*> 892ff0e0-01<*>
              878ac490-01<*> 86de5c50-01<*> 87741db0-01<*> 8679f020-01<*>
              880ac6d0-01<*> 86d8fb00-01<*>
KD: Scanning for held locks….

Resource @ Ntfs!NtfsData (0xf71665b0)    Shared 1 owning threads
     Threads: 8a78d660-01<*>
KD: Scanning for held locks.

Resource @ 0x8a5c7734    Shared 1 owning threads
    Contention Count = 507565
    NumberOfSharedWaiters = 128
    NumberOfExclusiveWaiters = 1
     Threads: 894b4db0-01    87c773e0-01    88de7020-01    891c9db0-01   
              894d2020-01    865af5f8-01    87867340-01    88c964a0-01<*>
              88e57c98-01    87ae3020-01    86dbe730-01    88343790-01   
              871102e8-01    8855f020-01    87c99920-01    8796a318-01   
              88028db0-01    88ad6610-01    88b73db0-01    89fba3f0-01   
              87d8bc00-01    86f4c5c8-01    8a028608-01    88c783f0-01   
              88c138e0-01    89236910-01    896fbb78-01    88523600-01   
              8926f3b0-01    88a49a48-01    87c19750-01    86c88c50-01   
              88adfad8-01    872b0020-01    87ecab18-01    88b02020-01   
              875f9b10-01    8755e020-01    86f9fdb0-01    86a1cab8-01   
              86816858-01    881eedb0-01    894a99f0-01    87c97740-01   
              8a3bf4b0-01    867765a8-01    8a787660-01    86810330-01   
              876ad268-01    87af3320-01    865fedb0-01    88eb8230-01   
              86b0c438-01    881c0230-01    888b67c8-01    883e3210-01   
              87acbc50-01    873d6648-01    86ed0db0-01    88e2d020-01   
              89fdadb0-01    8934e830-01    870f89f0-01    8756c5e0-01   
              878c88d0-01    86fec608-01    88fdb420-01    87fa0628-01   
              87cad8d8-01    88ee3978-01    86fc49a0-01    875d5020-01   
              871a5020-01    89667a60-01    87170db0-01    88254ae0-01   
              8775e408-01    88204db0-01    87989890-01    873b89a8-01   
              888e6bf8-01    88cc3db0-01    88bf1590-01    879565a0-01   
              86773db0-01    8731a020-01    88aa7a78-01    8759cdb0-01   
              87e555f8-01    86de5678-01    86e28020-01    86ec9320-01   
              86871af0-01    8719cba0-01    8723f820-01    884dac20-01   
              89249020-01    889da168-01    8900b810-01    8a78d660-01   
              88cac758-01    892984c8-01    87d0c020-01    87ecec50-01   
              87ad8c90-01    88109aa8-01    86ef5bf0-01    8a78d3f0-01   
              88d2b020-01    88640db0-01    86fec878-01    895b12d8-01   
              86dd6708-01    87386930-01    888e34e0-01    86a56c50-01   
              8815f768-01    886c42a0-01    898f2020-01    87ca3610-01   
              886dd448-01    86ada210-01    8a37adb0-01    8896c940-01   
              8800e898-01    8733d4b8-01    865fa358-01    88ae1af0-01   
              868dd020-01   
     Threads Waiting On Exclusive Access:
              8a78b020
     

Both swarms are grouped around NTFS structures as can be seen from thread stack traces but also have another module in common: PGPsdk

0: kd> !thread 88bf1590 1f
THREAD 88bf1590  Cid 4354.2338  Teb: 7ffdf000 Win32Thread: bc3e88f8 WAIT: (Unknown) KernelMode Non-Alertable
    8a7a73d8  Semaphore Limit 0x7fffffff
    88bf1608  NotificationTimer
IRP List:
    86fb39d0: (0006,0268) Flags: 00000004  Mdl: 00000000
Not impersonating
DeviceMap                 e13c9ca0
Owning Process            869a6d88       Image:         ApplicationA.exe
Wait Start TickCount      15423469       Ticks: 30 (0:00:00:00.468)
Context Switch Count      6465                 LargeStack
UserTime                  00:00:00.343
KernelTime                00:00:01.062
Win32 Start Address 0x0056f122
Start Address 0x77e617f8
Stack Init 97e9d000 Current 97e9c788 Base 97e9d000 Limit 97e98000 Call 0
Priority 14 BasePriority 8 PriorityDecrement 6
ChildEBP RetAddr 
97e9c7a0 8083d5b1 nt!KiSwapContext+0x26
97e9c7cc 8083df9e nt!KiSwapThread+0x2e5
97e9c814 8081e05b nt!KeWaitForSingleObject+0x346
97e9c850 80824ba8 nt!ExpWaitForResource+0xd5
97e9c870 f718a07d nt!ExAcquireResourceSharedLite+0xf5
97e9c884 f717b2eb Ntfs!NtfsAcquireSharedVcb+0×23
97e9c8f0 f717a2e2 Ntfs!NtfsCommonFlushBuffers+0xf5
97e9c954 80840153 Ntfs!NtfsFsdFlushBuffers+0×92

97e9c968 f7272c45 nt!IofCallDriver+0×45
97e9c990 80840153 fltmgr!FltpDispatch+0×6f
97e9c9a4 f6fb1835 nt!IofCallDriver+0×45
WARNING: Stack unwind information not available. Following frames may be wrong.
97e9c9b8 f6fad69a PGPsdk+0×5835
97e9c9c4 80840153 PGPsdk+0×169a

86fb39d0 00000000 nt!IofCallDriver+0×45

0: kd> !thread 88c964a0 1f
THREAD 88c964a0  Cid 323c.43f0  Teb: 7ffad000 Win32Thread: bc2ceea8 WAIT: (Unknown) KernelMode Non-Alertable
    88268338  SynchronizationEvent
    88c96518  NotificationTimer
IRP List:
    86dad430: (0006,0268) Flags: 00000404  Mdl: 00000000
Not impersonating
DeviceMap                 e16c8eb0
Owning Process            8886ac88       Image:         ApplicationB.EXE
Wait Start TickCount      15423352       Ticks: 147 (0:00:00:02.296)
Context Switch Count      1660                 LargeStack
UserTime                  00:00:00.078
KernelTime                00:00:00.109
Win32 Start Address 0x14225c34
Start Address 0x77e617ec
Stack Init 96835000 Current 96834640 Base 96835000 Limit 96832000 Call 0
Priority 14 BasePriority 8 PriorityDecrement 6
ChildEBP RetAddr 
96834658 8083d5b1 nt!KiSwapContext+0x26
96834684 8083df9e nt!KiSwapThread+0x2e5
968346cc 8081e05b nt!KeWaitForSingleObject+0x346
96834708 8082e012 nt!ExpWaitForResource+0xd5
96834728 f714b89b nt!ExAcquireResourceExclusiveLite+0x8d
96834738 f718b194 Ntfs!NtfsAcquirePagingResourceExclusive+0×20
9683493c f718b8d9 Ntfs!NtfsCommonCleanup+0×193
96834aac 80840153 Ntfs!NtfsFsdCleanup+0xcf

96834ac0 f7272c45 nt!IofCallDriver+0×45
96834ae8 80840153 fltmgr!FltpDispatch+0×6f
96834afc f6fb196c nt!IofCallDriver+0×45
WARNING: Stack unwind information not available. Following frames may be wrong.
96834b10 f6fad69a PGPsdk+0×596c
96834b1c 80840153 PGPsdk+0×169a

86dad430 00000000 nt!IofCallDriver+0×45

Because no processors are busy except the one that processes crash dump request via NMI interrupt and there are no ready threads it would be natural to assume that the problem with paging started some time ago and some checks for 3rd-party volume encryption software are necessary as PGP name of the module suggests:

0: kd> lmv m PGPsdk
start    end        module name
f6fac000 f6fb7000   PGPsdk     (no symbols)          
    Loaded symbol image file: PGPsdk.sys
    Image path: \SystemRoot\System32\Drivers\PGPsdk.sys
    Image name: PGPsdk.sys
    Timestamp:        Wed Jun 09 11:44:04 2004 (40C6E9F4)
    CheckSum:         00010F72
    ImageSize:        0000B000
    Translations:     0000.04b0 0000.04e0 0409.04b0 0409.04e0

0: kd> !running

System Processors f (affinity mask)
  Idle Processors e

     Prcb      Current   Next   
  0  ffdff120  808a68c0  86841588  ................

0: kd> !thread 808a68c0 1f
THREAD 808a68c0  Cid 0000.0000  Teb: 00000000 Win32Thread: 00000000 RUNNING on processor 0
Not impersonating
Owning Process            808a6b40       Image:         Idle
Wait Start TickCount      0              Ticks: 15423499 (2:18:56:32.171)
Context Switch Count      100782385            
UserTime                  00:00:00.000
KernelTime                2 Days 12:18:49.343
Stack Init 808a38b0 Current 808a35fc Base 808a38b0 Limit 808a08b0 Call 0
Priority 0 BasePriority 0 PriorityDecrement 0
ChildEBP RetAddr 
808a07bc 80a84df7 nt!KeBugCheckEx+0x1b
808a080c 80834b83 hal!HalHandleNMI+0x1a5
808a080c 80a80853 nt!KiTrap02+0x136 (TrapFrame @ 808a0820)
808a3570 f7659ca2 hal!HalpClockInterrupt+0xff (TrapFrame @ 808a3570)
808a3600 80839b12 intelppm!AcpiC1Idle+0x12
808a3604 00000000 nt!KiIdleLoop+0xa

0: kd> !ready
Processor 0: No threads in READY state
Processor 1: No threads in READY state
Processor 2: No threads in READY state
Processor 3: No threads in READY state

- Dmitry Vostokov @ DumpAnalysis.org -