Archive for June, 2009

Personalized MDA Certificates

Monday, June 15th, 2009

“A personal touch in Certification”

Dmitry Vostokov,
Founding Director of
Memory Analysis and Debugging Institute

More details on the previously announced MDA certification. Every certificate will have a separate unique ISBN number and available in bookshops and libraries worldwide. Of course, this comes at a price and it will be announced later. An example of a certificate as a book will be available by the end of July:

Memory Dump Analysis Certificate 0×1 (ISBN: 978-1906717766)

- Dmitry Vostokov @ DumpAnalysis.org -  

The Importance of Symbols

Sunday, June 14th, 2009

This post looks at incorrect stack traces in more detail and provides an example and explanation of why WinDbg is not able to get them right and why we need symbol files to beautify them. Consider the following stack trace from !analyze -v command:

STACK_TEXT: 
00c0ecc8 0042fa36 0190483c 4d445443 0032422c msvcrt!wcscmp+0×18
WARNING: Stack unwind information not available. Following frames may be wrong.
00c0ecec 0043045d Application!Array::operator=+0×2ea1b
00c0ed08 0042d7fb Application!Array::operator=+0×2f442
00c0ed38 0042d87a Application!Array::operator=+0×2c7e0
00c0ed58 0040f393 Application!Array::operator=+0×2c85f
00c0efc8 0040b2c1 Application!Array::operator=+0xe378
00c0eff8 0040c104 Application!Array::operator=+0xa2a6
00c0f038 004192e0 Application!Array::operator=+0xb0e9
00c0f0f0 7c829f5d Application!Array::operator=+0×182c5
01c3f138 00000000 00000000 00000000 00000000 ntdll!RtlFreeHeap+0×20e

Although string comparison function could be called from Application code, it has a semantic inconsistency: FreeHeap surely wouldn’t call Application code. So why it appears on the stack trace? To find out, we look at the thread raw stack data from ESP up to the base and try to do a manual descent to reconstruct that stack trace, starting from EBP value (EIP points to wcscmp):

0:000> r
eax=4d445443 ebx=00000013 ecx=018fe8a0 edx=0190483c esi=4d445443 edi=018fa148
eip=77bd8e21 esp=00c0ecc0 ebp=00c0ecc8 iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00010202
msvcrt!wcscmp+0×18:
77bd8e21 668b0e          mov     cx,word ptr [esi]        ds:0023:4d445443=????

0:000> !teb
TEB at 7ffdc000
    ExceptionList:        00c0efbc
    StackBase:            00c10000
    StackLimit:           00c0a000
    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7ffdc000
    EnvironmentPointer:   00000000
    ClientId:             00005d68 . 0000503c
    RpcHandle:            00000000
    Tls Storage:          00000000
    PEB Address:          7ffd7000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0

0:000> dds 00c0ecc0 00c10000
00c0ecc0  018fa148
00c0ecc4  018f9ff0
00c0ecc8  00c0ecec
00c0eccc  0042fa36 Application!Array::operator=+0×2ea1b
00c0ecd0  0190483c
[…]
00c0ecec  00c0ed08
00c0ecf0  0043045d Application!Array::operator=+0×2f442
00c0ecf4  0190483c
[…]
00c0ed08  00c0ed38
00c0ed0c  0042d7fb Application!Array::operator=+0×2c7e0
00c0ed10  01bb4914
[…]
00c0ed38  00c0ed58
00c0ed3c  0042d87a Application!Array::operator=+0×2c85f
00c0ed40  00000000
[…]
00c0ed58  00c0efc8
00c0ed5c  0040f393 Application!Array::operator=+0xe378
00c0ed60  01bb467c
[…]
00c0efc8  00c0eff8
00c0efcc  0040b2c1 Application!Array::operator=+0xa2a6
00c0efd0  00c0f014
[…]
00c0eff8  00c0f038
00c0effc  0040c104 Application!Array::operator=+0xb0e9
00c0f000  00c0f014
[…]
00c0f038  00c0f0d8
00c0f03c  004192e0 Application!Array::operator=+0×182c5
00c0f040  01902380
[…]
00c0f0d8  01c3f138
00c0f0dc  01c037a8
00c0f0e0  00000002
00c0f0e4  01c316d8
00c0f0e8  001402f8
00c0f0ec  01c3eab0
00c0f0f0  00c0f1d0
00c0f0f4  7c829f5d ntdll!RtlFreeHeap+0×20e
00c0f0f8  00140c28
[…]
00c0f1d0  00000000
00c0f1d4  00000001

