Archive for the ‘Crash Dump Patterns’ Category

Crash Dump Analysis Patterns (Part 166)

Sunday, February 12th, 2012

Runtime software exceptions (such as C++ exceptions) can be translated by custom exception handlers into other exceptions by changing exception data. This is different from nested exceptions where another exception is thrown. One example of such possible translation I recently encountered when looking at a raw stack data (!teb -> dps) having signs of hidden exceptions (multiple RaiseException calls) and also CLR execution residue (valid return addresses of clr module). In addition of final invalid handle exception and one hidden access violation there were many exception codes c0000027. Google search pointed to the article about skipped C++ destructors written by S. Senthil Kumar that prompted me to introduce the pattern Translated Exception.

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

Forthcoming Accelerated Mac OS X Core Dump Analysis training

Wednesday, February 1st, 2012

Memory Dump Analysis Services plans to introduce Mac OS X memory dump analysis training this year based on the success of its Windows variant. For details and how to register please visit this page:

http://www.dumpanalysis.com/accelerated-mac-os-x-core-dump-analysis

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

New Book: Advanced Windows Memory Dump Analysis

Friday, January 27th, 2012

Advanced training sessions time may not suitable due to different geographic time zones. So I have decided to publish this training in a book format (currently in PDF) and make it available in paperback on Amazon and B&N later. Book details:

  • Title: Advanced Windows Memory Dump Analysis with Data Structures: Training Course Transcript and WinDbg Practice Exercises with Notes
  • Description: The full transcript of Memory Dump Analysis Services Training with 10 step-by-step exercises, notes, and selected Q&A.
  • Authors: Dmitry Vostokov, Memory Dump Analysis Services
  • Publisher: OpenTask (January 2012)
  • Language: English
  • Product Dimensions: 28.0 x 21.6
  • Paperback: 180 pages
  • ISBN-13: 978-1908043344

Table of Contents

Now available for sale in PDF format from Memory Dump Analysis Services.

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

Crash Dump Analysis Patterns (Part 27d)

Wednesday, January 11th, 2012

In addition to stack trace collections for threads (unmanaged, managed and predicate) we introduce an additional pattern for I/O requests. Such requests are implemented via the so called I/O request packets (IRP) that “travel” from a device driver to a device driver similar to a C++ class method to another C++ class method (where a device object address is similar to a C++ object instance address). An IRP stack is used to keep a track of the current driver which is processing an IRP that is reused between device drivers. Its is basically an array of structures describing how a particular driver function was called with appropriate parameters similar to a call frame on an execution thread stack. Long time ago I created an UML diagram depicting the flow of an IRP through the driver (device) stack (diagram #3). An I/O stack location pointer is decremented (from the bottom to the top) like a thread stack pointer (ESP or RSP). We can list active and completed I/O requests with their stack traces using !irpfind -v WinDbg command:

1: kd> !irpfind -v

Scanning large pool allocation table for Tag: Irp? (832c7000 : 833c7000)

Irp    [ Thread ] irpStack: (Mj,Mn)   DevObj  [Driver]         MDL Process
8883dc18: Irp is active with 1 stacks 1 is current (= 0x8883dc88)
No Mdl: No System Buffer: Thread 888f8950:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  d, 0]   5  1 88515ae8 888f82f0 00000000-00000000    pending
\FileSystem\Npfs
Args: 00000000 00000000 00110008 00000000

891204c8: Irp is active with 1 stacks 1 is current (= 0x89120538)
No Mdl: No System Buffer: Thread 889635b0:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  3, 0]   0  1 88515ae8 84752028 00000000-00000000    pending
\FileSystem\Npfs
Args: 0000022a 00000000 00000000 00000000

89120ce8: Irp is active with 1 stacks 1 is current (= 0x89120d58)
No Mdl: No System Buffer: Thread 89212030:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  3, 0]   0  1 88515ae8 8921be00 00000000-00000000    pending
\FileSystem\Npfs
Args: 0000022a 00000000 00000000 00000000
Searching NonPaged pool (80000000 : ffc00000) for Tag: Irp?

[...]

892cbe48: Irp is active with 9 stacks 9 is current (= 0x892cbfd8)
No Mdl: No System Buffer: Thread 892add78:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
>[  c, 2]   0  1 8474a020 892c8c80 00000000-00000000    pending
\FileSystem\Ntfs
Args: 00000800 00000002 00000000 00000000

892daa88: Irp is active with 4 stacks 4 is current (= 0x892dab64)
No Mdl: System buffer=831559c8: Thread 8322c8e8:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
>[  e,2d]   5  1 884ba750 83190c40 00000000-00000000    pending
\Driver\AFD
Args: 890cbc44 890cbc44 88e55297 8943b6c8

892ea4e8: Irp is active with 4 stacks 4 is current (= 0x892ea5c4)
No Mdl: No System Buffer: Thread 00000000:  Irp stack trace.  Pending has been returned
cmd  flg cl Device   File     Completion-Context
[  0, 0]   0  2 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 c0000185
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  f, 0]   0  2 83a34bb0 00000000 84d779ed-88958050
\Driver\atapi CLASSPNP!ClasspMediaChangeDetectionCompletion
Args: 88958050 00000000 00000000 83992d10
>[  0, 0]   2  0 891ee030 00000000 00000000-00000000
\Driver\cdrom
Args: 00000000 00000000 00000000 00000000

8933fcb0: Irp is active with 1 stacks 1 is current (= 0x8933fd20)
No Mdl: No System Buffer: Thread 84753d78:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  3, 0]   0  1 88515ae8 84759f40 00000000-00000000    pending
\FileSystem\Npfs
Args: 0000022a 00000000 00000000 00000000

893cf550: Irp is active with 1 stacks 1 is current (= 0x893cf5c0)
No Mdl: No System Buffer: Thread 888fd3b8:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  3, 0]   0  1 88515ae8 834d30d0 00000000-00000000    pending
\FileSystem\Npfs
Args: 00000400 00000000 00000000 00000000

893da468: Irp is active with 6 stacks 7 is current (= 0x893da5b0)
Mdl=892878f0: No System Buffer: Thread 00000000:  Irp is completed.  Pending has been returned
cmd  flg cl Device   File     Completion-Context
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  f, 0]   0  0 84b3e028 00000000 9747fcd0-00000000
\Driver\usbehci USBSTOR!USBSTOR_CswCompletion
Args: 00000000 00000000 00000000 00000000
[  f, 0]   0  0 892ba8f8 00000000 84d780ce-8328e0f0
\Driver\USBSTOR CLASSPNP!TransferPktComplete
Args: 00000000 00000000 00000000 00000000

893efb00: Irp is active with 10 stacks 11 is current (= 0x893efcd8)
Mdl=83159378: No System Buffer: Thread 82b7f828:  Irp is completed.  Pending has been returned
cmd  flg cl Device   File     Completion-Context
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  3, 0]   0  0 885a55b8 00000000 81614138-00000000
\Driver\disk partmgr!PmReadWriteCompletion
Args: 00000000 00000000 00000000 00000000
[  3, 0]   0  0 89257c90 00000000 8042e4d4-831caab0
\Driver\partmgr volmgr!VmpReadWriteCompletionRoutine
Args: 00000000 00000000 00000000 00000000
[  3, 0]   0  0 831ca9f8 00000000 84dad0be-00000000
\Driver\volmgr ecache!EcDispatchReadWriteCompletion
Args: 00000000 00000000 00000000 00000000
[  3, 0]   0  0 8319c020 00000000 84dcc4d4-8576f8ac
\Driver\Ecache volsnap!VspSignalCompletion
Args: 00000000 00000000 00000000 00000000

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

Crash Dump Analysis Patterns (Part 20c)

Monday, December 26th, 2011

Sometimes we have memory leaks related to the growing number of page tables. One reason for that could be the growing number of zombie processes (noticeable with tens of thousands of them).

1: kd> !process 0 0
[...] 
PROCESS fffffa80266bd6f0
    SessionId: 0  Cid: 0a6c    Peb: 7fffffdc000  ParentCid: 03ac
    DirBase: 9d35a000  ObjectTable: fffff8a00170ac80  HandleCount: 152.
    Image: svchost.exe
[…] 
PROCESS fffffa8027de9b30
    SessionId: 0  Cid: 21d0    Peb: 7fffffdf000  ParentCid: 02e0
    DirBase: 37881000  ObjectTable: 00000000  HandleCount:   0.
    Image: conhost.exe
[…] 
PROCESS fffffa8028eb0600
    SessionId: 0  Cid: ab88    Peb: 7fffffdf000  ParentCid: 02e0
    DirBase: 27a2f000  ObjectTable: 00000000  HandleCount:   0.
    Image: conhost.exe
[…]

Even zombies have at least one remaining page (page directory) from the former page tables of their virtual to physical memory mapping (!dd is the same as dd command but for physical memory):

1: kd> !dd 9d35a000
#9d35a000 9dd62867 03c00000 00000000 00000000
#9d35a010 00000000 00000000 00000000 00000000
#9d35a020 00000000 00000000 00000000 00000000
#9d35a030 00000000 00000000 00000000 00000000
#9d35a040 00000000 00000000 00000000 00000000
#9d35a050 00000000 00000000 00000000 00000000
#9d35a060 00000000 00000000 00000000 00000000
#9d35a070 00000000 00000000 9d45e867 49500000

1: kd> !dd 37881000
#37881000 00000000 00000000 00000000 00000000
#37881010 00000000 00000000 00000000 00000000
#37881020 00000000 00000000 00000000 00000000
#37881030 00000000 00000000 00000000 00000000
#37881040 00000000 00000000 00000000 00000000
#37881050 00000000 00000000 00000000 00000000
#37881060 00000000 00000000 00000000 00000000
#37881070 00000000 00000000 00000000 00000000

1: kd> !dd 27a2f000
#27a2f000 00000000 00000000 00000000 00000000
#27a2f010 00000000 00000000 00000000 00000000
#27a2f020 00000000 00000000 00000000 00000000
#27a2f030 00000000 00000000 00000000 00000000
#27a2f040 00000000 00000000 00000000 00000000
#27a2f050 00000000 00000000 00000000 00000000
#27a2f060 00000000 00000000 00000000 00000000
#27a2f070 00000000 00000000 00000000 00000000

We also see that 2 conhost.exe processes have identical physical to virtual mapping because their user space mappings are no longer valid (zeroed) and svchost.exe process has user space mapping (in blue italics):

