Archive for June, 2010

Old Mental Dumps from June 24th

Thursday, June 24th, 2010

2009:

Crash Dump Analysis Patterns (Part 86)Nested Offender pattern. Appears also in the following case study: Stack trace collection, message box, hidden exception, nested offender, insufficient memory, C++ exception, heap leak and ubiquitous component

Dictionary of Debugging: Crash - posts that explain the difference between crashes and hangs: Crash Dumps for Dummies (Part 4) and Crash Dumps for Dummies (Part 6)

2008:

Crash Dump Analysis Patterns (Part 67) - Nested Exception pattern. Appears also in the following case study: WOW64 process, NULL data pointer, stack overflow, main thread, incorrect stack trace, nested exceptions, hidden exception, manual dump, multiple exceptions and virtualized system

2007:

No dumps on that day

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

Computer Memory Gardens

Wednesday, June 23rd, 2010

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

Museum of Debugging and Memory Dumps

Wednesday, June 23rd, 2010

Looks like reading Darwin biography influenced me in the direction of founding a museum. So I did and here’s its draft logo:

This multi-dimensional museum will show exhibitions dedicated to the history of debugging, memory dump artifacts and art. Stay tuned. The first exhibition opens very soon.

If you would like to donate an exhibit (for example, an old memory dump or a picture related to debugging) please use this page: http://www.dumpanalysis.org/contact. Any donations are greatly appreciated!

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

Icons for Memory Dump Analysis Patterns (Part 52)

Wednesday, June 23rd, 2010

Today we introduce an icon for Passive Thread (user space) pattern:

B/W

Color

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

Old Mental Dumps from June 23rd

Wednesday, June 23rd, 2010

2009:

Dictionary of Debugging: Hang - plan to resume DoD in July. Have lots of ideas about it.

Crash Dump Analysis Patterns (Part 85) - Ubiquitous Component pattern. Appears also in the following case study: Stack trace collection, message box, hidden exception, nested offender, insufficient memory, C++ exception, heap leak and ubiquitous component

2008:

Reflecting on 2008 (Part 1) - It is so interesting to look at what people search.

2007:

Detecting loops in code - a good exercise in disassembling

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

Don’t name your driver a “Missile”

Tuesday, June 22nd, 2010

Don’t give your modules and build folders funny names. When your application or system crashes people will laugh. Recently had seen a driver build path (PDB paths, !dh command) involving words “dust”, “devil” and “missile”. A missile driver may sound like a winner against competitors but looks funny in a crash dump WinDbg output. Another case was a module having words “screw” and “driver” in lmv command output.

Another piece of advice is not to name your modules “fault tolerant”. This looks funny on crash stacks:

STACK_TEXT: 
0016f0ac 776d1faf ntdll!RtlpLowFragHeapFree+0x31
0016f0c4 655b9ed9 ntdll!RtlFreeHeap+0x105
0016f0dc 7650f1cc ModuleA!FaultTolerantHeap::FreeHeap+0x61
[...]

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

Icons for Memory Dump Analysis Patterns (Part 51)

Tuesday, June 22nd, 2010

Today we introduce an icon for Accidental Lock pattern:

B/W

Color

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

Old Mental Dumps from June 22nd

Tuesday, June 22nd, 2010

2009:

There were several posts on that prolific day but only 2 are worth to repeat here

Succession of Patterns (Part 1) - More work needs to be done here. I recently revived this theme by writing the next post: Succession of Patterns (Part 2)

Bugtation No.97

2008:

No dumps on that day

2007:

No dumps on that day

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

Tell Your Windows Debugging Story

Monday, June 21st, 2010

Mad about debugging? Join the annual competition by telling your Windows debugging story (*) after 7/7/2010 and before 8/8/2010 (**). The first prize is 3 volumes of Memory Dump Analysis Anthology + Color Supplement all signed by the author. There are also 2nd, 3rd, 4th and 5th level prizes.

Please send your story using this page: http://www.dumpanalysis.org/contact or dmitry dot vostokov at dumpanalysis dot org (if your story is formatted with pictures)

(*) DumpAnalysis.org reserves the right to publish your story (in a modified form if necessary) in OpenTask magazines and books with full credit.

(**) 7/7 and 8/8 are originally proposed Memory Analysts and Debuggers Days. Other proposed days are 7/8 and 8/7.

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

