Archive for the ‘Crash Dump Analysis’ Category

Dictionary of Debugging: Manifold Memory Space

Tuesday, December 1st, 2009

Manifold Memory Space

A multiple virtual memory space view taking into account code and data sharing:

The same physical memory region can be mapped to different virtual memory regions. Here is another example of a sample manifold memory space where a physical memory region is mapped to the same virtual memory address range [N, M] of 3 OS processes:

Synonyms:

Antonyms:

Also: memory space, memory region, physical memory, virtual memory, memory mapping, orbifold memory space.

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 94a)

Monday, November 30th, 2009

Memory dump analysis is all about deviations and of them is Value Deviation (a super pattern), be it a number of open handles, a heap size, a  number of contended lockstime spent in kernel, and so on. Every system or process property has its average and mean values and large deviations are noticable as the so called anomalies. In this post we provide an example of a stack trace size (depth) deviation. The average number of frames for most stack traces is dependent on the type of a memory dump: user, kernel and complete but considerably longer or shorter stack traces are clearly visible in stack trace collections. I originally planned to call this pattern a Black Swan but after a moment of thought dismissed that idea because such deviations are not really rare after all. Here is an example of a stack trace collection from a CPU spiking process with a number of identical stack traces with just only 3 frames:

0:000> ~*kL

[...]

  19  Id: 1054.1430 Suspend: 1 Teb: 7ff9c000 Unfrozen
ChildEBP RetAddr 
1ac6ff50 7739bf53 ntdll!KiFastSystemCallRet
1ac6ffb8 77e6482f user32!NtUserWaitMessage+0xc
1ac6ffec 00000000 kernel32!BaseThreadStart+0x34

  20  Id: 1054.c90 Suspend: 1 Teb: 7ffaf000 Unfrozen
ChildEBP RetAddr 
1b30ff50 7739bf53 ntdll!KiFastSystemCallRet
1b30ffb8 77e6482f user32!NtUserWaitMessage+0xc
1b30ffec 00000000 kernel32!BaseThreadStart+0x34

  21  Id: 1054.a34 Suspend: 1 Teb: 7ff9a000 Unfrozen
ChildEBP RetAddr 
1b63ff50 7739bf53 ntdll!KiFastSystemCallRet
1b63ffb8 77e6482f user32!NtUserWaitMessage+0xc
1b63ffec 00000000 kernel32!BaseThreadStart+0×34

  22  Id: 1054.1584 Suspend: 1 Teb: 7ff99000 Unfrozen
ChildEBP RetAddr 
1ba9ff50 7739bf53 ntdll!KiFastSystemCallRet
1ba9ffb8 77e6482f user32!NtUserWaitMessage+0xc
1ba9ffec 00000000 kernel32!BaseThreadStart+0x34

[...]

These stack traces are correct from RetAddr analysis perspective:

0:000> ub 7739bf53
user32!PeekMessageW+0×11e:
7739bf42 nop
7739bf43 nop
7739bf44 nop
7739bf45 nop
7739bf46 nop
user32!NtUserWaitMessage:
7739bf47 mov     eax,124Ah
7739bf4c mov     edx,offset SharedUserData!SystemCallStub (7ffe0300)
7739bf51 call    dword ptr [edx]

0:000> ub 77e6482f
kernel32!BaseThreadStart+0×10:
77e6480b mov     eax,dword ptr fs:[00000018h]
77e64811 cmp     dword ptr [eax+10h],1E00h
77e64818 jne     kernel32!BaseThreadStart+0×2e (77e64829)
77e6481a cmp     byte ptr [kernel32!BaseRunningInServerProcess (77ecb008)],0
77e64821 jne     kernel32!BaseThreadStart+0×2e (77e64829)
77e64823 call    dword ptr [kernel32!_imp__CsrNewThread (77e4132c)]
77e64829 push    dword ptr [ebp+0Ch]
77e6482c call    dword ptr [ebp+8]

Looking at their thread times reveals that they were the most spikers:

0:000> !runaway
 User Mode Time
  Thread       Time
  19:1430      0 days 0:01:34.109
  22:1584      0 days 0:01:28.140
  21:a34       0 days 0:01:26.765
  20:c90       0 days 0:01:24.218

   0:e78       0 days 0:00:01.687
  10:398       0 days 0:00:01.062
   7:14e8      0 days 0:00:00.250
   4:1258      0 days 0:00:00.093
   6:2e8       0 days 0:00:00.015
   1:11c0      0 days 0:00:00.015
  26:1328      0 days 0:00:00.000
  25:7ec       0 days 0:00:00.000
[…]

In order to hypothesize about a possible culptit component we look at execution residue left on their raw stack data. Indeed, we see lots of non-coincidental symbolic references to 3rdPartyExtension module:

0:000> ~22s
eax=00000000 ebx=00000000 ecx=1ba9f488 edx=00000001 esi=1952bd40 edi=00000000
eip=7c82860c esp=1ba9ff54 ebp=1ba9ffb8 iopl=0         nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00240246
ntdll!KiFastSystemCallRet:
7c82860c ret

0:022> !teb
TEB at 7ff99000
    ExceptionList:        1ba9ffdc
    StackBase:            1baa0000
    StackLimit:           1ba8f000
    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7ff99000
    EnvironmentPointer:   00000000
    ClientId:             00001054 . 00001584
    RpcHandle:            00000000
    Tls Storage:          00000000
    PEB Address:          7ffd5000
    LastErrorValue:       0
    LastStatusValue:      c0000034
    Count Owned Locks:    0
    HardErrorMode:        0

0:022> dds 1ba8f000 1baa0000
1ba8f000  00000000
1ba8f004  00000000
[...]
1ba939e8  00000000
1ba939ec  00000000
1ba939f0  00000037
1ba939f4  1906e6c0
1ba939f8  064e1112 3rdPartyExtension!DllUnregisterServer+0xe1f1f
1ba939fc  1a042678
1ba93a00  034d2918
1ba93a04  00000000
1ba93a08  1a042660
1ba93a0c  00000008
1ba93a10  064e18ea 3rdPartyExtension!DllUnregisterServer+0xe26f7
1ba93a14  1a042678
1ba93a18  00000001
1ba93a1c  034d2870
1ba93a20  034d2b78
1ba93a24  0000001f
1ba93a28  00000007
1ba93a2c  034d2870
1ba93a30  1a01fc68
1ba93a34  00000001
1ba93a38  1ba93a54
1ba93a3c  064e1b45 3rdPartyExtension!DllUnregisterServer+0xe2952
1ba93a40  034d2b78
1ba93a44  00000000
1ba93a48  00000000
1ba93a4c  06e7b498
1ba93a50  00000212
1ba93a54  1ba93c00
1ba93a58  064e3bce 3rdPartyExtension!DllUnregisterServer+0xe49db
1ba93a5c  00000001
1ba93a60  00000001
1ba93a64  00000000
1ba93a68  115d7fbc
1ba93a6c  06e7b498
1ba93a70  062de91d 3rdPartyExtension+0xe91d
1ba93a74  0000020c
1ba93a78  1ba93b78
1ba93a7c  06363797 3rdPartyExtension+0×93797
1ba93a80  00000024
1ba93a84  00000000
1ba93a88  00000000
1ba93a8c  1ba93ee0
[…]

0:022> ub 064e1112
3rdPartyExtension!DllUnregisterServer+0xe1f0d:
064e1100 jge     3rdPartyExtension!DllUnregisterServer+0xe1f16 (064e1109)
064e1102 mov     ecx,dword ptr [ecx+10h]
064e1105 cmp     ecx,eax
064e1107 jne     3rdPartyExtension!DllUnregisterServer+0xe1f0a (064e10fd)
064e1109 push    ecx
064e110a push    ebx
064e110b mov     ecx,edi
064e110d call    3rdPartyExtension!DllUnregisterServer+0xe1d17 (064e0f0a)

- Dmitry Vostokov @ DumpAnalysis.org -