1: kd> !ptov 27a2f000
Amd64PtoV: pagedir 27a2f000
27a2f000 fffff6fb`7dbed000
71530000 fffff6fb`7dbee000
19d000 fffff6fb`7dbef000
199000 fffff6fb`7dbf0000
b6a04000 fffff6fb`7dbf1000
b1f57000 fffff6fb`7dbf2000
29c4000 fffff6fb`7dbf3000
1c53000 fffff6fb`7dbf5000 
[…]
2e4d8000 fffffa80`28f2d000
2c3d7000 fffffa80`28f2e000
30ed6000 fffffa80`28f2f000
2efd5000 fffffa80`28f30000
2ded4000 fffffa80`28f31000
2a5d3000 fffffa80`28f32000
bb400000 fffffa80`29600000 (large page)
bb200000 fffffa80`29800000 (large page)
100000 ffffffff`ffd00000
105000 ffffffff`ffd01000
101000 ffffffff`ffd02000
102000 ffffffff`ffd03000
103000 ffffffff`ffd04000
104000 ffffffff`ffd05000
fec00000 ffffffff`ffd06000
1000 ffffffff`ffd07000
106000 ffffffff`ffd08000
123000 ffffffff`ffd09000
0 ffffffff`ffd0a000
124000 ffffffff`ffd0b000
2000 ffffffff`ffd0c000
e00c7000 ffffffff`ffd0d000
e0080000 ffffffff`ffd0e000
107000 ffffffff`ffd25000
108000 ffffffff`ffd26000
109000 ffffffff`ffd27000
10a000 ffffffff`ffd28000
10b000 ffffffff`ffd29000
10c000 ffffffff`ffd2a000
10d000 ffffffff`ffd2b000
10e000 ffffffff`ffd2c000
10f000 ffffffff`ffd2d000
110000 ffffffff`ffd2e000
111000 ffffffff`ffd2f000
112000 ffffffff`ffd30000
113000 ffffffff`ffd31000
114000 ffffffff`ffd32000
115000 ffffffff`ffd33000
116000 ffffffff`ffd34000
117000 ffffffff`ffd35000
118000 ffffffff`ffd36000
119000 ffffffff`ffd37000
11a000 ffffffff`ffd38000
11b000 ffffffff`ffd39000
11c000 ffffffff`ffd3a000
11d000 ffffffff`ffd3b000
11e000 ffffffff`ffd3c000
11f000 ffffffff`ffd3d000
120000 ffffffff`ffd3e000
121000 ffffffff`ffd3f000
122000 ffffffff`ffd40000
fee00000 ffffffff`fffe0000

1: kd> !ptov 37881000
Amd64PtoV: pagedir 37881000
37881000 fffff6fb`7dbed000
8d482000 fffff6fb`7dbee000
19d000 fffff6fb`7dbef000
199000 fffff6fb`7dbf0000
b6a04000 fffff6fb`7dbf1000
b1f57000 fffff6fb`7dbf2000
29c4000 fffff6fb`7dbf3000
1c53000 fffff6fb`7dbf5000
[…]
2e4d8000 fffffa80`28f2d000
2c3d7000 fffffa80`28f2e000
30ed6000 fffffa80`28f2f000
2efd5000 fffffa80`28f30000
2ded4000 fffffa80`28f31000
2a5d3000 fffffa80`28f32000
bb400000 fffffa80`29600000 (large page)
bb200000 fffffa80`29800000 (large page)
100000 ffffffff`ffd00000
105000 ffffffff`ffd01000
101000 ffffffff`ffd02000
102000 ffffffff`ffd03000
103000 ffffffff`ffd04000
104000 ffffffff`ffd05000
fec00000 ffffffff`ffd06000
1000 ffffffff`ffd07000
106000 ffffffff`ffd08000
123000 ffffffff`ffd09000
0 ffffffff`ffd0a000
124000 ffffffff`ffd0b000
2000 ffffffff`ffd0c000
e00c7000 ffffffff`ffd0d000
e0080000 ffffffff`ffd0e000
107000 ffffffff`ffd25000
108000 ffffffff`ffd26000
109000 ffffffff`ffd27000
10a000 ffffffff`ffd28000
10b000 ffffffff`ffd29000
10c000 ffffffff`ffd2a000
10d000 ffffffff`ffd2b000
10e000 ffffffff`ffd2c000
10f000 ffffffff`ffd2d000
110000 ffffffff`ffd2e000
111000 ffffffff`ffd2f000
112000 ffffffff`ffd30000
113000 ffffffff`ffd31000
114000 ffffffff`ffd32000
115000 ffffffff`ffd33000
116000 ffffffff`ffd34000
117000 ffffffff`ffd35000
118000 ffffffff`ffd36000
119000 ffffffff`ffd37000
11a000 ffffffff`ffd38000
11b000 ffffffff`ffd39000
11c000 ffffffff`ffd3a000
11d000 ffffffff`ffd3b000
11e000 ffffffff`ffd3c000
11f000 ffffffff`ffd3d000
120000 ffffffff`ffd3e000
121000 ffffffff`ffd3f000
122000 ffffffff`ffd40000
fee00000 ffffffff`fffe0000

1: kd> !ptov 9d35a000
Amd64PtoV: pagedir 9d35a000
9e587000 10000
6871e000 20000
af5aa000 30000
af5ab000 31000
afaac000 32000
afbad000 33000
af2f5000 40000
9d66b000 50000
22199000 60000
9d962000 e5000
9d261000 e6000
9dc60000 e7000
9d256000 ea000
9d84f000 eb000
9e4ec000 ec000
9e081000 ed000
9d876000 ee000
9e271000 ef000
b8bfd000 f0000
b8efe000 f1000
b86ff000 f2000
b5302000 f3000
b5202000 f4000
b5502000 f5000
b7f03000 f6000
b8404000 f7000
b8415000 100000
b8b16000 101000
b1b17000 102000
[…]
2cd4000 77512000
5d7000 77515000
5d8000 77516000
4d9000 77517000
b358f000 77590000
aef04000 77591000
68624000 77592000
64b26000 77593000
af4c6000 77595000
b2042000 7efe0000
b2143000 7efe1000
b1a56000 7efe2000
b1a57000 7efe3000
b1b58000 7efe4000
1ba000 7ffe0000
9da69000 bfeb0000
aeeae000 ffea0000
af191000 ffea1000
9d76a000 ffea2000
ae793000 ffea3000
9dc8e000 ffea5000
b7eb7000 ffea6000
9dffc000 ffea7000

[…]
2e4d8000 fffffa80`28f2d000
2c3d7000 fffffa80`28f2e000
30ed6000 fffffa80`28f2f000
2efd5000 fffffa80`28f30000
2ded4000 fffffa80`28f31000
2a5d3000 fffffa80`28f32000
bb400000 fffffa80`29600000 (large page)
bb200000 fffffa80`29800000 (large page)
100000 ffffffff`ffd00000
105000 ffffffff`ffd01000
101000 ffffffff`ffd02000
102000 ffffffff`ffd03000
103000 ffffffff`ffd04000
104000 ffffffff`ffd05000
fec00000 ffffffff`ffd06000
1000 ffffffff`ffd07000
106000 ffffffff`ffd08000
123000 ffffffff`ffd09000
0 ffffffff`ffd0a000
124000 ffffffff`ffd0b000
2000 ffffffff`ffd0c000
e00c7000 ffffffff`ffd0d000
e0080000 ffffffff`ffd0e000
107000 ffffffff`ffd25000
108000 ffffffff`ffd26000
109000 ffffffff`ffd27000
10a000 ffffffff`ffd28000
10b000 ffffffff`ffd29000
10c000 ffffffff`ffd2a000
10d000 ffffffff`ffd2b000
10e000 ffffffff`ffd2c000
10f000 ffffffff`ffd2d000
110000 ffffffff`ffd2e000
111000 ffffffff`ffd2f000
112000 ffffffff`ffd30000
113000 ffffffff`ffd31000
114000 ffffffff`ffd32000
115000 ffffffff`ffd33000
116000 ffffffff`ffd34000
117000 ffffffff`ffd35000
118000 ffffffff`ffd36000
119000 ffffffff`ffd37000
11a000 ffffffff`ffd38000
11b000 ffffffff`ffd39000
11c000 ffffffff`ffd3a000
11d000 ffffffff`ffd3b000
11e000 ffffffff`ffd3c000
11f000 ffffffff`ffd3d000
120000 ffffffff`ffd3e000
121000 ffffffff`ffd3f000
122000 ffffffff`ffd40000
fee00000 ffffffff`fffe0000

In order to check user space virtual addresses we have to switch to the corresponding process context:

1: kd> !pte fffffa80`28f2d000
                                           VA fffffa8028f2d000
PXE at FFFFF6FB7DBEDFA8    PPE at FFFFF6FB7DBF5000    PDE at FFFFF6FB7EA00A38    PTE at FFFFF6FD40147968
contains 0000000001C53863  contains 0000000001C54863  contains 0000000049320863  contains 000000002E4D8963
pfn 1c53      —DA–KWEV  pfn 1c54      —DA–KWEV  pfn 49320     —DA–KWEV  pfn 2e4d8     -G-DA–KWEV

1: kd> .process /r /p fffffa80266bd6f0
Implicit process is now fffffa80`266bd6f0
Loading User Symbols

1: kd> !pte 10000
                                           VA 0000000000010000
PXE at FFFFF6FB7DBED000    PPE at FFFFF6FB7DA00000    PDE at FFFFF6FB40000000    PTE at FFFFF68000000080
contains 03C000009DD62867  contains 031000009D865867  contains 7C2000009DD66867  contains 9CB000009E587867
pfn 9dd62     —DA–UWEV  pfn 9d865     —DA–UWEV  pfn 9dd66     —DA–UWEV  pfn 9e587     —DA–UW-V

This pattern came to our attention after several customers complained about the growing number of memory allocated for page tables which exceeded a gigabyte after several days.

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

Crash Dump Analysis Patterns (Part 165)

Monday, December 26th, 2011

Sometimes debugging information is absent from module info in memory dumps and a debugger can’t recognize and automatically load symbol files. For example, we see this stack trace without loaded component symbols:

THREAD 8a17c6d8  Cid 02ec.02f0  Teb: 7ffdf000 Win32Thread: e17b4420 WAIT: (UserRequest) UserMode Non-Alertable
89873d00  SynchronizationEvent
IRP List:
89d9fd20: (0006,0094) Flags: 00000800  Mdl: 00000000
Not impersonating
DeviceMap                 e10086c8
Owning Process            0       Image:         <Unknown>
Attached Process          8a17cda0       Image:         ApplicationA.exe
Wait Start TickCount      8164394        Ticks: 2884 (0:00:00:45.062)
Context Switch Count      1769160                 LargeStack
UserTime                  00:00:55.250
KernelTime                00:01:56.109
Start Address 0×0103e5e1
Stack Init ba390000 Current ba38fca0 Base ba390000 Limit ba38b000 Call 0
Priority 15 BasePriority 15 PriorityDecrement 0 DecrementCount 0
*** ERROR: Module load completed but symbols could not be loaded for ModuleA.dll
ChildEBP RetAddr
ba38fcb8 80503836 nt!KiSwapContext+0×2f
ba38fcc4 804fb068 nt!KiSwapThread+0×8a
ba38fcec 805c0750 nt!KeWaitForSingleObject+0×1c2
ba38fd50 8054161c nt!NtWaitForSingleObject+0×9a
ba38fd50 7c90e4f4 nt!KiFastCallEntry+0xfc (TrapFrame @ ba38fd64)
0006f648 7c90df3c ntdll!KiFastSystemCallRet
0006f64c 7c91b22b ntdll!NtWaitForSingleObject+0xc
0006f6d4 7c901046 ntdll!RtlpWaitForCriticalSection+0×132
0006f6dc 01373df7 ntdll!RtlEnterCriticalSection+0×46
WARNING: Stack unwind information not available. Following frames may be wrong.
0006f7a4 0132b785 ModuleA+0×53df7
0006f7cc 0132c728 ModuleA+0xb785
0006f7e4 01346426 ModuleA+0xc728
0006f848 7e418734 ModuleA+0×26426

0006f874 7e418816 USER32!InternalCallWinProc+0×28
0006f8dc 7e4189cd USER32!UserCallWinProcCheckWow+0×150
0006f93c 7e418a10 USER32!DispatchMessageWorker+0×306
0006f94c 0084367e USER32!DispatchMessageW+0xf

0: kd> .process /r /p 8a17cda0
Implicit process is now 8a17cda0
Loading User Symbols

0: kd> lmv m ModuleA
start    end        module name
01320000 013bb000   ModuleA   (deferred)
Image path: C:\Program Files\VendorA\ModuleA.dll
Image name: ModuleA.dll
Timestamp:        Thu Aug 11 21:42:08 2011 (4E4484F0)
CheckSum:         000A9C8B
ImageSize:        0009B000
Translations:     0000.04b0 0000.04e4 0409.04b0 0409.04e4

0: kd> !lmi ModuleA
Loaded Module Info: [ModuleA]
Module: ModuleA
Base Address: 01320000
Image Name: ModuleA.dll
Machine Type: 332 (I386)
Time Stamp: 4e4484f0 Thu Aug 11 21:42:08 2011
Size: 9b000
CheckSum: a9c8b
Characteristics: 2102
Debug Data Dirs: Type  Size     VA  Pointer
CODEVIEW    5e, 830a0,   830a0 [Debug data not mapped] - can’t validate symbols, if present.
Symbol Type: DEFERRED - No error - symbol load deferred
Load Report: no symbols loaded

However, in a stack trace collection (!process 0 ff WinDbg command) we find another stack trace from a different process but with loaded symbol files for ModuleA:

THREAD 89703020  Cid 1068.1430  Teb: 7ffdf000 Win32Thread: e34d43a8 WAIT: (UserRequest) UserMode Non-Alertable
89a3ac58  NotificationEvent
89703110  NotificationTimer
IRP List:
899ab488: (0006,0094) Flags: 00000900  Mdl: 00000000
Not impersonating
DeviceMap                 e10086c8
Owning Process            0       Image:         <Unknown>
Attached Process          89825020       Image:         ApplicationB.exe
Wait Start TickCount      8164457        Ticks: 2821 (0:00:00:44.078)
Context Switch Count      552                 LargeStack
UserTime                  00:00:00.296
KernelTime                00:00:00.890
Start Address 0×0103e5e1
Stack Init b8796000 Current b8795ca0 Base b8796000 Limit b8791000 Call 0
Priority 15 BasePriority 15 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr
b8795cb8 80503836 nt!KiSwapContext+0×2f
b8795cc4 804fb068 nt!KiSwapThread+0×8a
b8795cec 805c0750 nt!KeWaitForSingleObject+0×1c2
b8795d50 8054161c nt!NtWaitForSingleObject+0×9a
b8795d50 7c90e4f4 nt!KiFastCallEntry+0xfc (TrapFrame @ b8795d64)
0006fa1c 7c90df3c ntdll!KiFastSystemCallRet
0006fa20 7c8025db ntdll!NtWaitForSingleObject+0xc
0006fa84 010ae96a kernel32!WaitForSingleObjectEx+0xa8
0006fafc 010aeaaf ModuleA!Wait+0xaa
0006fb38 010b84ce ModuleA!Read+0×6f

[…]

0: kd> !lmi ModuleA
Loaded Module Info: [ModuleA]
Module: ModuleA
Base Address: 01090000
Image Name: ModuleA.dll
Machine Type: 332 (I386)
Time Stamp: 4e4484f0 Thu Aug 11 21:42:08 2011
Size: 9b000
CheckSum: a9c8b
Characteristics: 2102
Debug Data Dirs: Type  Size     VA  Pointer
CODEVIEW    5e, 830a0,   830a0 RSDS - GUID: {C14E734A-367F-4DD0-974D-FA47C1194F28}
Age: 1, Pdb: Y:\src\…\ModuleA.pdb
Symbol Type: DEFERRED - No error - symbol load deferred
Load Report: no symbols loaded

0: kd> lmv m ModuleA
start    end        module name
01090000 0112b000   ModuleA   (deferred)
Image path: C:\Program Files\VendorA\ModuleA.dll
Image name: ModuleA.dll
Timestamp:        Thu Aug 11 21:42:08 2011 (4E4484F0)
CheckSum:         000A9C8B
ImageSize:        0009B000
File version:     1.3.0.0
Product version:  1.3.0.0
File flags:       8 (Mask 3F) Private
File OS:          40004 NT Win32
File type:        2.0 Dll
File date:        00000000.00000000
Translations:     0409.04b0
CompanyName:      VendorA
ProductName:      VendorA
InternalName:     ModuleA.dll
OriginalFilename: ModuleA.dll
ProductVersion:   1.3
FileVersion:      1.3.0.0
FileDescription:  ModuleA GUI
LegalCopyright:   Copyright VendorA

So we switch to that thread (with the new process context) to get the needed symbol path:

0: kd> .thread /r /p 89703020
Implicit thread is now 89703020
Implicit process is now 89825020
Loading User Symbols

0: kd> kL
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr
b8795cb8 80503836 nt!KiSwapContext+0x2f
b8795cc4 804fb068 nt!KiSwapThread+0x8a
b8795cec 805c0750 nt!KeWaitForSingleObject+0x1c2
b8795d50 8054161c nt!NtWaitForSingleObject+0x9a
b8795d50 7c90e4f4 nt!KiFastCallEntry+0xfc
0006fa1c 7c90df3c ntdll!KiFastSystemCallRet
0006fa20 7c8025db ntdll!NtWaitForSingleObject+0xc
0006fa84 010ae96a kernel32!WaitForSingleObjectEx+0xa8
0006fafc 010aeaaf ModuleA!Wait+0xaa
0006fb38 010b84ce ModuleA!Read+0×6f

[…]

0: kd> lmv m ModuleA
start    end        module name
01090000 0112b000   ModuleA   (private pdb symbols)  c:\sym\ModuleA.pdb\C14E734A367F4DD0974DFA47C1194F281\ModuleA.pdb
Loaded symbol image file: ModuleA.dll
[…]

Now we switch back to our problem stack trace and set the found symbol path explicitly:

0: kd> .thread /r /p 8a17c6d8
Implicit thread is now 8a17c6d8
Implicit process is now 8a17cda0
Loading User Symbols

0: kd> kL
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr
ba38fcb8 80503836 nt!KiSwapContext+0x2f
ba38fcc4 804fb068 nt!KiSwapThread+0x8a
ba38fcec 805c0750 nt!KeWaitForSingleObject+0x1c2
ba38fd50 8054161c nt!NtWaitForSingleObject+0x9a
ba38fd50 7c90e4f4 nt!KiFastCallEntry+0xfc
0006f648 7c90df3c ntdll!KiFastSystemCallRet
0006f64c 7c91b22b ntdll!NtWaitForSingleObject+0xc
0006f6d4 7c901046 ntdll!RtlpWaitForCriticalSection+0x132
*** ERROR: Module load completed but symbols could not be loaded for ModuleA.dll
0006f6dc 01373df7 ntdll!RtlEnterCriticalSection+0x46
WARNING: Stack unwind information not available. Following frames may be wrong.
0006f7a4 0132b785 ModuleA+0×53df7
0006f7cc 0132c728 ModuleA+0xb785
0006f7e4 01346426 ModuleA+0xc728
0006f848 7e418734 ModuleA+0×26426

0006f874 7e418816 USER32!InternalCallWinProc+0×28
0006f8dc 7e4189cd USER32!UserCallWinProcCheckWow+0×150
0006f93c 7e418a10 USER32!DispatchMessageWorker+0×306
0006f94c 0084367e USER32!DispatchMessageW+0xf
[…]

0: kd> .sympath+ c:\sym\ModuleA.pdb\C14E734A367F4DD0974DFA47C1194F281
Symbol search path is: SRV*c:\mss*http://msdl.microsoft.com/download/symbols; c:\sym\ModuleA.pdb\C14E734A367F4DD0974DFA47C1194F281
[…]

0: kd> .reload
Loading Kernel Symbols
Loading User Symbols
Loading unloaded module list

0: kd> kL
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr
ba38fcb8 80503836 nt!KiSwapContext+0x2f
ba38fcc4 804fb068 nt!KiSwapThread+0x8a
ba38fcec 805c0750 nt!KeWaitForSingleObject+0x1c2
ba38fd50 8054161c nt!NtWaitForSingleObject+0x9a
ba38fd50 7c90e4f4 nt!KiFastCallEntry+0xfc
0006f648 7c90df3c ntdll!KiFastSystemCallRet
0006f64c 7c91b22b ntdll!NtWaitForSingleObject+0xc
0006f6d4 7c901046 ntdll!RtlpWaitForCriticalSection+0x132
0006f6dc 01373df7 ntdll!RtlEnterCriticalSection+0x46
0006f6e4 0132b22e ModuleA!CSLock+0×7
0006f7a4 0132b785 ModuleA!SignalEvent+0×5e
[…]
0006f848 7e418734 ModuleA!WindowProc+0×136

