ALPC wait chain, missing threads, message box, zombie and special processes: pattern cooperation

September 18th, 2009

The purpose of this case study is to show how to choose what to include in a fiber bundle memory dump when x64 complete memory dumps are huge and not an option to deliver:

1: kd> !vm

*** Virtual Memory Usage ***
 Physical Memory:     5880464 (   23521856 Kb)
[…]

The dump we have is a kernel. When we dump all processes and threads and look for “Waiting for ” we find many ALPC wait chains spanning 3 - 4 processes (sometimes semicircular), sometimes originated from processes with missing threads (just one or two present threads when we expect a dozen of them in a normal state):

1: kd> !process fffffa800b834c10
PROCESS fffffa800b834c10
    SessionId: 205  Cid: 13c40    Peb: 7fffffdb000  ParentCid: 133c0
    DirBase: 13b61d000  ObjectTable: fffff8800c2295b0  HandleCount:  58.
    Image: ProcessA.exe
    VadRoot fffffa8007d70c00 Vads 121 Clone 0 Private 497. Modified 0. Locked 0.
    DeviceMap fffff88000007450
    Token                             fffff8800c695560
    ElapsedTime                       00:03:42.083
    UserTime                          00:00:00.000
    KernelTime                        00:00:00.000
    QuotaPoolUsage[PagedPool]         65968
    QuotaPoolUsage[NonPagedPool]      11520
    Working Set Sizes (now,min,max)  (1274, 50, 345) (5096KB, 200KB, 1380KB)
    PeakWorkingSetSize                1278
    VirtualSize                       37 Mb
    PeakVirtualSize                   38 Mb
    PageFaultCount                    1286
    MemoryPriority                    BACKGROUND
    BasePriority                      13
    CommitCharge                      581

THREAD fffffa800b845bb0  Cid 13c40.1332c  Teb: 000007fffffde000 Win32Thread: fffff900c0076010 WAIT: (WrLpcReply) UserMode Non-Alertable
    fffffa800b845f40  Semaphore Limit 0x1
Waiting for reply to ALPC Message fffff88012527770 : queued at port fffffa80055bca60 : owned by process fffffa80054dfc10
Not impersonating
DeviceMap                 fffff88000007450
Owning Process            fffffa800b834c10       Image:         ProcessA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10912787       Ticks: 14208 (0:00:03:42.000)
Context Switch Count      34                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.015
Win32 Start Address 0×00000000fff60260
Stack Init fffffa600e8d5db0 Current fffffa600e8d5670
Base fffffa600e8d6000 Limit fffffa600e8ce000 Call 0
Priority 15 BasePriority 15 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`0e8d56b0 fffff800`016a36fa nt!KiSwapContext+0×7f
fffffa60`0e8d57f0 fffff800`0169835b nt!KiSwapThread+0×13a
fffffa60`0e8d5860 fffff800`016cd4e2 nt!KeWaitForSingleObject+0×2cb
fffffa60`0e8d58f0 fffff800`01916d14 nt!AlpcpSignalAndWait+0×92
fffffa60`0e8d5980 fffff800`019137a6 nt!AlpcpReceiveSynchronousReply+0×44
fffffa60`0e8d59e0 fffff800`0190330f nt!AlpcpProcessSynchronousRequest+0×24f
fffffa60`0e8d5b00 fffff800`016a0ef3 nt!NtAlpcSendWaitReceivePort+0×19f
fffffa60`0e8d5bb0 00000000`774d756a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`0e8d5c20)
00000000`0026f038 00000000`00000000 0×774d756a

1: kd> !alpc /m fffff88012527770

Message @ fffff88012527770
  MessageID             : 0x10E8 (4328)
  CallbackID            : 0xC3416B (12796267)
  SequenceNumber        : 0x00000002 (2)
  Type                  : LPC_REQUEST
  DataLength            : 0x0040 (64)
  TotalLength           : 0x0068 (104)
  Canceled              : No
  Release               : No
  ReplyWaitReply        : No
  Continuation          : Yes
  OwnerPort             : fffffa80076e9660 [ALPC_CLIENT_COMMUNICATION_PORT]
  WaitingThread         : fffffa800b845bb0
  QueueType             : ALPC_MSGQUEUE_PENDING
  QueuePort             : fffffa80055bca60 [ALPC_CONNECTION_PORT]
  QueuePortOwnerProcess : fffffa80054dfc10 (ProcessB.exe)
  ServerThread          : fffffa800b711060
  QuotaCharged          : No
  CancelQueuePort       : 0000000000000000
  CancelSequencePort    : 0000000000000000
  CancelSequenceNumber  : 0×00000000 (0)
  ClientContext         : 00000000003fcf20
  ServerContext         : 0000000000000000
  PortContext           : 00000000029fda00
  CancelPortContext     : 0000000000000000
  SecurityData          : 0000000000000000
  View                  : 0000000000000000

1: kd> !thread fffffa800b711060
THREAD fffffa800b711060  Cid 032c.146e8  Teb: 000007fffff7c000 Win32Thread: 0000000000000000 WAIT: (WrLpcReply) UserMode Non-Alertable
    fffffa800b7113f0  Semaphore Limit 0x1
Waiting for reply to ALPC Message fffff8800e401200 : queued at port fffffa8005a32730 : owned by process fffffa8004c39040
Not impersonating
DeviceMap                 fffff88000007450
Owning Process            fffffa80054dfc10       Image:         ProcessB.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10916800       Ticks: 10195 (0:00:02:39.296)
Context Switch Count      401            
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0×000007fefe647780
Stack Init fffffa6001d33db0 Current fffffa6001d33670
Base fffffa6001d34000 Limit fffffa6001d2e000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 1 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Call Site
fffffa60`01d336b0 fffff800`016a36fa : nt!KiSwapContext+0×7f
fffffa60`01d337f0 fffff800`0169835b : nt!KiSwapThread+0×13a
fffffa60`01d33860 fffff800`016cd4e2 : nt!KeWaitForSingleObject+0×2cb
fffffa60`01d338f0 fffff800`01916d14 : nt!AlpcpSignalAndWait+0×92
fffffa60`01d33980 fffff800`019137a6 : nt!AlpcpReceiveSynchronousReply+0×44
fffffa60`01d339e0 fffff800`0190330f : nt!AlpcpProcessSynchronousRequest+0×24f
fffffa60`01d33b00 fffff800`016a0ef3 : nt!NtAlpcSendWaitReceivePort+0×19f
fffffa60`01d33bb0 00000000`774d756a : nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`01d33c20)
00000000`03d8e458 00000000`00000000 : 0×774d756a

1: kd> !alpc /m fffff8800e401200