Music for Debugging: The Memory Dump of the Dead

Wednesday, November 25th, 2009

Highly recommended to listen during analysis of a complete memory dump from an isolated dead system to build tension resulting in a problem resolution in 21 minutes:

Rachmaninov: Symphonic Dances & the Isle of the Dead

Buy from Amazon

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 93)

Tuesday, November 24th, 2009

Analysis of .NET managed code requires processor architectural platform specific SOS extension. For example, x64 WinDbg is not able to analyze the managed stack for a managed code exception in 32-bit process:

0:010> !analyze -v

[...]

FAULTING_IP:
kernel32!RaiseException+53
77e4bee7 5e              pop     esi

EXCEPTION_RECORD:  ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 77e4bee7 (kernel32!RaiseException+0x00000053)
   ExceptionCode: e0434f4d (CLR exception)
  ExceptionFlags: 00000001
NumberParameters: 1
   Parameter[0]: 80131509

[...]

MANAGED_STACK: !dumpstack -EE
No export dumpstack found

MANAGED_BITNESS_MISMATCH:
Managed code needs matching platform of sos.dll for proper analysis. Use ‘x86′ debugger.

[...]

0:010> kL 100
ChildEBP RetAddr 
0573f0a4 79f071ac kernel32!RaiseException+0x53
0573f104 79f0a780 mscorwks!RaiseTheExceptionInternalOnly+0x2a8
0573f1a8 058ed3b3 mscorwks!JIT_Rethrow+0xbf
WARNING: Frame IP not in any known module. Following frames may be wrong.
0573f33c 793b0d1f <Unloaded_DllA.dll>+0x58ed3b2
0573f344 79373ecd mscorlib_ni+0x2f0d1f
0573f358 793b0c68 mscorlib_ni+0x2b3ecd
0573f370 79e7c74b mscorlib_ni+0x2f0c68
0573f380 79e7c6cc mscorwks!CallDescrWorker+0x33
0573f400 79e7c8e1 mscorwks!CallDescrWorkerWithHandler+0xa3
0573f53c 79e7c783 mscorwks!MethodDesc::CallDescr+0x19c
0573f558 79e7c90d mscorwks!MethodDesc::CallTargetWorker+0x1f
0573f56c 79fc58cd mscorwks!MethodDescCallSite::Call_RetArgSlot+0x18
0573f754 79ef3207 mscorwks!ThreadNative::KickOffThread_Worker+0x190
0573f768 79ef31a3 mscorwks!Thread::DoADCallBack+0x32a
0573f7fc 79ef30c3 mscorwks!Thread::ShouldChangeAbortToUnload+0xe3
0573f838 79ef4826 mscorwks!Thread::ShouldChangeAbortToUnload+0x30a
0573f860 79fc57b1 mscorwks!Thread::ShouldChangeAbortToUnload+0x33e
0573f878 79fc56ac mscorwks!ManagedThreadBase::KickOff+0x13
0573f914 79f95a2e mscorwks!ThreadNative::KickOffThread+0x269
0573ffb8 77e64829 mscorwks!Thread::intermediateThreadProc+0x49
0573ffec 00000000 kernel32!BaseThreadStart+0x34

So we dutifully run x86 WinDbg and get the better picture of nested exceptions:

0:010> !analyze -v

[...]

MANAGED_STACK: !dumpstack -EE
OS Thread Id: 0xc68 (15)
Current frame:
ChildEBP RetAddr  Caller,Callee

EXCEPTION_OBJECT: !pe 16584f0
Exception object: 016584f0
Exception type: System.InvalidOperationException
Message: There is an error in XML document (12, 12182).

InnerException: System.IO.IOException, use !PrintException 0164f6dc to see more
[…]

StackTraceString: <none>
HResult: 80131509
There are nested exceptions on this thread. Run with -nested for details

EXCEPTION_OBJECT: !pe 164f6dc
Exception object: 0164f6dc
Exception type: System.IO.IOException
Message: Unable to read data from the transport connection: The connection was closed.

InnerException: <none>
[…]

StackTraceString: <none>
HResult: 80131620
There are nested exceptions on this thread. Run with -nested for details

MANAGED_OBJECT: !dumpobj 1655a38
Name: System.String
MethodTable: 790fd8c4
EEClass: 790fd824
Size: 270(0x10e) bytes
 (C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__[...]\mscorlib.dll)
String: Unable to read data from the transport connection: The connection was closed.

[...]

EXCEPTION_MESSAGE:  Unable to read data from the transport connection: The connection was closed.

MANAGED_OBJECT_NAME:  System.IO.IOException

[...]

There are other pattern instances of this kind when we need a Platform-Specific Debugger, for example, to do live debugging of an x86 process on x64 machine (needed x64 debugger) or we need to load an old 32-bit DLL extension (needed x86 debugger) for a postmortem analysis.

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 92)

Tuesday, November 24th, 2009

Sometimes the functionality of a system depends upon a specific application or service process. For example, in a database server environment it might be a database process, in printing environment it is a print spooler process or in a terminal services environment it is a terminal services process (termsvc, hosted by svchost.exe). In system failure scenarios we should check these processes for their presence (and also the presence of any coupled processes), hence the name of this pattern: Missing Process. However, if the vital process is present we should check if it is exited but references to it exist or there are any missing threads or components inside it, any suspended threads and special processes like a postmortem debugger. We shouldn’t also forget about service dependencies and their relevant process startup order. For example, we know that our service is hosted by svchost.exe and we see one such process exited but its object still referenced somewhere:

0: kd> !vm

*** Virtual Memory Usage ***
[...]
         0ed8 svchost.exe          0 (         0 Kb)
[…]

However, another command shows that it could be a different service hosted by the same image, svchost.exe, if we know that ServiceA depends on our service:

0: kd> !process 0 0
**** NT ACTIVE PROCESS DUMP ****
PROCESS 8b581818  SessionId: none  Cid: 0004    Peb: 00000000  ParentCid: 0000
    DirBase: bff4d020  ObjectTable: e1001e18  HandleCount: 1601.
    Image: System

PROCESS 8b06d778  SessionId: none  Cid: 01a8    Peb: 7ffde000  ParentCid: 0004
    DirBase: bff4d040  ObjectTable: e13eae40  HandleCount:  22.
    Image: smss.exe

[...]

PROCESS 8aabed88  SessionId: 0  Cid: 0854    Peb: 7ffd6000  ParentCid: 0220
    DirBase: bff4d4a0  ObjectTable: e1c867a8  HandleCount: 778.
    Image: ServiceA.exe

[...]

PROCESS 8aaa6510  SessionId: 0  Cid: 0ed8    Peb: 7ffd4000  ParentCid: 0220
    DirBase: bff4d580  ObjectTable: 00000000  HandleCount:   0.
    Image: svchost.exe

[...]

Another alternative is that our service was restarted but then exited. If our process is not visible it could be possible that it was either stopped or simply crashed before.

- Dmitry Vostokov @ DumpAnalysis.org -

Dictionary of Debugging: 7

Monday, November 23rd, 2009

7

A separating digit of user space and kernel space in equi-bipartitional 32-bit virtual memory, for example, on x86 Windows systems:

RetAddr
80833491 nt!KiSwapContext+0×26
80828f2b nt!KiSwapThread+0×2e5
8099490a nt!KeDelayExecutionThread+0×2ab
808897cc nt!NtDelayExecution+0×84
7c82860c nt!KiFastCallEntry+0xfc
7c826f69 ntdll!KiFastSystemCallRet
7c83d454 ntdll!NtDelayExecution+0xc
77e6482f ntdll!RtlpTimerThread+0×47
00000000 kernel32!BaseThreadStart+0×34

lkd> lm
start    end        module name
[…]
77bd0000 77c19000   GDI32
77c20000 77cbf000   RPCRT4
77cd0000 77d5b000   OLEAUT32
77e20000 77eb2000   USER32
77ec0000 77f12000   SHLWAPI
77f30000 77fdc000   ADVAPI32
7c800000 7c915000   kernel32
7c920000 7c9e8000   ntdll
7c9f0000 7d1f9000   SHELL32
7e020000 7e02f000   SAMLIB