0006f874 7e418816 USER32!InternalCallWinProc+0×28
0006f8dc 7e4189cd USER32!UserCallWinProcCheckWow+0×150
0006f93c 7e418a10 USER32!DispatchMessageWorker+0×306
0006f94c 0084367e USER32!DispatchMessageW+0xf
[…]

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

Crash Dump Analysis Patterns (Part 164)

Sunday, December 25th, 2011

When looking at network packet pools using NDIS WinDbg extension we might see increased number of allocated blocks possibly correlated with network problems, for example:

0: kd> !ndiskd.pktpools * normal
Pool     Allocator BlocksAllocated BlockSize PktsPerBlock PacketLength
8a467e20 b9090f96  0×1             0×1000    0×14         0xc8   tcpip!ARPRegister+119
8a491460 ba4eea56  0×1             0×1000    0×14         0xc8   wanarp!WanpInitializeNdis+a8
8a466508 b905d368  0×1             0×1000    0xd          0×138   tcpip!InitForwardingPools+53
8a373578 b905becb  0×3             0×1000    0×11         0xe8   tcpip!AllocIPPacketList+59
8a466580 b9095ac5  0×1             0×1000    0xe          0×118   tcpip!IPInit+e0
8a460958 bac40a97  0xb             0×1000    0×14         0xc8   vmxnet+a97

0: kd> !ndiskd.pktpools * no sent packets
Pool     Allocator BlocksAllocated BlockSize PktsPerBlock PacketLength
8a467e20 b9090f96  0×1             0×1000    0×14         0xc8 tcpip!ARPRegister+119
8a491460 ba4eea56  0×1             0×1000    0×14         0xc8 wanarp!WanpInitializeNdis+a8
8a466508 b905d368  0×1             0×1000    0xd          0×138 tcpip!InitForwardingPools+53
8a373578 b905becb  0xa3            0×1000    0×11         0xe8 tcpip!AllocIPPacketList+59
8a466580 b9095ac5  0×1             0×1000    0xe          0×118 tcpip!IPInit+e0
8a460958 bac40a97  0×9b            0×1000    0×14         0xc8 vmxnet+a97

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

Crash Dump Analysis Patterns (Part 163)

Sunday, December 25th, 2011

Sometimes we need to check network adapters (miniports) to see whether they are up, down, connected or disconnected. This can be done using ndiskd WinDbg extension and its commands. For example (a kernel memory dump):

1: kd> !ndiskd.miniports
raspptp.sys, v0.0
  88453360 NetLuidIndex  1, IfIndex  3,  WAN Miniport (PPTP)
raspppoe.sys, v0.0
  884860e8 NetLuidIndex  0, IfIndex  4,  WAN Miniport (PPPOE)
ndiswan.sys, v0.0
  8842f0e8 NetLuidIndex  0, IfIndex  5,  WAN Miniport (IPv6)
  8842e0e8 NetLuidIndex  3, IfIndex  6,  WAN Miniport (IP)
rasl2tp.sys, v0.0
  8842b0e8 NetLuidIndex  0, IfIndex  2,  WAN Miniport (L2TP)
E1G60I32.sys, v8.1
  84b730e8 NetLuidIndex  4, IfIndex  8,  Intel(R) PRO/1000 MT Network Connection

tunnel.sys, v1.0
  84b370e8 NetLuidIndex  2, IfIndex  9,  isatap.{0DC6D9AD-70DC-41CE-9798-F71D1A8C899F}

1: kd> !ndiskd.miniport 84b730e8

MINIPORT

    Intel(R) PRO/1000 MT Network Connection

    Ndis Handle        84b730e8
    Ndis API Version   v6.0
    Adapter Context    88460008
    Miniport Driver    84b44938 - E1G60I32.sys  v8.1
    Ndis Verifier      [No flags set]

    Media Type         802.3
    Physical Medium    802.3
    Device Path        \??\PCI#VEN_8086&DEV_100F&SUBSYS_075015AD&REV_01#4&b70f118&0&0888#{ad498944-762f-11d0-8dcb-00c04fc3358c}\{0DC6D9AD-70DC-41CE-9798-F71D1A8C899F}
    Device Object      84b73030
    MAC Address        00-0c-29-b1-7d-39

STATE

    Miniport           Running
    Device PnP         Started
    Datapath           00000002          ← DIVERTED_BECAUSE_MEDIA_DISCONNECTED
    NBL Status         NDIS_STATUS_MEDIA_DISCONNECTED
    Operational status DOWN
    Operational flags  00000002          ← DOWN_NOT_CONNECTED

    Admin status       ADMIN_UP
    Media              MediaDisconnected
    Power              D0
    References         6
    User Handles       0
    Total Resets       0
    Pending OID        None
    Flags              0c452218
        ↑ BUS_MASTER, 64BIT_DMA, SG_DMA, DEFAULT_PORT_ACTIVATED,
        SUPPORTS_MEDIA_SENSE, DOES_NOT_DO_LOOPBACK, NOT_MEDIA_CONNECTED
    PnPFlags           00210021
        ↑ PM_SUPPORTED, DEVICE_POWER_ENABLED, RECEIVED_START, HARDWARE_DEVICE

BINDINGS

    Filter List        Filter              Filter Driver      Context          _
    QoS Packet Scheduler-0000
                       88e453d8            88e18938           88e1ed60

    Open List          Open                Protocol           Context          _
    RSPNDR             8bcbb470            8bd23ac8           8bcbb820
    LLTDIO             8bcb8c00            8bd15980           8bd153f8
    TCPIP6             88e528e8            88e02350           88e52c98
    TCPIP              88e1c078            88e02aa8           88e1e6a8

MORE INFORMATION

     → Driver handlers                      → Task offloads
     → Power management
     → Pending OIDs                         → Timers
                                            → Receive Side Throttling
     → Wake-on-LAN (WoL)                    → Packet filter
     → NDIS ports

Another example from a different complete memory dump: 

STATE

    Device PnP         Started
    Datapath           00000002          ← DIVERTED_BECAUSE_MEDIA_DISCONNECTED
    Packet Status      NDIS_STATUS_NO_CABLE
    Media              Not Connected

  […]

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

Crash Dump Analysis Patterns (Part 162)

Wednesday, December 14th, 2011

Sometimes Problem Module pattern can help in troubleshooting. Problem modules (including process names) are components that due to their value adding behaviour might break normal software behaviour and therefore require some troubleshooting workarounds from minor configuration changes to complete removal. Typical examples include memory optimization services for terminal services environments or hooksware. Typically you can see main process modules in the output of !vm or !process 0 0 commands. lm command will list module names such as DLLs from a process memory dump, lmk command can give you the list of kernel space modules (for example, drivers) from kernel and complete memory dumps, and the following command lists all user space modules for each process in a complete memory dump:

!for_each_process ".process /r /p @#Process; lmu"

Of course you can also try various lm command variants if you are interested in timestamps and module information.

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

Crash Dump Analysis Patterns (Part 161)

Monday, December 12th, 2011

This is another stack trace related pattern that we call Empty Stack Trace. Here we might need to do manual stack trace reconstruction like in the following example:

0:002> ~2s
eax=00000070 ebx=0110fb94 ecx=00000010 edx=005725d8 esi=0110fe58 edi=00000d80
eip=7c82847c esp=0110efe0 ebp=0110eff0 iopl=0  nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000      efl=00000246
ntdll!KiFastSystemCallRet:
7c82847c c3              ret

0:002> kL
ChildEBP RetAddr
0110efdc 00000000 ntdll!KiFastSystemCallRet

0:002> !teb
TEB at 7ffdc000
ExceptionList:        0110f980
StackBase:            01110000
StackLimit:           0110d000
SubSystemTib:         00000000
FiberData:            00001e00
ArbitraryUserPointer: 00000000
Self:                 7ffdc000
EnvironmentPointer:   00000000
ClientId:             00000b04 . 00000bd0
RpcHandle:            00000000
Tls Storage:          00000000
PEB Address:          7ffda000
LastErrorValue:       87
LastStatusValue:      c000000d
Count Owned Locks:    0
HardErrorMode:        0

