Archive for the ‘Countefactual Debugging’ Category

Crossdisciplinary Memoretics as Interdisciplinary Science

Wednesday, September 21st, 2011

Memoretics as a science of memory snapshots borrows many ideas from the following disciplines (the list is not exhaustive):

  • Troubleshooting and Debugging
  • Intelligence Analysis
  • Critical Thinking
  • Forensics
  • Linguistics
  • Archaeology
  • Psychoanalysis
  • History
  • Mathematics: Sets and Categories
  • Literary Criticism and Narratology

It also contributes many ideas back. The following diagram depicts such an interaction:

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

The New School of Debugging

Saturday, January 1st, 2011

With the new year starts the new initiative to integrate traditional multidisciplinary debugging approaches and methodologies with multiplatform pattern-driven software problem solving, unified debugging patterns, best practices in memory dump analysis and software tracing, computer security, economics, and the new emerging trends I’m going to write about during this year.

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

Debugging in 2021: Trends for the Next Decade (Part 1)

Friday, December 17th, 2010

As the new decade is approaching (2011-2020) we would like to make a few previews and predictions:

- Increased complexity of software will bring more methods from biological, social sciences and humanities in addition to existing methods of automated debugging and computer science techniques

- Focus on first fault software problem solving (when aspect)

- Focus on pattern-driven software problem solving (how aspect)

- Fusion of debugging and malware analysis into a unified structural and behavioral pattern framework

- Visual debugging, memory and software trace visualization techniques

- Software maintenance certification

- Focus on domain-driven troubleshooting and debugging tools as a service (debugware TaaS)

- Focus on security issues related to memory dumps and software traces

- New scripting languages and programming language extensions for debugging

- The maturation of the science of memory snapshots and software traces (memoretics)

Imagining is not not limited to the above and more to come and explain in the forthcoming parts.

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

Memory Dump Analysis Anthology, Volume 4 is available for download

Saturday, November 6th, 2010

I’m pleased to announce that MDAA, Volume 4 is available in PDF format:

www.dumpanalysis.org/Memory+Dump+Analysis+Anthology+Volume+4

It features:

- 15 new crash dump analysis patterns
- 13 new pattern interaction case studies
- 10 new trace analysis patterns
- 6 new Debugware patterns and case study
- Workaround patterns
- Updated checklist
- Fully cross-referenced with Volume 1, Volume 2 and Volume 3
- Memory visualization tutorials
- Memory space art

Its table of contents is available here:

http://www.dumpanalysis.org/MDAA/MDA-Anthology-V4-TOC.pdf

Paperback and hardcover versions should be available in a week or two. I also started working on Volume 5 that should be available in December.

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

Main thread, critical section wait chains, critical section deadlock, stack trace collection, execution residue, data contents locality, self-diagnosis and not my version: pattern cooperation

Monday, April 19th, 2010

A spooler service process was hanging and its user memory dump shows many threads blocked waiting for critical sections including the main one:

0:000> kL
ChildEBP RetAddr 
0007fa94 7c827d29 ntdll!KiFastSystemCallRet
0007fa98 7c83d266 ntdll!ZwWaitForSingleObject+0xc
0007fad4 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×1a3
0007faf4 7c82dadf ntdll!RtlEnterCriticalSection+0xa8

0007fb94 7c82dad1 ntdll!LdrpGetProcedureAddress+0×128
0007fbb0 77e63db9 ntdll!LdrGetProcedureAddress+0×18
0007fbd8 01002ea1 kernel32!GetProcAddress+0×44
0007fc38 01002dbc spoolsv!__delayLoadHelper2+0×1d9
0007fc64 7d1e41fc spoolsv!_tailMerge_SPOOLSS+0xd
0007fcd8 7d1e1ed9 ADVAPI32!ScDispatcherLoop+0×287
0007ff3c 01004019 ADVAPI32!StartServiceCtrlDispatcherW+0xe3
0007ff44 010047a2 spoolsv!main+0xb
0007ffc0 77e6f23b spoolsv!mainCRTStartup+0×12f
0007fff0 00000000 kernel32!BaseProcessStart+0×23

0:000> !analyze -v -hang

DERIVED_WAIT_CHAIN:

Dl Eid Cid     WaitType
-- --- ------- --------------------------
   0   3990.3e80 Critical Section       –>
   18
  3990.3f28 Critical Section

PRIMARY_PROBLEM_CLASS:  APPLICATION_HANG_HeapCorruption

FOLLOWUP_IP:
msvcrt!calloc+118
77bbcdf3 8945e4          mov     dword ptr [ebp-1Ch],eax

0:018> kL 100
ChildEBP RetAddr 
03b589b4 7c827d19 ntdll!KiFastSystemCallRet
03b589b8 77e76792 ntdll!NtWaitForMultipleObjects+0xc
03b58cec 7c8604ae kernel32!UnhandledExceptionFilter+0x7c0
03b58cf4 7c8282f1 ntdll!RtlpPossibleDeadlock+0xa5
03b58d1c 7c828772 ntdll!_except_handler3+0x61
03b58d40 7c828743 ntdll!ExecuteHandler2+0x26
03b58de8 7c82865c ntdll!ExecuteHandler+0x24
03b590c8 7c860491 ntdll!RtlRaiseException+0×3d
03b5914c 7c84cf0c ntdll!RtlpPossibleDeadlock+0×8d
03b59180 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×226
03b591a0 7c82a284 ntdll!RtlEnterCriticalSection+0xa8
03b593c8 77bbcdf3 ntdll!RtlAllocateHeap+0×313