80800000 80a5d000   nt
80a5d000 80a89000   hal
bf800000 bf9d0000   win32k
[…]

This number continues to be used on x64 Windows systems, for example: 

RetAddr           Call Site
fffff800`0167e082 nt!KiSwapContext+0×7a
fffff800`0167a34b nt!KiCommitThreadWait+0×1d2
fffff800`01973def nt!KeWaitForMultipleObjects+0×271
fffff800`019746f6 nt!ObpWaitForMultipleObjects+0×294
fffff800`01675ed3 nt!NtWaitForMultipleObjects+0xe5
00000000`77ca030a nt!KiSystemServiceCopyEnd+0×13

lkd> lm
start             end               module name
00000000`774a0000 00000000`7756d000 USER32
00000000`77570000 00000000`7769d000 kernel32
00000000`776a0000 00000000`77826000 ntdll
00000000`ffe60000 00000000`ffec0000 services
000007fe`fca90000 000007fe`fca97000 wshtcpip
000007fe`fcae0000 000007fe`fcb0c000 NTMARTA
000007fe`fcbe0000 000007fe`fcc34000 schannel 
000007fe`fce10000 000007fe`fce5f000 mswsock
000007fe`fcf60000 000007fe`fcf69000 credssp
000007fe`fcf90000 000007fe`fcf97000 wship6
000007fe`fd0d0000 000007fe`fd207000 CRYPT32
000007fe`fd260000 000007fe`fd279000 MSASN1
000007fe`fd5a0000 000007fe`fd5b6000 NCObjAPI
000007fe`fd5c0000 000007fe`fd625000 SCESRV
000007fe`fd630000 000007fe`fd665000 apphelp
000007fe`fd680000 000007fe`fd6a6000 AUTHZ
000007fe`fd950000 000007fe`fd96c000 Secur32
000007fe`fd970000 000007fe`fd996000 USERENV
000007fe`fd9a0000 000007fe`fd9bc000 SAMLIB
000007fe`fdc80000 000007fe`fdce4000 GDI32
000007fe`fdd10000 000007fe`fdd1d000 LPK
000007fe`fdd20000 000007fe`fde28000 ADVAPI32
000007fe`fde30000 000007fe`fdecc000 msvcrt
000007fe`fded0000 000007fe`fdefd000 IMM32
000007fe`fdf00000 000007fe`fe0d8000 ole32
000007fe`fe0e0000 000007fe`fe0e7000 NSI
000007fe`fe190000 000007fe`fe22a000 USP10
000007fe`fe230000 000007fe`fe373000 RPCRT4
000007fe`ff340000 000007fe`ff395000 WLDAP32
000007fe`ff540000 000007fe`ff584000 WS2_32
000007fe`ff7d0000 000007fe`ff8d2000 MSCTF

fffff800`01802000 fffff800`01848000 hal
fffff800`01848000 fffff800`01d60000 nt
fffff960`000f0000 fffff960`003a1000 win32k
[…]

Synonyms:

Antonyms:

Also: virtual memory, user space, kernel space, x86, x64, 8

- Dmitry Vostokov @ DumpAnalysis.org -

Software Defect Researcher: A New Profession

Friday, November 20th, 2009

By analogy with a security researcher profession I propose the new title of a software defect researcher as a unified profession combining relevant fields of security research, testing, debugging, memory dump analysis, software reverse engineering, construction and maintenance. At least I consider myself a software defect researcher. If you think you consider yourself too please write a comment to this post. Thank you in advance.

- Dmitry Vostokov @ DumpAnalysis.org -

Stack trace collection, missing threads, waiting time, critical section and LPC wait chains: pattern cooperation

Friday, November 20th, 2009

Windows shutdown couldn’t progress and a complete memory dump was saved for later postmortem analysis. !stacks command showed reduced number of waiting threads in one important system service:

0: kd> !stacks
[...]
                            [89d6d8e8 ServiceA.exe]
1454.0014b0  89d36b60 0000163 Blocked    DriverA!Check+0x177
[...]

Normally this service had at least a dozen waiting threads. If we switch to the process we see many threads missing and the process itself is in the process of exiting (three “process” nouns in one sentence):

0: kd> !process 89d6d8e8
PROCESS 89d6d8e8  SessionId: 0  Cid: 1454    Peb: 7ffd8000  ParentCid: 0234
    DirBase: afa06000  ObjectTable: e5491278  HandleCount: 444.
    Image: ServiceA.exe
    VadRoot 89db18d8 Vads 213 Clone 0 Private 827. Modified 15. Locked 0.
    DeviceMap e10028c8
    Token                             e5556710
    ElapsedTime                       2 Days 02:59:39.285
    UserTime                          00:00:08.375
    KernelTime                        00:00:20.046
    QuotaPoolUsage[PagedPool]         50660
    QuotaPoolUsage[NonPagedPool]      9704
    Working Set Sizes (now,min,max)  (2523, 50, 345) (10092KB, 200KB, 1380KB)
    PeakWorkingSetSize                2953
    VirtualSize                       76 Mb
    PeakVirtualSize                   78 Mb
    PageFaultCount                    19259
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      1522

THREAD 89d36b60  Cid 1454.14b0  Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Alertable
    8a8d7438  NotificationEvent
    89d36bd8  NotificationTimer
Not impersonating
DeviceMap                 e10028c8
Owning Process            89d6d8e8       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      11760358       Ticks: 355 (0:00:00:05.546)
Context Switch Count      4591            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Start Address DriverA!CheckProtocolStackThread (0xf762cfa0)
Stack Init f3e7b000 Current f3e7acc0 Base f3e7b000 Limit f3e78000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
f3e7acd8 8083d5b1 nt!KiSwapContext+0x26
f3e7ad04 8083df9e nt!KiSwapThread+0x2e5
f3e7ad4c f762cf8d nt!KeWaitForSingleObject+0x346
[...]
f3e7adac 8092083b DriverA!CheckProtocolStackThread+0x5
f3e7addc 8083fe9f nt!PspSystemThreadStartup+0x2e
00000000 00000000 nt!KiThreadStartup+0x16

THREAD 89ce9580  Cid 1454.1630  Teb: 7ff9e000 Win32Thread: bc1e71f8 WAIT: (Unknown) UserMode Non-Alertable
     893fae40  SynchronizationEvent
Not impersonating
DeviceMap                 e10028c8
Owning Process            89d6d8e8       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      11048203       Ticks: 712510 (0:03:05:32.968)
Context Switch Count      1103                 LargeStack
UserTime                  00:00:00.281
KernelTime                00:00:01.484
Win32 Start Address DllA!OperationThread (0x1003b37e)
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init f65a3000 Current f65a2c60 Base f65a3000 Limit f65a0000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
f65a2c78 8083d5b1 nt!KiSwapContext+0x26
f65a2ca4 8083df9e nt!KiSwapThread+0x2e5
f65a2cec 8092ae67 nt!KeWaitForSingleObject+0x346
f65a2d50 80833bef nt!NtWaitForSingleObject+0x9a
f65a2d50 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ f65a2d64)
0293fd18 7c827d29 ntdll!KiFastSystemCallRet
0293fd1c 77e61d1e ntdll!ZwWaitForSingleObject+0xc
0293fd8c 77e61c8d kernel32!WaitForSingleObjectEx+0xac
0293fda0 724c705b kernel32!WaitForSingleObject+0x12
0293fdb4 724c6745 DllB!Cleanup+0x3b
[...]
0293fde0 7c81a352 DllB!DLLEntry+0x62
0293fe00 7c830e90 ntdll!LdrpCallInitRoutine+0x14
0293feb8 77e668ab ntdll!LdrShutdownProcess+0x182
0293ffa4 77e6690d kernel32!_ExitProcess+0×43
0293ffb8 77e792c1 kernel32!ExitProcess+0×14

