Archive for the ‘Debugging’ Category

Deadlock and Livelock Patterns

Tuesday, February 17th, 2009

While preparing a presentation for an engineering conference I found that a page to reference all different kinds of deadlocks is necessary, so I created this post:

I’ll update it as soon as I add more similar patterns.

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

The Mystery of Negative LockCount

Monday, February 16th, 2009

I’ve always wondered why LockCount is sometimes negative in the latest OS versions since SPs for Windows Server 2003:

0:000> !locks

CritSec +319ee0 at 00319EE0
LockCount -90
RecursionCount 1
OwningThread 1198
EntryCount 0
ContentionCount 734a6
*** Locked

CritSec +202e3d0 at 0202E3D0
LockCount -2
RecursionCount 1
OwningThread 1198
EntryCount 0
ContentionCount 0
*** Locked

CritSec +1b69ad4 at 01B69AD4
LockCount -2
RecursionCount 1
OwningThread 1198
EntryCount 0
ContentionCount 0
*** Locked

Finally the post on NT Debugging Blog pointed to WinDbg Help article (the section Interpreting Critical Section Fields in Windows Server 2003 SP1 and Later):

http://msdn.microsoft.com/en-us/library/cc267476.aspx

Be aware though that negative values could also mean Critical Section Corruption pattern:

CritSec printerA!DlgProc+53b38 at 107cddd8
WaiterWoken Yes
LockCount -69154612
RecursionCount 276618309
OwningThread 107cdd36

EntryCount 0
ContentionCount 0
*** Locked 

- Dmitry Vostokov @ DumpAnalysis.org -

Insufficient memory, handle leak, process factory, high contention and busy system: pattern cooperation

Monday, February 16th, 2009

It was reported that one system became slower and slower and eventually the complete memory dump was generated for analysis. Usual !vm 4 command shows pool allocation errors and particularly insufficient session pool memory for user session 1:

1: kd> !vm 4

*** Virtual Memory Usage ***
 Physical Memory:     1048503 (   4194012 Kb)
 Page File: \??\C:\pagefile.sys
   Current:   5109760 Kb  Free Space:   3668764 Kb
   Minimum:   5109760 Kb  Maximum:      5109760 Kb
 Available Pages:      409409 (   1637636 Kb)
 ResAvail Pages:       708135 (   2832540 Kb)
 Locked IO Pages:         108 (       432 Kb)
 Free System PTEs:     137566 (    550264 Kb)
 Free NP PTEs:          27288 (    109152 Kb)
 Free Special NP:           0 (         0 Kb)
 Modified Pages:          780 (      3120 Kb)
 Modified PF Pages:       771 (      3084 Kb)
 NonPagedPool Usage:    37587 (    150348 Kb)
 NonPagedPool Max:      65214 (    260856 Kb)

 PagedPool 0 Usage:     21583 (     86332 Kb)
 PagedPool 1 Usage:      3054 (     12216 Kb)
 PagedPool 2 Usage:      3076 (     12304 Kb)
 PagedPool 3 Usage:      3050 (     12200 Kb)
 PagedPool 4 Usage:      3040 (     12160 Kb)
 PagedPool Usage:       33803 (    135212 Kb)
 PagedPool Maximum:     66560 (    266240 Kb)

 ********** 185454 pool allocations have failed **********

 Shared Commit:        123289 (    493156 Kb)
 Special Pool:              0 (         0 Kb)
 Shared Process:       101937 (    407748 Kb)
 PagedPool Commit:      33850 (    135400 Kb)
 Driver Commit:          1697 (      6788 Kb)
 Committed pages:     1159581 (   4638324 Kb)
 Commit limit:        2283111 (   9132444 Kb)

[...]

 Session ID 1 @ af925000:
 Paged Pool Usage:       16868K

 *** 371034 Pool Allocation Failures ***

 Commit Usage:           17960K

 Session ID 2 @ af927000:
 Paged Pool Usage:        2856K
 Commit Usage:            3860K

[...]

The exploration of session 1 processes shows Process Factory pattern (5,000 launched processes) with explorer.exe ran amok:

1: kd> !sprocess 1
Dumping Session 1

_MM_SESSION_SPACE af925000
_MMSESSION        af925d80
PROCESS 87db34a0  SessionId: 1  Cid: 4a68    Peb: 7ffd4000  ParentCid: 01b8
    DirBase: cffb6d20  ObjectTable: e6084268  HandleCount: 11677.
    Image: csrss.exe

PROCESS 86083020  SessionId: 1  Cid: 4560    Peb: 7ffde000  ParentCid: 2978
    DirBase: cffb6f40  ObjectTable: e6c41410  HandleCount:  79.
    Image: AnotherApp.exe

PROCESS 8607c020  SessionId: 1  Cid: 44c8    Peb: 7ffdc000  ParentCid: 4cf8
    DirBase: cffb7080  ObjectTable: e3c9fd38  HandleCount: 25407.
    Image: explorer.exe

[...]

PROCESS 85e94738  SessionId: 1  Cid: 4868    Peb: 7ffde000  ParentCid: 44c8
    DirBase: cffb7c00  ObjectTable: e7038840  HandleCount:  39.
    Image: application.exe

PROCESS 85e5c020  SessionId: 1  Cid: 4668    Peb: 7ffd4000  ParentCid: 4a50
    DirBase: cffb7de0  ObjectTable: e11891d0  HandleCount: 172.
    Image: application.exe

PROCESS 85e51578  SessionId: 1  Cid: 4c9c    Peb: 7ffde000  ParentCid: 44c8
    DirBase: cffb7e40  ObjectTable: e2ee0070  HandleCount:  39.
    Image: application.exe

[...]

PROCESS 85c81020  SessionId: 1  Cid: 53a4    Peb: 7ffd7000  ParentCid: 44c8
    DirBase: cffb89c0  ObjectTable: e6d2f600  HandleCount:  39.
    Image: application.exe

PROCESS 85c6fb18  SessionId: 1  Cid: 53a8    Peb: 7ffd7000  ParentCid: 44c8
    DirBase: cffb89e0  ObjectTable: e54df078  HandleCount:  39.
    Image: application.exe

PROCESS 85c60020  SessionId: 1  Cid: 53bc    Peb: 7ffdf000  ParentCid: 44c8
    DirBase: cffb8a40  ObjectTable: e1214e90  HandleCount:  39.
    Image: application.exe

[...]

We can also see the very big number of handles in both csrss.exe and explorer.exe. If we look at one of 5,000 application.exe processes we would see that it is a GUI application and this explains session pool exhaustion:

1: kd> !process 85c60020 1f
PROCESS 85c60020  SessionId: 1  Cid: 53bc    Peb: 7ffdf000  ParentCid: 44c8
    DirBase: cffb8a40  ObjectTable: e1214e90  HandleCount:  39.
    Image: application.exe
    VadRoot 85c97450 Vads 80 Clone 0 Private 173. Modified 159. Locked 0.
    DeviceMap e3743340
    Token                             e2ead5e0
    ElapsedTime                       00:54:17.218
    UserTime                          00:00:00.015
    KernelTime                        00:00:00.000
    QuotaPoolUsage[PagedPool]         32460
    QuotaPoolUsage[NonPagedPool]      3200
    Working Set Sizes (now,min,max)  (30, 50, 345) (120KB, 200KB, 1380KB)
    PeakWorkingSetSize                778
    VirtualSize                       16 Mb
    PeakVirtualSize                   17 Mb
    PageFaultCount                    829
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      212

THREAD 85c25db0  Cid 53bc.5470  Teb: 7ffde000 Win32Thread: bd1a18a8 WAIT: (Unknown) UserMode Non-Alertable
    85bbf2a8  SynchronizationEvent
Not impersonating
DeviceMap                 e3743340
Owning Process            85c60020       Image:         application.exe
Wait Start TickCount      1121133        Ticks: 206877 (0:00:53:52.453)
Context Switch Count      19355  NoStackSwap    LargeStack
UserTime                  00:00:00.015
KernelTime                00:00:00.000
Win32 Start Address application (0x00402a38)
Start Address kernel32!BaseProcessStartThunk (0x7c8217f8)
Stack Init ad2b8000 Current ad2b7b1c Base ad2b8000 Limit ad2b4000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
ad2b7b34 80833ec5 nt!KiSwapContext+0x26
ad2b7b60 80829bc0 nt!KiSwapThread+0x2e5
ad2b7ba8 bf89aacc nt!KeWaitForSingleObject+0x346
ad2b7c04 bf8c4816 win32k!xxxSleepThread+0×1be
ad2b7ca0 bf8a134f win32k!xxxInterSendMsgEx+0×798
ad2b7cec bf85ae3c win32k!xxxSendMessageTimeout+0×1f3
ad2b7d10 bf8c13dc win32k!xxxWrapSendMessage+0×1b
ad2b7d40 8088ad3c win32k!NtUserMessageCall+0×9d

ad2b7d40 7c9485ec nt!KiFastCallEntry+0xfc (TrapFrame @ ad2b7d64)
0012f814 00000000 ntdll!KiFastSystemCallRet

We also see extremely high executive resource contention and various signs of a busy system like the fact that all processors are busy and very high number of ready threads at normal priority (about 1,000):

1: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****

Resource @ DriverA (0xbae016a0)    Exclusively owned
    Contention Count = 277088870
    NumberOfExclusiveWaiters = 3591
     Threads: 83b46db0-01<*> << Too many exclusive waiters to list>>

1: kd> !running

System Processors ff (affinity mask)
  Idle Processors 0

     Prcb      Current   Next   
  0  ffdff120  86300b40            …………….
  1  f772f120  f77320a0  852fadb0  …………….
  2  f7737120  f773a0a0  861528d0  …………….
  3  f773f120  f77420a0  877a4020  …………….
  4  f7747120  f774a0a0  865909a8  …………….
  5  f774f120  f77520a0  83d62cd0  …………….
  6  f7757120  f775a0a0  841aa020  …………….
  7  f775f120  f77620a0  ffb7b5e0  …………….

1: kd> !ready
Processor 0: No threads in READY state
Processor 1: Ready Threads at priority 10
    THREAD 861b1898  Cid 4860.4894  Teb: 7ffd8000 Win32Thread: bc1669a8 READY
Processor 1: Ready Threads at priority 9
    THREAD 83b46db0  Cid 44c8.a11c  Teb: 7f8f8000 Win32Thread: bcbabb38 READY
Processor 1: Ready Threads at priority 8
    THREAD 851408d0  Cid 6338.6398  Teb: 7ffdf000 Win32Thread: bc9bfbb8 READY
    THREAD 83eb1730  Cid 8f30.9568  Teb: 7ffdf000 Win32Thread: 00000000 READY
    THREAD fd310af8  Cid d53c.b4d8  Teb: 7ffdf000 Win32Thread: 00000000 READY
    THREAD 83bce8d0  Cid abec.6450  Teb: 7ffdd000 Win32Thread: 00000000 READY
    THREAD 83de2388  Cid a618.d79c  Teb: 7ffde000 Win32Thread: 00000000 READY
    THREAD 84197b40  Cid 44c8.6974  Teb: 7fe6a000 Win32Thread: bc662d48 READY
[…]

Processor 1: Ready Threads at priority 7
    THREAD 86d0c890  Cid 3524.365c  Teb: 7ff8e000 Win32Thread: bc403bb0 READY
Processor 2: No threads in READY state
Processor 3: No threads in READY state
Processor 4: No threads in READY state
Processor 5: No threads in READY state
Processor 6: No threads in READY state
Processor 7: No threads in READY state