03b59408 77bbd45b msvcrt!calloc+0×118
03b59428 77bd3e55 msvcrt!_calloc_crt+0×19
03b59430 77bcfc38 msvcrt!_getbuf+0×12
03b59444 77bd1f26 msvcrt!_flsbuf+0×76
03b5946c 77bd40e6 msvcrt!_putwc_lk+0×99
03b5947c 77bd445b msvcrt!_ftbuf+0×4d
03b598f8 77bd253b msvcrt!_woutput+0×2ee
03b59940 7617785d msvcrt!fwprintf+0×33
03b59950 761778d3 localspl!InitiateErrorReport+0×28
03b59984 76176cfa localspl!CaptureAndLogException+0×24
03b5998c 3f01484b localspl!SplExceptionLoggingFilter+0×15
WARNING: Stack unwind information not available. Following frames may be wrong.
03b599ac 02938a47 PrinterDriverA+0xb72b
03b59c34 7c8604ae PrinterDriverB+0xf2a7
03b59c3c 7c8282f1 ntdll!RtlpPossibleDeadlock+0xa5
03b59c64 7c828772 ntdll!_except_handler3+0×61
03b59c88 7c828743 ntdll!ExecuteHandler2+0×26
03b59d30 7c82865c ntdll!ExecuteHandler+0×24
03b5a010 7c860491 ntdll!RtlRaiseException+0×3d
03b5a094 7c84cf0c ntdll!RtlpPossibleDeadlock+0×8d
03b5a0c8 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×226
03b5a0e8 7c82a284 ntdll!RtlEnterCriticalSection+0xa8
03b5a310 77bbcdf3 ntdll!RtlAllocateHeap+0×313
03b5a350 77bbd45b msvcrt!calloc+0×118
03b5a370 77bd3e55 msvcrt!_calloc_crt+0×19
03b5a378 77bcfc38 msvcrt!_getbuf+0×12
03b5a38c 77bd1f26 msvcrt!_flsbuf+0×76
03b5a3b4 77bd40e6 msvcrt!_putwc_lk+0×99
03b5a3c4 77bd445b msvcrt!_ftbuf+0×4d
03b5a840 77bd253b msvcrt!_woutput+0×2ee
03b5a888 7617785d msvcrt!fwprintf+0×33
03b5a898 761778d3 localspl!InitiateErrorReport+0×28
03b5a8cc 76176cfa localspl!CaptureAndLogException+0×24
03b5a8d4 3f01484b localspl!SplExceptionLoggingFilter+0×15
03b5a8f4 02938a47 PrinterDriverA+0xb72b
03b5ab7c 7c8604ae PrinterDriverB+0xf2a7
03b5ab84 7c8282f1 ntdll!RtlpPossibleDeadlock+0xa5
03b5abac 7c828772 ntdll!_except_handler3+0×61
03b5abd0 7c828743 ntdll!ExecuteHandler2+0×26
03b5ac78 7c82865c ntdll!ExecuteHandler+0×24
03b5af58 7c860491 ntdll!RtlRaiseException+0×3d
03b5afdc 7c84cf0c ntdll!RtlpPossibleDeadlock+0×8d
03b5b010 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×226
03b5b030 7c82a284 ntdll!RtlEnterCriticalSection+0xa8
03b5b258 77bbcdf3 ntdll!RtlAllocateHeap+0×313
03b5b298 77bbd45b msvcrt!calloc+0×118
03b5b2b8 77bd3e55 msvcrt!_calloc_crt+0×19
03b5b2c0 77bcfc38 msvcrt!_getbuf+0×12
03b5b2d4 77bd1f26 msvcrt!_flsbuf+0×76
03b5b2fc 77bd40e6 msvcrt!_putwc_lk+0×99
03b5b30c 77bd445b msvcrt!_ftbuf+0×4d
03b5b788 77bd253b msvcrt!_woutput+0×2ee
03b5b7d0 7617785d msvcrt!fwprintf+0×33
03b5b7e0 761778d3 localspl!InitiateErrorReport+0×28
03b5b814 76176cfa localspl!CaptureAndLogException+0×24
03b5b81c 3f01484b localspl!SplExceptionLoggingFilter+0×15
03b5b83c 02938a47 PrinterDriverA+0xb72b
03b5bac4 7c8604ae PrinterDriverB+0xf2a7
03b5bacc 7c8282f1 ntdll!RtlpPossibleDeadlock+0xa5
03b5baf4 7c828772 ntdll!_except_handler3+0×61
03b5bb18 7c828743 ntdll!ExecuteHandler2+0×26
03b5bbc0 7c82865c ntdll!ExecuteHandler+0×24
03b5bea0 7c860491 ntdll!RtlRaiseException+0×3d
03b5bf24 7c84cf0c ntdll!RtlpPossibleDeadlock+0×8d
03b5bf58 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×226
03b5bf78 7c82a284 ntdll!RtlEnterCriticalSection+0xa8
03b5c1a0 77bbcdf3 ntdll!RtlAllocateHeap+0×313
03b5c1e0 77bbd45b msvcrt!calloc+0×118
03b5c200 77bd3e55 msvcrt!_calloc_crt+0×19
03b5c208 77bcfc38 msvcrt!_getbuf+0×12
03b5c21c 77bd1f26 msvcrt!_flsbuf+0×76
03b5c244 77bd40e6 msvcrt!_putwc_lk+0×99
03b5c254 77bd445b msvcrt!_ftbuf+0×4d
03b5c6d0 77bd253b msvcrt!_woutput+0×2ee
03b5c718 7617785d msvcrt!fwprintf+0×33
03b5c728 761778d3 localspl!InitiateErrorReport+0×28
03b5c75c 76176cfa localspl!CaptureAndLogException+0×24
03b5c764 3f01484b localspl!SplExceptionLoggingFilter+0×15
03b5c784 02938a47 PrinterDriverA+0xb72b
03b5ca0c 7c8604ae PrinterDriverB+0xf2a7
03b5ca14 7c8282f1 ntdll!RtlpPossibleDeadlock+0xa5
03b5ca3c 7c828772 ntdll!_except_handler3+0×61
03b5ca60 7c828743 ntdll!ExecuteHandler2+0×26
03b5cb08 7c82865c ntdll!ExecuteHandler+0×24
03b5cde8 7c860491 ntdll!RtlRaiseException+0×3d
03b5ce6c 7c84cf0c ntdll!RtlpPossibleDeadlock+0×8d
03b5cea0 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×226
03b5cec0 7c82a284 ntdll!RtlEnterCriticalSection+0xa8
03b5d0e8 77bbcdf3 ntdll!RtlAllocateHeap+0×313
03b5d128 77bbd45b msvcrt!calloc+0×118
03b5d148 77bd3e55 msvcrt!_calloc_crt+0×19
03b5d150 77bcfc38 msvcrt!_getbuf+0×12
03b5d164 77bd1f26 msvcrt!_flsbuf+0×76
03b5d18c 77bd40e6 msvcrt!_putwc_lk+0×99
03b5d19c 77bd445b msvcrt!_ftbuf+0×4d
03b5d618 77bd253b msvcrt!_woutput+0×2ee
03b5d660 7617785d msvcrt!fwprintf+0×33
03b5d670 761778d3 localspl!InitiateErrorReport+0×28
03b5d6a4 76176cfa localspl!CaptureAndLogException+0×24
03b5d6ac 3f01484b localspl!SplExceptionLoggingFilter+0×15
03b5d6cc 02938a47 PrinterDriverA+0xb72b
03b5d954 7c8604ae PrinterDriverB+0xf2a7
03b5d95c 7c8282f1 ntdll!RtlpPossibleDeadlock+0xa5
03b5d984 7c828772 ntdll!_except_handler3+0×61
03b5d9a8 7c828743 ntdll!ExecuteHandler2+0×26
03b5da50 7c82865c ntdll!ExecuteHandler+0×24
03b5dd30 7c860491 ntdll!RtlRaiseException+0×3d
03b5ddb4 7c84cf0c ntdll!RtlpPossibleDeadlock+0×8d
03b5dde8 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×226
03b5de08 7c82a284 ntdll!RtlEnterCriticalSection+0xa8
03b5e030 77bbcdf3 ntdll!RtlAllocateHeap+0×313
03b5e070 77bbd45b msvcrt!calloc+0×118
03b5e090 77bd3e55 msvcrt!_calloc_crt+0×19
03b5e098 77bcfc38 msvcrt!_getbuf+0×12
03b5e0ac 77bd1f26 msvcrt!_flsbuf+0×76
03b5e0d4 77bd40e6 msvcrt!_putwc_lk+0×99
03b5e0e4 77bd445b msvcrt!_ftbuf+0×4d
03b5e560 77bd253b msvcrt!_woutput+0×2ee
03b5e5a8 7617785d msvcrt!fwprintf+0×33
03b5e5b8 761778d3 localspl!InitiateErrorReport+0×28
03b5e5ec 76176cfa localspl!CaptureAndLogException+0×24
03b5e5f4 3f01484b localspl!SplExceptionLoggingFilter+0×15
03b5e614 02938a47 PrinterDriverA+0xb72b
03b5e89c 7c8604ae PrinterDriverB+0xf2a7
03b5e8a4 7c8282f1 ntdll!RtlpPossibleDeadlock+0xa5
03b5e8cc 7c828772 ntdll!_except_handler3+0×61
03b5e8f0 7c828743 ntdll!ExecuteHandler2+0×26
03b5e998 7c82865c ntdll!ExecuteHandler+0×24
03b5ec78 7c860491 ntdll!RtlRaiseException+0×3d
03b5ecfc 7c84cf0c ntdll!RtlpPossibleDeadlock+0×8d
03b5ed30 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×226
03b5ed50 7c82a284 ntdll!RtlEnterCriticalSection+0xa8
03b5ef78 77bbd08c ntdll!RtlAllocateHeap+0×313