0293ffec 00000000 kernel32!BaseThreadStart+0×5f

However, the brief scan of all other processes and threads from !process 0 ff command output shows that another important service ServiceB has critical section wait chains:

THREAD 89e1f890  Cid 09f4.1018  Teb: 7ff96000 Win32Thread: bc279160 WAIT: (Unknown) UserMode Non-Alertable
    89d96c30  SynchronizationEvent
Not impersonating
DeviceMap                 e10028c8
Owning Process            8a453b18       Image:         ServiceB.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      11750950       Ticks: 9763 (0:00:02:32.546)
Context Switch Count      327                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address msvcrt!_endthreadex (0×77bcb4bc)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init f6113000 Current f6112c60 Base f6113000 Limit f6110000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 1
Kernel stack not resident.
ChildEBP RetAddr 
f6112c78 8083d5b1 nt!KiSwapContext+0×26
f6112ca4 8083df9e nt!KiSwapThread+0×2e5
f6112cec 8092ae67 nt!KeWaitForSingleObject+0×346
f6112d50 80833bef nt!NtWaitForSingleObject+0×9a
f6112d50 7c82860c nt!KiFastCallEntry+0xfc
09eafd98 7c827d29 ntdll!KiFastSystemCallRet
09eafd9c 7c83d266 ntdll!ZwWaitForSingleObject+0xc
09eafdd8 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×1a3
09eafdf8 6738d489 ntdll!RtlEnterCriticalSection+0xa8

[…]
09eaffb8 77e6482f msvcrt!_endthreadex+0xa3
09eaffec 00000000 kernel32!BaseThreadStart+0×34

We switch to this process and find the owner of a critical section that blocks other threads:

0: kd> .process /r /p 8a453b18
Implicit process is now 8a453b18

0: kd> !cs -l -o -s
[...]
DebugInfo          = 0x0a199ea0
Critical section   = 0x0998ac80 (+0x998AC80)
LOCKED
LockCount          = 0x5
WaiterWoken        = No
OwningThread       = 0x00001680
RecursionCount     = 0x1
LockSemaphore      = 0xE08
SpinCount          = 0x00000000
OwningThread       = .thread 89bfc4d8
[…]

0: kd> !thread 89bfc4d8 1f
THREAD 89bfc4d8  Cid 09f4.1680  Teb: 7ff70000 Win32Thread: bc1e79d8 WAIT: (Unknown) UserMode Non-Alertable
    89bfc6c4  Semaphore Limit 0x1
Waiting for reply to LPC MessageId 00fbbc86:
Current LPC port e544f108
Not impersonating
DeviceMap                 e10028c8
Owning Process            8a453b18       Image:         ServiceB.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      11049035       Ticks: 711678 (0:03:05:19.968)
Context Switch Count      455269                 LargeStack
UserTime                  00:00:45.312
KernelTime                00:00:10.531
Win32 Start Address msvcrt!_endthreadex (0×77bcb4bc)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init f3b8b000 Current f3b8ac08 Base f3b8b000 Limit f3b88000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
f3b8ac20 8083d5b1 nt!KiSwapContext+0×26
f3b8ac4c 8083df9e nt!KiSwapThread+0×2e5
f3b8ac94 8093edb1 nt!KeWaitForSingleObject+0×346
f3b8ad50 80833bef nt!NtRequestWaitReplyPort+0×776
f3b8ad50 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ f3b8ad64)
0f13ebe8 7c827899 ntdll!KiFastSystemCallRet
0f13ebec 77c80a6e ntdll!ZwRequestWaitReplyPort+0xc
0f13ec38 77c7fcf0 RPCRT4!LRPC_CCALL::SendReceive+0×230
0f13ec44 77c80673 RPCRT4!I_RpcSendReceive+0×24
0f13ec58 77ce315a RPCRT4!NdrSendReceive+0×2b
0f13f040 771f40c4 RPCRT4!NdrClientCall2+0×22e
[…]
0f13ffb8 77e6482f msvcrt!_endthreadex+0xa3
0f13ffec 00000000 kernel32!BaseThreadStart+0×34

Following LPC chain we find that the blocking thread in ServiceB was waiting for a response from ServiceA:

0: kd> !lpc message 00fbbc86
[...]
    Server process  : 89d6d8e8 (ServiceA.exe)
[…]

Now the question arises: who was freezing first, ServiceA or ServiceB? We can compare waiting times to answer. We see that waiting time for ServiceB request thread is 3:05:19 and for ServiceA shutdown thread is 03:05:32 (from !thread and !process output above):

Owning Process            8a453b18       Image:         ServiceB.exe
[...]
Wait Start TickCount      11049035       Ticks: 711678 (0:03:05:19.968)

Owning Process            89d6d8e8       Image:         ServiceA.exe
[...]
Wait Start TickCount      11048203       Ticks: 712510 (0:03:05:32.968)

Therefore, we conclude that ServiceB was blocked after ServiceA was blocked. Such questions often arise in multivendor troubleshooting scenarious.

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 65b)

Monday, November 16th, 2009

This is a hardware counterpart of Not My Version pattern. Some problems manifest themselves on different hardware not used at the time of the product testing. In such cases we can look at kernel and complete memory dumps, extract hardware information using !sysinfo command and compare differences. This is similar to Virtualized System pattern and might provide troubleshooting hints. One example, I have seen in the past, involved a graphics intensive application that relied heavily upon hardware acceleration features. It was tested with certain processors and chipsets but after a few years failed to work on one computer despite the same OS image and drivers. !sysinfo command revealed significant hardware differences: the failing client computer was newer faster multiprocessor machine.

- Dmitry Vostokov @ DumpAnalysis.org -

Advanced .NET Debugging Book

Monday, November 16th, 2009

This weekend noticed that it is in stock and this means that I soon get it in the post:

Advanced .NET Debugging (Addison-Wesley Microsoft Technology Series)

Buy from Amazon

I plan to start reading it as soon as it arrives and put notes on my Software Generalist blog.

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 91)

Thursday, November 12th, 2009

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

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

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

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

0: kd> dp b60cdfbc L00000002
b60cdfbc  89b87770 b97004ac

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

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

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

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

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

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

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

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

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

- Dmitry Vostokov @ DumpAnalysis.org -

BoBo Address (Debugging Slang, Part 4)

Thursday, November 12th, 2009
bobo address - an address a system will definitely crash at, given an opportunity

Examples: bad0b0b0, 00000000

- Dmitry Vostokov @ DumpAnalysis.org -

BAD0B0B0 Address: Childhood Memories

Thursday, November 12th, 2009

The system crashes at it (Google search shows 164,000 hits). Notice the second part “b0b0″ after “bad”. For my eyes (I wear glasses) it is “bobo” – that was my mother telling me when I was a child and I was about to touch a hot or sharp object.

Bad! Bo-bo!

Was the address value designed intentionally or it is just a coincidence?

- Dmitry Vostokov @ DumpAnalysis.org -

Memory Dumps from Physicalist Artist Perspective

Monday, November 9th, 2009

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 90)

Wednesday, October 28th, 2009

Sometimes we have a managed code exception that was enveloping a handled unmanaged code exception, Mixed (Nested) Exception:

0:000> !analyze -v

[...]

EXCEPTION_RECORD:  ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 00000000
ExceptionCode: 80000003 (Break instruction exception)
ExceptionFlags: 00000000
NumberParameters: 0

ERROR_CODE: (NTSTATUS) 0x80000003 - {EXCEPTION}  Breakpoint  A breakpoint has been reached.

FAULTING_THREAD:  00000cfc

[...]

EXCEPTION_OBJECT: !pe 1f9af1ac
Exception object: 1f9af1ac
Exception type: System.AccessViolationException
Message: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
InnerException: <none>
StackTrace (generated):
SP       IP       Function
    0012EF3C 28DD9AF9 DllA!Component.getFirstField()+0×11
