Software Diagnostics Library

Born out of 2008 April Fool’s joke (although I was thinking about it long before) the idea is to have a general framework and associated IDE for analysis activities for various tools that produce logs. Similar to planned GUI Monitor integrating WindowHistory, MesageHistory and ScreenHistory tools but also including Debugger Log Analyzer, Debugging Notebooks, various memory and trace log visualization subsystems. It also has the working title UTF (Unified Tools Framework).

Seems I’m very easy on inceptions All this will be covered in great detail in the forthcoming book which I tirelessly advertise:

DebugWare: The Art and Craft of Writing Troubleshooting Tools

- Dmitry Vostokov @ DumpAnalysis.org -

This is an attempt to revive the forum closed a year ago due to the lack of interest during that time. Now the number of visitors has increased by an order of magnitude and I get more and more requests to help with crash dump analysis but I cannot guarantee immediate response. Therefore I upgraded and reopened Crash Dump Analysis and Debugging Forum and encourage using it. In order to prevent spammers gaining access any new registration has to be approved by me (usually in less than 24 hours).

- Dmitry Vostokov @ DumpAnalysis.org -

The case when a function pointer or a return address becomes a Wild Pointer and EIP or RIP value lies in a valid region of memory the execution path may continue through a region called Wild Code. This might loop on itself or eventually reach non-executable or invalid pages and produce an exception. Local Buffer Overflow might lead to this behavior and also data corruption that overwrites function pointers with valid memory addresses.

My favorite example is when a function pointer points to zeroed pages with EXECUTE page attribute. What will happen next when we dereference it? All zeroes are perfect x86/x64 code:

0:001> dd 0000000`771afdf0
00000000`771afdf0  00000000 00000000 00000000 00000000
00000000`771afe00  00000000 00000000 00000000 00000000
00000000`771afe10  00000000 00000000 00000000 00000000
00000000`771afe20  00000000 00000000 00000000 00000000
00000000`771afe30  00000000 00000000 00000000 00000000
00000000`771afe40  00000000 00000000 00000000 00000000
00000000`771afe50  00000000 00000000 00000000 00000000
00000000`771afe60  00000000 00000000 00000000 00000000

0:001> u
ntdll!DbgUserBreakPoint:
00000000`771afe00 0000    add     byte ptr [rax],al
00000000`771afe02 0000    add     byte ptr [rax],al
00000000`771afe04 0000    add     byte ptr [rax],al
00000000`771afe06 0000    add     byte ptr [rax],al
00000000`771afe08 0000    add     byte ptr [rax],al
00000000`771afe0a 0000    add     byte ptr [rax],al
00000000`771afe0c 0000    add     byte ptr [rax],al
00000000`771afe0e 0000    add     byte ptr [rax],al

Now if RAX points to a valid memory page with WRITE attribute the code will modify the first byte at that address:

0:001> dq @rax
000007ff`fffdc000 00000000`00000000 00000000`035a0000
000007ff`fffdc010 00000000`0359c000 00000000`00000000
000007ff`fffdc020 00000000`00001e00 00000000`00000000
000007ff`fffdc030 000007ff`fffdc000 00000000`00000000
000007ff`fffdc040 00000000`0000142c 00000000`00001504
000007ff`fffdc050 00000000`00000000 00000000`00000000
000007ff`fffdc060 000007ff`fffd8000 00000000`00000000
000007ff`fffdc070 00000000`00000000 00000000`00000000

Therefore the code will be perfectly executed:

0:001> t
ntdll!DbgBreakPoint+0x2:
00000000`771afdf2 0000    add     byte ptr [rax],al ds:000007ff`fffdc000=00

0:001> t
ntdll!DbgBreakPoint+0x4:
00000000`771afdf4 0000    add     byte ptr [rax],al ds:000007ff`fffdc000=00

0:001> t
ntdll!DbgBreakPoint+0x6:
00000000`771afdf6 0000    add     byte ptr [rax],al ds:000007ff`fffdc000=00

0:001> t
ntdll!DbgBreakPoint+0x8:
00000000`771afdf8 0000    add     byte ptr [rax],al ds:000007ff`fffdc000=00

0:001> t
ntdll!DbgBreakPoint+0xa:
00000000`771afdfa 0000    add     byte ptr [rax],al ds:000007ff`fffdc000=00

- Dmitry Vostokov @ DumpAnalysis.org -

Symbolless Analysis is another anti-pattern when an engineer either in a hurry or due to laziness doesn’t apply proper symbols and relies only on timestamps and module/offsets or trusts what WinDbg says and ignores symbol warnings. I usually apply symbols even in obvious cases and in hard ones strive to apply them until all possibilities are exhausted including search using PDBFinder.

Another weak variant is called Imageless Analysis when an engineer doesn’t specify proper Executable Image Search Path when it is necessary perhaps due to ignorance or just plain laziness again. Please see Minidump Analysis example for proper minidump analysis.

- Dmitry Vostokov @ DumpAnalysis.org -

Although the first volume has not been published yet (scheduled for 15th of April, 2008) the planning for the second volume has already begun. Preliminary information is:

• Title: Memory Dump Analysis Anthology, Volume 2
• Paperback: 512 pages (*)
• ISBN-13: 978-0-9558328-7-1
• Author: Dmitry Vostokov
• Publisher: Opentask (01 Oct 2008)
• Language: English
• Product Dimensions: 22.86 x 15.24

Hardcover version is also planned. PDF version will be available for download too.

(*) subject to change

- Dmitry Vostokov @ DumpAnalysis.org -

I’m coming back to my old Insufficient Memory pattern range (see Committed Memory, Handle Leak, Kernel Pool, PTE). This post discusses the user space case when we don’t have enough virtual memory available for reservation due to memory fragmentation. For example, a java virtual machine is pre-allocating memory for its garbage-collected heap. However after installing some 3rd-party software the amount of pre-allocated memory is less than expected. In such cases it is possible to do comparative memory dump analysis to see the difference in virtual address spaces. Original memory dump has this module distribution in memory:

0:000> lm
start    end        module name
00400000 0040b000   javaw      (deferred)            
009e0000 009e7000   hpi        (deferred)            
00a30000 00a3e000   verify     (deferred)            
00a40000 00a59000   java       (deferred)            
00a60000 00a6d000   zip        (deferred)            
03ff0000 03fff000   net        (deferred)            
040a0000 040a8000   nio        (deferred)            
040b0000 0410a000   hnetcfg    (deferred)            
041d0000 042e2000   awt        (deferred)            
04540000 04591000   fontmanager   (deferred)            
04620000 04670000   msctf      (deferred)            
047c0000 047de000   jpeg       (deferred)            
05820000 05842000   dcpr       (deferred)            
05920000 05932000   pkcs11wrapper   (deferred)            
08000000 08139000   jvm        (deferred)            
10000000 100e0000   moduleA    (deferred)            
68000000 68035000   rsaenh     (deferred)
6e220000 6e226000   RMProcessLink   (deferred)            
71ae0000 71ae8000   wshtcpip   (deferred)            
71b20000 71b61000   mswsock    (deferred)            
71bf0000 71bf8000   ws2help    (deferred)            
71c00000 71c17000   ws2_32     (deferred)            
71c20000 71c32000   tsappcmp   (deferred)            
71c40000 71c97000   netapi32   (deferred)            
73070000 73097000   winspool   (deferred)            
76290000 762ad000   imm32      (deferred)            
76920000 769e2000   userenv    (deferred)            
76aa0000 76acd000   winmm      (deferred)            
76b70000 76b7b000   psapi      (deferred)            
76ed0000 76efa000   dnsapi     (deferred)            
76f10000 76f3e000   wldap32    (deferred)            
76f50000 76f63000   secur32    (deferred)            
76f70000 76f77000   winrnr     (deferred)            
76f80000 76f85000   rasadhlp   (deferred)            
77380000 77411000   user32     (deferred)            
77670000 777a9000   ole32      (deferred)            
77ba0000 77bfa000   msvcrt     (deferred)            
77c00000 77c48000   gdi32      (deferred)            
77c50000 77cef000   rpcrt4     (deferred)            
77e40000 77f42000   kernel32   (deferred)            
77f50000 77feb000   advapi32   (deferred)            
78130000 781cb000   msvcr80    (deferred)            
7c800000 7c8c0000   ntdll      (pdb symbols)

We see the big gap between 100e0000 and 68000000 addresses. This means that it is theoretically possible to reserve and/or commit up to 57F20000 bytes (about 1.4Gb). !address WinDbg command shows that at least 1.1Gb region (shown in bold below) was reserved indeed:

0:000> !address
00000000 : 00000000 - 00010000
              Type     00000000
              Protect  00000001 PAGE_NOACCESS
              State    00010000 MEM_FREE
              Usage    RegionUsageFree
00010000 : 00010000 - 00001000
              Type     00020000 MEM_PRIVATE
              Protect  00000004 PAGE_READWRITE
              State    00001000 MEM_COMMIT
              Usage    RegionUsageEnvironmentBlock
00011000 : 00011000 - 0000f000
              Type     00000000
              Protect  00000001 PAGE_NOACCESS
              State    00010000 MEM_FREE
              Usage    RegionUsageFree
00020000 : 00020000 - 00001000
              Type     00020000 MEM_PRIVATE
              Protect  00000004 PAGE_READWRITE
              State    00001000 MEM_COMMIT
              Usage    RegionUsageProcessParametrs
00021000 : 00021000 - 0000f000
              Type     00000000
              Protect  00000001 PAGE_NOACCESS
              State    00010000 MEM_FREE
              Usage    RegionUsageFree
00030000 : 00030000 - 00003000
              Type     00020000 MEM_PRIVATE
              Protect  00000140 <unk>
              State    00001000 MEM_COMMIT
              Usage    RegionUsageStack
              Pid.Tid  97c.1b3c
...
...
...
100e0000 : 100e0000 - 000a0000
              Type     00020000 MEM_PRIVATE
              Protect  00000040 PAGE_EXECUTE_READWRITE
              State    00001000 MEM_COMMIT
              Usage    RegionUsageIsVAD
         10180000 - 05cc0000
              Type     00020000 MEM_PRIVATE
              State    00002000 MEM_RESERVE
              Usage    RegionUsageIsVAD
         15e40000 - 004f3000
              Type     00020000 MEM_PRIVATE
              Protect  00000040 PAGE_EXECUTE_READWRITE
              State    00001000 MEM_COMMIT
              Usage    RegionUsageIsVAD
         16333000 - 45bad000
              Type     00020000 MEM_PRIVATE
              State    00002000 MEM_RESERVE
              Usage    RegionUsageIsVAD
         5bee0000 - 00ac0000
              Type     00020000 MEM_PRIVATE
              Protect  00000040 PAGE_EXECUTE_READWRITE
              State    00001000 MEM_COMMIT
              Usage    RegionUsageIsVAD
         5c9a0000 - 03540000
              Type     00020000 MEM_PRIVATE
              State    00002000 MEM_RESERVE
              Usage    RegionUsageIsVAD
5fee0000 : 5fee0000 - 00120000
              Type     00000000
              Protect  00000001 PAGE_NOACCESS
              State    00010000 MEM_FREE
              Usage    RegionUsageFree
…
…
…

Looking at the problem memory dump we see that the gap is smaller (less than 1.1Gb):

0:000> lm
start    end        module name
00400000 0040b000   javaw      (deferred)            
08000000 08139000   jvm        (deferred)            
10000000 10007000   hpi        (deferred)            
51120000 511bb000   msvcr80  # (private pdb symbols)
520f0000 520fe000   verify     (deferred)            
52100000 52119000   java       (deferred)            
52120000 5212d000   zip        (deferred)            
52130000 5213f000   net        (deferred)            
52140000 52148000   nio        (deferred)            
52150000 52262000   awt        (deferred)            
52270000 522c1000   fontmanager   (deferred)            
522d0000 52320000   MSCTF      (deferred)            
52330000 5234e000   jpeg       (deferred)            
52350000 52372000   dcpr       (deferred)            
52510000 52522000   pkcs11wrapper   (deferred)            
5f270000 5f2ca000   hnetcfg    (deferred)            
60000000 60029000   3rdPartyHook   (deferred)            
61e80000 61e86000   detoured   (export symbols)
68000000 68035000   rsaenh     (deferred)            
71ae0000 71ae8000   wshtcpip   (deferred)            
71b20000 71b61000   mswsock    (deferred)            
71bf0000 71bf8000   ws2help    (deferred)            
71c00000 71c17000   ws2_32     (deferred)            
71c20000 71c32000   tsappcmp   (deferred)            
71c40000 71c97000   netapi32   (deferred)            
73070000 73097000   winspool   (deferred)            
76290000 762ad000   imm32      (deferred)            
76920000 769e2000   userenv    (deferred)            
76aa0000 76acd000   winmm      (deferred)            
76b70000 76b7b000   psapi      (deferred)            
76ed0000 76efa000   dnsapi     (deferred)            
76f10000 76f3e000   wldap32    (deferred)            
76f50000 76f63000   secur32    (deferred)            
76f70000 76f77000   winrnr     (deferred)            
76f80000 76f85000   rasadhlp   (deferred)            
77380000 77411000   user32     (pdb symbols)         
77670000 777a9000   ole32      (deferred)            
77ba0000 77bfa000   msvcrt     (deferred)            
77c00000 77c48000   gdi32      (deferred)            
77c50000 77cef000   rpcrt4     (deferred)            
77e40000 77f42000   kernel32   (pdb symbols)         
77f50000 77feb000   advapi32   (pdb symbols)         
7c340000 7c396000   msvcr71    (deferred)            
7c800000 7c8c0000   ntdll      (pdb symbols)

!address command shows that less memory was reserved in the latter case (about 896Mb):

0:000> !address
...
...
...
10010000 : 10010000 - 000a0000
             Type     00020000 MEM_PRIVATE
              Protect  00000040 PAGE_EXECUTE_READWRITE
              State    00001000 MEM_COMMIT
              Usage    RegionUsageIsVAD
         100b0000 - 04a70000
              Type     00020000 MEM_PRIVATE
              State    00002000 MEM_RESERVE
              Usage    RegionUsageIsVAD
         14b20000 - 004a6000
              Type     00020000 MEM_PRIVATE
              Protect  00000040 PAGE_EXECUTE_READWRITE
              State    00001000 MEM_COMMIT
              Usage    RegionUsageIsVAD
         14fc6000 - 3804a000
             Type     00020000 MEM_PRIVATE
              State    00002000 MEM_RESERVE
              Usage    RegionUsageIsVAD
          4d010000 - 00ac0000
              Type     00020000 MEM_PRIVATE
              Protect  00000040 PAGE_EXECUTE_READWRITE
              State    00001000 MEM_COMMIT
              Usage    RegionUsageIsVAD
          4dad0000 - 03540000
              Type     00020000 MEM_PRIVATE
              State    00002000 MEM_RESERVE
              Usage    RegionUsageIsVAD
51010000 : 51010000 - 00110000
              Type     00000000
              Protect  00000001 PAGE_NOACCESS
              State    00010000 MEM_FREE
              Usage    RegionUsageFree
…
…
…

Looking at module list again we notice that most java runtime modules were shifted to 50000000 address range. We also notice that new 3rdPartyHook and detoured modules appear in our problem memory dump. 

Module information is missing for detoured module:

0:000> lmv m detoured
start    end        module name
61e80000 61e86000   detoured   (deferred)            
    Image path: C:\WINDOWS\system32\detoured.dll
    Image name: detoured.dll
    Timestamp:        Thu Feb 07 04:14:16 2008 (47AA8598)
    CheckSum:         0000EF91
    ImageSize:        00006000
    File version:     0.0.0.0
    Product version:  0.0.0.0
    File flags:       0 (Mask 0)
    File OS:          0 Unknown Base
    File type:        0.0 Unknown
    File date:        00000000.00000000
    Translations:     0000.04b0 0000.04e0 0409.04b0 0409.04e0

However applying Unknown Component pattern we see that is Microsoft Research Detours Package:

0:000> db 61e80000 61e86000
61e80000  MZ..............
61e80010  ........@.......
61e80020  ................
61e80030  ................
61e80040  ........!..L.!Th
61e80050  is program canno
61e80060  t be run in DOS
61e80070  mode....$.......
61e80080  5...q...q...q...
61e80090  ....r...q...p...
61e800a0  V%..p...V%..p...
61e800b0  V%..p...V%..p...
61e800c0  Richq...........
61e800d0  ................
61e800e0  PE..L......G....
61e800f0  .......!........
61e80100  ................
...
...
...
...
61e84390  ..P.r.o.d.u.c.t.
61e843a0  N.a.m.e…..M.i.
61e843b0  c.r.o.s.o.f.t. .
61e843c0  R.e.s.e.a.r.c.h.
61e843d0  .D.e.t.o.u.r.s.
61e843e0  .P.a.c.k.a.g.e.
61e843f0  ….j.#…P.r.o.
61e84400  d.u.c.t.V.e.r.s.
61e84410  i.o.n…P.r.o.f.
61e84420  e.s.s.i.o.n.a.l.
61e84430  .V.e.r.s.i.o.n.
61e84440  .2…1. .B.u.i.
61e84450  l.d._.2.1.0…..
61e84460  D…..V.a.r.F.i.
…
…
…

0:000> du 61e843a0+C
61e843ac  "Microsoft Research Detours Packa"
61e843ec  "ge"

We can also see that 3rdPartyHook module imports this library and lots of kernel32 API related to memory allocation, file mapping and loading DLLs (see No Component Symbols pattern):

0:000> !dh 60000000
...
...
...
OPTIONAL HEADER VALUES
     10B magic #
    8.00 linker version
   18000 size of code
    F000 size of initialized data
       0 size of uninitialized data
   13336 address of entry point
    1000 base of code
         ----- new -----
60000000 image base
    1000 section alignment
    1000 file alignment
       2 subsystem (Windows GUI)
    4.00 operating system version
    0.00 image version
    4.00 subsystem version
   29000 size of image
    1000 size of headers
   3376F checksum
00100000 size of stack reserve
00001000 size of stack commit
00100000 size of heap reserve
00001000 size of heap commit
       0 [       0] address [size] of Export Directory
   218CC [      8C] address [size] of Import Directory
   25000 [     5F4] address [size] of Resource Directory
       0 [       0] address [size] of Exception Directory
   28000 [    19E0] address [size] of Security Directory
   26000 [    2670] address [size] of Base Relocation Directory
   19320 [      1C] address [size] of Debug Directory
       0 [       0] address [size] of Description Directory
       0 [       0] address [size] of Special Directory
       0 [       0] address [size] of Thread Storage Directory
   1F3C0 [      40] address [size] of Load Configuration Directory
       0 [       0] address [size] of Bound Import Directory
   19000 [     2B0] address [size] of Import Address Table Directory
       0 [       0] address [size] of Delay Import Directory
       0 [       0] address [size] of COR20 Header Directory
       0 [       0] address [size] of Reserved Directory
…
…
…

0:000> dds 60000000+19000 60000000+19000+2B0
60019064  7c82b0dc ntdll!RtlReAllocateHeap
60019068  77e4ec39 kernel32!HeapDestroy
6001906c  77e41fba kernel32!GetSystemTimeAsFileTime
60019070  77e619d1 kernel32!GetTickCount
60019074  77e69577 kernel32!QueryPerformanceCounter
60019078  7c82a9be ntdll!RtlSizeHeap
6001907c  77e82060 kernel32!SetUnhandledExceptionFilter
60019080  77e7690d kernel32!UnhandledExceptionFilter
60019084  77e42004 kernel32!TerminateProcess
60019088  7c82a136 ntdll!RtlRestoreLastWin32Error
6001908c  77e77a5f kernel32!SuspendThread
60019090  77e76a26 kernel32!SetThreadContext
60019094  77e77ae3 kernel32!GetThreadContext
60019098  77e73347 kernel32!FlushInstructionCache
6001909c  77e5f38b kernel32!ResumeThread
600190a0  77e616a8 kernel32!InterlockedCompareExchange
600190a4  77e645a9 kernel32!VirtualAlloc
600190a8  77e41fe3 kernel32!VirtualProtect
600190ac  77e66ed1 kernel32!VirtualQuery
600190b0  77e44960 kernel32!GetLogicalDriveStringsA
600190b4  77eab401 kernel32!GetVolumeNameForVolumeMountPointA
600190b8  77e6794d kernel32!GetACP
600190bc  77e6f3cf kernel32!GetLocaleInfoA
600190c0  77e622b7 kernel32!GetThreadLocale
600190c4  77e69d74 kernel32!GetVersionExA
600190c8  77e4beab kernel32!RaiseException
600190cc  77e60037 kernel32!GetSystemDirectoryA
600190d0  77e52bf4 kernel32!GetWindowsDirectoryA
600190d4  77e5c7a8 kernel32!lstrcmpA
600190d8  77e46c99 kernel32!OutputDebugStringA
600190dc  77e5bd7d kernel32!CreateEventA
600190e0  77e62311 kernel32!SetEvent
600190e4  77e51281 kernel32!ExpandEnvironmentStringsA
600190e8  77e9f365 kernel32!MoveFileA
600190ec  77e5da00 kernel32!IsDebuggerPresent
600190f0  77e9e4b1 kernel32!QueryDosDeviceA
600190f4  7c829e08 ntdll!RtlGetLastWin32Error
600190f8  77e63d7a kernel32!GetProcAddress
600190fc  77e41dc6 kernel32!LoadLibraryA
60019100  7c829e17 ntdll!RtlFreeHeap
60019104  77e62419 kernel32!LocalFree
60019108  7c829fd6 ntdll!RtlAllocateHeap
6001910c  77e63ec7 kernel32!GetProcessHeap
60019110  77ea2186 kernel32!VerifyVersionInfoA
60019114  7c81379f ntdll!VerSetConditionMask
60019118  77e63143 kernel32!WideCharToMultiByte
6001911c  77e70550 kernel32!SizeofResource
60019120  77e6b11b kernel32!SetHandleCount
60019124  77e69bf9 kernel32!LoadResource
60019128  77e511e1 kernel32!FindResourceA
6001912c  77e7388c kernel32!FindResourceExA
60019130  77e5be30 kernel32!lstrlenA
60019134  77e424de kernel32!Sleep
60019138  77ea2cb1 kernel32!WaitNamedPipeA
6001913c  77e63e6f kernel32!CloseHandle
60019140  77e5e123 kernel32!OpenEventA
60019144  77e622c9 kernel32!lstrlenW
60019148  77e62fc7 kernel32!GetCurrentThreadId
6001914c  77e5fdd4 kernel32!OpenProcess
60019150  77e63c78 kernel32!GetCurrentProcessId
60019154  7c81a3ab ntdll!RtlLeaveCriticalSection
60019158  7c81a360 ntdll!RtlEnterCriticalSection
6001915c  77e4cabf kernel32!GetComputerNameA
60019160  77e6f032 kernel32!ProcessIdToSessionId
60019164  77e645ff kernel32!GetModuleFileNameA
60019168  77e6474a kernel32!GetModuleHandleA
6001916c  77e62f9d kernel32!GetCurrentProcess
60019170  77e49968 kernel32!GetCurrentDirectoryA
60019174  77e61c7b kernel32!WaitForSingleObject
60019178  77e63868 kernel32!GetCurrentThread
6001917c  7c82c988 ntdll!RtlDeleteCriticalSection
60019180  77e67861 kernel32!InitializeCriticalSection
60019184  77e6b1a1 kernel32!FreeLibrary
60019188  77e63f41 kernel32!UnmapViewOfFile
6001918c  77e643f1 kernel32!MapViewOfFile
60019190  77e6b65f kernel32!OpenFileMappingA
60019194  77e61694 kernel32!InterlockedExchange
60019198  77e4d2fb kernel32!DeleteFileA
...
...
...
60019294  00000000
60019298  61e81000 detoured!Detoured
6001929c  00000000
…
…
…

This warrants the suspicion that 3rdPartyHook somehow optimized the virtual address space for its own purposes and this resulted in more fragmented virtual address space.

- Dmitry Vostokov @ DumpAnalysis.org -

Here is an additional kernel space example to my old Dynamic Memory Corruption pattern. If kernel pools are corrupt then calls that allocate or free memory result in bugchecks C2 or 19 and in other less frequent bugchecks (from Google stats):

Bug Checks 0xC2 and 0×19 have parameters in bugcheck arguments that tell the type of detected pool corruption. Refer to WinDbg help for details or use the variant of !analyze command where you can supply optional bugcheck arguments:

1: kd> !analyze -show c2
BAD_POOL_CALLER (c2)
The current thread is making a bad pool request.  Typically this is at a bad IRQL level or double freeing the same allocation, etc.
Arguments:
Arg1: 00000000, The caller is requesting a zero byte pool allocation.
Arg2: 00000000, zero.
Arg3: 00000000, the pool type being allocated.
Arg4: 00000000, the pool tag being used.

1: kd> !analyze -show 19 2 1 1 1
BAD_POOL_HEADER (19)
The pool is already corrupt at the time of the current request.
This may or may not be due to the caller.
The internal pool links must be walked to figure out a possible cause of
the problem, and then special pool applied to the suspect tags or the driver
verifier to a suspect driver.
Arguments:
Arg1: 00000002, the verifier pool pattern check failed.  The owner has likely corrupted the pool block
Arg2: 00000001, the pool entry being checked.
Arg3: 00000001, size of the block.
Arg4: 00000001, 0.

If we enable special pool on suspected drivers we might get these bugchecks too with the following Google frequency:

Here is one example of nonpaged pool corruption detected during free operation with the following !analyze -v output:

BAD_POOL_HEADER (19)
The pool is already corrupt at the time of the current request.
This may or may not be due to the caller.
The internal pool links must be walked to figure out a possible cause of
the problem, and then special pool applied to the suspect tags or the driver
verifier to a suspect driver.
Arguments:
Arg1: 00000020, a pool block header size is corrupt.
Arg2: a34583b8, The pool entry we were looking for within the page.
Arg3: a34584f0, The next pool entry.
Arg4: 0a270001, (reserved)

POOL_ADDRESS:  a34583b8 Nonpaged pool

PROCESS_NAME:  process.exe

CURRENT_IRQL:  2

STACK_TEXT: 
b80a60cc 808927bb nt!KeBugCheckEx+0x1b
b80a6134 80892b6f nt!ExFreePoolWithTag+0x477
b80a6144 b9591400 nt!ExFreePool+0xf
WARNING: Stack unwind information not available. Following frames may be wrong.
b80a615c b957b954 driver+0x38400
b80a617c b957d482 driver+0x22954
b80a61c0 b957abf4 driver+0x24482
b80a6260 b957ccef driver+0x21bf4
b80a62a8 8081df65 driver+0x23cef
b80a62bc f721ac45 nt!IofCallDriver+0x45
b80a62e4 8081df65 fltMgr!FltpDispatch+0x6f
b80a62f8 b99de70b nt!IofCallDriver+0x45
b80a6308 b99da6ee filter!Dispatch+0xfb
b80a6318 8081df65 filter!dispatch+0x6e
b80a632c b9bdebfe nt!IofCallDriver+0x45
b80a6334 8081df65 2ndfilter!Redirect+0x7ea
b80a6348 b9bd1756 nt!IofCallDriver+0x45
b80a6374 b9bd1860 3rdfilter!PassThrough+0x136
b80a6384 8081df65 3rdfilter!Dispatch+0x80
b80a6398 808f5437 nt!IofCallDriver+0x45
b80a63ac 808ef963 nt!IopSynchronousServiceTail+0x10b
b80a63d0 8088978c nt!NtQueryDirectoryFile+0x5d
b80a63d0 7c8285ec nt!KiFastCallEntry+0xfc
00139524 7c8274eb ntdll!KiFastSystemCallRet
00139528 77e6ba40 ntdll!NtQueryDirectoryFile+0xc
00139830 77e6bb5f kernel32!FindFirstFileExW+0x3d5
00139850 6002665e kernel32!FindFirstFileW+0x16
00139e74 60026363 process+0x2665e
0013a328 60027852 process+0x26363
0013a33c 60035b58 process+0x27852
0013b104 600385ff process+0x35b58
0013b224 612cb643 process+0x385ff
0013b988 612cc109 dll!FileDialog+0xc53
0013bba0 612cb47b dll!FileDialog+0x1719
0013c2c0 7739b6e3 dll!FileDialog+0xa8b
0013c2ec 77395f82 USER32!InternalCallWinProc+0x28
0013c368 77395e22 USER32!UserCallDlgProcCheckWow+0x147
0013c3b0 7739c9c6 USER32!DefDlgProcWorker+0xa8
0013c3d8 7c828536 USER32!__fnDWORD+0x24
0013c3d8 808308f4 ntdll!KiUserCallbackDispatcher+0x2e
b80a66b8 8091d6d1 nt!KiCallUserMode+0x4
b80a6710 bf8a2622 nt!KeUserModeCallback+0x8f
b80a6794 bf8a2517 win32k!SfnDWORD+0xb4
b80a67dc bf8a13d9 win32k!xxxSendMessageToClient+0x133
b80a6828 bf85ae67 win32k!xxxSendMessageTimeout+0x1a6
b80a684c bf8847a1 win32k!xxxWrapSendMessage+0x1b
b80a6868 bf8c1459 win32k!NtUserfnNCDESTROY+0x27
b80a68a0 8088978c win32k!NtUserMessageCall+0xc0
b80a68a0 7c8285ec nt!KiFastCallEntry+0xfc
0013c3d8 7c828536 ntdll!KiFastSystemCallRet
0013c3d8 808308f4 ntdll!KiUserCallbackDispatcher+0x2e
b80a6b7c 8091d6d1 nt!KiCallUserMode+0x4
b80a6bd4 bf8a2622 nt!KeUserModeCallback+0x8f
b80a6c58 bf8a23a0 win32k!SfnDWORD+0xb4
b80a6ca0 bf8a13d9 win32k!xxxSendMessageToClient+0x118
b80a6cec bf85ae67 win32k!xxxSendMessageTimeout+0x1a6
b80a6d10 bf8c148c win32k!xxxWrapSendMessage+0x1b
b80a6d40 8088978c win32k!NtUserMessageCall+0x9d
b80a6d40 7c8285ec nt!KiFastCallEntry+0xfc
0013f474 7c828536 ntdll!KiFastSystemCallRet
0013f4a0 7739d1ec ntdll!KiUserCallbackDispatcher+0x2e
0013f4dc 7738cf29 USER32!NtUserMessageCall+0xc
0013f4fc 612d3276 USER32!SendMessageA+0x7f
0013f63c 611add41 dll!SubWindow+0x3dc6
0013f658 7739b6e3 dll!SetWindowText+0x37a1
0013f684 7739b874 USER32!InternalCallWinProc+0x28
0013f6fc 7739ba92 USER32!UserCallWinProcCheckWow+0x151
0013f764 7739bad0 USER32!DispatchMessageWorker+0x327
0013f774 61221ca8 USER32!DispatchMessageW+0xf
0013f7e0 0040156d dll!MainLoop+0x2c8
0013ff24 00401dfa process+0x156d
0013ffc0 77e6f23b process+0x1dfa
0013fff0 00000000 kernel32!BaseProcessStart+0x23

MODULE_NAME: driver

IMAGE_NAME:  driver.sys

We see that WinDbg pointed to driver.sys by using a procedure described in one of my old minidump analysis posts: BugCheck C2 Minidump Analysis. 

However any OS component could corrupt the pool prior to detection as the bugcheck description says: “The pool is already corrupt at the time of the current request.”. What other evidence can reinforce our belief in driver.sys? Let’s look at our pool entry tag first:

1: kd> !pool a34583b8
Pool page a34583b8 region is Nonpaged pool
 a3458000 size:  270 previous size:    0  (Allocated)  Thre (Protected)
 a3458270 size:   10 previous size:  270  (Free)       RxIr
 a3458280 size:   40 previous size:   10  (Allocated)  Vadl
 a34582c0 size:   98 previous size:   40  (Allocated)  File (Protected)
 a3458358 size:    8 previous size:   98  (Free)       Vadl
 a3458360 size:   50 previous size:    8  (Allocated)  Gsem
 a34583b0 size:    8 previous size:   50  (Free)       CcSc
*a34583b8 size:  138 previous size:    8  (Allocated) *DRIV
  Owning component : Unknown (update pooltag.txt)
a34584f0 is not a valid large pool allocation, checking large session pool…
a34584f0 is freed (or corrupt) pool
Bad allocation size @a34584f0, zero is invalid

***
*** An error (or corruption) in the pool was detected;
*** Attempting to diagnose the problem.
***
*** Use !poolval a3458000 for more details.
***

Pool page [ a3458000 ] is __inVALID.

Analyzing linked list...
[ a34583b8 --> a34583d8 (size = 0x20 bytes)]: Corrupt region
[ a34583f8 --> a34585e8 (size = 0x1f0 bytes)]: Corrupt region

Scanning for single bit errors...

None found

We see that the tag is DRIV and we know either from association or from similar problems in the past that it belongs to driver.sys. Let’s dump our pool entry contents to see if there are any symbolic hints in it:

1: kd> dps a34583b8
a34583b8 0a270001
a34583bc 5346574e
a34583c0 00000000
a34583c4 00000000
a34583c8 b958f532 driver+0×36532
a34583cc a3471010
a34583d0 0000012e
a34583d4 00000001
a34583d8 00041457
a34583dc 05af0026
a34583e0 00068002
a34583e4 7b9ec6f5
a34583e8 ffffff00
a34583ec 73650cff
a34583f0 7461445c
a34583f4 97a10061
a34583f8 ff340004
a34583fc c437862a
a3458400 6a000394
a3458404 00000038
a3458408 00000000
a345840c bf000000
a3458410 bf0741b5
a3458414 f70741b5
a3458418 00000000
a345841c 00000000
a3458420 00000000
a3458424 00000000
a3458428 05000000
a345842c 34303220
a3458430 31323332
a3458434 ff322d36

Indeed we see the possible code pointer driver+0×36532 and the code around this address looks normal:

3: kd> .asm no_code_bytes
Assembly options: no_code_bytes

3: kd> u b958f532
driver+0x36532:
b958f532 push    2Ch
b958f534 push    offset driver+0x68d08 (b95c1d08)
b958f539 call    driver+0x65c50 (b95bec50)
b958f53e mov     byte ptr [ebp-19h],0
b958f542 and     dword ptr [ebp-24h],0
b958f546 call    dword ptr [driver+0x65f5c (b95bef5c)]
b958f54c mov     ecx,dword ptr [ebp+0Ch]
b958f54f cmp     eax,ecx

3: kd> ub b958f532
driver+0x36528:
b958f528 leave
b958f529 ret     18h
b958f52c int     3
b958f52d int     3
b958f52e int     3
b958f52f int     3
b958f530 int     3
b958f531 int     3

- Dmitry Vostokov @ DumpAnalysis.org -

259 bugchecks are documented in WinDbg help. I did Google search for every one and here is their search results distribution graph cut off for data with less than 10 matches:

Of course there is some noise and matches do not always correspond to WinDbg bugcheck analysis output but we can get rough idea about bugcheck frequency. For example, unhandled exceptions in kernel mode, IRQL contract violation, pool corruption and hardware failures are the most frequent. Here is the full table:

- Dmitry Vostokov @ DumpAnalysis.org -

Now it’s time to write about Wild Pointer pattern I briefly mentioned in Local Buffer Overflow post which shows examples of pointers having UNICODE structure in their values. I have also observed pointers with ASCII structure as .formats WinDbg command indicates:

FAILED_INSTRUCTION_ADDRESS: 
65747379`735c5357 ??              ???

