Software Diagnostics Library

Data Contents Locality is a comparative pattern that helps not only in identifying the class of the problem but increases our confidence and degree of belief in the specific hypothesis. Suppose we have a database of notes of previous problems. If we see the same or similar data accessed in the new memory dump we might suppose that the issue is similar. If Data Contents Locality is complemented by Code Path Locality (similar partial stack traces and code residues) it even  greater boosts our confidence in suggesting specific troubleshooting steps, recommending fixes and service packs or routing the problem to the next support or development service supply chain (like escalating the issue).

Suppose we got a new kernel memory dump with IRQL_NOT_LESS_OR_EQUAL  (A) bugcheck pointing to our module and we notice the write access to a structure in a nonpaged pool having specific pool tag:

3: kd> .trap 9ee8d9b0
ErrCode = 00000002
eax=85407650 ebx=858f6650 ecx=ffffffff edx=85407648 esi=858f65a8 edi=858f6620
eip=8083df4c esp=9ee8da24 ebp=9ee8da64 iopl=0 nv up ei pl zr na pe nc
cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000 efl=00010246
nt!KeWaitForSingleObject+0x24f:
8083df4c 8919            mov     dword ptr [ecx],ebx  ds:0023:ffffffff=????????

STACK_TEXT: 
9ee8d9b0 8083df4c badb0d00 85407648 00000000 nt!KiTrap0E+0x2a7
9ee8da64 80853f3f 85407648 0000001d 00000000 nt!KeWaitForSingleObject+0×24f
9ee8da7c 8081d45f 865b18d8 854076b0 f4b9e53b nt!KiAcquireFastMutex+0×13
9ee8da88 f4b9e53b 00000004 86940110 85407638 nt!ExAcquireFastMutex+0×20
9ee8daa8 f4b9ed98 85407638 00000000 86940110 driver!Query+0×143
[…]

3: kd> !pool 85407648
Pool page 85407648 region is Nonpaged pool
 85407000 size:   80 previous size:    0  (Allocated)  Mdl
 85407080 size:   30 previous size:   80  (Allocated)  Even (Protected)
 854070b0 size:   28 previous size:   30  (Allocated)  Ntfn
 854070d8 size:   28 previous size:   28  (Allocated)  NtFs
 85407100 size:   28 previous size:   28  (Allocated)  Ntfn
[...]
 85407570 size:   28 previous size:   70  (Allocated)  Ntfn
 85407598 size:   98 previous size:   28  (Allocated)  File (Protected)
*85407630 size:   b0 previous size:   98  (Free ) *DrvA

Dumping the memory address passed to KeWaitForSingleObject shows simple but peculiar pattern:

3: kd> dd 85407648
85407648  ffffffff ffffffff ffffffff ffffffff
85407658  ffffffff ffffffff ffffffff ffffffff
85407668  ffffffff ffffffff ffffffff ffffffff
85407678  ffffffff ffffffff ffffffff ffffffff
85407688  ffffffff ffffffff ffffffff ffffffff
85407698  ffffffff ffffffff ffffffff ffffffff
854076a8  ffffffff ffffffff ffffffff ffffffff
854076b8  ffffffff ffffffff ffffffff ffffffff

We find several similar cases in our database but with different overall call stacks except the topmost wait call. Then we notice that in previous cases there were mutants associated with thread structure and we have the same now:

0: kd> !thread
THREAD 858f65a8 Cid 474c.4530 Teb: 7ffdf000 Win32Thread: bc012410 RUNNING on processor 0
[…]

3: kd> dt /r _KTHREAD 858f65a8 MutantListHead
nt!_KTHREAD
   +0×010 MutantListHead : _LIST_ENTRY [ 0×86773040 - 0×86773040 ]

3: kd> !pool 86773040
Pool page 86773040 region is Nonpaged pool
*86773000 size:   50 previous size:    0  (Allocated) *Muta (Protected)
  Pooltag Muta : Mutant objects
[…]

This narrows the issue to only a few previous cases. In one previous case WaitBlockList associated with a thread structure had 0xffffffff in its pointers. Our block shows the same pattern:

0: kd> dt -r _KTHREAD 858f65a8  WaitBlockList
nt!_KTHREAD
   +0×054 WaitBlockList : 0×858f6650 _KWAIT_BLOCK

0: kd> dt _KWAIT_BLOCK 0x858f6650
nt!_KWAIT_BLOCK
   +0x000 WaitListEntry    : _LIST_ENTRY [ 0x85407650 - 0xffffffff ]
   +0×008 Thread           : 0×858f65a8 _KTHREAD
   +0×00c Object           : 0×85407648
   +0×010 NextWaitBlock    : 0×858f6650 _KWAIT_BLOCK
   +0×014 WaitKey          : 0
   +0×016 WaitType         : 0×1 ”
   +0×017 SpareByte        : 0 ”

We have probably narrowed down the issue to a specific case. Although this doesn’t work always and mostly based on intuition there are spectacular cases where it really helps in troubleshooting. Here is another example where the contents of EDI register from exception context provided specific recommendation hints. When looking at the crash point we see an instance of Wild Code pattern:

0:000> kv
ChildEBP RetAddr  Args to Child             
WARNING: Frame IP not in any known module. Following frames may be wrong.
49ab5bba 00000000 00000000 00000000 00000000 0x60f1011a

0:000> r
eax=38084ff0 ebx=52303340 ecx=963f1416 edx=0000063d esi=baaff395 edi=678c5804
eip=60f1011a esp=5a9d0f48 ebp=49ab5bba iopl=0  nv up ei pl nz na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000  efl=00210206
60f1011a cd01            int     1

0:000> u
60f1011a cd01            int     1
60f1011c cc              int     3
60f1011d 8d              ???
60f1011e c0eb02          shr     bl,2
60f10121 0f840f31cd01    je      62be3236
60f10127 8d              ???
60f10128 c0cc0f          ror     ah,0Fh
60f1012b 0bce            or      ecx,esi

Looking at raw stack data we notice the presence of a specific component that is known to patch the process import table. Applying techniques outlined in Hooked Functions pattern we notice two different 3rd-party components that patched two different modules (kernel32 and user32):

0:000> !chkimg -lo 50 -d !kernel32 -v
Searching for module with expression: !kernel32
Will apply relocation fixups to file used for comparison
Will ignore NOP/LOCK errors
Will ignore patched instructions
Image specific ignores will be applied
Comparison image path: c:\mss\kernel32.dll\4626487F102000\kernel32.dll
No range specified

Scanning section:    .text
Size: 564709
Range to scan: 77e41000-77ecade5
    77e41ae5-77e41ae9  5 bytes - kernel32!LoadLibraryExW
 [ 6a 34 68 48 7b:e9 16 e5 f4 07 ]
    77e44a8a-77e44a8e  5 bytes - kernel32!WaitNamedPipeW (+0×2fa5)
 [ 8b ff 55 8b ec:e9 71 b5 f9 07 ]
    77e5106a-77e5106e  5 bytes - kernel32!CreateProcessInternalW (+0xc5e0)
[…]
Total bytes compared: 564709(100%)
Number of errors: 49
49 errors : !kernel32 (77e41ae5-77e9aa16)

0:000> u 77e41ae5
kernel32!LoadLibraryExW:
77e41ae5 jmp     7fd90000
77e41aea out     77h,al
77e41aec call    kernel32!_SEH_prolog (77e6b779)
77e41af1 xor     edi,edi
77e41af3 mov     dword ptr [ebp-28h],edi
77e41af6 mov     dword ptr [ebp-2Ch],edi
77e41af9 mov     dword ptr [ebp-20h],edi
77e41afc cmp     dword ptr [ebp+8],edi