[…]
0012EFC8 7B194170 System_Windows_Forms_ni!System.Windows.Forms. Control.OnClick(System.EventArgs)+0×70
0012EFE0 7B6F74B4 System_Windows_Forms_ni!System.Windows.Forms. Control.WmMouseUp(System.Windows.Forms.Message ByRef, System.Windows.Forms.MouseButtons, Int32)+0×170
0012F06C 7BA29B66 System_Windows_Forms_ni!System.Windows.Forms. Control.WndProc(System.Windows.Forms.Message ByRef)+0×861516
0012F0C4 7B1D1D6A System_Windows_Forms_ni!System.Windows.Forms. ScrollableControl.WndProc(System.Windows.Forms.Message ByRef)+0×2a
0012F0D0 7B1C8640 System_Windows_Forms_ni!System.Windows.Forms. Control+ControlNativeWindow.OnMessage(System.Windows.Forms.Message ByRef)+0×10
0012F0D8 7B1C85C1 System_Windows_Forms_ni!System.Windows.Forms. Control+ControlNativeWindow.WndProc(System.Windows.Forms.Message ByRef)+0×31
0012F0EC 7B1C849A System_Windows_Forms_ni!System.Windows.Forms. NativeWindow.Callback(IntPtr, Int32, IntPtr, IntPtr)+0×5a

[...]

We see that it was the access violation exception and check the thread with TID cfc:

0:000> kL
ChildEBP RetAddr
0012db54 77d70dde ntdll!KiFastSystemCallRet
0012db58 7b1d8e48 user32!NtUserWaitMessage+0xc
0012dbec 7b1d8937 System_Windows_Forms_ni+0x208e48
0012dc44 7b1d8781 System_Windows_Forms_ni+0x208937
0012dc74 7b6edd1f System_Windows_Forms_ni+0x208781
0012dc8c 7b72246b System_Windows_Forms_ni+0x71dd1f
0012dd18 7b722683 System_Windows_Forms_ni+0x75246b
0012dd58 7b6f77f6 System_Windows_Forms_ni+0x752683
0012dd64 7b6fa27c System_Windows_Forms_ni+0x7277f6
0012f148 77d6f8d2 System_Windows_Forms_ni+0x72a27c
0012f174 77d6f794 user32!InternalCallWinProc+0x23
0012f1ec 77d70008 user32!UserCallWinProcCheckWow+0x14b
0012f250 77d70060 user32!DispatchMessageWorker+0x322
0012f260 0a1412fa user32!DispatchMessageW+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
0012f27c 578439f7 0xa1412fa
0012f2ec 578430c9 WindowsBase_ni+0x939f7
0012f2f8 5784306c WindowsBase_ni+0x930c9
0012f304 55bed46e WindowsBase_ni+0x9306c
0012f310 55bec76f PresentationFramework_ni+0x1cd46e
0012f334 55bd3aa6 PresentationFramework_ni+0x1cc76f

If there was an exception it must be hidden so we inspect the thread raw stack:

0:000> !teb
TEB at 7ffdf000
ExceptionList:        0012e470
StackBase:            00130000
StackLimit:           0011e000

SubSystemTib:         00000000
FiberData:            00001e00
ArbitraryUserPointer: 00000000
Self:                 7ffdf000
EnvironmentPointer:   00000000
ClientId:             00000b6c . 00000cfc
RpcHandle:            00000000
Tls Storage:          7ffdf02c
PEB Address:          7ffd4000
LastErrorValue:       0
LastStatusValue:      c0000139
Count Owned Locks:    0
HardErrorMode:        0

0:000> dps 0011e000 00130000
0011e000  00000000
0011e004  00000000
0011e008  00000000
[...]
0012e72c  00130000
0012e730  0011e000
0012e734  00ee350d
0012e738  0012ea3c
0012e73c  77f299f7 ntdll!KiUserExceptionDispatcher+0xf
0012e740  0012e750
0012e744  0012e76c
0012e748  0012e750
0012e74c  0012e76c
0012e750  c0000005
0012e754  00000000
0012e758  00000000
0012e75c  77f17d89 ntdll!RtlLeaveCriticalSection+0×9
0012e760  00000002
0012e764  00000001
0012e768  00000028
0012e76c  0001003f
0012e770  00000000
0012e774  00000000
0012e778  00000000
0012e77c  00000000
[…]

0:000> .cxr 0012e76c
eax=00000020 ebx=09ca1fa0 ecx=781c1b78 edx=00000001 esi=00000020 edi=09ca1ff8
eip=77f17d89 esp=0012ea38 ebp=0012ea3c iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00010202
ntdll!RtlLeaveCriticalSection+0x9:
77f17d89 834608ff        add     dword ptr [esi+8],0FFFFFFFFh ds:0023:00000028=????????

0:000> kL
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr
0012ea3c 7813e5b5 ntdll!RtlLeaveCriticalSection+0x9
0012ea44 2071c9ba msvcr80!_unlock_file+0x35
WARNING: Stack unwind information not available. Following frames may be wrong.
0012ea68 2071c31e DllB!getType+0×286a
0012ee34 206bbfbc DllB!getType+0×3eb
0012ee68 206c8abb DllC+0xbfbc
0012ee98 79e71ca7 DllC!getFirstField+0×3b

0012f148 77d6f8d2 mscorwks!NDirectGenericStubReturnFromCall
0012f1ec 77d70008 user32!InternalCallWinProc+0×23
0012f240 77db51b9 user32!DispatchMessageWorker+0×322
0012f4a4 79e95feb user32!_W32ExceptionHandler+0×18
0012f4fc 79e968b0 mscorwks!MetaSig::HasRetBuffArg+0×5
0012f50c 79e9643e mscorwks!MetaSig::MetaSig+0×3a
0012f610 79e96534 mscorwks!MethodDesc::CallDescr+0xaf
0012f62c 79e96552 mscorwks!MethodDesc::CallTargetWorker+0×1f
0012f644 79eefa45 mscorwks!MethodDescCallSite::CallWithValueTypes+0×1a
0012f7a8 79eef965 mscorwks!ClassLoader::RunMain+0×223

Therefore we identified DllB and DllC components as suspicious. If we check exception chain we see that .NET runtime registered custom exception handlers:

0:000> !exchain
0012e470: mscorwks!COMPlusNestedExceptionHandler+0 (79edd6d7)
0012f13c: mscorwks!FastNExportExceptHandler+0 (7a00a2e7)

0012f1dc: user32!_except_handler4+0 (77db51ba)
0012f240: user32!_except_handler4+0 (77db51ba)
0012f46c: mscorwks!COMPlusFrameHandler+0 (79edc3bc)
0012f4c0: mscorwks!_except_handler4+0 (79f908a2)
0012f798: mscorwks!_except_handler4+0 (79f908a2)
0012fa04: mscorwks!GetManagedNameForTypeInfo+a680 (7a328d90)
0012fed4: mscorwks!GetManagedNameForTypeInfo+82c8 (7a325a3a)
0012ff20: mscorwks!_except_handler4+0 (79f908a2)
0012ff6c: mscorwks!GetManagedNameForTypeInfo+a6e (7a319ee4)
0012ffc4: ntdll!_except_handler4+0 (77ed9834)
Invalid exception stack at ffffffff

We check that GetManagedNameForTypeInfo+a6e (7a319ee4) is an exception handler indeed:

0:000> .asm no_code_bytes
Assembly options: no_code_bytes

0:000> uf 7a319ee4
msvcr80!__CxxFrameHandler:
78158aeb push ebp
78158aec mov ebp,esp
78158aee sub esp,8
78158af1 push ebx
78158af2 push esi
78158af3 push edi
78158af4 cld
78158af5 mov dword ptr [ebp-4],eax
78158af8 xor eax,eax
78158afa push eax
78158afb push eax
78158afc push eax
78158afd push dword ptr [ebp-4]
78158b00 push dword ptr [ebp+14h]
78158b03 push dword ptr [ebp+10h]
78158b06 push dword ptr [ebp+0Ch]
78158b09 push dword ptr [ebp+8]
78158b0c call msvcr80!__InternalCxxFrameHandler (7815897e)
78158b11 add esp,20h
78158b14 mov dword ptr [ebp-8],eax
78158b17 pop edi
78158b18 pop esi
78158b19 pop ebx
78158b1a mov eax,dword ptr [ebp-8]
78158b1d mov esp,ebp
78158b1f pop ebp
78158b20 ret