Icons for Memory Dump Analysis Patterns (Part 50)

Monday, June 21st, 2010

Today we introduce an icon for High Contention (critical sections) pattern:

B/W

Color

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

Old Mental Dumps from June 21st

Monday, June 21st, 2010

I was looking for Wordpress plugins to display past year (two-, three-, etc.) old posts and after a few tries decided to create such posts manually to add fresh perspective and new comments on them (in italics). Today we start with June 21st.

2009:

• Debugalov has been burnt! - The book still sells every month and I’m now thinking about a hardcover gift edition. The cover fascinates many people, see for example this review: Book Review - The Adventures of Dr Debugalov. Now we also have Dr. DebugLove. Who is a good and who is a bad guy? Or is it a personality split?

2008:

No dumps on that day

2007:

Looks like the very prolific day. There were 3 blog posts:

• Crash Dump Analysis Patterns (Part 16a) - Stack overflow in kernel. Generated some comments and can also be seen in the following pattern case study: Lateral damage, stack overflow and execution residue

• Repair Clipboard Chain 2.0.1 - One of the most popular Citrix tool in the past

• Guessing stack trace - This old command still works for x86 WinDbg and x86 memory dumps

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

Icons for Memory Dump Analysis Patterns (Part 49)

Friday, June 18th, 2010

Today we introduce an icon for High Contention (executive resources) pattern:

B/W

Color

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

Reading Notebook: 16-June-10

Friday, June 18th, 2010

Comments in italics are mine and express my own views, thoughts and opinions

Windows Internals by M. Russinovich, D. Solomon and A. Ionescu:

Local security policy audit (pp. 511 - 512) - I used in the past to recommend process audit to track process launch sequences for debugging purposes

Access tokens have separate ACL (pp. 512 - 513)

MSV1_0 - local authentication package (p. 513)

Default credential providers authui.dll amd SmartcardCredentialProvider.dll (p. 514) - Here are stack traces from x64 LogonUI.exe:

THREAD fffffa8013dde9d0  Cid 0238.04f8  Teb: 000007fffffd7000 Win32Thread: fffff900c0679d50 WAIT: (UserRequest) UserMode Non-Alertable
fffffa8013ddee60  SynchronizationEvent
fffffa8013dde810  SynchronizationEvent
Not impersonating
DeviceMap                 fffff88000008e00
Owning Process            fffffa80296ecae0       Image:         LogonUI.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      26019          Ticks: 402642 (0:01:44:41.255)
Context Switch Count      170                 LargeStack
UserTime                  00:00:00.015
KernelTime                00:00:00.046
Win32 Start Address authui!CCredentialProviderThread::_sThreadProc (0x000007fefc6d151c)
Stack Init fffffa6008efadb0 Current fffffa6008efa230
Base fffffa6008efb000 Limit fffffa6008ef5000 Call 0
Priority 15 BasePriority 13 PriorityDecrement 2 IoPriority 2 PagePriority 5
Kernel stack not resident.
Child-SP          RetAddr           Call Site
fffffa60`08efa270 fffff800`01a6b9fa nt!KiSwapContext+0x7f
fffffa60`08efa3b0 fffff800`01a712db nt!KiSwapThread+0x13a
fffffa60`08efa420 fffff800`01cd160e nt!KeWaitForMultipleObjects+0x2eb
fffffa60`08efa4a0 fffff800`01cd1c53 nt!ObpWaitForMultipleObjects+0x26e
fffffa60`08efa960 fffff800`01a69233 nt!NtWaitForMultipleObjects+0xe2
fffffa60`08efabb0 00000000`778c72ca nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffffa60`08efac20)
00000000`0211f978 00000000`7769bc03 ntdll!ZwWaitForMultipleObjects+0xa
00000000`0211f980 00000000`777ce2b5 kernel32!WaitForMultipleObjectsEx+0x10b
00000000`0211fa90 00000000`777ce32e USER32!RealMsgWaitForMultipleObjectsEx+0x129
00000000`0211fb30 000007fe`fe4fb196 USER32!MsgWaitForMultipleObjectsEx+0x46
00000000`0211fb70 000007fe`fe608d42 ole32!CCliModalLoop::BlockFn+0xb6
00000000`0211fbb0 000007fe`fc6d07ad ole32!CoWaitForMultipleHandles+0x102
00000000`0211fcb0 000007fe`fc6d15d4 authui!InternalCoWaitForSingleHandle+0x31
00000000`0211fcf0 000007fe`fc6d1525 authui!CCredentialProviderThread::_vThreadProc+0xa0
00000000`0211fd30 00000000`7769be3d authui!CCredentialProviderThread::_sThreadProc+0x9
00000000`0211fd60 00000000`778a6a51 kernel32!BaseThreadInitThunk+0xd
00000000`0211fd90 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