0:000> u 7fd90000
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for ComponentA.dll -
7fd90000 jmp     ComponentA!DllUnregisterServer+0×2700 (678c4280)
7fd90005 push    34h
7fd90007 push    offset kernel32!`string’+0xc (77e67b48)
7fd9000c jmp     kernel32!LoadLibraryExW+0×7 (77e41aec)
7fd90011 add     byte ptr [eax],al
7fd90013 add     byte ptr [eax],al
7fd90015 add     byte ptr [eax],al
7fd90017 add     byte ptr [eax],al

0:000> !chkimg -lo 50 -d !user32 -v
Searching for module with expression: !user32
Will apply relocation fixups to file used for comparison
Will ignore NOP/LOCK errors
Will ignore patched instructions
Image specific ignores will be applied
Comparison image path: c:\mss\user32.dll\45E7BFD692000\user32.dll
No range specified

Scanning section:    .text
Size: 396943
Range to scan: 77381000-773e1e8f
    77383f38-77383f3c  5 bytes - user32!EnumDisplayDevicesW
 [ 8b ff 55 8b ec:e9 c3 c0 82 08 ]
    77384406-7738440a  5 bytes - user32!EnumDisplaySettingsExW (+0×4ce)
 [ 8b ff 55 8b ec:e9 f5 bb 7e 08 ]
    773844d9-773844dd  5 bytes - user32!EnumDisplaySettingsW (+0xd3)
 [ 8b ff 55 8b ec:e9 22 bb 80 08 ]
    7738619b-7738619f  5 bytes - user32!EnumDisplayDevicesA (+0×1cc2)
 [ 8b ff 55 8b ec:e9 60 9e 83 08 ]
    7738e985-7738e989  5 bytes - user32!CreateWindowExA (+0×87ea)
 [ 8b ff 55 8b ec:e9 76 16 8c 08 ]
[…]
Total bytes compared: 396943(100%)
Number of errors: 119
119 errors : !user32 (77383f38-773c960c)

0:000> u 77383f38
user32!EnumDisplayDevicesW:
77383f38 e9c3c08208      jmp     7fbb0000
77383f3d 81ec58030000    sub     esp,358h
77383f43 a1ac243e77      mov     eax,dword ptr [user32!__security_cookie (773e24ac)]
77383f48 8b5508          mov     edx,dword ptr [ebp+8]
77383f4b 83a5acfcffff00  and     dword ptr [ebp-354h],0
77383f52 53              push    ebx
77383f53 56              push    esi
77383f54 8b7510          mov     esi,dword ptr [ebp+10h]

0:000> u 7fbb0000
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for ComponentB.dll -
7fbb0000 e91b43d5e5      jmp     ComponentB+0×4320 (65904320)
7fbb0005 8bff            mov     edi,edi
7fbb0007 55              push    ebp
7fbb0008 8bec            mov     ebp,esp
7fbb000a e92e3f7df7      jmp     user32!EnumDisplayDevicesW+0×5 (77383f3d)
7fbb000f 0000            add     byte ptr [eax],al
7fbb0011 0000            add     byte ptr [eax],al
7fbb0013 0000            add     byte ptr [eax],al

Which one should we try to eliminate first to test our assumption that they somehow resulted in application faults? Looking at register context again we see that one specific register (EDI) has a value that lies in ComponentA address range:

0:000> r
eax=38084ff0 ebx=52303340 ecx=963f1416 edx=0000063d esi=baaff395 edi=678c5804
eip=60f1011a esp=5a9d0f48 ebp=49ab5bba iopl=0  nv up ei pl nz na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000 efl=00210206
60f1011a cd01            int     1

0:000> lm
start    end        module name
00400000 01901000   Application
[...]
678c0000 6791d000   ComponentA   ComponentA.DLL
[…]

- Dmitry Vostokov @ DumpAnalysis.org -

Not My Version is another basic pattern of DLL Hell variety. It is when we look at the component timestamps and paths and realize that that one of the modules from the production environment is older than we had during development and testing. The lmft WinDbg command will produce the necessary output. If there are many modules we might want to create a CAD graph (Component Age Diagram) to spot anomalies. Component version check is one of the basic troubleshooting and system administration activities that will be fully illustrated in the forthcoming book “Crash Dump Analysis for System Administrators and Support Engineers” (ISBN-13: 978-1-906717-02-5). Here is one example (module start and end load addresses are removed for visual clarity):

0:000> kL
Child-SP          RetAddr           Call Site
00000000`0012fed8 00000001`40001093 MyDLL!fnMyDLL
00000000`0012fee0 00000001`40001344 2DLLs+0×1093
00000000`0012ff10 00000000`773acdcd 2DLLs+0×1344
00000000`0012ff60 00000000`774fc6e1 kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0×1d


0:000> lmft
module name
MyDLL    C:\OLD\MyDLL.dll Wed Jun 18 14:49:13 2004
user32   C:\Windows\System32\user32.dll Thu Feb 15 05:22:33 2007
kernel32 C:\Windows\System32\kernel32.dll Thu Nov 02 11:14:48 2006
ntdll    C:\Windows\System32\ntdll.dll Thu Nov 02 11:16:02 2006
2DLLs    C:\2DLLs\2DLLs.exe Thu Jun 19 10:46:44 2008 (485A2B04)
uxtheme  C:\Windows\System32\uxtheme.dll Thu Nov 02 11:15:07 2006
rpcrt4   C:\Windows\System32\rpcrt4.dll Tue Jul 17 05:21:15 2007
lpk      C:\Windows\System32\lpk.dll Thu Nov 02 11:12:33 2006
oleaut32 C:\Windows\System32\oleaut32.dll Thu Dec 06 05:09:35 2007
usp10    C:\Windows\System32\usp10.dll Thu Nov 02 11:15:03 2006
ole32    C:\Windows\System32\ole32.dll Thu Nov 02 11:14:31 2006
advapi32 C:\Windows\System32\advapi32.dll Thu Nov 02 11:11:35 2006
gdi32    C:\Windows\System32\gdi32.dll Thu Feb 21 04:40:51 2008
msvcrt   C:\Windows\System32\msvcrt.dll Thu Nov 02 11:13:37 2006
imm32    C:\Windows\System32\imm32.dll Thu Nov 02 11:13:15 2006
msctf    C:\Windows\System32\msctf.dll Thu Nov 02 11:13:42 2006

This pattern should be checked when we have instances of Module Variety and, especially, Duplicated Module. Note that this pattern can also easily become an anti-pattern when applied to an unknown component: Alien Component.

- Dmitry Vostokov @ DumpAnalysis.org -

In addition to Module Variety there is another DLL Hell pattern that I call Duplicated Module. Here the same module is loaded at least twice and we can detect this when we see the module load address appended to its name in the output of lm commands (this is done to make the name of the module unique):

0:000> lm
start    end        module name
00b20000 0147f000   MSO_b20000
30000000 309a7000   EXCEL
30c90000 31848000   mso
71c20000 71c32000   tsappcmp
745e0000 7489e000   msi  
76290000 762ad000   imm32 
76b70000 76b7b000   psapi            
76f50000 76f63000   secur32            
77380000 77411000   user32
77670000 777a9000   ole32
77ba0000 77bfa000   msvcrt
77c00000 77c48000   gdi32          
77c50000 77cef000   rpcrt4           
77da0000 77df2000   shlwapi            
77e40000 77f42000   kernel32
77f50000 77feb000   advapi32           
7c800000 7c8c0000   ntdll

Usually his happens when the DLL is loaded from different locations. It can be exactly the same DLL version. The problems usually surface when there are different DLL versions and the new code loads the old version of the DLL and uses it. This may result in interface incompatibility issues and ultimately in application fault like an access violation.

In order to provide a dump to play with I created a small toy program called 2DLLs to model the worst case scenario similar to the one I encountered in a production environment a couple of days ago. The program periodically loads MyDLL module to call one of its functions. Unfortunately in one place it uses hardcoded relative path:

HMODULE hLib = LoadLibrary(L".\\DLL\\MyDLL.dll");

and in another place it relies on DLL search order:

hLib = LoadLibrary(L".\\MyDLL.dll");

PATH variable directories are used for search if this DLL was not found in other locations specified by DLL search order. We see that the problem can happen when another application is installed which uses the old version of that DLL and modifies PATH variable to point to its location. To model interface incompatibility I compiled the version of MyDLL that causes NULL pointer access violation when the same function is called from it. The DLL was placed into a separate folder and the PATH variable was modified to reference that folder:

C:\>set PATH=C:\OLD;%PATH%

The application crashes and the installed default postmortem debugger (CDB) saves its crash dump. If we open it we would see that it crashed in MyDLL_1e60000 module which should trigger suspicion:

0:000> r
rax=0000000001e61010 rbx=0000000000000000 rcx=0000775dcac00000
rdx=0000000000000000 rsi=0000000000000006 rdi=0000000000001770
rip=0000000001e61010 rsp=000000000012fed8 rbp=0000000000000000
 r8=0000000000000000  r9=000000000012fd58 r10=0000000000000001
r11=000000000012fcc0 r12=0000000000000000 r13=0000000000000002
r14=0000000000000000 r15=0000000000000000
iopl=0         nv up ei pl nz na pe nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010200
MyDLL_1e60000!fnMyDLL:
00000000`01e61010 c704250000000000000000 mov dword ptr [0],0 ds:00000000`00000000=????????

0:000> kL
Child-SP          RetAddr           Call Site
00000000`0012fed8 00000001`40001093 MyDLL_1e60000!fnMyDLL
00000000`0012fee0 00000001`40001344 2DLLs+0×1093
00000000`0012ff10 00000000`773acdcd 2DLLs+0×1344
00000000`0012ff60 00000000`774fc6e1 kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

Looking at the list of modules we see two versions of MyDLL loaded from two different folders:

0:000> lm
start             end                 module name
00000000`01e60000 00000000`01e71000   MyDLL_1e60000
00000000`772a0000 00000000`7736a000   user32
00000000`77370000 00000000`774a1000   kernel32
00000000`774b0000 00000000`7762a000   ntdll
00000001`40000000 00000001`40010000   2DLLs
00000001`80000000 00000001`80011000   MyDLL
000007fe`fc9e0000 000007fe`fca32000   uxtheme
000007fe`fe870000 000007fe`fe9a9000   rpcrt4
000007fe`fe9b0000 000007fe`fe9bc000   lpk
000007fe`fea10000 000007fe`feae8000   oleaut32
000007fe`fecd0000 000007fe`fed6a000   usp10
000007fe`fedd0000 000007fe`fefb0000   ole32
000007fe`fefb0000 000007fe`ff0af000   advapi32
000007fe`ff0d0000 000007fe`ff131000   gdi32
000007fe`ff2e0000 000007fe`ff381000   msvcrt
000007fe`ff390000 000007fe`ff3b8000   imm32
000007fe`ff4b0000 000007fe`ff5b4000   msctf

0:000> lmv m MyDLL_1e60000
start             end                 module name
00000000`01e60000 00000000`01e71000   MyDLL_1e60000
    Loaded symbol image file: MyDLL.dll
    Image path: C:\OLD\MyDLL.dll
    Image name: MyDLL.dll
    Timestamp:        Wed Jun 18 14:49:13 2008 (48591259)
[…]

0:000> lmv m MyDLL
start             end                 module name
00000001`80000000 00000001`80011000   MyDLL
    Image path: C:\2DLLs\DLL\MyDLL.dll
    Image name: MyDLL.dll
    Timestamp:        Wed Jun 18 14:50:56 2008 (485912C0)
[...]

We can also see that the old version of MyDLL was the last loaded DLL:

0:000> !dlls -l

0x002c2680: C:\2DLLs\2DLLs.exe
      Base   0x140000000  EntryPoint  0x1400013b0  Size        0x00010000
      Flags  0x00004000  LoadCount   0x0000ffff  TlsIndex    0x00000000
             LDRP_ENTRY_PROCESSED

[...]

0x002ea9b0: C:\2DLLs\DLL\MyDLL.dll
      Base   0x180000000  EntryPoint  0x1800013d0  Size        0x00011000
      Flags  0x00084004  LoadCount   0x00000001  TlsIndex    0x00000000
             LDRP_IMAGE_DLL
             LDRP_ENTRY_PROCESSED
             LDRP_PROCESS_ATTACH_CALLED

[...]

0x002ec430: C:\OLD\MyDLL.dll
      Base   0×01e60000  EntryPoint  0×01e613e0  Size        0×00011000
      Flags  0×00284004  LoadCount   0×00000001  TlsIndex    0×00000000
             LDRP_IMAGE_DLL
             LDRP_ENTRY_PROCESSED
             LDRP_PROCESS_ATTACH_CALLED
             LDRP_IMAGE_NOT_AT_BASE

We can also see that the PATH variable points to its location and this might explain why it was loaded:

0:000> !peb
PEB at 000007fffffd6000
[...]
Path=C:\OLD;C:\Windows\system32;C:\Windows;[…]
[…]

We might think that the module having address in its name was loaded the last but this is not true. If we save another copy of the dump from the existing one using .dump command and load the new dump file we would see that order of the module names is reversed:

0:000> kL
Child-SP          RetAddr           Call Site
00000000`0012fed8 00000001`40001093 MyDLL!fnMyDLL
00000000`0012fee0 00000001`40001344 2DLLs+0×1093
00000000`0012ff10 00000000`773acdcd 2DLLs+0×1344
00000000`0012ff60 00000000`774fc6e1 kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

0:000> lm
start             end                 module name
00000000`01e60000 00000000`01e71000   MyDLL
00000000`772a0000 00000000`7736a000   user32
00000000`77370000 00000000`774a1000   kernel32
00000000`774b0000 00000000`7762a000   ntdll
00000001`40000000 00000001`40010000   2DLLs
00000001`80000000 00000001`80011000   MyDLL_180000000
000007fe`fc9e0000 000007fe`fca32000   uxtheme
000007fe`fe870000 000007fe`fe9a9000   rpcrt4
000007fe`fe9b0000 000007fe`fe9bc000   lpk
000007fe`fea10000 000007fe`feae8000   oleaut32
000007fe`fecd0000 000007fe`fed6a000   usp10
000007fe`fedd0000 000007fe`fefb0000   ole32
000007fe`fefb0000 000007fe`ff0af000   advapi32
000007fe`ff0d0000 000007fe`ff131000   gdi32
000007fe`ff2e0000 000007fe`ff381000   msvcrt
000007fe`ff390000 000007fe`ff3b8000   imm32
000007fe`ff4b0000 000007fe`ff5b4000   msctf

0:000> !dlls -l

[...]

0x002ec430: C:\OLD\MyDLL.dll
      Base   0×01e60000  EntryPoint  0×01e613e0  Size        0×00011000
      Flags  0×00284004  LoadCount   0×00000001  TlsIndex    0×00000000
             LDRP_IMAGE_DLL
             LDRP_ENTRY_PROCESSED
             LDRP_PROCESS_ATTACH_CALLED
             LDRP_IMAGE_NOT_AT_BASE

The postprocessed dump file can be downloaded from FTP to play with:

ftp://dumpanalysis.org/pub/CDAPatternDuplicatedModule.zip 

- Dmitry Vostokov @ DumpAnalysis.org -

Analysis of computer memory snapshots (memory dumps) and their evolution is the domain of memoretics. Computer memory semiotics (memiotics or memosemiotics) is the branch of memoretics that studies the interpretation of computer memory, its meaning, signs and symbols.

- Dmitry Vostokov @ DumpAnalysis.org -     

Looking at computer memory visual images combined with listening to the incredible nostalgic music composed by Oystein Sevag is highly recommended to relieve stress while immersing yourself in the vast depths of memory hierarchy. I really like “Painful Love” tracks. Is love and passion for programming painful?…

Visual

Link

- Dmitry Vostokov @ DumpAnalysis.org -

Mistake #2 - Not seeing semantic and pragmatic inconsistencies

Why would FreeHeap need a file name? See Incorrect Stack Trace pattern case study for semantic inconsistency. Why is this function on the stack trace

dll!exit+0x10,834

67,636 bytes long (0×10,834 in decimal)?  

The latter is an example of pragmatic inconsistency and the answer is that we don’t have symbols and the name appears from the DLL export table. The code on the stack has nothing to do with exit action when proper symbols are applied.

Another example. The memory dump of a hanging process has only one thread and it is waiting for an event. Is this the problem in ThreadProc and application logic or in the fact that _endthreadex was called when the thread was created?

STACK_TEXT: 
0379fa50 7642dcea ntdll!NtWaitForMultipleObjects+0x15
0379faec 75e08f76 kernel32!WaitForMultipleObjectsEx+0x11d
0379fb40 75e08fbf user32!RealMsgWaitForMultipleObjectsEx+0x14d
0379fb5c 00f6b45d user32!MsgWaitForMultipleObjects+0x1f
0379fba8 752e29bb application!ThreadProc+0xad
0379fbe0 752e2a47 msvcr80!_endthreadex+0×3b
0379fbe8 7649e3f3 msvcr80!_endthreadex+0xc7
0379fbf4 7773cfed kernel32!BaseThreadInitThunk+0xe
0379fc34 7773d1ff ntdll!__RtlUserThreadStart+0×23
0379fc4c 00000000 ntdll!_RtlUserThreadStart+0×1b

The latter assumption is wrong. The presence of _endthreadex stems from the fact that its address was pushed to let a user thread procedure to automatically call it upon the normal function return:  

0:000> u 752e29bb
msvcr80!_endthreadex+0x3b:
752e29bb 50              push    eax
752e29bc e8bfffffff      call    msvcr80!_endthreadex (752e2980)
752e29c1 8b45ec          mov     eax,dword ptr [ebp-14h]
752e29c4 8b08            mov     ecx,dword ptr [eax]
752e29c6 8b09            mov     ecx,dword ptr [ecx]
752e29c8 894de4          mov     dword ptr [ebp-1Ch],ecx
752e29cb 50              push    eax
752e29cc 51              push    ecx

A thread procedure passed to thread creation API call can be any C function. How would a C/C++ compiler understand that it needs to generate a call to thread exit API especially if ThreadProc is named FooBar and resides in a different compilation unit or a library? It seems logical that the runtime environment provides such an automatic return address dynamically. Also why and how _endthreadex knows about our custom ThreadProc to call it? Looks like inconsistency. The ability to see and reason about them is very important skill in memory dump analysis and debugging. The lack of sufficient unmanaged code programming experience might partly explain many analysis mistakes.

- Dmitry Vostokov @ DumpAnalysis.org -

Klaus Schulze was one of my favorite electronic composers in 90s. Now I’m revisiting my past collection and recommend ”X” album featuring several musical biographies including Nietzsche. “X” here stands for 10th album not for “x” WinDbg command. Good for meditation during slow debugging sessions. All music is very sad and mystical. I even think about this title: “Musical Biography of a Bug“:

X

- Dmitry Vostokov @ DumpAnalysis.org -

Due to a request I opened AERA subforum:

http://www.dumpanalysis.org/forum/viewforum.php?f=29

Everyone is welcome to comment and add thoughts.

IBCDAS code name has been changed to AERA

- Dmitry Vostokov @ DumpAnalysis.org - 

I decided to post selected crash dumps for some case studies and patterns after getting feedback from readers of my MDAA book. They are custom made from my toy programs and preprocessed to clear sensitive information that might have leaked from my home computers otherwise. They can be found at the following public FTP address:

ftp://dumpanalysis.org/pub/

The first example was published today for Missing Component (static linking) pattern. I also created the following page to list them all including the ones that I add for some previously published patterns:

Memory Dump File Samples

- Dmitry Vostokov @ DumpAnalysis.org -

Previously I introduced Missing Component pattern where the example and emphasis was on dynamically loaded modules. In this part I cover statically linked modules. Failure for a loader to find one of them results in a software exception. The most frequent of them are (numbers were taken from Google search):

C0000142 918
C0000143 919
C0000145 1,530
C0000135 24,900

0:001> !error c0000142
Error code: (NTSTATUS) 0xc0000142 (3221225794) - {DLL Initialization Failed}  Initialization of the dynamic link library %hs failed. The process is terminating abnormally.

0:001> !error c0000143
Error code: (NTSTATUS) 0xc0000143 (3221225795) - {Missing System File}  The required system file %hs is bad or missing.

0:001> !error c0000145
Error code: (NTSTATUS) 0xc0000145 (3221225797) - {Application Error}  The application failed to initialize properly (0x%lx). Click on OK to terminate the application.

0:000> !error c0000135
Error code: (NTSTATUS) 0xc0000135 (3221225781) - {Unable To Locate Component}  This application has failed to start because %hs was not found. Re-installing the application may fix this problem.

In this part I only consider user mode exceptions. If we have a default debugger configured it will usually save a crash dump. To model this problem I modified one of my applications by changing all occurrences of KERNEL32.DLL to  KERNEL32.DL using Visual Studio Binary Editor. CDB was configured as a default postmortem debugger (see Custom postmortem debuggers on Vista). When the application was launched CDB attached to it and saved a crash dump. If we open it in WinDbg we get characteristic Special Stack Trace involving loader functions:

Loading Dump File [C:\UserDumps\CDAPatternMissingComponent.dmp]
User Mini Dump File with Full Memory: Only application data is available

Symbol search path is: srv*c:\mss*http://msdl.microsoft.com/download/symbols
Executable search path is:
Windows Vista Version 6000 MP (2 procs) Free x86 compatible
Product: WinNt, suite: SingleUserTS
Debug session time: Thu Jun 12 12:03:28.000 2008 (GMT+1)
System Uptime: 1 days 8:46:23.167
Process Uptime: 0 days 0:00:48.000

This dump file has an exception of interest stored in it.
The stored exception information can be accessed via .ecxr.
(da4.f60): Wake debugger - code 80000007 (first/second chance not available)
eax=00000000 ebx=77c4a174 ecx=75ce3cf9 edx=00000000 esi=7efde028 edi=7efdd000
eip=77bcf1d1 esp=0017fca4 ebp=0017fd00 iopl=0         nv up ei pl zr na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
ntdll!_LdrpInitialize+0x6d:
77bcf1d1 8b45b8          mov     eax,dword ptr [ebp-48h] ss:002b:0017fcb8=7efde000

0:000> kL
ChildEBP RetAddr 
0017fd00 77b937ea ntdll!_LdrpInitialize+0×6d
0017fd10 00000000 ntdll!LdrInitializeThunk+0×10

Verbose analysis command doesn’t give us an indication of what had happened so we need to dig further:

0:000> !analyze -v
[...]

FAULTING_IP:
+0
00000000 ??              ???

EXCEPTION_RECORD:  ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 00000000
   ExceptionCode: 80000007 (Wake debugger)
  ExceptionFlags: 00000000
NumberParameters: 0

BUGCHECK_STR:  80000007

PROCESS_NAME:  StackOverflow.exe

ERROR_CODE: (NTSTATUS) 0x80000007 - {Kernel Debugger Awakened}  the system debugger was awakened by an interrupt.

NTGLOBALFLAG:  400

APPLICATION_VERIFIER_FLAGS:  0

DERIVED_WAIT_CHAIN: 

Dl Eid Cid     WaitType
-- --- ------- --------------------------
   0   da4.f60 Unknown               

WAIT_CHAIN_COMMAND:  ~0s;k;;

BLOCKING_THREAD:  00000f60

DEFAULT_BUCKET_ID:  APPLICATION_HANG_BusyHang

PRIMARY_PROBLEM_CLASS:  APPLICATION_HANG_BusyHang

LAST_CONTROL_TRANSFER:  from 77b937ea to 77bcf1d1

FAULTING_THREAD:  00000000

STACK_TEXT: 
0017fd00 77b937ea 0017fd24 77b60000 00000000 ntdll!_LdrpInitialize+0x6d
0017fd10 00000000 0017fd24 77b60000 00000000 ntdll!LdrInitializeThunk+0x10

FOLLOWUP_IP:
ntdll!_LdrpInitialize+6d
77bcf1d1 8b45b8          mov     eax,dword ptr [ebp-48h]

SYMBOL_STACK_INDEX:  0

SYMBOL_NAME:  ntdll!_LdrpInitialize+6d

FOLLOWUP_NAME:  MachineOwner

MODULE_NAME: ntdll

IMAGE_NAME:  ntdll.dll

DEBUG_FLR_IMAGE_TIMESTAMP:  4549bdf8

STACK_COMMAND:  ~0s ; kb

BUCKET_ID:  80000007_ntdll!_LdrpInitialize+6d

FAILURE_BUCKET_ID:  ntdll.dll!_LdrpInitialize_80000007_APPLICATION_HANG_BusyHang

Followup: MachineOwner

Last event and error code are not helpful too: 

0:000> .lastevent
Last event: da4.f60: Wake debugger - code 80000007 (first/second chance not available)
  debugger time: Thu Jun 12 15:04:38.917 2008 (GMT+1)

0:000> !gle
LastErrorValue: (Win32) 0 (0) - The operation completed successfully.
LastStatusValue: (NTSTATUS) 0 - STATUS_WAIT_0

Let’s search thread raw stack data for any signs of exceptions:

0:000> !teb
TEB at 7efdd000
    ExceptionList:        0017fcf0
    StackBase:            00180000
    StackLimit:           0017e000
    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7efdd000
    EnvironmentPointer:   00000000
    ClientId:             00000da4 . 00000f60
    RpcHandle:            00000000
    Tls Storage:          00000000
    PEB Address:          7efde000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0

0:000> dds 0017e000 00180000
[...]
0017f8d8  7efdd000
0017f8dc  0017f964
0017f8e0  77c11c78 ntdll!_except_handler4
0017f8e4  00000000
0017f8e8  0017f988
0017f8ec  0017f900
0017f8f0  77ba1ddd ntdll!RtlCallVectoredContinueHandlers+0x15
0017f8f4  0017f988
0017f8f8  0017f9d8
0017f8fc  77c40370 ntdll!RtlpCallbackEntryList
0017f900  0017f970
0017f904  77ba1db5 ntdll!RtlDispatchException+0×11f
0017f908  0017f988
0017f90c  0017f9d8
0017f910  7efde028
0017f914  00000001
0017f918  77630000 kernel32!_imp___aullrem <PERF> (kernel32+0×0)
0017f91c  00000001
0017f920  776ced81 kernel32!_DllMainCRTStartupForGS2+0×10
0017f924  0017f938
0017f928  7765d4d9 kernel32!BaseDllInitialize+0×18
0017f92c  76042340 user32!$$VProc_ImageExportDirectory
0017f930  00000001
0017f934  00000000
0017f938  0017f9e0
0017f93c  77b8f890 ntdll!LdrpSnapThunk+0xc9
0017f940  0040977a StackOverflow+0×977a
0017f944  0000030b
0017f948  76030000 user32!_imp__RegSetValueExW <PERF> (user32+0×0)
0017f94c  76042f94 user32!$$VProc_ImageExportDirectory+0xc54
0017f950  77bb8881 ntdll!LdrpSnapThunk+0×40d
0017f954  0017bb30
0017f958  00409770 StackOverflow+0×9770
0017f95c  00881a50
0017f960  004098b2 StackOverflow+0×98b2
0017f964  77bac282 ntdll!ZwRaiseException+0×12
0017f968  00180000
0017f96c  0017fc48
0017f970  0017fd00
0017f974  77bac282 ntdll!ZwRaiseException+0×12
0017f978  77b7ee72 ntdll!KiUserExceptionDispatcher+0×2a
0017f97c  0017f988 ; exception record
0017f980  0017f9d8 ; exception context
0017f984  00000000
0017f988  c0000135
0017f98c  00000001
0017f990  00000000
0017f994  77bcf1d1 ntdll!_LdrpInitialize+0×6d
0017f998  00000000
0017f99c  77c11c78 ntdll!_except_handler4
0017f9a0  77b8dab8 ntdll!RtlpRunTable+0×218
0017f9a4  fffffffe
0017f9a8  77ba2515 ntdll!vDbgPrintExWithPrefixInternal+0×214
0017f9ac  77ba253b ntdll!DbgPrintEx+0×1e
0017f9b0  77b7f356 ntdll! ?? ::FNODOBFM::`string’
0017f9b4  00000055
0017f9b8  00000003
0017f9bc  77b809c2 ntdll! ?? ::FNODOBFM::`string’
0017f9c0  0017fc9c
0017f9c4  00000001
0017f9c8  0017fd00
0017f9cc  77bcf28e ntdll!_LdrpInitialize+0×12a
0017f9d0  00000055
0017f9d4  75ce3cf9
0017f9d8  0001003f
0017f9dc  00000000
0017f9e0  00000000
0017f9e4  00000000
0017f9e8  00000000
0017f9ec  00000000
0017f9f0  00000000
0017f9f4  0000027f
[…]

We see exception dispatching calls highlighted above. One of their parameters is an exception record and we try to get one:

0:000> .exr 0017f988
ExceptionAddress: 77bcf1d1 (ntdll!_LdrpInitialize+0x0000006d)
   ExceptionCode: c0000135
  ExceptionFlags: 00000001
NumberParameters: 0

Error c0000135 means that the loader was unable to locate a component. Now we try to examine the same raw stack data for any string patterns. For example, the following UNICODE pattern is clearly visible:

0017f2fc  00000000
0017f300  00880ec4
0017f304  77b910d7 ntdll!RtlpDosPathNameToRelativeNtPathName_Ustr+0x344
0017f308  00000000
0017f30c  43000043
0017f310  0042002a
0017f314  0017f33c
0017f318  00000000
0017f31c  00000002
0017f320  00000008
0017f324  00000000
0017f328  0000008c
0017f32c  000a0008
0017f330  77b91670 ntdll!`string'
0017f334  00b92bd6
0017f338  0017f5d4
0017f33c  003a0043
0017f340  0050005c
0017f344  006f0072
0017f348  00720067
0017f34c  006d0061
0017f350  00460020
0017f354  006c0069
0017f358  00730065
0017f35c  00280020
0017f360  00380078
0017f364  00290036
0017f368  0043005c
0017f36c  006d006f
0017f370  006f006d
0017f374  0020006e
0017f378  00690046
0017f37c  0065006c
0017f380  005c0073
0017f384  006f0052
0017f388  00690078
0017f38c  0020006f
0017f390  00680053
0017f394  00720061
0017f398  00640065
0017f39c  0044005c
0017f3a0  004c004c
0017f3a4  00680053
0017f3a8  00720061
0017f3ac  00640065
0017f3b0  004b005c
0017f3b4  00520045
0017f3b8  0045004e
0017f3bc  0033004c
0017f3c0  002e0032
0017f3c4  006c0064
0017f3c8  00000000
0017f3cc  00000000