mscorwks!__CxxFrameHandler3:
79f5f258 jmp dword ptr [mscorwks!_imp____CxxFrameHandler3 (79e711c4)]

mscorwks!GetManagedNameForTypeInfo+0xa6e:
7a319ee4 mov edx,dword ptr [esp+8]
7a319ee8 lea eax,[edx+0Ch]
7a319eeb mov ecx,dword ptr [edx-30h]
7a319eee xor ecx,eax
7a319ef0 call mscorwks!__security_check_cookie (79e72037)
7a319ef5 mov eax,offset mscorwks!_CT??_R0H+0xc14 (7a319f00)
7a319efa jmp mscorwks!__CxxFrameHandler3 (79f5f258)

- Dmitry Vostokov @ DumpAnalysis.org -

Bugtation No.107

Tuesday, October 27th, 2009

“Simplifying computing with a” crash.

Dmitry Vostokov’s excavative exclamation upon hearing a marketing slogan “I have a crush on you”

- Dmitry Vostokov @ DumpAnalysis.org -

DNA and RNA of Ruptured Computation

Friday, October 23rd, 2009

First, I introduce the notion of a ruptured computation that is a relaunched, restarted or resumed process from a checkpoint after a rupture in its fabric, for example, crash, hang, spike and leak forcing termination. DNA can be an abbreviation of a Dump of Nasty Application or Double-ruptures of Nasty Application but I got an enlightenment spike in my head recently after recognizing that C, H, S and L are 4 DNA bases: Crash, Hang, Spike and Leak. Do you see a parallel with the real DNA and its 4 bases: A, T, G, C? Now a sample of a  ruptured computation DNA strand (imagine, we launch an application and it crashes, …, crashes, …, crashes, …, spikes, …, crashes, …, hangs, …) can be represented as: …CCCSCH… . What about its second strand? I’m in search of it now but in the mean time I introduce the second notion of RNA (Really Nasty Application or Ruptures of Nasty Application) that is just one strand of …CCCSCH… as needed (real RNA is mostly single-stranded).

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 89)

Friday, October 23rd, 2009

When looking at stack traces seasoned memory dump analysis and software maintenance engineers immediately spot the right function to dig into its source code:

STACK_TEXT:
05b3f514 66ed52d3 08d72fee 08da6fc4 05b3f540 msvcrt!wcscpy+0xe
05b3f53c 77c50193 07516fc8 06637fc4 00000006 ModuleA!Add+0xd8
05b3f568 77cb33e1 66ed51fb 05b3f750 00000006 rpcrt4!Invoke+0x30
05b3f968 77cb1968 08d6afe0 0774cf4c 0660af28 rpcrt4!NdrStubCall2+0x299
[...]

Most will start with ModuleA!Add and examine parameters to wcscpy. This is because wcscpy (UNICODE version of strcpy) is considered as a Well-Tested Function. For the purposes of default analysis via !analyse -v command it is possible to configure WinDbg to ignore our own functions and modules as well if we are sure they were well-tested or pass-through. For details please see the old minidump analysis case study.

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 88)

Friday, October 23rd, 2009

Some modules like drivers or runtime DLLs are always present after some action has happened. I call them Effect Components. It is the last thing to assume them to be the “Cause” components” or “Root Cause” or the so so called “culprit” components. Typical example, is dump disk driver symbolic references found in execution residue on the raw stack of a running bugchecking thread:

0: kd> !thread
THREAD fffffa8002bdebb0  Cid 03c4.03f0  Teb: 000007fffffde000 Win32Thread: fffff900c20f9810 RUNNING on processor 0
IRP List:
    fffffa8002b986f0: (0006,0118) Flags: 00060000  Mdl: 00000000
