Archive for the ‘Crash Dump Analysis’ Category

Inconsistent dump, blocked threads, wait chains, incorrect stack trace and process factory: pattern cooperation

Tuesday, June 9th, 2009

The more busy the system is, the more inconsistent are complete memory dumps produced by external physical memory dumpers. On the contrary, quiet systems, with idle existent users and when no one can connect, are more consistent than usual. Here is one example:

Loading Dump File [complete_dump.dmp]
Kernel Complete Dump File: Full address space is available

[...]

WARNING: Process directory table base 00039000 doesn't match CR3 CB759000
[...]

BugCheck 0, {0, 0, 0, 0}

Probably caused by : LiveKdD.SYS ( LiveKdD+12d1 )

In such cases I often dump all processes and threads to look for anomalies and indeed we find plenty of blocked threads in several services. For example, ServiceA.exe has blocked threads waiting for critical sections and LPC requests:

0: kd> !process 0 ff
**** NT ACTIVE PROCESS DUMP ****

[...]

THREAD 86f21118  Cid 07d4.2914  Teb: 7ffa5000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     86f21304  Semaphore Limit 0x1
Waiting for reply to LPC MessageId 00f2b546:
Current LPC port d79c6e00
Impersonation token:  db621028 (Level Impersonation)
DeviceMap                 dca24d50
Owning Process            88948d88       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      14788708       Ticks: 3643121 (0:15:48:43.765)
Context Switch Count      52            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address ServiceA!EventWorkerThread (0×0042e2f8)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b2246000 Current b2245c08 Base b2246000 Limit b2243000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
b2245c10 00000000 0×149c3
[…]

THREAD 8736fdb0  Cid 07d4.3cc4  Teb: 7ff9c000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     8736ff9c  Semaphore Limit 0x1
Waiting for reply to LPC MessageId 00f2b518:
Current LPC port d79c6e00
Impersonation token:  da1b51a8 (Level Impersonation)
DeviceMap                 d9f9e368
Owning Process            88948d88       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      14788707       Ticks: 3643122 (0:15:48:43.781)
Context Switch Count      44            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address ServiceA!EventWorkerThread (0×0042e2f8)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init ae5d3000 Current ae5d2c08 Base ae5d3000 Limit ae5d0000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
WARNING: Frame IP not in any known module. Following frames may be wrong.
ae5d2c10 3fe63bfa 0×73e40763
[…]

THREAD 85e89c80  Cid 07d4.5648  Teb: 7ff6a000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     871d6e80  SynchronizationEvent
Impersonation token:  d7a1c028 (Level Impersonation)
DeviceMap                 d66ef860
Owning Process            88948d88       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      14320472       Ticks: 4111357 (0:17:50:39.953)
Context Switch Count      28            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0x00ebebcc
LPC Server thread working on message Id ebebcc
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init a536b000 Current a536ac60 Base a536b000 Limit a5368000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
a536ac78 8083d5b1 nt!KiSwapContext+0x26
a536aca4 8083df9e nt!KiSwapThread+0x2e5
a536acec 8092ae57 nt!KeWaitForSingleObject+0x346
a536ad50 80833bdf nt!NtWaitForSingleObject+0x9a
a536ad50 7c8285ec nt!KiFastCallEntry+0xfc
05b6f7d0 7c827d0b ntdll!KiFastSystemCallRet
05b6f7d4 7c83d236 ntdll!NtWaitForSingleObject+0xc
05b6f810 7c83d281 ntdll!RtlpWaitOnCriticalSection+0×1a3
05b6f830 0040bb5b ntdll!RtlEnterCriticalSection+0xa8

05b6f874 00415889 ServiceA!OnRequest+0×23
[…]
05b6f8b4 77ce33e1 RPCRT4!Invoke+0×30
05b6fcb4 77ce35c4 RPCRT4!NdrStubCall2+0×299
05b6fcd0 77c7ff7a RPCRT4!NdrServerCall2+0×19
05b6fd04 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
05b6fd58 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
05b6fd7c 77c7e0d4 RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
05b6fdbc 77c7e080 RPCRT4!RPC_INTERFACE::DispatchToStubWithObject+0xc0
05b6fdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×41e
05b6fe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
05b6ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
05b6ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
05b6ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
05b6ffb8 77e64829 RPCRT4!ThreadStartRoutine+0×1b
05b6ffec 00000000 kernel32!BaseThreadStart+0×34

Knowing that ServiceA is crucial for our system functions we examine LPC wait chains. All “Waiting for reply to LPC MessageId <…>” threads depend on another service:

0: kd> !lpc message 00f2b546
Searching message f2b546 in threads ...
Client thread 86f21118 waiting a reply from f2b546                         
    Server thread 860cc9e0 is working on message f2b546
[…]
    Server process  : 87d21698 (svchost.exe)
[…]

We find this thread in svchost.exe hosting ServiceB:

0: kd> !thread 860cc9e0 1f
THREAD 860cc9e0  Cid 1310.4ad8  Teb: 7ff88000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     871d47d0  Mutant - owning thread 867322e0
Not impersonating
DeviceMap                 d64008f8
Owning Process            87d21698       Image:         svchost.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      14788708       Ticks: 3643121 (0:15:48:43.765)
Context Switch Count      1791            
UserTime                  00:00:00.031
KernelTime                00:00:00.046
Win32 Start Address 0×00f2b546
LPC Server thread working on message Id f2b546
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b055e000 Current b055dc60 Base b055e000 Limit b055b000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
b055dc78 8083d5b1 nt!KiSwapContext+0×26
b055dca4 8083df9e nt!KiSwapThread+0×2e5
b055dcec 8092ae57 nt!KeWaitForSingleObject+0×346
b055dd50 80833bdf nt!NtWaitForSingleObject+0×9a
b055dd50 7c8285ec nt!KiFastCallEntry+0xfc
0400f718 7c827d0b ntdll!KiFastSystemCallRet
0400f71c 7654bf59 ntdll!NtWaitForSingleObject+0xc
0400f73c 7654c694 ServiceB!Lock+0×42
0400f754 76558b17 ServiceB!FindObjectById+0×39
0400f8ac 7654fa50 ServiceB!QueryInformation+0×3e
0400f8c8 77c80193 ServiceB!RpcQueryInformation+0×49
0400f8f8 77ce33e1 RPCRT4!Invoke+0×30
0400fcf8 77ce35c4 RPCRT4!NdrStubCall2+0×299
0400fd14 77c7ff7a RPCRT4!NdrServerCall2+0×19
0400fd48 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
0400fd9c 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
0400fdc0 77c811dc RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
0400fdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×42c
0400fe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
0400ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
0400ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
0400ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
0400ffb8 77e64829 RPCRT4!ThreadStartRoutine+0×1b
0400ffec 00000000 kernel32!BaseThreadStart+0×34

We notice that about 45 threads are waiting for the mutant 871d47d0 owned by thread 867322e0, like this one with incorrect stack trace because of inconsistent dump file data:

0: kd> !thread 86cad210 1f
THREAD 86cad210  Cid 1310.31a4  Teb: 7ff15000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     871d47d0  Mutant - owning thread 867322e0
Not impersonating
DeviceMap                 d64008f8
Owning Process            87d21698       Image:         svchost.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      18020896       Ticks: 410933 (0:01:47:00.828)
Context Switch Count      43            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address RPCRT4!ThreadStartRoutine (0×77c7b0f5)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init abb1b000 Current abb1ac60 Base abb1b000 Limit abb18000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
Kernel stack not resident.
ChildEBP RetAddr 
WARNING: Frame IP not in any known module. Following frames may be wrong.
abb1ac68 60203020 0×84
[…]

We inspect the thread 867322e0:

0: kd> !thread 867322e0 1f
THREAD 867322e0  Cid 1310.26dc  Teb: 7ff56000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
     869d4020  ProcessObject
     86732358  NotificationTimer
Not impersonating
DeviceMap                 d64008f8
Owning Process            87d21698       Image:         svchost.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      18454684    
Context Switch Count      5172            
UserTime                  00:00:00.000
KernelTime                00:00:00.031
Win32 Start Address 0×0083fd5d
LPC Server thread working on message Id 83fd5d
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init ad350000 Current ad34fc60 Base ad350000 Limit ad34d000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
ad34fc78 8083d5b1 nt!KiSwapContext+0×26
ad34fca4 8083df9e nt!KiSwapThread+0×2e5
ad34fcec 8092ae57 nt!KeWaitForSingleObject+0×346
ad34fd50 80833bdf nt!NtWaitForSingleObject+0×9a
ad34fd50 7c8285ec nt!KiFastCallEntry+0xfc
04f5fbec 7c827d0b ntdll!KiFastSystemCallRet
04f5fbf0 76548721 ntdll!NtWaitForSingleObject+0xc
04f5fc0c 7654c596 ServiceB!WaitForProcess+0×4a