It is a path to DLL that was probably missing:

0:000> du 0017f33c
0017f33c  "C:\Program Files (x86)\Common Fi"
0017f37c  "les\Roxio Shared\DLLShared\KERNE"
0017f3bc  "L32.dl"

I think the loader was trying to find KERNEL32.dl following the DLL search order and this was the last path element:

0:000> !peb
PEB at 7efde000
    InheritedAddressSpace:    No
    ReadImageFileExecOptions: No
    BeingDebugged:            Yes
    ImageBaseAddress:         00400000
    Ldr                       77c40080
    Ldr.Initialized:          Yes
    Ldr.InInitializationOrderModuleList: 00881ad0 . 008831b8
    Ldr.InLoadOrderModuleList:           00881a50 . 00883dc8
    Ldr.InMemoryOrderModuleList:         00881a58 . 00883dd0
            Base TimeStamp                     Module
[...]
    Environment:  00881de8
[...] 
Path=C:\Windows\system32; C:\Windows; C:\Windows\System32\Wbem; C:\Program Files\ATI Technologies\ATI.ACE; c:\Program Files (x86)\Microsoft SQL Server\90\Tools\binn\; C:\Program Files (x86)\Common Files\Roxio Shared\DLLShared\
[…]

In  similar situations !dlls command might help that shows the load order (-l switch) and points to the last processed DLL:

0:001> !dlls -l

0x004740e8: C:\Program Files\Application\Application.exe
      Base   0x012a0000  EntryPoint  0x012b0903  Size        0x00057000
      Flags  0x00004010  LoadCount   0x0000ffff  TlsIndex    0x00000000
             LDRP_ENTRY_PROCESSED

0x00474158: C:\Windows\SysWOW64\ntdll.dll
      Base   0x77d00000  EntryPoint  0x00000000  Size        0x00160000
      Flags  0x00004014  LoadCount   0x0000ffff  TlsIndex    0x00000000
             LDRP_IMAGE_DLL
             LDRP_ENTRY_PROCESSED

0x00474440: C:\Windows\syswow64\kernel32.dll
      Base   0x77590000  EntryPoint  0x775a1f3e  Size        0x00110000
      Flags  0x00084014  LoadCount   0x0000ffff  TlsIndex    0x00000000
             LDRP_IMAGE_DLL
             LDRP_ENTRY_PROCESSED
             LDRP_PROCESS_ATTACH_CALLED

[…] 

0x00498ff8: C:\Windows\WinSxS\x86_microsoft.windows.common-controls_...\comctl32.dll
      Base   0x74d90000  EntryPoint  0x74dc43e5  Size        0x0019e000
      Flags  0x100c4014  LoadCount   0x00000003  TlsIndex    0x00000000
             LDRP_IMAGE_DLL
             LDRP_ENTRY_PROCESSED
             LDRP_DONT_CALL_FOR_THREADS
             LDRP_PROCESS_ATTACH_CALLED

0x004991b8: C:\Windows\WinSxS\x86_microsoft.vc80.mfcloc_...\MFC80ENU.DLL
      Base   0x71b10000  EntryPoint  0x00000000  Size        0x0000e000
      Flags  0x10004014  LoadCount   0x00000001  TlsIndex    0x00000000
             LDRP_IMAGE_DLL
             LDRP_ENTRY_PROCESSED

If it is difficult to identify what had really happened in crash dumps we can enable loader snaps using gflags and run the application under a debugger. For example, for notepad.exe we have:

Microsoft (R) Windows Debugger Version 6.8.0004.0 AMD64
Copyright (c) Microsoft Corporation. All rights reserved.