IP_ON_HEAP:  65747379735c5357

0:012> .formats rip
Evaluate expression:
  Hex:     65747379`735c5357
  Decimal: 7310595060592825175
  Octal:   0625643467456327051527
  Binary:  01100101 01110100 01110011 01111001 01110011 01011100 01010011 01010111
  Chars:   etsys\SW
  Time:    Wed May 10 22:00:59.282 24767 (GMT+1)
  Float:   low 1.7456e+031 high 7.21492e+022
  Double:  5.30388e+180

Here is another example of a pointer having UNICODE structure:

FAILED_INSTRUCTION_ADDRESS: 
0045004c`00490046 ??              ???

0:014> .formats rip
Evaluate expression:
  Hex:     0045004c`00490046
  Decimal: 19422099815333958
  Octal:   0001050004600022200106
  Binary:  00000000 01000101 00000000 01001100 00000000 01001001 00000000 01000110
  Chars:   .E.L.I.F
  Time:    Wed Jul 19 07:46:21.533 1662 (GMT+1)
  Float:   low 6.70409e-039 high 6.33676e-039
  Double:  2.33646e-307

When we have EIP or RIP pointers I have another pattern to name when the value is coincidentally lies inside some valid region of memory: Wild Code. Here is one example of the latter pattern I’m going to write about soon:

IP_ON_STACK:
+e11ffa8

STACK_TEXT:
0e11ff7c 098eeef2 0xe11ffa8
0e11ff84 77b6b530 dll!StartWorking+0xcab
0e11ffb8 7c826063 msvcrt!_endthreadex+0xa3
0e11ffec 00000000 kernel32!BaseThreadStart+0×34

0:020> u
0e11ffa8 dcff fdiv st(7),st
…
…
…

We see that EIP is very close to EBP/ESP and this explains why !analyze -v reports IP_ON_STACK. Clearly floating-point code is not what we should expect. This example shows that wild pointers sometimes are valid but either through code chain or pointer chain execution reaches Invalid Pointer and a process or a system crashes.

- Dmitry Vostokov @ DumpAnalysis.org -

Sometimes when listing processes we see the so called Zombie Processes. They are better visible in the output of !vm command as processes with zero private memory:

0: kd> !vm

*** Virtual Memory Usage ***
 Physical Memory:      999294 (   3997176 Kb)
 Page File: \??\C:\pagefile.sys
   Current:   5995520 Kb  Free Space:   5324040 Kb
   Minimum:   5995520 Kb  Maximum:      5995520 Kb
 Available Pages:      626415 (   2505660 Kb)
 ResAvail Pages:       902639 (   3610556 Kb)
 Locked IO Pages:         121 (       484 Kb)
 Free System PTEs:     201508 (    806032 Kb)
 Free NP PTEs:          32766 (    131064 Kb)
 Free Special NP:           0 (         0 Kb)
 Modified Pages:          256 (      1024 Kb)
 Modified PF Pages:       256 (      1024 Kb)
 NonPagedPool Usage:    12304 (     49216 Kb)
 NonPagedPool Max:      65359 (    261436 Kb)
 PagedPool 0 Usage:     18737 (     74948 Kb)
 PagedPool 1 Usage:      2131 (      8524 Kb)
 PagedPool 2 Usage:      2104 (      8416 Kb)
 PagedPool 3 Usage:      2140 (      8560 Kb)
 PagedPool 4 Usage:      2134 (      8536 Kb)
 PagedPool Usage:       27246 (    108984 Kb)
 PagedPool Maximum:     67072 (    268288 Kb)
 Shared Commit:         60867 (    243468 Kb)
 Special Pool:              0 (         0 Kb)
 Shared Process:        14359 (     57436 Kb)
 PagedPool Commit:      27300 (    109200 Kb)
 Driver Commit:          1662 (      6648 Kb)
 Committed pages:      501592 (   2006368 Kb)
 Commit limit:        2456879 (   9827516 Kb)

 Total Private:        368810 (   1475240 Kb)
...
...
...
         3654 explorer.exe      2083 (      8332 Kb)
         037c MyService.exe     2082 (      8328 Kb)
         315c explorer.exe      2045 (      8180 Kb)
…
…
…
         0588 svchost.exe        360 (      1440 Kb)
         3f94 csrss.exe          288 (      1152 Kb)
         0acc svchost.exe        245 (       980 Kb)
         0380 smss.exe            38 (       152 Kb)
         0004 System               7 (        28 Kb)
         6ee8 cmd.exe              0 (         0 Kb)
         6d7c cmd.exe              0 (         0 Kb)
         6ca8 cmd.exe              0 (         0 Kb)
         6b48 IEXPLORE.EXE         0 (         0 Kb)
         6ac4 cmd.exe              0 (         0 Kb)
         69e8 cmd.exe              0 (         0 Kb)
         69dc cmd.exe              0 (         0 Kb)
         68dc AcroRd32.exe         0 (         0 Kb)
         6860 cmd.exe              0 (         0 Kb)
         6858 cmd.exe              0 (         0 Kb)
         67d8 cmd.exe              0 (         0 Kb)
         6684 AcroRd32.exe         0 (         0 Kb)
         6484 cmd.exe              0 (         0 Kb)
         6464 cmd.exe              0 (         0 Kb)
         6288 cmd.exe              0 (         0 Kb)
         626c cmd.exe              0 (         0 Kb)
         6260 cmd.exe              0 (         0 Kb)
         6258 cmd.exe              0 (         0 Kb)
         620c IEXPLORE.EXE         0 (         0 Kb)
         60f0 cmd.exe              0 (         0 Kb)
         5fa4 cmd.exe              0 (         0 Kb)
         5f60 cmd.exe              0 (         0 Kb)
         5eec cmd.exe              0 (         0 Kb)
         5d24 IEXPLORE.EXE         0 (         0 Kb)
         5bd4 cmd.exe              0 (         0 Kb)
         5b9c cmd.exe              0 (         0 Kb)
         5b10 cmd.exe              0 (         0 Kb)
         5b08 cmd.exe              0 (         0 Kb)
         5a4c cmd.exe              0 (         0 Kb)
         5a08 cmd.exe              0 (         0 Kb)
         5934 cmd.exe              0 (         0 Kb)
         58b8 cmd.exe              0 (         0 Kb)
         56dc cmd.exe              0 (         0 Kb)
         558c cmd.exe              0 (         0 Kb)
         5588 cmd.exe              0 (         0 Kb)
         5574 cmd.exe              0 (         0 Kb)
         5430 cmd.exe              0 (         0 Kb)
         5424 cmd.exe              0 (         0 Kb)
         53b0 cmd.exe              0 (         0 Kb)
         5174 explorer.exe         0 (         0 Kb)
         5068 cmd.exe              0 (         0 Kb)
         5028 IEXPLORE.EXE         0 (         0 Kb)
         5004 cmd.exe              0 (         0 Kb)
         4f3c javaw.exe            0 (         0 Kb)
         4de4 cmd.exe              0 (         0 Kb)
         4dd8 cmd.exe              0 (         0 Kb)
         4c50 cmd.exe              0 (         0 Kb)
         4c48 cmd.exe              0 (         0 Kb)
         4c08 cmd.exe              0 (         0 Kb)
         4a8c cmd.exe              0 (         0 Kb)
         49ac cmd.exe              0 (         0 Kb)
         4938 cmd.exe              0 (         0 Kb)
         4928 cmd.exe              0 (         0 Kb)
         491c cmd.exe              0 (         0 Kb)
         4868 POWERPNT.EXE         0 (         0 Kb)
         4724 cmd.exe              0 (         0 Kb)
         46cc cmd.exe              0 (         0 Kb)
         44a8 cmd.exe              0 (         0 Kb)
         43cc cmd.exe              0 (         0 Kb)
         4350 cmd.exe              0 (         0 Kb)
         4208 cmd.exe              0 (         0 Kb)
         41f4 cmd.exe              0 (         0 Kb)
         41ec cmd.exe              0 (         0 Kb)
         4170 cmd.exe              0 (         0 Kb)
         40bc cmd.exe              0 (         0 Kb)
         3ddc cmd.exe              0 (         0 Kb)
         3dcc cmd.exe              0 (         0 Kb)
         3db8 cmd.exe              0 (         0 Kb)
         3d88 cmd.exe              0 (         0 Kb)
         3d10 cmd.exe              0 (         0 Kb)
         3cac cmd.exe              0 (         0 Kb)
         3ca4 cmd.exe              0 (         0 Kb)
         3c88 cmd.exe              0 (         0 Kb)
         337c cmd.exe              0 (         0 Kb)
         3310 cmd.exe              0 (         0 Kb)
         3308 cmd.exe              0 (         0 Kb)
         32f0 cmd.exe              0 (         0 Kb)
         32b8 cmd.exe              0 (         0 Kb)
         2ed0 cmd.exe              0 (         0 Kb)
         2eb8 cmd.exe              0 (         0 Kb)
         2e28 cmd.exe              0 (         0 Kb)
         2d44 AcroRd32.exe         0 (         0 Kb)
         2d24 cmd.exe              0 (         0 Kb)
         2c94 cmd.exe              0 (         0 Kb)
         2c54 IEXPLORE.EXE         0 (         0 Kb)
         2a28 cmd.exe              0 (         0 Kb)
         29e4 cmd.exe              0 (         0 Kb)
         2990 cmd.exe              0 (         0 Kb)
         28c0 cmd.exe              0 (         0 Kb)
         25a0 cmd.exe              0 (         0 Kb)
         2558 cmd.exe              0 (         0 Kb)
         2478 cmd.exe              0 (         0 Kb)
         244c cmd.exe              0 (         0 Kb)
         23dc cmd.exe              0 (         0 Kb)
         2320 cmd.exe              0 (         0 Kb)
         2280 cmd.exe              0 (         0 Kb)
         2130 cmd.exe              0 (         0 Kb)
         205c cmd.exe              0 (         0 Kb)
         2014 cmd.exe              0 (         0 Kb)
         1fd8 cmd.exe              0 (         0 Kb)
         1fa0 cmd.exe              0 (         0 Kb)
         1eb8 cmd.exe              0 (         0 Kb)
         1d68 IEXPLORE.EXE         0 (         0 Kb)
         1cb8 cmd.exe              0 (         0 Kb)
         1c9c cmd.exe              0 (         0 Kb)
         1c50 cmd.exe              0 (         0 Kb)
         1a74 cmd.exe              0 (         0 Kb)
         1954 cmd.exe              0 (         0 Kb)
         1948 cmd.exe              0 (         0 Kb)
         06e4 cmd.exe              0 (         0 Kb)
         0650 cmd.exe              0 (         0 Kb)

We see lots of cmd.exe processes. Let’s examine a few of them:

0: kd> !process 0650
Searching for Process with Cid == 650
PROCESS 89237d88  SessionId: 0  Cid: 0650    Peb: 7ffde000  ParentCid: 037c
    DirBase: f3b31940  ObjectTable: 00000000  HandleCount:   0.
    Image: cmd.exe
    VadRoot 00000000 Vads 0 Clone 0 Private 0. Modified 2. Locked 0.
    DeviceMap e10038a8
    Token                             e4eb5b98
    ElapsedTime                       1 Day 00:16:11.706
    UserTime                          00:00:00.015
    KernelTime                        00:00:00.015
    QuotaPoolUsage[PagedPool]         0
    QuotaPoolUsage[NonPagedPool]      0
    Working Set Sizes (now,min,max)  (7, 50, 345) (28KB, 200KB, 1380KB)
    PeakWorkingSetSize                588
    VirtualSize                       11 Mb
    PeakVirtualSize                   14 Mb
    PageFaultCount                    663
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      0

No active threads

0: kd> !process 2130
Searching for Process with Cid == 2130
PROCESS 89648020  SessionId: 0  Cid: 2130    Peb: 7ffdc000  ParentCid: 037c
    DirBase: f3b31060  ObjectTable: 00000000  HandleCount:   0.
    Image: cmd.exe
    VadRoot 00000000 Vads 0 Clone 0 Private 0. Modified 2. Locked 0.
    DeviceMap e10038a8
    Token                             e5167bb8
    ElapsedTime                       15:40:17.643
    UserTime                          00:00:00.015
    KernelTime                        00:00:00.000
    QuotaPoolUsage[PagedPool]         0
    QuotaPoolUsage[NonPagedPool]      0
    Working Set Sizes (now,min,max)  (7, 50, 345) (28KB, 200KB, 1380KB)
    PeakWorkingSetSize                545
    VirtualSize                       11 Mb
    PeakVirtualSize                   14 Mb
    PageFaultCount                    621
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      0

No active threads

We see that most of them have Parent PID as 037c which is MyService.exe. Let’s peek inside its handle table:

0: kd> !kdexts.handle 0 3 037c
processor number 0, process 0000037c
Searching for Process with Cid == 37c
PROCESS 8a8fa8c0  SessionId: 0  Cid: 037c    Peb: 7ffd8000  ParentCid: 04ac
    DirBase: f3b10360  ObjectTable: e1c276b8  HandleCount: 500.
    Image: MyService.exe

Handle table at e272d000 with 500 Entries in use
0004: Object: e1000638  GrantedAccess: 00000003 Entry: e1caf008
Object: e1000638  Type: (8ad79ad0) KeyedEvent
    ObjectHeader: e1000620 (old version)
        HandleCount: 151  PointerCount: 152
        Directory Object: e1001898  Name: CritSecOutOfMemoryEvent

0008: Object: 8a8cfdf8  GrantedAccess: 001f0003 Entry: e1caf010
Object: 8a8cfdf8  Type: (8ad7a990) Event
    ObjectHeader: 8a8cfde0 (old version)
        HandleCount: 1  PointerCount: 1

000c: Object: e186d690  GrantedAccess: 00000003 Entry: e1caf018
Object: e186d690  Type: (8ad84e70) Directory
    ObjectHeader: e186d678 (old version)
        HandleCount: 150  PointerCount: 181
        Directory Object: e1003b28  Name: KnownDlls

0010: Object: 8a8d1328  GrantedAccess: 00100020 (Inherit) Entry: e1caf020
Object: 8a8d1328  Type: (8ad74900) File
    ObjectHeader: 8a8d1310 (old version)
        HandleCount: 1  PointerCount: 1
        Directory Object: 00000000  Name: \WINDOWS\system32 {HarddiskVolume1}
...
...
...
0484: Object: 89648020  GrantedAccess: 001f0fff Entry: e1caf908
Object: 89648020  Type: (8ad84900) Process
    ObjectHeader: 89648008 (old version)
        HandleCount: 1  PointerCount: 2
…
…
…
0510: Object: 89237d88  GrantedAccess: 001f0fff Entry: e1cafa20
Object: 89237d88  Type: (8ad84900) Process
    ObjectHeader: 89237d70 (old version)
        HandleCount: 1  PointerCount: 2
…
…
…
 
Therefore we may guess that MyService.exe probably forgot to close process handles either after launching cmd.exe or after waiting for their exit when process objects become signaled:

0510: Object: 89237d88  GrantedAccess: 001f0fff Entry: e1cafa20
Object: 89237d88  Type: (8ad84900) Process
    ObjectHeader: 89237d70 (old version)
        HandleCount: 1  PointerCount: 2 

0: kd> dt _DISPATCHER_HEADER 89237d88
ntdll!_DISPATCHER_HEADER
   +0x000 Type             : 0x3 '' ; PROCESS OBJECT
   +0x001 Absolute         : 0 ''
   +0x001 NpxIrql          : 0 ''
   +0x002 Size             : 0x1e ''
   +0x002 Hand             : 0x1e ''
   +0x003 Inserted         : 0 ''
   +0x003 DebugActive      : 0 ''
   +0x000 Lock             : 1966083
   +0×004 SignalState      : 1
   +0×008 WaitListHead     : _LIST_ENTRY [ 0×89237d90 - 0×89237d90 ]

This pattern can also be seen a specialization of a more general Handle Leak pattern.

- Dmitry Vostokov @ DumpAnalysis.org -

We often say that a particular thread is blocked and/or it blocks other threads. At the same time we know that almost all threads are “blocked” to some degree except those currently running on processors. They are either preempted and in the ready lists, voluntary yielded their execution or they are waiting for some synchronization object. Therefore the notion of Blocked Thread is highly context and problem dependent and usually we notice them when comparing current thread stack traces with their expected normal stack traces. Here reference guides are indispensible especially those created for troubleshooting concrete products. Forthcoming Debugger Log Analyzer was partially incepted to address this problem.  

To show the diversity of “blocked” threads I propose the following thread classification:

Running threads

Their EIP (RIP) points to some function different from KiSwapContext:

3: kd> !running

System Processors f (affinity mask)
  Idle Processors 0

     Prcb      Current   Next   
  0  ffdff120  a30a9350            ................
  1  f7727120  a3186448            ................
  2  f772f120  a59a1b40            ................
  3  f7737120  a3085888            ................

3: kd> !thread a59a1b40
THREAD a59a1b40  Cid 0004.00b8  Teb: 00000000 Win32Thread: 00000000 RUNNING on processor 2
Not impersonating
DeviceMap                 e10028b0
Owning Process            a59aa648       Image:         System
Wait Start TickCount      1450446        Ticks: 1 (0:00:00:00.015)
Context Switch Count      308765            
UserTime                  00:00:00.000
KernelTime                00:00:01.250
Start Address nt!ExpWorkerThread (0×80880356)
Stack Init f7055000 Current f7054cec Base f7055000 Limit f7052000 Call 0
Priority 12 BasePriority 12 PriorityDecrement 0
ChildEBP RetAddr
f7054bc4 8093c55c nt!ObfReferenceObject+0×1c
f7054ca0 8093d2ae nt!ObpQueryNameString+0×2ba
f7054cbc 808f7d0f nt!ObQueryNameString+0×18
f7054d80 80880441 nt!IopErrorLogThread+0×197
f7054dac 80949b7c nt!ExpWorkerThread+0xeb
f7054ddc 8088e062 nt!PspSystemThreadStartup+0×2e
00000000 00000000 nt!KiThreadStartup+0×16

3: kd> .thread a59a1b40
Implicit thread is now a59a1b40

3: kd> r
Last set context:
eax=00000028 ebx=e1000228 ecx=e1002b30 edx=e1000234 esi=e1002b18 edi=0000001a
eip=8086c73e esp=f7054bc4 ebp=f7054ca0 iopl=0 nv up ei pl nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00000202
nt!ObfReferenceObject+0×1c:
8086c73e 40              inc     eax
 
These threads can also be identified by RUNNING attribute in the output of !process 0 ff command applied for complete and kernel memory dumps.

Ready threads  

These threads can be seen in the output of !ready command or identified by READY attribute in the output of !process 0 ff command:

3: kd> !ready
Processor 0: No threads in READY state
Processor 1: Ready Threads at priority 11
    THREAD a3790790  Cid 0234.1108  Teb: 7ffab000 Win32Thread: 00000000 READY
    THREAD a32799a8  Cid 0234.061c  Teb: 7ff83000 Win32Thread: 00000000 READY
    THREAD a3961798  Cid 0c04.0c68  Teb: 7ffab000 Win32Thread: bc204ea8 READY
Processor 1: Ready Threads at priority 10
    THREAD a32bedb0  Cid 1fc8.1a30  Teb: 7ffad000 Win32Thread: bc804468 READY
Processor 1: Ready Threads at priority 9
    THREAD a52dcd48  Cid 0004.04d4  Teb: 00000000 Win32Thread: 00000000 READY
Processor 2: Ready Threads at priority 11
    THREAD a37fedb0  Cid 0c04.11f8  Teb: 7ff8e000 Win32Thread: 00000000 READY
Processor 3: Ready Threads at priority 11
    THREAD a5683db0  Cid 0234.0274  Teb: 7ffd6000 Win32Thread: 00000000 READY
    THREAD a3151b48  Cid 0234.2088  Teb: 7ff88000 Win32Thread: 00000000 READY
    THREAD a5099d80  Cid 0ecc.0d60  Teb: 7ffd4000 Win32Thread: 00000000 READY
    THREAD a3039498  Cid 0c04.275c  Teb: 7ff7d000 Win32Thread: 00000000 READY

If we look at these threads we would see that they were either scheduled to run because of a signaled object they were waiting for:

3: kd> !thread a3039498
THREAD a3039498  Cid 0c04.275c  Teb: 7ff7d000 Win32Thread: 00000000 READY
IRP List:
    a2feb008: (0006,0094) Flags: 00000870  Mdl: 00000000
Not impersonating
DeviceMap                 e10028b0
Owning Process            a399a770       Image:         svchost.exe
Wait Start TickCount      1450447        Ticks: 0
Context Switch Count      1069            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0x001e4f22
LPC Server thread working on message Id 1e4f22
Start Address KERNEL32!BaseThreadStartThunk (0x77e617ec)
Stack Init f171b000 Current f171ac60 Base f171b000 Limit f1718000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr  Args to Child             
f171ac78 80833465 a3039498 a3039540 e7561930 nt!KiSwapContext+0x26
f171aca4 80829a62 00000000 00000000 00000000 nt!KiSwapThread+0x2e5
f171acec 80938d0c a301cad8 00000006 f171ad01 nt!KeWaitForSingleObject+0×346
f171ad50 8088978c 00000c99 00000000 00000000 nt!NtWaitForSingleObject+0×9a
f171ad50 7c8285ec 00000c99 00000000 00000000 nt!KiFastCallEntry+0xfc
03d9efa8 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet

3: kd> !object a301cad8
Object: a301cad8  Type: (a59a0720) Event
    ObjectHeader: a301cac0 (old version)
    HandleCount: 1  PointerCount: 3

Or they were boosted in priority:

3: kd> !thread a3790790
THREAD a3790790  Cid 0234.1108  Teb: 7ffab000 Win32Thread: 00000000 READY
IRP List:
    a2f8b7f8: (0006,0094) Flags: 00000900  Mdl: 00000000
Not impersonating
DeviceMap                 e10028b0
Owning Process            a554bcc8       Image:         lsass.exe
Wait Start TickCount      1450447        Ticks: 0
Context Switch Count      384            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address RPCRT4!ThreadStartRoutine (0x77c7b0f5)
Start Address KERNEL32!BaseThreadStartThunk (0x77e617ec)
Stack Init f3ac1000 Current f3ac0ce8 Base f3ac1000 Limit f3abe000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr  Args to Child             
f3ac0d00 80831266 a3790790 a50f1870 a3186448 nt!KiSwapContext+0x26
f3ac0d20 8082833a 00000000 a50f1870 8098b56c nt!KiExitDispatcher+0xf8
f3ac0d3c 8098b5b9 a50f1870 00000000 00f5f8d0 nt!KeSetEventBoostPriority+0×156
f3ac0d58 8088978c a50f1870 00f5f8d4 7c8285ec nt!NtSetEventBoostPriority+0×4d
f3ac0d58 7c8285ec a50f1870 00f5f8d4 7c8285ec nt!KiFastCallEntry+0xfc
00f5f8d4 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet

3: kd> !object a50f1870
Object: a50f1870  Type: (a59a0720) Event
    ObjectHeader: a50f1858 (old version)
    HandleCount: 1  PointerCount: 15

Or were interrupted and queued to be run again:

3: kd> !thread a5683db0
THREAD a5683db0 Cid 0234.0274 Teb: 7ffd6000 Win32Thread: 00000000 READY
IRP List:
  a324d498: (0006,0094) Flags: 00000900 Mdl: 00000000
  a2f97a20: (0006,0094) Flags: 00000900 Mdl: 00000000
  a50c3e70: (0006,0190) Flags: 00000000 Mdl: a50a22d0
  a5167750: (0006,0094) Flags: 00000800 Mdl: 00000000
Not impersonating
DeviceMap e10028b0
Owning Process a554bcc8 Image: lsass.exe
Wait Start TickCount 1450447 Ticks: 0
Context Switch Count 9619
UserTime 00:00:00.156
KernelTime 00:00:00.234
Win32 Start Address RPCRT4!ThreadStartRoutine (0x77c7b0f5)
Start Address KERNEL32!BaseThreadStartThunk (0x77e617ec)
Stack Init f59f3000 Current f59f2d00 Base f59f3000 Limit f59f0000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr
f59f2d18 80a5c1ae nt!KiDispatchInterrupt+0xb1
f59f2d48 80a5c577 hal!HalpDispatchSoftwareInterrupt+0x5e
f59f2d54 80a59902 hal!HalEndSystemInterrupt+0x67
f59f2d54 77c6928d hal!HalpIpiHandler+0xd2 (TrapFrame @ f59f2d64)
00c5f908 00000000 RPCRT4!OSF_SCALL::GetBuffer+0×37

3: kd> .thread a5683db0
Implicit thread is now a5683db0

3: kd> r
Last set context:
eax=00000000 ebx=00000000 ecx=00000000 edx=00000000 esi=00000000 edi=00000000
eip=8088dba1 esp=f59f2d0c ebp=f59f2d2c iopl=0 nv up di pl nz na po nc
cs=0008 ss=0010 ds=0000 es=0000 fs=0000 gs=0000 efl=00000000
nt!KiDispatchInterrupt+0xb1:
8088dba1 b902000000 mov ecx,2

3: kd> ub
nt!KiDispatchInterrupt+0x8f:
8088db7f mov dword ptr [ebx+124h],esi
8088db85 mov byte ptr [esi+4Ch],2
8088db89 mov byte ptr [edi+5Ah],1Fh
8088db8d mov ecx,edi
8088db8f lea edx,[ebx+120h]
8088db95 call nt!KiQueueReadyThread (80833490)
8088db9a mov cl,1
8088db9c call nt!SwapContext (8088dbd0)

3: kd> u
nt!KiDispatchInterrupt+0xb1:
8088dba1 mov ecx,2
8088dba6 call dword ptr [nt!_imp_KfLowerIrql (80801108)]
8088dbac mov ebp,dword ptr [esp]
8088dbaf mov edi,dword ptr [esp+4]
8088dbb3 mov esi,dword ptr [esp+8]
8088dbb7 add esp,0Ch
8088dbba pop ebx
8088dbbb ret

We can get user space thread stack by using .trap command but we need to switch to its process context first:

3: kd> .process /r /p a554bcc8
Implicit process is now a554bcc8
Loading User Symbols

3: kd> kL
  *** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr
00c5f908 77c7ed60 RPCRT4!OSF_SCALL::GetBuffer+0x37
00c5f924 77c7ed14 RPCRT4!I_RpcGetBufferWithObject+0x7f
00c5f934 77c7f464 RPCRT4!I_RpcGetBuffer+0xf
00c5f944 77ce3470 RPCRT4!NdrGetBuffer+0x2e
00c5fd44 77ce35c4 RPCRT4!NdrStubCall2+0x35c
00c5fd60 77c7ff7a RPCRT4!NdrServerCall2+0x19
00c5fd94 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0x38
00c5fde8 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0x11f
00c5fe0c 77c68e0d RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
00c5fe40 77c68cb3 RPCRT4!OSF_SCALL::DispatchHelper+0x149
00c5fe54 77c68c2b RPCRT4!OSF_SCALL::DispatchRPCCall+0x10d
00c5fe84 77c68b5e RPCRT4!OSF_SCALL::ProcessReceivedPDU+0x57f
00c5fea4 77c6e8db RPCRT4!OSF_SCALL::BeginRpcCall+0x194
00c5ff04 77c6e7b4 RPCRT4!OSF_SCONNECTION::ProcessReceiveComplete+0x435
00c5ff18 77c7b799 RPCRT4!ProcessConnectionServerReceivedEvent+0x21
00c5ff84 77c7b9b5 RPCRT4!LOADABLE_TRANSPORT::ProcessIOEvents+0x1b8
00c5ff8c 77c8872d RPCRT4!ProcessIOEventsWrapper+0xd
00c5ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0x9d
00c5ffb8 77e64829 RPCRT4!ThreadStartRoutine+0x1b
00c5ffec 00000000 kernel32!BaseThreadStart+0x34

Waiting threads (wait originated from user space)

THREAD a34369d0  Cid 1fc8.1e88  Teb: 7ffae000 Win32Thread: bc6d5818 WAIT: (Unknown) UserMode Non-Alertable
    a34d9940  SynchronizationEvent
    a3436a48  NotificationTimer
Not impersonating
DeviceMap                 e12256a0
Owning Process            a3340a10       Image:         IEXPLORE.EXE
Wait Start TickCount      1450409        Ticks: 38 (0:00:00:00.593)
Context Switch Count      7091                 LargeStack
UserTime                  00:00:01.015
KernelTime                00:00:02.250
Win32 Start Address mshtml!CExecFT::StaticThreadProc (0x7fab1061)
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init f252b000 Current f252ac60 Base f252b000 Limit f2528000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
f252ac78 80833465 nt!KiSwapContext+0x26
f252aca4 80829a62 nt!KiSwapThread+0x2e5
f252acec 80938d0c nt!KeWaitForSingleObject+0x346
f252ad50 8088978c nt!NtWaitForSingleObject+0x9a
f252ad50 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ f252ad64)
030dff08 7c827d0b ntdll!KiFastSystemCallRet
030dff0c 77e61d1e ntdll!NtWaitForSingleObject+0xc
030dff7c 77e61c8d kernel32!WaitForSingleObjectEx+0xac
030dff90 7fab08a3 kernel32!WaitForSingleObject+0×12
030dffa8 7fab109c mshtml!CDwnTaskExec::ThreadExec+0xae
030dffb0 7fab106e mshtml!CExecFT::ThreadProc+0×28
030dffb8 77e64829 mshtml!CExecFT::StaticThreadProc+0xd
030dffec 00000000 kernel32!BaseThreadStart+0×34

If we had taken user dump of iexplore.exe we would have seen the following stack trace there:

030dff08 7c827d0b ntdll!KiFastSystemCallRet
030dff0c 77e61d1e ntdll!NtWaitForSingleObject+0xc
030dff7c 77e61c8d kernel32!WaitForSingleObjectEx+0xac
030dff90 7fab08a3 kernel32!WaitForSingleObject+0×12
030dffa8 7fab109c mshtml!CDwnTaskExec::ThreadExec+0xae
030dffb0 7fab106e mshtml!CExecFT::ThreadProc+0×28
030dffb8 77e64829 mshtml!CExecFT::StaticThreadProc+0xd
030dffec 00000000 kernel32!BaseThreadStart+0×34

Another example:

THREAD a31f2438  Cid 1fc8.181c  Teb: 7ffaa000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
    a30f8c20  NotificationEvent
    a5146720  NotificationEvent
    a376fbb0  NotificationEvent
Not impersonating
DeviceMap                 e12256a0
Owning Process            a3340a10       Image:         IEXPLORE.EXE
Wait Start TickCount      1419690        Ticks: 30757 (0:00:08:00.578)
Context Switch Count      2            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address USERENV!NotificationThread (0x76929dd9)
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init f5538000 Current f5537900 Base f5538000 Limit f5535000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
f5537918 80833465 nt!KiSwapContext+0x26
f5537944 80829499 nt!KiSwapThread+0x2e5
f5537978 80938f68 nt!KeWaitForMultipleObjects+0x3d7
f5537bf4 809390ca nt!ObpWaitForMultipleObjects+0x202
f5537d48 8088978c nt!NtWaitForMultipleObjects+0xc8
f5537d48 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ f5537d64)
0851fec0 7c827cfb ntdll!KiFastSystemCallRet
0851fec4 77e6202c ntdll!NtWaitForMultipleObjects+0xc
0851ff6c 77e62fbe kernel32!WaitForMultipleObjectsEx+0x11a
0851ff88 76929e35 kernel32!WaitForMultipleObjects+0×18
0851ffb8 77e64829 USERENV!NotificationThread+0×5f
0851ffec 00000000 kernel32!BaseThreadStart+0×34

Waiting threads (wait originated from kernel space)

Examples include explicit wait as a result from calling potentially blocking API:

THREAD a33a9740  Cid 1980.1960  Teb: 7ffde000 Win32Thread: bc283ea8 WAIT: (Unknown) UserMode Non-Alertable
    a35e3168  SynchronizationEvent
Not impersonating
DeviceMap                 e689f298
Owning Process            a342d3a0       Image:         explorer.exe
Wait Start TickCount      1369801        Ticks: 80646 (0:00:21:00.093)
Context Switch Count      1667                 LargeStack
UserTime                  00:00:00.015
KernelTime                00:00:00.093
Win32 Start Address Explorer!ModuleEntry (0x010148a4)
Start Address kernel32!BaseProcessStartThunk (0x77e617f8)
Stack Init f258b000 Current f258ac50 Base f258b000 Limit f2585000 Call 0
Priority 13 BasePriority 10 PriorityDecrement 1
Kernel stack not resident.
ChildEBP RetAddr 
f258ac68 80833465 nt!KiSwapContext+0x26
f258ac94 80829a62 nt!KiSwapThread+0x2e5
f258acdc bf89abd3 nt!KeWaitForSingleObject+0×346
f258ad38 bf89da43 win32k!xxxSleepThread+0×1be
f258ad4c bf89e401 win32k!xxxRealWaitMessageEx+0×12
f258ad5c 8088978c win32k!NtUserWaitMessage+0×14
f258ad5c 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ f258ad64)
0007feec 7739bf53 ntdll!KiFastSystemCallRet
0007ff08 7c8fadbd USER32!NtUserWaitMessage+0xc
0007ff14 0100fff1 SHELL32!SHDesktopMessageLoop+0×24
0007ff5c 0101490c Explorer!ExplorerWinMain+0×2c4
0007ffc0 77e6f23b Explorer!ModuleEntry+0×6d
0007fff0 00000000 kernel32!BaseProcessStart+0×23

and implicit wait when a thread yields execution to another thread voluntarily via explicit context swap:

THREAD a3072b68  Cid 1fc8.1d94  Teb: 7ffaf000 Win32Thread: bc1e3c20 WAIT: (Unknown) UserMode Non-Alertable
    a37004d8  QueueObject
    a3072be0  NotificationTimer
IRP List:
    a322be00: (0006,01fc) Flags: 00000000  Mdl: a30b8e30
    a30bcc38: (0006,01fc) Flags: 00000000  Mdl: a35bf530
Not impersonating
DeviceMap                 e12256a0
Owning Process            a3340a10       Image:         IEXPLORE.EXE
Wait Start TickCount      1447963        Ticks: 2484 (0:00:00:38.812)
Context Switch Count      3972                 LargeStack
UserTime                  00:00:00.140
KernelTime                00:00:00.250
Win32 Start Address ntdll!RtlpWorkerThread (0x7c839efb)
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init f1cc3000 Current f1cc2c38 Base f1cc3000 Limit f1cbf000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
f1cc2c50 80833465 nt!KiSwapContext+0x26
f1cc2c7c 8082b60f nt!KiSwapThread+0x2e5
f1cc2cc4 808ed620 nt!KeRemoveQueue+0×417
f1cc2d48 8088978c nt!NtRemoveIoCompletion+0xdc
f1cc2d48 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ f1cc2d64)
06ceff70 7c8277db ntdll!KiFastSystemCallRet
06ceff74 7c839f38 ntdll!ZwRemoveIoCompletion+0xc
06ceffb8 77e64829 ntdll!RtlpWorkerThread+0×3d
06ceffec 00000000 kernel32!BaseThreadStart+0×34

THREAD a3612020  Cid 1980.1a48  Teb: 7ffd9000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Alertable
    a3612098  NotificationTimer
Not impersonating
DeviceMap                 e689f298
Owning Process            a342d3a0       Image:         explorer.exe
Wait Start TickCount      1346718        Ticks: 103729 (0:00:27:00.765)
Context Switch Count      4            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address ntdll!RtlpTimerThread (0x7c83d3dd)
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init f2453000 Current f2452c80 Base f2453000 Limit f2450000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
f2452c98 80833465 nt!KiSwapContext+0x26
f2452cc4 80828f0b nt!KiSwapThread+0x2e5
f2452d0c 80994812 nt!KeDelayExecutionThread+0×2ab
f2452d54 8088978c nt!NtDelayExecution+0×84
f2452d54 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ f2452d64)
0149ff9c 7c826f4b ntdll!KiFastSystemCallRet
0149ffa0 7c83d424 ntdll!NtDelayExecution+0xc
0149ffb8 77e64829 ntdll!RtlpTimerThread+0×47
0149ffec 00000000 kernel32!BaseThreadStart+0×34

Explicit waits in kernel can be originated from GUI threads and their message loops, for example, Main Thread. Blocked GUI Thread pattern can be seen as an example of a genuine Blocked Thread. Some “blocked” threads are just really Passive Threads.

- Dmitry Vostokov @ DumpAnalysis.org -

Sometimes processes dump themselves using Microsoft DbgHelp API when they encounter internal errors or for other debugging purposes. I separate this from unhandled exceptions which usually cause an external postmortem debugger process to dump memory contents as explained in my previous posts:

• Who calls the postmortem debugger?
• Inside Vista Error Reporting (Part 1)

It is important to understand that a process can dump itself for any reasons that came to mind of an application designer and not only as a reaction to hardware and software exceptions. In any case it is useful to look at raw stack dump of all threads and search for first chance exceptions like c0000005 and custom exception handlers. 

I call this pattern Self-Dump and consider it as a specialized version of Special Stack Trace pattern. The typical thread stack might look like (and might be Incorrect Stack Trace that requires manual reconstruction):

0:012> kL
ChildEBP RetAddr 
0151f0c4 77e61f0c ntdll!KiFastSystemCallRet
0151f0d4 08000000 kernel32!CreateFileMappingW+0xc8
WARNING: Frame IP not in any known module. Following frames may be wrong.
0151f0f0 7c82728b 0x8000000
0151f0f4 77e63e41 ntdll!NtMapViewOfSection+0xc
0151f12c 77e6440c kernel32!MapViewOfFileEx+0x71
0151f14c 7c826d2b kernel32!MapViewOfFile+0x1b
0151f1d4 028ca67c ntdll!ZwClose+0xc
0151f2a4 028cc2f1 dbghelp!GenGetClrMemory+0xec
0151f2b4 028c8e55 dbghelp!Win32LiveSystemProvider::CloseMapping+0×11
0151f414 00000000 dbghelp!GenAllocateModuleObject+0×3c5

Raw stack data should reveal DbgHelp API calls:

0151f944  00000000
0151f948  00000000
0151f94c  0151f9c0
0151f950  028c7662 dbghelp!MiniDumpWriteDump+0×1b2
0151f954  ffffffff
0151f958  00000cb0
0151f95c  00c21ea8
0151f960  00c21f88
0151f964  00c21e90
0151f968  00c21fa0
0151f96c  00000002
0151f970  00000000
0151f974  00000000
0151f978  00000000
0151f97c  7c829f60 ntdll!CheckHeapFillPattern+0×64
0151f980  ffffffff
0151f984  7c829f59 ntdll!RtlFreeHeap+0×70f
0151f988  7c34218a msvcr71!free+0xc3
0151f98c  00000000
0151f990  00000000
0151f994  00c21e90
0151f998  00c21fa0
0151f99c  00c21ea8
0151f9a0  00c21f88
0151f9a4  00000002
0151f9a8  021a00da
0151f9ac  001875d8
0151f9b0  7c3416db msvcr71!_nh_malloc+0×10
0151f9b4  0151f998
0151f9b8  001875d8
0151f9bc  00000000
0151f9c0  0151fbe4
0151f9c4  57b77d01 application!write_problem_report+0×18d1
0151f9c8  ffffffff
0151f9cc  00000cb0
0151f9d0  00000718
0151f9d4  00000002
0151f9d8  00000000
0151f9dc  00000000
0151f9e0  00000000
0151f9e4  00029722
0151f9e8  0151fc20

Partially reconstructed stack trace might look like:

0:012> k L=0151f94c
ChildEBP RetAddr 
0151f0c4 77e61f0c ntdll!KiFastSystemCallRet
0151f94c 028c7662 kernel32!CreateFileMappingW+0xc8
0151f9c0 57b77d01 dbghelp!MiniDumpWriteDump+0×1b2
0151fbe4 57b77056 application!write_problem_report+0×18d1
0151fc30 579c83af application!TerminateThread+0×18

- Dmitry Vostokov @ DumpAnalysis.org -

Another suspicious threads in crash dumps are GUI threads executing message box code. Usually message boxes are displayed to show some error and we can see it by dumping the second and the third MessageBox parameters:

int MessageBox(     
    HWND hWnd,     
    LPCTSTR lpText,
    LPCTSTR lpCaption,
    UINT uType);

Sometimes message boxes block processes as shown in the example illustrating Coupled Process pattern. Other threads might point to possibly “hang” sessions and processes in memory dumps coming from terminal services environments. I call this pattern Message Box and it is another example of the forthcoming collective Blocked Thread pattern. 

Let’s look at one example where message box pointed to the right direction of troubleshooting. Some user process was reported hanging from time to time however it was not specified which one. Searching for MessageBox in the log of all threads in the system produced by !process 0 ff WinDbg command revealed the following thread:

THREAD 88b14da8  Cid 0a04.0c14  Teb: 7ffdd000 Win32Thread: e5e50ab0 WAIT: (WrUserRequest) UserMode Non-Alertable
    87b74358  SynchronizationEvent
IRP List:
    87a0ba00: (0006,0244) Flags: 00000000  Mdl: 00000000
Not impersonating
DeviceMap                 e14bec28
Owning Process            888ffb60       Image:         OUTLOOK.EXE
Wait Start TickCount      1275435        Ticks: 210 (0:00:00:03.281)
Context Switch Count      1050203                 LargeStack
UserTime                  00:00:16.812
KernelTime                00:00:18.000
Win32 Start Address OUTLOOK (0x30001084)
Start Address kernel32!BaseProcessStartThunk (0x7c810665)
Stack Init a0c98000 Current a0c97cb0 Base a0c98000 Limit a0c90000 Call 0
Priority 11 BasePriority 8 PriorityDecrement 2 DecrementCount 16
ChildEBP RetAddr 
a0c97cc8 804e1bd2 nt!KiSwapContext+0x2f
a0c97cd4 804e1c1e nt!KiSwapThread+0x8a
a0c97cfc bf802f70 nt!KeWaitForSingleObject+0x1c2
a0c97d38 bf803776 win32k!xxxSleepThread+0x192
a0c97d4c bf803793 win32k!xxxRealWaitMessageEx+0x12
a0c97d5c 804dd99f win32k!NtUserWaitMessage+0x14
a0c97d5c 7c90eb94 nt!KiFastCallEntry+0xfc
0013f3a8 7e419418 ntdll!KiFastSystemCallRet
0013f3e0 7e42593f USER32!NtUserWaitMessage+0xc
0013f408 7e43a91e USER32!InternalDialogBox+0xd0
0013f6c8 7e43a284 USER32!SoftModalMessageBox+0x938
0013f818 7e4661d3 USER32!MessageBoxWorker+0x2ba
0013f870 7e466278 USER32!MessageBoxTimeoutW+0x7a
0013f8a4 7e450617 USER32!MessageBoxTimeoutA+0x9c
0013f8c4 7e4505cf USER32!MessageBoxExA+0x1b
0013f8e0 088098a9 USER32!MessageBoxA+0x45
...
...
...

0: kd> .process /r /p 888ffb60
Implicit process is now 888ffb60
Loading User Symbols

0: kd> !thread 88b14da8
...
...
...
ChildEBP RetAddr  Args to Child             
...
...
...
0013f8e0 088098a9 00000000 0013f944 088708f0 USER32!MessageBoxA+0×45
…
…
…

0: kd> dA 0013f944
0013f944  "Cannot contact database, Retry"

This immediately raised suspicion and looking at other threads in the same application revealed that many of them were trying to open a network connection, for example:

THREAD 87a70da8  Cid 0a04.0cc0  Teb: 7ff83000 Win32Thread: 00000000 WAIT: (UserRequest) UserMode Non-Alertable
    87d690b0  NotificationEvent
    87a70e98  NotificationTimer
IRP List:
    87af7bc8: (0006,0244) Flags: 00000000  Mdl: 00000000
Not impersonating
DeviceMap                 e14bec28
Owning Process            888ffb60       Image:         OUTLOOK.EXE
Wait Start TickCount      1267130        Ticks: 8515 (0:00:02:13.046)
Context Switch Count      18            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address msmapi32!FOpenThreadImpersonationToken (0×35f76963)
Start Address kernel32!BaseThreadStartThunk (0×7c810659)
Stack Init 9fbc5000 Current 9fbc4ca0 Base 9fbc5000 Limit 9fbc2000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 16
Kernel stack not resident.
ChildEBP RetAddr 
9fbc4cb8 804e1bd2 nt!KiSwapContext+0×2f
9fbc4cc4 804e1c1e nt!KiSwapThread+0×8a
9fbc4cec 8056d2f9 nt!KeWaitForSingleObject+0×1c2
9fbc4d50 804dd99f nt!NtWaitForSingleObject+0×9a
9fbc4d50 7c90eb94 nt!KiFastCallEntry+0xfc
1bd8f52c 7c90e9c0 ntdll!KiFastSystemCallRet
1bd8f530 7c8025cb ntdll!ZwWaitForSingleObject+0xc
1bd8f594 7c802532 kernel32!WaitForSingleObjectEx+0xa8
1bd8f5a8 77eec4c6 kernel32!WaitForSingleObject+0×12
1bd8f6a4 77eec8b7 RPCRT4!WS_Open+0×31d
1bd8f7c8 77eec96d RPCRT4!TCPOrHTTP_Open+0×19e
1bd8f800 77e83e8d RPCRT4!TCP_Open+0×55
1bd8f84c 77e843f7 RPCRT4!OSF_CCONNECTION::TransOpen+0×5e
1bd8f8b4 77e84581 RPCRT4!OSF_CCONNECTION::OpenConnectionAndBind+0xbc
1bd8f8f8 77e844d0 RPCRT4!OSF_CCALL::BindToServer+0×104
1bd8f95c 77e7f99c RPCRT4!OSF_BINDING_HANDLE::AllocateCCall+0×2b0
1bd8f98c 77e791c1 RPCRT4!OSF_BINDING_HANDLE::NegotiateTransferSyntax+0×28
1bd8f9a4 77e791f8 RPCRT4!I_RpcGetBufferWithObject+0×5b
1bd8f9b4 77e79825 RPCRT4!I_RpcGetBuffer+0xf
1bd8f9c4 77ef460b RPCRT4!NdrGetBuffer+0×28
1bd8fda4 35bae645 RPCRT4!NdrClientCall2+0×195
…
…
…

Looking at IRP showed the possible problem with network at TDI level:

0: kd> !irp 87af7bc8
Irp is active with 4 stacks 2 is current (= 0x87af7c5c)  No Mdl: No System Buffer: Thread 87a70da8:  Irp stack trace. 
     cmd  flg cl Device   File     Completion-Context
 [  0, 0]   0  0 00000000 00000000 00000000-00000000   
   Args: 00000000 00000000 00000000 00000000
>[  f, 3]   0 e1 897b0310 87bb24c8 a1ad7080-87b6f1f0 Success Error Cancel pending
        \Driver\Tcpip    MYTDI!WaitForNetwork
   Args: 00000000 87a33988 87a33af8 a1a57600
 [  f, 3]   0 e1 88c13020 87bb24c8 a1a6bea5-87a33988 Success Error Cancel pending
        \Driver\SYMTDI afd!AfdRestartSuperConnect
   Args: 00000000 87a33988 87a33af8 a1a57600
 [  e,31]   5  0 88bedf18 87d3af90 00000000-00000000   
        \Driver\AFD
   Args: 00000000 00000016 000120c7 1bd8f52c

- Dmitry Vostokov @ DumpAnalysis.org -

Comparing reference stack traces with the output of !process 0 ff command or just visually inspecting the long log and trying to spot anomalies is very difficult and largely based on personal experience with prior problem cases. A tool is needed and I’m currently writing the one. It will compare logs from problem memory dumps with reference stack traces and other information and automatically pinpoint any anomalies and highlight areas for more detailed manual inspection. This is similar to Kernel Memory Space Analyzer original intent but far more useful. Originally I thought about calling it WinDbg Log Analyzer but later decided to make it more general and extendable to other types of logs from different debuggers like GDB. Some people asked me the question: won’t a WinDbg debugger extension suffice? My answer was no - some companies cannot send complete, kernel and process memory dumps due to security considerations but they can send logs free from sensitive data as explained in my previous article:

Resolving security issues with crash dumps

Additionally I want it to be debugger independent at least in the second version and I want it to be web-based too and free from the choice of the hosting platform.  

Stay tuned because the working prototype will be soon as a command line tool first. I personally need it for my day-to-day job. The latter always was my primary motivation to create various tools to automate or semi-automate data gathering and improve customer problem analysis.

The next version will have front-end GUI and I still haven’t decided yet whether to employ embedded HTML control like IE, RichEdit or revive my old text processor project. I’m inclined to choose the former due to endless possibilities with HTML and its platform independence. The choice of command line tool written in C++/STL will help to port it to FreeBSD/Linux/Solaris and adapt to other debuggers like GDB/ADB. The latter is my “wild fantasy” at the moment but its good to think towards other platforms that slowly increase their presence in my professional life

Any suggestions are very welcome especially if you have dealt with large debugger logs including not only backtraces but also various synchronization objects, module information, timing and I/O packet distribution.

- Dmitry Vostokov @ DumpAnalysis.org -

Beginner users of WinDbg sometimes confuse the first 3 parameters (or 4 for x64) displayed by kb or kv commands with real function parameters: 

0:000> kbnL
 # ChildEBP RetAddr  Args to Child
00 002df5f4 0041167b 002df97c 00000000 7efdf000 ntdll!DbgBreakPoint
01 002df6d4 004115c9 00000000 40000000 00000001 CallingConventions!A::thiscallFunction+0×2b
02 002df97c 004114f9 00000001 40001000 00000002 CallingConventions!fastcallFunction+0×69
03 002dfbf8 0041142b 00000000 40000000 00000001 CallingConventions!cdeclFunction+0×59
04 002dfe7c 004116e8 00000000 40000000 00000001 CallingConventions!stdcallFunction+0×5b
05 002dff68 00411c76 00000001 005a2820 005a28c8 CallingConventions!wmain+0×38
06 002dffb8 00411abd 002dfff0 7d4e7d2a 00000000 CallingConventions!__tmainCRTStartup+0×1a6
07 002dffc0 7d4e7d2a 00000000 00000000 7efdf000 CallingConventions!wmainCRTStartup+0xd
08 002dfff0 00000000 00411082 00000000 000000c8 kernel32!BaseProcessStart+0×28

The calling sequence for it is:

stdcallFunction(0, 0x40000000, 1, 0x40001000, 2, 0x40002000) ->
cdeclFunction(0, 0x40000000, 1, 0x40001000, 2, 0x40002000) ->
fastcallFunction(0, 0x40000000, 1, 0x40001000, 2, 0x40002000) ->
A::thiscallFunction(0, 0x40000000, 1, 0x40001000, 2, 0x40002000)

and we see that only in the case of fastcall calling convention we have discrepancy due to the fact that the first 2 parameters are passed not via stack but through ECX and EDX:

0:000> ub 004114f9
CallingConventions!cdeclFunction+0x45
004114e5 push    ecx
004114e6 mov     edx,dword ptr [ebp+14h]
004114e9 push    edx
004114ea mov     eax,dword ptr [ebp+10h]
004114ed push    eax
004114ee mov     edx,dword ptr [ebp+0Ch]
004114f1 mov     ecx,dword ptr [ebp+8]
004114f4 call    CallingConventions!ILT+475(?fastcallFunctionYIXHHHHHHZ) (004111e0)

However if we have full symbols we can see all parameters:

0:000> .frame 2
02 002df97c 004114f9 CallingConventions!fastcallFunction+0x69

0:000> dv /i /V
prv param  002df974 @ebp-0x08               a = 0
prv param  002df968 @ebp-0x14               b = 1073741824
prv param  002df984 @ebp+0x08               c = 1
prv param  002df988 @ebp+0x0c               d = 1073745920
prv param  002df98c @ebp+0x10               e = 2
prv param  002df990 @ebp+0x14               f = 1073750016
prv local  002df7c7 @ebp-0x1b5             obj = class A
prv local  002df7d0 @ebp-0x1ac           dummy = int [100]

How does dv command know about values in ECX and EDX which were definitely overwritten by later code? This is because the called function prolog saved them as local variables which you can notice as negative offsets for EBP register in dv output above:

0:000> uf CallingConventions!fastcallFunction
CallingConventions!fastcallFunction
   32 00411560 push    ebp
   32 00411561 mov     ebp,esp
   32 00411563 sub     esp,27Ch
   32 00411569 push    ebx
   32 0041156a push    esi
   32 0041156b push    edi
   32 0041156c push    ecx
   32 0041156d lea     edi,[ebp-27Ch]
   32 00411573 mov     ecx,9Fh
   32 00411578 mov     eax,0CCCCCCCCh
   32 0041157d rep stos dword ptr es:[edi]
   32 0041157f pop     ecx
   32 00411580 mov     dword ptr [ebp-14h],edx
   32 00411583 mov     dword ptr [ebp-8],ecx
…
…
…

I call this pattern as False Function Parameters where double checks and knowledge of calling conventions are required. Sometimes this pattern is a consequence of another pattern that I previously called Optimized Code.

x64 stack traces don’t show any discrepancies except the fact that thiscall function parameters are shifted to the right:

0:000> kbL
RetAddr           : Args to Child                                                           : Call Site
00000001`40001397 : cccccccc`cccccccc cccccccc`cccccccc cccccccc`cccccccc cccccccc`cccccccc : ntdll!DbgBreakPoint
00000001`40001233 : 00000000`0012fa94 cccccccc`00000000 cccccccc`40000000 cccccccc`00000001 : CallingConventions!A::thiscallFunction+0×37
00000001`40001177 : cccccccc`00000000 cccccccc`40000000 cccccccc`00000001 cccccccc`40001000 : CallingConventions!fastcallFunction+0×93
00000001`400010c7 : cccccccc`00000000 cccccccc`40000000 cccccccc`00000001 cccccccc`40001000 : CallingConventions!cdeclFunction+0×87
00000001`400012ae : cccccccc`00000000 cccccccc`40000000 cccccccc`00000001 cccccccc`40001000 : CallingConventions!stdcallFunction+0×87
00000001`400018ec : 00000001`00000001 00000000`00481a80 00000000`00000000 00000001`400026ee : CallingConventions!wmain+0×4e
00000001`4000173e : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : CallingConventions!__tmainCRTStartup+0×19c
00000000`77d5964c : 00000000`77d59620 00000000`00000000 00000000`00000000 00000000`0012ffa8 : CallingConventions!wmainCRTStartup+0xe
00000000`00000000 : 00000001`40001730 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseProcessStart+0×29

How this can happen if the standard x64 calling convention passes the first 4 parameters via ECX, EDX, R8 and R9? This is because the called function prolog saved them on stack (this might not be true in the case of optimized code):

0:000> uf CallingConventions!fastcallFunction
CallingConventions!fastcallFunction
   32 00000001`400011a0 44894c2420      mov     dword ptr [rsp+20h],r9d
   32 00000001`400011a5 4489442418      mov     dword ptr [rsp+18h],r8d
   32 00000001`400011aa 89542410        mov     dword ptr [rsp+10h],edx
   32 00000001`400011ae 894c2408        mov     dword ptr [rsp+8],ecx
...
...
...

A::thiscallFunction function passes this pointer via ECX too and this explains the right shift of parameters.

Here is the C++ code I used for experimentation:

#include "stdafx.h"
#include <windows.h>

void __stdcall stdcallFunction (int, int, int, int, int, int);
void __cdecl cdeclFunction (int, int, int, int, int, int);
void __fastcall fastcallFunction (int, int, int, int, int, int);

class A
{
public:
 void thiscallFunction (int, int, int, int, int, int) { DebugBreak(); };
};

void __stdcall stdcallFunction (int a, int b, int c, int d, int e, int f)
{
 int dummy[100] = {0};

 cdeclFunction (a, b, c, d, e, f);
}

void __cdecl cdeclFunction (int a, int b, int c, int d, int e, int f)
{
 int dummy[100] = {0};

 fastcallFunction (a, b, c, d, e, f);
}

void __fastcall fastcallFunction (int a, int b, int c, int d, int e, int f)
{
 int dummy[100] = {0};

 A obj;

 obj.thiscallFunction (a, b, c, d, e, f);
}

int _tmain(int argc, _TCHAR* argv[])
{
 stdcallFunction (0, 0x40000000, 1, 0x40001000, 2, 0x40002000);

 return 0;
}

- Dmitry Vostokov @ DumpAnalysis.org -

Frame Pointer Omission pattern is the most visible compiler optimization technique and you can notice it in verbose stack traces:

0:000> kv
ChildEBP RetAddr
0012ee10 004737a7 application!MemCopy+0x17 (FPO: [3,0,2])
0012ef0c 35878c5b application!ProcessData+0×97 (FPO: [Uses EBP] [3,59,4])
WARNING: Frame IP not in any known module. Following frames may be wrong.
0012ef1c 72a0015b 0×35878c5b
0012ef20 a625e1b0 0×72a0015b
0012ef24 d938bcfe 0xa625e1b0
0012ef28 d4f91bb4 0xd938bcfe
0012ef2c c1c035ce 0xd4f91bb4
…
…
…

To recall FPO is a compiler optimization where ESP register is used to address local variables and parameters instead of EBP. EBP may or may not be used for other purposes. When it is used you will notice

FPO: [Uses EBP]

as in the trace above. For description of other FPO number triplets please see Debugging Tools for Windows help section “k, kb, kd, kp, kP, kv (Display Stack Backtrace)”

Running analysis command points to possible stack corruption:

PRIMARY_PROBLEM_CLASS:  STACK_CORRUPTION

BUGCHECK_STR:  APPLICATION_FAULT_STACK_CORRUPTION

FAULTING_IP:
application!MemCopy+17
00438637 f3a5 rep movs dword ptr es:[edi],dword ptr [esi]

Looking at EBP and ESP shows that they are mismatched:

0:000> r
eax=00000100 ebx=00a027f3 ecx=00000040 edx=0012ee58 esi=d938bcfe edi=0012ee58
eip=00438637 esp=0012ee0c ebp=00a02910 iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000202
application!MemCopy+0×17:
00438637 f3a5 rep movs dword ptr es:[edi],dword ptr [esi] es:0023:0012ee58=00000010 ds:0023:d938bcfe=????????

We might think about Local Buffer Overflow pattern here but two top stack trace lines are in accordance with each other:

0:000> ub 004737a7
application!ProcessData+0x80:
00473790 cmp     eax,edi
00473792 jb      application!ProcessData+0x72 (00473782)
00473794 mov     ecx,dword ptr [esp+104h]
0047379b push    esi
0047379c lea     edx,[esp+38h]
004737a0 push    ecx
004737a1 push    edx
004737a2 call    application!MemCopy (00438620)

So perhaps EBP value differs greatly from ESP due to its usage as general purpose register and in fact there was no any stack corruption. Despite using public symbols we have the instance of Incorrect Stack Trace pattern and we might want to reconstruct it manually. Let’s search for EBP value on raw stack below the crash point:

0:000> !teb
TEB at 7ffdf000
    ExceptionList:        0012ffb0
    StackBase:            00130000
    StackLimit:           00126000
    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7ffdf000
    EnvironmentPointer:   00000000
    ClientId:             0000660c . 00005890
    RpcHandle:            00000000
    Tls Storage:          00000000
    PEB Address:          7ffd9000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0

0:000> dds  00126000 00130000
00126000  00000000
00126004  00000000
00126008  00000000
...
...
...
0012eb0c  00a02910
0012eb10  7c90e25e ntdll!NtRaiseException+0xc
0012eb14  7c90eb15 ntdll!KiUserExceptionDispatcher+0x29
0012eb18  0012eb24
0012eb1c  0012eb40
0012eb20  00000000
0012eb24  c0000005
0012eb28  00000000
0012eb2c  00000000
0012eb30  00438637 application!MemCopy+0x17
0012eb34  00000002
0012eb38  00000000
0012eb3c  d938bcfe
...
...
...
0012ebf4  00a02910
0012ebf8  00438637 application!MemCopy+0×17
0012ebfc  0000001b
…
…
…
0012f134  00436323 application!ConstructInfo+0×113
0012f138  00a02910
0012f13c  0000011c
…
…
…

Let’s see what functions ConstructInfo calls:

0:000> ub 00436323
application!ConstructInfo+0x103
00436313 lea     edx,[esp+10h]
00436317 push    edx
00436318 push    eax
00436319 push    30h
0043631b push    ecx
0043631c push    ebx
0043631d push    ebp
0043631e call    application!EnvelopeData (00438bf0)

We notice EBP was pushed prior to calling EnvelopeData. If we disassemble this function we would see that it calls ProcessData from our partial stack trace: 

0:000> uf 00438bf0
application!EnvelopeData:
00438bf0 sub     esp,1F4h
00438bf6 push    ebx
00438bf7 mov     ebx,dword ptr [esp+20Ch]
00438bfe test    ebx,ebx
00438c00 push    ebp
...
...
...
00438c76 rep stos byte ptr es:[edi]
00438c78 lea     eax,[esp+14h]
00438c7c push    eax
00438c7d push    ebp
00438c7e call    application!ProcessData (00473710)
00438c83 pop     edi
00438c84 pop     esi

Let’s try elaborate form of k command and supply it with custom ESP and EBP values pointing to

0012f134  00436323 application!ConstructInfo+0×113

and also EIP of the fault:

0:000> k L=0012f134 0012f134 00438637
ChildEBP RetAddr 
0012f1cc 00435a65 application!MemCopy+0×17
0012f28c 0043532e application!ClientHandleServerRequest+0×395
0012f344 00434fcd application!Accept+0×23
0012f374 0042e4f3 application!DataArrival+0×17d
0012f43c 0041aea9 application!ProcessInput+0×98
0012ff0c 0045b278 application!AppMain+0xda
0012ff24 0041900e application!WinMain+0×78
0012ffc0 7c816fd7 application!WinMainCRTStartup+0×134
0012fff0 00000000 kernel32!BaseProcessStart+0×23

We see that although it misses some initial frames after MemCopy we aided WinDbg to walk to the bottom of the stack and reconstruct the plausible stack trace for us.

- Dmitry Vostokov @ DumpAnalysis.org -

Special Stack Trace pattern is about stack traces not present in normal crash dumps. The similar pattern is called Special Process which is about processes not running during normal operation or highly domain specific processes that are the sign of certain software environment, for example, OS running inside VMWare or VirtualPC. Here I’ll show one example when identifying specific process led to successful problem identification inside a complete memory dump.

Inspection of running processes shows the presence of Dr. Watson:

5: kd> !process 0 0
**** NT ACTIVE PROCESS DUMP ****
PROCESS 89d9b648  SessionId: none  Cid: 0004    Peb: 00000000  ParentCid: 0000
    DirBase: 54d5d020  ObjectTable: e1000e20  HandleCount: 1711.
    Image: System

PROCESS 8979b758  SessionId: none  Cid: 01b0    Peb: 7ffdd000  ParentCid: 0004
    DirBase: 54d5d040  ObjectTable: e181d8b0  HandleCount:  29.
    Image: smss.exe

PROCESS 89793cf0  SessionId: 0  Cid: 01e0    Peb: 7ffde000  ParentCid: 01b0
    DirBase: 54d5d060  ObjectTable: e13eea10  HandleCount: 1090.
    Image: csrss.exe

...
...
...

PROCESS 8797a600  SessionId: 1  Cid: 17d0    Peb: 7ffdc000  ParentCid: 1720
    DirBase: 54d5d8c0  ObjectTable: e2870af8  HandleCount: 243.
    Image: explorer.exe

PROCESS 87966d88  SessionId: 2  Cid: 0df0    Peb: 7ffd4000  ParentCid: 01b0
    DirBase: 54d5d860  ObjectTable: e284cd48  HandleCount:  53.
    Image: csrss.exe

PROCESS 879767c8  SessionId: 0  Cid: 0578    Peb: 7ffde000  ParentCid: 0ca8
    DirBase: 54d5d8a0  ObjectTable: e2c05268  HandleCount: 180.
    Image: drwtsn32.exe

Inspecting stack traces shows that drwtsn32.exe is waiting for a debugger event so there must be some debugging target (debuggee):

5: kd> .process /r /p 879767c8
Implicit process is now 879767c8
Loading User Symbols

5: kd> !process 879767c8
PROCESS 879767c8  SessionId: 0  Cid: 0578    Peb: 7ffde000  ParentCid: 0ca8
    DirBase: 54d5d8a0  ObjectTable: e2c05268  HandleCount: 180.
    Image: drwtsn32.exe
    VadRoot 88a33cd0 Vads 59 Clone 0 Private 1737. Modified 10792. Locked 0.
    DeviceMap e10028e8
    Token                             e2ee2330
    ElapsedTime                       00:01:12.703
    UserTime                          00:00:00.203
    KernelTime                        00:00:00.031
    QuotaPoolUsage[PagedPool]         52092
    QuotaPoolUsage[NonPagedPool]      2360
    Working Set Sizes (now,min,max)  (2488, 50, 345) (9952KB, 200KB, 1380KB)
    PeakWorkingSetSize                2534
    VirtualSize                       34 Mb
    PeakVirtualSize                   38 Mb
    PageFaultCount                    13685
    MemoryPriority                    BACKGROUND
    BasePriority                      6
    CommitCharge                      1927

THREAD 87976250  Cid 0578.04bc  Teb: 7ffdd000 Win32Thread: bc14a008 WAIT: (Unknown) UserMode Non-Alertable
    87976558  Thread
Not impersonating
DeviceMap                 e10028e8
Owning Process            879767c8       Image:         drwtsn32.exe
Wait Start TickCount      13460          Ticks: 4651 (0:00:01:12.671)
Context Switch Count      15                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address drwtsn32!mainCRTStartup (0x01007c1d)
Start Address kernel32!BaseProcessStartThunk (0x7c8217f8)
Stack Init f433b000 Current f433ac60 Base f433b000 Limit f4337000 Call 0
Priority 6 BasePriority 6 PriorityDecrement 0
ChildEBP RetAddr 
f433ac78 80833465 nt!KiSwapContext+0x26
f433aca4 80829a62 nt!KiSwapThread+0x2e5
f433acec 80938d0c nt!KeWaitForSingleObject+0x346
f433ad50 8088978c nt!NtWaitForSingleObject+0x9a
f433ad50 7c9485ec nt!KiFastCallEntry+0xfc
0007fe98 7c821c8d ntdll!KiFastSystemCallRet
0007feac 01005557 kernel32!WaitForSingleObject+0x12
0007ff0c 01003ff8 drwtsn32!NotifyWinMain+0x1ba
0007ff44 01007d4c drwtsn32!main+0x31
0007ffc0 7c82f23b drwtsn32!mainCRTStartup+0x12f
0007fff0 00000000 kernel32!BaseProcessStart+0x23

THREAD 87976558  Cid 0578.0454  Teb: 7ffdc000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
    89de2e50  NotificationEvent
    879765d0  NotificationTimer
Not impersonating
DeviceMap                 e10028e8
Owning Process            879767c8       Image:         drwtsn32.exe
Wait Start TickCount      18102          Ticks: 9 (0:00:00:00.140)
Context Switch Count      1163            
UserTime                  00:00:00.203
KernelTime                00:00:00.031
Win32 Start Address drwtsn32!DispatchDebugEventThread (0x01003d6d)
Start Address kernel32!BaseThreadStartThunk (0x7c8217ec)
Stack Init f4e26000 Current f4e25be8 Base f4e26000 Limit f4e23000 Call 0
Priority 6 BasePriority 6 PriorityDecrement 0
ChildEBP RetAddr 
f4e25c00 80833465 nt!KiSwapContext+0x26
f4e25c2c 80829a62 nt!KiSwapThread+0x2e5
f4e25c74 809a06ab nt!KeWaitForSingleObject+0x346
f4e25d4c 8088978c nt!NtWaitForDebugEvent+0xd5
f4e25d4c 7c9485ec nt!KiFastCallEntry+0xfc
0095ed20 60846f8f ntdll!KiFastSystemCallRet
0095ee6c 60816ecf dbgeng!LiveUserTargetInfo::WaitForEvent+0x1fa
0095ee88 608170d3 dbgeng!WaitForAnyTarget+0x45
0095eecc 60817270 dbgeng!RawWaitForEvent+0x15f
0095eee4 01003f8d dbgeng!DebugClient::WaitForEvent+0×80
0095ffb8 7c824829 drwtsn32!DispatchDebugEventThread+0×220
0095ffec 00000000 kernel32!BaseThreadStart+0×34

Knowing that a debugger suspends threads in a debuggee (Suspended Thread pattern) we see the problem process indeed:

5: kd> !process 0 2
**** NT ACTIVE PROCESS DUMP ****

...
...
...

PROCESS 898285b0  SessionId: 0  Cid: 0ca8    Peb: 7ffda000  ParentCid: 022c
    DirBase: 54d5d500  ObjectTable: e2776880  HandleCount:   2.
    Image: svchost.exe

THREAD 888b8668  Cid 0ca8.1448  Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
SuspendCount 2
  888b87f8  Semaphore Limit 0×2

Dumping its thread stacks shows only one system thread where we normally expect plenty of them originated from user space. There is also the presence of a debug port:

5: kd> .process /r /p 898285b0
Implicit process is now 898285b0
Loading User Symbols

5: kd> !process 898285b0
PROCESS 898285b0  SessionId: 0  Cid: 0ca8    Peb: 7ffda000  ParentCid: 022c
    DirBase: 54d5d500  ObjectTable: e2776880  HandleCount:   2.
    Image: svchost.exe
    VadRoot 88953220 Vads 209 Clone 0 Private 901. Modified 3. Locked 0.
    DeviceMap e10028e8
    Token                             e27395b8
    ElapsedTime                       00:03:25.640
    UserTime                          00:00:00.156
    KernelTime                        00:00:00.234
    QuotaPoolUsage[PagedPool]         82988
    QuotaPoolUsage[NonPagedPool]      8824
    Working Set Sizes (now,min,max)  (2745, 50, 345) (10980KB, 200KB, 1380KB)
    PeakWorkingSetSize                2819
    VirtualSize                       82 Mb
    PeakVirtualSize                   83 Mb
    PageFaultCount                    4519
    MemoryPriority                    BACKGROUND
    BasePriority                      6
    CommitCharge                      1380
    DebugPort                         89de2e50

THREAD 888b8668  Cid 0ca8.1448  Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
SuspendCount 2
    888b87f8  Semaphore Limit 0x2
Not impersonating
DeviceMap                 e10028e8
Owning Process            898285b0       Image:         svchost.exe
Wait Start TickCount      13456          Ticks: 4655 (0:00:01:12.734)
Context Switch Count      408            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Start Address driverA!DriverThread (0xf6fb8218)
Stack Init f455b000 Current f455a3ac Base f455b000 Limit f4558000 Call 0
Priority 6 BasePriority 6 PriorityDecrement 0
ChildEBP RetAddr 
f455a3c4 80833465 nt!KiSwapContext+0x26
f455a3f0 80829a62 nt!KiSwapThread+0x2e5
f455a438 80833178 nt!KeWaitForSingleObject+0x346
f455a450 8082e01f nt!KiSuspendThread+0x18
f455a498 80833480 nt!KiDeliverApc+0x117
f455a4d0 80829a62 nt!KiSwapThread+0x300
f455a518 f6fb7f13 nt!KeWaitForSingleObject+0x346
f455a548 f4edd457 driverA!WaitForSingleObject+0x75
f455a55c f4edcdd8 driverB!DeviceWaitForRead+0x19
f455ad90 f6fb8265 driverB!InputThread+0x17e
f455adac 80949b7c driverA!DriverThread+0x4d
f455addc 8088e062 nt!PspSystemThreadStartup+0x2e
00000000 00000000 nt!KiThreadStartup+0x16

The most likely scenario was that svchost.exe experienced an unhandled exception that triggered the launch of a postmortem debugger such as Dr. Watson.

Other similar examples this pattern might include the presence of WerFault.exe on Vista, NTSD and other JIT debuggers running.

- Dmitry Vostokov @ DumpAnalysis.org -

It is very easy to become a publisher nowadays. Much easier than I thought. I registered myself as a publisher under the name of OpenTask which is my registered business name in Ireland. I also got the list of ISBN numbers and therefore can announce product details for the first volume of Memory Dump Analysis Anthology series:

Memory Dump Analysis Anthology, Volume 1

• Paperback: 720 pages (*)
• ISBN-13: 978-0-9558328-0-2

• Hardcover: 720 pages (*)
• ISBN-13: 978-0-9558328-1-9

• Author: Dmitry Vostokov
• Publisher: Opentask (15 Apr 2008)
• Language: English
• Product Dimensions: 22.86 x 15.24

(*) subject to change 

PDF file will be available for download too.

- Dmitry Vostokov @ DumpAnalysis.org -

Most of the time threads are not suspended explicitly. If you look at active and waiting threads in kernel and complete memory dumps their SuspendCount member is 0:

THREAD 88951bc8  Cid 03a4.0d24  Teb: 7ffaa000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
    889d6a78  Semaphore Limit 0x7fffffff
    88951c40  NotificationTimer
Not impersonating
DeviceMap                 e1b80b98
Owning Process            888a9d88       Image:         svchost.exe
Wait Start TickCount      12669          Ticks: 5442 (0:00:01:25.031)
Context Switch Count      3            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address RPCRT4!ThreadStartRoutine (0x77c4b0f5)
Start Address kernel32!BaseThreadStartThunk (0x7c8217ec)
Stack Init f482f000 Current f482ec0c Base f482f000 Limit f482c000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
f482ec24 80833465 nt!KiSwapContext+0x26
f482ec50 80829a62 nt!KiSwapThread+0x2e5
f482ec98 809226bd nt!KeWaitForSingleObject+0x346
f482ed48 8088978c nt!NtReplyWaitReceivePortEx+0x521
f482ed48 7c9485ec nt!KiFastCallEntry+0xfc (TrapFrame @ f482ed64)
00efff84 77c58792 ntdll!KiFastSystemCallRet
00efff8c 77c5872d RPCRT4!RecvLotsaCallsWrapper+0xd
00efffac 77c4b110 RPCRT4!BaseCachedThreadRoutine+0x9d
00efffb8 7c824829 RPCRT4!ThreadStartRoutine+0x1b
00efffec 00000000 kernel32!BaseThreadStart+0x34

5: kd> dt _KTHREAD 88951bc8
ntdll!_KTHREAD
   +0x000 Header           : _DISPATCHER_HEADER
   +0x010 MutantListHead   : _LIST_ENTRY [ 0x88951bd8 - 0x88951bd8 ]
   +0x018 InitialStack     : 0xf482f000
   +0x01c StackLimit       : 0xf482c000
   +0x020 KernelStack      : 0xf482ec0c
   +0x024 ThreadLock       : 0
   +0x028 ApcState         : _KAPC_STATE
...
...
...
   +0x14f FreezeCount      : 0 ''
   +0×150 SuspendCount     : 0 ”
…
…
…

You won’t find SuspendCount in reference stack traces. Only when some other thread explicitly suspends another thread the latter has non-zero suspend count. Suspended threads are excluded from thread scheduling and therefore can be considered as blocked. This might be the sign of a debugger present, for example, all threads in a process are suspended when a user debugger is processing a debugger event like a breakpoint or access violation exception. In this case !process 0 ff command output shows SuspendCount value:

THREAD 888b8668  Cid 0ca8.1448  Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
SuspendCount 2
    888b87f8  Semaphore Limit 0×2
Not impersonating
DeviceMap                 e10028e8
Owning Process            898285b0       Image:         processA.exe
Wait Start TickCount      13456          Ticks: 4655 (0:00:01:12.734)
Context Switch Count      408            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Start Address driver!DriverThread (0xf6fb8218)
Stack Init f455b000 Current f455a3ac Base f455b000 Limit f4558000 Call 0
Priority 6 BasePriority 6 PriorityDecrement 0
ChildEBP RetAddr 
f455a3c4 80833465 nt!KiSwapContext+0×26
f455a3f0 80829a62 nt!KiSwapThread+0×2e5
f455a438 80833178 nt!KeWaitForSingleObject+0×346
f455a450 8082e01f nt!KiSuspendThread+0×18
f455a498 80833480 nt!KiDeliverApc+0×117
f455a4d0 80829a62 nt!KiSwapThread+0×300
f455a518 f6fb7f13 nt!KeWaitForSingleObject+0×346
f455a548 f4edd457 driver!WaitForSingleObject+0×75
f455a55c f4edcdd8 driver!DeviceWaitForRead+0×19
f455ad90 f6fb8265 driver!InputThread+0×17e
f455adac 80949b7c driver!DriverThread+0×4d
f455addc 8088e062 nt!PspSystemThreadStartup+0×2e
00000000 00000000 nt!KiThreadStartup+0×16

5: kd> dt _KTHREAD 888b8668
ntdll!_KTHREAD
   +0x000 Header           : _DISPATCHER_HEADER
   +0x010 MutantListHead   : _LIST_ENTRY [ 0x888b8678 - 0x888b8678 ]
   +0x018 InitialStack     : 0xf455b000
   +0x01c StackLimit       : 0xf4558000
   +0x020 KernelStack      : 0xf455a3ac
   +0x024 ThreadLock       : 0
...
...
...
   +0x14f FreezeCount      : 0 ''
   +0×150 SuspendCount     : 2 ”
…
…
…

I call this pattern Suspended Thread. It should rise suspicion bar and in some cases coupled with Special Process pattern can lead to immediate problem identification.

- Dmitry Vostokov @ DumpAnalysis.org -

In order to maintain virtual to physical address translation OS needs page tables. These tables occupy memory too. If there is not enough memory for new tables the system will fail to create processes, allocate I/O buffers and memory from pools. You might see the following diagnostic message from WinDbg:

4: kd> !vm

*** Virtual Memory Usage ***
 Physical Memory:      851422 (   3405688 Kb)
 Page File: \??\C:\pagefile.sys
   Current:   2095104 Kb  Free Space:   2081452 Kb
   Minimum:   2095104 Kb  Maximum:      4190208 Kb
 Available Pages:      683464 (   2733856 Kb)
 ResAvail Pages:       800927 (   3203708 Kb)
 Locked IO Pages:         145 (       580 Kb)
 Free System PTEs:      23980 (     95920 Kb)

 ******* 356363 system PTE allocations have failed ******

 Free NP PTEs:           6238 (     24952 Kb)
 Free Special NP:           0 (         0 Kb)
 Modified Pages:          482 (      1928 Kb)
 Modified PF Pages:       482 (      1928 Kb)
 NonPagedPool Usage:    18509 (     74036 Kb)
 NonPagedPool Max:      31970 (    127880 Kb)
 PagedPool 0 Usage:      8091 (     32364 Kb)
 PagedPool 1 Usage:      2495 (      9980 Kb)
 PagedPool 2 Usage:      2580 (     10320 Kb)
 PagedPool 3 Usage:      2552 (     10208 Kb)
 PagedPool 4 Usage:      2584 (     10336 Kb)
 PagedPool Usage:       18302 (     73208 Kb)
 PagedPool Maximum:     39936 (    159744 Kb)

 ********** 48530 pool allocations have failed **********

 Shared Commit:          5422 (     21688 Kb)
 Special Pool:              0 (         0 Kb)
 Shared Process:         5762 (     23048 Kb)
 PagedPool Commit:      18365 (     73460 Kb)
 Driver Commit:          2347 (      9388 Kb)
 Committed pages:      129014 (    516056 Kb)
 Commit limit:        1342979 (   5371916 Kb)

We also see another diagnostic message about pool allocation failures which could be the consequence of PTE allocation failures.

The cause of system PTE allocation failures might be incorrect value of SystemPages registry key that needs to be adjusted as explained in the following TechNet article:

The number of free page table entries is low, which can cause system instability

Another cause would be /3GB boot option on x86 systems especially used for hosting terminal sessions. This case is explained in Brad Rutkowski’s blog post which also shows how to detect /3GB kernel and complete memory dumps:

Consequences of running 3GB and PAE together  

In our case the system was booted with /3GB:

4: kd> vertarget
Windows Server 2003 Kernel Version 3790 (Service Pack 2) MP (8 procs) Free x86 compatible
Product: Server, suite: Enterprise TerminalServer
Built by: 3790.srv03_sp2_gdr.070304-2240
Kernel base = 0xe0800000 PsLoadedModuleList = 0xe08af9c8
Debug session time: Fri Feb  1 09:10:17.703 2008 (GMT+0)
System Uptime: 6 days 17:14:45.528

Normal Windows 2003 systems have different kernel base address which can be checked from Reference Stack Traces for Windows Server 2003 (Virtual Memory section): 

kd> vertarget
Windows Server 2003 Kernel Version 3790 (Service Pack 2) UP Free x86 compatible
Product: Server, suite: Enterprise TerminalServer SingleUserTS
Built by: 3790.srv03_sp2_rtm.070216-1710
Kernel base = 0×80800000 PsLoadedModuleList = 0×8089ffa8
Debug session time: Wed Jan 30 17:54:13.390 2008 (GMT+0)
System Uptime: 0 days 0:30:12.000

- Dmitry Vostokov @ DumpAnalysis.org -