There is AnotherApp.exe in the session process list that executes a VBS script:  

1: kd> .process /r /p 86083020
Implicit process is now 86083020
Loading User Symbols

1: kd> !process 86083020
[...]

        THREAD 860b0db0  Cid 4560.4e4c  Teb: 7ffdd000 Win32Thread: bc1bf4d0 WAIT: (Unknown) KernelMode Non-Alertable
            860b0e28  NotificationTimer

1: kd> .thread 860b0db0
Implicit thread is now 860b0db0

1: kd> kv 100
ChildEBP RetAddr  Args to Child             
ae7ec76c 80833ec5 860b0db0 860b0ea0 00000000 nt!KiSwapContext+0x26
ae7ec798 80829069 0000001e 00000000 bae016a0 nt!KiSwapThread+0x2e5
ae7ec7e0 badff394 00000000 00000000 ffdff5f0 nt!KeDelayExecutionThread+0x2ab
[...]
0012f6ac 7c8024d5 00000000 00000000 00a43280 kernel32!CreateProcessInternalA+0x28b
0012f6e4 00401b31 00000000 00a43280 00000000 kernel32!CreateProcessA+0×2c
[…]

1: kd> da /c 100 00a43280
00a43280  “wscript.exe C:\Scripts\script.vbs parameters”

The examination of that script showed that it contained a coding error resulted in an infinite loop.

- Dmitry Vostokov @ DumpAnalysis.org -

The Topos of Debugging

Sunday, February 15th, 2009

An idea struck me today while I was walking in People’s Park near Dun Laoghaire to formalize various effective intuitive notions in memory dump analysis, debugging and troubleshooting using topos theory. More on this later.

- Dmitry Vostokov @ DumpAnalysis.org -

WDPF book gains value after being used

Friday, February 13th, 2009

Noticed today on Amazon that my book becomes more expensive after being used:

- Dmitry Vostokov @ DumpAnalysis.org -

Crash Dump Analysis Patterns (Part 80)

Friday, February 13th, 2009

I remember in my old days of PDP-11 system programming I learnt about the system call to spawn processes and wrote a program in assembly language that was spawning itself. This recursive spawning resulted in geometrical progression of running tasks and brought RSX-11M system to halt very quickly. Recently I observed the similar but non-recursive Process Factory pattern in one of memory dumps: explorer was relentlessly creating application.exe processes and at the time some effect was noticed there were more than 5,000 of them:

1: kd> !vm
[...]
5d20 application.exe 212 ( 848 Kb)
5d08 application.exe 212 ( 848 Kb)
5d04 application.exe 212 ( 848 Kb)
5cf8 application.exe 212 ( 848 Kb)
5cf0 application.exe 212 ( 848 Kb)
5ce8 application.exe 212 ( 848 Kb)
5cdc application.exe 212 ( 848 Kb)
5ccc application.exe 212 ( 848 Kb)
5cc8 application.exe 212 ( 848 Kb)
5cc0 application.exe 212 ( 848 Kb)
5ca8 application.exe 212 ( 848 Kb)
5c9c application.exe 212 ( 848 Kb)
5c98 application.exe 212 ( 848 Kb)
5c90 application.exe 212 ( 848 Kb)
5c88 application.exe 212 ( 848 Kb)
5c7c application.exe 212 ( 848 Kb)
5c70 application.exe 212 ( 848 Kb)
5c68 application.exe 212 ( 848 Kb)
5c64 application.exe 212 ( 848 Kb)
5c60 application.exe 212 ( 848 Kb)
5c50 application.exe 212 ( 848 Kb)
5c4c application.exe 212 ( 848 Kb)
5c44 application.exe 212 ( 848 Kb)
5c3c application.exe 212 ( 848 Kb)
5c34 application.exe 212 ( 848 Kb)
5c2c application.exe 212 ( 848 Kb)
5c24 application.exe 212 ( 848 Kb)
5c1c application.exe 212 ( 848 Kb)
5bf8 application.exe 212 ( 848 Kb)
5be0 application.exe 212 ( 848 Kb)
5bd4 application.exe 212 ( 848 Kb)
5bd0 application.exe 212 ( 848 Kb)
5ba4 application.exe 212 ( 848 Kb)
5b58 application.exe 212 ( 848 Kb)
5b50 application.exe 212 ( 848 Kb)
5b44 application.exe 212 ( 848 Kb)
5b38 application.exe 212 ( 848 Kb)
5b30 application.exe 212 ( 848 Kb)
5b04 application.exe 212 ( 848 Kb)
5af4 application.exe 212 ( 848 Kb)
5ad8 application.exe 212 ( 848 Kb)
5ad4 application.exe 212 ( 848 Kb)
5ac8 application.exe 212 ( 848 Kb)
5ac4 application.exe 212 ( 848 Kb)
5ab4 application.exe 212 ( 848 Kb)
5aa4 application.exe 212 ( 848 Kb)
5a9c application.exe 212 ( 848 Kb)
5a94 application.exe 212 ( 848 Kb)
5a8c application.exe 212 ( 848 Kb)
5a88 application.exe 212 ( 848 Kb)
5a74 application.exe 212 ( 848 Kb)
[...]

1: kd> !process 0 0
**** NT ACTIVE PROCESS DUMP ****
PROCESS 8b57f020  SessionId: none  Cid: 0004    Peb: 00000000  ParentCid: 0000
    DirBase: cffb3020  ObjectTable: e1003da0  HandleCount: 3932.
    Image: System

PROCESS 8a9f8d88  SessionId: none  Cid: 01b8    Peb: 7ffdf000  ParentCid: 0004
    DirBase: cffb3040  ObjectTable: e13e3f68  HandleCount: 111.
    Image: smss.exe

PROCESS 89f0d508  SessionId: 0  Cid: 01f0    Peb: 7ffd8000  ParentCid: 01b8
    DirBase: cffb3060  ObjectTable: e16bc370  HandleCount: 1292.
    Image: csrss.exe

PROCESS 89eea7c8  SessionId: 0  Cid: 0208    Peb: 7ffde000  ParentCid: 01b8
    DirBase: cffb3080  ObjectTable: e14b4160  HandleCount: 564.
    Image: winlogon.exe

[...]

PROCESS 8607c020  SessionId: 1  Cid: 44c8    Peb: 7ffdc000  ParentCid: 4cf8
    DirBase: cffb7080  ObjectTable: e3c9fd38  HandleCount: 25407.
    Image: explorer.exe

[...]

PROCESS 85e1d020  SessionId: 1  Cid: 538c    Peb: 7ffda000  ParentCid: 44c8
    DirBase: cffb8980  ObjectTable: e8065b20  HandleCount:  39.
    Image: application.exe

PROCESS 85c74610  SessionId: 1  Cid: 5394    Peb: 7ffd9000  ParentCid: 44c8
    DirBase: cffb89a0  ObjectTable: e6951878  HandleCount:  39.
    Image: application.exe

PROCESS 85c81020  SessionId: 1  Cid: 53a4    Peb: 7ffd7000  ParentCid: 44c8
    DirBase: cffb89c0  ObjectTable: e6d2f600  HandleCount:  39.
    Image: application.exe

PROCESS 85c6fb18  SessionId: 1  Cid: 53a8    Peb: 7ffd7000  ParentCid: 44c8
    DirBase: cffb89e0  ObjectTable: e54df078  HandleCount:  39.
    Image: application.exe

PROCESS 85c60020  SessionId: 1  Cid: 53bc    Peb: 7ffdf000  ParentCid: 44c8
    DirBase: cffb8a40  ObjectTable: e1214e90  HandleCount:  39.
    Image: application.exe

PROCESS 85c5d380  SessionId: 1  Cid: 53c8    Peb: 7ffde000  ParentCid: 44c8
    DirBase: cffb8a60  ObjectTable: e7baf638  HandleCount:  39.
    Image: application.exe

PROCESS 85c648b8  SessionId: 1  Cid: 53dc    Peb: 7ffde000  ParentCid: 44c8
    DirBase: cffb8a80  ObjectTable: e759d060  HandleCount:  39.
    Image: application.exe

PROCESS 85c62528  SessionId: 1  Cid: 53e0    Peb: 7ffde000  ParentCid: 44c8
    DirBase: cffb8aa0  ObjectTable: e3b8fa00  HandleCount:  39.
    Image: application.exe

PROCESS 85c59d88  SessionId: 1  Cid: 53e8    Peb: 7ffdc000  ParentCid: 44c8
    DirBase: cffb8ac0  ObjectTable: e31751e0  HandleCount:  39.
    Image: application.exe

PROCESS 85c46d88  SessionId: 1  Cid: 542c    Peb: 7ffd5000  ParentCid: 4d9c
    DirBase: cffb8b00  ObjectTable: e6fbc500  HandleCount: 136.
    Image: nlapplication.exe

PROCESS 85c3c020  SessionId: 1  Cid: 5464    Peb: 7ffdc000  ParentCid: 44c8
    DirBase: cffb8b40  ObjectTable: e218b948  HandleCount:  39.
    Image: application.exe

PROCESS 85c2a020  SessionId: 1  Cid: 546c    Peb: 7ffdb000  ParentCid: 44c8
    DirBase: cffb8b60  ObjectTable: e639a8d0  HandleCount:  39.
    Image: application.exe

PROCESS 85c202c8  SessionId: 1  Cid: 5474    Peb: 7ffd7000  ParentCid: 44c8
    DirBase: cffb8b80  ObjectTable: e517caa8  HandleCount:  39.
    Image: application.exe

PROCESS 85c1b020  SessionId: 1  Cid: 547c    Peb: 7ffd6000  ParentCid: 44c8
    DirBase: cffb8ba0  ObjectTable: e6c0cbc0  HandleCount:  39.
    Image: application.exe

PROCESS 85c1dd88  SessionId: 1  Cid: 5484    Peb: 7ffd5000  ParentCid: 44c8
    DirBase: cffb8bc0  ObjectTable: e4a42f68  HandleCount:  39.
    Image: application.exe

PROCESS 85d3ed88  SessionId: 1  Cid: 5488    Peb: 7ffd5000  ParentCid: 44c8
    DirBase: cffb8be0  ObjectTable: e68558f0  HandleCount:  39.
    Image: application.exe

[...]

We see that all created processes have the same parent process with PID 44c8 and when we inspect it we see many threads inside creating application.exe process:

1: kd> .process /r /p 8607c020
Implicit process is now 8607c020
Loading User Symbols

1: kd> !process 8607c020
PROCESS 8607c020  SessionId: 1  Cid: 44c8    Peb: 7ffdc000  ParentCid: 4cf8
    DirBase: cffb7080  ObjectTable: e3c9fd38  HandleCount: 25407.
    Image: explorer.exe
    VadRoot 88efec98 Vads 3445 Clone 0 Private 30423. Modified 71292. Locked 0.
    DeviceMap e3743340
    Token                             e29be5e0
    ElapsedTime                       00:54:31.359
    UserTime                          00:00:19.234
    KernelTime                        00:04:04.828
    QuotaPoolUsage[PagedPool]         1075132
    QuotaPoolUsage[NonPagedPool]      137800
    Working Set Sizes (now,min,max)  (15457, 50, 345) (61828KB, 200KB, 1380KB)
    PeakWorkingSetSize                48919
    VirtualSize                       585 Mb
    PeakVirtualSize                   978 Mb
    PageFaultCount                    123488
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      49919

[...]

THREAD 84f25300  Cid 44c8.6288  Teb: 7ff8e000 Win32Thread: bc486830 READY
IRP List:
    88699110: (0006,0220) Flags: 00000884  Mdl: 00000000