CommandLine: C:\Windows\notepad.exe
Symbol search path is: srv*c:\mss*http://msdl.microsoft.com/download/symbols
Executable search path is:
ModLoad: 00000000`ffac0000 00000000`ffaef000   notepad.exe
ModLoad: 00000000`779b0000 00000000`77b2a000   ntdll.dll
LDR: NEW PROCESS
     Image Path: C:\Windows\notepad.exe (notepad.exe)
     Current Directory: C:\Program Files\Debugging Tools for Windows 64-bit\
     Search Path: C:\Windows; C:\Windows\system32; C:\Windows\system; C:\Windows;.; C:\Program Files\Debugging Tools for Windows 64-bit\winext\arcade; C:\Windows\system32;C:\Windows; C:\Windows\System32\Wbem; C:\Program Files\ATI Technologies\ATI.ACE; c:\Program Files (x86)\Microsoft SQL Server\90\Tools\binn\; C:\Program Files (x86)\Common Files\Roxio Shared\DLLShared\
LDR: LdrLoadDll, loading kernel32.dll from
ModLoad: 00000000`777a0000 00000000`778d1000   C:\Windows\system32\kernel32.dll
LDR: kernel32.dll bound to ntdll.dll
LDR: kernel32.dll has stale binding to ntdll.dll
LDR: Stale Bind ntdll.dll from kernel32.dll
LDR: LdrGetProcedureAddress by NAME - BaseThreadInitThunk
[3d8,1278] LDR: Real INIT LIST for process C:\Windows\notepad.exe pid 984 0x3d8
[3d8,1278]    C:\Windows\system32\kernel32.dll init routine 00000000777DC960
[3d8,1278] LDR: kernel32.dll loaded - Calling init routine at 00000000777DC960
LDR: notepad.exe bound to ADVAPI32.dll
ModLoad: 000007fe`fe520000 000007fe`fe61f000   C:\Windows\system32\ADVAPI32.dll
LDR: ADVAPI32.dll bound to ntdll.dll
LDR: ADVAPI32.dll has stale binding to ntdll.dll
LDR: Stale Bind ntdll.dll from ADVAPI32.dll
LDR: ADVAPI32.dll bound to KERNEL32.dll
LDR: ADVAPI32.dll has stale binding to KERNEL32.dll
LDR: ADVAPI32.dll bound to ntdll.dll via forwarder(s) from kernel32.dll
LDR: ADVAPI32.dll has stale binding to ntdll.dll
LDR: Stale Bind KERNEL32.dll from ADVAPI32.dll
LDR: LdrGetProcedureAddress by NAME - RtlAllocateHeap
LDR: LdrGetProcedureAddress by NAME - RtlReAllocateHeap
LDR: LdrGetProcedureAddress by NAME - RtlEncodePointer
LDR: LdrGetProcedureAddress by NAME - RtlDecodePointer
LDR: LdrGetProcedureAddress by NAME - RtlSizeHeap
LDR: LdrGetProcedureAddress by NAME - RtlDeleteCriticalSection
LDR: LdrGetProcedureAddress by NAME - RtlEnterCriticalSection
LDR: LdrGetProcedureAddress by NAME - RtlLeaveCriticalSection
LDR: ADVAPI32.dll bound to RPCRT4.dll
[...]

This technique only works for native platform loader snaps. For example, it doesn’t show loader snaps for 32-bit modules loaded under WOW64 (to the best of my knowledge):

Microsoft (R) Windows Debugger Version 6.8.0004.0 X86
Copyright (c) Microsoft Corporation. All rights reserved.

CommandLine: C:\Apps\StackOverflow.exe
Symbol search path is: srv*c:\mss*http://msdl.microsoft.com/download/symbols
Executable search path is:
ModLoad: 00400000 00418000   StackOverflow.exe
ModLoad: 77b60000 77cb0000   ntdll.dll
LDR: NEW PROCESS
     Image Path: C:\Apps\StackOverflow.exe (StackOverflow.exe)
[...]
LDR: Loading (STATIC, NON_REDIRECTED) C:\Windows\system32\wow64cpu.dll
LDR: wow64cpu.dll bound to ntdll.dll
LDR: wow64cpu.dll has stale binding to ntdll.dll
LDR: Stale Bind ntdll.dll from wow64cpu.dll
LDR: wow64cpu.dll bound to wow64.dll
LDR: wow64cpu.dll has stale binding to wow64.dll
LDR: Stale Bind wow64.dll from wow64cpu.dll
LDR: wow64.dll has stale binding to wow64cpu.dll
LDR: Stale Bind wow64cpu.dll from wow64.dll
LDR: Refcount wow64cpu.dll (1)
LDR: Refcount wow64.dll (2)
LDR: Refcount wow64win.dll (1)
LDR: Refcount wow64.dll (3)
LDR: LdrGetProcedureAddress by NAME - Wow64LdrpInitialize
[...]
ModLoad: 77630000 77740000   C:\Windows\syswow64\kernel32.dll
ModLoad: 76030000 76100000   C:\Windows\syswow64\USER32.dll
ModLoad: 775a0000 77630000   C:\Windows\syswow64\GDI32.dll
ModLoad: 76d00000 76dbf000   C:\Windows\syswow64\ADVAPI32.dll
ModLoad: 76df0000 76ee0000   C:\Windows\syswow64\RPCRT4.dll
ModLoad: 75d60000 75dc0000   C:\Windows\syswow64\Secur32.dll
(1ec.1290): Unknown exception - code c0000135 (first chance)
(1ec.1290): Unknown exception - code c0000135 (!!! second chance !!!)
eax=00000000 ebx=77c4a174 ecx=75ce3cf9 edx=00000000 esi=7efde028 edi=7efdd000
eip=77bcf1d1 esp=0017fca4 ebp=0017fd00 iopl=0         nv up ei pl zr na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
ntdll!_LdrpInitialize+0×6d:
77bcf1d1 8b45b8          mov     eax,dword ptr [ebp-48h] ss:002b:0017fcb8=7efde000

The dump file that I used was modified to remove sensitive information (see Data Hiding in Crash Dumps for this technique). It can be downloaded from FTP to play with:

ftp://dumpanalysis.org/pub/CDAPatternMissingComponent.zip

- Dmitry Vostokov @ DumpAnalysis.org -

Suppose we want to send a complete memory dump to a vendor but want to remove certain sensitive details or perhaps the whole process or image from it. In this case we can use f WinDbg command (virtual addresses) or fp (physical addresses) to fill pages with zeroes. Let’s open a complete memory dump and erase environment variables for a process:

kd> !process 0 0
**** NT ACTIVE PROCESS DUMP ****
PROCESS fffffadfe7afd8e0
    SessionId: none  Cid: 0004    Peb: 00000000  ParentCid: 0000
    DirBase: 0014a000  ObjectTable: fffffa8000000c10  HandleCount: 730.
    Image: System

PROCESS fffffadfe6edc040
    SessionId: none  Cid: 0130    Peb: 7fffffdf000  ParentCid: 0004
    DirBase: 34142000  ObjectTable: fffffa80009056d0  HandleCount:  19.
    Image: smss.exe

[...]

PROCESS fffffadfe67905a0
    SessionId: 0  Cid: 085c    Peb: 7fffffd4000  ParentCid: 0acc
    DirBase: 232e2000  ObjectTable: fffffa8000917e10  HandleCount:  55.
    Image: SystemDump.exe