Message @ fffff8800e401200
  MessageID             : 0x0BA4 (2980)
  CallbackID            : 0xC3E68A (12838538)
  SequenceNumber        : 0x00021911 (137489)
  Type                  : LPC_REQUEST
  DataLength            : 0x00C0 (192)
  TotalLength           : 0x00E8 (232)
  Canceled              : No
  Release               : No
  ReplyWaitReply        : No
  Continuation          : Yes
  OwnerPort             : fffffa8005b119c0 [ALPC_CLIENT_COMMUNICATION_PORT]
  WaitingThread         : fffffa800b711060
  QueueType             : ALPC_MSGQUEUE_PENDING
  QueuePort             : fffffa8005a32730 [ALPC_CONNECTION_PORT]
  QueuePortOwnerProcess : fffffa8004c39040 (ProcessC.exe)
  ServerThread          : fffffa800a843bb0
  QuotaCharged          : No
  CancelQueuePort       : 0000000000000000
  CancelSequencePort    : 0000000000000000
  CancelSequenceNumber  : 0×00000000 (0)
  ClientContext         : 0000000002e2e810
  ServerContext         : 0000000000000000
  PortContext           : 00000000002f3eb0
  CancelPortContext     : 0000000000000000
  SecurityData          : 0000000000000000
  View                  : 0000000000000000

1: kd> !thread fffffa800a843bb0
THREAD fffffa800a843bb0  Cid 048c.fbec  Teb: 000007ffffdaa000 Win32Thread: 0000000000000000 WAIT: (UserRequest) UserMode Non-Alertable
    fffffa8006027d80  Semaphore Limit 0x7fffffff
    fffffa800a843c68  NotificationTimer
Not impersonating
DeviceMap                 fffff88001800ba0
Owning Process            fffffa8004c39040       Image:         ProcessC.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10916801       Ticks: 10194 (0:00:02:39.281)
Context Switch Count      239            
UserTime                  00:00:00.000
KernelTime                00:00:00.015
Win32 Start Address 0×000007fefe647780
Stack Init fffffa601b280db0 Current fffffa601b280940
Base fffffa601b281000 Limit fffffa601b27b000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Call Site
fffffa60`1b280980 fffff800`016a36fa : nt!KiSwapContext+0×7f
fffffa60`1b280ac0 fffff800`0169835b : nt!KiSwapThread+0×13a
fffffa60`1b280b30 fffff800`019013e8 : nt!KeWaitForSingleObject+0×2cb
fffffa60`1b280bc0 fffff800`016a0ef3 : nt!NtWaitForSingleObject+0×98
fffffa60`1b280c20 00000000`774d6d5a : nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`1b280c20)
00000000`10b7e548 00000000`00000000 : 0×774d6d5a

Some processes designed to be non-interactive have threads that wait for UI messages and therefore could be potential message or dialog box threads waiting for a dismissal and blocking other threads:

THREAD fffffa8005a7aa20  Cid 061c.0778  Teb: 000007fffff9e000 Win32Thread: fffff900c079fd50 WAIT: (WrUserRequest) UserMode Non-Alertable
    fffffa8005a7a5a0  SynchronizationEvent
Not impersonating
DeviceMap                 fffff88000007450
Owning Process            fffffa80058f01b0       Image:         ProcessD.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      10911798       Ticks: 15197 (0:00:03:57.453)
Context Switch Count      88939                 LargeStack
UserTime                  00:00:00.078
KernelTime                00:00:00.609
Win32 Start Address 0×000007fefa8238a0
Stack Init fffffa60046a8db0 Current fffffa60046a8720
Base fffffa60046a9000 Limit fffffa60046a0000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`046a8760 fffff800`016a36fa nt!KiSwapContext+0×7f
fffffa60`046a88a0 fffff800`0169835b nt!KiSwapThread+0×13a
fffffa60`046a8910 fffff960`0014c053 nt!KeWaitForSingleObject+0×2cb
fffffa60`046a89a0 fffff960`0014c0ea win32k!xxxRealSleepThread+0×25f
fffffa60`046a8a40 fffff960`0014bb3a win32k!xxxSleepThread+0×56
fffffa60`046a8a70 fffff960`0014bc39 win32k!xxxRealInternalGetMessage+0×72e
fffffa60`046a8b50 fffff960`0014d0d9 win32k!xxxInternalGetMessage+0×35
fffffa60`046a8b90 fffff800`016a0ef3 win32k!NtUserGetMessage+0×79

fffffa60`046a8c20 00000000`773dd58a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffffa60`046a8c20)
00000000`03d2f7b8 00000000`00000000 0×773dd58a

We also have more than 30,000 zombie processes including some special ones signifying past faults:

1: kd> !vm
[...]
         15714 ProcessE.exe       0 (         0 Kb)
         15650 WerFault.exe       0 (         0 Kb)
         15644 ProcessF.exe       0 (         0 Kb)
         15640 ProcessE.exe       0 (         0 Kb)
         15610 ProcessG.exe       0 (         0 Kb)
         1560c ProcessE.exe       0 (         0 Kb)
         155f8 ProcessH.exe       0 (         0 Kb)
         155e8 ProcessE.exe       0 (         0 Kb)
         155c4 ProcessG.exe       0 (         0 Kb)
         155bc ProcessE.exe       0 (         0 Kb)
         155b8 ProcessH.exe       0 (         0 Kb)
         1559c WerFault.exe       0 (         0 Kb)
         15560 ProcessE.exe       0 (         0 Kb)
[…]

What we recommend here is to save user dumps of processes A, B, C and D and then force a kernel dump next time the problem surfaces. Also to check WER settings for any recorder faults and, because of the fact the the system is W2K8, configure LocalDumps registry keys to capture full user dumps.

- Dmitry Vostokov @ DumpAnalysis.org -

Forthcoming Books in Q4, 2009

September 17th, 2009

I plan the following titles to be published in Q4:

- Debugged! MZ/PE: Software Tracing, September, 2009 (ISBN: 978-1906717797)
- Windows Debugging Notebook: Essential Concepts, WinDbg Commands and Tools (ISBN: 978-1906717001)
- Memory Dump Analysis Anthology, Volume 3 (ISBN: 978-1906717438 and 978-1906717445)
- Memory Dump Analysis Anthology: Color Supplement for Volumes 1-3 (ISBN: 978-1906717698)
- First Fault Software Problem Solving: A Guide for Engineers, Managers and Users (ISBN: 978-1906717421) by Dan Skwire
- Crash Dump Analysis for System Administrators and Support Engineers (Windows Edition)  (ISBN: 978-1906717025) 

The title of the latter book was slightly changed. After some time we realized that the same material is appropriate for support engineers as well.

- Dmitry Vostokov @ DumpAnalysis.org -

Public Statement on Book Delays

September 17th, 2009

Some users and fans were asking why many announced books are delayed and delayed. The answer is very simple: I am a full time employee of Citrix Systems,  prioritize my job first and put books and blogs at the end of the priority chain. However, I have now reserved 2-3 hours every evening to finish a few books and my next blog post announces which of them are scheduled for Q4 this Year of Debugging.

- Dmitry Vostokov @ DumpAnalysis.org -

Debugging and Asm Bestsellers

September 17th, 2009

Occasionally I check my books to see how they are positioned on Amazon and noticed that Windows Debugging: Practical Foundations and Memory Dump Analysis Anthology, Volume 1 paperback titles are #1 and #2 bestsellers (at the time of this writing) on Amazon Debugging and Assembly Language Programming bestselling lists:

- Dmitry Vostokov @ DumpAnalysis.org -

Bugtation No.103

September 16th, 2009

“You” run code “from beginning to end. You” debug code “the opposite way. You start with the end, and then you do everything you must to reach” the beginning.

Harold Sydney Geneen

- Dmitry Vostokov @ DumpAnalysis.org -