THREAD fffffa8013e48060  Cid 0238.0610  Teb: 000007fffffa0000 Win32Thread: 0000000000000000 WAIT: (UserRequest) UserMode Non-Alertable
fffffa8013e4ab50  NotificationEvent
fffffa8013e425b0  SynchronizationEvent
Not impersonating
DeviceMap                 fffff88000008e00
Owning Process            fffffa80296ecae0       Image:         LogonUI.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      13245          Ticks: 415416 (0:01:48:00.531)
Context Switch Count      29
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address SmartcardCredentialProvider!I_ReaderMonitorThreadProc (0x000007fefc481db0)
Stack Init fffffa6009181db0 Current fffffa6009181230
Base fffffa6009182000 Limit fffffa600917c000 Call 0
Priority 15 BasePriority 13 PriorityDecrement 2 IoPriority 2 PagePriority 5
Kernel stack not resident.
Child-SP          RetAddr           Call Site
fffffa60`09181270 fffff800`01a6b9fa nt!KiSwapContext+0x7f
fffffa60`091813b0 fffff800`01a712db nt!KiSwapThread+0x13a
fffffa60`09181420 fffff800`01cd160e nt!KeWaitForMultipleObjects+0x2eb
fffffa60`091814a0 fffff800`01cd1c53 nt!ObpWaitForMultipleObjects+0x26e
fffffa60`09181960 fffff800`01a69233 nt!NtWaitForMultipleObjects+0xe2
fffffa60`09181bb0 00000000`778c72ca nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffffa60`09181c20)
00000000`045efa48 00000000`7769bc03 ntdll!ZwWaitForMultipleObjects+0xa
00000000`045efa50 00000000`77691aa1 kernel32!WaitForMultipleObjectsEx+0x10b
00000000`045efb60 000007fe`fc4819bb kernel32!WaitForMultipleObjects+0x11
00000000`045efba0 000007fe`fc481de1 SmartcardCredentialProvider!I_ReaderMonitorWorker+0x8f
00000000`045efc30 00000000`7769be3d SmartcardCredentialProvider!I_ReaderMonitorThreadProc+0x31
00000000`045efc70 00000000`778a6a51 kernel32!BaseThreadInitThunk+0xd
00000000`045efca0 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

Win32k.sys sends keyboard messages to LogonUI.exe via RPC (p. 514)

Secondary authentication providers in LogonUI.exe, SSON (p. 515)

wininit.exe is for session 0 legacy GUI processes (p. 516)

Raw input thread (p. 516) - here’re 3 kinds of csrss.exe (different IRPs):

session 0 (no IRP)