03b5ef98 74ef12ca msvcrt!malloc+0×6c
03b5efac 74ef1241 resutils!_malloc_crt+0xf
03b5efb8 74ef132b resutils!_CRT_INIT+0×37
03b5efd8 7c81a352 resutils!_DllMainCRTStartup+0×42
03b5eff8 7c83348d ntdll!LdrpCallInitRoutine+0×14
03b5f100 7c834339 ntdll!LdrpRunInitializeRoutines+0×367
03b5f394 7c83408d ntdll!LdrpLoadDll+0×3cd
03b5f610 77e41bf7 ntdll!LdrLoadDll+0×198
03b5f678 77e5c70b kernel32!LoadLibraryExW+0×1b2
03b5f68c 7406621a kernel32!LoadLibraryW+0×11
03b5f6a8 740663c4 SPOOLSS!TClusterAPI::TClusterAPI+0×2d
03b5f758 74072c6b SPOOLSS!GetClusterIPAddresses+0×26
03b5f7bc 74072d8e SPOOLSS!TNameResolutionCache::IsNameCluster+0xdf
03b5f7d0 7403cf4d SPOOLSS!CacheIsNameCluster+0×1c
03b5f7e8 7403514e win32spl!IsNameTheLocalMachineOrAClusterSpooler+0xa1
03b5f818 74067306 win32spl!CacheOpenPrinter+0×4d
03b5f864 74066cf5 SPOOLSS!RouterOpenPrinterW+0×1bb
03b5f884 01004cf4 SPOOLSS!OpenPrinterW+0×19
03b5f8ac 01004c9e spoolsv!YOpenPrinter+0×5a
03b5f8d0 77c80193 spoolsv!RpcOpenPrinter+0×37
03b5f8f8 77ce33e1 RPCRT4!Invoke+0×30
03b5fcf8 77ce35c4 RPCRT4!NdrStubCall2+0×299
03b5fd14 77c7ff7a RPCRT4!NdrServerCall2+0×19
03b5fd48 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
03b5fd9c 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
03b5fdc0 77c811dc RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
03b5fdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×42c
03b5fe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
03b5ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
03b5ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
03b5ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
03b5ffb8 77e6482f RPCRT4!ThreadStartRoutine+0×1b
03b5ffec 00000000 kernel32!BaseThreadStart+0×34

The default command also reports a heap corruption but the closer inspection reveals that it was a detected deadlock:

0:018> kv 100
ChildEBP RetAddr  Args to Child             
03b589b4 7c827d19 77e76792 00000002 03b58b5c ntdll!KiFastSystemCallRet
03b589b8 77e76792 00000002 03b58b5c 00000001 ntdll!NtWaitForMultipleObjects+0xc
03b58cec 7c8604ae 03b58d14 7c8282f1 03b58d1c kernel32!UnhandledExceptionFilter+0×7c0
03b58cf4 7c8282f1 03b58d1c 00000000 03b58d1c ntdll!RtlpPossibleDeadlock+0xa5
03b58d1c 7c828772 03b590e0 03b5913c 03b58df8 ntdll!_except_handler3+0×61
03b58d40 7c828743 03b590e0 03b5913c 03b58df8 ntdll!ExecuteHandler2+0×26
03b58de8 7c82865c 03b58000 03b58df8 00010007 ntdll!ExecuteHandler+0×24
03b590c8 7c860491 03b590e0 7c88a9e8 00030608 ntdll!RtlRaiseException+0×3d
03b5914c 7c84cf0c 00030608 00000001 0003060c ntdll!RtlpPossibleDeadlock+0×8d
03b59180 7c83d2b1 00000c4c 00000004 00030000 ntdll!RtlpWaitOnCriticalSection+0×226
03b591a0 7c82a284 00030608 00000000 00001000 ntdll!RtlEnterCriticalSection+0xa8
03b593c8 77bbcdf3 00030000 00000008 00001000 ntdll!RtlAllocateHeap+0×313
[…]
03b5e89c 7c8604ae 03b5e8c4 7c8282f1 03b5e8cc PrinterDriverA+0xf2a7
03b5e8a4 7c8282f1 03b5e8cc 00000000 03b5e8cc ntdll!RtlpPossibleDeadlock+0xa5
03b5e8cc 7c828772 03b5ec90 03b5ecec 03b5e9a8 ntdll!_except_handler3+0×61
03b5e8f0 7c828743 03b5ec90 03b5ecec 03b5e9a8 ntdll!ExecuteHandler2+0×26
03b5e998 7c82865c 03b58000 03b5e9a8 00010007 ntdll!ExecuteHandler+0×24
03b5ec78 7c860491 03b5ec90 7c88a9e8 00030608 ntdll!RtlRaiseException+0×3d
03b5ecfc 7c84cf0c 00030608 00000001 0003060c ntdll!RtlpPossibleDeadlock+0×8d
03b5ed30 7c83d2b1 00000c4c 00000004 00030000 ntdll!RtlpWaitOnCriticalSection+0×226
03b5ed50 7c82a284 00030608 00000080 00000000 ntdll!RtlEnterCriticalSection+0xa8
03b5ef78 77bbd08c 00030000 00000000 00000080 ntdll!RtlAllocateHeap+0×313
03b5ef98 74ef12ca 00000080 00000000 00000000 msvcrt!malloc+0×6c
03b5efac 74ef1241 00000001 03b5efd8 74ef132b resutils!_malloc_crt+0xf
03b5efb8 74ef132b 74ef0000 00000001 00000000 resutils!_CRT_INIT+0×37
03b5efd8 7c81a352 74ef0000 00000001 00000000 resutils!_DllMainCRTStartup+0×42
03b5eff8 7c83348d 74ef12f4 74ef0000 00000001 ntdll!LdrpCallInitRoutine+0×14
03b5f100 7c834339 00000000 00000000 00000004 ntdll!LdrpRunInitializeRoutines+0×367
03b5f394 7c83408d 00000000 02785a60 03b5f65c ntdll!LdrpLoadDll+0×3cd
03b5f610 77e41bf7 02785a60 03b5f65c 03b5f63c ntdll!LdrLoadDll+0×198
03b5f678 77e5c70b 740654d4 00000000 00000000 kernel32!LoadLibraryExW+0×1b2
03b5f68c 7406621a 740654d4 000348b8 03b5f784 kernel32!LoadLibraryW+0×11
03b5f6a8 740663c4 000348b8 00000000 534c4354 SPOOLSS!TClusterAPI::TClusterAPI+0×2d
03b5f758 74072c6b 03b5f784 000e5874 00000610 SPOOLSS!GetClusterIPAddresses+0×26
03b5f7bc 74072d8e 00032920 000e5874 00000000 SPOOLSS!TNameResolutionCache::IsNameCluster+0xdf
03b5f7d0 7403cf4d 000e5874 000e5870 00000000 SPOOLSS!CacheIsNameCluster+0×1c
03b5f7e8 7403514e 000e5870 74075040 00c538f0 win32spl!IsNameTheLocalMachineOrAClusterSpooler+0xa1
03b5f818 74067306 000e5870 03b5f858 03b5f8a0 win32spl!CacheOpenPrinter+0×4d
03b5f864 74066cf5 000e5870 0273e500 03b5f8a0 SPOOLSS!RouterOpenPrinterW+0×1bb
03b5f884 01004cf4 000e5870 0273e500 03b5f8a0 SPOOLSS!OpenPrinterW+0×19
03b5f8ac 01004c9e 000e5870 0273e500 00000000 spoolsv!YOpenPrinter+0×5a
03b5f8d0 77c80193 000e5870 0273e500 00000000 spoolsv!RpcOpenPrinter+0×37
03b5f8f8 77ce33e1 01004c65 03b5fae0 00000005 RPCRT4!Invoke+0×30
03b5fcf8 77ce35c4 00000000 00000000 000f73d4 RPCRT4!NdrStubCall2+0×299
03b5fd14 77c7ff7a 000f73d4 000e4d30 000f73d4 RPCRT4!NdrServerCall2+0×19
03b5fd48 77c8042d 01002c47 000f73d4 03b5fdec RPCRT4!DispatchToStubInCNoAvrf+0×38
03b5fd9c 77c80353 00000001 00000000 0100d228 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
03b5fdc0 77c811dc 000f73d4 00000000 0100d228 RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
03b5fdfc 77c812f0 000f21d8 000e7028 000e5828 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×42c
03b5fe20 77c88678 000e7060 03b5fe38 000f21d8 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
03b5ff84 77c88792 03b5ffac 77c8872d 000e7028 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
03b5ff8c 77c8872d 000e7028 00000000 00000000 RPCRT4!RecvLotsaCallsWrapper+0xd
03b5ffac 77c7b110 000995b8 03b5ffec 77e6482f RPCRT4!BaseCachedThreadRoutine+0×9d
03b5ffb8 77e6482f 02753798 00000000 00000000 RPCRT4!ThreadStartRoutine+0×1b
03b5ffec 00000000 77c7b0f5 02753798 00000000 kernel32!BaseThreadStart+0×34