Debugging Spy Network

September 15th, 2009

SecretSES (Secret Software Engineering Society) announces Debugging Spy Network of Memory Analysis Forensics and Intelligence Agents (MAFIA).

Motivation: seeing various nomadic and settled debugging teams I finally decided to unfold my own net.

- Dmitry Vostokov @ DumpAnalysis.org -

Counterfactual Debugging: Data Ordering

September 15th, 2009

Having discussed dereference fixpoints we come back to the quiz code and see what happens when we execute it after compilation as default Debug target with Debug Information Format set to Program Database to avoid extra stack space allocation:

int _tmain(int argc, _TCHAR* argv[])
{
   char c;
   char* pc = &c;
   while(1)
   {
     *pc = 0;
     pc++;
   }

  

   return 0;
}

Expecting crashes I created the following key HKEY_LOCAL_MACHINE \ SOFTWARE \ Microsoft \ Windows \ Windows Error Reporting \ LocalDumps with the following values: DumpFolder (REG_EXPAND_SZ) and DumpType (2, Full).

When running the compiled program I noticed that it crashed according to my expectations. The saved dump StackErasure.exe.2096.dmp confirmed that the crash was due to the stack underflow when it hit the base address:

0:000> r
eax=002c0000 ebx=7efde000 ecx=00000001 edx=002c0000 esi=00000000 edi=00000000
eip=00e11039 esp=002bf7c4 ebp=002bf7d4 iopl=0         nv up ei pl nz na po nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010202
StackErasure!wmain+0x29:
00e11039 c60200          mov     byte ptr [edx],0           ds:002b:002c0000=??

0:000> !teb
TEB at 7efdd000
    ExceptionList:        002bf810
    StackBase:            002c0000
    StackLimit:           002be000
    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7efdd000
    EnvironmentPointer:   00000000
    ClientId:             00000830 . 00000a78
    RpcHandle:            00000000
    Tls Storage:          7efdd02c
    PEB Address:          7efde000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0

The loop from source code is highlighted in blue:

0:000> uf wmain
StackErasure!wmain:
00e11010 push    ebp
00e11011 mov     ebp,esp
00e11013 sub     esp,10h
00e11016 mov     eax,0CCCCCCCCh
00e1101b mov     dword ptr [ebp-10h],eax
00e1101e mov     dword ptr [ebp-0Ch],eax
00e11021 mov     dword ptr [ebp-8],eax
00e11024 mov     dword ptr [ebp-4],eax
00e11027 lea     eax,[ebp-5]
00e1102a mov     dword ptr [ebp-10h],eax

StackErasure!wmain+0x1d:
00e1102d mov     ecx,1
00e11032 test    ecx,ecx
00e11034 je      StackErasure!wmain+0x37 (00e11047)

StackErasure!wmain+0x26:
00e11036 mov     edx,dword ptr [ebp-10h]
00e11039 mov     byte ptr [edx],0
00e1103c mov     eax,dword ptr [ebp-10h]
00e1103f add     eax,1
00e11042 mov     dword ptr [ebp-10h],eax
00e11045 jmp     StackErasure!wmain+0x1d (00e1102d)

StackErasure!wmain+0x37:
00e11047 xor     eax,eax
00e11049 push    edx
00e1104a mov     ecx,ebp
00e1104c push    eax
00e1104d lea     edx,[StackErasure!wmainCRTStartup+0x10 (00e11060)]
00e11053 call    StackErasure!__tmainCRTStartup+0x50 (00e110c0)
00e11058 pop     eax
00e11059 pop     edx
00e1105a mov     esp,ebp
00e1105c pop     ebp
00e1105d ret

We see that our char variable ‘c’ is located at EBP-5 and the pointer ‘pc’ is located at EBP-10 (in another words ‘c’ follows ‘pc’ in memory):

00e11027 lea     eax,[ebp-5]
00e1102a mov     dword ptr [ebp-10h],eax

Both locations were initialized to 0xCCCCCCCC:

00e11016 mov     eax,0CCCCCCCCh
00e1101b mov     dword ptr [ebp-10h],eax
00e1101e mov     dword ptr [ebp-0Ch],eax
00e11021 mov     dword ptr [ebp-8],eax  ; this ends with EBP-5
00e11024 mov     dword ptr [ebp-4],eax

The memory layout before the start of the loop is depicted on the following diagram in the style of Windows Debugging: Practical Foundations book:

At the crash point we have the following final memory layout:

We can see it from the raw stack:

0:000> db esp
002bf7c4  00 00 2c 00 cc cc cc cc-cc cc cc 00 00 00 00 00
002bf7d4  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf7e4  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf7f4  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf804  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf814  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf824  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00
002bf834  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00

or in pointer-sized (double word) values where we can see little endian effects (compare 00 00 2c 00  with 002c0000):

0:000> dp esp
002bf7c4  002c0000 cccccccc 00cccccc 00000000
002bf7d4  00000000 00000000 00000000 00000000
002bf7e4  00000000 00000000 00000000 00000000
002bf7f4  00000000 00000000 00000000 00000000
002bf804  00000000 00000000 00000000 00000000
002bf814  00000000 00000000 00000000 00000000
002bf824  00000000 00000000 00000000 00000000
002bf834  00000000 00000000 00000000 00000000

The loop code erases stack starting from EBP-5 until it hits the base address. 

Now we change Basic Runtime Checks in Code Generation properties to Default, recompile and launch the project. Suddenly it no longer crashes but loops infinitely (shown in blue):

0:000> bp wmain

0:000> g
[...]

0:000> uf wmain
StackErasure!wmain:
00d01010 push    ebp
00d01011 mov     ebp,esp
00d01013 sub     esp,8
00d01016 lea     eax,[ebp-5]
00d01019 mov     dword ptr [ebp-4],eax

StackErasure!wmain+0xc:
00d0101c mov     ecx,1
00d01021 test    ecx,ecx
00d01023 je      StackErasure!wmain+0x26 (00d01036)

StackErasure!wmain+0x15:
00d01025 mov     edx,dword ptr [ebp-4]
00d01028 mov     byte ptr [edx],0
00d0102b mov     eax,dword ptr [ebp-4]
00d0102e add     eax,1
00d01031 mov     dword ptr [ebp-4],eax
00d01034 jmp     StackErasure!wmain+0xc (00d0101c)

StackErasure!wmain+0x26:
00d01036 xor     eax,eax
00d01038 mov     esp,ebp
00d0103a pop     ebp
00d0103b ret

At first it looks strange but if we look at the stack memory layout we would see that ‘pc’ pointer follows ‘c’ (the opposite to the memory layout discussed above):

00d01016 lea     eax,[ebp-5]
00d01019 mov     dword ptr [ebp-4],eax

0:000> dp esp
002dfb90 00d014ee 002dfb93 002dfbe4 00d01186
002dfba0 00000001 00081d70 00081df8 5a16a657
002dfbb0 00000000 00000000 7ffdb000 00000000
002dfbc0 00000000 00000000 00000000 002dfbac
002dfbd0 000001bb 002dfc28 00d06e00 5aed06eb
002dfbe0 00000000 002dfbec 00d0105f 002dfbf8
002dfbf0 77844911 7ffdb000 002dfc38 7791e4b6
002dfc00 7ffdb000 705b3701 00000000 00000000

