Software Diagnostics Library

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 -

An advice to succeed in Software Technical Support:

They said : The dump came from the wrong site
He’s a page from the end of the dump
I said : The dump came from the right site
Took me just one look
<…>
With a little debugging
You will survive
With a little debugging
You will get by
Do what you want
Go your own way
in Technical Support.

Modern Talking

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

This is another tracing example of unified debugging patterns introduced previously.

- Analysis Patterns

Focus of Tracing

- Architectural Patterns

Debug Event Subscription / Notification

- Design Patterns

Shared Debug Event State

- Implementation Patterns

Shared Variable

- Usage Patterns

Saving a memory address obtained at a breakpoint event in a debugger pseudo-register for use at later breakpoint events

Debugging.tv published a case study for tracing window messages in WinDbg. There a pseudo-register is used to save a buffer address before GetMessage call and then to reuse it after the call. Please look at Event State Management slide on Frames episode 0×06 presentation. The full WinDbg log and the recording are available there too.

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

This is a seasonal greetings postcard with Windows 8 bluescreen theme:

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

Based on ideas of Roman Jakobson about “marked” and “unmarked” categories we propose another pattern called Marked Message that groups trace messages based on having some feature or property. For example, marked messages may point to some domain of software activity such related to functional requirements and therefore may help in troubleshooting and debugging. Unmarked messages include all other messages that don’t say anything about such activities (although may include messages pointing to such activities indirectly we unaware of) or messages that say explicitly that no such activity has occurred. We can even borrow a notation of distinctive features from phonology and annotate any trace or log after analysis to compare it with a master trace, for example, compose the following list of software trace distinctive features:

session database queries [+]
session initialization [-]
socket activity [+]
process A launched [+]
process B launched [-]
process A exited [-]
[…]

Here [+] means the activity is present in the trace and [-]  means the activity is either undetected or definitely not present. Sometime a non-present activity can be a marked activity corresponding to all inclusive unmarked present activity (see, for example, No Activity pattern).

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

A WinDbg snippet from a multithreaded service:

0:2011> ~2012s
0:2012>

PS. Teaching WinDbg commands on the eve!

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

The beginning of a debugging tale:

He was debugging for 7 years and when he stopped and looked around he saw only 2 people left from the team of 50 strong technical support engineers.

Folktale

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

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 -

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 -

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 -

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 -

I created a special picture based on CPU and memory timing diagram (an optimistic version of the original computicart):

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

Before I finished book I knew very little about USA history limited by my school education in former Soviet Union times. Now I feel more confident and plan to read 4 volumes of Oxford History of the United States and 16 volumes of History of America and not being overwhelmed by details. I’m also reading 3 volumes of The Cambridge History of the Cold War and the book provided missing context for the first volume. As a researcher of a history of Russian revolutions (a book is scheduled by OpenTask publisher for the centennial in 2017) I firmly believe that in order to understand a history of your own country it is beneficial to read about other countries. Then discerned historical patterns and insights can be applied to a different narrative.

America, Empire of Liberty: A New History of the United States

The book also has an overview of historical literature at the back which might be useful if you are interested in further pursuing special topics. Additionally the book provides the great overview of background historical material needed to understand modern cyber conflicts.

In conclusion, I must say I’d never thought before that US history was so interesting and I now feel great sympathy for this country.

- Dmitry Vostokov @ LiterateScientist.com -

In order to understand the politics of cyberwar in historical context it is beneficial to know the world history and especially the history of USA. Cyberconflicts and cyberwars are modern extensions of the previous power-driven tensions and conflicts. Knowing very little about actual USA history limited by school education in Soviet Union I found this almost 700 page book (UK paperback Penguin edition) written from a supposedly detached European perspective and read it from cover to cover:

America, Empire of Liberty: A New History of the United States

Which state will become an “Empire of Cyberwar” is my next question? Or such an empire will be at a supranational (suprastate) level? Looking forward to reading not yet written A Cyber History of the United States.

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

Word of Memory.

Dmitry Vostokov, Memoriarch

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

150 bugtations so far…

Program history has two sides, a computational and a human.

Philip Schaff

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

This is the first initiative for the year of software trace analysis: the first and unique software trace and log analysis training based entirely on patterns of software behavior. No longer you will be frustrated when opening a software trace with millions of messages from hundreds of software components, threads and processes.

Memory Dump Analysis Services (DumpAnalysis.com) organizes a training course:

Learn how to efficiently and effectively analyze software traces and logs from complex software environments. Covered popular software logs and trace formats from Microsoft and Citrix products and tools including Event Tracing for Windows (ETW) and Citrix Common Diagnostics Format (CDF). Learn how to use pioneering and innovative pattern-driven software problem behavior analysis to troubleshoot and debug software incidents.

If your are registered you are allowed to optionally submit your software traces and logs before the training. This will allow us in addition to the carefully constructed problems tailor additional examples to the needs of the attendees.

The training consists of 2 two-hour sessions and additional homework exercises. When you finish the training you additionally get:

1. A full transcript in PDF format (retail price $200)
2. 6 volumes of Memory Dump Analysis Anthology in PDF format (retail price $120)
3. A personalized attendance certificate with unique CID (PDF format)
4. Free Dump Analysis World Network membership including updates to full PDF transcript Q&A section

Prerequisites: Basic Windows troubleshooting.

Audience: Software technical support and escalation engineers, software maintenance engineers, system administrators.

Session 1: October 12, 2012 4:00 PM - 6:00 PM BST
Session 2: October 15, 2012 4:00 PM - 6:00 PM BST

Price: 210 USD

Space is limited.
Reserve your remote training seat now at:
https://student.gototraining.com/r/5287623225237732608

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

Making Software A Better World.

Dmitry Vostokov, Memory Dump Analysis Services

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

The number of software trace analysis patterns approaches the critical mass of 50 and we have decided to focus on software tracing and logging in the forthcoming year. Some books on tracing including Volume 7 of Memory Dump Analysis Anthology will be published by OpenTask during that year and our efforts will be to further advance software narratology, software trace linguistics, and software trace analysis in the context of memory dump analysis, generative debugging and modeling software behavior.

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

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 -