0:018> .exptr 03b58d14

----- Exception record at 03b590e0:
ExceptionAddress: 7c860491 (ntdll!RtlpPossibleDeadlock+0x0000008d)
   ExceptionCode: c0000194
  ExceptionFlags: 00000000
NumberParameters: 1
   Parameter[0]: 00030608
Critical section at 00030608 is owned by thread 00000000,
causing this thread to raise an exception

----- Context record at 03b58df8:
eax=00000000 ebx=00000003 ecx=00030608 edx=03b590e0 esi=01000002 edi=7c88a9e8
eip=7c860491 esp=03b590d4 ebp=03b5914c 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!RtlpPossibleDeadlock+0x8d:
7c860491 eb24            jmp     ntdll!RtlpPossibleDeadlock+0xa9 (7c8604b7)

0:018> .exr 03b5ec90
ExceptionAddress: 7c860491 (ntdll!RtlpPossibleDeadlock+0×0000008d)
   ExceptionCode: c0000194
  ExceptionFlags: 00000000
NumberParameters: 1
   Parameter[0]: 00030608
Critical section at 00030608 is owned by thread 00000000,
causing this thread to raise an exception

Notice that the problem section doesn’t have an owner. In order to find it we do search in memory:

0:018> s -d 0 L4000000 00030608
00030578  00030608 00000000 00030688 01010000
0162fa04  00030608 00000002 0162fad0 0162fb1c
03b58b6c  00030608 00000704 00000082 03b589d4
03b58ea4  00030608 00000000 03b5914c 7c860491
03b5907c  00030608 00000003 000000e8 010000e8
03b590d8  00030608 00000003 c0000194 00000000
03b590f4  00030608 00000704 0000e7c8 03b58e84
03b59154  00030608 00000001 0003060c 00000000
03b591a8  00030608 00000000 00001000 00000000
03b59dec  00030608 00000000 03b5a094 7c860491
03b59fc4  00030608 00000003 000000e8 010000e8
03b5a020  00030608 00000003 c0000194 00000000
03b5a03c  00030608 00000704 0000e7c8 03b59dcc
03b5a09c  00030608 00000001 0003060c 00000000
03b5a0f0  00030608 00000000 00001000 00000000
03b5ad34  00030608 00000000 03b5afdc 7c860491
03b5af0c  00030608 00000003 000000e8 010000e8
03b5af68  00030608 00000003 c0000194 00000000
03b5af84  00030608 00000704 0000e7c8 03b5ad14
03b5afe4  00030608 00000001 0003060c 00000000
03b5b038  00030608 00000000 00001000 00000000
03b5bc7c  00030608 00000000 03b5bf24 7c860491
03b5be54  00030608 00000003 000000e8 010000e8
03b5beb0  00030608 00000003 c0000194 00000000
03b5becc  00030608 00000704 0000e7c8 03b5bc5c
03b5bf2c  00030608 00000001 0003060c 00000000
03b5bf80  00030608 00000000 00001000 00000000
03b5cbc4  00030608 00000000 03b5ce6c 7c860491
03b5cd9c  00030608 00000003 000000e8 010000e8
03b5cdf8  00030608 00000003 c0000194 00000000
03b5ce14  00030608 00000704 0000e7c8 03b5cba4
03b5ce74  00030608 00000001 0003060c 00000000
03b5cec8  00030608 00000000 00001000 00000000
03b5db0c  00030608 00000000 03b5ddb4 7c860491
03b5dce4  00030608 00000003 000000e8 010000e8
03b5dd40  00030608 00000003 c0000194 00000000
03b5dd5c  00030608 00000704 0000e7c8 03b5daec
03b5ddbc  00030608 00000001 0003060c 00000000
03b5de10  00030608 00000000 00001000 00000000
03b5ea54  00030608 00000000 03b5ecfc 7c860491
03b5ec2c  00030608 00000003 000000e8 010000e8
03b5ec88  00030608 00000003 c0000194 00000000
03b5eca4  00030608 7c82a11c 0000e7c8 03b5ea34
03b5ed04  00030608 00000001 0003060c 00000000
03b5ed58  00030608 00000080 00000000 7c829ff6

Addresses that start with 03b5 belong to the thread #18 we have seen already, 00030578 looks like belonging to the critical section list and the address 0162fa04 belongs to the thread #8 (we find it by looking at all thread stacks and search for 0162 in ChildEBP fields):

0:018> ~*k

[...]

   8  Id: 3990.3d60 Suspend: 1 Teb: 7ffae000 Unfrozen
ChildEBP RetAddr 
0162ff18 7c827d29 ntdll!KiFastSystemCallRet
0162ff1c 77e61d1e ntdll!ZwWaitForSingleObject+0xc
0162ff8c 77e61c8d kernel32!WaitForSingleObjectEx+0xac
0162ffa0 72461375 kernel32!WaitForSingleObject+0×12
0162ffb8 77e6482f tcpmon!CDeviceStatus::StatusThread+0×2a
0162ffec 00000000 kernel32!BaseThreadStart+0×34

[...]

Nothing interesting until we look at raw stack and execution residue:

0:008> ~8s; !teb
eax=00000001 ebx=7246b050 ecx=0162fa78 edx=00000010 esi=0000041c edi=00000000
eip=7c82860c esp=0162ff1c ebp=0162ff8c iopl=0         nv up ei ng nz ac pe cy
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000297
ntdll!KiFastSystemCallRet:
7c82860c c3              ret
TEB at 7ffae000
    ExceptionList:        0162ff7c
    StackBase:            01630000
    StackLimit:           01628000

    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7ffae000
    EnvironmentPointer:   00000000
    ClientId:             00003990 . 00003d60
    RpcHandle:            00000000
    Tls Storage:          00000000
    PEB Address:          7ffde000
    LastErrorValue:       0
    LastStatusValue:      c000000d
    Count Owned Locks:    0
    HardErrorMode:        0