0:002> dps 0110d000 01110000
0110d000  00000000
0110d004  00000000
[...]
0110f63c  00001000
0110f640  0110f64c
0110f644  02b91ea8
0110f648  00001000
0110f64c  00000004
0110f650  0110f6f0
0110f654  0374669d DbgHelp!WriteFullMemory+0×3cd
0110f658  ffffffff
0110f65c  0110d000
0110f660  00000000
0110f664  0480f5c0
0110f668  00003000
0110f66c  0110f7b0
0110f670  0110d000
0110f674  00000000
0110f678  00000065
0110f67c  00003000
0110f680  0110d000
0110f684  00000000
0110f688  01010000
0110f68c  00000000
0110f690  00000004
0110f694  00060002
0110f698  00003000
0110f69c  00000000
0110f6a0  00001000
0110f6a4  00000004
0110f6a8  00020000
0110f6ac  00040004
0110f6b0  7ffe0000 SharedUserData
0110f6b4  00000000
0110f6b8  00001000
0110f6bc  00000000
0110f6c0  0480f5c0
0110f6c4  00000000
0110f6c8  04c4a000
0110f6cc  00000000
0110f6d0  000003c7
0110f6d4  00000000
0110f6d8  00023b17
0110f6dc  00000000
0110f6e0  01110000
0110f6e4  00000000
0110f6e8  0099f000
0110f6ec  00000000
0110f6f0  0110f704
0110f6f4  037469d6 DbgHelp!WriteDumpData+0×206
0110f6f8  0110f738
0110f6fc  0110f7b0
0110f700  00000000
0110f704  0110f868
0110f708  03747449 DbgHelp!MiniDumpProvideDump+0×359
0110f70c  0110f738
0110f710  0110f7b0
0110f714  02b91fb0
0110f718  00000000
0110f71c  00000000
0110f720  00000000
0110f724  02b91fb0
0110f728  00000000
0110f72c  00000000
[…]
0110ff1c  00000001
0110ff20  00000008
0110ff24  0000000a
0110ff28  33017f51 ModuleA!Run+0xde
0110ff2c  00000001
0110ff30  0110ff74
0110ff34  00f08898
0110ff38  00000000
0110ff3c  00f082a8
0110ff40  00000000
0110ff44  00000001
0110ff48  33017e33 ModuleA!ThreadProc+0×2c
0110ff4c  a9b21e1e
0110ff50  00000000
0110ff54  00000000
0110ff58  00f08898
0110ff5c  0110ff4c
0110ff60  0110ffac
0110ff64  0110ff9c
0110ff68  33054245
0110ff6c  9ba52ad2
0110ff70  00000000
0110ff74  0110ffac
0110ff78  78543433 msvcr90!_endthreadex+0×44
0110ff7c  00f082a8
0110ff80  a9b2b0d3
0110ff84  00000000
0110ff88  00000000
0110ff8c  00f08898
0110ff90  0110ff80
0110ff94  0110ff80
0110ff98  0110ffdc
0110ff9c  0110ffdc
0110ffa0  7858cf5e msvcr90!_except_handler4
0110ffa4  d0f887df
0110ffa8  00000000
0110ffac  0110ffb8
0110ffb0  785434c7 msvcr90!_endthreadex+0xd8
0110ffb4  00000000
0110ffb8  0110ffec
0110ffbc  77e6482f kernel32!BaseThreadStart+0×34
0110ffc0  00f08898
0110ffc4  00000000
0110ffc8  00000000
0110ffcc  00f08898
0110ffd0  00000000
0110ffd4  0110ffc4
0110ffd8  80833bcc
0110ffdc  ffffffff
0110ffe0  77e61a60 kernel32!_except_handler3
0110ffe4  77e64838 kernel32!`string’+0×98
0110ffe8  00000000
0110ffec  00000000
0110fff0  00000000
0110fff4  7854345e msvcr90!_endthreadex+0×6f
0110fff8  00f08898
0110fffc  00000000
01110000  00000130

0:002> k L=0110f650 0110f650  0110f650
ChildEBP RetAddr
WARNING: Frame IP not in any known module. Following frames may be wrong.
0110f650 0374669d 0x110f650
0110f6f0 037469d6 DbgHelp!WriteFullMemory+0x3cd
0110f704 03747449 DbgHelp!WriteDumpData+0x206
0110f868 03747662 DbgHelp!MiniDumpProvideDump+0x359
0110f8dc 33050dd9 DbgHelp!MiniDumpWriteDump+0x1b2
[...]
0110fdfc 33031726 ModuleA!WriteExceptionMiniDump+0x50
0110fea0 33018c81 ModuleA!ThreadHung+0x6c
[...]
0110ff44 33017e33 ModuleA!Run+0xde
00000000 00000000 ModuleA!ThreadProc+0x2c

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

What is Software Trace and Memory Dump Analysis? A One Sentence Definition

Monday, December 12th, 2011

More than 4 years passed since I provided a longer structuralist definition. Recently I came to recognize a pattern-driven iterative and incremental nature of memory and software trace analysis and post-construction software problem solving in general and therefore a one sentence definition became necessary:

“Recognition and interpretation of patterns of software behavior”

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

Crash Dump Analysis Patterns (Part 160)

Sunday, December 11th, 2011

When doing software behavior artifact collection, live debugging or postmortem memory dump analysis we must also take into consideration the possibility of Debugger Bugs. I classify them into hard and soft bugs. The former are those software defects and behavioral problems that result in further abnormal software behavior incidents like crashes and hangs. One example is this Microsoft KB article about DebugDiag. Soft debugger bugs usually manifest themselves as glitches in data output, nonsense or false positive diagnostics, for example, this excessive non-paged pool usage message in the output from !vm WinDbg command (see the corresponding MS KB article):

1: kd> !vm

*** Virtual Memory Usage ***
Physical Memory:     1031581 (   4126324 Kb)
Page File: \??\C:\pagefile.sys
Current:   4433524 Kb  Free Space:   4433520 Kb
Minimum:   4433524 Kb  Maximum:     12378972 Kb
Unimplemented error for MiSystemVaTypeCount
Available Pages:      817652 (   3270608 Kb)
ResAvail Pages:       965229 (   3860916 Kb)
Locked IO Pages:           0 (         0 Kb)
Free System PTEs:   33555714 ( 134222856 Kb)
Modified Pages:        15794 (     63176 Kb)
Modified PF Pages:     15793 (     63172 Kb)
NonPagedPool Usage: 88079121 ( 352316484 Kb)
NonPagedPoolNx Usage:  12885 (     51540 Kb)
NonPagedPool Max:     764094 (   3056376 Kb)
********** Excessive NonPaged Pool Usage *****
PagedPool 0 Usage:     35435 (    141740 Kb)
PagedPool 1 Usage:      3620 (     14480 Kb)
PagedPool 2 Usage:       573 (      2292 Kb)
PagedPool 3 Usage:       535 (      2140 Kb)
PagedPool 4 Usage:       538 (      2152 Kb)
PagedPool Usage:       40701 (    162804 Kb)
PagedPool Maximum:  33554432 ( 134217728 Kb)
Session Commit:         9309 (     37236 Kb)
Shared Commit:          6460 (     25840 Kb)
Special Pool:              0 (         0 Kb)
Shared Process:         5760 (     23040 Kb)
PagedPool Commit:      40765 (    163060 Kb)
Driver Commit:          2805 (     11220 Kb)
Committed pages:      212472 (    849888 Kb)
Commit limit:        2139487 (   8557948 Kb)

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

Crash Dump Analysis Patterns (Part 159)

Monday, December 5th, 2011

Sometimes we have a value or a pointer or a handle and would like to know all memory addresses that reference it. This can be done by virtual memory search (s WinDbg command). If you look for references in code (for example, or pool tags please see this case study) you can combine search with !for_each_module WinDbg extension command. There is also !search command for physical pages. We cover this Value References pattern in the forthcoming Advanced Windows Memory Dump Analysis training with a step-by-step complete memory dump analysis exercise. For object references there is also recently added !obtrace command with good examples in WinDbg help.

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

Crash Dump Analysis Patterns (Part 69c)

Sunday, December 4th, 2011

This is a variant of Self-Diagnosis (kernel mode) pattern for system configuration database (registry). Sometimes it is possible to see which part of it (hive) caused the problem. Here’s an example involving possibly corrupt user profiles:

REGISTRY_ERROR (51)
Something has gone badly wrong with the registry.  If a kernel debugger is available, get a stack trace. It can also indicate that the registry got an I/O error while trying to read one of its files, so it can be caused by hardware problems or filesystem corruption. It may occur due to a failure in a refresh operation, which is used only in by the security system, and then only when resource limits are encountered.
Arguments:
Arg1: 00000003, (reserved)
Arg2: 00000004, (reserved)
Arg3: e82372f8, depends on where Windows bugchecked, may be pointer to hive
Arg4: 00000000, depends on where Windows bugchecked, may be return code of HvCheckHive if the hive is corrupt.

0: kd> !reg hivelist

-------------------------------------------------------------------------------------------------------------
| HiveAddr |Stable Length|Stable Map|Volatile Length|Volatile Map|MappedViews|PinnedViews|U(Cnt)| BaseBlock | FileName
-------------------------------------------------------------------------------------------------------------
| e1008a68 |      13000  | e1008ac8 |       1000    |  e1008c04  |        0  |        0  |     0| e1015000  | <NONAME>
| e101a4e0 |     901000  | e1023000 |      40000    |  e101a67c  |      202  |        0  |     0| e101e000  | SYSTEM
| e1938188 |       d000  | e19381e8 |       4000    |  e1938324  |        0  |        0  |     0| e193a000  | <NONAME>
| e1968290 |       8000  | e19682f0 |          0    |  00000000  |        3  |        0  |     0| e1d39000  | \SystemRoot\System32\Config\SAM
| e1cab270 |      3d000  | e1cab2d0 |       1000    |  e1cab40c  |       16  |        0  |     0| e1d32000  | emRoot\System32\Config\SECURITY
| e1c9f448 |    3f70000  | e1e37000 |       1000    |  e1c9f5e4  |      256  |        0  |     0| e1d71000  | temRoot\System32\Config\DEFAULT
| e1d75a80 |    7d5d000  | e1ee3000 |      23000    |  e1d75c1c  |      254  |       12  |     0| e1d37000  | emRoot\System32\Config\SOFTWARE
| e1ba30d0 |      37000  | e1ba3130 |       1000    |  e1ba326c  |       17  |        0  |     0| e1b9e000  | tings\NetworkService\ntuser.dat
| e1ba8060 |       1000  | e1ba80c0 |          0    |  00000000  |        1  |        0  |     0| e1b8e000  | \Microsoft\Windows\UsrClass.dat
| e1afc068 |      3b000  | e1afc0c8 |       1000    |  e1afc204  |       17  |        0  |     0| e1b3d000  | ettings\LocalService\ntuser.dat
| e1d6e2a0 |       1000  | e1d6e300 |          0    |  00000000  |        1  |        0  |     0| e1b39000  | \Microsoft\Windows\UsrClass.dat
[...]
| e82372f8 |     106000  | e8237358 |          0    |  00000000  |       55  |        4  |     0| e514c000  | ings\User123\NTUSER.DAT
[…]
————————————————————————————————————-

0: kd> dt _CMHIVE e82372f8
nt!_CMHIVE
   +0x000 Hive             : _HHIVE
   +0x2d0 FileHandles      : [3] 0x80002234 Void
   +0x2dc NotifyList       : _LIST_ENTRY [ 0x0 - 0x0 ]
   +0x2e4 HiveList         : _LIST_ENTRY [ 0xe7a38d64 - 0xe4d9fc9c ]
   +0x2ec HiveLock         : _EX_PUSH_LOCK
   +0x2f0 ViewLock         : 0x877b0120 _KGUARDED_MUTEX
   +0x2f4 WriterLock       : _EX_PUSH_LOCK
   +0x2f8 FlusherLock      : _EX_PUSH_LOCK
   +0x2fc SecurityLock     : _EX_PUSH_LOCK
   +0x300 LRUViewListHead  : _LIST_ENTRY [ 0xe6160170 - 0xe3d71978 ]
   +0x308 PinViewListHead  : _LIST_ENTRY [ 0xe2714fe0 - 0xe108d9e0 ]
   +0x310 FileObject       : 0x89ecf310 _FILE_OBJECT
   +0x314 FileFullPath     : _UNICODE_STRING "\Device\HarddiskVolumeX\Documents and Settings\User123\NTUSER.DAT"
   +0×31c FileUserName     : _UNICODE_STRING “\??\E:\Documents and Settings\User123\NTUSER.DAT”
   +0×324 MappedViews      : 0×37
   +0×326 PinnedViews      : 4
   +0×328 UseCount         : 0
   +0×32c SecurityCount    : 9
   +0×330 SecurityCacheSize : 9
   +0×334 SecurityHitHint  : 0n0
   +0×338 SecurityCache    : 0xe74d5008 _CM_KEY_SECURITY_CACHE_ENTRY
   +0×33c SecurityHash     : [64] _LIST_ENTRY [ 0xe3f80228 - 0xe5901ef0 ]
   +0×53c UnloadEvent      : (null)
   +0×540 RootKcb          : (null)
   +0×544 Frozen           : 0 ”
   +0×548 UnloadWorkItem   : (null)
   +0×54c GrowOnlyMode     : 0 ”
   +0×550 GrowOffset       : 0
   +0×554 KcbConvertListHead : _LIST_ENTRY [ 0xe823784c - 0xe823784c ]
   +0×55c KnodeConvertListHead : _LIST_ENTRY [ 0xe8237854 - 0xe8237854 ]
   +0×564 CellRemapArray   : (null)
   +0×568 Flags            : 1
   +0×56c TrustClassEntry  : _LIST_ENTRY [ 0xe8237864 - 0xe8237864 ]
   +0×574 FlushCount       : 0
   +0×578 CreatorOwner     : (null)

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

Crash Dump Analysis Patterns (Part 158)

Sunday, December 4th, 2011

Certain System Objects can be found in object directory and can be useful to see additional system and other product activity. For example, in a complete memory dump from Accelerated .NET Memory Dump Analysis training we see that LowCommitCondition event is signalled:

1: kd> !object \KernelObjects
Object: 85a08030  Type: (82b38ed0) Directory
    ObjectHeader: 85a08018 (old version)
    HandleCount: 0  PointerCount: 19
    Directory Object: 85a074c0  Name: KernelObjects

    Hash Address  Type          Name
    ---- -------  ----          ----
     02  82b7b0b8 Event         HighCommitCondition
     04  82b7b780 Event         HighMemoryCondition
     10  82b7b178 Event         LowNonPagedPoolCondition
     11  82b7b138 Event         HighNonPagedPoolCondition
     17  82b7b0f8 Event         LowCommitCondition
     20  82b78d08 Event         SuperfetchParametersChanged
         82b6eb58 Event         BootLoaderTraceReady
     23  84bfdd58 Session       Session0
         82b78c88 Event         PrefetchTracesReady
     24  84b7d1f8 Session       Session1
     25  82b78cc8 Event         SuperfetchScenarioNotify
         82b7b740 Event         LowPagedPoolCondition
     26  82b7b1b8 Event         HighPagedPoolCondition
         82b7a030 Event         MemoryErrors
     28  82b78c48 Event         SuperfetchTracesReady
     32  82b7b7c0 Event         LowMemoryCondition
         85a09d00 KeyedEvent    CritSecOutOfMemoryEvent
     34  82b7b078 Event         MaximumCommitCondition

1: kd> dt _DISPATCHER_HEADER 82b7b0f8
ntdll!_DISPATCHER_HEADER
   +0x000 Type             : 0 ''
   +0x001 Abandoned        : 0 ''
   +0x001 Absolute         : 0 ''
   +0x001 NpxIrql          : 0 ''
   +0x001 Signalling       : 0 ''
   +0x002 Size             : 0x4 ''
   +0x002 Hand             : 0x4 ''
   +0x003 Inserted         : 0 ''
   +0x003 DebugActive      : 0 ''
   +0x003 DpcActive        : 0 ''
   +0x000 Lock             : 0n262144
   +0×004 SignalState      : 0n1
   +0×008 WaitListHead     : _LIST_ENTRY [ 0×82b7b100 - 0×82b7b100 ]

If we check virtual memory statistics we see lots of free space for the currrent physical memory and pagefile: 

1: kd> !vm

*** Virtual Memory Usage ***
 Physical Memory:      261872 (   1047488 Kb)
 Page File: \??\C:\pagefile.sys
   Current:   1354688 Kb  Free Space:     53120 Kb
   Minimum:   1354688 Kb  Maximum:      4194304 Kb
 Available Pages:      180984 (    723936 Kb)
 ResAvail Pages:       216475 (    865900 Kb)
 Locked IO Pages:           0 (         0 Kb)
 Free System PTEs:     352925 (   1411700 Kb)
 Modified Pages:          129 (       516 Kb)
 Modified PF Pages:        94 (       376 Kb)
 NonPagedPool Usage:        0 (         0 Kb)
 NonPagedPoolNx Usage:  16894 (     67576 Kb)
 NonPagedPool Max:     192350 (    769400 Kb)
 PagedPool 0 Usage:      5957 (     23828 Kb)
 PagedPool 1 Usage:      3218 (     12872 Kb)
 PagedPool 2 Usage:       965 (      3860 Kb)
 PagedPool 3 Usage:      1311 (      5244 Kb)
 PagedPool 4 Usage:      1064 (      4256 Kb)
 PagedPool Usage:       12515 (     50060 Kb)
 PagedPool Maximum:    523264 (   2093056 Kb)
 Session Commit:         5021 (     20084 Kb)
 Shared Commit:         15023 (     60092 Kb)
 Special Pool:              0 (         0 Kb)
 Shared Process:         1938 (      7752 Kb)
 PagedPool Commit:      12523 (     50092 Kb)
 Driver Commit:          2592 (     10368 Kb)
 Committed pages:      402494 (   1609976 Kb)
 Commit limit:         589254 (   2357016 Kb)
[...]

Another example is from Windows 7 memory dump I used for Fundamentals of Complete Crash and Hang Memory Dump Analysis presentation. Here we can find WER reporting mutant in session 1 object directory and get problem PID from its name:

0: kd> !object \Sessions\1\BaseNamedObjects\
Object: fffff8a0016eb290  Type: (fffffa800426df30) Directory
    ObjectHeader: fffff8a0016eb260 (new version)
    HandleCount: 57  PointerCount: 217
    Directory Object: fffff8a0016e9220  Name: BaseNamedObjects

    Hash Address          Type          Name
    ---- -------          ----          ----
     00  fffffa8008437670 Event         STOP_HOOKING64
[...]
    08  fffffa80044baa40 Mutant        WERReportingForProcess1788
[…]

0: kd> !process 0n1788 1
Searching for Process with Cid == 6fc
Cid handle table at fffff8a00180b000 with 21248 entries in use

PROCESS fffffa8004364060
    SessionId: 1  Cid: 06fc    Peb: 7fffffd4000  ParentCid: 0840
    DirBase: 5fbc2000  ObjectTable: fffff8a004c8e930  HandleCount:  16.
    Image: ApplicationD.exe
    VadRoot fffffa8009d85170 Vads 34 Clone 0 Private 206. Modified 0. Locked 0.
    DeviceMap fffff8a001ce6b90
    Token                             fffff8a003eab060
    ElapsedTime                       00:01:51.543
    UserTime                          00:00:00.000
    KernelTime                        00:00:00.000
    QuotaPoolUsage[PagedPool]         0
    QuotaPoolUsage[NonPagedPool]      0
    Working Set Sizes (now,min,max)  (483, 50, 345) (1932KB, 200KB, 1380KB)
    PeakWorkingSetSize                483
    VirtualSize                       13 Mb
    PeakVirtualSize                   13 Mb
    PageFaultCount                    481
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      231

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

Crash Dump Analysis Patterns (Part 157)

Saturday, December 3rd, 2011

In addition to functions we also have module variables like nt!MmPagedPoolCommit in Windows 7:

0: kd> x nt!MmPagedPool*
fffff800`031148d0 nt!MmPagedPoolInfo = <no type information>
fffff800`03092d20 nt!MmPagedPoolCommit = <no type information>
fffff800`031141a0 nt!MmPagedPoolEnd = <no type information>
fffff800`031175c0 nt!MmPagedPoolWs = <no type information>

If we are not sure whether we have a function or Module Variable we can try to disassemble:

0: kd> u nt!MmPagedPoolCommit
nt!MmPagedPoolCommit:
fffff800`03092d20 e3b2            jrcxz   nt!MmTotalNonPagedPoolQuota+0x4 (fffff800`03092cd4)
fffff800`03092d22 0000            add     byte ptr [rax],al
fffff800`03092d24 0000            add     byte ptr [rax],al
fffff800`03092d26 0000            add     byte ptr [rax],al
fffff800`03092d28 0000            add     byte ptr [rax],al
fffff800`03092d2a 0000            add     byte ptr [rax],al
fffff800`03092d2c 0000            add     byte ptr [rax],al
fffff800`03092d2e 0000            add     byte ptr [rax],al

Here the value is probably in pages so we multiply by 4 to get Kb value and compare to the output of !vm command:

0: kd> dp nt!MmPagedPoolCommit
fffff800`03092d20  00000000`0000b2e3 00000000`00000000
fffff800`03092d30  00000000`00000000 00000000`00000000
fffff800`03092d40  00000000`00000001 00000000`00000000
fffff800`03092d50  00000000`00000000 00000000`00060107
fffff800`03092d60  fffff800`03092d60 fffff800`03092d60
fffff800`03092d70  00000000`00000000 00000000`0001e972
fffff800`03092d80  fffff900`c0000000 00000000`00000002
fffff800`03092d90  fffff880`071dc0a8 fffff880`057340a8

0: kd> ? b2e3 * 4
Evaluate expression: 183180 = 00000000`0002cb8c

0: kd> !vm

*** Virtual Memory Usage ***
 Physical Memory:     1035228 (   4140912 Kb)
 Page File: \??\C:\pagefile.sys
   Current:   4448112 Kb  Free Space:   4448108 Kb
   Minimum:   4448112 Kb  Maximum:     12422736 Kb
Unimplemented error for MiSystemVaTypeCount
 Available Pages:      594029 (   2376116 Kb)
 ResAvail Pages:       889795 (   3559180 Kb)
 Locked IO Pages:           0 (         0 Kb)
 Free System PTEs:   33556870 ( 134227480 Kb)
 Modified Pages:        20079 (     80316 Kb)
 Modified PF Pages:     19441 (     77764 Kb)
 NonPagedPool Usage: 50865104 ( 203460416 Kb)
 NonPagedPoolNx Usage:  28163 (    112652 Kb)
 NonPagedPool Max:     763396 (   3053584 Kb)
 ********** Excessive NonPaged Pool Usage *****
 PagedPool 0 Usage:     39420 (    157680 Kb)
 PagedPool 1 Usage:      5194 (     20776 Kb)
 PagedPool 2 Usage:       367 (      1468 Kb)
 PagedPool 3 Usage:       338 (      1352 Kb)
 PagedPool 4 Usage:       440 (      1760 Kb)
 PagedPool Usage:       45759 (    183036 Kb)
 PagedPool Maximum:  33554432 ( 134217728 Kb)
 Session Commit:         8112 (     32448 Kb)
 Shared Commit:         31802 (    127208 Kb)
 Special Pool:              0 (         0 Kb)
 Shared Process:        10765 (     43060 Kb)
 PagedPool Commit:      45795 (    183180 Kb)
 Driver Commit:         13773 (     55092 Kb)
 Committed pages:      540998 (   2163992 Kb)
 Commit limit:        2146794 (   8587176 Kb)
[…]

Knowledge of available module variables is useful because some of them are not included in WinDbg extension command output. For their list please consult Windows Internals book. Also useful variables can be found in other modules as well, for example, srv!srvcomputername:

0: kd> dS srv!srvcomputername
fffff8a0`0344b090  "MYNOTEBOOK"

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

Crash Dump Analysis Patterns (Part 27c)

Saturday, December 3rd, 2011

Sometimes we need to narrow general stack trace collection to a few threads that satisfy some predicate, for example, all threads with kernel time spent greater than some value or all suspended threads or all threads that wait for a specific synchronization object type. We call this pattern variant Stack Trace Collection (predicate). This can be implemented using WinDbg scripts and / or debugger extensions.

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

2 WinDbg Scripts That Changed The World

Saturday, December 3rd, 2011

If not for you then definitely for me because I now diagnose Spiking Thread pattern much faster. One of the readers if this blog asked me whether there is !runaway command equivalent for kernel and complete memory dumps. So, after some thinking I gave it a try especially in the context of WinDbg scripting exercises designed for Advanced Windows Memory Dump Analysis training. As a result I wrote 2 scripts initially that you can try yourself. Their output here is taken from a complete memory dump I used for Fundamentals of Complete Crash and Hang Memory Dump Analysis presentation.

The first one dumps the most CPU consuming threads for user and kernel mode:

$$
$$ krunawaymost.wds
$$ Copyright (c) 2011 Memory Dump Analysis Services
$$ GNU GENERAL PUBLIC LICENSE
$$ http://www.gnu.org/licenses/gpl-3.0.txt
$$
r $t0 = 0
!for_each_thread “r $t1 = dwo( @#Thread + @@c++(#FIELD_OFFSET(nt!_KTHREAD, UserTime)) ); .if (@$t1 > @$t0) {r $t0 = @$t1; r $t2 = @#Thread}”
.echo “The largest UserTime value: ”
? @$t0
!thread @$t2 ff
r $t0 = 0
!for_each_thread “r $t1 = dwo( @#Thread + @@c++(#FIELD_OFFSET(nt!_KTHREAD, KernelTime)) ); .if (@$t1 > @$t0) {r $t0 = @$t1; r $t2 = @#Thread}”
.echo “The largest KernelTime value: ”
? @$t0
!thread @$t2 ff

0: kd> $$><c:\Scripts\krunawaymost.wds
The largest UserTime value:
Evaluate expression: 5470 = 00000000`0000155e

THREAD fffffa800451d720  Cid 1418.17fc  Teb: 000007fffffdc000 Win32Thread: 0000000000000000 RUNNING on processor 2
Not impersonating
DeviceMap                 fffff8a001ce6b90
Owning Process            fffffa800442ab30       Image:         ApplicationE.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      22295          Ticks: 0
Context Switch Count      27960            
UserTime                  00:01:25.332
KernelTime                00:00:00.015
*** ERROR: Module load completed but symbols could not be loaded for ApplicationE.exe
Win32 Start Address ApplicationE (0×000000013f0f1578)
Stack Init fffff8800723cc70 Current fffff8800723c960
Base fffff8800723d000 Limit fffff88007237000 Call 0
Priority 8 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
00000000`0021f9e0 00000000`00000000 ApplicationE+0×6cd3

The largest KernelTime value:
Evaluate expression: 187 = 00000000`000000bb

THREAD fffffa80098d7b60  Cid 07bc.0a14  Teb: 000007fffffd7000 Win32Thread: fffff900c2ca0c20 WAIT: (UserRequest) KernelMode Non-Alertable
    fffffa8008a4a030  NotificationEvent
Not impersonating
DeviceMap                 fffff8a001ce6b90
Owning Process            fffffa80096beb30       Image:         dwm.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      22294          Ticks: 1 (0:00:00:00.015)
Context Switch Count      15473                 LargeStack
UserTime                  00:00:06.801
KernelTime                00:00:02.917
Win32 Start Address dwmcore!CPartitionThread::ThreadMain (0×000007fef8a1f0d8)
Stack Init fffff8800d3d5c70 Current fffff8800d3d5740
Base fffff8800d3d6000 Limit fffff8800d3cf000 Call 0
Priority 15 BasePriority 15 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffff880`0d3d5780 fffff800`02ee6f32 nt!KiSwapContext+0×7a
fffff880`0d3d58c0 fffff800`02ee974f nt!KiCommitThreadWait+0×1d2
fffff880`0d3d5950 fffff880`0fef65b3 nt!KeWaitForSingleObject+0×19f
fffff880`0d3d59f0 fffff960`001fedea dxgkrnl!DxgkWaitForVerticalBlankEvent+0×53f
fffff880`0d3d5ab0 fffff800`02ee0ed3 win32k!NtGdiDdDDIWaitForVerticalBlankEvent+0×12
fffff880`0d3d5ae0 000007fe`ff1d143a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`0d3d5ae0)
00000000`0287f778 000007fe`f8791da1 GDI32!NtGdiDdDDIWaitForVerticalBlankEvent+0xa
00000000`0287f780 000007fe`f89e1b6e dxgi!CDXGIOutput::WaitForVBlank+0×51
00000000`0287f7c0 000007fe`f89e1ae9 dwmcore!CD3DDeviceLevel1::WaitForVBlank+0×1f9
00000000`0287f810 000007fe`f89e1a9d dwmcore!CHwDisplayRenderTarget::WaitForVBlank+0×39
00000000`0287f850 000007fe`f89e1a4c dwmcore!CDesktopRenderTarget::WaitForVBlank+0×40
00000000`0287f880 000007fe`f89d3513 dwmcore!CSlaveHWndRenderTarget::WaitForVBlank+0×2c
00000000`0287f8c0 000007fe`f89d3584 dwmcore!CRenderTargetManager::WaitForVBlank+0×7d
00000000`0287f900 000007fe`f89d2661 dwmcore!CPartitionVerticalBlankScheduler::WaitForVBlank+0×7c
00000000`0287f950 000007fe`f8a1f0f4 dwmcore!CPartitionVerticalBlankScheduler::Run+0xe5
00000000`0287f9b0 00000000`7719652d dwmcore!CPartitionThread::ThreadMain+0×1c
00000000`0287f9e0 00000000`772cc521 kernel32!BaseThreadInitThunk+0xd
00000000`0287fa10 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

The second script takes two arguments and shows all threads that have UserTime and KernelTime ticks value greater than (you can have the idea of the maximum from the previous script):

$$
$$ krunawaygt.wds
$$ Copyright (c) 2011 Memory Dump Analysis Services
$$ GNU GENERAL PUBLIC LICENSE
$$ http://www.gnu.org/licenses/gpl-3.0.txt
$$
!for_each_thread “r $t1 = dwo( @#Thread + @@c++(#FIELD_OFFSET(nt!_KTHREAD, UserTime)) ); r $t0 = $arg1; .if (@$t1 > @$t0) {!thread @#Thread ff}”
!for_each_thread “r $t1 = dwo( @#Thread + @@c++(#FIELD_OFFSET(nt!_KTHREAD, KernelTime)) ); r $t0 = $arg2; .if (@$t1 > @$t0) {!thread @#Thread ff}”

Using hints from the previous script run (the largest UserTime ticks value is 0×155e) we now get threads that spent more than 0×100 ticks in user mode:

0: kd> $$>a<c:\Scripts\krunawaygt.wds 100 100
THREAD fffffa800843e060  Cid 03f4.0658  Teb: 000007fffff90000 Win32Thread: 0000000000000000 WAIT: (WrQueue) UserMode Non-Alertable
    fffffa800843c2c0  QueueObject
Not impersonating
DeviceMap                 fffff8a000008aa0
Owning Process            fffffa800916b060       Image:         MsMpEng.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      21211          Ticks: 1084 (0:00:00:16.910)
Context Switch Count      6028            
UserTime                  00:00:10.140
KernelTime                00:00:00.296
Win32 Start Address msvcrt!endthreadex (0×000007feff5173fc)
Stack Init fffff88009d4bc70 Current fffff88009d4b660
Base fffff88009d4c000 Limit fffff88009d46000 Call 0
Priority 9 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for mprtp.dll -
Child-SP          RetAddr           Call Site
fffff880`09d4b6a0 fffff800`02ee6f32 nt!KiSwapContext+0×7a
fffff880`09d4b7e0 fffff800`02ee9f93 nt!KiCommitThreadWait+0×1d2
fffff880`09d4b870 fffff800`031ca647 nt!KeRemoveQueueEx+0×323
fffff880`09d4b930 fffff800`0319cae5 nt!IoRemoveIoCompletion+0×47
fffff880`09d4b9c0 fffff800`02ee0ed3 nt!NtRemoveIoCompletion+0×145
fffff880`09d4ba70 00000000`772f13aa nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`09d4bae0)
00000000`0209fb08 000007fe`fd9e169d ntdll!ZwRemoveIoCompletion+0xa
00000000`0209fb10 00000000`7718a4e1 KERNELBASE!GetQueuedCompletionStatus+0×39
00000000`0209fb70 00000000`748f2c74 kernel32!GetQueuedCompletionStatusStub+0×11
00000000`0209fbb0 00000000`0045cbc0 mprtp!MpPluginSignatureChange+0×3e170
00000000`0209fbb8 000007fe`fbac25ff 0×45cbc0
00000000`0209fbc0 00000000`00466610 FLTLIB!FilterGetMessage+0×2b
00000000`0209fc20 00000000`00000000 0×466610

THREAD fffffa800845c060  Cid 03f4.065c  Teb: 000007fffff8e000 Win32Thread: 0000000000000000 WAIT: (WrQueue) UserMode Non-Alertable
    fffffa800843c2c0  QueueObject
Not impersonating
DeviceMap                 fffff8a000008aa0
Owning Process            fffffa800916b060       Image:         MsMpEng.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      21520          Ticks: 775 (0:00:00:12.090)
Context Switch Count      4979            
UserTime                  00:00:04.149
KernelTime                00:00:00.156
Win32 Start Address msvcrt!endthreadex (0×000007feff5173fc)
Stack Init fffff88009d52c70 Current fffff88009d52660
Base fffff88009d53000 Limit fffff88009d4d000 Call 0
Priority 8 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for mprtp.dll -
Child-SP          RetAddr           Call Site
fffff880`09d526a0 fffff800`02ee6f32 nt!KiSwapContext+0×7a
fffff880`09d527e0 fffff800`02ee9f93 nt!KiCommitThreadWait+0×1d2
fffff880`09d52870 fffff800`031ca647 nt!KeRemoveQueueEx+0×323
fffff880`09d52930 fffff800`0319cae5 nt!IoRemoveIoCompletion+0×47
fffff880`09d529c0 fffff800`02ee0ed3 nt!NtRemoveIoCompletion+0×145
fffff880`09d52a70 00000000`772f13aa nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`09d52ae0)
00000000`01ccf498 000007fe`fd9e169d ntdll!ZwRemoveIoCompletion+0xa
00000000`01ccf4a0 00000000`7718a4e1 KERNELBASE!GetQueuedCompletionStatus+0×39
00000000`01ccf500 00000000`748f2c74 kernel32!GetQueuedCompletionStatusStub+0×11
00000000`01ccf540 00000000`0045d030 mprtp!MpPluginSignatureChange+0×3e170
00000000`01ccf548 000007fe`fbac25ff 0×45d030
00000000`01ccf550 00000000`004666b0 FLTLIB!FilterGetMessage+0×2b
00000000`01ccf5b0 00000000`00000000 0×4666b0

THREAD fffffa80092b7060  Cid 03f4.1268  Teb: 000007fffff6a000 Win32Thread: 0000000000000000 WAIT: (WrQueue) UserMode Alertable
    fffffa8009299140  QueueObject
Not impersonating
DeviceMap                 fffff8a000008aa0
Owning Process            fffffa800916b060       Image:         MsMpEng.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      7762           Ticks: 14533 (0:00:03:46.716)
Context Switch Count      3297            
UserTime                  00:00:06.489
KernelTime                00:00:00.499
Win32 Start Address ntdll!TppWorkerThread (0×00000000772bfbc0)
Stack Init fffff8800e620c70 Current fffff8800e620680
Base fffff8800e621000 Limit fffff8800e61b000 Call 0
Priority 8 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffff880`0e6206c0 fffff800`02ee6f32 nt!KiSwapContext+0×7a
fffff880`0e620800 fffff800`02ee9f93 nt!KiCommitThreadWait+0×1d2
fffff880`0e620890 fffff800`031ca647 nt!KeRemoveQueueEx+0×323
fffff880`0e620950 fffff800`02ecdb36 nt!IoRemoveIoCompletion+0×47
fffff880`0e6209e0 fffff800`02ee0ed3 nt!NtWaitForWorkViaWorkerFactory+0×285
fffff880`0e620ae0 00000000`772f2c1a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`0e620ae0)
00000000`0540f998 00000000`772bfe0b ntdll!ZwWaitForWorkViaWorkerFactory+0xa
00000000`0540f9a0 00000000`7719652d ntdll!TppWorkerThread+0×2c9
00000000`0540fca0 00000000`772cc521 kernel32!BaseThreadInitThunk+0xd
00000000`0540fcd0 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

THREAD fffffa80098d7b60  Cid 07bc.0a14  Teb: 000007fffffd7000 Win32Thread: fffff900c2ca0c20 WAIT: (UserRequest) KernelMode Non-Alertable
    fffffa8008a4a030  NotificationEvent
Not impersonating
DeviceMap                 fffff8a001ce6b90
Owning Process            fffffa80096beb30       Image:         dwm.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      22294          Ticks: 1 (0:00:00:00.015)
Context Switch Count      15473                 LargeStack
UserTime                  00:00:06.801
KernelTime                00:00:02.917
Win32 Start Address dwmcore!CPartitionThread::ThreadMain (0×000007fef8a1f0d8)
Stack Init fffff8800d3d5c70 Current fffff8800d3d5740
Base fffff8800d3d6000 Limit fffff8800d3cf000 Call 0
Priority 15 BasePriority 15 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffff880`0d3d5780 fffff800`02ee6f32 nt!KiSwapContext+0×7a
fffff880`0d3d58c0 fffff800`02ee974f nt!KiCommitThreadWait+0×1d2
fffff880`0d3d5950 fffff880`0fef65b3 nt!KeWaitForSingleObject+0×19f
fffff880`0d3d59f0 fffff960`001fedea dxgkrnl!DxgkWaitForVerticalBlankEvent+0×53f
fffff880`0d3d5ab0 fffff800`02ee0ed3 win32k!NtGdiDdDDIWaitForVerticalBlankEvent+0×12
fffff880`0d3d5ae0 000007fe`ff1d143a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`0d3d5ae0)
00000000`0287f778 000007fe`f8791da1 GDI32!NtGdiDdDDIWaitForVerticalBlankEvent+0xa
00000000`0287f780 000007fe`f89e1b6e dxgi!CDXGIOutput::WaitForVBlank+0×51
00000000`0287f7c0 000007fe`f89e1ae9 dwmcore!CD3DDeviceLevel1::WaitForVBlank+0×1f9
00000000`0287f810 000007fe`f89e1a9d dwmcore!CHwDisplayRenderTarget::WaitForVBlank+0×39
00000000`0287f850 000007fe`f89e1a4c dwmcore!CDesktopRenderTarget::WaitForVBlank+0×40
00000000`0287f880 000007fe`f89d3513 dwmcore!CSlaveHWndRenderTarget::WaitForVBlank+0×2c
00000000`0287f8c0 000007fe`f89d3584 dwmcore!CRenderTargetManager::WaitForVBlank+0×7d
00000000`0287f900 000007fe`f89d2661 dwmcore!CPartitionVerticalBlankScheduler::WaitForVBlank+0×7c
00000000`0287f950 000007fe`f8a1f0f4 dwmcore!CPartitionVerticalBlankScheduler::Run+0xe5
00000000`0287f9b0 00000000`7719652d dwmcore!CPartitionThread::ThreadMain+0×1c
00000000`0287f9e0 00000000`772cc521 kernel32!BaseThreadInitThunk+0xd
00000000`0287fa10 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

THREAD fffffa800451d720  Cid 1418.17fc  Teb: 000007fffffdc000 Win32Thread: 0000000000000000 RUNNING on processor 2
Not impersonating
DeviceMap                 fffff8a001ce6b90
Owning Process            fffffa800442ab30       Image:         ApplicationE.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      22295          Ticks: 0
Context Switch Count      27960            
UserTime                  00:01:25.332
KernelTime                00:00:00.015
*** ERROR: Module load completed but symbols could not be loaded for ApplicationE.exe
Win32 Start Address ApplicationE (0×000000013f0f1578)
Stack Init fffff8800723cc70 Current fffff8800723c960
Base fffff8800723d000 Limit fffff88007237000 Call 0
Priority 8 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
00000000`0021f9e0 00000000`00000000 ApplicationE+0×6cd3

Memory Dump Analysis Services is now working to incorporate client-side WinDbg scripting into their CARE2 architecture. 

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org

Exception Patterns

Tuesday, November 29th, 2011

A page to reference all different kinds of exception related patterns is necessary, so I created this post:

I’ll update it as soon as I add more similar patterns.

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

Crash Dump Analysis Patterns (Part 156)

Tuesday, November 29th, 2011

One pattern I missed is called FPU Exception and it sometimes happens where you least expect it. Here’s extract from one crash dump raw stack analysis showing exception context, record and the usage of r WinDbg command variant to display FPU registers:

0:002> dps 056c1000 057c0000  
[...]
057bdee0  00000008
057bdee4  00000000
057bdee8  057bed6c
057bdeec  0d6e3130
057bdef0  057c0000
057bdef4  057b9000
057bdef8  006e3138
057bdefc  057be200
057bdf00  7c90e48a ntdll!KiUserExceptionDispatcher+0xe
057bdf04  057bed6c
057bdf08  057bdf2c
057bdf0c  057bdf14
057bdf10  057bdf2c
057bdf14  c0000090
057bdf18  00000010
057bdf1c  00000000
057bdf20  79098cc0 mscorjit!Compiler::FlatFPIsSameAsFloat+0xd
057bdf24  00000001
057bdf28  00000000
057bdf2c  0001003f
057bdf30  00000000
057bdf34  00000000
057bdf38  00000000
057bdf3c  00000000
057bdf40  00000000
057bdf44  00000000
057bdf48  ffff1372
057bdf4c  fffffda1
057bdf50  ffffbfff 
[…]

0:002> .cxr 057bdf2c
eax=c0000090 ebx=00000000 ecx=c0000090 edx=00000000 esi=057be244 edi=001d4388
eip=79f5236b esp=057be1f8 ebp=057be200 iopl=0         nv up ei ng nz ac pe cy
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00010297
mscorwks!SOTolerantBoundaryFilter+0x22:
79f5236b d9059823f579    fld     dword ptr [mscorwks!_real (79f52398)] ds:0023:79f52398=40800000

0:002> .exr 057bdf14
ExceptionAddress: 79098cc0 (mscorjit!Compiler::FlatFPIsSameAsFloat+0x0000000d)
   ExceptionCode: c0000090
  ExceptionFlags: 00000010
NumberParameters: 1
   Parameter[0]: 00000000

0:002> !error c0000090
Error code: (NTSTATUS) 0xc0000090 (3221225616) - {EXCEPTION}  Floating-point invalid operation.

0:002> rMF
Last set context:
eax=c0000090 ebx=00000000 ecx=c0000090 edx=00000000 esi=057be244 edi=001d4388
eip=79f5236b esp=057be1f8 ebp=057be200 iopl=0         nv up ei ng nz ac pe cy
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00010297
fpcw=1372: rn 64 pu–d-  fpsw=FDA1: top=7 cc=1101 b-p—-i  fptw=BFFF
fopcode=045D  fpip=001b:79098cc0  fpdp=0023:057bea7c
st0=-1.#IND00000000000000000e+0000  st1= 0.006980626232475338220e-4916
st2= 6.543831490564206840810e-4932  st3=-0.003025663186207448300e+2614
st4= 2.000000000000000000000e+0000  st5= 6.291456000000000000000e+0006
st6= 1.000000000000000000000e+0000  st7= 2.500000000000000000000e-0001
mscorwks!SOTolerantBoundaryFilter+0×22:
79f5236b d9059823f579    fld     dword ptr [mscorwks!_real (79f52398)] ds:0023:79f52398=40800000

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