THREAD fffffa8013a7d980  Cid 02ec.0338  Teb: 000007fffffae000 Win32Thread: fffff900c00da010 WAIT: (WrUserRequest) KernelMode Alertable
fffffa8013665d00  SynchronizationEvent
fffffa8013037df0  NotificationTimer
fffffa8013665c80  SynchronizationTimer
fffff80001bb9f60  NotificationEvent
Not impersonating
DeviceMap                 fffff88000008e00
Owning Process            fffffa8029668710       Image:         csrss.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      428616         Ticks: 45 (0:00:00:00.702)
Context Switch Count      317                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address winsrv!StartCreateSystemThreads (0x000007fefde7c3b0)
Stack Init fffffa6002c33db0 Current fffffa6002c33890
Base fffffa6002c34000 Limit fffffa6002c2e000 Call 0
Priority 15 BasePriority 13 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`02c338d0 fffff800`01a6b9fa nt!KiSwapContext+0x7f
fffffa60`02c33a10 fffff800`01a712db nt!KiSwapThread+0x13a
fffffa60`02c33a80 fffff960`000ed088 nt!KeWaitForMultipleObjects+0x2eb
fffffa60`02c33b00 fffff960`00068317 win32k!RawInputThread+0x79c
fffffa60`02c33bc0 fffff960`000eddc6 win32k!xxxCreateSystemThreads+0x67
fffffa60`02c33bf0 fffff800`01a69233 win32k!NtUserCallNoParam+0x36
fffffa60`02c33c20 000007fe`fde7c3da nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffffa60`02c33c20)
00000000`002afd98 000007fe`fde7c3c9 winsrv!ZwUserCallNoParam+0xa
00000000`002afda0 00000000`778e2f6c winsrv!StartCreateSystemThreads+0x19
00000000`002afdd0 00000000`00000000 ntdll!RtlUserThreadStart+0x29

session 1 (console, keyboard IRP)

THREAD fffffa80296821d0  Cid 0324.0370  Teb: 000007fffffd3000 Win32Thread: fffff900c00e33b0 WAIT: (WrUserRequest) KernelMode Alertable
fffffa80137c6430  SynchronizationEvent
fffffa802967fc30  NotificationTimer
fffffa8029680360  SynchronizationTimer
fffffa802967f970  SynchronizationEvent
IRP List:
fffffa802968b2e0: (0006,03a0) Flags: 00060970  Mdl: 00000000
fffffa802960d4c0: (0006,03a0) Flags: 00060970  Mdl: 00000000
fffffa8012ec7470: (0006,03a0) Flags: 00060970  Mdl: 00000000

Not impersonating
DeviceMap                 fffff88000008e00
Owning Process            fffffa8029672c10       Image:         csrss.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      428605         Ticks: 56 (0:00:00:00.873)
Context Switch Count      24934                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address winsrv!StartCreateSystemThreads (0×000007fefde7c3b0)
Stack Init fffffa6008bd0db0 Current fffffa6008bd0890
Base fffffa6008bd1000 Limit fffffa6008bcb000 Call 0
Priority 15 BasePriority 13 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`08bd08d0 fffff800`01a6b9fa nt!KiSwapContext+0×7f
fffffa60`08bd0a10 fffff800`01a712db nt!KiSwapThread+0×13a
fffffa60`08bd0a80 fffff960`000ed088 nt!KeWaitForMultipleObjects+0×2eb
fffffa60`08bd0b00 fffff960`00068317 win32k!RawInputThread+0×79c
fffffa60`08bd0bc0 fffff960`000eddc6 win32k!xxxCreateSystemThreads+0×67
fffffa60`08bd0bf0 fffff800`01a69233 win32k!NtUserCallNoParam+0×36
fffffa60`08bd0c20 000007fe`fde7c3da nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`08bd0c20)
00000000`014afab8 000007fe`fde7c3c9 winsrv!ZwUserCallNoParam+0xa
00000000`014afac0 00000000`778e2f6c winsrv!StartCreateSystemThreads+0×19
00000000`014afaf0 00000000`00000000 ntdll!RtlUserThreadStart+0×29

15: kd> !irp fffffa802968b2e0
Irp is active with 7 stacks 7 is current (= 0xfffffa802968b560)
No Mdl: System buffer=fffffa8029688790: Thread fffffa80296821d0:  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
>[  3, 0]   0  1 fffffa8013703ce0 fffffa8029687670 00000000-00000000    pending
        \Driver\kbdclass
Args: 00000078 00000000 00000000 00000000

15: kd> !irp fffffa802960d4c0
Irp is active with 10 stacks 10 is current (= 0xfffffa802960d818)
No Mdl: System buffer=fffffa8029681010: Thread fffffa80296821d0:  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
[  0, 0]   0  0 00000000 00000000 00000000-00000000   

   Args: 00000000 00000000 00000000 00000000
>[  3, 0]   0  1 fffffa801392ace0 fffffa8029686880 00000000-00000000    pending
        \Driver\kbdclass
Args: 00000078 00000000 00000000 00000000

15: kd> !irp fffffa8012ec7470
Irp is active with 3 stacks 3 is current (= 0xfffffa8012ec75d0)
No Mdl: System buffer=fffffa8029687010: Thread fffffa80296821d0:  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
>[  3, 0]   0  1 fffffa8013722060 fffffa8029680200 00000000-00000000    pending
        \Driver\kbdclass
Args: 00000078 00000000 00000000 00000000

session N (terminal services, termdd IRP)