Not impersonating
DeviceMap                 fffff88005346920
Owning Process            fffffa80035bec10       Image:         Application.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      35246          Ticks: 7 (0:00:00:00.109)
Context Switch Count      1595                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.031
Win32 Start Address Application (0x0000000140002708)
Stack Init fffffa600495ddb0 Current fffffa600495d720
Base fffffa600495e000 Limit fffffa6004955000 Call 0
Priority 11 BasePriority 8 PriorityDecrement 1 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Call Site
fffffa60`0495d558 fffff800`0186e3ee : nt!KeBugCheckEx
fffffa60`0495d560 fffff800`0186d2cb : nt!KiBugCheckDispatch+0×6e
fffffa60`0495d6a0 fffffa60`03d5917a : nt!KiPageFault+0×20b (TrapFrame @ fffffa60`0495d6a0)
[…]

0: kd> dps fffffa6004955000 fffffa600495e000
fffffa60`04955000  00d4d0c8`00d4d0c8
fffffa60`04955008  00d4d0c8`00d4d0c8
fffffa60`04955010  00d4d0c8`00d4d0c8
[…]
fffffa60`0495c7e0  00000000`00000001
fffffa60`0495c7e8  fffffa60`02877f6f dump_SATA_Driver!RecordExecutionHistory+0xcf
fffffa60`0495c7f0  fffffa80`024c05a8
fffffa60`0495c7f8  fffffa60`02869ad4 dump_dumpata!IdeDumpNotification+0×1a4
fffffa60`0495c800  fffffa60`0495cb00
fffffa60`0495c808  fffff800`0182ff34 nt!output_l+0×6c0
fffffa60`0495c810  fffffa60`02860110 crashdmp!StrBeginningDump
fffffa60`0495c818  fffffa60`0495cb00
fffffa60`0495c820  00000000`00000000
fffffa60`0495c828  fffffa60`02869b18 dump_dumpata!IdeDumpNotification+0×1e8
fffffa60`0495c830  00000000`00000000
fffffa60`0495c838  fffffa60`0495c8c0
fffffa60`0495c840  00000000`00000000
fffffa60`0495c848  fffffa60`00000024
fffffa60`0495c850  00000000`ffffffff
fffffa60`0495c858  00000000`00000000
fffffa60`0495c860  00000000`00000000
fffffa60`0495c868  fffffa60`0495cb00
fffffa60`0495c870  fffffa80`00000000
fffffa60`0495c878  00000000`00000000
fffffa60`0495c880  00000000`00000101
fffffa60`0495c888  fffffa60`02877f6f dump_SATA_Driver!RecordExecutionHistory+0xcf
fffffa60`0495c890  fffffa60`0495cb0f
fffffa60`0495c898  fffff800`0182ff34 nt!output_l+0×6c0
fffffa60`0495c8a0  fffffa60`0495cb0f
fffffa60`0495c8a8  fffffa60`0495cb90
fffffa60`0495c8b0  00000000`00000040
fffffa60`0495c8b8  fffffa60`02877f6f dump_SATA_Driver!RecordExecutionHistory+0xcf
fffffa60`0495c8c0  fffffa80`024c0728
fffffa60`0495c8c8  fffffa80`024c0728
fffffa60`0495c8d0  00000001`00000000
fffffa60`0495c8d8  fffffa60`00000026
fffffa60`0495c8e0  00000000`ffffffff
fffffa60`0495c8e8  00000000`00000000
fffffa60`0495c8f0  fffffa80`00000000
fffffa60`0495c8f8  fffffa60`0495cb90
fffffa60`0495c900  00000000`00000000
fffffa60`0495c908  fffffa60`02877f6f dump_SATA_Driver!RecordExecutionHistory+0xcf
fffffa60`0495c910  00000000`00000000
fffffa60`0495c918  fffffa60`02877f6f dump_SATA_Driver!RecordExecutionHistory+0xcf
fffffa60`0495c920  fffff880`05311010
fffffa60`0495c928  00000000`00000002
fffffa60`0495c930  fffffa60`02875094 dump_SATA_Driver!AhciAdapterControl
fffffa60`0495c938  fffffa80`024c6018
fffffa60`0495c940  fffffa80`024c0728
fffffa60`0495c948  fffffa60`02877f6f dump_SATA_Driver!RecordExecutionHistory+0xcf
fffffa60`0495c950  fffffa80`024c0728
fffffa60`0495c958  00000000`00000000
fffffa60`0495c960  fffffa60`0495ca18
fffffa60`0495c968  00000000`00000000
fffffa60`0495c970  fffffa80`024c0728
fffffa60`0495c978  fffffa60`02876427 dump_SATA_Driver!AhciHwInitialize+0×337
fffffa60`0495c980  fffffa80`024c0be6
fffffa60`0495c988  fffffa60`0286a459 dump_dumpata!IdeDumpWaitOnRequest+0×79
fffffa60`0495c990  00000000`00000000
fffffa60`0495c998  00000000`0000023a
fffffa60`0495c9a0  20474e55`534d4153
fffffa60`0495c9a8  204a4831`36314448
fffffa60`0495c9b0  20202020`20202020
fffffa60`0495c9b8  20202020`20202020
fffffa60`0495c9c0  fffffa80`024c05a8
fffffa60`0495c9c8  fffffa60`02869b18 dump_dumpata!IdeDumpNotification+0×1e8
fffffa60`0495c9d0  00000000`00000000
fffffa60`0495c9d8  fffffa60`0495ca60
fffffa60`0495c9e0  00000000`00000001
fffffa60`0495c9e8  fffffa60`02869396 dump_dumpata!IdeDumpMiniportChannelInitialize+0×236
fffffa60`0495c9f0  fffffa80`024c05a8
fffffa60`0495c9f8  fffffa60`02869ad4 dump_dumpata!IdeDumpNotification+0×1a4
fffffa60`0495ca00  00000000`00000000
fffffa60`0495ca08  fffffa60`0495ca90
fffffa60`0495ca10  00000000`00000001
fffffa60`0495ca18  00000001`00000038
fffffa60`0495ca20  00000000`10010000
fffffa60`0495ca28  00000000`00000003
fffffa60`0495ca30  fffffa80`024c05a8
fffffa60`0495ca38  fffffa60`0286a954 dump_dumpata!AtaPortGetPhysicalAddress+0×2c
fffffa60`0495ca40  fffffa80`024c0728
fffffa60`0495ca48  fffffa60`02877f6f dump_SATA_Driver!RecordExecutionHistory+0xcf
fffffa60`0495ca50  00000000`00000001
fffffa60`0495ca58  0000003f`022a8856
fffffa60`0495ca60  fffffa80`0000000c
fffffa60`0495ca68  fffffa80`024c0728
fffffa60`0495ca70  00000000`00000200
fffffa60`0495ca78  fffffa60`02877f6f dump_SATA_Driver!RecordExecutionHistory+0xcf
fffffa60`0495ca80  fffffa80`024c0728
fffffa60`0495ca88  ffff6226`4f5f3eb8
fffffa60`0495ca90  00000000`00000010
fffffa60`0495ca98  fffffa60`02860370 crashdmp!Context+0×30
fffffa60`0495caa0  fffffa80`024c05a8
fffffa60`0495caa8  fffffa60`02875a0d dump_SATA_Driver!AhciHwStartIo+0×69d
fffffa60`0495cab0  fffffa80`024c0728
fffffa60`0495cab8  00000000`00000000
fffffa60`0495cac0  00000000`00000001
fffffa60`0495cac8  fffff800`018f3dfc nt!DisplayCharacter+0×5c
fffffa60`0495cad0  00000000`00000000
fffffa60`0495cad8  fffffa60`02877f6f dump_SATA_Driver!RecordExecutionHistory+0xcf
fffffa60`0495cae0  00000000`00010000
fffffa60`0495cae8  00000000`00000000
fffffa60`0495caf0  fffffa60`0495cd10
fffffa60`0495caf8  fffffa60`0495cc00
fffffa60`0495cb00  fffffa80`024c01c0
fffffa60`0495cb08  fffffa60`02875c3f dump_SATA_Driver!AhciHwInterrupt+0×2b
fffffa60`0495cb10  fffffa80`024c05a8
fffffa60`0495cb18  00000000`00000000
fffffa60`0495cb20  00000000`00000000
fffffa60`0495cb28  fffff800`01d406c9 hal!KeStallExecutionProcessor+0×25
fffffa60`0495cb30  00000000`00010000
fffffa60`0495cb38  00000000`00000000
fffffa60`0495cb40  fffffa60`0495cd10
fffffa60`0495cb48  fffffa60`0495cc00
fffffa60`0495cb50  00000000`00000000
fffffa60`0495cb58  fffffa60`0286a429 dump_dumpata!IdeDumpWaitOnRequest+0×49
fffffa60`0495cb60  fffffa60`02860370 crashdmp!Context+0×30
fffffa60`0495cb68  00000000`d8bda325
fffffa60`0495cb70  00000000`00000000
fffffa60`0495cb78  00000000`0000033e
fffffa60`0495cb80  00000000`00000000
fffffa60`0495cb88  fffffa60`028694d2 dump_dumpata!IdeDumpWritePending+0xee
fffffa60`0495cb90  fffffa80`024c0000
fffffa60`0495cb98  fffffa80`024c01c0
fffffa60`0495cba0  00000000`00000000
fffffa60`0495cba8  00000000`00000000
fffffa60`0495cbb0  fffffa80`024c01c0
fffffa60`0495cbb8  fffffa80`01e3c740
fffffa60`0495cbc0  00000000`00010000
fffffa60`0495cbc8  00000000`00000000
fffffa60`0495cbd0  00000000`0c01f000
fffffa60`0495cbd8  fffffa60`0285bca9 crashdmp!WritePageSpanToDisk+0×181
fffffa60`0495cbe0  00000000`83d81000
fffffa60`0495cbe8  00000000`00000000
fffffa60`0495cbf0  fffffa60`02860370 crashdmp!Context+0×30
fffffa60`0495cbf8  00000000`00000002
fffffa60`0495cc00  00000000`00000000
fffffa60`0495cc08  00000000`00030000
fffffa60`0495cc10  00000000`00000000
fffffa60`0495cc18  fffffa60`00441000
fffffa60`0495cc20  fffffa60`00441000
fffffa60`0495cc28  00000000`00010000
fffffa60`0495cc30  00000000`0000c080
fffffa60`0495cc38  00000000`0000c081
fffffa60`0495cc40  00000000`0000c082
fffffa60`0495cc48  00000000`0000c083
fffffa60`0495cc50  00000000`0000c084
fffffa60`0495cc58  00000000`0000c085
fffffa60`0495cc60  00000000`0000c086
fffffa60`0495cc68  00000000`0000c087
fffffa60`0495cc70  00000000`0000c088
fffffa60`0495cc78  00000000`0000c089
fffffa60`0495cc80  00000000`0000c08a
fffffa60`0495cc88  00000000`0000c08b
fffffa60`0495cc90  00000000`0000c08c
fffffa60`0495cc98  00000000`0000c08d
fffffa60`0495cca0  00000000`0000c08e
fffffa60`0495cca8  00000000`0000c08f
fffffa60`0495ccb0  00000000`00000000
fffffa60`0495ccb8  00000000`00000000
fffffa60`0495ccc0  00000000`00000000
fffffa60`0495ccc8  00000000`00000010
fffffa60`0495ccd0  00000000`0000c01d
fffffa60`0495ccd8  fffffa60`02860370 crashdmp!Context+0×30
fffffa60`0495cce0  00000000`0000bf80
fffffa60`0495cce8  00000000`00000001
fffffa60`0495ccf0  00000000`00000000
fffffa60`0495ccf8  fffffa80`01e353d0
fffffa60`0495cd00  fffffa80`01e353f8
fffffa60`0495cd08  fffffa60`0285bacc crashdmp!WriteFullDump+0×70
fffffa60`0495cd10  00000002`3a3d8000
fffffa60`0495cd18  00000000`0000c080
fffffa60`0495cd20  fffffa80`00000000
fffffa60`0495cd28  fffffa60`0285c9c0 crashdmp!CrashdmpWriteRoutine
fffffa60`0495cd30  fffff880`05311010
fffffa60`0495cd38  00000000`00000002
fffffa60`0495cd40  fffffa60`0495cf70
fffffa60`0495cd48  00000000`00000000
fffffa60`0495cd50  fffffa60`02860370 crashdmp!Context+0×30
fffffa60`0495cd58  fffffa60`0285b835 crashdmp!DumpWrite+0xc5
fffffa60`0495cd60  00000000`00000000
fffffa60`0495cd68  00000000`0000000f
fffffa60`0495cd70  00000000`00000001
fffffa60`0495cd78  fffffa60`00000001
fffffa60`0495cd80  fffffa80`02bdebb0
fffffa60`0495cd88  fffffa60`0285b153 crashdmp!CrashdmpWrite+0×57
fffffa60`0495cd90  00000000`00000000
fffffa60`0495cd98  fffffa60`028602f0 crashdmp!StrInitPortDriver
fffffa60`0495cda0  00000000`00000000
fffffa60`0495cda8  fffffa60`02860a00 crashdmp!ContextCopy
fffffa60`0495cdb0  00000000`00000000
fffffa60`0495cdb8  fffff800`01902764 nt!IoWriteCrashDump+0×3f4
fffffa60`0495cdc0  fffffa60`0495ce00
fffffa60`0495cdc8  00000028`00000025
fffffa60`0495cdd0  fffff800`018afd40 nt! ?? ::FNODOBFM::`string’
fffffa60`0495cdd8  00000000`000000d1
fffffa60`0495cde0  fffff880`05311010
fffffa60`0495cde8  00000000`00000002
fffffa60`0495cdf0  00000000`00000000
fffffa60`0495cdf8  fffffa60`03d5917a
fffffa60`0495ce00  202a2a2a`0a0d0a0d
fffffa60`0495ce08  7830203a`504f5453
fffffa60`0495ce10  31443030`30303030
fffffa60`0495ce18  46464646`78302820
fffffa60`0495ce20  31333530`30383846
fffffa60`0495ce28  fffff800`018f5f83 nt!VidDisplayString+0×143
fffffa60`0495ce30  30303030`30300030
fffffa60`0495ce38  2c323030`30303030
fffffa60`0495ce40  30303030`30307830
fffffa60`0495ce48  30303030`30303030
fffffa60`0495ce50  46464678`302c3030
fffffa60`0495ce58  fffff800`018fe040 nt!KiInvokeBugCheckEntryCallbacks+0×80
fffffa60`0495ce60  fffffa80`02bdebb0
fffffa60`0495ce68  fffff800`01921d52 nt!InbvDisplayString+0×72
fffffa60`0495ce70  fffff880`05311000
fffffa60`0495ce78  fffff800`01d406c9 hal!KeStallExecutionProcessor+0×25
fffffa60`0495ce80  00000000`00000001
fffffa60`0495ce88  00000000`0000000a
fffffa60`0495ce90  fffffa60`03d5917a
fffffa60`0495ce98  00000000`40000082
fffffa60`0495cea0  00000000`00000001
fffffa60`0495cea8  fffff800`01922c3e nt!KeBugCheck2+0×92e
fffffa60`0495ceb0  fffff800`000000d1
fffffa60`0495ceb8  00000000`000004d0
fffffa60`0495cec0  fffff800`01a43640 nt!KiProcessorBlock
fffffa60`0495cec8  00000000`0000000a
fffffa60`0495ced0  fffffa60`03d5917a
fffffa60`0495ced8  fffffa60`0495cf70
fffffa60`0495cee0  fffffa80`02bdebb0
fffffa60`0495cee8  00000000`00000000
fffffa60`0495cef0  00000000`00000000
fffffa60`0495cef8  fffffa80`02bdebb0
fffffa60`0495cf00  00000000`c21a6d00
fffffa60`0495cf08  00000000`00000000
fffffa60`0495cf10  fffff800`0198e7a0 nt!KiInitialPCR+0×2a0
fffffa60`0495cf18  fffff800`0198e680 nt!KiInitialPCR+0×180
fffffa60`0495cf20  fffffa80`02bb7320
fffffa60`0495cf28  00000000`00000000
fffffa60`0495cf30  00000000`00000000
fffffa60`0495cf38  fffff960`00000003
fffffa60`0495cf40  fffffa60`0495e000
fffffa60`0495cf48  fffffa60`04955000
fffffa60`0495cf50  00000001`c0643000
fffffa60`0495cf58  00000000`00000000
fffffa60`0495cf60  fffff900`c06ca53c
fffffa60`0495cf68  fffffa60`0495d090
fffffa60`0495cf70  00000000`00000000
fffffa60`0495cf78  00000000`00000000
fffffa60`0495cf80  00000000`00000000
fffffa60`0495cf88  00000000`00000000
fffffa60`0495cf90  00000000`00000000
fffffa60`0495cf98  00000000`00000000
fffffa60`0495cfa0  00001f80`0010000f
fffffa60`0495cfa8  0053002b`002b0010
fffffa60`0495cfb0  00000286`0018002b
fffffa60`0495cfb8  00000000`00000000
fffffa60`0495cfc0  00000000`00000000
fffffa60`0495cfc8  00000000`00000000
fffffa60`0495cfd0  00000000`00000000
fffffa60`0495cfd8  00000000`00000000
fffffa60`0495cfe0  00000000`00000000
fffffa60`0495cfe8  fffffa60`0495d660
fffffa60`0495cff0  00000000`0000000a
fffffa60`0495cff8  fffff880`05311010
fffffa60`0495d000  fffff880`05311010
fffffa60`0495d008  fffffa60`0495d558
fffffa60`0495d010  fffffa60`0495d720
fffffa60`0495d018  fffffa80`02b986f0
fffffa60`0495d020  fffffa80`02b98720
fffffa60`0495d028  00000000`00000002
fffffa60`0495d030  00000000`00000000
fffffa60`0495d038  fffffa60`03d5917a
fffffa60`0495d040  00000000`000001f1
fffffa60`0495d048  fffffa80`026a9df0
fffffa60`0495d050  00000000`00000001
fffffa60`0495d058  00000000`83360018
fffffa60`0495d060  fffffa80`02b3ee40
fffffa60`0495d068  fffff800`0186e650 nt!KeBugCheckEx
fffffa60`0495d070  00000000`00000000
fffffa60`0495d078  00000000`00000000
fffffa60`0495d080  00000000`00000000
fffffa60`0495d088  00000000`00000000
fffffa60`0495d090  00000000`00000000
fffffa60`0495d098  00000000`00000000
fffffa60`0495d0a0  00000000`00000000
[…]

If a BSOD was reported after installing new drivers we shouldn’t suspect SATA_Driver package here because its components would almost always be present on any bugcheck thread as referenced after a bugcheck cause. There presence is the “effect”. This example might seem trivial and pointless but I’ve seen some memory dump analysis conclusions based on the reversal of causes and effects.

- Dmitry Vostokov @ DumpAnalysis.org -

Software Victimology (Part 1)

Friday, October 23rd, 2009

What prompted me to found this discipline (that is supposed to be a sister discipline of software criminology, software security, secure code construction and software defect construction) is understanding that some software components are innocent victims of other component coding mistakes or deliberate subversion and some start as a part of crimeware but eventually become victims themselves (they crash, hang, spike, leak, are dumped, subverted, etc.). I would also like to borrow and reuse the neglected term victimware here in a broad sense. More on this later as I have to switch to software trace analysis patterns.

- Dmitry Vostokov @ DumpAnalysis.org -