04f5ffb8 77e64829 ServiceB!LpcThread+0×14e
04f5ffec 00000000 kernel32!BaseThreadStart+0×34

We see that it is waiting for the process 869d4020 and we find the latter one with a single thread blocked by DriverA:

0: kd> !process 869d4020 ff
PROCESS 869d4020  SessionId: 18  Cid: 56b8    Peb: 7ffde000  ParentCid: 3608
    DirBase: 758b3000  ObjectTable: dd7083c0  HandleCount:  79.
    Image: rundll32.exe
    VadRoot 869d5228 Vads 107 Clone 0 Private 330. Modified 1706. Locked 0.
    DeviceMap d8d260a8
    Token                             dfa8f028
    ElapsedTime                       1 Day 23:52:06.918
    UserTime                          00:00:00.312
    KernelTime                        00:00:01.484
    QuotaPoolUsage[PagedPool]         34784
    QuotaPoolUsage[NonPagedPool]      5016
    Working Set Sizes (now,min,max)  (810, 50, 345) (3240KB, 200KB, 1380KB)
    PeakWorkingSetSize                2088
    VirtualSize                       37 Mb
    PeakVirtualSize                   47 Mb
    PageFaultCount                    34473
    MemoryPriority                    BACKGROUND
    BasePriority                      10
    CommitCharge                      707
[..]
    CommandLine:  ‘rundll32 C:\WINDOWS\system32\DllA.dll,CheckData /name”PropertyA”‘
[…]

THREAD 86bac020  Cid 56b8.4904  Teb: 7ffdb000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
     8774a930  NotificationEvent
Not impersonating
DeviceMap                 d8d260a8
Owning Process            869d4020       Image:         rundll32.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10113815       Ticks: 8318014 (1:12:06:08.968)
Context Switch Count      188            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0x2b169ecb
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init af12b000 Current af12ac34 Base af12b000 Limit af128000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
af12ac4c 8083d5b1 nt!KiSwapContext+0x26
af12ac78 8083df9e nt!KiSwapThread+0x2e5
af12acc0 b5075a82 nt!KeWaitForSingleObject+0x346
WARNING: Stack unwind information not available. Following frames may be wrong.
af12acf4 b507f989 DriverA+0×3a82
[…]

We also check virtual memory consumption and instantly see hundreds of rundll32.exe processes like in a process factory pattern:

0: kd> !vm
[...]
57f4 rundll32.exe       586 (      2344 Kb)
57d0 rundll32.exe       586 (      2344 Kb)
57b4 rundll32.exe       586 (      2344 Kb)
578c rundll32.exe       586 (      2344 Kb)
5780 rundll32.exe       586 (      2344 Kb)
577c rundll32.exe       586 (      2344 Kb)
5744 rundll32.exe       586 (      2344 Kb)
572c rundll32.exe       586 (      2344 Kb)
5724 rundll32.exe       586 (      2344 Kb)
5708 rundll32.exe       586 (      2344 Kb)
56d4 rundll32.exe       586 (      2344 Kb)
56a4 rundll32.exe       586 (      2344 Kb)
564c rundll32.exe       586 (      2344 Kb)
5630 rundll32.exe       586 (      2344 Kb)
55e0 rundll32.exe       586 (      2344 Kb)
55b8 rundll32.exe       586 (      2344 Kb)
55ac rundll32.exe       586 (      2344 Kb)
558c rundll32.exe       586 (      2344 Kb)
550c rundll32.exe       586 (      2344 Kb)
546c rundll32.exe       586 (      2344 Kb)
5428 rundll32.exe       586 (      2344 Kb)
5418 rundll32.exe       586 (      2344 Kb)
53d0 rundll32.exe       586 (      2344 Kb)
53bc rundll32.exe       586 (      2344 Kb)
53b0 rundll32.exe       586 (      2344 Kb)
53a8 rundll32.exe       586 (      2344 Kb)
530c rundll32.exe       586 (      2344 Kb)
5300 rundll32.exe       586 (      2344 Kb)
52e8 rundll32.exe       586 (      2344 Kb)
52a4 rundll32.exe       586 (      2344 Kb)
5294 rundll32.exe       586 (      2344 Kb)
5228 rundll32.exe       586 (      2344 Kb)
5118 rundll32.exe       586 (      2344 Kb)
50bc rundll32.exe       586 (      2344 Kb)
50a8 rundll32.exe       586 (      2344 Kb)
5080 rundll32.exe       586 (      2344 Kb)
5030 rundll32.exe       586 (      2344 Kb)
4fc8 rundll32.exe       586 (      2344 Kb)
4f88 rundll32.exe       586 (      2344 Kb)
4ef0 rundll32.exe       586 (      2344 Kb)
4e84 rundll32.exe       586 (      2344 Kb)
4e70 rundll32.exe       586 (      2344 Kb)
4e68 rundll32.exe       586 (      2344 Kb)
4e4c rundll32.exe       586 (      2344 Kb)
4e38 rundll32.exe       586 (      2344 Kb)
4df8 rundll32.exe       586 (      2344 Kb)
4df4 rundll32.exe       586 (      2344 Kb)
4d2c rundll32.exe       586 (      2344 Kb)
4d00 rundll32.exe       586 (      2344 Kb)
4cd4 rundll32.exe       586 (      2344 Kb)
4cbc rundll32.exe       586 (      2344 Kb)
4c90 rundll32.exe       586 (      2344 Kb)
4c80 rundll32.exe       586 (      2344 Kb)
4c68 rundll32.exe       586 (      2344 Kb)
4c40 rundll32.exe       586 (      2344 Kb)
[...]

By switching the current process context to 869d4020 (.process /r /p command) and using lmv command we check vendors for DllA and DriverA. It seems that they are different. We also see that DllA module is no longer loaded (not seen in the module list) by the time DriverA is waiting for a notification event. All rundll32.exe processes are waiting for that DriverA kernel module. We therefore decide to contact its vendor.

- Dmitry Vostokov @ DumpAnalysis.org -

Chemistry of Virtual Memory Space (Part 1)

Tuesday, June 9th, 2009

I was reading General Chemistry book on the way to my office today and found a nice basic chemical formula representation for processes in memory. In this nomenclature, the class of modules developed by a particular vendor constitutes an ”element”. For example, M is for Microsoft modules, C is for Citrix modules, etc. Individual modules of particular elements are similar to “atoms” and denoted as numbers in subscript. For example, net.exe command running in a typical Citrix terminal services environment has the following loaded modules where I highlighted Citrix modules in blue and Microsoft modules in red:

0:000> lm1m
net
wdmaudhook
tzhook
twnhook
scardhook
mmhook
mfaphook
cxinjime
CtxSbxHook

MPR
NETAPI32
Secur32
USER32
msvcrt
GDI32
RPCRT4
kernel32
ADVAPI32
MSVCR71
ntdll

Therefore the formula is this:

M12C8.

I put the element of the main process module first in such formulae.

The formula for IE process from the following case study:

M126A5U

where A is for Adobe modules and U is for an unknown module that needs identification, see Unknown Component pattern.  

These formulas can useful to highlight various hooksware components and distinguish memory dumps generated after eliminating modules for troubleshooting and debugging purposes. It also forms the basis for one of many classificatory schemes for the purposes of micro- and macro-taxonomy of software discussed in the forthcoming book: 

The Variety of Software: The Richness of Computation (ISBN: 978-1906717544) 

In the forthcoming parts I’m also going to discuss the structural formulas as well, similar to the ones used in organic chemistry. 

- Dmitry Vostokov @ DumpAnalysis.org -

Main blocked thread, missing component, execution residue and data contents locality: pattern cooperation

Monday, June 8th, 2009

The application failed to start and exception monitor saved the process memory dump with the following stack trace of the main thread that was blocked by raising a status:

0:000> !analyze -v

[...]

ERROR_CODE: (NTSTATUS) 0xc0150004 - The referenced assembly is not installed on your system.

[...]

STACK_TEXT: 
0012fca4 7c93f14e c0150004 0012fd30 7c90d950 ntdll!RtlRaiseStatus+0×26
0012fd1c 7c90e437 0012fd30 7c900000 00000000 ntdll!_LdrpInitialize+0×241
00000000 00000000 00000000 00000000 00000000 ntdll!KiUserApcDispatcher+0×7

[...]