THREAD fffffa80168fbac0  Cid 175c.533c  Teb: 000007fffffae000 Win32Thread: fffff900c018d010 WAIT: (WrUserRequest) KernelMode Alertable
fffffa8015355e70  SynchronizationEvent
fffffa8016442950  NotificationTimer
fffffa80156f9f70  SynchronizationTimer
fffffa8016967a50  SynchronizationEvent
IRP List:
fffffa801501ba30: (0006,0118) Flags: 00060900  Mdl: 00000000

Not impersonating
DeviceMap                 fffff88000008e00
Owning Process            fffffa802b33ac10       Image:         csrss.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      428641         Ticks: 20 (0:00:00:00.312)
Context Switch Count      32238                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.218
Win32 Start Address winsrv!StartCreateSystemThreads (0×000007fefde7c3b0)
Stack Init fffffa601ccdbdb0 Current fffffa601ccdb890
Base fffffa601ccdc000 Limit fffffa601ccd6000 Call 0
Priority 15 BasePriority 13 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`1ccdb8d0 fffff800`01a6b9fa nt!KiSwapContext+0×7f
fffffa60`1ccdba10 fffff800`01a712db nt!KiSwapThread+0×13a
fffffa60`1ccdba80 fffff960`000ed088 nt!KeWaitForMultipleObjects+0×2eb
fffffa60`1ccdbb00 fffff960`00068317 win32k!RawInputThread+0×79c
fffffa60`1ccdbbc0 fffff960`000eddc6 win32k!xxxCreateSystemThreads+0×67
fffffa60`1ccdbbf0 fffff800`01a69233 win32k!NtUserCallNoParam+0×36
fffffa60`1ccdbc20 000007fe`fde7c3da nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`1ccdbc20)
00000000`0137f878 000007fe`fde7c3c9 winsrv!ZwUserCallNoParam+0xa
00000000`0137f880 00000000`778e2f6c winsrv!StartCreateSystemThreads+0×19
00000000`0137f8b0 00000000`00000000 ntdll!RtlUserThreadStart+0×29

15: kd> !irp fffffa801501ba30
Irp is active with 1 stacks 1 is current (= 0xfffffa801501bb00)
No Mdl: No System Buffer: Thread fffffa80168fbac0:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  3, 0]   0  1 fffffa801370adb0 fffffa801705ef20 00000000-00000000    pending
        \Driver\TermDD
Args: 00000078 00000000 00000000 00000000

Half-hash caching of passwords (p. 517)

logonsessions tool (pp. 519 - 520)

Icons for Memory Dump Analysis Patterns (Part 48)

Thursday, June 17th, 2010

Today we introduce an icon for Coupled Processes (weak) pattern:

B/W

Color

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

Introducing Crash and Hang Analysis Audit Service

Wednesday, June 16th, 2010

Adding AI. Analysis Improvement.

After reading earlier today Windows Internals pages about system audit an idea came to my mind in the evening to provide audit services for memory dump and software trace analysis. One mind is good but two are better, especially if the second is a pattern-driven AI. Here are possible problem scenarios:

Problem: You are not satisfied with a crash report.

Problem: Your critical issue is escalated to the VP level. Engineers analyze memory dumps and software traces. No definite conclusion so far. You want to be sure that nothing has been omitted from the analysis.

Problem: You analyze a system dump or a software trace. You need a second pair of eyes but don’t want to send your memory dump due to your company security policies.

Other scenarios (use cases) will be added as soon as I see the service fit to the realities of software technical support.

I plan to make this service operational in July - August, 2010. Prices to be announced soon.

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

10 Common Mistakes in Memory Analysis (Part 8)

Wednesday, June 16th, 2010

Yet another common mistake is not looking past the first found evidence. For example, not looking further to prove or disprove a hypothesis after finding a pattern. Let me illustrate this by a complete memory dump from a frozen system. Careful analysis of wait chains revealed a thread owning a mutant and blocking other threads from many processes:

THREAD 882e8730  Cid 0f64.2ce0  Teb: 7ff76000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
    89a76e08  SynchronizationEvent
IRP List:
    883fbba0: (0006,0220) Flags: 00000830  Mdl: 00000000
Not impersonating
DeviceMap                 e1003880
Owning Process            89e264e8       Image:         ProcessA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      5090720        Ticks: 1981028 (0:08:35:53.562)
Context Switch Count      8376            
UserTime                  00:00:00.000
KernelTime                00:00:00.015
Win32 Start Address 0×010d22a3
LPC Server thread working on message Id 10d22a3
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b6e8b000 Current b6e8ac60 Base b6e8b000 Limit b6e88000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
b6e8ac78 8083d26e nt!KiSwapContext+0×26
b6e8aca4 8083dc5e nt!KiSwapThread+0×2e5
b6e8acec 8092cd88 nt!KeWaitForSingleObject+0×346
b6e8ad50 8083387f nt!NtWaitForSingleObject+0×9a
b6e8ad50 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ b6e8ad64)
0408f910 7c827d29 ntdll!KiFastSystemCallRet
0408f914 77e61d1e ntdll!ZwWaitForSingleObject+0xc
0408f984 77e61c8d kernel32!WaitForSingleObjectEx+0xac
0408f998 027f0808 kernel32!WaitForSingleObject+0×12
0408f9bc 027588d4 DllA!DriverB_DependentFunction+0×86
[…]
0408ffec 00000000 kernel32!BaseThreadStart+0×34

So we did found a culprit component, DllA, or not? Could this blockage result from earlier problems? We search stack trace collection for any other anomalous activity (Semantic Split) and we find indeed a recurrent stack trace pattern across process landscape:

THREAD 89edadb0  Cid 09fc.1050  Teb: 7ff54000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
    8a38b82c  SynchronizationEvent
IRP List:
    893a7470: (0006,0094) Flags: 00000000  Mdl: 00000000
Not impersonating
DeviceMap                 e16dc398
Owning Process            8a2ad5e0       Image:         ProcessB.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      3704877        Ticks: 3366871 (0:14:36:47.359)
Context Switch Count      121867            
UserTime                  00:00:25.093
KernelTime                00:00:01.968
Win32 Start Address MSVCR71!_threadstartex (0×7c3494f6)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init f3a9c000 Current f3a9b548 Base f3a9c000 Limit f3a99000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
f3a9b560 8083d26e nt!KiSwapContext+0×26
f3a9b58c 8083dc5e nt!KiSwapThread+0×2e5
f3a9b5d4 f6866255 nt!KeWaitForSingleObject+0×346
f3a9b5f4 f68663e3 DriverA!Block+0×1b
f3a9b604 f5ba05f1 DriverA!BlockWithTracker+0×19
f3a9b634 f5b9ba24 DriverB!DoRequest+0xc2
f3a9b724 f5b9b702 DriverB!QueryInfo+0×392

[…]

0: kd> !irp 893a7470
Irp is active with 1 stacks 1 is current (= 0×893a74e0)
 No Mdl: No System Buffer: Thread 89edadb0:  Irp stack trace. 
     cmd  flg cl Device   File     Completion-Context
>[  e, 0]   0  1 8a216f18 8a023f70 00000000-00000000    pending
        \Driver\DriverB
   Args: 0000015c 00000024 00120003 111af32c

We know that DllA!DriverB_DependentFunction will not work if DriverB device doesn’t function (for example, remote file system access without network access). The thread 89edadb0 had been waiting for more 14 hours and the originally found thread 882e8730 was waiting for less than 9 hours. This suggests looking first into DriverB / DriverA functions first.

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

Icons for Memory Dump Analysis Patterns (Part 47)

Monday, June 14th, 2010

Today we introduce an icon for Coupled Processes (strong) pattern:

B/W

Color

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

The Extended Software Trace

Sunday, June 13th, 2010

By analogy with paratext let’s introduce a software narratological concept of the extended software trace that consists of a software trace plus additional supporting information that makes troubleshooting and debugging easier. Such “paratextual” information can consists of pictures, videos, accounts of scenarios and past problem histories, customer interviews and even software trace delivery medium and format (if preformatted).

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

Attached Processes

Friday, June 11th, 2010

I’d always seen the empty field Attached Process in !thread command output:

1: kd> !thread fffffa802c2cfbb0 ff
THREAD fffffa802c2cfbb0  Cid 43b8.470c  Teb: 000007fffffda000 Win32Thread: 0000000000000000 WAIT: (WrQueue) UserMode Non-Alertable
    fffffa802acfc970  QueueObject
    fffffa802c2cfc68  NotificationTimer
Not impersonating
DeviceMap                 fffff88000008e00
Owning Process            fffffa802af8ac10       Image:         winlogon.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      428658         Ticks: 3 (0:00:00:00.046)
Context Switch Count      4            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address RPCRT4!ThreadStartRoutine (0×000007fefea07780)
Stack Init fffffa6029203db0 Current fffffa60292037e0
Base fffffa6029204000 Limit fffffa60291fe000 Call 0
Priority 13 BasePriority 13 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`29203820 fffff800`01a6b9fa nt!KiSwapContext+0×7f
fffffa60`29203960 fffff800`01a6ee94 nt!KiSwapThread+0×13a
fffffa60`292039d0 fffff800`01cd1cd7 nt!KeRemoveQueueEx+0×4b4
fffffa60`29203a80 fffff800`01ca8b2d nt!IoRemoveIoCompletion+0×47
fffffa60`29203b00 fffff800`01a69233 nt!NtRemoveIoCompletion+0×13d
fffffa60`29203bb0 00000000`778c6daa nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`29203c20)
00000000`017ff9f8 00000000`7769f65c ntdll!NtRemoveIoCompletion+0xa
00000000`017ffa00 000007fe`fea25d0d kernel32!GetQueuedCompletionStatus+0×48
00000000`017ffa60 000007fe`fea25b93 RPCRT4!COMMON_ProcessCalls+0×7d
00000000`017ffaf0 000007fe`fea07769 RPCRT4!LOADABLE_TRANSPORT::ProcessIOEvents+0×133
00000000`017ffba0 000007fe`fea07714 RPCRT4!ProcessIOEventsWrapper+0×9
00000000`017ffbd0 000007fe`fea077a4 RPCRT4!BaseCachedThreadRoutine+0×94
00000000`017ffc10 00000000`7769be3d RPCRT4!ThreadStartRoutine+0×24
00000000`017ffc40 00000000`778a6a51 kernel32!BaseThreadInitThunk+0xd
00000000`017ffc70 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

Until recently I got this stack trace from winlogon.exe deep in win32k.sys. Because csrss.exe is a session-specific user-space counterpart to win32k.sys it make sense to see it attached:

1: kd> !thread fffffa802b2e6bb0 ff
THREAD fffffa802b2e6bb0  Cid 43b8.74d0  Teb: 000007fffffdc000 Win32Thread: fffff900c0016690 RUNNING on processor 1
Not impersonating
DeviceMap                 fffff88000008e00
Owning Process            fffffa802af8ac10       Image:         winlogon.exe
Attached Process          fffffa80174d7040       Image:         csrss.exe
Wait Start TickCount      428661         Ticks: 0
Context Switch Count      212                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.031
Win32 Start Address 0×00000000ff860260
Stack Init fffffa60294c15f0 Current fffffa60294c0ec0
Base fffffa60294c3000 Limit fffffa60294b9000 Call fffffa60294c1840
Priority 15 BasePriority 15 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`294c0340 fffff800`01a77197 nt!MiAllocatePagedPoolPages+0×69d
fffffa60`294c0410 fffff800`01b49f07 nt!ExpAllocateBigPool+0xa7
fffffa60`294c04f0 fffff960`00082f28 nt!ExAllocatePoolWithTag+0×767
fffffa60`294c05c0 fffff960`00094863 win32k!EngAllocMem+0×3c
fffffa60`294c05f0 fffff960`00094749 win32k!ttfdOpenFontContextInternal+0xbf
fffffa60`294c0630 fffff960`000976d9 win32k!ttfdOpenFontContext+0×1d
fffffa60`294c0670 fffff960`0009762c win32k!ttfdQueryFontData+0×49
fffffa60`294c06c0 fffff960`0008c335 win32k!ttfdSemQueryFontData+0×7c
fffffa60`294c0720 fffff960`0008989a win32k!PDEVOBJ::QueryFontData+0×79
fffffa60`294c0780 fffff960`0008bacb win32k!RFONTOBJ::bGetDEVICEMETRICS+0×6a
fffffa60`294c07d0 fffff960`0004d0e1 win32k!RFONTOBJ::bRealizeFont+0×2df
fffffa60`294c08f0 fffff960`0004caa5 win32k!RFONTOBJ::vInit+0×379
fffffa60`294c0bb0 fffff960`00048fdd win32k!RFONTOBJ::vInitEUDC+0×5e5
fffffa60`294c0d80 fffff960`0008c516 win32k!RFONTOBJ::wpgdGetLinkMetricsPlus+0×33d
fffffa60`294c0e00 fffff960`0009b1b2 win32k!RFONTOBJ::bGetGlyphMetrics+0×1b6
fffffa60`294c0e80 fffff960`00082699 win32k!RFONTOBJ::bGetWidthTable+0×262
fffffa60`294c1080 fffff960`00082395 win32k!iGetPublicWidthTable+0×28d
fffffa60`294c1430 fffff800`01a69233 win32k!NtGdiSetupPublicCFONT+0×25
fffffa60`294c1460 000007fe`fe23c55a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`294c1460)