kd> .process /r /p fffffadfe7287610
Implicit process is now fffffadf`e7287610
Loading User Symbols

kd> !peb
PEB at 000007fffffd4000
[...]
    Environment:  0000000000010000

kd> dd 10000
00000000`00010000  004c0041 0055004c 00450053 00530052
00000000`00010010  00520050 0046004f 004c0049 003d0045
00000000`00010020  003a0043 0044005c 0063006f 006d0075
00000000`00010030  006e0065 00730074 00610020 0064006e
00000000`00010040  00530020 00740065 00690074 0067006e
00000000`00010050  005c0073 006c0041 0020006c 00730055
00000000`00010060  00720065 002e0073 00320057 0033004b
00000000`00010070  00410000 00500050 00410044 00410054

kd> f 10000 10000+1000 0
Filled 0x1000 bytes

kd> dd 10000
00000000`00010000  00000000 00000000 00000000 00000000
00000000`00010010  00000000 00000000 00000000 00000000
00000000`00010020  00000000 00000000 00000000 00000000
00000000`00010030  00000000 00000000 00000000 00000000
00000000`00010040  00000000 00000000 00000000 00000000
00000000`00010050  00000000 00000000 00000000 00000000
00000000`00010060  00000000 00000000 00000000 00000000
00000000`00010070  00000000 00000000 00000000 00000000

Now we can save the modified complete dump file:

kd> .dump /f c:\Dumps\SecuredDump.dmp

If we want to find and erase read-write pages, for example, we can use !vad WinDbg command to get the description of virtual address ranges:

kd> !process
PROCESS fffffadfe67905a0
    SessionId: 0  Cid: 085c    Peb: 7fffffd4000  ParentCid: 0acc
    DirBase: 232e2000  ObjectTable: fffffa8000917e10  HandleCount:  55.
    Image: SystemDump.exe
    VadRoot fffffadfe6f293e0 Vads 65 Clone 0 Private 388. Modified 84. Locked 0.
    DeviceMap fffffa80020777c0
    Token                             fffffa80008e5b50
    ElapsedTime                       00:00:06.265
    UserTime                          00:00:00.031
    KernelTime                        00:00:00.062
    QuotaPoolUsage[PagedPool]         113464
    QuotaPoolUsage[NonPagedPool]      5152
    Working Set Sizes (now,min,max)  (1429, 50, 345) (5716KB, 200KB, 1380KB)
    PeakWorkingSetSize                1429
    VirtualSize                       61 Mb
    PeakVirtualSize                   63 Mb
    PageFaultCount                    1555
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      471

kd> !vad fffffadfe6f293e0
VAD             level      start      end    commit
fffffadfe682bdf0 ( 6)         10       10         1 Private      READWRITE
fffffadfe73a0e10 ( 5)         20       20         1 Private      READWRITE
fffffadfe73a0dd0 ( 4)         30      12f         8 Private      READWRITE
fffffadfe71a4770 ( 5)        130      134         0 Mapped       READONLY
fffffadfe781bbe0 ( 3)        140      141         0 Mapped       READONLY
[…]
fffffadfe772d630 (-2)   7fffffdc 7fffffdd         2 Private      READWRITE
fffffadfe788e180 (-1)   7fffffde 7fffffdf         2 Private      READWRITE

Total VADs:    65  average level: 66076419  maximum depth: -1

In the output start and end columns refer to virtual page numbers (VPN). To get an address we need to multiply by 0×1000, for example,  7fffffde000. 

Filling memory with zeroes to hide data with subsequent saving of a modified crash dump is applicable to user dumps too. Please also check for additional security-related flags in .dump command:

WinDbg is privacy-aware

Another application for data hiding and modification could be the creation of the customized crash dumps for digital forensics exercises and contests.

- Dmitry Vostokov @ DumpAnalysis.org -

I’ve just found that although I covered Stack Overflow in kernel mode I didn’t do this for user mode. In fact this is one of the simplest patterns to see in crash dumps. It has its own characteristic exception code and stack trace:

FAULTING_IP:
StackOverflow!SoFunction+27
00401317 6a00            push    0

EXCEPTION_RECORD:  ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 00401300 (StackOverflow!SoFunction+0x00000010)
   ExceptionCode: c00000fd (Stack overflow)
  ExceptionFlags: 00000000
NumberParameters: 2
   Parameter[0]: 00000001
   Parameter[1]: 00082ffc

0:000> kL
ChildEBP RetAddr 
00083000 00401317 StackOverflow!SoFunction+0x10
00083010 00401317 StackOverflow!SoFunction+0×27
00083020 00401317 StackOverflow!SoFunction+0×27
00083030 00401317 StackOverflow!SoFunction+0×27
00083040 00401317 StackOverflow!SoFunction+0×27
00083050 00401317 StackOverflow!SoFunction+0×27
00083060 00401317 StackOverflow!SoFunction+0×27
00083070 00401317 StackOverflow!SoFunction+0×27
00083080 00401317 StackOverflow!SoFunction+0×27
00083090 00401317 StackOverflow!SoFunction+0×27
000830a0 00401317 StackOverflow!SoFunction+0×27
000830b0 00401317 StackOverflow!SoFunction+0×27
000830c0 00401317 StackOverflow!SoFunction+0×27
000830d0 00401317 StackOverflow!SoFunction+0×27
000830e0 00401317 StackOverflow!SoFunction+0×27
000830f0 00401317 StackOverflow!SoFunction+0×27
00083100 00401317 StackOverflow!SoFunction+0×27
00083110 00401317 StackOverflow!SoFunction+0×27
00083120 00401317 StackOverflow!SoFunction+0×27
00083130 00401317 StackOverflow!SoFunction+0×27

There could be thousands of stack frames:

0:000> kL 2000
[...]
000a2fa0 00401317 StackOverflow!SoFunction+0x27
000a2fb0 00401317 StackOverflow!SoFunction+0x27
000a2fc0 00401317 StackOverflow!SoFunction+0x27
000a2fd0 00401317 StackOverflow!SoFunction+0x27
000a2fe0 00401317 StackOverflow!SoFunction+0x27
000a2ff0 00401317 StackOverflow!SoFunction+0x27

To reach the bottom and avoid over scrolling we can dump the raw stack data, search for the end of the repeating pattern of StackOverflow!SoFunction+0×27 and try to manually reconstruct the bottom of the stack trace:

0:000> !teb
TEB at 7efdd000
    ExceptionList:        0017fdf0
    StackBase:            00180000
    StackLimit:           00081000
    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7efdd000
    EnvironmentPointer:   00000000
    ClientId:             00001dc4 . 00001b74
    RpcHandle:            00000000
    Tls Storage:          7efdd02c
    PEB Address:          7efde000
    LastErrorValue:       0
    LastStatusValue:      c0000034
    Count Owned Locks:    0
    HardErrorMode:        0

0:000> dds 00081000 00180000
[...]
0017fc74  00401317 StackOverflow!SoFunction+0×27
0017fc78  00000000
0017fc7c  a3a8ea65
0017fc80  0017fc90
0017fc84  00401317 StackOverflow!SoFunction+0×27
0017fc88  10001843
0017fc8c  a3a8ea95
0017fc90  0017fca0
0017fc94  00401317 StackOverflow!SoFunction+0×27
0017fc98  0017fcb8
0017fc9c  a3a8ea85
0017fca0  0017fcb0
0017fca4  00401317 StackOverflow!SoFunction+0×27
0017fca8  00000003
0017fcac  a3a8eab5
0017fcb0  0017fcc0
0017fcb4  00401317 StackOverflow!SoFunction+0×27
0017fcb8  76c68738 user32!_EndUserApiHook+0×11
0017fcbc  a3a8eaa5
0017fcc0  0017fcd0
0017fcc4  00401317 StackOverflow!SoFunction+0×27
0017fcc8  76c6a6cc user32!DefWindowProcW+0×94
0017fccc  a3a8ead5
0017fcd0  0017fce0
0017fcd4  00401317 StackOverflow!SoFunction+0×27
0017fcd8  0037311e
0017fcdc  a3a8eac5
0017fce0  0017fcf0
0017fce4  00401317 StackOverflow!SoFunction+0×27
0017fce8  0017fcd0
0017fcec  a3a8eaf5
0017fcf0  0017fd00
0017fcf4  00401317 StackOverflow!SoFunction+0×27
0017fcf8  76c6ad0f user32!NtUserBeginPaint+0×15
0017fcfc  a3a8eae5
0017fd00  0017fd5c
0017fd04  00401272 StackOverflow!WndProc+0xe2
0017fd08  00401190 StackOverflow!WndProc
0017fd0c  00000003
0017fd10  cf017ada
[…]

We use the extended version of k WinDbg command and supply EBP, ESP and EIP to see in what function it started:

0:000> r
eax=a3b739e5 ebx=00000000 ecx=ac430000 edx=ffefd944 esi=0037311e edi=00000000
eip=00401300 esp=00082ff8 ebp=00083000 iopl=0         nv up ei ng nz na po nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010282
StackOverflow!SoFunction+0×10:
00401300 89442404        mov     dword ptr [esp+4],eax ss:002b:00082ffc=00000000

0:000> k L=0017fcf0 00082ff8 00401300
ChildEBP RetAddr 
0017fcb0 00401317 StackOverflow!SoFunction+0×10
0017fd00 00401272 StackOverflow!SoFunction+0×27
0017fd5c 76c687af StackOverflow!WndProc+0xe2
0017fd88 76c68936 user32!InternalCallWinProc+0×23
0017fe00 76c6a571 user32!UserCallWinProcCheckWow+0×109
0017fe5c 76c6a5dd user32!DispatchClientMessage+0xe0
0017fe98 77ccee2e user32!__fnDWORD+0×2b
0017fedc 0040107d ntdll!KiUserCallbackDispatcher+0×2e
0017ff08 0040151e StackOverflow!wWinMain+0×7d
00402ba0 20245c8b StackOverflow!__tmainCRTStartup+0×176

- Dmitry Vostokov @ DumpAnalysis.org -

My friend was typing a long message in IE to one of his old schoolmates that he had just found on Internet. He spent about an hour writing and rewriting and when finally hit the Send button he got a page saying that connection was probably lost. Going back in URL history brought the empty edit box and all data was lost. Or was it? He called me and I immediately advised him to save a crash dump of iexplore.exe using Task Manager (Vista). I also asked him for a word he used to start his message. It was “Hello” in Russian. I got his dump file and opened it in WinDbg. Because the language of his message was Russian I assumed that it was still there in local buffers or heap entries in UNICODE format so I typed “ello” in Notepad and saved this in a Unicode text file. Loading it in a binary editor (I used Visual C++) showed the following sequence of bytes:

40 04 38 04 32 04 35 04 42 04

Then I did a search in WinDbg for this sequence from the first loaded module address till the end of user space:

0:000> lm
start    end        module name
003c0000 0045b000   iexplore
[...]

0:000> s 003c0000 L?7FFFFFFF 40 04 38 04 32 04 35 04 42 04
[...]
048971e4 40 04 38 04 32 04 35 04-42 04 2c 00 20 00 1c 04  @.8.2.5.B.,. ...
[...]
08530fe4 40 04 38 04 32 04 35 04-42 04 2c 00 20 00 1c 04 @.8.2.5.B.,. ...
[...]
201ea65c 40 04 38 04 32 04 35 04-42 04 2c 00 20 00 1c 04 @.8.2.5.B.,. ...
[...] 

The number of found entries was big and I decided to output every entry into a file using the following script: 

.foreach ( address { s-[1]b 003c0000 L?7FFFFFFF 40 04 38 04 32 04 35 04 42 04 }) {.writemem c:\dmitry\ieout${address}.txt ${address}-10 ${address}+1000}

I got numerous files:

C:\dmitry>dir ieout*.txt
[...]
09/06/2008  08:53               4112 ieout0x048971e4.txt
09/06/2008  08:53               4112 ieout0x0489784c.txt
09/06/2008  08:53               4112 ieout0x0489b854.txt
09/06/2008  08:53               4112 ieout0x0489bc5c.txt
[...]

I combined all of them into one big file and sent it to my friend:

C:\dmitry>type ieout0x*.txt >ieoutall.txt

The file contained not only the final message but all intermediate typing histories too. He was very happy.

- Dmitry Vostokov @ DumpAnalysis.org -

If you remember I promised to review this CD:

 The first Memory Analysis CD album

Finally it arrived by post and here it is:

I’ve just finished listening to it. It is wonderful! Clearly belongs to my Music for Debugging collection. Here is my commentary (italics) on track titles:

1. Chameleon 
   It crashes then hangs then spikes then leaks. You never know what happens next…
2. Silence Before The Storm 
   Waiting for the problem to start dumping memory
3. Appearances 
   Multiple occurrences of the issue ease crash dump collection
4. Memory Analysis 
   Memory dump analysis activity
5. Voices From Heaven 
   It’s my blog full of crash dump analysis patterns
6. Figure In The Fog 
   It’s that DLL! I see it clearly!!!
7. Diamond Tear 
   Customer is happy
8. The Toy Soldier 
   WinDbg
9. Tears In Dragon’s Eyes 
   Operating system vendor is happy too
10. Forgotten Song 
   No pasaran (bugs)
11. Skies
   We are debugging gods!

Enjoy :-) 

- Dmitry Vostokov @ DumpAnalysis.org -

Another pattern that we need to pay attention is called Thread Starvation. This happens when some threads or processes have higher priority and favored by OS thread dispatcher effectively starving other threads. If prioritized threads are CPU-bound we also see Spiking Thread pattern. However, if their thread priorities were normal they would have been preempted by other threads and latter threads would not be starved. Here is one example where 2 threads from 2 different applications but from one user session are spiking on 2 processors (threads from other processors have above normal and normal priority):

System Uptime: 0 days 6:40:41.143

0: kd> !running

System Processors f (affinity mask)
  Idle Processors None

     Prcb      Current   Next    
  0  f773a120  89864c86 ................
  1  f773d120  89f243d2 ................
  2  f7737120  89f61398 ................
  3  f773f120  897228a0 ................

0: kd> .thread /r /p 89f61398
Implicit thread is now 89f61398
Implicit process is now 88bcc2e0
Loading User Symbols

0: kd> !thread 89f61398 1f
THREAD 89f61398  Cid 16f8.2058  Teb: 7ffdf000 Win32Thread: bc41aea8 RUNNING on processor 2
Not impersonating
DeviceMap                 e48a6508
Owning Process            88bcc2e0       Image:         application.exe
Wait Start TickCount      1569737        Ticks: 0
Context Switch Count      7201654                 LargeStack
UserTime                  01:24:06.687
KernelTime                00:14:53.828
Win32 Start Address application (0×0040a52c)
Start Address kernel32!BaseProcessStartThunk (0×77e617f8)
Stack Init ba336000 Current ba335d00 Base ba336000 Limit ba330000 Call 0
Priority 24 BasePriority 24 PriorityDecrement 0
ChildEBP RetAddr 
0012e09c 762c3b7d USER32!IsWindowVisible
0012e0c4 762d61bb MSVBVM50!RbyCountVisibleDesks+0×3c
0012e0d0 004831f6 MSVBVM50!rtcDoEvents+0×7
0012e348 0046d1ae application+0×831f6
0012e3a0 762ce5a9 application+0×6d1ae
0012e3dc 762ce583 MSVBVM50!CallProcWithArgs+0×20
0012e3f8 762db781 MSVBVM50!InvokeVtblEvent+0×33
0012e434 762cfbc2 MSVBVM50!InvokeEvent+0×32
0012e514 762cfa4a MSVBVM50!EvtErrFireWorker+0×175
0012e55c 762b1aa3 MSVBVM50!EvtErrFire+0×18
0012e5ac 7739bffa MSVBVM50!CThreadPool::GetThreadData+0xf
0012e58c 762cd13b USER32!CallHookWithSEH+0×21
0012e5ac 7739bffa MSVBVM50!VBDefControlProc_2787+0xad
0012e618 762d3348 USER32!CallHookWithSEH+0×21
0012e640 762cda44 MSVBVM50!PushCtlProc+0×2e
0012e668 762cd564 MSVBVM50!CommonGizWndProc+0×4e
0012e6b8 7739b6e3 MSVBVM50!StdCtlWndProc+0×171
0012e6e4 7739b874 USER32!InternalCallWinProc+0×28
0012e75c 7739ba92 USER32!UserCallWinProcCheckWow+0×151
0012e7c4 773a16e5 USER32!DispatchMessageWorker+0×327
0012e7d4 762d616e USER32!DispatchMessageA+0xf
0012e828 762d6054 MSVBVM50!ThunderMsgLoop+0×97
0012e874 762d5f55 MSVBVM50!SCM::FPushMessageLoop+0xaf
0012e8b4 004831f6 MSVBVM50!CMsoComponent::PushMsgLoop+0×24
0012e8c0 00d3b3c8 application+0×831f6
00184110 00000000 0xd3b3c8

0: kd> .thread /r /p 897228a0
Implicit thread is now 897228a0
Implicit process is now 897348a8
Loading User Symbols

0: kd> !thread 897228a0 1f 100
THREAD 897228a0  Cid 2984.2988  Teb: 7ffdf000 Win32Thread: bc381488 RUNNING on processor 3
IRP List:
    89794bb8: (0006,0220) Flags: 00000000  Mdl: 8a145878
Not impersonating
DeviceMap                 e3ec0360
Owning Process            897348a8       Image:         application2.exe
Wait Start TickCount      1569737        Ticks: 0
Context Switch Count      10239625                 LargeStack
UserTime                  02:38:18.890
KernelTime                00:29:36.187
Win32 Start Address application2 (0×00442e4c)
Start Address kernel32!BaseProcessStartThunk (0×77e617f8)
Stack Init f1d90000 Current f1d8fd00 Base f1d90000 Limit f1d88000 Call 0
Priority 24 BasePriority 24 PriorityDecrement 0
ChildEBP RetAddr 
0012f66c 762d61bb USER32!_SEH_prolog+0×5
0012f678 00fdb0b9 MSVBVM50!rtcDoEvents+0×7
0012f92c 00fca760 application2+0xbdb0b9
0012fa20 762ce5a9 application2+0xbca760
0012fa40 762ce583 MSVBVM50!CallProcWithArgs+0×20
0012fa5c 762db781 MSVBVM50!InvokeVtblEvent+0×33
0012fa98 762cfbc2 MSVBVM50!InvokeEvent+0×32
0012fb78 762cfa4a MSVBVM50!EvtErrFireWorker+0×175
0012fb90 76330b2b MSVBVM50!EvtErrFire+0×18
0012fbf0 762cd13b MSVBVM50!ErrDefMouse_100+0×16d
0012fca4 762cda44 MSVBVM50!VBDefControlProc_2787+0xad
0012fccc 7631c826 MSVBVM50!CommonGizWndProc+0×4e
0012fd08 762cd523 MSVBVM50!StdCtlPreFilter_50+0×9e
0012fd5c 7739b6e3 MSVBVM50!StdCtlWndProc+0×130
0012fd88 7739b874 USER32!InternalCallWinProc+0×28
0012fe00 7739ba92 USER32!UserCallWinProcCheckWow+0×151
0012fe68 773a16e5 USER32!DispatchMessageWorker+0×327
0012fe78 762d616e USER32!DispatchMessageA+0xf
0012fea8 762bb78f MSVBVM50!ThunderMsgLoop+0×97
0012feb8 762d60cb MSVBVM50!MsoFInitPx+0×39
0012fecc 762d6054 MSVBVM50!CMsoCMHandler::FPushMessageLoop+0×1a
0012ff18 762d5f55 MSVBVM50!SCM::FPushMessageLoop+0xaf
0012ffa0 8082ea41 MSVBVM50!CMsoComponent::PushMsgLoop+0×24
0012fef8 762d5f8e nt!KiDeliverApc+0×11f
0012ff18 762d5f55 MSVBVM50!SCM_MsoCompMgr::FPushMessageLoop+0×2f
0012ffa0 8082ea41 MSVBVM50!CMsoComponent::PushMsgLoop+0×24
0012ff18 762d5f55 nt!KiDeliverApc+0×11f
0012ffa0 8082ea41 MSVBVM50!CMsoComponent::PushMsgLoop+0×24
0012ffd4 0012ffc8 nt!KiDeliverApc+0×11f
00000000 00000000 0×12ffc8

What we see here is unusually high Priority and BasePriority values (24 and 24). This means that the base priority for these processes was most likely artificially increased to Realtime. Most processes have base priority 8 (Normal):

0: kd> !thread 88780db0 1f
THREAD 88780db0  Cid 44a8.1b8c  Teb: 7ffaf000 Win32Thread: bc315d20 WAIT: (Unknown) UserMode Non-Alertable
    887b8650  Semaphore Limit 0x7fffffff
    88780e28  NotificationTimer
Not impersonating
DeviceMap                 e1085298
Owning Process            889263a0       Image:         explorer.exe
Wait Start TickCount      1565543        Ticks: 4194 (0:00:01:05.531)
Context Switch Count      7                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b6754000 Current b6753c0c Base b6754000 Limit b6750000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
b6753c24 80833e8d nt!KiSwapContext+0×26
b6753c50 80829b74 nt!KiSwapThread+0×2e5
b6753c98 809249cd nt!KeWaitForSingleObject+0×346
b6753d48 8088ac4c nt!NtReplyWaitReceivePortEx+0×521
b6753d48 7c8285ec nt!KiFastCallEntry+0xfc
01a2fe18 7c82783b ntdll!KiFastSystemCallRet
01a2fe1c 77c885ac ntdll!NtReplyWaitReceivePortEx+0xc
01a2ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×198
01a2ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
01a2ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
01a2ffb8 77e64829 RPCRT4!ThreadStartRoutine+0×1b
01a2ffec 00000000 kernel32!BaseThreadStart+0×34

Some important system processes like csrss.exe have base priority 13 (High) but their threads wait most of the time and this doesn’t create any problems:

0: kd> !thread 887eb3d0 1f
THREAD 887eb3d0  Cid 4cf4.2bd4  Teb: 7ffaf000 Win32Thread: bc141cc0 WAIT: (Unknown) UserMode Non-Alertable
    888769b0  SynchronizationEvent
Not impersonating
DeviceMap                 e1000930
Owning Process            8883f7c0       Image:         csrss.exe
Wait Start TickCount      1540456        Ticks: 29281 (0:00:07:37.515)
Context Switch Count      40                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Start Address winsrv!ConsoleInputThread (0×75a81b18)
Stack Init b5c5a000 Current b5c59bac Base b5c5a000 Limit b5c55000 Call 0
Priority 15 BasePriority 13 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
b5c59bc4 80833e8d nt!KiSwapContext+0×26
b5c59bf0 80829b74 nt!KiSwapThread+0×2e5
b5c59c38 bf89b1c3 nt!KeWaitForSingleObject+0×346
b5c59c94 bf89b986 win32k!xxxSleepThread+0×1be
b5c59cec bf89da22 win32k!xxxRealInternalGetMessage+0×46a
b5c59d4c 8088ac4c win32k!NtUserGetMessage+0×3f
b5c59d4c 7c8285ec nt!KiFastCallEntry+0xfc
00ffff64 7739c811 ntdll!KiFastSystemCallRet
00ffff84 75a81c47 USER32!NtUserGetMessage+0xc
00fffff4 00000000 winsrv!ConsoleInputThread+0×16c

However it is very unusual for a process to have Realtime base priority. I can speculate what had really happened before the system crash was forced. The system administrator noticed two applications consuming CPU over the long period of time and decided to intervene. Unfortunately his hand slipped when he was browsing Task Manager Set Priority menu and Realtime was selected instead of Low. Human error…

See also the similar starvation pattern resulted from threads with normal priority.

- Dmitry Vostokov @ DumpAnalysis.org -

Motivated by The Science of Sherlock Holmes I plan to write a book about the history of debugging with the following preliminary product details and tentative release date (which may come earlier if I have enough time):

• Title: The Science of Dr. Watson: An Illustrated History of Debugging
• Author: Dmitry Vostokov
• Publisher: Opentask (01 September 2010)
• Language: English
• Product Dimensions: 22.86 x 15.24
• ISBN-13: 978-1-906717-07-0
• Paperback: 256 pages

- Dmitry Vostokov @ DumpAnalysis.org -

Sometimes certain files are opened but not closed when not needed and this prevents other applications and users from using, deleting or replacing them. Sometimes on behalf of certain API calls another process opens them. One of the questions I was asked recently is how to find that process. The answer that I found is very simple: just list all handles from all processes and search for that file name there. This works in kernel and complete memory dumps and also in live kernel debugging session including its local kernel debugging variant. The following WinDbg command lists all objects (we need to open a log because the output is usually of several megabytes):

3: kd> !for_each_process "!handle 0 3 @#Process"

!handle 0 3 @#Process
processor number 3, process 8a392818
PROCESS 8a392818  SessionId: none  Cid: 0004    Peb: 00000000  ParentCid: 0000
    DirBase: bfc51000  ObjectTable: e1001e00  HandleCount: 2650.
    Image: System

Handle table at e16a3000 with 2650 Entries in use
0004: Object: 8a392818  GrantedAccess: 001f0fff Entry: e1004008
Object: 8a392818  Type: (8a392e70) Process
    ObjectHeader: 8a392800 (old version)
        HandleCount: 3  PointerCount: 235

0008: Object: 8a391db0  GrantedAccess: 00000000 Entry: e1004010
Object: 8a391db0  Type: (8a392ca0) Thread
    ObjectHeader: 8a391d98 (old version)
        HandleCount: 1  PointerCount: 1

000c: Object: e101bca0  GrantedAccess: 00000000 Entry: e1004018
Object: e101bca0  Type: (8a37db00) Key
    ObjectHeader: e101bc88 (old version)
        HandleCount: 1  PointerCount: 3
        Directory Object: 00000000  Name: \REGISTRY

[...]

1fac: Object: 88ec72b0  GrantedAccess: 00000003 (Protected) Entry: e1ed7f58
Object: 88ec72b0  Type: (8a36f900) File
    ObjectHeader: 88ec7298 (old version)
        HandleCount: 1  PointerCount: 2
        Directory Object: 00000000  Name: \Documents and Settings\MyUserName\NTUSER.DAT {HarddiskVolume1}

[...]

07fc: Object: e1000768  GrantedAccess: 00000003 Entry: e2fefff8
Object: e1000768  Type: (8a387e70) KeyedEvent
    ObjectHeader: e1000750 (old version)
        HandleCount: 273  PointerCount: 274
        Directory Object: e1001a48  Name: CritSecOutOfMemoryEvent

processor number 3, process 8873f3b8
PROCESS 8873f3b8  SessionId: 6  Cid: 4c1c    Peb: 7ffdf000  ParentCid: 42bc
    DirBase: 49dbb000  ObjectTable: e325f788  HandleCount:  90.
    Image: PROFLWIZ.EXE

Handle table at e36c3000 with 90 Entries in use
0004: Object: e1000768  GrantedAccess: 00000003 Entry: e36c3008
Object: e1000768  Type: (8a387e70) KeyedEvent
    ObjectHeader: e1000750 (old version)
        HandleCount: 273  PointerCount: 274
        Directory Object: e1001a48  Name: CritSecOutOfMemoryEvent

[...]

- Dmitry Vostokov @ DumpAnalysis.org -

Following the introductory division of memory analysis into two broad categories I decided to plan yet another book with the following title and preliminary product details:

• Title: Memory Analysis Forensics and Intelligence: An Integral Approach
• Author: Dmitry Vostokov
• Publisher: Opentask (01 September 2009)
• Language: English
• Product Dimensions: 22.86 x 15.24
• ISBN-13: 978-1-906717-05-6
• Paperback: 256 pages

As you might have noticed, I prefer to put 128, 256 or 512 pages in my book announcements. What that would say about the author’s background? I would like to set 1024 pages for my memory dump analysis anthology series but 740 or 800 pages is the limit for POD technology I use.

- Dmitry Vostokov @ DumpAnalysis.org -

Software ageing can be the cause of the problem. Sometimes a look at the following WinDbg output can give irresistible temptation to suggest periodic reboots:

Debug session time: Wed April 28 15:36:52.330 2008 (GMT+0)
System Uptime: 124 days 6:27:16.658

The suggested pattern name is Overaged System.

- Dmitry Vostokov @ DumpAnalysis.org -

While working on WDN book I noticed that it is possible to analyze managed code in complete memory dumps. We just need to switch to the process in question and load SOS DLL (if memory dumps are from 64-bit Windows we need to run 64-bit WinDbg because it needs to load 64-bit SOS from Microsoft.NET \ Framework64 \ vX.X.XXXXX folder).

Here is some command output from a complete memory dump generated from SystemDump when running TestDefaultDebugger.NET application where we try to find and disassemble IL code for this function:

namespace WindowsApplication1
{
  public partial class Form1 : Form
  {
[...]
  private void button1_Click(object sender, EventArgs e)
  {
  System.Collections.Stack stack = new System.Collections.Stack();stack.Pop();
  }
  }
}

Loading Dump File [C:\W2K3\MEMORY_NET.DMP]
Kernel Complete Dump File: Full address space is available

Symbol search path is: srv*c:\mss*http://msdl.microsoft.com/download/symbols
Executable search path is:
Windows Server 2003 Kernel Version 3790 (Service Pack 2) UP Free x64
Product: Server, suite: Enterprise TerminalServer
Built by: 3790.srv03_sp2_gdr.070321-2337
Kernel base = 0xfffff800`01000000 PsLoadedModuleList = 0xfffff800`01198b00

kd> !process 0 0
**** NT ACTIVE PROCESS DUMP ****
[...]
PROCESS fffffadfe7287610
    SessionId: 0  Cid: 0ad8    Peb: 7fffffdf000  ParentCid: 0acc
    DirBase: 12cd9000  ObjectTable: fffffa800163c260  HandleCount: 114.
    Image: TestDefaultDebugger.NET.exe

PROCESS fffffadfe67905a0
    SessionId: 0  Cid: 085c    Peb: 7fffffd4000  ParentCid: 0acc
    DirBase: 232e2000  ObjectTable: fffffa8000917e10  HandleCount:  55.
    Image: SystemDump.exe

kd> .process /r /p fffffadfe7287610
Implicit process is now fffffadf`e7287610
Loading User Symbols