The error code suggests that some DLL was missing. We see that the process just started indeed and only a few DLL were loaded:

0:000> version
Windows XP Version 2600 (Service Pack 3) MP (2 procs) Free x86 compatible
[...]
System Uptime: 0 days 18:00:08.328
Process Uptime: 0 days 0:00:05.000
  Kernel time: 0 days 0:00:00.000
  User time: 0 days 0:00:00.000
[…]

0:000> !dlls -l

0x00261ec0: C:\Program Files\CompanyA\Application.exe
      Base   0x00400000  EntryPoint  0x00410a13  Size        0x00057000
      Flags  0x00005000  LoadCount   0x0000ffff  TlsIndex    0x00000000
             LDRP_LOAD_IN_PROGRESS
             LDRP_ENTRY_PROCESSED

0x00261f18: C:\WINDOWS\system32\ntdll.dll
      Base   0x7c900000  EntryPoint  0x7c912c28  Size        0x000af000
      Flags  0x00085004  LoadCount   0x0000ffff  TlsIndex    0x00000000
             LDRP_IMAGE_DLL
             LDRP_LOAD_IN_PROGRESS
             LDRP_ENTRY_PROCESSED
             LDRP_PROCESS_ATTACH_CALLED

0x00261fc0: C:\WINDOWS\system32\kernel32.dll
      Base   0x7c800000  EntryPoint  0x7c80b63e  Size        0x000f6000
      Flags  0x00085004  LoadCount   0x0000ffff  TlsIndex    0x00000000
             LDRP_IMAGE_DLL
             LDRP_LOAD_IN_PROGRESS
             LDRP_ENTRY_PROCESSED
             LDRP_PROCESS_ATTACH_CALLED

So we try to find any execution residue left on the raw stack that suggests the name of the missing DLL. We dump all raw stack range and try to interpret every double word as a pointer to UNICODE and ASCII strings. We find these entries:

0:000> !teb
TEB at 7ffde000
    ExceptionList:        0012fd0c
    StackBase:            00130000
    StackLimit:           0012e000

    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7ffde000
    EnvironmentPointer:   00000000
    ClientId:             000001dc . 00000dc8
    RpcHandle:            00000000
    Tls Storage:          00000000
    PEB Address:          7ffdf000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0

0:000> dpa 0012e000 00130000
0012e000  00000000
0012e004  00000000
0012e008  00000000
0012e00c  00000000
[…]
0012f28c  0012f2a0 “”
0012f290  7c945afc “SXS: RtlGetAssemblyStorageRoot() unable to resolve stor”
0012f294  00000000
0012f298  7c91eaf4 “”
0012f29c  7c91eaf4 “”
0012f2a0  00000000
0012f2a4  00000001
0012f2a8  35313063
0012f2ac  34303030
0012f2b0  00000001
0012f2b4  0012f34c “SXS: RtlGetAssemblyStorageRoot().Z.|…”
0012f2b8  000074da
0012f2bc  0012f2f8 “”
0012f2c0  7c92fb96 “…….t..M…^..”
0012f2c4  0012f2d8 “”
0012f2c8  7c945afc “SXS: RtlGetAssemblyStorageRoot() unable to resolve stor”
0012f2cc  00000000
[…]

0:000> dpu 0012e000 00130000
0012e000  00000000
0012e004  00000000
0012e008  00000000
0012e00c  00000000
0012e010  00000000
[…]
0012f164  020800ac
0012f168  0012f194 “C:\WINDOWS\WinSxS\x86_Microsoft.VC80.CRT_1fc8b3b9a1e18e”
0012f16c  00000000
0012f170  00000000
0012f174  00860086
0012f178  001505d0 “x86_Microsoft.VC80.CRT_1fc8b3b9a1e18e3b_8.0.50727.762_x”
0012f17c  00000000
0012f180  00000000
0012f184  019101bb
0012f188  ffffffff
[…]

We also find this path by visual inspection of the raw stack data that is located near the exception code c0150004:

0:000> dc 0012e000 00130000
0012e000  00000000 00000000 00000000 00000000  …………….
0012e010  00000000 00000000 00000000 00000000  …………….
[…]
0012f190  0012f164 003a0043 0057005c 004e0049  d…C.:.\.W.I.N.
0012f1a0  004f0044 00530057 0057005c 006e0069  D.O.W.S.\.W.i.n.
0012f1b0  00780053 005c0053 00380078 005f0036  S.x.S.\.x.8.6._.
0012f1c0  0069004d 00720063 0073006f 0066006f  M.i.c.r.o.s.o.f.
0012f1d0  002e0074 00430056 00300038 0043002e  t…V.C.8.0…C.
0012f1e0  00540052 0031005f 00630066 00620038  R.T._.1.f.c.8.b.
0012f1f0  00620033 00610039 00650031 00380031  3.b.9.a.1.e.1.8.
0012f200  00330065 005f0062 002e0038 002e0030  e.3.b._.8…0…
0012f210  00300035 00320037 002e0037 00360037  5.0.7.2.7…7.6.
0012f220  005f0032 002d0078 00770077 0036005f  2._.x.-.w.w._.6.
0012f230  00310062 00380032 00300037 005c0030  b.1.2.8.7.0.0.\.