What we can see that 00c0f0d8 points to 01c3f138 which is outside stack data range so WinDbg searches for the next symbol and it is ntdll!RtlFreeHeap+0×20e.

After applying correct symbols the magic occurs:

0:000> kl 100
ChildEBP RetAddr 
00c0ecc8 0042fa36 msvcrt!wcscmp+0x18
00c0ecec 0043045d Application!foo17+0x5d
00c0ed08 0042d7fb Application!foo16+0x69
00c0ed38 0042d87a Application!foo15+0xe1
00c0ed58 0040f393 Application!foo14+0x64
00c0ef7c 0040a4fe Application!foo13+0x8a
00c0efc8 0040b2c1 Application!foo12+0x76a
00c0eff8 0040c104 Application!foo11+0x126
00c0f038 004192e0 Application!foo10+0x11e
00c0f280 004193dd Application!foo9+0x34c
00c0f2b4 0041953d Application!foo8+0xc3
00c0f2e8 00415abd Application!foo7+0xb7
00c0f304 0040c19a Application!foo6+0x36
00c0f81c 0040ca44 Application!foo5+0x6a
00c0f834 0040cb04 Application!foo4+0x7e
00c0f874 00415cc6 Application!foo3+0x83
00c0f884 00403839 Application!foo2+0x26
00c0f898 77c80193 Application!foo+0x56
00c0f8b4 77ce33e1 rpcrt4!Invoke+0x30
00c0fcb4 77ce35c4 rpcrt4!NdrStubCall2+0x299
00c0fcd0 77c7ff7a rpcrt4!NdrServerCall2+0x19
00c0fd04 77c8042d rpcrt4!DispatchToStubInCNoAvrf+0x38
00c0fd58 77c80353 rpcrt4!RPC_INTERFACE::DispatchToStubWorker+0x11f
00c0fd7c 77c7e0d4 rpcrt4!RPC_INTERFACE::DispatchToStub+0xa3
00c0fdbc 77c7e080 rpcrt4!RPC_INTERFACE::DispatchToStubWithObject+0xc0
00c0fdfc 77c812f0 rpcrt4!LRPC_SCALL::DealWithRequestMessage+0x41e
00c0fe20 77c88678 rpcrt4!LRPC_ADDRESS::DealWithLRPCRequest+0x127
00c0ff84 77c88792 rpcrt4!LRPC_ADDRESS::ReceiveLotsaCalls+0x430
00c0ff8c 77c8872d rpcrt4!RecvLotsaCallsWrapper+0xd
00c0ffac 77c7b110 rpcrt4!BaseCachedThreadRoutine+0x9d
00c0ffb8 77e6482f rpcrt4!ThreadStartRoutine+0x1b
00c0ffec 00000000 kernel32!BaseThreadStart+0x34

- Dmitry Vostokov @ DumpAnalysis.org -

Software Narratology: A Definition

Friday, June 12th, 2009

Let’s define a software or computer narratology as an application of the theory and methods of literary narratology to the domain of software execution where software traces and logs are considered as a narrative, the story of a computation (*). As an example, we have the following correspondence between 4-tiers of literary and software narrative models:

Events            Instructions, statements, functions
History           Concrete execution path
Narrative         Software trace
Presentation      View (from a trace viewer)

(*) Please do not confuse software narratology with computational narratology.

- Dmitry Vostokov @ TraceAnalysis.org -

Invalid pointer, incorrect stack trace, multiple exceptions, insufficient memory and memory leak: pattern cooperation

Wednesday, June 10th, 2009

Users cannot connect and ultimately the server bluescreens. The dump shows an invalid pointer access while copying a buffer:

Loading Dump File [MEMORY.DMP]
Kernel Summary Dump File: Only kernel address space is available

6: kd> !analyze -v
[...]
PAGE_FAULT_IN_NONPAGED_AREA (50)
Invalid system memory was referenced.  This cannot be protected by try-except,
it must be protected by a Probe.  Typically the address is just plain bad or it
is pointing at freed memory.
Arguments:
Arg1: fe2cc128, memory referenced.
Arg2: 00000001, value 0 = read operation, 1 = write operation.
Arg3: b574414c, If non-zero, the instruction address which referenced the bad memory
 address.
Arg4: 00000000, (reserved)
[...]

TRAP_FRAME:  aefed9d8 -- (.trap 0xffffffffaefed9d8)
ErrCode = 00000002
eax=fe2fb09c ebx=00000006 ecx=00000001 edx=00000006 esi=f5312bcd edi=fe2cc128
eip=b574414c esp=aefeda4c ebp=aefeda58 iopl=0 nv up ei pl nz na po cy
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010203
Driver+0×1614c:
b574414c f3a5            rep movs dword ptr es:[edi],dword ptr [esi]
Resetting default scope

STACK_TEXT: 
aefed948 8085ed19 00000050 fe2cc128 00000001 nt!KeBugCheckEx+0x1b
aefed9c0 8088c7c8 00000001 fe2cc128 00000000 nt!MmAccessFault+0xb25
aefed9c0 b574414c 00000001 fe2cc128 00000000 nt!KiTrap0E+0xdc
WARNING: Stack unwind information not available. Following frames may be wrong.
aefeda58 b574472d f5312bcd 00000006 fe2fb09c Driver+0×1614c
[…]
aefedb70 8081df85 fe2fb000 aefedbcc 88d0e010 Driver+0×2758a
aefedc50 808f5437 8c556c88 8a1fea78 8c556c18 nt!IofCallDriver+0×45
aefedc64 808f61bf 90510070 8c556c18 8a1fea78 nt!IopSynchronousServiceTail+0×10b
aefedd00 808eed08 00001250 00000000 00000000 nt!IopXxxControlFile+0×5e5
aefedd34 808897bc 00001250 00000000 00000000 nt!NtDeviceIoControlFile+0×2a
aefedd34 7c82860c 00001250 00000000 00000000 nt!KiFastCallEntry+0xfc
0620f428 00000000 00000000 00000000 00000000 0×7c82860c

6: kd> !pte edi
               VA fe2cc000
PDE at 00000000C0603F88    PTE at 00000000C07F1660
contains 0000000000ABE863  contains 0000000000000000
pfn abe        —DA–KWEV

The warning about frames suggests that stack trace could be incorrect but backward and forward disassembly and preceding frames show that it is correct indeed and the warning results from the lack of symbol files:

6: kd> ub b574414c
*** ERROR: Module load completed but symbols could not be loaded for Driver.SYS
Driver+0×16139:
b5744139 8d341a          lea     esi,[edx+ebx]
b574413c 03fa            add     edi,edx
b574413e 3bf1            cmp     esi,ecx
b5744140 8b7508          mov     esi,dword ptr [ebp+8]
b5744143 771f            ja      Driver+0×16164 (b5744164)
b5744145 8bcb            mov     ecx,ebx
b5744147 8bd1            mov     edx,ecx
b5744149 c1e902          shr     ecx,2

6: kd> u b574414c
Driver+0×1614c:
b574414c f3a5            rep movs dword ptr es:[edi],dword ptr [esi]
b574414e 8bca            mov     ecx,edx
b5744150 83e103          and     ecx,3
b5744153 f3a4            rep movs byte ptr es:[edi],byte ptr [esi]
b5744155 8b4810          mov     ecx,dword ptr [eax+10h]
b5744158 5f              pop     edi
b5744159 03cb            add     ecx,ebx
b574415b 5e              pop     esi

At the same time we see a second fault on another processor but it seems to be a demand zero page access:

6: kd> ~7s;kv
ChildEBP RetAddr  Args to Child             
ae331854 8095dddf badb0d00 0000000f 808a623c nt!KiTrap0E+0xbc (FPO: [0,0] TrapFrame @ ae331854)
ae3318cc 809731b2 de019000 00000001 3b9aca07 nt!RtlCreateSecurityDescriptorRelative+0×13 (FPO: [2,0,4])
ae331934 808d3229 ae3319e8 de019000 ae3319ec nt!SeQuerySecurityDescriptorInfo+0×198 (FPO: [SEH])
ae33194c 808d443c dc0d9330 ae3319e8 de019000 nt!CmpQuerySecurityDescriptorInfo+0×23 (FPO: [5,0,0])
ae3319b0 809383d3 e09e33f0 00000001 ae3319e8 nt!CmpSecurityMethod+0×212 (FPO: [SEH])
ae3319f0 8093866e e09e33f0 ae331a1c e09e33ec nt!ObpGetObjectSecurity+0×99 (FPO: [4,2,0])
ae331a20 808d8ecc e09e33f0 8ae88740 00000001 nt!ObCheckObjectAccess+0×2c (FPO: [5,4,0])
ae331a7c 808da58b dbef6008 009fd5e0 00000000 nt!CmpDoOpen+0×3a0 (FPO: [SEH])
ae331b90 809374b1 f0d9d348 00000000 8ae88740 nt!CmpParseKey+0×547 (FPO: [10,50,0])
ae331c10 80933a76 0000004c ae331c50 00000040 nt!ObpLookupObjectName+0×11f (FPO: [11,17,4])
ae331c64 808bb471 00000000 908fb868 80934601 nt!ObOpenObjectByName+0xea (FPO: [7,5,4])
ae331d50 808897bc 0013f7bc 00020019 0013f720 nt!NtOpenKey+0×1ad (FPO: [SEH])
ae331d50 7c82860c 0013f7bc 00020019 0013f720 nt!KiFastCallEntry+0xfc (FPO: [0,0] TrapFrame @ ae331d64)

7: kd> .trap ae331854
ErrCode = 00000002
eax=00000000 ebx=ae3319e8 ecx=de019000 edx=0000000f esi=de019000 edi=de019000
eip=8095dddf esp=ae3318c8 ebp=ae3318cc iopl=0  nv up ei pl zr na pe nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010246
nt!RtlCreateSecurityDescriptorRelative+0×13:
8095dddf ab              stos    dword ptr es:[edi]   es:0023:de019000=????????

7: kd> !pte edi
               VA de019000
PDE at 00000000C0603780    PTE at 00000000C06F00C8
contains 00000003D2FF9863  contains 00000000000000C0
pfn 3d2ff9     —DA–KWEV    not valid
                       DemandZero
                       Protect: 6 - ReadWriteExecute

We suspect that users cannot connect because of the lack of kernel pool resources and see the shortage of paged pool along with session pool shortage for one session:

7: kd> !vm 4

*** Virtual Memory Usage ***
Physical Memory:     4193705 (  16774820 Kb)
Page File: \??\C:\pagefile.sys
  Current:  25160704 Kb  Free Space:  18350628 Kb
  Minimum:  25160704 Kb  Maximum:     25160704 Kb
Available Pages:     2556764 (  10227056 Kb)
ResAvail Pages:      3996322 (  15985288 Kb)
Locked IO Pages:         292 (      1168 Kb)
Free System PTEs:      22827 (     91308 Kb)

******* 4 system PTE allocations have failed ******

Free NP PTEs:          32534 (    130136 Kb)
Free Special NP:           0 (         0 Kb)
Modified Pages:           86 (       344 Kb)
Modified PF Pages:        85 (       340 Kb)
NonPagedPool Usage:    32376 (    129504 Kb)
NonPagedPool Max:      65215 (    260860 Kb)
PagedPool 0 Usage:     84341 (    337364 Kb)
PagedPool 1 Usage:      7945 (     31780 Kb)
PagedPool 2 Usage:      8073 (     32292 Kb)
PagedPool 3 Usage:      7979 (     31916 Kb)
PagedPool 4 Usage:      8048 (     32192 Kb)
PagedPool Usage:      116386 (    465544 Kb)
PagedPool Maximum:    134144 (    536576 Kb)