kd> .loadby sos mscorwks

kd> !threads

ThreadCount: 2
UnstartedThread: 0
BackgroundThread: 1
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
                                              PreEmptive                                                Lock
       ID OSID        ThreadOBJ     State   GC     GC Alloc Context                  Domain           Count APT Exception
       1  a94 0000000000161150      6020 Enabled  0000000000000000:0000000000000000 000000000014ccb0     0 STA
       2  604 00000000001688b0      b220 Enabled  0000000000000000:0000000000000000 000000000014ccb0     0 MTA (Finalizer)

kd> !process fffffadfe7287610 4
PROCESS fffffadfe7287610
    SessionId: 0  Cid: 0ad8    Peb: 7fffffdf000  ParentCid: 0acc
    DirBase: 12cd9000  ObjectTable: fffffa800163c260  HandleCount: 114.
    Image: TestDefaultDebugger.NET.exe

        THREAD fffffadfe668cbf0  Cid 0ad8.0a94  Teb: 000007fffffdd000 Win32Thread: fffff97ff4df2830 WAIT
        THREAD fffffadfe727e6d0  Cid 0ad8.0f54  Teb: 000007fffffdb000 Win32Thread: 0000000000000000 WAIT
        THREAD fffffadfe72d5bf0  Cid 0ad8.0604  Teb: 000007fffffd9000 Win32Thread: 0000000000000000 WAIT
        THREAD fffffadfe679cbf0  Cid 0ad8.06b0  Teb: 000007fffffd7000 Win32Thread: 0000000000000000 WAIT
        THREAD fffffadfe67d23d0  Cid 0ad8.0b74  Teb: 000007fffffd5000 Win32Thread: fffff97ff4b99010 WAIT