0012f240  00000000 002a056c 000006e2 001601c8  ….l.*………
0012f250  00000001 00000fa0 7c911066 7c9101bb  ……..f..|…|
0012f260  00000000 00271f10 00000004 7c910ee4  ……’……..|
0012f270  35313063 34303030 00000314 0000000a  c0150004……..
0012f280  000074da 0012f2c0 7c92fb96 0012f2a0  .t………|….
0012f290  7c945afc 00000000 7c91eaf4 7c91eaf4  .Z.|…….|…|
0012f2a0  00000000 00000001 35313063 34303030  ……..c0150004
0012f2b0  00000001 0012f34c 000074da 0012f2f8  ….L….t……
0012f2c0  7c92fb96 0012f2d8 7c945afc 00000000  …|…..Z.|….
0012f2d0  7c91eaf4 7c91eaf4 00000000 00000001  …|…|……..
0012f2e0  0012f2fc 7c92fcbb 00000001 0012f384  …….|……..
0012f2f0  0000005b 00000035 00000000 0012f5a0  […5………..
0012f300  7c92fc78 0012f37c 00000035 7c91eab5  x..||…5……|
0012f310  00000000 c0150004 00000003 00000000  …………….
0012f320  00150020 00000000 0012f57c 7c935996   …….|….Y.|
0012f330  00162f90 7c945afc 0012f598 00000000  ./…Z.|……..
0012f340  0000005b 7c91005b 0012f34c 3a535853  […[..|L…SXS:
0012f350  6c745220 41746547 6d657373 53796c62   RtlGetAssemblyS
0012f360  61726f74 6f526567 2928746f 7c945afc  torageRoot().Z.|
[…]

0:000> du /c 90 012f190+4
0012f194  “C:\WINDOWS\WinSxS\x86_Microsoft. VC80.CRT_1fc8b3b9a1e18e3b_8.0.50727.762_x-ww_6b128700\”

Doing Google search we find that others experienced similar problems and they were resolved by (re-)installing VC++ 2005 redistribution package and the latest service pack.

- Dmitry Vostokov @ DumpAnalysis.org -

Quantum Memory Dumps (Part 1)

Friday, June 5th, 2009

Quantum computation, quantum memory and quantum information are hot topics today. Unfortunately quantum mechanics forbids perfect (ideal) memory dumps due to the so called no cloning theorem. Still it is possible to get inconsistent (imperfect) memory dumps and perfect memory dumps can be made from quantum computer simulators. The analysis of quantum memory snapshots is the domain of Quantum Memoretics.

- Dmitry Vostokov @ DumpAnalysis.org -

Software Engineering for Memory Analysis

Thursday, June 4th, 2009

Sometimes I’m asked about a broad software engineering book to recommend for general memory dump analysis that covers software architecture, design methods and diagramming languages like UML, programming languages, concurrency, real-time issues and many other topics you need to know to have systems understanding that helps in problem identification and debugging. Here’s the book that I was fortunate to buy 4-5 years ago in a book shop and is a sheer pleasure to read:

Software Engineering for Real-Time Systems

Buy from Amazon

Today I found that there even exists an OMG certification based on it:

http://www.omg.org/ocres/exam-info.htm

I might try later this summer. 

- Dmitry Vostokov @ DumpAnalysis.org -

Irish Government on Dumps

Thursday, June 4th, 2009

Whom to blame if a process or a system crashes or freezes?

“Mr. Quinn: It is very dangerous to ignore political dumps these days. Mr. Dempsey: All dumps are political.”

Source

- Dmitry Vostokov @ DumpAnalysis.org -

Manual dump, virtualized process, stack trace collection, multiple exceptions, optimized code, wild code pointer, incorrect stack trace and hidden exception: pattern cooperation

Thursday, June 4th, 2009

The following WER dialog appeared after I copied an RTF text from an e-mail client to IE while editing another blog post:

 

Although the dialog points to html.iec it is good to show the basic techniques for component identification using WinDbg. I took a manual user dump of that unresponsive process while it was showing that dialog above using Task Manager:

The saved process memory dump shows that IE was virtualized 32-bit process running on x64 Windows:

STACK_TEXT: 
00000000`000dee18 00000000`75bbab46 : wow64cpu!TurboDispatchJumpAddressEnd+0xef
00000000`000deec0 00000000`75bba14c : wow64!Wow64SystemServiceEx+0×27a
00000000`000deef0 00000000`778f52d3 : wow64!Wow64LdrpInitialize+0×4b4
00000000`000df450 00000000`778f5363 : ntdll!CsrClientConnectToServer+0×493
00000000`000df700 00000000`778e85ce : ntdll!CsrClientConnectToServer+0×523
00000000`000df7b0 00000000`00000000 : ntdll!LdrInitializeThunk+0xe

However, even after switching to x86 mode, !analyze -v doesn’t report any signs of exception violation, c0000005, seen from WER dialog above:

0:000> .load wow64exts; .effmach x86
Effective machine: x86 compatible (x86)

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

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

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

STACK_TEXT: 
0027e428 7679e91a ntdll_77a60000!NtWaitForMultipleObjects+0x15
0027e4c4 76a58f76 kernel32!WaitForMultipleObjectsEx+0x11d
0027e518 75ad6071 user32!RealMsgWaitForMultipleObjectsEx+0x14d
WARNING: Frame IP not in any known module. Following frames may be wrong.
0027e538 75ad61f0 ieui+0x6071
0027e560 75ad6196 ieui+0x61f0
0027e59c 7291ffc6 ieui+0x6196
0027e5a8 7290f579 ieframe!BrowserThreadProc+0x3f
0027e5cc 7290f4c7 ieframe!BrowserNewThreadProc+0x7b
0027f63c 728fd1ba ieframe!SHOpenFolderWindow+0x188
0027f86c 013133c3 ieframe!IEWinMain+0x2d9
0027fcb0 0131325a iexplore!wWinMain+0x27b
0027fd44 7680e4a5 iexplore!_initterm_e+0x1b1
0027fd50 77adcfed kernel32!BaseThreadInitThunk+0xe
0027fd90 77add1ff ntdll_77a60000!__RtlUserThreadStart+0x23
0027fda8 00000000 ntdll_77a60000!_RtlUserThreadStart+0x1b

We list all threads for any exception processing signs and we find one such thread indeed:

0:002:x86> ~*kc 100

[...]

   2  Id: 404.ba4 Suspend: 0 Teb: 7efaa000 Unfrozen

ntdll_77a60000!NtWaitForMultipleObjects
kernel32!WaitForMultipleObjectsEx
kernel32!WaitForMultipleObjects
kernel32!WerpReportFaultInternal
kernel32!WerpReportFault
kernel32!UnhandledExceptionFilter
ntdll_77a60000!__RtlUserThreadStart
ntdll_77a60000!_EH4_CallFilterFunc
ntdll_77a60000!_except_handler4
ntdll_77a60000!ExecuteHandler2
ntdll_77a60000!ExecuteHandler
ntdll_77a60000!KiUserExceptionDispatcher

WARNING: Frame IP not in any known module. Following frames may be wrong.
0×0
html!LwMultDivRU
html!FMarkListCallback
html!JcCalcFromXaExtents
html!EmitNonBreakingSpace
html!FEmitHtmlFnOtag
html!ConvertRtfToForeign
html!FceRtfToForeign
html!RtfToForeign32
mshtmled!CRtfToHtmlConverter::ExternalRtfToInternalHtml
mshtmled!CRtfToHtmlConverter::StringRtfToStringHtml
mshtmled!CRtfToHtmlConverter::StringRtfToStringHtml
mshtmled!CHTMLEditor::ConvertRTFToHTML
mshtmled!CPasteCommand::PasteFromClipboard
mshtmled!CPasteCommand::PrivateExec
mshtmled!CCommand::Exec
mshtmled!CMshtmlEd::Exec
mshtml!CEditRouter::ExecEditCommand
mshtml!CDoc::ExecHelper
mshtml!CFrameSite::Exec
mshtml!CDoc::RouteCTElement
mshtml!CDoc::ExecHelper
mshtml!CDoc::Exec
mshtml!CDoc::OnCommand
mshtml!CDoc::OnWindowMessage
mshtml!CServer::WndProc
user32!InternalCallWinProc
user32!UserCallWinProcCheckWow
user32!SendMessageWorker
user32!SendMessageW
mshtml!CElement::PerformTA
mshtml!CDoc::PerformTA
mshtml!CDoc::PumpMessage
mshtml!CDoc::DoTranslateAccelerator
mshtml!CServer::TranslateAcceleratorW
mshtml!CDoc::TranslateAcceleratorW
ieframe!CProxyActiveObject::TranslateAcceleratorW
ieframe!CDocObjectView::TranslateAcceleratorW
ieframe!CCommonBrowser::v_MayTranslateAccelerator
ieframe!CShellBrowser2::_MayTranslateAccelerator
ieframe!CShellBrowser2::v_MayTranslateAccelerator
ieframe!CTabWindow::_TabWindowThreadProc
kernel32!BaseThreadInitThunk
ntdll_77a60000!__RtlUserThreadStart
ntdll_77a60000!_RtlUserThreadStart

[...]

The same stack fragment with function parameters has a zero for its UnhandledExceptionFilter first parameter, perhaps because of optimized code reusing local variable slots, and we cannot apply .exptr meta-command:

0:002:x86> ~2kv
ChildEBP RetAddr  Args to Child             
0361d938 7679e91a 00000002 0361d988 00000001 ntdll_77a60000!NtWaitForMultipleObjects+0x15
0361d9d4 767949d9 0361d988 0361da24 00000000 kernel32!WaitForMultipleObjectsEx+0x11d
0361d9f0 7684573d 00000002 0361da24 00000000 kernel32!WaitForMultipleObjects+0x18
0361da5c 76845969 0361db2c 00000001 00000001 kernel32!WerpReportFaultInternal+0x16d
0361da70 7681c66f 0361db2c 00000001 35137a6c kernel32!WerpReportFault+0x70
0361dafc 77add03e 00000000 77aaf2d0 00000000 kernel32!UnhandledExceptionFilter+0×1b5
0361db04 77aaf2d0 00000000 0361fe04 77a8da38 ntdll_77a60000!__RtlUserThreadStart+0×6f
0361db18 77b129b3 00000000 00000000 00000000 ntdll_77a60000!_EH4_CallFilterFunc+0×12
0361db40 77a83099 fffffffe 0361fdf4 0361dc7c ntdll_77a60000!_except_handler4+0×8e
0361db64 77a8306b 0361dc2c 0361fdf4 0361dc7c ntdll_77a60000!ExecuteHandler2+0×26
0361dc14 77a82eff 0161dc2c 0361dc7c 0361dc2c ntdll_77a60000!ExecuteHandler+0×24
0361dc18 0161dc2c 0361dc7c 0361dc2c 0361dc7c ntdll_77a60000!KiUserExceptionDispatcher+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
0361df5c 72333b0e 07feaee4 0000001f 00000000 0×161dc2c
0361df74 72332ba9 00000000 0361dffc 00000000 html!LwMultDivRU+0×4b6
0361dfb8 7233518a 0361dffc 0000000c 0361e074 html!FMarkListCallback+0×56c
0361dfc8 723368b7 0000001f 0361dffc 0000000f html!JcCalcFromXaExtents+0×91
0361e074 723370c5 0000000f 00000000 000007d0 html!EmitNonBreakingSpace+0×445
0361e1a0 723407ff 00000000 0000000f 00000104 html!FEmitHtmlFnOtag+0×17d
0361e1c4 7231c6a8 00000001 00000000 00000000 html!ConvertRtfToForeign+0×105
0361e64c 7231c745 00ed03bc 00000000 00ed0374 html!FceRtfToForeign+0×266

Also the transition from html.iec module to exception processing code is through an invalid address 0×161dc2c so we might guess that this was an instance of wild code pointer or the case of incorrect stack trace. However using techniques to get exception context from hidden exceptions we get the following stack trace:

0:002:x86> .cxr 0361dc7c
eax=0000004e ebx=09d5755f ecx=07feaee4 edx=07feaf08 esi=07feaee4 edi=00000000
eip=7233d50b esp=0361df48 ebp=0361df5c iopl=0  nv up ei pl nz na pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00010206
html!FPseudoStyleBis+0×26:
7233d50b 0fb70f          movzx   ecx,word ptr [edi]       ds:002b:00000000=????

0:002:x86> kL 100
ChildEBP RetAddr 
0361df50 7233d597 html!FPseudoStyleBis+0x26
0361df5c 72333b0e html!BisFromLpxszStyle+0x1c
0361df74 72332ba9 html!LwMultDivRU+0x4b6
0361dfb8 7233518a html!FMarkListCallback+0x56c
0361dfc8 723368b7 html!JcCalcFromXaExtents+0x91
0361e074 723370c5 html!EmitNonBreakingSpace+0x445
0361e1a0 723407ff html!FEmitHtmlFnOtag+0x17d
0361e1c4 7231c6a8 html!ConvertRtfToForeign+0x105
0361e64c 7231c745 html!FceRtfToForeign+0x266
0361e674 744e5ad4 html!RtfToForeign32+0x51
0361eabc 744e5c83 mshtmled!CRtfToHtmlConverter::ExternalRtfToInternalHtml+0x163
0361ef10 7449cc15 mshtmled!CRtfToHtmlConverter::StringRtfToStringHtml+0x11a
0361ef2c 7449cd81 mshtmled!CRtfToHtmlConverter::StringRtfToStringHtml+0x38
0361ef40 744cdcea mshtmled!CHTMLEditor::ConvertRTFToHTML+0x12
0361efac 744ce392 mshtmled!CPasteCommand::PasteFromClipboard+0x2c0
0361f01c 7448d218 mshtmled!CPasteCommand::PrivateExec+0x47a
0361f040 7448d1ad mshtmled!CCommand::Exec+0x4b
0361f064 74000d14 mshtmled!CMshtmlEd::Exec+0xf9
0361f094 73ff88a8 mshtml!CEditRouter::ExecEditCommand+0xd6
0361f43c 7415eccf mshtml!CDoc::ExecHelper+0x338d
0361f488 73ff8a2f mshtml!CFrameSite::Exec+0x264
0361f4bc 73ff87af mshtml!CDoc::RouteCTElement+0xf1
0361f854 73ff8586 mshtml!CDoc::ExecHelper+0x325e
0361f874 740a0e7b mshtml!CDoc::Exec+0x1e
0361f8ac 7401a708 mshtml!CDoc::OnCommand+0x9c
0361f9c0 73f297e1 mshtml!CDoc::OnWindowMessage+0x841
0361f9ec 76a58807 mshtml!CServer::WndProc+0x78
0361fa18 76a58962 user32!InternalCallWinProc+0x23
0361fa90 76a5c4b6 user32!UserCallWinProcCheckWow+0x109
0361fad4 76a5c517 user32!SendMessageWorker+0x55b
0361faf8 7400fb9b user32!SendMessageW+0x7f
0361fb24 73f68e5a mshtml!CElement::PerformTA+0x71
0361fb44 73f68db9 mshtml!CDoc::PerformTA+0xd8
0361fbc0 73ff381c mshtml!CDoc::PumpMessage+0x8e0
0361fc74 73ff3684 mshtml!CDoc::DoTranslateAccelerator+0x33f
0361fc90 73ff34cc mshtml!CServer::TranslateAcceleratorW+0x56
0361fcb0 7296f550 mshtml!CDoc::TranslateAcceleratorW+0x83
0361fccc 7296f600 ieframe!CProxyActiveObject::TranslateAcceleratorW+0x30
0361fcf0 7296fca1 ieframe!CDocObjectView::TranslateAcceleratorW+0xb1
0361fd10 7296faf4 ieframe!CCommonBrowser::v_MayTranslateAccelerator+0xda
0361fd3c 7296f7b0 ieframe!CShellBrowser2::_MayTranslateAccelerator+0x68
0361fd4c 7296f7f5 ieframe!CShellBrowser2::v_MayTranslateAccelerator+0x15
0361fdb8 7680e4a5 ieframe!CTabWindow::_TabWindowThreadProc+0x264
0361fdc4 77adcfed kernel32!BaseThreadInitThunk+0xe
0361fe04 77add1ff ntdll_77a60000!__RtlUserThreadStart+0x23
0361fe1c 00000000 ntdll_77a60000!_RtlUserThreadStart+0x1b

Then we can use lmv command to see the component version:

0:002:x86> lmv m html
start             end                 module name
722f0000 7236f000   html     # (pdb symbols)          c:\mss\html.pdb\34A9E6645AEA4E6A83EA51D2849C731C1\html.pdb
    Loaded symbol image file: html.iec
    Image path: C:\Windows\System32\html.iec
    Image name: html.iec
    Timestamp:        Tue Mar 03 03:26:33 2009 (49ACA369)
    CheckSum:         00086241
    ImageSize:        0007F000
    File version:     2017.0.0.18226
    Product version:  6.0.6001.18226
    File flags:       0 (Mask 3F)
    File OS:          40004 NT Win32
    File type:        2.0 Dll
    File date:        00000000.00000000
    Translations:     0409.04b0
    CompanyName:      Microsoft Corporation
    ProductName:      Microsoft® Windows® Operating System
    InternalName:     HTML.IEC
    OriginalFilename: HTML.IEC
    ProductVersion:   6.0.6001.18226
    FileVersion:      2017.0.0.18226 (vistasp1_gdr.090302-1506)
    FileDescription:  Microsoft HTML Converter
    LegalCopyright:   © Microsoft Corporation. All rights reserved.

- Dmitry Vostokov @ DumpAnalysis.org -

Efficient vs. Effective: DATA View

Wednesday, June 3rd, 2009

DATA (Dump Artifact + Trace Artifact) - > DATA (Dump Analysis + Trace Analysis) examples:

1.  Efficient

- My 64Gb server bluescreens. I set a complete memory dump option in Control Panel.

- A user cannot connect. I started tracing yesterday. Stopped today.

- I analyze all these artifacts every day.

2. Effective

- My 64Gb server bluescreens. I set a kernel memory dump option in Control Panel.

- A user cannot connect. I started tracing, tried to connect, stopped tracing.

- I analyze all these artifacts every day and write articles to reduce DATA load.

- Dmitry Vostokov @ DumpAnalysis.org -

Memory Dumps Show Signs of Economic Recovery

Monday, June 1st, 2009

The number of blog visits (excluding portal main page and other my blogs) was about 15,000 - 16,000 by the end of the last year and then it dropped to 13,000. I explain this as the fact that 5% - 10% of engineers were no longer interested in crash dumps and debugging due to layoffs. This month I see the number of visits exceeds 14,000 and this surely makes me more optimistic about the prospect of economic recovery:

- Dmitry Vostokov @ DumpAnalysis.org -

New Portal Store

Sunday, May 31st, 2009

DumpAnalysis.org has changed its book store to Amazon aStore to incorporate all published OpenTask books, magazines and notebooks:

Here is the direct link:

Dump Analysis Portal Store

The screenshot:

 - Dmitry Vostokov @ DumpAnalysis.org -

The Meaning of DATA

Tuesday, May 26th, 2009

I was suddenly enlightened by the unification of software traces with memory dumps and it came to me that DATA is simply Dump Analysis + Trace Analysis. It is commutative with TADA, the sound of accomplishment (tada.wav in Windows \ Media folder).

This can’t be a coincidence, can it?

- Dmitry Vostokov @ DumpAnalysis.org -

Comprehensive Rootkit Book

Monday, May 25th, 2009

Found today this book while browsing Amazon:

The Rootkit Arsenal: Escape and Evasion in the Dark Corners of the System

Buy from Amazon

Intrigued, I searched for its table of contents and found the author’s site:

Book TOC

Looks enough comprehensive so I pre-ordered the book and plan to write a review later from windows internals and memory dump analysis perspective.

- Dmitry Vostokov @ DumpAnalysis.org -

Collapsed Stack Trace

Saturday, May 23rd, 2009

This is a stack trace (backtrace) where all finctions are removed and only modules are left. Useful for depicting component dependencies. Here is an example:

0: kd> kc 100
nt!KiSwapContext
nt!KiSwapThread
nt!KeDelayExecutionThread
3rdPartyAVDriver
3rdPartyAVDriver
3rdPartyAVDriver
3rdPartyAVDriver
nt!IofCallDriver
DriverA!Dispatch
DriverA!KUI_dispatch
nt!IofCallDriver
DriverB!PassThrough
DriverB!Dispatch
nt!IofCallDriver
DriverC!LowerPassThrough
DriverC
DriverC
DriverC
DriverC!DispatchPassThrough
nt!IofCallDriver
nt!IopParseDevice
nt!ObpLookupObjectName
nt!ObOpenObjectByName
nt!IopCreateFile
nt!IoCreateFile
nt!NtOpenFile
nt!KiFastCallEntry
ntdll!KiFastSystemCallRet
ntdll!NtOpenFile
ntdll!LdrpCreateDllSection
ntdll!LdrpMapDll
ntdll!LdrpLoadDll
ntdll!LdrLoadDll
kernel32!LoadLibraryExW
kernel32!LoadLibraryW
ntdll!LdrpCallInitRoutine
ntdll!LdrpRunInitializeRoutines
ntdll!LdrpLoadDll
ntdll!LdrLoadDll
kernel32!LoadLibraryExW
kernel32!LoadLibraryW
USER32!LoadAppDlls
USER32!ClientThreadSetup
USER32!__ClientThreadSetup
ntdll!KiUserCallbackDispatcher
nt!KiCallUserMode
nt!KeUserModeCallback
win32k!xxxClientThreadSetup
win32k!xxxCreateThreadInfo
win32k!UserThreadCallout
win32k!W32pThreadCallout
nt!PsConvertToGuiThread
nt!KiBBTUnexpectedRange

Collapsed stack trace is much simpler to grasp: 

nt
3rdPartyAVDriver
nt
DriverA
nt
DriverB
nt
DriverC
nt
ntdll
kernel32
ntdll
kernel32
USER32
ntdll
nt
win32k
nt

- Dmitry Vostokov @ DumpAnalysis.org -

Graphical Notation for Memory Dumps (Part 1)

Saturday, May 23rd, 2009

Inspired by Penrose tensor notation encountered in The Road to Reality book and Feynman diagrams I’d like to introduce Visual Dump Objects (VDO) graphical notation to depict and communicate memory dump analysis patterns, their combinations and analysis results. Let’s look at some basic visual objects (shown in handwriting).

1. A thread:

   or   

2. A function:

3. A module:

4. A thread running through functions, modules or both (stack trace). Optional arrowhead can indicate stack trace direction:

  or    or  

Threads running through modules depict collapsed stack traces.

5. A blocked thread:

An example of 3 threads blocked by another thread (an arrowhead can disambiguate the direction of the waiting chain):

6. A spiking thread (colors are encouraged in VDO notation):

   or   

7. Space boundary between user land and kernel land:

 

Here is an example of the thread spiking in kernel space:

or with modules from stack trace:

More notation to come very soon.

- Dmitry Vostokov @ DumpAnalysis.org -

Bugtation No.94

Saturday, May 23rd, 2009

Universal memory dumps come from astronomical observations:

Dumps “are meaningless without” symbols “to interpret them.”

Raymond Arthur Lyttleton, Quoted in Astroparticle Physics, page 50

- Dmitry Vostokov @ DumpAnalysis.org -

Comparative Memory Dump Analysis: CPU Spikes

Friday, May 22nd, 2009

Comparative analysis is based on saving several consecutive memory dump files to see similarities and differences. Most often this technique is used for memory leaks, for example, process heap leaks. Here we see another example related to CPU spikes.

One application was spiking CPU and its user dump file was saved manually. !runaway WinDbg command showed the following distribution of kernel and user thread times:

0:000> !runaway f
 User Mode Time
  Thread       Time
  14:f48       0 days 1:22:34.343
  15:f4c       0 days 0:00:45.671
  17:f54       0 days 0:00:41.359
  18:f58       0 days 0:00:33.468
  16:f50       0 days 0:00:24.171
  12:f40       0 days 0:00:17.531
  13:f44       0 days 0:00:07.109
   0:f10       0 days 0:00:00.500
[…]
 Kernel Mode Time
  Thread       Time
  15:f4c       0 days 0:00:51.046
  17:f54       0 days 0:00:41.125
  18:f58       0 days 0:00:32.765
  16:f50       0 days 0:00:23.500
  12:f40       0 days 0:00:18.671
  13:f44       0 days 0:00:07.453
  14:f48       0 days 0:00:02.031
   1:f14       0 days 0:00:00.343
[…]
 Elapsed Time
  Thread       Time
   1:f14       0 days 12:01:42.656
   0:f10       0 days 12:01:42.656
  24:f70       0 days 12:01:42.093
  23:f6c       0 days 12:01:42.093
  22:f68       0 days 12:01:42.093
  21:f64       0 days 12:01:42.093
  20:f60       0 days 12:01:42.093
  19:f5c       0 days 12:01:42.093
  18:f58       0 days 12:01:42.093
  17:f54       0 days 12:01:42.093
  16:f50       0 days 12:01:42.093
  15:f4c       0 days 12:01:42.093
  14:f48       0 days 12:01:42.093
  13:f44       0 days 12:01:42.093
[…]

We see that thread #14 spent 1 hour and 22 minutes in user space and only 2 seconds in kernel space. Its thread stack showed DllA and DllB modules:

0:000> ~14s
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for DllA.dll -
eax=00010da2 ebx=09227bdc ecx=09236bcc edx=0000003a esi=006769e4 edi=00000335
eip=6120b231 esp=00fefd04 ebp=00fefd2c iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
DllA!foo+0×3549:
6120b231 8b45ec          mov     eax,dword ptr [ebp-14h] ss:0023:00fefd18=09251a30

0:000> kv
ChildEBP RetAddr  Args to Child             
WARNING: Stack unwind information not available. Following frames may be wrong.
00fefd2c 6120be31 00000063 8633cdb9 006769e4 DllA!foo+0×3549
00fefd64 6120c6db 00fefe00 00006f07 0353f594 DllA!foo+0×4149
00fefdbc 6120d517 00fefe00 00fefde8 8633cd25 DllA!foo+0×49f3
00fefdf8 6120db4d 0353f594 09251848 00000000 DllA!foo+0×582f
00fefe14 6120f280 006769a0 00000000 0000020c DllA!foo+0×5e65
00fefe84 00933436 0000020c 0353f5ac 00000001 DllA!foo+0×7598

00fefec0 008414f1 0353f580 034db5d0 00000003 DllB!read+0xc6
[…]
00feffb8 77e64829 0078f290 00000000 00000000 msvcr71!_endthreadex+0xa0
00feffec 00000000 7c3494f6 0078f290 00000000 kernel32!BaseThreadStart+0×34

These modules belong to different vendors and the code could loop in DllB or in one of DllA functions. In order to show statistically which module is more suspect than the other, we requested 3 consecutive memory dumps of the same spiking process. They revealed the similar uniform pattern:

0:000> !runaway f
 User Mode Time
  Thread       Time
  16:e5c       0 days 1:37:24.640
   0:e1c       0 days 0:00:00.640
  17:e60       0 days 0:00:00.453
  18:e64       0 days 0:00:00.328
  15:e58       0 days 0:00:00.265
  14:e54       0 days 0:00:00.203
[…]
 Kernel Mode Time
  Thread       Time
  16:e5c       0 days 0:00:00.687
  15:e58       0 days 0:00:00.421
  17:e60       0 days 0:00:00.375
  14:e54       0 days 0:00:00.265
  18:e64       0 days 0:00:00.250
   0:e1c       0 days 0:00:00.046
[…]
 Elapsed Time
  Thread       Time
   1:e20       0 days 4:41:11.562
   0:e1c       0 days 4:41:11.562
  18:e64       0 days 4:41:10.875
  17:e60       0 days 4:41:10.875
  16:e5c       0 days 4:41:10.875
  15:e58       0 days 4:41:10.875
  14:e54       0 days 4:41:10.875
  13:e50       0 days 4:41:10.875
  12:e4c       0 days 4:41:10.875
  11:e48       0 days 4:41:10.875
  10:e44       0 days 4:41:10.875
   9:e40       0 days 4:41:10.875
   8:e3c       0 days 4:41:10.875
   7:e38       0 days 4:41:10.875
   6:e34       0 days 4:41:10.875
   5:e30       0 days 4:41:10.875
   4:e2c       0 days 4:41:10.875
   3:e28       0 days 4:41:10.875
   2:e24       0 days 4:41:10.875
[…]

1st dump file: Process Uptime: 0 days 4:41:12.000

0:000> ~16r
eax=07abbb6c ebx=07ab45d4 ecx=07ab4604 edx=00679344 esi=006769e4 edi=00000035
eip=6120b23e esp=0106fd30 ebp=0106fd58 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
DllA!foo+0×3556:
6120b23e 8bcb            mov     ecx,ebx

0:000> ~16kv
ChildEBP RetAddr  Args to Child             
WARNING: Stack unwind information not available. Following frames may be wrong.
0106fd58 6120be31 0000000b 47d6689c 006769e4 DllA!foo+0×3556
0106fd90 6120c6db 0106fe2c 00007329 0342d14c DllA!foo+0×4149
0106fde8 6120d517 0106fe2c 0106fe14 47d66b28 DllA!foo+0×49f3
0106fe24 6120db4d 0342d14c 07abb960 00000000 DllA!foo+0×582f
0106fe40 6120f280 006769a0 00000000 000001d8 DllA!foo+0×5e65
0106feb0 00933436 000001d8 0342d164 00000001 DllA!foo+0×7598

0106feec 008414f1 0342d138 00000000 0340b290 DllB!read+0xc6
[…]
0106ffb8 77e64829 00784be0 00000000 00000000 msvcr71!_endthreadex+0xa0
0106ffec 00000000 7c3494f6 00784be0 00000000 kernel32!BaseThreadStart+0×34

2nd dump file: Process Uptime: 0 days 4:41:42.000

0:000> ~16r
eax=0002550b ebx=00679344 ecx=07ab45d4 edx=00000009 esi=006769e4 edi=00000035
eip=6120b231 esp=0106fd30 ebp=0106fd58 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for DllA.dll -
DllA!foo+0×3549:
6120b231 8b45ec          mov     eax,dword ptr [ebp-14h] ss:0023:0106fd44=07abbb48

0:000> ~16kv
ChildEBP RetAddr  Args to Child             
WARNING: Stack unwind information not available. Following frames may be wrong.
0106fd58 6120be31 0000000b 47d6689c 006769e4 DllA!foo+0×3549
0106fd90 6120c6db 0106fe2c 00007329 0342d14c DllA!foo+0×4149
0106fde8 6120d517 0106fe2c 0106fe14 47d66b28 DllA!foo+0×49f3
0106fe24 6120db4d 0342d14c 07abb960 00000000 DllA!foo+0×582f
0106fe40 6120f280 006769a0 00000000 000001d8 DllA!foo+0×5e65
0106feb0 00933436 000001d8 0342d164 00000001 DllA!foo+0×7598

0106feec 008414f1 0342d138 00000000 0340b290 DllB!read+0xc6
[…]
0106ffb8 77e64829 00784be0 00000000 00000000 msvcr71!_endthreadex+0xa0
0106ffec 00000000 7c3494f6 00784be0 00000000 kernel32!BaseThreadStart+0×34

3rd dump file: Process Uptime: 0 days 4:41:59.000

0:000> ~16r
eax=07abbb6c ebx=07ab4604 ecx=07ab45d4 edx=07ab4604 esi=006769e4 edi=00000035
eip=6120b239 esp=0106fd30 ebp=0106fd58 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
DllA!foo+0×3551:
6120b239 895108          mov     dword ptr [ecx+8],edx ds:0023:07ab45dc=07ab4604

0:000> ~16kv
ChildEBP RetAddr  Args to Child             
WARNING: Stack unwind information not available. Following frames may be wrong.
0106fd58 6120be31 0000000b 47d6689c 006769e4 DllA!foo+0×3551
0106fd90 6120c6db 0106fe2c 00007329 0342d14c DllA!foo+0×4149
0106fde8 6120d517 0106fe2c 0106fe14 47d66b28 DllA!foo+0×49f3
0106fe24 6120db4d 0342d14c 07abb960 00000000 DllA!foo+0×582f
0106fe40 6120f280 006769a0 00000000 000001d8 DllA!foo+0×5e65
0106feb0 00933436 000001d8 0342d164 00000001 DllA!foo+0×7598

0106feec 008414f1 0342d138 00000000 0340b290 DllB!read+0xc6
[…]
0106ffb8 77e64829 00784be0 00000000 00000000 msvcr71!_endthreadex+0xa0
0106ffec 00000000 7c3494f6 00784be0 00000000 kernel32!BaseThreadStart+0×34

We see exactly the same stack trace except the first (top) frame. The offset differs very little: +0×3556, +0×3549 (twice) and +0×3551. We can suspect the small loop here:

0:000> ub
DllA!foo+0x3549:
6120b231 8b45ec          mov     eax,dword ptr [ebp-14h]
6120b234 8d0490          lea     eax,[eax+edx*4]
6120b237 8b10            mov     edx,dword ptr [eax]
6120b239 895108          mov     dword ptr [ecx+8],edx
6120b23c 8908            mov     dword ptr [eax],ecx
6120b23e 8bcb            mov     ecx,ebx
6120b240 85db            test    ebx,ebx
6120b242 75e3            jne     DllA!foo+0x353f (6120b227)

0:000> ub 6120b231
DllA!foo+0x3535:
6120b21d 8b4d08          mov     ecx,dword ptr [ebp+8]
6120b220 8b0c88          mov     ecx,dword ptr [eax+ecx*4]
6120b223 3bcb            cmp     ecx,ebx
6120b225 741d            je      DllA!foo+0x355c (6120b244)
6120b227 8b5908          mov     ebx,dword ptr [ecx+8]
6120b22a 8b410c          mov     eax,dword ptr [ecx+0Ch]
6120b22d 33d2            xor     edx,edx
6120b22f f7f7            div     eax,edi

0:000> u
DllA!foo+0x3549:
6120b231 8b45ec          mov     eax,dword ptr [ebp-14h]
6120b234 8d0490          lea     eax,[eax+edx*4]
6120b237 8b10            mov     edx,dword ptr [eax]
6120b239 895108          mov     dword ptr [ecx+8],edx
6120b23c 8908            mov     dword ptr [eax],ecx
6120b23e 8bcb            mov     ecx,ebx
6120b240 85db            test    ebx,ebx
6120b242 75e3            jne     DllA!foo+0x353f (6120b227)

0:000> u 6120b242
DllA!foo+0x355a:
6120b242 75e3            jne     DllA!foo+0x353f (6120b227)
6120b244 ff4508          inc     dword ptr [ebp+8]
6120b247 8b4508          mov     eax,dword ptr [ebp+8]
6120b24a 3b4608          cmp     eax,dword ptr [esi+8]
6120b24d 72cc            jb      DllA!foo+0x3533 (6120b21b)
6120b24f ff36            push    dword ptr [esi]
6120b251 e88dc70000      call    DllA!foo+0xfcfb (612179e3)
6120b256 59              pop     ecx

All this strongly rules out DllB and points to DllA as the first vendor contact.

- Dmitry Vostokov @ DumpAnalysis.org -

1000 Blog Posts: T&D Labyrinth

Monday, May 18th, 2009

This post number is 1,000. Wordpress admin panel reports that I have written 999 (excluding this one):

Of course, I wrote my 1,000th blog post some time ago if I count all my 7 blogs but this is 1,000th post for just this blog.

To celebrate this event, I’m posting a picture of troubleshooting and debugging labyrinth resting on a notion of universal memory dumps that are observational snapshots and include both memory and various traces we collect to resolve problems.

 

This picture shows how we arrive to problem resolution. For example:  

I’m also working on another picture, called T&D Tangram :-)

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 84)

Friday, May 15th, 2009

Sometimes the assembly code looks almost wild (not like generated by your favourite compiler). For example (that also shows .NET runtime native unhandled exception processing):

0:000> kL 100
ChildEBP RetAddr 
0014dbb4 77189254 ntdll!KiFastSystemCallRet
0014dbb8 75fec244 ntdll!ZwWaitForSingleObject+0xc
0014dc28 75fec1b2 kernel32!WaitForSingleObjectEx+0xbe
0014dc3c 72605389 kernel32!WaitForSingleObject+0x12
0014dc6c 726058e7 mscorwks!ClrWaitForSingleObject+0x24
0014e128 72608084 mscorwks!RunWatson+0x1df
0014e86c 7260874a mscorwks!DoFaultReportWorker+0xb59
0014e8a8 72657452 mscorwks!DoFaultReport+0xc3
0014e8cc 7265c0c7 mscorwks!WatsonLastChance+0x3f
0014e924 7265c173 mscorwks!CLRAddVectoredHandlers+0x209
0014e92c 7603f4be mscorwks!InternalUnhandledExceptionFilter+0x22
0014e9e8 771a85b7 kernel32!UnhandledExceptionFilter+0×127
0014e9f0 77139a14 ntdll!__RtlUserThreadStart+0×6f
0014ea04 771340f4 ntdll!_EH4_CallFilterFunc+0×12
0014ea2c 77189b99 ntdll!_except_handler4+0×8e
0014ea50 77189b6b ntdll!ExecuteHandler2+0×26
0014eb00 771899f7 ntdll!ExecuteHandler+0×24
0014eb00 03ca0141 ntdll!KiUserExceptionDispatcher+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
0014ee28 634c2f42 0×3ca0141
0014ee34 67715e44 System_ni+0×132f42
0014ee70 72431b4c System_ServiceProcess_ni+0×25e44
0014ee80 724421f9 mscorwks!CallDescrWorker+0×33
0014ef00 72456571 mscorwks!CallDescrWorkerWithHandler+0xa3
0014f03c 724565a4 mscorwks!MethodDesc::CallDescr+0×19c
0014f058 724565c2 mscorwks!MethodDesc::CallTargetWorker+0×1f
0014f070 724afac5 mscorwks!MethodDescCallSite::CallWithValueTypes+0×1a
0014f1d4 724af9e5 mscorwks!ClassLoader::RunMain+0×223
0014f43c 724aff35 mscorwks!Assembly::ExecuteMainMethod+0xa6
0014f90c 724b011f mscorwks!SystemDomain::ExecuteMainMethod+0×456
0014f95c 724b004f mscorwks!ExecuteEXE+0×59
0014f9a4 72f57c24 mscorwks!_CorExeMain+0×15c
0014f9b4 75fe4911 mscoree!_CorExeMain+0×2c
0014f9c0 7716e4b6 kernel32!BaseThreadInitThunk+0xe
0014fa00 7716e489 ntdll!__RtlUserThreadStart+0×23
0014fa18 00000000 ntdll!_RtlUserThreadStart+0×1b

We set exception context:

0:000> kv 100
ChildEBP RetAddr  Args to Child             
[...]
0014e9e8 771a85b7 0014ea18 77139a14 00000000 kernel32!UnhandledExceptionFilter+0×127 (FPO: [SEH])
[…]

0:000> .exptr 0014ea18

----- Exception record at 0014eb18:
ExceptionAddress: 03ca0141
   ExceptionCode: c0000005 (Access violation)
  ExceptionFlags: 00000000
NumberParameters: 2
   Parameter[0]: 00000000
   Parameter[1]: 00000000
Attempt to read from address 00000000

----- Context record at 0014eb34:
eax=00000001 ebx=08394ff8 ecx=00000000 edx=00000001 esi=056a2a94 edi=00000000
eip=03ca0141 esp=0014ee00 ebp=0014ee28 iopl=0         nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00010246
03ca0141 3909            cmp     dword ptr [ecx],ecx  ds:0023:00000000=????????

Then we disassemble the code at crash point and it looks strange including calls through DS data segment:

0:000> .asm no_code_bytes
Assembly options: no_code_bytes

0:000> u 03ca0141
03ca0141 cmp     dword ptr [ecx],ecx
03ca0143 call    dword ptr ds:[36067C0h]
03ca0149 mov     ecx,dword ptr [esi+5Ch]
03ca014c cmp     dword ptr [ecx],ecx
03ca014e call    dword ptr ds:[3606D10h]
03ca0154 mov     dword ptr [ebp-1Ch],0
03ca015b mov     dword ptr [ebp-18h],0FCh
03ca0162 push    3CA0180h

However further disassembly finally reaches RET instruction:

0:000> u
03ca0167 jmp     03ca0169
03ca0169 movzx   edx,byte ptr [ebp-24h]
03ca016d mov     ecx,dword ptr [ebp-28h]
03ca0170 call    System_ServiceProcess_ni+0x25140 (67715140)
03ca0175 pop     eax
03ca0176 jmp     eax
03ca0178 lea     esp,[ebp-0Ch]
03ca017b pop     ebx

0:000> u
03ca017c pop     esi
03ca017d pop     edi
03ca017e pop     ebp
03ca017f ret

03ca0180 mov     dword ptr [ebp-18h],0
03ca0187 jmp     03ca0178
03ca0189 add     byte ptr [eax],al
03ca018b add     byte ptr [eax],al

and backward disassembling shows the matching function prolog code:

0:000> ub 03ca0141
03ca0127 movzx   eax,byte ptr [ebp-24h]
03ca012b test    eax,eax
03ca012d je      03ca0154
03ca012f cmp     dword ptr [esi+60h],0
03ca0133 je      03ca013e
03ca0135 mov     ecx,dword ptr [esi+60h]
03ca0138 call    dword ptr ds:[3C20010h]
03ca013e mov     ecx,dword ptr [esi+58h]

0:000> ub 03ca0127
03ca0114 push    esi
03ca0115 push    ebx
03ca0116 sub     esp,1Ch

03ca0119 xor     eax,eax
03ca011b mov     dword ptr [ebp-18h],eax
03ca011e mov     dword ptr [ebp-28h],ecx
03ca0121 mov     dword ptr [ebp-24h],edx
03ca0124 mov     esi,dword ptr [ebp-28h]

0:000> ub 03ca0114
03ca0102 retf
03ca0103 add     eax,dword ptr [eax+36h]
03ca0106 retf
03ca0107 add     ebx,dword ptr [esi+esi-35h]
03ca010b add     esi,esp
03ca010d cmp     eax,8B550360h
03ca0112 in      al,dx
03ca0113 push    edi

From stack trace I suspected this code as JIT-compiled .NET code of the the main assemebly method. And indeed I found the similar call signatures like mine

03ca0141 cmp     dword ptr [ecx],ecx
03ca0143 call    dword ptr ds:[36067C0h]

in the following MSDN article:

Drill Into .NET Framework Internals to See How the CLR Creates Runtime Objects

Hence the name of this pattern: JIT Code.

- Dmitry Vostokov @ DumpAnalysis.org -

Pattern-Driven Memory Analysis (Part 3)

Thursday, May 14th, 2009

Part 2 briefly discussed debuggers and their commands. Debugger commands can be grouped together into scripts that can be run against memory dump files and their resulted textual output can be redirected to log files.

Therefore we start with the first step in our analysis process diagram introduced in Part 1:

Information Collection: Scripts

Here a script is a sequence of instructions to extract formatted textual information from a memory dump file (or a live system). There are many advantages of scripts and logs. Many companies, for example, banks, avoid sending plain memory dump files because of security considerations in order to prevent exposure of company or private information. After the advent of 64-bit personal computing complete memory dump files became larger and larger and it is now common to get 32Gb memory dumps. Processing multiple long-running commands can easily be done from textual log files. Additionally, scripts can be used to process hundreds of memory dumps in one go to look for similarities and differences. Many tools can be used for such purpose including built-in debugger scripting capabilities, shell scripting and regular expressions for intelligent search.

- Dmitry Vostokov @ DumpAnalysis.org -

Sentinel Pointers

Wednesday, May 13th, 2009

Consider this crash point:

0:000> r
eax=02d0f15c ebx=02a62918 ecx=77e41c30 edx=00000000 esi=ffffffff edi=02a8ed28
eip=76154193 esp=02d0f124 ebp=02d0f130 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00010246
Application!GetData+0xb:
76154193 8b9eac000000    mov     ebx,dword ptr [esi+0ACh] ds:0023:000000ab=????????

Seeing 000000ab address we can think that ESI was 0 but it was 0xFFFFFFFF. Adding 0xAC to it produced an effective NULL data pointer 0xAB through integer addition overflow if we consider addition as unsigned. It is easy to see the result if we consider 0xFFFFFFFF as signed -1. Looking at stack trace and function disassembly we see that 0xFFFFFFFF was passed as a parameter:

0:000> kv
ChildEBP RetAddr  Args to Child             
02d0f130 7616328d ffffffff 02d0f15c 02d0f150 Application!GetData+0xb
[…]
02d0ffec 00000000 740420d8 02a74070 00000000 kernel32!BaseThreadStart+0×34

0:000> u Application!GetData
Application!GetData:
76154188 mov     edi,edi
7615418a push    ebp
7615418b mov     ebp,esp
7615418d push    ecx
7615418e push    ebx
7615418f push    esi
76154190 mov     esi,dword ptr [ebp+8]
76154193 mov     ebx,dword ptr [esi+0ACh]

This is an example of a sentinel pointer marking the end of a linked list, for example, although NULL pointers having 0 value are usually used. Also -1 value can be used to assign an invalid pointer value. 

- Dmitry Vostokov @ DumpAnalysis.org -