********** 841 pool allocations have failed **********

Shared Commit:         95929 (    383716 Kb)
Special Pool:              0 (         0 Kb)
Shared Process:       126106 (    504424 Kb)
PagedPool Commit:     116435 (    465740 Kb)
Driver Commit:          2605 (     10420 Kb)
Committed pages:     3454252 (  13817008 Kb)
Commit limit:       10419631 (  41678524 Kb)

Total Private:       2961488 (  11845952 Kb)
721c Application.exe  334248 (   1336992 Kb)
4b4c iexplore.exe      36048 (    144192 Kb)
[…]

 Terminal Server Memory Usage By Session:

 Session Paged Pool Maximum is 32768K
 Session View Space Maximum is 20480K

 Session ID 0 @ ba1c5000:
 Paged Pool Usage:        2288K
 Commit Usage:            3344K

[...]

 Session ID 1b @ ba1e3000:
 Paged Pool Usage:       12020K

 *** 622 Pool Allocation Failures ***

 Commit Usage:           13176K

[...]

We also see that the process with PID 721c (Application.exe) consumed 1.3Gb of memory and it belongs to the problem session 0×1b (0n27):

7: kd> !sprocess 1b
Dumping Session 1b

_MM_SESSION_SPACE ba1e3000
_MMSESSION        ba1e3d80
PROCESS 8a4fd020  SessionId: 27  Cid: 1f24    Peb: 7ffde000  ParentCid: 01e4
    DirBase: cfe3f820  ObjectTable: ec731d08  HandleCount: 281.
    Image: csrss.exe

PROCESS 8a4d6b18  SessionId: 27  Cid: 2160    Peb: 7ffde000  ParentCid: 01e4
    DirBase: cfe3f800  ObjectTable: ee932bf0  HandleCount: 436.
    Image: winlogon.exe

[...]

PROCESS 8a467020  SessionId: 27  Cid: 721c    Peb: 7ffdf000  ParentCid: 5728
    DirBase: cfe3f8a0  ObjectTable: f0397350  HandleCount: 380.
    Image: Application.exe

[...]

Unfortunately the dump file is only kernel dump and we cannot inspect user space of that process. We can only say that it was not a handle leak because the number of handles is low (380). We also inspect paged pool stats and find a 3rd-party driver with AAAA tag that used almost 80Mb of paged pool:

7: kd> !poolused 4
   Sorting by  Paged Pool Consumed

  Pool Used:
            NonPaged            Paged
 Tag    Allocs     Used    Allocs     Used
 MmSt        0        0     57216 91753456 Mm section object prototype ptes , Binary: nt!mm
 AAAA        0        0       613 79465472 UNKNOWN pooltag ‘AAAA’, please update pooltag.txt
 CM35        0        0       529 40398848 Internal Configuration manager allocations , Binary: nt!cm
 Ntff        5     1040     35955 29339280 FCB_DATA , Binary: ntfs.sys
 Toke        0        0      3334 12631056 Token objects , Binary: nt!se
 IoNm        0        0     43494  9611392 Io parsing names , Binary: nt!io
 CMAl        0        0      1981  8114176 internal registry memory allocator pool tag , Binary: nt!cm
 Obtb        0        0      2569  6687344 object tables via EX handle.c , Binary: nt!ob
 CM16        0        0      1429  6299648 Internal Configuration manager allocations , Binary: nt!cm
[…]

We can find this driver like explained here. We recommend to contact the vendor of that driver and also monitor instances of Application.exe and get 2-3 subsequent process memory dumps, when it grows, to inspect its virtual memory using differential memory analysis techniques.

- Dmitry Vostokov @ DumpAnalysis.org -

The Ghost of Adelphi Training Center

Tuesday, June 9th, 2009