kd> !EEHeap -gc
Number of GC Heaps: 1
generation 0 starts at 0x0000000002a41030
generation 1 starts at 0x0000000002a41018
generation 2 starts at 0x0000000002a41000
ephemeral segment allocation context: (0x0000000002a8d528, 0x0000000002a8dfe8)
         segment            begin         allocated             size
00000000001a1260 0000064274e28f60  0000064274e5f610 0x00000000000366b0(222896)
00000000001a1070 000006427692ffe8  000006427695af20 0x000000000002af38(175928)
0000000000164f60 00000642787c7380  0000064278809150 0x0000000000041dd0(269776)
0000000002a40000 0000000002a41000  0000000002a8dfe8 0x000000000004cfe8(315368)
Large object heap starts at 0x0000000012a41000
         segment            begin         allocated             size
0000000012a40000 0000000012a41000  0000000012a4e738 0x000000000000d738(55096)
Total Size           0xfdad8(1039064)
------------------------------
GC Heap Size           0xfdad8(1039064)

kd> !gchandles
Bad MethodTable for Obj at 0000000002a7a7b8
Bad MethodTable for Obj at 0000000002a7a750
Bad MethodTable for Obj at 0000000002a445b0
GC Handle Statistics:
Strong Handles: 25
Pinned Handles: 7
Async Pinned Handles: 0
Ref Count Handles: 1
Weak Long Handles: 30
Weak Short Handles: 63
Other Handles: 0
Statistics:
              MT    Count    TotalSize Class Name
[...]
0000064280016580        1          464 WindowsApplication1.Form1
[…]

kd> !dumpmt -md 0000064280016580
EEClass: 0000064280143578
Module: 0000064280012e00
Name: WindowsApplication1.Form1
mdToken: 02000002  (C:\TestDefaultDebugger.NET.exe)
BaseSize: 0×1d0
ComponentSize: 0×0
Number of IFaces in IFaceMap: 15
Slots in VTable: 375
————————————–
MethodDesc Table
           Entry       MethodDesc      JIT Name
[…]
0000064280150208 00000642800164d0      JIT WindowsApplication1.Form1.InitializeComponent()
0000064280150210 00000642800164e0      JIT WindowsApplication1.Form1..ctor()
0000064280150218 00000642800164f0     NONE WindowsApplication1.Form1.button1_Click(System.Object, System.EventArgs)

kd> !dumpil 00000642800164f0
ilAddr = 00000000004021bc
IL_0000: newobj System.Collections.Stack::.ctor
IL_0005: stloc.0
IL_0006: ldloc.0
IL_0007: callvirt System.Collections.Stack::Pop
IL_000c: pop
IL_000d: ret

- Dmitry Vostokov @ DumpAnalysis.org -