Therefore, when the pointer at EBP-4 is incremented by 1 during the first loop iteration it becomes a dereference fixpoint:

0:000> bp 00d0101c

0:000> g
Breakpoint 1 hit
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=00081df8 esi=00000000 edi=00000000
eip=00d0101c esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000206
StackErasure!wmain+0xc:
00d0101c b901000000      mov     ecx,1

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=00081df8 esi=00000000 edi=00000000
eip=00d01021 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000206
StackErasure!wmain+0x11:
00d01021 85c9            test    ecx,ecx

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=00081df8 esi=00000000 edi=00000000
eip=00d01023 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x13:
00d01023 7411            je      StackErasure!wmain+0x26 (00d01036)      [br=0]

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=00081df8 esi=00000000 edi=00000000
eip=00d01025 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x15:
00d01025 8b55fc          mov     edx,dword ptr [ebp-4] ss:0023:002dfb94=002dfb93

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01028 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x18:
00d01028 c60200          mov     byte ptr [edx],0           ds:0023:002dfb93=00

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d0102b esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x1b:
00d0102b 8b45fc          mov     eax,dword ptr [ebp-4] ss:0023:002dfb94=002dfb93

0:000> t
eax=002dfb93 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d0102e esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x1e:
00d0102e 83c001          add     eax,1

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01031 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x21:
00d01031 8945fc          mov     dword ptr [ebp-4],eax ss:0023:002dfb94=002dfb93

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01034 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x24:
00d01034 ebe6            jmp     StackErasure!wmain+0xc (00d0101c)

0:000> dp ebp-4 l1
002dfb94  002dfb94

During the second iteration the assignment of zero to ‘*pc’ clears the first byte of ‘pc’:

0:000> t
Breakpoint 1 hit
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d0101c esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0xc:
00d0101c b901000000      mov     ecx,1

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01021 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x11:
00d01021 85c9            test    ecx,ecx

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01023 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x13:
00d01023 7411            je      StackErasure!wmain+0x26 (00d01036)      [br=0]

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb93 esi=00000000 edi=00000000
eip=00d01025 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x15:
00d01025 8b55fc          mov     edx,dword ptr [ebp-4] ss:0023:002dfb94=002dfb94

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb94 esi=00000000 edi=00000000
eip=00d01028 esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x18:
00d01028 c60200          mov     byte ptr [edx],0           ds:0023:002dfb94=94

0:000> t
eax=002dfb94 ebx=7ffdb000 ecx=00000001 edx=002dfb94 esi=00000000 edi=00000000
eip=00d0102b esp=002dfb90 ebp=002dfb98 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
StackErasure!wmain+0x1b:
00d0102b 8b45fc          mov     eax,dword ptr [ebp-4] ss:0023:002dfb94=002dfb00

0:000> dp esp
002dfb90  00d014ee 002dfb00 002dfbe4 00d01186
002dfba0  00000001 00081d70 00081df8 5a16a657
002dfbb0  00000000 00000000 7ffdb000 00000000
002dfbc0  00000000 00000000 00000000 002dfbac
002dfbd0  000001bb 002dfc28 00d06e00 5aed06eb
002dfbe0  00000000 002dfbec 00d0105f 002dfbf8
002dfbf0  77844911 7ffdb000 002dfc38 7791e4b6
002dfc00  7ffdb000 705b3701 00000000 00000000

The new ‘pc’ pointer points to the following region of the stack:

0:000> dp 002dfb00 l100/4
002dfb00  002dfb0c 00000004 00000000 5c008ede
002dfb10  002dfb28 00d0634a 0008128c 5aed018b
002dfb20  000807f8 7790fb66 00000000 7ffdb000
002dfb30  00000000 002dfb40 00d089a6 00d68ab8
002dfb40  002dfb4c 00d019bc 00000008 002dfb84
002dfb50  00d07520 00d07519 5a16a637 00000000
002dfb60  00000000 7ffdb000 00d02b10 00000004
002dfb70  00000002 002dfbd4 00d06e00 5aed007b
002dfb80  fffffffe 002dfb90 00d0769e 002dfba0
002dfb90  00d014ee 002dfb00 002dfbe4 00d01186
002dfba0  00000001 00081d70 00081df8 5a16a657
002dfbb0  00000000 00000000 7ffdb000 00000000
002dfbc0  00000000 00000000 00000000 002dfbac
002dfbd0  000001bb 002dfc28 00d06e00 5aed06eb
002dfbe0  00000000 002dfbec 00d0105f 002dfbf8
002dfbf0  77844911 7ffdb000 002dfc38 7791e4b6

The loop code now starts clearing this region until the pointer becomes the fixpoint again after successive increments and therefore continues to loop indefinitely:

0:000> bc 0 1

0:000> g
(1238.c9c): Break instruction exception - code 80000003 (first chance)
eax=7ffde000 ebx=00000000 ecx=00000000 edx=7796d094 esi=00000000 edi=00000000
eip=77927dfe esp=00a4ff30 ebp=00a4ff5c iopl=0         nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000246
ntdll!DbgBreakPoint:
77927dfe cc              int     3

0:001> dp 002dfb00 l100/4
002dfb00  0000000c 00000000 00000000 00000000
002dfb10  00000000 00000000 00000000 00000000
002dfb20  00000000 00000000 00000000 00000000
002dfb30  00000000 00000000 00000000 00000000
002dfb40  00000000 00000000 00000000 00000000
002dfb50  00000000 00000000 00000000 00000000
002dfb60  00000000 00000000 00000000 00000000
002dfb70  00000000 00000000 00000000 00000000
002dfb80  00000000 00000000 00000000 00000000
002dfb90  00000000
002dfb1f 002dfbe4 00d01186
002dfba0  00000001 00081d70 00081df8 5a16a657
002dfbb0  00000000 00000000 7ffdb000 00000000
002dfbc0  00000000 00000000 00000000 002dfbac
002dfbd0  000001bb 002dfc28 00d06e00 5aed06eb
002dfbe0  00000000 002dfbec 00d0105f 002dfbf8
002dfbf0  77844911 7ffdb000 002dfc38 7791e4b6

StackErasure that loops indefinitely is available for download

- Dmitry Vostokov @ DumpAnalysis.org -

Video from Microsoft GEC

September 14th, 2009

Ntdebugging blog has put the link to the video online from Microsoft Global Engineering Conference where I presented the pattern-driven memory dump analysis methodology:

Citrix engineers at Microsoft GEC

Note: you need to open a video link URL from the blog post in Windows Media Player if you don’t have an association for WMV files or save the file.

- Dmitry Vostokov @ DumpAnalysis.org -

Counterfactual Debugging: Dereference Fixpoints

September 11th, 2009

Imagine we have the following arrangements in memory:

address: value

where value == address, so we have effectively:

address: address

So when we dereference the address we get the address value. If we name the dereference function as p(address) we get

p(address) = address

That gave me an idea to name after the mathematical notion of a function fixpoint (fixed point).

In C++ we can write the following code to initialize a fixpoint:

void *pc = &pc;

in assembly language:

lea      eax, [pc]
mov      dword ptr [pc], eax

or using local variables:

lea      eax, [ebp-4]
mov      dword ptr [ebp-4], eax