The Adelphi Training Center in Dublin, Ireland, is haunted by the ghost of pre-Internet epoch. During one debugging night, when installing a secret service, Drilliam Traceless was murdered by a redundant engineer who was envy to his charisma. He stubbed him in the back while Drilliam was unlocking his mini-computer case. He died whispering: “I’ll be back debugging”. His face sometimes appears on greenish screensavers running on computers located in that center. During morning training sessions, many trainees think this is a kind of the so called Guinness effect.

The story is adapted from The Ghost of Adelphi Theatre. 

- Dmitry Vostokov @ DumpAnalysis.org -

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 -

Memory Dumps as Relics

Friday, June 5th, 2009

Some memory dumps can serve the role of a relic and be the subject of veneration. For example, a universal memory dump that reveals the eternity and infinity of Memory. Speaking about earthly artifacts, like computer memory dumps, some of them could be relics and subjects of personal veneration after being generated from a cult system or when a venerated person was working on a computer, for example, doing code construction or writing and composing great works of significant value.

- 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 -

Welcome to TraceAnalysis.org!

Wednesday, June 3rd, 2009

DumpAnalysis.org acquires TraceAnalysis.org to complete computer DATA artifact analysis. The domain currently points to Dump Analysis Portal page but this might change in the future.

- Dmitry Vostokov @ DumpAnalysis.org -

Trace Analysis Patterns (Part 3)

Wednesday, June 3rd, 2009

Next obvious structural trace analysis pattern is called Circular Trace. Sometimes this information is missing in the problem description or trace metadata doesn’t reflect this. Then circular traces can be detected by trace file size (usually large) and from timestamps, like this 100Mb CDF trace snippet:

No     Module  PID  TID  Date      Time         Statement
[Begin of trace listing]
1      ModuleA 4280 1736 5/28/2009 08:53:50.496 [... Trace statement 1]
2      ModuleB 6212 6216 5/28/2009 08:53:52.876 [... Trace statement 2] 
3      ModuleA 4280 4776 5/28/2009 08:54:13.537 [... Trace statement 3] 
[... Some traced exceptions helpful for analysis ...]
3799   ModuleA 4280 3776 5/28/2009 09:15:00.853 [… Trace statement 3799]
3800   ModuleA 4280 1736 5/27/2009 09:42:12.029 [… Trace statement 3800]
[… Skipped …]
[… Skipped …]
[… Skipped …]
579210 ModuleA 4280 4776 5/28/2009 08:53:35.989 [… Trace statement 579210]
[End of trace listing]

In such traces the analysis region usually can be found at the beginning at the trace because as soon as elusive and hard to reproduce problem happens the trace is stopped.

- Dmitry Vostokov @ TraceAnalysis.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 -

Tracing Best Practices

Wednesday, June 3rd, 2009

Good software engineers write good software trace statements. Good software support engineers and responsible customers trace(*) software wisely, enabling it at the right time and in the right quantities. The following preliminary article was written to help to trace software effectively to result in faster problem resolution via trace analysis:

Tracing Best Practices

Although, currently it’s geared towards CDF tracing in Citrix terminal services environment, these recommendations can be generalized to other traces as well and the article will be extended over time.

(*) Note the following terminological difference here. “Tracing” is meant in “select” / “start” / “stop” sense and not how to write good software trace statements during code construction and maintenance phases.

- Dmitry Vostokov @ TraceAnalysis.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 -

Espresso Book Machine for My Books

Monday, June 1st, 2009

I was delighted to know that my books in paperback editions will be available in minutes via Espresso Book Machine: Source. You can read more about this ATM book machine from its inventor:

http://www.ondemandbooks.com/home.htm

- Dmitry Vostokov @ DumpAnalysis.org -

LiterateScientist update (May, 2009)

Monday, June 1st, 2009

Monthly summary of my Literate Scientist blog (last month focus was mostly on physics):

Ideas That Matter

Linear Algebra Demystified

The 10,000 Year Explosion

Homework for Grown-ups

Einstein’s Mistakes

Relativity Demystified

Quantum Mechanics Demystified

30,000 Years of Art

Quantum Field Theory Demystified

Quantum Field Theory I

- Dmitry Vostokov @ DumpAnalysis.org -