Not impersonating
DeviceMap                 e3743340
Owning Process            8607c020       Image:         explorer.exe
Wait Start TickCount      1327981        Ticks: 29 (0:00:00:00.453)
Context Switch Count      145332                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.093
Win32 Start Address SHLWAPI!SHCreateThread (0x77ec3ea5)
Start Address kernel32!BaseThreadStartThunk (0x7c8217ec)
Stack Init a98e4000 Current a98e3700 Base a98e4000 Limit a98e0000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
a98e3718 80833ec5 nt!KiSwapContext+0x26
a98e3744 80829bc0 nt!KiSwapThread+0x2e5
a98e378c 8087e0d8 nt!KeWaitForSingleObject+0x346
a98e37c4 8087e397 nt!ExpWaitForResource+0x30
a98e37e4 badff32a nt!ExAcquireResourceExclusiveLite+0x8d
a98e3808 badffe35 driverA+0x132a
a98e3824 bae00208 driverA+0x1e35
a98e3868 bae0e45a driverA+0x2208
a98e38a0 8081e095 driverA+0x1045a
a98e38b4 b972c73b nt!IofCallDriver+0x45
[...]
a98e38e8 b9b194e1 nt!IofCallDriver+0x45
[...]
a98e3940 b85cbf08 nt!IofCallDriver+0x45
a98e3968 b85bcfcc driverB!LowerDevicePassThrough+0x48
a98e398c b85bd63d driverB+0x6fcc
a98e3a24 b85cb167 driverB+0x763d
a98e3a34 b85cb1b7 driverB+0x15167
a98e3a5c 8081e095 driverB!DispatchPassThrough+0x48
a98e3a70 808fb13b nt!IofCallDriver+0x45
a98e3b58 80939c6a nt!IopParseDevice+0xa35
a98e3bd8 80935d9e nt!ObpLookupObjectName+0x5b0
a98e3c2c 808ece57 nt!ObOpenObjectByName+0xea
a98e3ca8 808ee0f1 nt!IopCreateFile+0x447
a98e3d04 808f1e31 nt!IoCreateFile+0xa3
a98e3d44 8088ad3c nt!NtOpenFile+0x27
a98e3d44 7c9485ec nt!KiFastCallEntry+0xfc (TrapFrame @ a98e3d64)
03bbda04 7c82bdf6 ntdll!KiFastSystemCallRet
03bbda2c 7c82dd9a kernel32!BasepSxsCreateStreams+0xe2
03bbda9c 7c82d895 kernel32!BasepSxsCreateProcessCsrMessage+0x136
03bbe2c4 7c8024a0 kernel32!CreateProcessInternalW+0x1943
03bbe2fc 7ca36750 kernel32!CreateProcessW+0×2c
03bbed80 7ca36b45 SHELL32!_SHCreateProcess+0×387
03bbedd4 7ca3617b SHELL32!CShellExecute::_DoExecCommand+0xb4
03bbede0 7ca35a76 SHELL32!CShellExecute::_TryInvokeApplication+0×49
03bbedf4 7ca3599f SHELL32!CShellExecute::ExecuteNormal+0xb1
03bbee08 7ca35933 SHELL32!ShellExecuteNormal+0×30
03bbee24 7ca452ff SHELL32!ShellExecuteExW+0×8d

1: kd> .thread 84e6a600
Implicit thread is now 84e6a600

1: kd> kv 100
[...]
03bbda04 7c82bdf6 001200a9 03bbda8c 03bbdb20 ntdll!KiFastSystemCallRet
03bbda2c 7c82dd9a 00000000 00000003 001200a9 kernel32!BasepSxsCreateStreams+0xe2
03bbda9c 7c82d895 00000000 00000000 03bbdc38 kernel32!BasepSxsCreateProcessCsrMessage+0x136
03bbe2c4 7c8024a0 00000000 01dafb9c 01dad904 kernel32!CreateProcessInternalW+0x1943
03bbe2fc 7ca36750 01dafb9c 01dad904 00000000 kernel32!CreateProcessW+0×2c
03bbed80 7ca36b45 00010098 00000000 01daffac SHELL32!_SHCreateProcess+0×387
[…]

1: kd> du /c 100 01dafb9c
01dafb9c  “C:\Program Files\App Package\Application.exe”

The difference of this pattern and similar Handle Leak or Zombie Processes is the fact that leaks usually happen when a process forgets to close handles but Process Factory creates active processes which are full resource containers and consume system resources, for example, they all have full handle table or consume GDI resources if they are GUI processes.

- Dmitry Vostokov @ DumpAnalysis.org -

Music for Debugging: Some Bugs Never Disappear

Wednesday, February 11th, 2009

If you complain about heap corruption again or type !locks every day and see pages of output filled with columns the following album from Supertramp reminds us that

Some Things Never Change

Here is my track name interpretation:

1. It’s a Buggy World
2. You Code, I Debug
3. Let’s Debug Together
4. Live to Debug It
5. Some Bugs Never Disappear
6. Read My Bug Report Please
7. Sooner or Later I Fix It
8. Help Me Down that Code Path
9. And the Customer
10. Il Est De Mon Bug!
11. Where There’s a Bug

- Dmitry Vostokov @ DumpAnalysis.org -

Geometrical Debugging (Part 1)

Tuesday, February 10th, 2009

Most of (if not all) debugging is arithmetical. Here I would like to introduce a new kind of debugging and troubleshooting approach that interprets observables as objects in their own spaces, for example, the possible space of various GUI forms. These spaces are not necessarily rational-valued spaces of simulation output or discreet arithmetic spaces of memory locations and values.

This geometrical approach applies modeling and systems theory to debugging and troubleshooting by treating them as mappings (or functions in the case of one-to-one or many-to-one mappings) from the space of all possible software environment states (SE) to the space(s) of observables. Here we have a family of mappings to different spaces:

fi: SE → SOi

Some observables can be found fixed like the list of components and the number of mappings can be reduced (i < j):

fj: SEa,b,c,d,… → SOj

In every system and its environment we have something fixed as parameters (a, b, c, d, …) and this could be the list of components as high level ”genotype” or it could be just specific code (low-level “genotype”), specific data or hardware specification. The whole family of mappings become parametrized. If we want, we can reduce mappings even more to treat them as many-valued (one-to-many or many-to-many) if several observables belong to the same kind of space. 

Let me illustrate this by an analogy with modeling of a natural system. The system to be modeled is a falling ball together with its environment (Earth). The system obviously has some internal structure (abstract space of states, E) but we don’t know it. Fortunately, we can observe some measurable values like the ball position at any time (Q). So we have these mappings for balls with different masses:

fm: E → Q

We also find that for any individual ball its mass doesn’t change so we abstract it as a parameter:

f: Em → Q

The same modeling approach can be applied to a software system be it an application or a service running inside an operating system or a software system itself running inside a hardware. The case of pure software system abstracted from hardware is simple. In such a case SE space theoretically could be the space of abstract memory dumps. Practically we deal with the space of observables (universal memory dumps) that approximate SE and spaces of software “phenotypes”, observable behaviour, like distorted GUI, for example, or measured values of memory and CPU consumption or disk I/O throughput. 

- Dmitry Vostokov @ DumpAnalysis.org -

WDPF book is available on Amazon

Tuesday, February 10th, 2009

The book is available for ordering from Amazon with a significant discount:

Windows Debugging: Practical Foundations

Buy from Amazon

Although listed as temporarily out of stock at the time of this writing it should appear in stock in a few days. Search Inside is also enabled.

- Dmitry Vostokov @ DumpAnalysis.org -

32-bit stack traces from x64 complete dumps

Friday, February 6th, 2009

In the past I was not able or didn’t know how to view 32-bit process thread stacks when looking at a complete memory dump from x64 Windows. So I had to request user dumps. Now I want to share a technique a reader of my blog (Yuhong Bao) suggested: to use .thread WinDbg command with /w option. Here are additional steps that I found necessary when playing with my test complete memory dump from x64 Windows Server 2003 SP2 (I used the latest version of WinDbg from 64-bit Debugging Tools for Windows):

0. Find a 32-bit process of interest:

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

PROCESS fffffadfe6b14040
    SessionId: none  Cid: 0130    Peb: 7fffffd8000  ParentCid: 0004
    DirBase: 353c0000  ObjectTable: fffffa80009104a0  HandleCount:  19.
    Image: smss.exe

PROCESS fffffadfe65cec20
    SessionId: 0  Cid: 0160    Peb: 7fffffde000  ParentCid: 0130
    DirBase: 30210000  ObjectTable: fffffa80006a4d80  HandleCount: 732.
    Image: csrss.exe

PROCESS fffffadfe73b7040
    SessionId: 0  Cid: 0270    Peb: 7fffffdc000  ParentCid: 0130
    DirBase: 302b6000  ObjectTable: fffffa8000520710  HandleCount: 751.
    Image: winlogon.exe

PROCESS fffffadfe737d040
    SessionId: 0  Cid: 02a0    Peb: 7fffffd7000  ParentCid: 0270
    DirBase: 0060d000  ObjectTable: fffffa80008df6a0  HandleCount: 339.
    Image: services.exe

PROCESS fffffadfe6574040
    SessionId: 0  Cid: 02ac    Peb: 7fffffd5000  ParentCid: 0270
    DirBase: 0070d000  ObjectTable: fffffa80008e16a0  HandleCount: 510.
    Image: lsass.exe

PROCESS fffffadfe7860040
    SessionId: 0  Cid: 0364    Peb: 7fffffd7000  ParentCid: 02a0
    DirBase: 0935e000  ObjectTable: fffffa8000969710  HandleCount:  87.
    Image: svchost.exe

[...]

PROCESS fffffadfe751d040
    SessionId: 0  Cid: 0bcc    Peb: 7efdf000  ParentCid: 0abc
    DirBase: 18861000  ObjectTable: fffffa8001ecbc30  HandleCount: 326.
    Image: Application32.exe

[...]

1. Switch to the process context:

kd> .process /r /p fffffadfe751d040
Implicit process is now fffffadf`e751d040
Loading User Symbols

Stacks traces are 64-bit:

kd> !process fffffadfe751d040
PROCESS fffffadfe751d040
    SessionId: 0  Cid: 0bcc    Peb: 7efdf000  ParentCid: 0abc
    DirBase: 18861000  ObjectTable: fffffa8001ecbc30  HandleCount: 326.
    Image: Application32.exe
    VadRoot fffffadfe7550ae0 Vads 160 Clone 0 Private 1616. Modified 1675. Locked 0.
    DeviceMap fffffa800210e600
    Token                             fffffa80028ef060
    ElapsedTime                       21:57:59.125
    UserTime                          00:00:00.718
    KernelTime                        00:00:00.953
    QuotaPoolUsage[PagedPool]         185704
    QuotaPoolUsage[NonPagedPool]      20080
    Working Set Sizes (now,min,max)  (3021, 50, 345) (12084KB, 200KB, 1380KB)
    PeakWorkingSetSize                3696
    VirtualSize                       93 Mb
    PeakVirtualSize                   104 Mb
    PageFaultCount                    12097
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      2051

THREAD fffffadfe664e040  Cid 0bcc.0bdc  Teb: 000000007efdb000 Win32Thread: fffff97ff4898bd0 WAIT: (Unknown) UserMode Non-Alertable
    fffffadfe73bac40  SynchronizationEvent
    fffffadfe6b69790  SynchronizationEvent
Not impersonating
DeviceMap                 fffffa800210e600
Owning Process            fffffadfe751d040       Image:         Application32.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      4153935        Ticks: 912354 (0:03:57:35.531)
Context Switch Count      8088                 LargeStack
UserTime                  00:00:00.343
KernelTime                00:00:00.593
Win32 Start Address Application32 (0x00000000004077ec)
Start Address 0x0000000077d59620
Stack Init fffffadfdede7e00 Current fffffadfdede7250
Base fffffadfdede8000 Limit fffffadfdede2000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
Kernel stack not resident.
Child-SP          RetAddr           Call Site
fffffadf`dede7290 fffff800`0103b0a3 nt!KiSwapContext+0x85
fffffadf`dede7410 fffff800`0103af8a nt!KiSwapThread+0xc3
fffffadf`dede7450 fffff800`012b9958 nt!KeWaitForMultipleObjects+0x5ec
fffffadf`dede74f0 fffff800`012e63ec nt!ObpWaitForMultipleObjects+0x325
fffffadf`dede79b0 fffff800`0104113d nt!NtWaitForMultipleObjects32+0xcc
fffffadf`dede7c00 00000000`78b83d44 nt!KiSystemServiceCopyEnd+0x3 (TrapFrame @ fffffadf`dede7c70)
00000000`0012edc8 00000000`6b006a5a wow64cpu!WaitForMultipleObjects32+0x3a
00000000`0012ee70 00000000`6b005e0d wow64!RunCpuSimulation+0xa
00000000`0012eea0 00000000`77ed8030 wow64!Wow64LdrpInitialize+0x2ed
00000000`0012f6d0 00000000`77ed582f ntdll!LdrpInitializeProcess+0x1538
00000000`0012f9d0 00000000`77ef30a5 ntdll!LdrpInitialize+0x18f
00000000`0012fab0 00000000`77d59620 ntdll!KiUserApcDispatcher+0x15 (TrapFrame @ 00000000`0012fe18)
[...]

2. Load WOW64 extension

kd> .load wow64exts

3. Set the current thread and switch to x86 context:

kd> .thread /w fffffadfe664e040
Implicit thread is now fffffadf`e664e040
x86 context set

4. Sometimes reloading symbols is necessary:

kd:x86> .reload
Loading Kernel Symbols
Loading User Symbols
Loading unloaded module list
Loading Wow64 Symbols

5. Now we can get our stack trace (it is a bit rough because Application32.exe symbols were not available)

kd:x86> kv 100
ChildEBP          RetAddr           Args to Child                                        
002cfd94 7d4e286c 00000002 002cfde0 00000001 ntdll_7d600000!NtWaitForMultipleObjects+0x15 (FPO: [5,0,0])
002cfe3c 7d94d299 00000002 002cfe64 00000000 kernel32!WaitForMultipleObjectsEx+0x11a (FPO: [SEH])
002cfe98 7d94d327 00000001 002d8148 ffffffff USER32!RealMsgWaitForMultipleObjectsEx+0x152 (FPO: [5,13,0])
*** ERROR: Module load completed but symbols could not be loaded for Application32.exe
002cfeb4 00408081 00000001 002d8148 00000000 USER32!MsgWaitForMultipleObjects+0x1f (FPO: [5,0,0])
WARNING: Stack unwind information not available. Following frames may be wrong.
002cff00 00407d4b ffffffff 00408b78 004010ee Application32+0x8081
002cff08 00408b78 004010ee 004352e0 004352e0 Application32+0x7d4b
002cff0c 004010ee 004352e0 004352e0 0042f004 Application32+0x8b78
00408b78 90909090 90c3c033 90909090 90909090 Application32+0x10ee
00408b7c 90c3c033 90909090 90909090 90909090 0x90909090
00408b80 90909090 90909090 90909090 433aa0a1 0x90c3c033
[...]

6. We can also access raw stack trace if we need to see 32-bit execution residue and reconstruct partial stack traces:  

kd:x86> !teb
Wow64 TEB32 at 000000007efdd000
[...]
Wow64 TEB at 000000007efdb000
    ExceptionList:        000000007efdd000
    StackBase:            0000000000130000
    StackLimit:           000000000012a000

    SubSystemTib:         0000000000000000
    FiberData:            0000000000001e00
    ArbitraryUserPointer: 0000000000000000
    Self:                 000000007efdb000
    EnvironmentPointer:   0000000000000000
    ClientId:             0000000000000bcc . 0000000000000bdc
    RpcHandle:            0000000000000000
    Tls Storage:          0000000000000000
    PEB Address:          000000007efdf000
    LastErrorValue:       6
    LastStatusValue:      c0000034
    Count Owned Locks:    0
    HardErrorMode:        0

kd:x86> dds 000000000012a000 0000000000130000
[...]

- Dmitry Vostokov @ DumpAnalysis.org -

NULL code pointer, changed environment, hooked functions and execution residue: pattern cooperation

Wednesday, February 4th, 2009

After an upgrade to the new version of a productivity software package one unrelated application started to crash frequently. A crash dump was collected and the following stack trace pointed to a NULL code pointer:

0:000> r
eax=09680104 ebx=0013aefc ecx=0968a710 edx=0cdc0c0c esi=16a19058 edi=00000001
eip=00000000 esp=0013aea8 ebp=0013aeb8 iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00200202
00000000 ??              ???

0:000> k 100
ChildEBP RetAddr 
WARNING: Frame IP not in any known module. Following frames may be wrong.
0013aea4 096e28a0 0×0
0013aeb8 32e688bd dllC!Abort+0×10
0013aec8 32c82395 dllB+0×589e
0013aed8 32865718 dllB+0×18f1
[…]
0013b0c0 314de1ff dllB+0×4c6
0013b154 31293494 dllA!DllGetLCID+0×46d2d
0013b178 312af217 dllA!DllGetClassObject+0×4e896
[…]
0013f3d0 300e8721 dllA!DllGetClassObject+0×69e42
0013f578 300e7f5a application+0xcff5
[…]
0013ffc0 7c816ff7 application+0×51d5
0013fff0 00000000 kernel32!BaseProcessStart+0×23

To see if changed environment somehow affected this application the presence of any DLL hooks was checked. The following  hooked functions were found in user32.dll:

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

Scanning section:    .text
Size: 389095
Range to scan: 7e411000-7e46ffe7
    7e4188a6-7e4188aa  5 bytes - USER32!GetWindowLongW
 [ 6a 08 68 e0 88:e9 55 77 a4 01 ]
    7e418f9c-7e418fa0  5 bytes - USER32!GetSystemMetrics (+0×6f6)
 [ 6a 10 68 00 90:e9 5f 70 b5 01 ]
    7e41945d-7e419461  5 bytes - USER32!GetWindowLongA (+0×4c1)
 [ 6a 10 68 78 9f:e9 f5 60 a2 01 ]
    7e41b6ae-7e41b6b2  5 bytes - USER32!GetClientRect (+0×17a8)
 [ 8b ff 55 8b ec:e9 4d 49 9f 01 ]
    7e41b6d4-7e41b6d8  5 bytes - USER32!GetWindowRect (+0×26)
 [ b8 74 11 00 00:e9 98 30 af 01 ]
    7e41d60d-7e41d611  5 bytes - USER32!SetWindowLongA (+0×6aa)
 [ 8b ff 55 8b ec:e9 ee 29 a5 01 ]
    7e41d62b-7e41d62f  5 bytes - USER32!SetWindowLongW (+0×1e)
 [ 6a 08 68 28 f5:e9 0e 0b b2 01 ]
    7e41fc25-7e41fc29  5 bytes - USER32!CreateWindowExW (+0×738)
 [ 8b ff 55 8b ec:e9 d6 03 b6 01 ]
    7e41ff33-7e41ff37  5 bytes - USER32!CreateWindowExA (+0×30e)
Total bytes compared: 389095(100%)
Number of errors: 52
52 errors : !user32 (7e4188a6-7e42e8d5)

The hooking DLL was found to be from that upgraded package:

0:000> u 7e4188a6
USER32!GetWindowLongW:
7e4188a6 e95577a401      jmp     7fe60000
7e4188ab 41              inc     ecx
7e4188ac 7ee8            jle     USER32!_GetWindowLong+0xda (7e418896)
7e4188ae 0e              push    cs
7e4188af fd              std
7e4188b0 ff              ???
7e4188b1 ff8b4d08e816    dec     dword ptr [ebx+16E8084Dh]
7e4188b7 fc              cld

0:000> u 7fe60000
7fe60000 e9bb62b080      jmp     hookA+0×62c0 (009662c0)
7fe60005 6a08            push    8
7fe60007 68e088417e      push    offset USER32!`string’+0×34 (7e4188e0)
7fe6000c e99c885bfe      jmp     USER32!GetWindowLongW+0×7 (7e4188ad)
7fe60011 0000            add     byte ptr [eax],al
7fe60013 0000            add     byte ptr [eax],al
7fe60015 0000            add     byte ptr [eax],al
7fe60017 0000            add     byte ptr [eax],al

0:000> lmv m hookA
start    end        module name
00960000 00976000   hookA     (no symbols)          
    Loaded symbol image file: hookA.dll
    Image path: C:\Program Files\CompanyA\hookA.dll
    Image name: hookA.dll
    […]
    ProductName:      ProductA
    […]

Execution residue from hookA module was also found on the problem thread raw stack and it looks like real code (not a coincidental symbolic information):

0:000> !teb
TEB at 7ffdf000
    ExceptionList:        0013f02c
    StackBase:            00140000
    StackLimit:           0010c000

    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7ffdf000
    EnvironmentPointer:   00000000
    ClientId:             00000c38 . 00000840
    RpcHandle:            00000000
    Tls Storage:          00163268
    PEB Address:          7ffdb000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0

0:000> dds 0010c000 00140000
0010c000  00000000
0010c004  00000000
0010c008  00000000
[…]
00121f50  0096d7d1*** ERROR: Module load completed but symbols could not be loaded for hookA.dll
 hookA+0xd7d1

00121f54  00009924
00121f58  00121fb4
00121f5c  00000000
00121f60  00121f9c
00121f64  0096d895 hookA+0xd895
00121f68  00121f78
00121f6c  00000000
00121f70  00122008
00121f74  00000000
00121f78  00000000
00121f7c  00000000
00121f80  00000000
00121f84  00121f6c
00121f88  000001fe
00121f8c  001220fc
00121f90  0096ec98 hookA+0xec98
00121f94  00970e48 hookA+0×10e48
00121f98  00121fb4
00121f9c  7e41b6a3 USER32!_GetClientRect+0×6e
00121fa0  00122008
00121fa4  fffffa01
[…]

0:000> u 0096d895
hookA+0xd895:
0096d895 8bc6            mov     eax,esi
0096d897 8b4df0          mov     ecx,dword ptr [ebp-10h]
0096d89a 64890d00000000  mov     dword ptr fs:[0],ecx
0096d8a1 5f              pop     edi
0096d8a2 5e              pop     esi
0096d8a3 5b              pop     ebx
0096d8a4 8be5            mov     esp,ebp
0096d8a6 5d              pop     ebp

0:000> ub 0096d895
hookA+0xd876:
0096d876 8b65e8          mov     esp,dword ptr [ebp-18h]
0096d879 be0d000000      mov     esi,0Dh
0096d87e c745fcffffffff  mov     dword ptr [ebp-4],0FFFFFFFFh
0096d885 eb05            jmp     hookA+0xd88c (0096d88c)
0096d887 be72000000      mov     esi,72h
0096d88c 8d55dc          lea     edx,[ebp-24h]
0096d88f 52              push    edx
0096d890 e8fbfeffff      call    hookA+0xd790 (0096d790)

As was found the upgraded application had special DLL hooks to improve productivity and ease of use of GUI applications. Fortunately it was possible to disable that hook on a per-application basis and application crashes disappeared.

- Dmitry Vostokov @ DumpAnalysis.org -

Debugging Études

Tuesday, February 3rd, 2009

Listening to étude No. 1 in C major written by Frédéric Chopin (Op. 10) an idea came to me about writing 16 debugging études (ISBN: 978-1906717575). It is surprising that there are many programming études out there but there are no debugging ones. Stay tuned and be in touch with this blog.

Draft definition:

Debugging étude is a composition of software with intentional defects (bugs) of considerable difficulty to find and fix, designed to provide practice material to perfect debugging techniques and problem-solving skills.

The idea actually came to me long time ago to create some sort of debugging excersises for training purposes. 

- Dmitry Vostokov @ DumpAnalysis.org -

The Year of Dump Analysis!

Tuesday, February 3rd, 2009

DumpAnalysis.org announces forthcoming 2010 as The Year of Dump Analysis.

Q&A 

Q. Why 2010?

A. Two reasons: 1) To do dump analysis effectively and efficiently an engineer needs some experience in debugging acquired in the previous year of debugging (perhaps after 7 debugging nights, 2009, 0×7D9); 2) 2010 is 0×7DA.

Q. What is the meaning of 7?

A. It is interpreted as Dump Analysis 7 days a week. Like what I do. Or from kernel pool tag perspective it is AD7: Analysis of Dumps 7 days a week. 

Q. What about the year 2011, 2012, 2013? 0×7DB, 0×7DC and 0×7DD?

A. Hmm, sounds like WinDbg commands db, dc and dd

- Dmitry Vostokov @ DumpAnalysis.org -

Windows Debugging book has been published!

Monday, February 2nd, 2009

I very proud to announce that after 3 weeks of final work the book has been released in both paperback and PDF format. In a week or so it should also appear on Amazon and other booksellers around the world. The book information and how to buy it can be found on the portal:

Windows Debugging: Practical Foundations

- Dmitry Vostokov @ DumpAnalysis.org -

TOC for WDPF Book

Thursday, January 29th, 2009

Draft Table of Contents is available for the forthcoming Windows Debugging: Practical Foundations book to be released next week:

Draft Table of Contents

- Dmitry Vostokov @ DumpAnalysis.org -

How to simulate a process hang?

Monday, January 26th, 2009

One question that people often ask is to how to simulate a process hang. One method that I found is to attach WinDbg noninvasively, freeze all threads by executing the following command:

~*n

and then quit by using q command. This leaves an application or a service process in a total hang state.

- Dmitry Vostokov @ DumpAnalysis.org -

Memory leak, spiking threads, wait chain, high critical section contention and module variety: pattern cooperation

Monday, January 26th, 2009

I noticed yesterday that my home Vista computer suddenly became slower than usual so I brought Task Manager, sorted processes by CPU usage and discovered an instance of IE7 with 50% - 60% of CPU consumption. Dumping processes in Vista is easier than ever, so I did the right click on that process and selected Create Dump File menu option. The dump was saved and I killed the process. The size of the dump file was 1.2Gb and that definitely indicated a memory leak. Examining process heap showed large heap segments amounting to 800Mb and therefore pointing to the possible heap leak:

0:000> !heap 0 0
Index   Address  Name      Debugging options enabled
  1:   00370000
    Segment at 00370000 to 00470000 (00100000 bytes committed)
    Segment at 04990000 to 04a90000 (00100000 bytes committed)
    Segment at 063e0000 to 065e0000 (00200000 bytes committed)
    Segment at 08440000 to 08840000 (00400000 bytes committed)
    Segment at 0ce80000 to 0d680000 (00800000 bytes committed)
    Segment at 160b0000 to 17080000 (00fd0000 bytes committed)
    Segment at 19b00000 to 1aad0000 (00fd0000 bytes committed)
    Segment at 1c8c0000 to 1d890000 (00fd0000 bytes committed)
    Segment at 27870000 to 28840000 (00fd0000 bytes committed)
    Segment at 29870000 to 2a840000 (00fd0000 bytes committed)
    Segment at 2d1f0000 to 2e1c0000 (00fd0000 bytes committed)
    Segment at 31fb0000 to 32f80000 (00fd0000 bytes committed)
    Segment at 384c0000 to 39490000 (00fd0000 bytes committed)
    Segment at 3c040000 to 3d010000 (00fd0000 bytes committed)
    Segment at 41cf0000 to 42cc0000 (00fd0000 bytes committed)
    Segment at 43c90000 to 44c60000 (00fd0000 bytes committed)
    Segment at 44c60000 to 45c30000 (00fd0000 bytes committed)
    Segment at 473f0000 to 483c0000 (00fd0000 bytes committed)
    Segment at 4a390000 to 4b360000 (00fd0000 bytes committed)
    Segment at 4b360000 to 4c330000 (00fd0000 bytes committed)
    Segment at 4d300000 to 4e2d0000 (00fd0000 bytes committed)
    Segment at 4e2d0000 to 4f2a0000 (00fd0000 bytes committed)
    Segment at 50480000 to 51450000 (00fd0000 bytes committed)
    Segment at 51450000 to 52420000 (00fd0000 bytes committed)
    Segment at 533f0000 to 543c0000 (00fd0000 bytes committed)
    Segment at 54810000 to 557e0000 (00fd0000 bytes committed)
    Segment at 567b0000 to 57780000 (00fd0000 bytes committed)
    Segment at 57c80000 to 58c50000 (00fc1000 bytes committed)
    Segment at 59c20000 to 5abf0000 (00fc6000 bytes committed)
    Segment at 5b0f0000 to 5c0c0000 (00fc1000 bytes committed)
    Segment at 5c0c0000 to 5d090000 (00fc1000 bytes committed)
    Segment at 5d090000 to 5e060000 (00fc1000 bytes committed)
    Segment at 5f030000 to 60000000 (00fc1000 bytes committed)
    Segment at 60000000 to 60fd0000 (00fc1000 bytes committed)
    Segment at 60fd0000 to 61fa0000 (00fd0000 bytes committed)
    Segment at 61fa0000 to 62f70000 (00e26000 bytes committed)

  2:   00010000
    Segment at 00010000 to 00020000 (00003000 bytes committed)
  3:   00d80000
    Segment at 00d80000 to 00d90000 (00010000 bytes committed)
    Segment at 00050000 to 00150000 (00014000 bytes committed)
  4:   00190000
    Segment at 00190000 to 001a0000 (00010000 bytes committed)
    Segment at 00d90000 to 00e90000 (00100000 bytes committed)
    Segment at 0a430000 to 0a630000 (00200000 bytes committed)
    Segment at 0d8d0000 to 0dcd0000 (00400000 bytes committed)
    Segment at 0ecc0000 to 0f4c0000 (00800000 bytes committed)
    Segment at 18690000 to 19660000 (00fd0000 bytes committed)
    Segment at 24fe0000 to 25fb0000 (00fd0000 bytes committed)
    Segment at 2bf40000 to 2cf10000 (00fd0000 bytes committed)
    Segment at 303b0000 to 31380000 (00fd0000 bytes committed)
    Segment at 33370000 to 34340000 (00fd0000 bytes committed)
    Segment at 39490000 to 3a460000 (00fd0000 bytes committed)
    Segment at 40d20000 to 41cf0000 (00fd0000 bytes committed)
    Segment at 483c0000 to 49390000 (00fd0000 bytes committed)
    Segment at 557e0000 to 567b0000 (00452000 bytes committed)
  5:   00330000
    Segment at 00330000 to 00340000 (00010000 bytes committed)
    Segment at 00c10000 to 00d10000 (00100000 bytes committed)
    Segment at 0c910000 to 0cb10000 (00200000 bytes committed)
    Segment at 18280000 to 18680000 (00400000 bytes committed)
    Segment at 2ec20000 to 2f420000 (00800000 bytes committed)
    Segment at 42cc0000 to 43c90000 (00fc7000 bytes committed)
    Segment at 4c330000 to 4d300000 (00d45000 bytes committed)
    Segment at 52420000 to 533f0000 (00d39000 bytes committed)
    Segment at 58c50000 to 59c20000 (00ddc000 bytes committed)
    Segment at 5e060000 to 5f030000 (00dd1000 bytes committed)
  6:   00e90000
    Segment at 00e90000 to 00ea0000 (00010000 bytes committed)
    Segment at 06780000 to 06880000 (00026000 bytes committed)
  7:   00170000
    Segment at 00170000 to 00180000 (00010000 bytes committed)
    Segment at 06880000 to 06980000 (00026000 bytes committed)
  8:   01bf0000
    Segment at 01bf0000 to 01c00000 (00010000 bytes committed)
    Segment at 03bb0000 to 03cb0000 (00100000 bytes committed)
    Segment at 0e610000 to 0e810000 (00200000 bytes committed)
  9:   00bf0000
    Segment at 00bf0000 to 00c00000 (00001000 bytes committed)
 10:   00b70000
    Segment at 00b70000 to 00b80000 (00003000 bytes committed)
 11:   01b60000
    Segment at 01b60000 to 01ba0000 (00040000 bytes committed)
 12:   03650000
    Segment at 03650000 to 03690000 (00009000 bytes committed)
 13:   039c0000
    Segment at 039c0000 to 039d0000 (00008000 bytes committed)
    Segment at 07e30000 to 07f30000 (00012000 bytes committed)
 14:   00b20000
    Segment at 00b20000 to 00b30000 (00003000 bytes committed)
 15:   01b00000
    Segment at 01b00000 to 01b40000 (00040000 bytes committed)
    Segment at 22b80000 to 22c80000 (00032000 bytes committed)
 16:   00b30000
    Segment at 00b30000 to 00b70000 (00040000 bytes committed)
    Segment at 08f00000 to 09000000 (00100000 bytes committed)
    Segment at 376f0000 to 378f0000 (000e3000 bytes committed)
 17:   03700000
    Segment at 03700000 to 03740000 (00040000 bytes committed)
 18:   03a70000
    Segment at 03a70000 to 03ab0000 (00040000 bytes committed)
 19:   00be0000
    Segment at 00be0000 to 00bf0000 (00010000 bytes committed)
    Segment at 0a630000 to 0a730000 (000a8000 bytes committed)
 20:   04df0000
    Segment at 04df0000 to 04ef0000 (00100000 bytes committed)
 21:   044d0000
    Segment at 044d0000 to 044e0000 (00010000 bytes committed)
    Segment at 04390000 to 04490000 (00028000 bytes committed)
 22:   04730000
    Segment at 04730000 to 04740000 (00010000 bytes committed)
    Segment at 04620000 to 04720000 (00100000 bytes committed)
    Segment at 23fb0000 to 241b0000 (001f6000 bytes committed)
 23:   055e0000
    Segment at 055e0000 to 056e0000 (00100000 bytes committed)
 24:   05ce0000
    Segment at 05ce0000 to 05cf0000 (00010000 bytes committed)
    Segment at 06bb0000 to 06cb0000 (00012000 bytes committed)
 25:   05e20000
    Segment at 05e20000 to 05e60000 (00020000 bytes committed)
 26:   04860000
    Segment at 04860000 to 04870000 (00010000 bytes committed)
    Segment at 0df60000 to 0e060000 (00024000 bytes committed)
 27:   04dc0000
    Segment at 04dc0000 to 04dd0000 (00010000 bytes committed)
    Segment at 062e0000 to 063e0000 (00100000 bytes committed)
    Segment at 26d70000 to 26f70000 (001eb000 bytes committed)
 28:   06aa0000
    Segment at 06aa0000 to 06ab0000 (00010000 bytes committed)
    Segment at 06980000 to 06a80000 (00100000 bytes committed)
    Segment at 1ede0000 to 1efe0000 (00200000 bytes committed)
    Segment at 1efe0000 to 1f3e0000 (00322000 bytes committed)
    Segment at 1f3e0000 to 1fbe0000 (00800000 bytes committed)
    Segment at 205e0000 to 215b0000 (001c7000 bytes committed)
 29:   05420000
    Segment at 05420000 to 05430000 (00010000 bytes committed)
    Segment at 06ab0000 to 06bb0000 (00053000 bytes committed)
 30:   05980000
    Segment at 05980000 to 05990000 (00010000 bytes committed)
    Segment at 17d90000 to 17e90000 (00012000 bytes committed)
 31:   07c20000
    Segment at 07c20000 to 07c60000 (00040000 bytes committed)
    Segment at 08cc0000 to 08dc0000 (00100000 bytes committed)
    Segment at 1fbe0000 to 1fde0000 (001fd000 bytes committed)
    Segment at 241b0000 to 245b0000 (003fa000 bytes committed)
    Segment at 2a840000 to 2b040000 (0007c000 bytes committed)
 32:   07be0000
    Segment at 07be0000 to 07c20000 (0003a000 bytes committed)
    Segment at 17900000 to 17a00000 (000fd000 bytes committed)
    Segment at 3b2b0000 to 3b4b0000 (001fe000 bytes committed)
    Segment at 45c30000 to 46030000 (00289000 bytes committed)
 33:   07df0000
    Segment at 07df0000 to 07e30000 (0003a000 bytes committed)
    Segment at 22810000 to 22910000 (0001c000 bytes committed)
 34:   08000000
    Segment at 08000000 to 08040000 (00001000 bytes committed)
 35:   07da0000
    Segment at 07da0000 to 07de0000 (00001000 bytes committed)
 36:   04b60000
    Segment at 04b60000 to 04b70000 (00002000 bytes committed)
 37:   08990000
    Segment at 08990000 to 089a0000 (00010000 bytes committed)
    Segment at 06cb0000 to 06db0000 (00024000 bytes committed)
 38:   051f0000
    Segment at 051f0000 to 05200000 (00010000 bytes committed)
    Segment at 050c0000 to 051c0000 (00100000 bytes committed)
    Segment at 0c110000 to 0c310000 (00200000 bytes committed)
    Segment at 0c310000 to 0c710000 (003f6000 bytes committed)
    Segment at 1bd00000 to 1c500000 (00529000 bytes committed)
    Segment at 216c0000 to 22690000 (00376000 bytes committed)
 39:   0ac10000
    Segment at 0ac10000 to 0ac20000 (00010000 bytes committed)
    Segment at 0aa80000 to 0ab80000 (000c4000 bytes committed)
 40:   12ed0000
    Segment at 12ed0000 to 12ee0000 (00010000 bytes committed)
    Segment at 199e0000 to 19ae0000 (00022000 bytes committed)
 41:   15450000
    Segment at 15450000 to 15490000 (00001000 bytes committed)
 42:   17ad0000
    Segment at 17ad0000 to 17b10000 (00001000 bytes committed)
 43:   1b2f0000
    Segment at 1b2f0000 to 1b300000 (00010000 bytes committed)
    Segment at 1ad30000 to 1ae30000 (0002c000 bytes committed)
 44:   232b0000
    Segment at 232b0000 to 232f0000 (00015000 bytes committed)
 45:   21680000
    Segment at 21680000 to 216c0000 (00001000 bytes committed)
 46:   23490000
    Segment at 23490000 to 234d0000 (00001000 bytes committed)
 47:   23670000
    Segment at 23670000 to 236b0000 (00001000 bytes committed)
 48:   17ed0000
    Segment at 17ed0000 to 17f10000 (00001000 bytes committed)
 49:   247f0000
    Segment at 247f0000 to 24830000 (00040000 bytes committed)
 50:   28c40000
    Segment at 28c40000 to 28c80000 (00040000 bytes committed)
 51:   2ffd0000
    Segment at 2ffd0000 to 2ffe0000 (00006000 bytes committed)
 52:   376b0000
    Segment at 376b0000 to 376f0000 (00040000 bytes committed)
 53:   2ff90000
    Segment at 2ff90000 to 2ffd0000 (00040000 bytes committed)
 54:   26260000
    Segment at 26260000 to 262a0000 (00040000 bytes committed)
 55:   3a530000
    Segment at 3a530000 to 3a570000 (00040000 bytes committed)

However I concentrated on CPU spike and !runaway WinDbg command showed the following distribution of thread user mode times:

0:000> !runaway
 User Mode Time
  Thread       Time
 117:10a0      0 days 3:09:13.643
  13:ca4       0 days 2:18:41.311

  61:16c4      0 days 0:25:46.515
  33:1690      0 days 0:25:25.954
   4:fb0       0 days 0:22:20.797
  29:840       0 days 0:21:25.385
  23:1614      0 days 0:21:08.194
  77:3e0       0 days 0:18:57.434
  45:11f4      0 days 0:17:13.647
  71:1314      0 days 0:17:10.667
  31:1198      0 days 0:16:48.374
  39:156c      0 days 0:16:40.980
  59:d1c       0 days 0:16:37.610
 115:3e8       0 days 0:16:32.384
  57:170c      0 days 0:16:30.746
  47:1364      0 days 0:16:18.360
  84:12a8      0 days 0:15:56.145
 112:a10       0 days 0:15:52.089
 106:1374      0 days 0:15:51.652
  89:b58       0 days 0:15:47.768
 125:115c      0 days 0:15:41.122
 101:1100      0 days 0:15:30.748
 104:1294      0 days 0:15:16.147
  99:d00       0 days 0:15:15.008
  96:9b4       0 days 0:15:13.604
 123:1624      0 days 0:15:12.247
  86:1444      0 days 0:15:11.654
 131:1728      0 days 0:14:35.914
 135:100c      0 days 0:14:16.414
 133:1530      0 days 0:14:04.963
 137:a30       0 days 0:13:41.360
 139:dd8       0 days 0:13:40.674
 142:1098      0 days 0:12:51.284
   0:efc       0 days 0:02:43.005
   1:f44       0 days 0:01:34.536
  19:8d0       0 days 0:00:42.557
  98:54c       0 days 0:00:28.282
 114:138c      0 days 0:00:26.598
  83:1060      0 days 0:00:22.354
  88:17ec      0 days 0:00:22.027
 103:da8       0 days 0:00:20.404
 141:15c8      0 days 0:00:19.843
  10:b14       0 days 0:00:12.526
   8:5b8       0 days 0:00:02.246
  21:cfc       0 days 0:00:00.795
  12:10c       0 days 0:00:00.561
  11:8d4       0 days 0:00:00.312
  65:b0c       0 days 0:00:00.202
  22:ae8       0 days 0:00:00.187
  17:744       0 days 0:00:00.124
  28:168c      0 days 0:00:00.093
   6:5a8       0 days 0:00:00.046
   2:f90       0 days 0:00:00.031
 130:fa4       0 days 0:00:00.015
 113:17c4      0 days 0:00:00.015
  76:1a4       0 days 0:00:00.015
  70:10a8      0 days 0:00:00.015
  32:df0       0 days 0:00:00.015
  18:ee0       0 days 0:00:00.015
   7:3f4       0 days 0:00:00.015
 148:11cc      0 days 0:00:00.000
 147:132c      0 days 0:00:00.000
 146:1458      0 days 0:00:00.000
 145:133c      0 days 0:00:00.000
 144:1268      0 days 0:00:00.000
 143:838       0 days 0:00:00.000
 140:1168      0 days 0:00:00.000
 138:f48       0 days 0:00:00.000
 136:1f0       0 days 0:00:00.000
 134:17ac      0 days 0:00:00.000
 132:119c      0 days 0:00:00.000
 129:fc4       0 days 0:00:00.000
 128:bd8       0 days 0:00:00.000
 127:1528      0 days 0:00:00.000
 126:1058      0 days 0:00:00.000
 124:16a4      0 days 0:00:00.000
 122:1518      0 days 0:00:00.000
 121:7c        0 days 0:00:00.000
 120:103c      0 days 0:00:00.000
 119:a2c       0 days 0:00:00.000
 118:1524      0 days 0:00:00.000
 116:1240      0 days 0:00:00.000
 111:1248      0 days 0:00:00.000
 110:de8       0 days 0:00:00.000
 109:dc8       0 days 0:00:00.000
 108:17e8      0 days 0:00:00.000
 107:994       0 days 0:00:00.000
 105:162c      0 days 0:00:00.000
 102:112c      0 days 0:00:00.000
 100:1764      0 days 0:00:00.000
  97:1548      0 days 0:00:00.000
  95:1334      0 days 0:00:00.000
  94:1024      0 days 0:00:00.000
  93:1170      0 days 0:00:00.000
  92:12f0      0 days 0:00:00.000
  91:12d4      0 days 0:00:00.000
  90:1264      0 days 0:00:00.000
  87:12d8      0 days 0:00:00.000
  85:153c      0 days 0:00:00.000
  82:14c4      0 days 0:00:00.000
  81:834       0 days 0:00:00.000
  80:17f4      0 days 0:00:00.000
  79:1784      0 days 0:00:00.000
  78:530       0 days 0:00:00.000
  75:1320      0 days 0:00:00.000
  74:15fc      0 days 0:00:00.000
  73:16e4      0 days 0:00:00.000
  72:17b0      0 days 0:00:00.000
  69:af0       0 days 0:00:00.000
  68:83c       0 days 0:00:00.000
  67:b78       0 days 0:00:00.000
  66:cc4       0 days 0:00:00.000
  64:14fc      0 days 0:00:00.000
  63:14dc      0 days 0:00:00.000
  62:16b0      0 days 0:00:00.000
  60:1130      0 days 0:00:00.000
  58:1504      0 days 0:00:00.000
  56:1160      0 days 0:00:00.000
  55:16c0      0 days 0:00:00.000
  54:bfc       0 days 0:00:00.000
  53:f70       0 days 0:00:00.000
  52:1178      0 days 0:00:00.000
  51:1448      0 days 0:00:00.000
  50:15e8      0 days 0:00:00.000
  49:1410      0 days 0:00:00.000
  48:10c0      0 days 0:00:00.000
  46:14e4      0 days 0:00:00.000
  44:1150      0 days 0:00:00.000
  43:1454      0 days 0:00:00.000
  42:131c      0 days 0:00:00.000
  41:8cc       0 days 0:00:00.000
  40:17bc      0 days 0:00:00.000
  38:17c0      0 days 0:00:00.000
  37:15a4      0 days 0:00:00.000
  36:1048      0 days 0:00:00.000
  35:143c      0 days 0:00:00.000
  34:1384      0 days 0:00:00.000
  30:fa0       0 days 0:00:00.000
  27:1688      0 days 0:00:00.000
  26:1684      0 days 0:00:00.000
  25:1680      0 days 0:00:00.000
  24:161c      0 days 0:00:00.000
  20:500       0 days 0:00:00.000
  16:1a0       0 days 0:00:00.000
  15:a18       0 days 0:00:00.000
  14:c44       0 days 0:00:00.000
   9:6c4       0 days 0:00:00.000
   5:ec8       0 days 0:00:00.000
   3:fa8       0 days 0:00:00.000

Threads 117 and 13 were waiting for a critical section 6e1876c4:

0:000> ~117kv
ChildEBP RetAddr  Args to Child             
35f0e468 77009254 76ff33b4 00000520 00000000 ntdll!KiFastSystemCallRet
35f0e46c 76ff33b4 00000520 00000000 00000000 ntdll!ZwWaitForSingleObject+0xc
35f0e4d0 76ff323c 00000000 00000000 00000000 ntdll!RtlpWaitOnCriticalSection+0x155
35f0e4f8 6e16ac32 6e1876c4 00071370 35f0e59c ntdll!RtlEnterCriticalSection+0x152
35f0e510 6e16b4cc 6e16e2f1 00000000 35f0e59c AcRedir!NS_RedirectRegistry::RedirectorRegistry::LookupKOECache+0×22
35f0e524 6e16bb90 00071370 00000000 00000000 AcRedir!NS_RedirectRegistry::RedirectorRegistry::PreChecks+0xd3
35f0e544 6e16bbce 00071370 00000000 00000008 AcRedir!NS_RedirectRegistry::RedirectorRegistry::InitializeMergeW+0×1a
35f0e574 6e16e327 00071370 00000002 00000002 AcRedir!NS_RedirectRegistry::RedirectorRegistry::InitializeEnumeration+0×26

*** ERROR: Symbol file could not be found.  Defaulted to export symbols for PDFCreator_Toolbar.dll -
35f0e620 05729772 00071370 00000002 35f0e690 AcRedir!NS_RedirectRegistry::APIHook_RegEnumValueA+0×36
WARNING: Stack unwind information not available. Following frames may be wrong.
35f0e6a4 76b60528 c02193db 00000128 00000000 PDFCreator_Toolbar!DllUnregisterServer+0×3b7ce
35f0e6dc 73207be1 000319f8 00000128 00030001 user32!DefWindowProcW+0×86
76b60528 90909090 fffffffe 00000000 ffffffd0 comctl32!ToolbarWndProc+0×14f7
76b60528 00000000 fffffffe 00000000 ffffffd0 0×90909090

0:000> ~13kv
ChildEBP RetAddr  Args to Child             
0c90e5ec 77009254 76ff33b4 00000520 00000000 ntdll!KiFastSystemCallRet
0c90e5f0 76ff33b4 00000520 00000000 00000000 ntdll!ZwWaitForSingleObject+0xc
0c90e654 76ff323c 00000000 00000000 00000000 ntdll!RtlpWaitOnCriticalSection+0x155
0c90e67c 6e16ac32 6e1876c4 00071348 0c90e720 ntdll!RtlEnterCriticalSection+0x152
0c90e694 6e16b4cc 6e16e2f1 00000000 0c90e720 AcRedir!NS_RedirectRegistry::RedirectorRegistry::LookupKOECache+0×22
0c90e6a8 6e16bb90 00071348 00000000 00000000 AcRedir!NS_RedirectRegistry::RedirectorRegistry::PreChecks+0xd3
0c90e6c8 6e16bbce 00071348 00000000 00000008 AcRedir!NS_RedirectRegistry::RedirectorRegistry::InitializeMergeW+0×1a
0c90e6f8 6e16e327 00071348 0000000c 00000002 AcRedir!NS_RedirectRegistry::RedirectorRegistry::InitializeEnumeration+0×26
0c90e7a4 05729772 00071348 0000000c 0c90e814 AcRedir!NS_RedirectRegistry::APIHook_RegEnumValueA+0×36

WARNING: Stack unwind information not available. Following frames may be wrong.
0c90e858 76b60528 73207be1 000205e2 00000128 PDFCreator_Toolbar!DllUnregisterServer+0×3b7ce
0c90e8d4 76b5f8d2 626f6441 44502065 00200046 user32!DefWindowProcW+0×86
0c90e978 76b60817 0041fecc 73207ae0 000205e2 user32!InternalCallWinProc+0×23
00030ad4 0031002e 00300038 00350036 006e005f user32!DispatchClientMessage+0xda
00030ad4 00000000 00300038 00350036 006e005f 0×31002e

Examining critical section locks showed this section to be the only one locked and having high contention:

0:000> !locks

CritSec AcRedir!NS_RedirectRegistry::RedirectorRegistry::ClassLock+0 at 6e1876c4
WaiterWoken        No
LockCount          32
RecursionCount     1
OwningThread       d1c
EntryCount         0
ContentionCount    c74ad4
*** Locked

Scanned 22054 critical sections

There were 32 threads waiting on it. Examining its owning thread d1c showed similar stack trace pattern:

0:000> ~~[d1c]kv
ChildEBP RetAddr  Args to Child             
269ae72c 6e16f1da 269ae808 31f4a7e8 269ae75c AcRedir!NS_RedirectRegistry::OwnedRegistryKeyPair::Match+0×14
269ae73c 6e16f40c 269ae7ec 269ae808 269ae808 AcRedir!NS_RedirectRegistry::MergedRegistryKey::Match+0×22
269ae75c 6e16bc11 269ae7ec 269ae808 269ae784 AcRedir!NS_RedirectRegistry::MergedRegistryKeyList::FindItem+0×25
269ae790 6e16e327 00c211b0 00000008 00000002 AcRedir!NS_RedirectRegistry::RedirectorRegistry::InitializeEnumeration+0×69
269ae83c 05729772 000714a4 00000008 269ae8ac AcRedir!NS_RedirectRegistry::APIHook_RegEnumValueA+0×36

WARNING: Stack unwind information not available. Following frames may be wrong.
269ae8f0 76b60528 73207be1 00050cf8 00000128 PDFCreator_Toolbar!DllUnregisterServer+0×3b7ce
269ae96c 76b5f8d2 00000001 00070598 00040582 user32!DefWindowProcW+0×86
269aea10 76b60817 0041fecc 73207ae0 00050cf8 user32!InternalCallWinProc+0×23
00030ad4 0031002e 00300038 00350036 006e005f user32!DispatchClientMessage+0xda
00030ad4 00000000 00300038 00350036 006e005f 0×31002e

Two components immediately came to suspicion, AcRedir.dll and PDFCreator_Toolbar.dll:

0:000> lmv m AcRedir
start    end        module name
6e150000 6e18e000   AcRedir    (pdb symbols)          c:\mss\AcRedir.pdb\923AF38F594246C99580DC1CFB4B3AE02\AcRedir.pdb
    Loaded symbol image file: AcRedir.dll
    Image path: C:\Windows\AppPatch\AcRedir.dll
    Image name: AcRedir.dll
    Timestamp:        Sat Jan 19 07:26:39 2008 (4791A62F)
    CheckSum:         0003F278
    ImageSize:        0003E000
    File version:     6.0.6001.18000
    Product version:  6.0.6001.18000
    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:     Microsoft® Windows® Operating System
    OriginalFilename: Microsoft® Windows® Operating System
    ProductVersion:   6.0.6001.18000
    FileVersion:      6.0.6001.18000 (longhorn_rtm.080118-1840)
    FileDescription:  Windows Compatibility DLL
    LegalCopyright:   © Microsoft Corporation. All rights reserved.

0:000> lmv m PDFCreator_Toolbar
start    end        module name
056e0000 057bb000   PDFCreator_Toolbar   (export symbols)       PDFCreator_Toolbar.dll
    Loaded symbol image file: PDFCreator_Toolbar.dll
    Image path: C:\Program Files\PDFCreator Toolbar\v3.3.0.1\PDFCreator_Toolbar.dll
    Image name: PDFCreator_Toolbar.dll
    Timestamp:        Sat Aug 09 08:53:38 2008 (489D4D02)
    CheckSum:         000AA334
    ImageSize:        000DB000
    File version:     3.3.0.1
    Product version:  3.3.0.1
    File flags:       0 (Mask 3F)
    File OS:          4 Unknown Win32
    File type:        2.0 Dll
    File date:        00000000.00000000
    Translations:     0409.04b0
    ProductName:      PDFCreator Toolbar
    InternalName:     PDFCreator Toolbar
    OriginalFilename: Toolbar.dll
    ProductVersion:   3,3,0,1
    FileVersion:      3,3,0,1
    FileDescription:  PDFCreator Toolbar
    LegalCopyright:   Copyright 2006

Then I decided to examine some heap blocks from leaked segments and found the prolifiration of UNICODE string fragments containing “PDFCreator Toolbar”:

0:000> dc 567b0000 l3000
[...]
567b21a0  00000001 00000008 00000040 00650054  ............T.e.
567b21b0  0070006d 00610044 00610074 00730000  m.p.D.a.t.a...s.
567b21c0  00740069 006f0069 0000006e 00000072  i.t.i.o.n...r...
567b21d0  00000068 005c0067 00440050 00430046  h…g.\.P.D.F.C.
567b21e0  00650072 00740061 0072006f 00540020  r.e.a.t.o.r. .T.
567b21f0  006f006f 0062006c 00720061 002d0000  o.o.l.b.a.r…-.

567b2200  00300031 00300030 00300000 00420025  1.0.0.0…0.%.B.
567b2210  00250030 00310044 00380025 00250031  0.%.D.1.%.8.1.%.
567b2220  00310044 00380025 00000031 00000000  D.1.%.8.1…….
567b2230  52332e04 88000000 00000001 00000013  ..3R…………
567b2240  00000040 00690044 00450064 0061006e  @…D.i.d.E.n.a.
567b2250  006c0062 00410065 00740075 0053006f  b.l.e.A.u.t.o.S.
567b2260  00610065 00630072 00000068 005c0067  e.a.r.c.h…g.\.
567b2270  00440050 00430046 00650072 00740061  P.D.F.C.r.e.a.t.
567b2280  0072006f 00540020 006f006f 0062006c  o.r. .T.o.o.l.b.
567b2290  00720061 002d0000 00300031 00300030  a.r…-.1.0.0.0.

567b22a0  00300000 00420025 00250030 00310044  ..0.%.B.0.%.D.1.
567b22b0  00380025 00250031 00310044 00380025  %.8.1.%.D.1.%.8.
567b22c0  00000031 00000000 52332e1b 88000000  1………3R….
567b22d0  00000001 00000005 00000040 004c0053  …………S.L.
567b22e0  00730069 00000074 00450052 0070005c  i.s.t…R.E.\.p.
567b22f0  00660064 006f0066 00670072 002e0065  d.f.f.o.r.g.e…
567b2300  0072006f 005c0067 00440050 00430046  o.r.g.\.P.D.F.C.
567b2310  00650072 00740061 0072006f 00540020  r.e.a.t.o.r. .T.
567b2320  006f006f 0062006c 00720061 00300000  o.o.l.b.a.r…0.

567b2330  00420025 00250042 00300044 00420025  %.B.B.%.D.0.%.B.
567b2340  00250030 00310044 00380025 00250031  0.%.D.1.%.8.1.%.
567b2350  00310044 00380025 00000031 00000000  D.1.%.8.1…….
567b2360  52332e2e 88000000 00000001 00000005  ..3R…………

Because AcRedir code was called from PDFCreator Toolbar component the final decision was to uninstall PDFCreator Toolbar. Before I quit the debugger I dumped the list of modules and was astonished at the module variety:

0:000> lm
start    end        module name
00850000 008eb000   iexplore   (pdb symbols)         
05430000 054ab000   ssv        (deferred)            
056e0000 057bb000   PDFCreator_Toolbar   (export symbols)
0a7f0000 0aa73000   igdumd32   (deferred)            
10000000 100a4000   swg        (deferred)            
16080000 160a5000   mdnsNSP    (deferred)            
28f90000 28f9a000   icalogon   (deferred)            
29330000 29337000   PScript    (deferred)            
29440000 29462000   ctxmui     (deferred)            
29470000 29476000   TcpPServ   (deferred)            
29480000 29492000   CgpCore    (deferred)            
295a0000 295b0000   confmgr    (deferred)            
295b0000 295b7000   logging    (deferred)            
296c0000 296c7000   icafile    (deferred)            
296d0000 296d6000   cgpcfg     (deferred)            
296e0000 296e5000   ctxmuiUI   (deferred)            
2bd20000 2bd8e000   Wfica      (deferred)            
30000000 303ae000   Flash9e    (export symbols)
63f00000 63f0c000   mscorie    (deferred)            
655e0000 65639000   rpbrowserrecordplugin   (deferred)            
692a0000 69a66000   wmploc     (deferred)            
69a70000 6a4a0000   wmp        (deferred)            
6b220000 6b2e3000   VGX        (deferred)            
6b2f0000 6b3bc000   d3dim700   (deferred)            
6b450000 6b4d3000   AdobeUpdater   (deferred)            
6b4e0000 6b7de000   agcore     (deferred)            
6b7e0000 6ba63000   fastsearch_219B3E1547538286   (deferred)            
6ba70000 6be17000   GoogleToolbarDynamic_F423308312A7B033   (export symbols)   
6be20000 6be89000   vbscript   (deferred)            
6bf90000 6c302000   mshtml     (export symbols)   
6c320000 6c36a000   ntshrui    (deferred)            
6c3d0000 6c447000   mshtmled   (deferred)            
6c4d0000 6c527000   dxtmsft    (deferred)            
6c590000 6c60d000   jscript    (pdb symbols)         
6c610000 6c649000   dxtrans    (pdb symbols)         
6c770000 6c7e0000   dsound     (deferred)            
6c810000 6c839000   msls31     (deferred)            
6ca50000 6ca6b000   cryptnet   (deferred)            
6ca90000 6cada000   rasapi32   (deferred)            
6cca0000 6ccb4000   rasman     (deferred)            
6cd40000 6cd71000   tapi32     (deferred)            
6d0b0000 6d0fc000   Wpc        (deferred)            
6d350000 6d410000   npctrl     (deferred)            
6d450000 6d482000   iepeers    (deferred)            
6d4d0000 6d530000   ieapfltr   (deferred)            
6d5b0000 6d603000   AcroIEFavClient   (deferred)            
6d6b0000 6d795000   ddraw      (deferred)            
6d7a0000 6d818000   AcSpecfc   (deferred)            
6d820000 6d82e000   pngfilt    (deferred)            
6d830000 6d892000   mscms      (deferred)            
6dbc0000 6dc5b000   msvcr80    (deferred)            
6dc60000 6dce7000   msvcp80    (deferred)            
6dd70000 6ddf8000   AcLayers   (deferred)            
6de00000 6de0a000   ddrawex    (deferred)            
6de60000 6de83000   msvfw32    (deferred)            
6dfb0000 6dfc1000   AcroIEHelperShim   (deferred)            
6dff0000 6e036000   GoogleToolbar   (deferred)            
6e060000 6e086000   dssenh     (deferred)            
6e090000 6e0f0000   tiptsf     (deferred)            
6e0f0000 6e11f000   ieui       (pdb symbols)         
6e130000 6e140000   AcroIEHelper   (deferred)            
6e150000 6e18e000   AcRedir    (pdb symbols)         
6e570000 6e57b000   msimtf     (deferred)            
6e580000 6e58f000   davclnt    (deferred)            
6e590000 6e5a3000   ntlanman   (deferred)            
6e610000 6e618000   drprov     (deferred)            
6e620000 6e630000   iebrshim   (deferred)            
6e650000 6e680000   mlang      (deferred)            
6f7b0000 6f7b8000   dispex     (deferred)            
6f8a0000 6f8ab000   cscapi     (deferred)            
6fa70000 6fb4c000   dbghelp    (deferred)            
6fe40000 6fe73000   msrating   (deferred)            
6ff00000 6ff3a000   sqlite     (deferred)            
70530000 70afe000   ieframe    (pdb symbols)      
71260000 71462000   msi        (deferred)            
717c0000 717d2000   pnrpnsp    (deferred)            
71870000 71877000   wsock32    (deferred)            
718a0000 718a7000   msiltcfg   (pdb symbols)      
71920000 71973000   actxprxy   (deferred)            
71980000 7198c000   wshbth     (deferred)            
71990000 71998000   winrnr     (deferred)            
719e0000 71b06000   msxml3     (deferred)            
71b10000 71b1f000   NapiNSP    (deferred)            
71b20000 71b29000   linkinfo   (deferred)            
71c70000 71c76000   SensApi    (deferred)            
71d10000 71e56000   browseui   (deferred)            
71ee0000 71fe7000   shdocvw    (deferred)            
72100000 72109000   snmpapi    (deferred)            
72580000 725c2000   winspool   (deferred)            
725d0000 725d6000   rasadhlp   (deferred)            
72610000 72615000   sfc        (deferred)            
72620000 7262c000   dwmapi     (deferred)            
72640000 72676000   mfplat     (deferred)            
72850000 72857000   midimap    (deferred)            
72860000 72874000   msacm32_72860000   (deferred)            
72880000 72933000   WindowsCodecs   (deferred)            
72940000 729a6000   AudioEng   (deferred)            
729b0000 729d1000   AudioSes   (deferred)            
729e0000 72a0f000   wdmaud     (pdb symbols)      
72a50000 72a59000   msacm32    (deferred)            
72a60000 72a64000   ksuser     (deferred)            
72a70000 72aa2000   winmm      (pdb symbols)      
72b60000 72b6c000   imgutil    (deferred)            
72b80000 72b8d000   sfc_os     (deferred)            
72b90000 72bae000   shimeng    (deferred)            
72bb0000 72bb6000   dciman32   (deferred)            
72c60000 72c8f000   xmllite    (deferred)            
72c90000 72c9c000   rtutils    (deferred)            
72ed0000 72f66000   FWPUCLNT   (deferred)            
73080000 731ca000   msxml6     (deferred)            
731d0000 731d5000   msimg32    (deferred)            
73200000 73285000   comctl32   (pdb symbols)      
73290000 732ef000   winhttp    (deferred)            
73380000 733b9000   oleacc     (deferred)            
733c0000 733ff000   uxtheme    (deferred)            
73400000 73430000   duser      (deferred)            
73430000 735db000   GdiPlus    (deferred)            
738d0000 7398b000   propsys    (deferred)            
74460000 74474000   atl        (deferred)            
74580000 7471e000   comctl32_74580000   (pdb symbols)
74890000 748b7000   MMDevAPI   (deferred)            
74960000 74975000   cabinet    (deferred)            
74980000 749ad000   wintrust   (deferred)            
74a40000 74a4f000   nlaapi     (deferred)            
74a50000 74a5a000   wtsapi32   (deferred)            
74b10000 74b15000   WSHTCPIP   (deferred)            
74b20000 74b27000   avrt       (deferred)            
74b30000 74b4a000   powrprof   (deferred)            
74b50000 74b71000   ntmarta    (deferred)            
74bb0000 74beb000   rsaenh     (deferred)            
74c20000 74c64000   schannel   (deferred)            
74dd0000 74de5000   gpapi      (deferred)            
74ed0000 74f0b000   mswsock    (pdb symbols)         
74f10000 74f55000   bcrypt     (deferred)            
74f60000 74f95000   ncrypt     (deferred)            
74fb0000 74fd1000   dhcpcsvc6   (deferred)            
74fe0000 74fe7000   winnsi     (deferred)            
74ff0000 75025000   dhcpcsvc   (deferred)            
75030000 75049000   IPHLPAPI   (deferred)            
75050000 75090000   wevtapi    (deferred)            
75090000 750ca000   SLC        (deferred)            
750d0000 751c1000   crypt32    (deferred)            
75200000 75214000   mpr        (deferred)            
75260000 75265000   wship6     (deferred)            
75270000 75278000   version    (deferred)            
75280000 75287000   credssp    (deferred)            
752c0000 752d2000   msasn1     (deferred)            
752e0000 752f1000   samlib     (deferred)            
75300000 7532c000   dnsapi     (deferred)            
75360000 753d5000   netapi32   (deferred)            
755a0000 755ff000   sxs        (deferred)            
75660000 7568c000   apphelp    (deferred)            
756c0000 756d4000   secur32    (deferred)            
756e0000 756fe000   userenv    (deferred)            
75820000 75865000   iertutil   (deferred)            
75870000 76380000   shell32    (deferred)            
76380000 763ca000   Wldap32    (deferred)            
763d0000 76428000   shlwapi    (deferred)            
76430000 764b4000   clbcatq    (deferred)            
764c0000 76588000   msctf      (deferred)            
76590000 765b9000   imagehlp   (deferred)            
765c0000 76682000   rpcrt4     (pdb symbols)        
76690000 76760000   wininet    (pdb symbols)        
76760000 767ab000   gdi32      (deferred)            
767b0000 767dd000   ws2_32     (pdb symbols)        
767e0000 76924000   ole32      (pdb symbols)        
76930000 76aba000   setupapi   (deferred)            
76ac0000 76b33000   comdlg32   (deferred)            
76b40000 76bdd000   user32     (pdb symbols)        
76be0000 76cbb000   kernel32   (pdb symbols)    
76cc0000 76d3d000   usp10      (deferred)            
76d40000 76dea000   msvcrt     (pdb symbols)    
76df0000 76f19000   urlmon     (deferred)            
76f20000 76fad000   oleaut32   (deferred)            
76fb0000 770d7000   ntdll      (pdb symbols)    
770e0000 770e7000   psapi      (deferred)            
770f0000 770f9000   lpk        (deferred)            
77100000 7711e000   imm32      (deferred)            
77120000 77126000   nsi        (deferred)            
77130000 77133000   normaliz   (deferred)            
77140000 77206000   advapi32   (deferred)            
79000000 79046000   mscoree    (deferred)            
7c340000 7c396000   msvcr71    (deferred)            
7c3a0000 7c41b000   msvcp71    (deferred)

Actually, before I quit the debugger, I saved a secured stripped version of the dump file using this command: 

0:000> .dump /mrRFt c:\UserDumps\ie7_pattern_cooperation.dmp

The dump file is available on ftp:

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

Thread times and stack traces are available in it together with module information. However heap data and critical section list was not included in it.

- Dmitry Vostokov @ DumpAnalysis.org -

Forthcoming Windows Debugging via IDA

Friday, January 23rd, 2009

According to Hex Blog IDA v5.4 will be able to do user and kernel local and remote mode debugging on Windows automatically loading PDB files if necessary. I’m now considering to spend a portion of my book author compensation on purchasing a licence for IDA Pro :-)

- Dmitry Vostokov @ DumpAnalysis.org -

Bugtation No.83

Thursday, January 22nd, 2009

“Some” tester, “I believe, has said that true pleasure lies not in the discovery of” a bug, “but in the search for it.”

Lev Nikolayevich Tolstoy,
Anna Karenina

- Dmitry Vostokov @ DumpAnalysis.org -

Next Generation Memory Viewers

Wednesday, January 21st, 2009

DumpAnalysis.org team starts working on the next generation multi-monitor memory visualization framework utilizing DirectShow, Direct2D, Direct3D and DXGI technologies. Full system architecture and sample code for memory viewers using DirectShow technology will be featured in the forthcoming Computer Memory Visualization book.

- Dmitry Vostokov @ DumpAnalysis.org -