0:008> dds 01628000 01630000
01628000  00000000
01628004  00000000
01628008  00000000
0162800c  00000000
01628010  00000000
01628014  00000000
01628018  00000000
[…]
0162f984  313231a0
0162f988  0000e7c8
0162f98c  0162f9c8
0162f990  7c80b429 ntdll!_vsnprintf+0×2f
0162f994  0162f9a8
0162f998  7c84cf68 ntdll!RtlpNotOwnerCriticalSection+0×118
0162f99c  0000e7c8
0162f9a0  0162f9dc
0162f9a4  7c80b429 ntdll!_vsnprintf+0×2f
0162f9a8  0162f9bc
0162f9ac  7c84cfb8 ntdll!RtlpNotOwnerCriticalSection+0×168
0162f9b0  0162fcc0
0162f9b4  00000000
0162f9b8  00000200
0162f9bc  7c808080 ntdll!DbgSetDebugFilterState+0xc
0162f9c0  00000000
0162f9c4  00000000
0162f9c8  7c808080 ntdll!DbgSetDebugFilterState+0xc
0162f9cc  00000001
0162f9d0  0162f9ec
0162f9d4  7c8081d9 ntdll!DebugPrint+0×1c
0162f9d8  00000001
0162f9dc  0162fa78
0162f9e0  00000010
0162f9e4  ffffffff
0162f9e8  00000000
0162f9ec  0162fc94
0162f9f0  7c808194 ntdll!vDbgPrintExWithPrefixInternal+0×177
0162f9f4  0162fa60
0162f9f8  ffffffff
0162f9fc  7c812f85 ntdll!vDbgPrintExWithPrefixInternal+0×1d5
0162fa00  7c88a9e8 ntdll!RtlpTimeout
0162fa04  00030608
0162fa08  00000002
0162fa0c  0162fad0
0162fa10  0162fb1c
0162fa14  7c828290 ntdll!_except_handler3
0162fa18  7c82d9b8 ntdll!`string’+0xc
0162fa1c  ffffffff
0162fa20  7c82d9b5 ntdll!LdrpGetProcedureAddress+0xb3
0162fa24  7c82eaa3 ntdll!LdrpSnapThunk+0×31c
0162fa28  7c800000 ntdll!RtlDosPathSeperatorsString <PERF> (ntdll+0×0)
0162fa2c  0162fa64
[…]

Here we find DebugPrint call in close proximity to our critical section address and we dump its possible local data:

0:008> dc 0162fa78
0162fa78  3a4c5452 2d655220 74696157 0a676e69  RTL: Re-Waiting.
0162fa88  43203400 69746972 206c6163 74636553  .4 Critical Sect
0162fa98  206e6f69 33303030 38303630 43202d20  ion 00030608 - C
0162faa8  65746e6f 6f69746e 756f436e 3d20746e  ontentionCount =
0162fab8  0a38203d 00007000 000923a8 0162fad0  = 8..p…#….b.
0162fac8  7c82b0ae 00000000 65440000 65646f63  …|……Decode
0162fad8  6e696f50 00726574 0162fba4 00007078  Pointer…b.xp..
0162fae8  000923a8 0162faf8 7c82b0ae 00000000  .#….b….|….

Nothing still points to that critical section owner and we try to find similar self-diagnostic messages in our original thread #18. We find one DebugPrint call in close proximity to deadlock detection and exception raising calls (after similar ~18s; !teb and dds commands):

03b58de0  03b60000
03b58de4  00000000
03b58de8  03b590c8
03b58dec  7c82865c ntdll!RtlRaiseException+0x3d
03b58df0  03b58000
03b58df4  03b58df8
03b58df8  00010007
03b58dfc  00000000
03b58e00  00000000
03b58e04  00000000
03b58e08  00000000
03b58e0c  00000000
03b58e10  33303030
03b58e14  38303630
03b58e18  00000000
03b58e1c  32323100
03b58e20  0000e7c8
03b58e24  03b58e60
03b58e28  7c80b429 ntdll!_vsnprintf+0x2f
03b58e2c  03b58e40
03b58e30  7c84cf68 ntdll!RtlpNotOwnerCriticalSection+0x118
03b58e34  03b59144
03b58e38  00000000
03b58e3c  00000200
03b58e40  7c808080 ntdll!DbgSetDebugFilterState+0xc
03b58e44  00000000
03b58e48  00000000
03b58e4c  7c808080 ntdll!DbgSetDebugFilterState+0xc
03b58e50  00000001
03b58e54  03b58e70
03b58e58  7c8081d9 ntdll!DebugPrint+0×1c
03b58e5c  00000001
03b58e60  03b58efc
03b58e64  00000058
03b58e68  ffffffff
03b58e6c  00000000
03b58e70  03b59118
03b58e74  7c808194 ntdll!vDbgPrintExWithPrefixInternal+0×177
03b58e78  03b58ee4
03b58e7c  ffffffff
03b58e80  7c812f85 ntdll!vDbgPrintExWithPrefixInternal+0×1d5
03b58e84  7c880000 ntdll!_raise_exc_ex+0xc5
03b58e88  0003003b
03b58e8c  00000023
03b58e90  00030023
03b58e94  7c88a9e8 ntdll!RtlpTimeout
03b58e98  01000002 spoolsv!_imp__SetServiceStatus <PERF> (spoolsv+0×2)
03b58e9c  00000003
03b58ea0  03b590e0
03b58ea4  00030608
03b58ea8  00000000
03b58eac  03b5914c
03b58eb0  7c860491 ntdll!RtlpPossibleDeadlock+0×8d
03b58eb4  0000001b
03b58eb8  00000246
03b58ebc  03b590d4
03b58ec0  00000023
03b58ec4  00000000

0:018> dc 03b58efc
03b58efc  3a4c5452 64695020 6469542e 39393320  RTL: Pid.Tid 399
03b58f0c  66332e30 202c3832 656e776f 69742072  0.3f28, owner ti
03b58f1c  62332064 43203439 69746972 206c6163  d 3b94 Critical
03b58f2c  74636553 206e6f69 33303030 38303630  Section 00030608
03b58f3c  43202d20 65746e6f 6f69746e 756f436e   - ContentionCou
03b58f4c  3d20746e 0a38203d 00165200 0277f0b0  nt == 8..R….w.
03b58f5c  000afa08 00020007 004cbe42 ffff0000  ……..B.L…..
03b58f6c  004cbe41 00165230 00000072 0000000a  A.L.0R..r…….

Now we see the owner TID 3b94! We immediately check its stack trace:

0:018> ~~[3b94]s
eax=036a82e0 ebx=00000000 ecx=00000003 edx=00000070 esi=7c8897a0 edi=7c88a9e8
eip=7c82860c esp=036a7930 ebp=036a796c 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:
7c82860c c3              ret

0:020> kL 100
ChildEBP RetAddr 
036a792c 7c827d29 ntdll!KiFastSystemCallRet
036a7930 7c83d266 ntdll!ZwWaitForSingleObject+0xc
036a796c 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×1a3
036a798c 7c82d263 ntdll!RtlEnterCriticalSection+0xa8

036a79c0 77e63cd8 ntdll!LdrLockLoaderLock+0xe4
036a7a20 0292703f kernel32!GetModuleFileNameW+0×77
WARNING: Stack unwind information not available. Following frames may be wrong.
036a809c 02926f2c PrinterDriverA+0×1c1f
036a84e8 6dfd059a PrinterDriverA+0×1b0c

036a854c 6dfce91c COMPSTUI!CallpfnPSUI+0xdb
036a8564 6dfce5fc COMPSTUI!DeleteCPSUIPageProc+0×52
036a8580 6dfcff97 COMPSTUI!EnumCPSUIPages+0×40
036a87f0 6dfd00a2 COMPSTUI!InsertPSUIPage+0×27a
036a8848 7307c9ae COMPSTUI!CPSUICallBack+0xed
036a8870 6dfd059a WINSPOOL!DevicePropertySheets+0xd4
036a88d4 6dfcff1e COMPSTUI!CallpfnPSUI+0xdb
036a8b40 6dfd00a2 COMPSTUI!InsertPSUIPage+0×201
036a8b98 6dfd06a3 COMPSTUI!CPSUICallBack+0xed
036a8bcc 6dfd0799 COMPSTUI!DoCommonPropertySheetUI+0×74
036a8be4 730801c5 COMPSTUI!CommonPropertySheetUIW+0×17
036a8c2c 73080f5d WINSPOOL!CallCommonPropertySheetUI+0×43
036a9074 35145947 WINSPOOL!PrinterPropertiesNative+0×10c
036a90c4 3513a045 PrinterDriverA+0×159c7
036ae9ac 35131819 PrinterDriverA+0xa0c5
036aebdc 7111460e PrinterDriverA+0×1899

036aec04 7110faa3 UNIDRVUI!HComOEMPrinterEvent+0×33
036aec48 02927a79 UNIDRVUI!DrvPrinterEvent+0×27a
036aeea4 7308218c PrinterDriverA+0×20f9
036aeef0 761543c8 WINSPOOL!SpoolerPrinterEventNative+0×57
036aef0c 761560d2 localspl!SplDriverEvent+0×21
036aef30 761447f9 localspl!PrinterDriverEvent+0×46
036af3f8 76144b12 localspl!SplAddPrinter+0×5f3
036af424 74070193 localspl!LocalAddPrinterEx+0×2e
036af874 7407025c SPOOLSS!AddPrinterExW+0×151
036af890 0100792d SPOOLSS!AddPrinterW+0×17
036af8ac 01006762 spoolsv!YAddPrinter+0×75
036af8d0 77c80193 spoolsv!RpcAddPrinter+0×37
036af8f8 77ce33e1 RPCRT4!Invoke+0×30
036afcf8 77ce35c4 RPCRT4!NdrStubCall2+0×299
036afd14 77c7ff7a RPCRT4!NdrServerCall2+0×19
036afd48 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
036afd9c 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
036afdc0 77c811dc RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
036afdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×42c
036afe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
036aff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
036aff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
036affac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
036affb8 77e6482f RPCRT4!ThreadStartRoutine+0×1b
036affec 00000000 kernel32!BaseThreadStart+0×34

We see that it also has PrinterDriverA module on the stack trace and is waiting for a critical section that is owned by the thread #18 we have already seen:

0:020> kv
ChildEBP RetAddr  Args to Child             
036a792c 7c827d29 7c83d266 000001b4 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0])
036a7930 7c83d266 000001b4 00000000 7c88a9e8 ntdll!ZwWaitForSingleObject+0xc (FPO: [3,0,0])
036a796c 7c83d2b1 000001b4 00000004 00000001 ntdll!RtlpWaitOnCriticalSection+0x1a3 (FPO: [2,7,4])
036a798c 7c82d263 7c8897a0 01000000 7c8897ec ntdll!RtlEnterCriticalSection+0xa8 (FPO: [1,1,0])
036a79c0 77e63cd8 00000001 00000000 036a79fc ntdll!LdrLockLoaderLock+0xe4 (FPO: [SEH])
036a7a20 0292703f 00000000 036a7a68 00000208 kernel32!GetModuleFileNameW+0×77 (FPO: [SEH])
[…]

0:020> !cs -o 7c8897a0
—————————————–
Critical section   = 0×7c8897a0 (ntdll!LdrpLoaderLock+0×0)
DebugInfo          = 0×7c8897c0
LOCKED
LockCount          = 0xB
WaiterWoken        = No
OwningThread       = 0×00003f28
RecursionCount     = 0×2
LockSemaphore      = 0×1B4
SpinCount          = 0×00000000
OwningThread DbgId = ~18s
OwningThread Stack =
[…]

If we look again at the thread #18 we would see PrinterDriverA there too. So check its timestamp using lmv command and find out that its version is older than expected.

Note: !cs -l -o -s command is not helpful here and in fact it doesn’t list #20 thread as blocking thread so our inference about PrinterDriverA is speculative. 

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

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

Sunday, April 18th, 2010

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

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

Product information:

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

Information about individual volumes:

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

Forthcoming Memory Dump Analysis Anthology, Volume 4

Thursday, February 11th, 2010

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

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

Product information:

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

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

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

Music for Debugging: Ancient Computations and A Vision of The New Dump

Friday, January 8th, 2010

Today found a CD in my old case (the link I give is for MP3 though):

Ancient Journeys: A Vision Of The New World

Here’s my version of track titles:

1. Discovering the Interface
2. Conquering the New Space
3. Frozen System
4. MS DOS  
5. Russian OS
6. The Journeys of RIP
7. The Spiking Threads
8. Not Enough Space
9. Against Bugs

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 91)

Thursday, November 12th, 2009

Sometimes we can observe rare events when abnormal conditions that usually result in a system crash result in a milder problem, for example, a service is unavailable and not affecting other services and users. It was reported that an application was freezing during user session logoff. A complete memory dump was saved at that time and its stack trace collection (!stacks command) shows the following suspicious thread in a user process (all other threads were normally waiting):

0: kd> !stacks
Proc.Thread  .Thread  Ticks   ThreadState Blocker
[...]
                                    [89cfa960 Application.exe]
ea0.001c4c  89a11db0 0499cd1 Blocked    DriverA+0×69db
[…]

0: kd> !thread 89a11db0 16
THREAD 89a11db0  Cid 0ea0.1c4c  Teb: 7ffdf000 Win32Thread: bc347a48 WAIT: (Unknown) KernelMode Non-Alertable
    89b87770  Unknown
    b97004ac  NotificationEvent
IRP List:
    899e2668: (0006,0244) Flags: 00000884  Mdl: 00000000
Not impersonating
DeviceMap                 daf62b28
Owning Process            89cfa960       Image:         Application.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      909331         Ticks: 4824273 (0:20:56:19.265)
Context Switch Count      186                 LargeStack
UserTime                  00:00:00.015
KernelTime                00:00:00.093
*** ERROR: Module load completed but symbols could not be loaded for Application.exe
Win32 Start Address Application (0×00406b2a)
Start Address kernel32!BaseProcessStartThunk (0×77e617f8)
Stack Init b60ceb30 Current b60cdf10 Base b60cf000 Limit b60cb000 Call b60ceb34
Priority 10 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr  Args to Child             
b60cdf28 80833485 89a11db0 00000002 00000000 nt!KiSwapContext+0×26
b60cdf54 808294b9 dc399008 89b87748 b60ce01c nt!KiSwapThread+0×2e5
b60cdf88 b96d69db 00000002 b60cdfbc 00000001 nt!KeWaitForMultipleObjects+0×3d7
WARNING: Stack unwind information not available. Following frames may be wrong.
b60cdfe8 b96d719e 89b87748 dc399008 b60ce01c DriverA+0×69db
[…]

We notice “89b87770  Unknown” and double check what object the thread is waiting for:

0: kd> dp b60cdfbc L00000002
b60cdfbc  89b87770 b97004ac

These are exactly the same objects that are listed in !thread command output. We see that the second one is normal and resides in a nonpaged area:

0: kd> dt _DISPATCHER_HEADER b97004ac
ntdll!_DISPATCHER_HEADER
   +0x000 Type             : 0 ''
   +0x001 Absolute         : 0 ''
   +0x001 NpxIrql          : 0 ''
   +0x002 Size             : 0x4 ''
   +0x002 Hand             : 0x4 ''
   +0x003 Inserted         : 0 ''
   +0x003 DebugActive      : 0 ''
   +0x000 Lock             : 262144
   +0x004 SignalState      : 0
   +0x008 WaitListHead     : _LIST_ENTRY [ 0x89a11e70 - 0x89a11e70 ]

0: kd> !address b97004ac
  a71e3000 - 13e1d000                          
          Usage       KernelSpaceUsageNonPagedSystem

The other looks like an invalid Random Object from the free nonpaged pool entry (it even says about itself that it is bad) that used to belong in the past to Configuration Manager:

0: kd> !pool 89b87770
Pool page 89b87770 region is Nonpaged pool
[...]
 89b87540 size:   98 previous size:   40  (Allocated)  File (Protected)
*89b875d8 size:  260 previous size:   98  (Free)      *CMpa
  Pooltag CMpa : registry post apcs, Binary : nt!cm

 89b87838 size:   28 previous size:  260  (Allocated)  FSfm
[…]

0: kd> dd 89b87770
89b87770  bad0b0b0 00000000 00000000 00000000
89b87780  8a04be01 00000000 89b87788 89b87788
89b87790  00150006 e56c6946 8993e208 89ab96b8
89b877a0  00000000 00000000 bad0b0b0 c0000800
89b877b0  02110004 63426343 88ebbf80 00001000
89b877c0  00199000 00000000 8993e238 88d0d248
89b877d0  0019a000 00000000 00000000 00000000
89b877e0  00000000 00000000 00000000 00000000

0: kd> dt _DISPATCHER_HEADER 89b87770
ntdll!_DISPATCHER_HEADER
   +0×000 Type             : 0xb0 ”
   +0×001 Absolute         : 0xb0 ”
   +0×001 NpxIrql          : 0xb0 ”
   +0×002 Size             : 0xd0 ”
   +0×002 Hand             : 0xd0 ”
   +0×003 Inserted         : 0xba ”
   +0×003 DebugActive      : 0xba ”
   +0×000 Lock             : -1160728400
   +0×004 SignalState      : 0
   +0×008 WaitListHead     : _LIST_ENTRY [ 0×0 - 0×0 ]

Now some counterfactual thinking. One possible scenario after KeWaitForMultipleObjects was called to wait for both objects to become signalled (3rd WAIT_TYPE parameter) the free pool slot was allocated or coalesced with SignalState becoming nonzero by coincidence and other members becoming random values and then the second normal object becomes signalled when another thread sets the notification event…

- Dmitry Vostokov @ DumpAnalysis.org -

Forthcoming Memory Dump Analysis Anthology, Volume 3

Saturday, September 26th, 2009

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

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

Product information:

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

Back cover features 3D computer memory visualization image.

- Dmitry Vostokov @ DumpAnalysis.org -

Counterfactual Debugging: Data Ordering

Tuesday, September 15th, 2009

Having discussed dereference fixpoints we come back to the quiz code and see what happens when we execute it after compilation as default Debug target with Debug Information Format set to Program Database to avoid extra stack space allocation:

int _tmain(int argc, _TCHAR* argv[])
{
   char c;
   char* pc = &c;
   while(1)
   {
     *pc = 0;
     pc++;
   }

  

   return 0;
}

Expecting crashes I created the following key HKEY_LOCAL_MACHINE \ SOFTWARE \ Microsoft \ Windows \ Windows Error Reporting \ LocalDumps with the following values: DumpFolder (REG_EXPAND_SZ) and DumpType (2, Full).

When running the compiled program I noticed that it crashed according to my expectations. The saved dump StackErasure.exe.2096.dmp confirmed that the crash was due to the stack underflow when it hit the base address:

0:000> r
eax=002c0000 ebx=7efde000 ecx=00000001 edx=002c0000 esi=00000000 edi=00000000
eip=00e11039 esp=002bf7c4 ebp=002bf7d4 iopl=0         nv up ei pl nz na po nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010202
StackErasure!wmain+0x29:
00e11039 c60200          mov     byte ptr [edx],0           ds:002b:002c0000=??

0:000> !teb
TEB at 7efdd000
    ExceptionList:        002bf810
    StackBase:            002c0000
    StackLimit:           002be000
    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7efdd000
    EnvironmentPointer:   00000000
    ClientId:             00000830 . 00000a78
    RpcHandle:            00000000
    Tls Storage:          7efdd02c
    PEB Address:          7efde000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0

The loop from source code is highlighted in blue:

0:000> uf wmain
StackErasure!wmain:
00e11010 push    ebp
00e11011 mov     ebp,esp
00e11013 sub     esp,10h
00e11016 mov     eax,0CCCCCCCCh
00e1101b mov     dword ptr [ebp-10h],eax
00e1101e mov     dword ptr [ebp-0Ch],eax
00e11021 mov     dword ptr [ebp-8],eax
00e11024 mov     dword ptr [ebp-4],eax
00e11027 lea     eax,[ebp-5]
00e1102a mov     dword ptr [ebp-10h],eax

StackErasure!wmain+0x1d:
00e1102d mov     ecx,1
00e11032 test    ecx,ecx
00e11034 je      StackErasure!wmain+0x37 (00e11047)

StackErasure!wmain+0x26:
00e11036 mov     edx,dword ptr [ebp-10h]
00e11039 mov     byte ptr [edx],0
00e1103c mov     eax,dword ptr [ebp-10h]
00e1103f add     eax,1
00e11042 mov     dword ptr [ebp-10h],eax
00e11045 jmp     StackErasure!wmain+0x1d (00e1102d)

StackErasure!wmain+0x37:
00e11047 xor     eax,eax
00e11049 push    edx
00e1104a mov     ecx,ebp
00e1104c push    eax
00e1104d lea     edx,[StackErasure!wmainCRTStartup+0x10 (00e11060)]
00e11053 call    StackErasure!__tmainCRTStartup+0x50 (00e110c0)
00e11058 pop     eax
00e11059 pop     edx
00e1105a mov     esp,ebp
00e1105c pop     ebp
00e1105d ret

We see that our char variable ‘c’ is located at EBP-5 and the pointer ‘pc’ is located at EBP-10 (in another words ‘c’ follows ‘pc’ in memory):

00e11027 lea     eax,[ebp-5]
00e1102a mov     dword ptr [ebp-10h],eax

Both locations were initialized to 0xCCCCCCCC:

00e11016 mov     eax,0CCCCCCCCh
00e1101b mov     dword ptr [ebp-10h],eax
00e1101e mov     dword ptr [ebp-0Ch],eax
00e11021 mov     dword ptr [ebp-8],eax  ; this ends with EBP-5
00e11024 mov     dword ptr [ebp-4],eax

The memory layout before the start of the loop is depicted on the following diagram in the style of Windows Debugging: Practical Foundations book:

At the crash point we have the following final memory layout:

We can see it from the raw stack:

0:000> db esp
002bf7c4  00 00 2c 00 cc cc cc cc-cc cc cc 00 00 00 00 00
002bf7d4  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf7e4  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf7f4  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf804  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf814  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf824  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf834  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00

or in pointer-sized (double word) values where we can see little endian effects (compare 00 00 2c 00  with 002c0000):

0:000> dp esp
002bf7c4  002c0000 cccccccc 00cccccc 00000000
002bf7d4  00000000 00000000 00000000 00000000
002bf7e4  00000000 00000000 00000000 00000000
002bf7f4  00000000 00000000 00000000 00000000
002bf804  00000000 00000000 00000000 00000000
002bf814  00000000 00000000 00000000 00000000
002bf824  00000000 00000000 00000000 00000000
002bf834  00000000 00000000 00000000 00000000

The loop code erases stack starting from EBP-5 until it hits the base address. 

Now we change Basic Runtime Checks in Code Generation properties to Default, recompile and launch the project. Suddenly it no longer crashes but loops infinitely (shown in blue):

0:000> bp wmain

0:000> g
[...]

0:000> uf wmain
StackErasure!wmain:
00d01010 push    ebp
00d01011 mov     ebp,esp
00d01013 sub     esp,8
00d01016 lea     eax,[ebp-5]
00d01019 mov     dword ptr [ebp-4],eax

StackErasure!wmain+0xc:
00d0101c mov     ecx,1
00d01021 test    ecx,ecx
00d01023 je      StackErasure!wmain+0x26 (00d01036)

StackErasure!wmain+0x15:
00d01025 mov     edx,dword ptr [ebp-4]
00d01028 mov     byte ptr [edx],0
00d0102b mov     eax,dword ptr [ebp-4]
00d0102e add     eax,1
00d01031 mov     dword ptr [ebp-4],eax
00d01034 jmp     StackErasure!wmain+0xc (00d0101c)

StackErasure!wmain+0x26:
00d01036 xor     eax,eax
00d01038 mov     esp,ebp
00d0103a pop     ebp
00d0103b ret

At first it looks strange but if we look at the stack memory layout we would see that ‘pc’ pointer follows ‘c’ (the opposite to the memory layout discussed above):

00d01016 lea     eax,[ebp-5]
00d01019 mov     dword ptr [ebp-4],eax

0:000> dp esp
002dfb90 00d014ee 002dfb93 002dfbe4 00d01186
002dfba0 00000001 00081d70 00081df8 5a16a657
002dfbb0 00000000 00000000 7ffdb000 00000000
002dfbc0 00000000 00000000 00000000 002dfbac
002dfbd0 000001bb 002dfc28 00d06e00 5aed06eb
002dfbe0 00000000 002dfbec 00d0105f 002dfbf8
002dfbf0 77844911 7ffdb000 002dfc38 7791e4b6
002dfc00 7ffdb000 705b3701 00000000 00000000

Therefore, when the pointer at EBP-4 is incremented by 1 during the first loop iteration it becomes a dereference fixpoint:

0:000> bp 00d0101c

0:000> g
Breakpoint 1 hit
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=00081df8 esi=00000000 edi=00000000
eip=00d0101c esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000206
StackErasure!wmain+0xc:
00d0101c b901000000      mov     ecx,1

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=00081df8 esi=00000000 edi=00000000
eip=00d01021 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000206
StackErasure!wmain+0x11:
00d01021 85c9            test    ecx,ecx

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=00081df8 esi=00000000 edi=00000000
eip=00d01023 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x13:
00d01023 7411            je      StackErasure!wmain+0x26 (00d01036)      [br=0]

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=00081df8 esi=00000000 edi=00000000
eip=00d01025 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x15:
00d01025 8b55fc          mov     edx,dword ptr [ebp-4] ss:0023:002dfb94=002dfb93

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01028 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x18:
00d01028 c60200          mov     byte ptr [edx],0           ds:0023:002dfb93=00

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d0102b esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x1b:
00d0102b 8b45fc          mov     eax,dword ptr [ebp-4] ss:0023:002dfb94=002dfb93

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d0102e esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x1e:
00d0102e 83c001          add     eax,1

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01031 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x21:
00d01031 8945fc          mov     dword ptr [ebp-4],eax ss:0023:002dfb94=002dfb93

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01034 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x24:
00d01034 ebe6            jmp     StackErasure!wmain+0xc (00d0101c)

0:000> dp ebp-4 l1
002dfb94  002dfb94

During the second iteration the assignment of zero to ‘*pc’ clears the first byte of ‘pc’:

0:000> t
Breakpoint 1 hit
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d0101c esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0xc:
00d0101c b901000000      mov     ecx,1

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01021 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x11:
00d01021 85c9            test    ecx,ecx

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01023 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x13:
00d01023 7411            je      StackErasure!wmain+0x26 (00d01036)      [br=0]

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01025 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x15:
00d01025 8b55fc          mov     edx,dword ptr [ebp-4] ss:0023:002dfb94=002dfb94

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb94 esi=00000000 edi=00000000
eip=00d01028 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x18:
00d01028 c60200          mov     byte ptr [edx],0           ds:0023:002dfb94=94

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb94 esi=00000000 edi=00000000
eip=00d0102b esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x1b:
00d0102b 8b45fc          mov     eax,dword ptr [ebp-4] ss:0023:002dfb94=002dfb00

0:000> dp esp
002dfb90  00d014ee 002dfb00 002dfbe4 00d01186
002dfba0  00000001 00081d70 00081df8 5a16a657
002dfbb0  00000000 00000000 7ffdb000 00000000
002dfbc0  00000000 00000000 00000000 002dfbac
002dfbd0  000001bb 002dfc28 00d06e00 5aed06eb
002dfbe0  00000000 002dfbec 00d0105f 002dfbf8
002dfbf0  77844911 7ffdb000 002dfc38 7791e4b6
002dfc00  7ffdb000 705b3701 00000000 00000000

The new ‘pc’ pointer points to the following region of the stack:

0:000> dp 002dfb00 l100/4
002dfb00  002dfb0c 00000004 00000000 5c008ede
002dfb10  002dfb28 00d0634a 0008128c 5aed018b
002dfb20  000807f8 7790fb66 00000000 7ffdb000
002dfb30  00000000 002dfb40 00d089a6 00d68ab8
002dfb40  002dfb4c 00d019bc 00000008 002dfb84
002dfb50  00d07520 00d07519 5a16a637 00000000
002dfb60  00000000 7ffdb000 00d02b10 00000004
002dfb70  00000002 002dfbd4 00d06e00 5aed007b
002dfb80  fffffffe 002dfb90 00d0769e 002dfba0
002dfb90  00d014ee 002dfb00 002dfbe4 00d01186
002dfba0  00000001 00081d70 00081df8 5a16a657
002dfbb0  00000000 00000000 7ffdb000 00000000
002dfbc0  00000000 00000000 00000000 002dfbac
002dfbd0  000001bb 002dfc28 00d06e00 5aed06eb
002dfbe0  00000000 002dfbec 00d0105f 002dfbf8
002dfbf0  77844911 7ffdb000 002dfc38 7791e4b6

The loop code now starts clearing this region until the pointer becomes the fixpoint again after successive increments and therefore continues to loop indefinitely:

0:000> bc 0 1

0:000> g
(1238.c9c): Break instruction exception - code 80000003 (first chance)
eax=7ffde000 ebx=00000000 ecx=00000000 edx=7796d094 esi=00000000 edi=00000000
eip=77927dfe esp=00a4ff30 ebp=00a4ff5c 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!DbgBreakPoint:
77927dfe cc              int     3

0:001> dp 002dfb00 l100/4
002dfb00  0000000c 00000000 00000000 00000000
002dfb10  00000000 00000000 00000000 00000000
002dfb20  00000000 00000000 00000000 00000000
002dfb30  00000000 00000000 00000000 00000000
002dfb40  00000000 00000000 00000000 00000000
002dfb50  00000000 00000000 00000000 00000000
002dfb60  00000000 00000000 00000000 00000000
002dfb70  00000000 00000000 00000000 00000000
002dfb80  00000000 00000000 00000000 00000000
002dfb90  00000000
002dfb1f 002dfbe4 00d01186
002dfba0  00000001 00081d70 00081df8 5a16a657
002dfbb0  00000000 00000000 7ffdb000 00000000
002dfbc0  00000000 00000000 00000000 002dfbac
002dfbd0  000001bb 002dfc28 00d06e00 5aed06eb
002dfbe0  00000000 002dfbec 00d0105f 002dfbf8
002dfbf0  77844911 7ffdb000 002dfc38 7791e4b6

StackErasure that loops indefinitely is available for download

- Dmitry Vostokov @ DumpAnalysis.org -

Counterfactual Debugging: Dereference Fixpoints

Friday, September 11th, 2009

Imagine we have the following arrangements in memory:

address: value

where value == address, so we have effectively:

address: address

So when we dereference the address we get the address value. If we name the dereference function as p(address) we get

p(address) = address

That gave me an idea to name after the mathematical notion of a function fixpoint (fixed point).

In C++ we can write the following code to initialize a fixpoint:

void *pc = &pc;

in assembly language:

lea      eax, [pc]
mov      dword ptr [pc], eax

or using local variables:

lea      eax, [ebp-4]
mov      dword ptr [ebp-4], eax

Dereference of a fixpoint pointer gives us the same value as its address, for example, using old style conversion:

int *pc = (int *)&pc;

if (pc == (int *)*pc) {
 // TRUE

or for C++ purists:

int *pc = reinterpret_cast<int *>(&pc);

if (pc == reinterpret_cast<int *>(*pc)) {
 // TRUE

In x86 assembly language we have this comparison:

mov         eax,dword ptr [pc]
mov         ecx,dword ptr [pc]
cmp         ecx,dword ptr [eax]

or using local variables:

mov         eax,dword ptr [ebp-4]
mov         ecx,dword ptr [ebp-4]
cmp         ecx,dword ptr [eax]

Now, having discussed fixpoints, let me ask the question to ponder over this weekend. What would this code do?

int _tmain(int argc, _TCHAR* argv[])
{
   char c;
   char* pc = &c;

   while(1)
   {
     *pc = 0;
     pc++;
   }
 

   return 0;
}

Would it produce stack overflow with an exception, or stack underflow with an exception or loop indefinitely? The C++ Standard answer of compiler and platform dependence is not acceptable. I plan to elaborate on this topic on Monday.

The notion of counterfactual debugging (”what if” debugging) was inspired by the so called counterfactual history.

- Dmitry Vostokov @ DumpAnalysis.org -