1: kd> !thread fffffa802bd9f060 ff
THREAD fffffa802bd9f060  Cid 7624.28b8  Teb: 000007fffffdd000 Win32Thread: fffff900c0016690 RUNNING on processor 0
Not impersonating
DeviceMap                 fffff88000008e00
Owning Process            fffffa802b18d040       Image:         winlogon.exe
Attached Process          fffffa802ad2fc10       Image:         csrss.exe
Wait Start TickCount      428661         Ticks: 0
Context Switch Count      196                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.046
Win32 Start Address 0×00000000ff860260
Stack Init fffffa60296b3db0 Current fffffa60296b1980
Base fffffa60296b4000 Limit fffffa60296aa000 Call 0
Priority 15 BasePriority 15 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`296b22b8 fffff960`0009022a win32k!itrp_CINDEX+0×4f
fffffa60`296b22c0 fffff960`00092817 win32k!itrp_InnerExecute+0×36
fffffa60`296b22f0 fffff960`0009022a win32k!itrp_CALL+0×26f
fffffa60`296b2360 fffff960`00092817 win32k!itrp_InnerExecute+0×36
fffffa60`296b2390 fffff960`0009022a win32k!itrp_CALL+0×26f
fffffa60`296b2400 fffff960`0009a6e3 win32k!itrp_InnerExecute+0×36
fffffa60`296b2430 fffff960`00099720 win32k!itrp_Execute+0×384
fffffa60`296b2540 fffff960`0009968e win32k!itrp_ExecutePrePgm+0×78
fffffa60`296b2590 fffff960`00096da6 win32k!fsg_RunPreProgram+0×222
fffffa60`296b25e0 fffff960`00096af4 win32k!fs__Contour+0×256
fffffa60`296b26a0 fffff960`0009796c win32k!bGetGlyphOutline+0×125
fffffa60`296b26d0 fffff960`000978d8 win32k!lGetGlyphBitmap+0×4c
fffffa60`296b2890 fffff960`0009762c win32k!ttfdQueryFontData+0×248
fffffa60`296b28e0 fffff960`0008c335 win32k!ttfdSemQueryFontData+0×7c
fffffa60`296b2940 fffff960`0008c213 win32k!PDEVOBJ::QueryFontData+0×79
fffffa60`296b29a0 fffff960`0008bf4f win32k!RFONTOBJ::bInitCache+0×15f
fffffa60`296b2a40 fffff960`00086337 win32k!RFONTOBJ::bRealizeFont+0×763
fffffa60`296b2b60 fffff960`0008aac8 win32k!RFONTOBJ::bInit+0×523
fffffa60`296b2c70 fffff960`00037597 win32k!GreGetTextMetricsW+0×48
fffffa60`296b2cb0 fffff960`00038a42 win32k!GetTextMetricsW+0×17
fffffa60`296b2d30 fffff960`00047951 win32k!GetCharDimensions+0×26
fffffa60`296b2db0 fffff960`00049aae win32k!xxxSetNCFonts+0×181
fffffa60`296b2e60 fffff960`0005be45 win32k!xxxSetWindowNCMetrics+0×3e
fffffa60`296b30e0 fffff960`000768bf win32k!xxxInitWindowStation+0xa1
fffffa60`296b3140 fffff960`00077daf win32k!xxxCreateWindowStation+0×1cf
fffffa60`296b3500 fffff800`01a69233 win32k!NtUserCreateWindowStation+0×4b3
fffffa60`296b3bb0 00000000`777b1a6a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`296b3c20)
00000000`000ff338 00000000`00000000 USER32!NtUserCreateWindowStation+0xa

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

Free Verse (Debugging Slang, Part 12)

Thursday, June 10th, 2010

Free Verse - Source code without rules, for example, [p=malloc(); free(p); free(p);] that results in all problems associated with freedom.

Examples: What an ugly free verse! A master of free verse. Please check out that free verse written a few months ago.

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