Dereference of a fixpoint pointer gives us the same value as its address, for example, using old style conversion:

int *pc = (int *)&pc;

if (pc == (int *)*pc) {
 // TRUE

or for C++ purists:

int *pc = reinterpret_cast<int *>(&pc);

if (pc == reinterpret_cast<int *>(*pc)) {
 // TRUE

In x86 assembly language we have this comparison:

mov         eax,dword ptr [pc]
mov         ecx,dword ptr [pc]
cmp         ecx,dword ptr [eax]

or using local variables:

mov         eax,dword ptr [ebp-4]
mov         ecx,dword ptr [ebp-4]
cmp         ecx,dword ptr [eax]

Now, having discussed fixpoints, let me ask the question to ponder over this weekend. What would this code do?

int _tmain(int argc, _TCHAR* argv[])
{
   char c;
   char* pc = &c;

   while(1)
   {
     *pc = 0;
     pc++;
   }
 

   return 0;
}

Would it produce stack overflow with an exception, or stack underflow with an exception or loop indefinitely? The C++ Standard answer of compiler and platform dependence is not acceptable. I plan to elaborate on this topic on Monday.

The notion of counterfactual debugging (”what if” debugging) was inspired by the so called counterfactual history.

- Dmitry Vostokov @ DumpAnalysis.org -

Stalin: The Court of the Red Tsar

September 10th, 2009

While finishing Comrades book I started to read this “sequel” to Young Stalin (it was published before the latter book). I’m interested in psychology of a court and think this book is a good supplement to The 48 Laws of Power book that I started reading too. I have also Beria biography on the reading list. Actually I became interested in Stalin epoch after reading a book in Russian 2 years ago with a title that can be translated to English like “Killers of Stalin and Beria”. The main idea of that book were that Beria (and Stalin) wanted to do Perestroika similar to what Gorbachev did and Khrushchev murdered him (and possibly murdered Stalin too) for that. Anyway The Court of the Red Tsar was very smooth and fascinating read, revealing hidden transcripts of Stalin power. At the end the author also mentions the possibility that Beria was a possible precursor to Perestroika but contrary to that Russian book I read before he mentions the hypothesis that Beria himself poisoned Stalin’s wine. The finishing touch of Valechka weeping on Stalin corpse like Russian baba really made me sorrow. I really liked Postscriptum where the fortunes of Stalin’s and other magnates’ relatives, children and grandchildren fortunes after Stalin death up to now was mentioned.

Stalin: The Court of the Red Tsar

Buy from Amazon

- Dmitry Vostokov @ LiterateScientist.com -

Truncated dump, stack trace collection, waiting thread time and wait chains: pattern cooperation

September 10th, 2009

It was reported that functionality of some applications was not available until ServiceA was killed and restarted. Complete memory dump was forced. For that memory dump WinDbg !stacks command shows every thread bugchecking the system, for example:

0: kd> !stacks
Proc.Thread  .Thread  Ticks   ThreadState Blocker
[...]
                            [8ca72020 ApplicationA.exe]
 4bc.0004c4  8bf76af0 0000cc4 Blocked    nt!KeBugCheckEx+0x1b
 4bc.0004d0  8bf53650 000055d Blocked    nt!KeBugCheckEx+0x1b
 4bc.0004e8  8bf33c88 0000094 Blocked    nt!KeBugCheckEx+0x1b
 4bc.001ffc  8ba86020 0000eed Blocked    nt!KeBugCheckEx+0x1b
 4bc.001e30  8b7a0ca8 00003ac Blocked    nt!KeBugCheckEx+0x1b
 4bc.001934  8b664020 0000eed Blocked    nt!KeBugCheckEx+0x1b
 4bc.001af0  8ca6d3b0 0000094 Blocked    nt!KeBugCheckEx+0x1b
 4bc.001cac  8bf41af0 0001412 Blocked    nt!KeBugCheckEx+0x1b
 4bc.00141c  8b6458d0 0000094 Blocked    nt!KeBugCheckEx+0x1b
[...]

Seeing this nonsense I checked that complete dump was truncated by half because page file was 4Gb but the amount of physical memory was 8Gb:

0: kd> !vm
*** Virtual Memory Usage ***
 Physical Memory:     2096553 (   8386212 Kb)
 Paging File Name paged out
   Current:   4195328 Kb  Free Space:   4182336 Kb
   Minimum:   4195328 Kb  Maximum:      4195328 Kb
[…]

However it was possible to get stack trace collection using !process 0 ff command with most data from _ETHREAD structures present but most of kernel and user space stack traces not present in the output. ServiceA has many threads waiting for LPC requests during last 5 minutes (the bugcheck was forced after 3 - 4 minutes the issue manifested itself):

THREAD 8cc9b590  Cid 053c.0668  Teb: 7ffaf000 Win32Thread: b84e5770 WAIT: (Unknown) UserMode Non-Alertable
    8cc9b77c  Semaphore Limit 0x1
Waiting for reply to LPC MessageId 0005bbdf:
Current LPC port e2cee338
IRP List:
    8b6548b8: (0006,0268) Flags: 00000000  Mdl: 00000000
Not impersonating
DeviceMap                 e1003860
Owning Process            8bf81d88       Image:         ServiceA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      193823         Ticks: 13752 (0:00:03:34.875)
Context Switch Count      389                 LargeStack
UserTime                  00:00:00.015
KernelTime                00:00:00.000
Win32 Start Address 0×7d1f5e70
Start Address 0×77e617ec
Stack Init b3a44000 Current b3a43c08 Base b3a44000 Limit b3a41000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.

The similar waits were found for ApplicationB and ApplicationC processes. Therefore it was advised to limit the amount of physical memory to 4Gb and reproduce the issue or if the liveliness of the system needs to be preserved to manually dump the following processes on the next occasion:

ServiceA.exe
ApplicationB.exe
ApplicationC.exe

- Dmitry Vostokov @ DumpAnalysis.org -

DebugWare Patterns (Part 7)

September 10th, 2009

Trace Expert pattern came to my mind when I was writing about software trace patterns. It is a very lightweight expert system relying on trace collector and trace formatter (patterns to be written about soon). It is a module that takes a preformatted software trace message file or a buffer and a set of built in rules and uses simple search (peharps involving regular expressions) to dig out diagnostic information and provide troubleshooting and debugging directions.

This module is schematically depicted on the following UML component diagram:

- Dmitry Vostokov @ DumpAnalysis.org -

Electronic Version of Debugged! Magazine

September 8th, 2009

Responding to numerous requests and suggestions I plan to make magazine interior excluding promotional vouchers available for free download. If someone needs covers including back covers where I put tips and tables to be used as posters or certification vouchers printed inside then they should buy the magazine from Amazon or other bookshops.

This initiative will be accompanied by a smart marketing trick that I plan to unveil in a few days together with the magazine website.

- Dmitry Vostokov @ DumpAnalysis.org -

Metaphorical Bijectionism: A Method of Inquiry

September 7th, 2009

Consider this example mapping (taken metaphorically from the mathematical notion of an injection) of one domain of knowledge to another:

This mapping between concepts and ideas was once called “bijectivism” but was trivially described either as one to one mapping between two domains (like physical vs. mathematical) or fusing different concepts together to get another emerging concept. I myself proposed the similar mapping and called it a metaphorical bijection.  

Now consider another mapping metaphorically equivalent to a mathematical notion of a surjection where all constituents of the second domain are covered metaphorically by the first domain:

What we strive for is to establish the complete bijective mapping and reorganize our knowledge of both domains to achieve that:

In diagrams above small boxes can represent sets of ideas, methods, etc. or individual ideas, methods, etc. The established metaphorical bijection can divide sets or combine them if needed. There can be several such bijections, of course, and we can use other methods of inquiry (for example, the scientific method) to choose between competing metaphorical bijections.

Useful mnemonic:

BEIS (B=I+S or to BE IS …)

Bijectionism Equals Injection + Surjection

Another mnemonic:

BET (B=T or to BE Transformation…)

Bijectionism Equals Transformation 

Note also the second letter of Alef-Beis or Alef-Bet, the letter of Light that has interpretation of Creation in Biblical Hebrew.   

More on this later as I need to come back to DebugWare patterns.

- Dmitry Vostokov @ DumpAnalysis.org -

Manual parameter reconstruction on x64 Windows systems

September 4th, 2009

Although the first 2 parameters are passed via registers RCX and RDX they are saved on a stack as the part of a function prolog (as can be seen in many examples from my book x64 Windows Debugging: Practical Foundations):

0:000> uf arithmetic
FunctionParameters!arithmetic [c:\dumps\wdpf-x64\functionparameters\arithmetic.cpp @ 2]:
    2 00000001`40001020 mov     dword ptr [rsp+10h],edx
    2 00000001`40001024 mov     dword ptr [rsp+8],ecx

    2 00000001`40001028 push    rdi
    3 00000001`40001029 mov     eax,dword ptr [rsp+10h]
    3 00000001`4000102d mov     ecx,dword ptr [rsp+18h]
    3 00000001`40001031 add     ecx,eax
    3 00000001`40001033 mov     eax,ecx
    3 00000001`40001035 mov     dword ptr [rsp+18h],eax
    4 00000001`40001039 mov     eax,dword ptr [rsp+10h]
    4 00000001`4000103d add     eax,1
    4 00000001`40001040 mov     dword ptr [rsp+10h],eax
    5 00000001`40001044 mov     eax,dword ptr [rsp+10h]
    5 00000001`40001048 imul    eax,dword ptr [rsp+18h]
    5 00000001`4000104d mov     dword ptr [rsp+18h],eax
    7 00000001`40001051 mov     eax,dword ptr [rsp+18h]
    8 00000001`40001055 pop     rdi
    8 00000001`40001056 ret

Notice that RDI is saved too. This helps us later in a more complex case. If we put a breakpoint at arithmetic entry we see that WinDbg is not able to get parameters from RCX and RDX:

0:000> bp 00000001`40001020

0:000> g
ModLoad: 000007fe`ff4d0000 000007fe`ff5d8000   C:\Windows\system32\ADVAPI32.DLL
ModLoad: 000007fe`fef80000 000007fe`ff0c3000   C:\Windows\system32\RPCRT4.dll
Breakpoint 0 hit
FunctionParameters!arithmetic:
00000001`40001020 89542410        mov     dword ptr [rsp+10h],edx ss:00000000`0012fe88=cccccccc

0:000> kv
Child-SP          RetAddr           : Args to Child                                                           : Call Site
00000000`0012fe78 00000001`400010a5 : cccccccc`cccccccc cccccccc`cccccccc cccccccc`cccccccc cccccccc`cccccccc : FunctionParameters!arithmetic
00000000`0012fe80 00000001`4000137c : 00000000`00000001 00000000`00282960 00000000`00000000 00000000`00000000 : FunctionParameters!main+0×35
00000000`0012fec0 00000001`4000114e : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : FunctionParameters!__tmainCRTStartup+0×21c
00000000`0012ff30 00000000`7776be3d : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : FunctionParameters!mainCRTStartup+0xe
00000000`0012ff60 00000000`778a6a51 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0×1d

This seems correct approach in general because at the time of any other breakpoint in the middle of the code parameter passing registers could be already overwritten, for example, RCX at 0000000140001031. However, as soon as we execute the first two MOV instruction one by one, parameters appear on kv output one by one too:

0:000> t
ModLoad: 000007fe`fd810000 000007fe`fd845000   C:\Windows\system32\apphelp.dll
FunctionParameters!arithmetic+0x4:
00000001`40001024 894c2408        mov     dword ptr [rsp+8],ecx ss:00000000`0012fe80=cccccccc

0:000> kv
Child-SP          RetAddr           : Args to Child                                                           : Call Site
00000000`0012fe78 00000001`400010a5 : cccccccc`cccccccc cccccccc`00000001 cccccccc`cccccccc cccccccc`cccccccc : FunctionParameters!arithmetic+0×4
00000000`0012fe80 00000001`4000137c : 00000000`00000001 00000000`00282960 00000000`00000000 00000000`00000000 : FunctionParameters!main+0×35
00000000`0012fec0 00000001`4000114e : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : FunctionParameters!__tmainCRTStartup+0×21c
00000000`0012ff30 00000000`7776be3d : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : FunctionParameters!mainCRTStartup+0xe
00000000`0012ff60 00000000`778a6a51 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0×1d

0:000> t
FunctionParameters!arithmetic+0x8:
00000001`40001028 57              push    rdi

0:000> kv
Child-SP          RetAddr           : Args to Child                                                           : Call Site
00000000`0012fe78 00000001`400010a5 : cccccccc`00000001 cccccccc`00000001 cccccccc`cccccccc cccccccc`cccccccc : FunctionParameters!arithmetic+0×8
00000000`0012fe80 00000001`4000137c : 00000000`00000001 00000000`00282960 00000000`00000000 00000000`00000000 : FunctionParameters!main+0×35
00000000`0012fec0 00000001`4000114e : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : FunctionParameters!__tmainCRTStartup+0×21c
00000000`0012ff30 00000000`7776be3d : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : FunctionParameters!mainCRTStartup+0xe
00000000`0012ff60 00000000`778a6a51 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0×1d

Now we come to the more complex example:

1: kd> kv
  *** Stack trace for last set context - .thread/.cxr resets it
Child-SP          RetAddr           : Args to Child                                                           : Call Site
fffffa60`166a7020 fffffa60`07e9dbf2 : fffffa80`1dbd8820 00000000`00000000 fffffa80`1ec3b7a8 fffffa60`166a7278 : Driver!DeviceWrite+0xae
fffffa60`166a7050 fffffa60`062ae7cb : 00000000`00000000 fffffa80`1dbd8820 fffffa60`166a7340 fffffa80`1df4f520 : Driver!RawWrite+0×8a
[…]

1: kd> r
Last set context:
rax=000000000083a03b rbx=fffffa801ec3b800 rcx=fffffa8018cdc000
rdx=0000000000000004 rsi=fffffa801ec3b9f0 rdi=0000000005040000
rip=fffffa6007ea006e rsp=fffffa60166a7020 rbp=fffffa801ec3b7a8
 r8=fffff6fd400f61e0  r9=000000000083a03b r10=fffffa801ec3b9f8
r11=fffffa801ec3b9f8 r12=fffffa801e7c9000 r13=0000000000000000
r14=000000000038011b r15=fffffa8019891670
iopl=0         nv up ei ng nz na po cy
cs=0010 ss=0018 ds=002b es=002b fs=0053 gs=002b efl=00010287
Driver!DeviceWrite+0xae:
fffffa60`07ea006e mov     rax,qword ptr [rdi+10h] ds:002b:00000000`05040010=????????????????

We know that the first parameter to Write function is a pointer to some structure we want to explore because we see from the disassembly that some member from that structure was used ([rcx+320h]) and it was used as a pointer (assigned to RDI) that was trapping ([rdi+10h]):

1: kd> .asm no_code_bytes
Assembly options: no_code_bytes

1: kd> u Driver!DeviceWrite Driver!DeviceWrite+0xae+10
Driver!DeviceWrite:
fffffa60`07e9ffc0 mov     qword ptr [rsp+8],rbx
fffffa60`07e9ffc5 mov     qword ptr [rsp+10h],rbp
fffffa60`07e9ffca mov     qword ptr [rsp+18h],rsi
fffffa60`07e9ffcf push    rdi
fffffa60`07e9ffd0 sub     rsp,20h
fffffa60`07e9ffd4 mov     rdi,qword ptr [rcx+320h]
[…]
fffffa60`07ea006e mov     rax,qword ptr [rdi+10h] ; TRAP
[…]

Unfortunately RCX was not saved on the stack and fffffa80`1dbd8820 from kv was just the value of the saved RBX. This can be double-checked by verifying that parameter+320 doesn’t point to RDI value (05040000) at the time of the trap:

1: kd> dq fffffa80`1dbd8820+320 l1
fffffa80`1dbd8b40  00000000`00020000

Looking at DeviceWrite caller we see that RCX was initialized from RDI:

1: kd> ub fffffa60`07e9dbf2
Driver!RawWrite+0x66:
fffffa60`07e9dbce mov     rax,qword ptr [rdi+258h]
fffffa60`07e9dbd5 mov     qword ptr [rcx-18h],rax
fffffa60`07e9dbd9 mov     rax,qword ptr [rdi+260h]
fffffa60`07e9dbe0 mov     qword ptr [rcx-20h],rax
fffffa60`07e9dbe4 mov     dword ptr [rdx+10h],ebp
fffffa60`07e9dbe7 mov     rdx,rsi
fffffa60`07e9dbea mov     rcx,rdi
fffffa60`07e9dbed call    Driver!DeviceWrite (fffffa60`07e9ffc0)

We also see that RDI was saved at the function prolog so we can get our real first parameter from the raw stack bearing in mind that 0×20 was subtracted from RSP too:

1: kd> dq esp
fffffa60`166a7020  fffffa80`1ec3b800 00000000`05040000 ; SUB RSP, 20H
fffffa60`166a7030  fffffa60`07edc5dd fffffa60`07ee6f8f ;
fffffa60`166a7040  fffffa80`1ec3b520 fffffa60`07e9dbf2 ; Saved RDI - Return Address
fffffa60`166a7050  fffffa80`1dbd8820 00000000`00000000 ; Saved RBX and RBP
fffffa60`166a7060  fffffa80`1ec3b7a8 fffffa60`166a7278 ; Saved RSI 
fffffa60`166a7070  fffffa60`166a7250 fffffa60`01ab5180
fffffa60`166a7080  fffffa80`1e2937c8 fffff800`018a928a
fffffa60`166a7090  00000003`0004000d 00000026`0024000d

We see that saved RDI value +320 points to the right expected address:

1: kd> dq fffffa80`1ec3b520+320 l1
fffffa80`1ec3b840  00000000`05040000

Now we can investigate the structure but this is beyond the scope of this post. 

- Dmitry Vostokov @ DumpAnalysis.org -

Wild code and partial stack reconstruction

September 4th, 2009

I recently got a chance to see an instance of Wild Code pattern in kernel mode:

ATTEMPTED_EXECUTE_OF_NOEXECUTE_MEMORY (fc)
An attempt was made to execute non-executable memory. The guilty driver is on the stack trace (and is typically the current instruction pointer). When possible, the guilty driver's name (Unicode string) is printed on the bugcheck screen and saved in KiBugCheckDriver.
Arguments:
Arg1: a98ccfc4, Virtual address for the attempted execute.
Arg2: 17b1b963, PTE contents.
Arg3: a98ccf38, (reserved)
Arg4: 00000001, (reserved)

3: kd> .trap 0xffffffffa98ccf38
ErrCode = 00000011
eax=00000000 ebx=bf8c16eb ecx=bf855770 edx=00000026 esi=be4da0e8 edi=0000029e
eip=a98ccfc4 esp=a98ccfac ebp=a98ccfa0 iopl=0 nv up ei ng nz ac pe nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010296
a98ccfc4 dcda  fcomp3  st(2)

3: kd> !pte a98ccfc4
VA a98ccfc4
PDE at 00000000C0602A60    PTE at 00000000C054C660
contains 000000000B40A863  contains 8000000017B1B963
pfn b40a       ---DA--KWEV    pfn 17b1b      -G-DA--KW-V

3: kd> k
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr
WARNING: Frame IP not in any known module. Following frames may be wrong.
a98ccff0 80889db4 0xa98ccfc4
a98ccff0 00000000 nt!KiCallbackReturn+0×84

We see that the execution address belongs to thread kernel stack range:

3: kd> !thread
THREAD 8959f548  Cid 20c4.0dd8  Teb: 7ffdf000 Win32Thread: bc1a9550 RUNNING on processor 3
Not impersonating
DeviceMap                 e183a628
Owning Process            890af4b0       Image:         ApplicationA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      67969974       Ticks: 0
Context Switch Count      2833569                 LargeStack
UserTime                  00:01:18.171
KernelTime                00:00:50.468
Win32 Start Address 0x00401c94
Start Address 0x7c8217f8
Stack Init a98cd260 Current a98ccc48 Base a98ce000 Limit a98c3000 Call a98cd268
Priority 13 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr  Args to Child
a98ccea8 8085eced 000000fc a98ccfc4 17b1b963 nt!KeBugCheckEx+0×1b
a98ccf20 8088c798 00000008 a98ccfc4 00000000 nt!MmAccessFault+0xb25
a98ccf20 a98ccfc4 00000008 a98ccfc4 00000000 nt!KiTrap0E+0xdc
WARNING: Frame IP not in any known module. Following frames may be wrong.
a98ccff0 80889db4 0013e3d4 0000000c 00000000 0xa98ccfc4
a98ccff0 00000000 0013e3d4 0000000c 00000000 nt!KiCallbackReturn+0×84

Something must have gone wrong after the return from KiCallbackReturn. On x86 systems this is an IDT entry (2b). See an example output I did while writing down notes on Windows Internals. Windows NT/2000 Native API Reference states that it is the same function as ZwCallBackReturn and it is used to return from win32k.sys user-mode and space callbacks, for example, to send a window message (p. 408). We find the following call on raw stack and use an extended version of k command to get partial stack trace before user-mode callback call:

3: kd> dds a98c3000 a98ce000
[...]
a98cd244 a98cd270
a98cd248 80833485 nt!KiSwapThread+0x305
a98cd24c 8959f548
a98cd250 8959f5f0
a98cd254 00000001
a98cd258 8959f548
a98cd25c 00000000
a98cd260 ffffffff
a98cd264 00000001
a98cd268 a98cd8a0
a98cd26c a98cd604
a98cd270 a98cd8a8
a98cd274 0013f2e4
a98cd278 7ffdf000
a98cd27c 0013e3ac
a98cd280 a98cd2d8
a98cd284 8091d6d1 nt!KeUserModeCallback+0×8f

a98cd288 a98cd388
a98cd28c a98cd384
a98cd290 a98cd370
a98cd294 bc1a9550
a98cd298 006fa0e8
a98cd29c 0013f2e4
a98cd2a0 7ffdf000
a98cd2a4 00000018
a98cd2a8 8948c7f8
[…]

3: kd> k L=a98cd280
ChildEBP RetAddr
WARNING: Frame IP not in any known module. Following frames may be wrong.
a98cd280 8091d6d1 0xa98ccfc4
a98cd2d8 bf858a9a nt!KeUserModeCallback+0×8f
a98cd3b4 bf8a244e win32k!SfnINOUTNCCALCSIZE+0×10b
a98cd3fc bf8a13fa win32k!xxxSendMessageToClient+0×176
a98cd448 bf8a130f win32k!xxxSendMessageTimeout+0×1a6
a98cd46c bf85cd68 win32k!xxxSendMessage+0×1b
a98cd530 bf85daca win32k!xxxCalcValidRects+0×3bc
a98cd58c bf85def4 win32k!xxxEndDeferWindowPosEx+0xf2
a98cd5a8 bf85061c win32k!xxxSetWindowPos+0xb1
a98cd5cc bf8e3df8 win32k!xxxRedrawFrame+0×16
a98cd5d8 bf8a2b69 win32k!xxxDrawMenuBar+0×19
a98cd5f4 8088978c win32k!NtUserCallHwndLock+0×6b
a98cd5f4 7c9485ec nt!KiFastCallEntry+0xfc

0013e438 00000000 0×7c9485ec

- Dmitry Vostokov @ DumpAnalysis.org -

Bugtation No.102

September 4th, 2009

I don’t read mere books. I analyze memory dumps. Books are memory dumps. Memory dumps are books.

Dmitry Vostokov, Variation on a theme “A book is a memory dump”

- Dmitry Vostokov @ DumpAnalysis.org -

SAD Events (Debugging Slang, Part 3)

September 3rd, 2009
SAD event

System or Application Dump event

- Dmitry Vostokov @ DumpAnalysis.org -

Stack Space and Program Database Types

September 2nd, 2009

Readers of my book Windows Debugging: Practical Foundations asked why so much space is allocated on a stack when they run the sample from Chapter 10, “Frame Pointer and Local Variables”. They expected the following instruction for two integer local variables:

sub esp, 8

What they see is:

sub esp, d8h

Originally I thought that it was the effect of certain optimization or verification options for default Debug configuration in Visual C++. To check that I created a small console project with the following C/C++ code:

int _tmain(int argc, _TCHAR* argv[])
{
    int a = 1;

    return 0;
}

Default Debug configuration in Visual C++ 2008 Express Edition generates this code:

0:000:x86> uf wmain
StackAllocation!wmain:
    7 01211370 push    ebp
    7 01211371 mov     ebp,esp
    7 01211373 sub     esp,0CCh
    7 01211379 push    ebx
    7 0121137a push    esi
    7 0121137b push    edi
    7 0121137c lea     edi,[ebp-0CCh]
    7 01211382 mov     ecx,33h
    7 01211387 mov     eax,0CCCCCCCCh
    7 0121138c rep stos dword ptr es:[edi]
    8 0121138e mov     dword ptr [ebp-8],1
   10 01211395 xor     eax,eax
   11 01211397 pop     edi
   11 01211398 pop     esi
   11 01211399 pop     ebx
   11 0121139a mov     esp,ebp
   11 0121139c pop     ebp
   11 0121139d ret

Default Release configuration with disabled optimization and whole program optimization properties also generates the code with large stack space reservation:

0:000:x86> uf wmain
StackAllocation!wmain:
    7 00021000 push    ebp
    7 00021001 mov     ebp,esp
    7 00021003 sub     esp,44h
    7 00021006 push    ebx
    7 00021007 push    esi
    7 00021008 push    edi
    8 00021009 mov     dword ptr [ebp-4],1
   10 00021010 xor     eax,eax
   11 00021012 pop     edi
   11 00021013 pop     esi
   11 00021014 pop     ebx
   11 00021015 mov     esp,ebp
   11 00021017 pop     ebp
   11 00021018 ret

We still have 0×44 bytes allocated instead of 4. Playing with further options I found that choosing Program Database (/Zi) instead of default Program Database for Edit & Continue (/ZI) Debug Information Format general property reduces allocated stack space down to exact 4 bytes:

0:000:x86> uf wmain
StackAllocation!wmain:
    7 00c71000 push    ebp
    7 00c71001 mov     ebp,esp
    7 00c71003 push    ecx
    8 00c71004 mov     dword ptr [ebp-4],1
   10 00c7100b xor     eax,eax
   11 00c7100d mov     esp,ebp
   11 00c7100f pop     ebp
   11 00c71010 ret

We see here push ecx instead of sub esp, 4 but the result is equivalent in terms of space reservation of 4 bytes. Going back to Debug configuration and changing Debug Information Format we reduce space allocation too:

0:000:x86> uf wmain
StackAllocation!wmain:
    7 01361010 push    ebp
    7 01361011 mov     ebp,esp
    7 01361013 push    ecx
    7 01361014 mov     dword ptr [ebp-4],0CCCCCCCCh
    8 0136101b mov     dword ptr [ebp-4],1
   10 01361022 xor     eax,eax
   11 01361024 mov     esp,ebp
   11 01361026 pop     ebp
   11 01361027 ret

We also see redundant filling of 4 bytes with 0xCC pattern but this is the effect of Basic Runtime Checks in Code Generation properties. If we change them to Default we eliminate filling and the code becomes identical to Release configuration:

0:000:x86> uf wmain
StackAllocation!wmain:
    7 010e1010 push    ebp
    7 010e1011 mov     ebp,esp
    7 010e1013 push    ecx
    8 010e1014 mov     dword ptr [ebp-4],1
   10 010e101b xor     eax,eax
   11 010e101d mov     esp,ebp
   11 010e101f pop     ebp
   11 010e1020 ret

- Dmitry Vostokov @ DumpAnalysis.org -

Exception Processing Of Crash Hypothesis (EPOCH)

September 2nd, 2009

Our Universe is Unhandled Exception Processing saving one huge Memory Dump from a runaway HUC (Big Bang of Hyper-Universal Computation, or simply HUge Computation). The idea came to me some months ago but I decided to publish it after learning today about a “Mathematical Universe Hypothesis” (MUH) from Max Tegmark stating that our Universe is Mathematics.

EPOCH

Exception Processing Of Crash Hypothesis (or Memory Dump Universe Hypothesis)

Note: what a sad feeling I had while simultaneously listening to the Light track from Thin Red Line soundtrack while writing this post…

- Dmitry Vostokov @ DumpAnalysis.org -