Software Diagnostics Library

If you analyze ETW-based traces such as CDF you may frequently encounter No Trace Metafile pattern especially after product updates and fixes. This complicates pattern analysis because we may not be able to see Significant Events, Anchor Messages, and Error Messages. In some cases we can recover messages by comparing Message Context for unknown messages. If we have source code access this may also help. Both approaches are illustrated in the following diagram:

The same approach may also be applied for a different kind of trace artifacts when some messages are corrupt. In such cases it is possible to recover diagnostic evidence and, therefore, we call this pattern Recovered Messages.

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

Sometimes we notice that data values are in a different order than expected. We call this pattern Data Reversal. By data values we mean some variable parts of a specific repeated message such the address of some structure or object. Data Reversal may happen for one message type:

But it can also happen for some message types and not for others. Typical example here are Enter/Leave trace messages for nested synchronization objects such as monitors and critical sections:

Since we talk about the same message type (the same Message Invariant) this pattern is different from Event Sequence Order pattern.

In rare cases we may observe Data Reversal inside one message with several variable parts but this may also be a case of Data Association.

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

Recently we analyzed a memory dump posted in DA+TA group and posted our results there. The problem was resolved. Afterwards, we decided to look at the earlier dump that was posted for the same problem: a COM server program was unresponsive. That dump was not fully analyzed by group members so we decided to write a case study based on it since it had one more pattern.

When we open the dump in WinDbg it shows Virtualized Process (WOW64) pattern:

wow64cpu!TurboDispatchJumpAddressEnd+0x598:
00000000`77cf2772 c3 ret

We load symbols, WOW64 extension, and switch to x86 mode:

0:000> .symfix c:\mss

0:000> .reload

0:000> .load wow64exts

0:000> !sw
Switched to 32bit mode

Then we check threads in Stack Trace Collection:

0:000:x86> ~*kL

. 0 Id: 16d8.11e0 Suspend: 0 Teb: fffdc000 Unfrozen
ChildEBP RetAddr
002fb0a8 765c10fd ntdll_77d00000!NtWaitForSingleObject+0xc
002fb118 76606586 KERNELBASE!WaitForSingleObjectEx+0x99
002fb138 00499ddc KERNELBASE!GetOverlappedResult+0x9d
WARNING: Stack unwind information not available. Following frames may be wrong.
002fb1a0 005261a4 ServerA+0x99ddc
002fb1e4 005278c9 ServerA+0x1261a4
002fb454 0053bc4d ServerA+0x1278c9
002fba34 005fe5c8 ServerA+0x13bc4d
002fbe20 006094eb ServerA+0x1fe5c8
002fc40c 0060a0d7 ServerA+0x2094eb
0038ee8c 0061a0cb ServerA+0x20a0d7
0038eea4 75e65c3e ServerA+0x21a0cb
0038eed0 75edf497 rpcrt4!Invoke+0×2a
0038f55c 763b04d5 rpcrt4!NdrStubCall2+0×33c
0038f5a4 769aa572 combase!CStdStubBuffer_Invoke+0×96
0038f5c4 763b039d oleaut32!CUnivStubWrapper::Invoke+0×30
0038f650 762b3733 combase!SyncStubInvoke+0×144
(Inline) ——– combase!StubInvoke+0×9a
0038f77c 763b1198 combase!CCtxComChnl::ContextInvoke+0×222
(Inline) ——– combase!DefaultInvokeInApartment+0×4e
(Inline) ——– combase!ClassicSTAInvokeInApartment+0×103
0038f824 763b0bc2 combase!AppInvoke+0×258
0038f980 762b277e combase!ComInvokeWithLockAndIPID+0×5fb
(Inline) ——– combase!ComInvoke+0×15c
(Inline) ——– combase!ThreadDispatch+0×169
0038f9b0 75cf7834 combase!ThreadWndProc+0×2ad
0038f9dc 75cf7a9a user32!_InternalCallWinProc+0×23
0038fa6c 75cf988e user32!UserCallWinProcCheckWow+0×184
0038fad8 75d08857 user32!DispatchMessageWorker+0×208
0038fae0 0061cb88 user32!DispatchMessageA+0×10
0038ff74 0061d85a ServerA+0×21cb88
0038ff8c 7617919f ServerA+0×21d85a
0038ff98 77d4a8cb kernel32!BaseThreadInitThunk+0xe
0038ffdc 77d4a8a1 ntdll_77d00000!__RtlUserThreadStart+0×20
0038ffec 00000000 ntdll_77d00000!_RtlUserThreadStart+0×1b

1 Id: 16d8.f5c Suspend: 0 Teb: fffd9000 Unfrozen
ChildEBP RetAddr
WARNING: Frame IP not in any known module. Following frames may be wrong.
0159ff8c 7617919f 0×3b02c8
0159ff98 77d4a8cb kernel32!BaseThreadInitThunk+0xe
0159ffdc 77d4a8a1 ntdll_77d00000!__RtlUserThreadStart+0×20
0159ffec 00000000 ntdll_77d00000!_RtlUserThreadStart+0×1b

2 Id: 16d8.a88 Suspend: 0 Teb: ffe47000 Unfrozen
ChildEBP RetAddr
097cfde8 77d227d3 ntdll_77d00000!NtWaitForWorkViaWorkerFactory+0xc
097cff8c 7617919f ntdll_77d00000!TppWorkerThread+0x259
097cff98 77d4a8cb kernel32!BaseThreadInitThunk+0xe
097cffdc 77d4a8a1 ntdll_77d00000!__RtlUserThreadStart+0x20
097cffec 00000000 ntdll_77d00000!_RtlUserThreadStart+0x1b

3 Id: 16d8.ab0 Suspend: 0 Teb: fffd3000 Unfrozen
ChildEBP RetAddr
0414fde8 77d227d3 ntdll_77d00000!NtWaitForWorkViaWorkerFactory+0xc
0414ff8c 7617919f ntdll_77d00000!TppWorkerThread+0x259
0414ff98 77d4a8cb kernel32!BaseThreadInitThunk+0xe
0414ffdc 77d4a8a1 ntdll_77d00000!__RtlUserThreadStart+0x20
0414ffec 00000000 ntdll_77d00000!_RtlUserThreadStart+0x1b

4 Id: 16d8.868 Suspend: 0 Teb: ffe4d000 Unfrozen
ChildEBP RetAddr
0460fde8 77d227d3 ntdll_77d00000!NtWaitForWorkViaWorkerFactory+0xc
0460ff8c 7617919f ntdll_77d00000!TppWorkerThread+0x259
0460ff98 77d4a8cb kernel32!BaseThreadInitThunk+0xe
0460ffdc 77d4a8a1 ntdll_77d00000!__RtlUserThreadStart+0x20
0460ffec 00000000 ntdll_77d00000!_RtlUserThreadStart+0x1b

The first thread (#0) has Technology-Specific Subtrace (COM interface invocation) calling ServerA module code, and the second trace (#1) seems to be Active Thread (not waiting) having RIP Stack Trace.

However, only thread #0 seems to be Spiking Thread:

0:000:x86> !runaway f
 User Mode Time
  Thread       Time
   0:11e0      0 days 0:44:44.890
   4:868       0 days 0:00:00.000
   3:ab0       0 days 0:00:00.000
   2:a88       0 days 0:00:00.000
   1:f5c       0 days 0:00:00.000
 Kernel Mode Time
  Thread       Time
   0:11e0      0 days 0:10:38.312
   4:868       0 days 0:00:00.015
   3:ab0       0 days 0:00:00.000
   2:a88       0 days 0:00:00.000
   1:f5c       0 days 0:00:00.000
 Elapsed Time
  Thread       Time
   0:11e0      0 days 2:56:23.297
   1:f5c       0 days 2:56:22.625
   2:a88       0 days 2:54:36.883
   3:ab0       0 days 0:02:18.705
   4:868       0 days 0:01:07.372

Last Error Collection is clear but needs to be double checked by TEB32 (since we have a virtualized process):

0:000:x86> !gle
LastErrorValue: (Win32) 0 (0) - The operation completed successfully.
LastStatusValue: (NTSTATUS) 0 - STATUS_WAIT_0
Wow64 TEB status:
LastErrorValue: (Win32) 0 (0) - The operation completed successfully.
LastStatusValue: (NTSTATUS) 0 - STATUS_WAIT_0

0:000:x86> !teb
Wow64 TEB32 at 00000000fffde000
    ExceptionList:        00000000002fb108
    StackBase:            0000000000390000
    StackLimit:           0000000000255000
    SubSystemTib:         0000000000000000
    FiberData:            0000000000001e00
    ArbitraryUserPointer: 0000000000000000
    Self:                 00000000fffde000
    EnvironmentPointer:   0000000000000000
    ClientId:             00000000000016d8 . 00000000000011e0
    RpcHandle:            0000000000000000
    Tls Storage:          0000000000e12978
    PEB Address:          00000000fffdf000
    LastErrorValue:       38
    LastStatusValue:      c0000011
    Count Owned Locks:    0
    HardErrorMode:        0

Wow64 TEB at 00000000fffdc000
    ExceptionList:        00000000fffde000
    StackBase:            000000000008fd30
    StackLimit:           0000000000083000
    SubSystemTib:         0000000000000000
    FiberData:            0000000000001e00
    ArbitraryUserPointer: 0000000000000000
    Self:                 00000000fffdc000
    EnvironmentPointer:   0000000000000000
    ClientId:             00000000000016d8 . 00000000000011e0
    RpcHandle:            0000000000000000
    Tls Storage:          0000000000000000
    PEB Address:          00000000fffd6000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0

From the errors we suggested to check the code dealing with EOF condition.

0:000:x86> !error 0n38
Error code: (Win32) 0x26 (38) - Reached the end of the file.

0:000:x86> !error c0000011
Error code: (NTSTATUS) 0xc0000011 (3221225489) - The end-of-file marker has been reached. There is no valid data in the file beyond this marker.

But let’s look at the thread #1 raw address and check whether we have traces of malware or JIT code or something else:

0:000:x86> ~1s
003b02c8 c20c00          ret     0Ch

0:001:x86> u 0×3b02c8
003b02c8 c20c00          ret     0Ch
003b02cb 90              nop
003b02cc cc              int     3
003b02cd cc              int     3
003b02ce cc              int     3
003b02cf cc              int     3
003b02d0 cc              int     3
003b02d1 cc              int     3

0:001:x86> ub 0x3b02c8
003b02b6 cc              int     3
003b02b7 cc              int     3
003b02b8 cc              int     3
003b02b9 cc              int     3
003b02ba cc              int     3
003b02bb cc              int     3
003b02bc b803000d00      mov     eax,0D0003h
003b02c1 64ff15c0000000  call    dword ptr fs:[0C0h]

0:001:x86> dps fs:[0C0h] L1
0053:000000c0  77cf11d8 wow64cpu!KiFastSystemCall

0:001:x86> !address 0x3b02c8

Usage:                  
Base Address:           003b0000
End Address:            003b1000
Region Size:            00001000
State:                  00001000	MEM_COMMIT
Protect:                00000020	PAGE_EXECUTE_READ
Type:                   00020000	MEM_PRIVATE
Allocation Base:        003b0000
Allocation Protect:     00000040	PAGE_EXECUTE_READWRITE

Dumping this executable region only shows WOW64 calls:

0:001:x86> dc 003b0000 003b1000
[...]

0:001:x86> .asm no_code_bytes
Assembly options: no_code_bytes

0:001:x86> u 003b0110 003b02e0
003b0110 add     byte ptr [eax],al
003b0112 add     byte ptr [eax],al
003b0114 add     byte ptr [eax],al
003b0116 add     byte ptr [eax],al
003b0118 mov     eax,3000Eh
003b011d call    dword ptr fs:[0C0h]
003b0124 ret     4
003b0127 nop
003b0128 int     3
003b0129 int     3
003b012a int     3
003b012b int     3
003b012c int     3
003b012d int     3
003b012e int     3
003b012f int     3
003b0130 int     3
003b0131 int     3
003b0132 int     3
003b0133 int     3
003b0134 mov     eax,32h
003b0139 call    dword ptr fs:[0C0h]
003b0140 ret     18h
003b0143 nop
003b0144 int     3
003b0145 int     3
003b0146 int     3
003b0147 int     3
003b0148 int     3
003b0149 int     3
003b014a int     3
003b014b int     3
003b014c int     3
003b014d int     3
003b014e int     3
003b014f int     3
003b0150 mov     eax,1B0006h
003b0155 call    dword ptr fs:[0C0h]
003b015c ret     28h
003b015f nop
003b0160 int     3
003b0161 int     3
003b0162 int     3
003b0163 int     3
003b0164 int     3
003b0165 int     3
003b0166 int     3
003b0167 int     3
003b0168 int     3
003b0169 int     3
003b016a int     3
003b016b int     3
003b016c mov     eax,7002Bh
003b0171 call    dword ptr fs:[0C0h]
003b0178 ret     8
003b017b nop
003b017c int     3
003b017d int     3
003b017e int     3
003b017f int     3
003b0180 int     3
003b0181 int     3
003b0182 int     3
003b0183 int     3
003b0184 int     3
003b0185 int     3
003b0186 int     3
003b0187 int     3
003b0188 mov     eax,17h
003b018d call    dword ptr fs:[0C0h]
003b0194 ret     18h
003b0197 nop
003b0198 int     3
003b0199 int     3
003b019a int     3
003b019b int     3
003b019c int     3
003b019d int     3
003b019e int     3
003b019f int     3
003b01a0 int     3
003b01a1 int     3
003b01a2 int     3
003b01a3 int     3
003b01a4 mov     eax,4Fh
003b01a9 call    dword ptr fs:[0C0h]
003b01b0 ret     14h
003b01b3 nop
003b01b4 int     3
003b01b5 int     3
003b01b6 int     3
003b01b7 int     3
003b01b8 int     3
003b01b9 int     3
003b01ba int     3
003b01bb int     3
003b01bc int     3
003b01bd int     3
003b01be int     3
003b01bf int     3
003b01c0 mov     eax,1Dh
003b01c5 call    dword ptr fs:[0C0h]
003b01cc ret     10h
003b01cf nop
003b01d0 int     3
003b01d1 int     3
003b01d2 int     3
003b01d3 int     3
003b01d4 int     3
003b01d5 int     3
003b01d6 int     3
003b01d7 int     3
003b01d8 int     3
003b01d9 int     3
003b01da int     3
003b01db int     3
003b01dc mov     eax,22h
003b01e1 call    dword ptr fs:[0C0h]
003b01e8 ret     18h
003b01eb nop
003b01ec int     3
003b01ed int     3
003b01ee int     3
003b01ef int     3
003b01f0 int     3
003b01f1 int     3
003b01f2 int     3
003b01f3 int     3
003b01f4 int     3
003b01f5 int     3
003b01f6 int     3
003b01f7 int     3
003b01f8 mov     eax,47h
003b01fd call    dword ptr fs:[0C0h]
003b0204 ret     14h
003b0207 nop
003b0208 int     3
003b0209 int     3
003b020a int     3
003b020b int     3
003b020c int     3
003b020d int     3
003b020e int     3
003b020f int     3
003b0210 int     3
003b0211 int     3
003b0212 int     3
003b0213 int     3
003b0214 mov     eax,1A0005h
003b0219 call    dword ptr fs:[0C0h]
003b0220 ret     24h
003b0223 nop
003b0224 int     3
003b0225 int     3
003b0226 int     3
003b0227 int     3
003b0228 int     3
003b0229 int     3
003b022a int     3
003b022b int     3
003b022c int     3
003b022d int     3
003b022e int     3
003b022f int     3
003b0230 mov     eax,10h
003b0235 call    dword ptr fs:[0C0h]
003b023c ret     14h
003b023f nop
003b0240 int     3
003b0241 int     3
003b0242 int     3
003b0243 int     3
003b0244 int     3
003b0245 int     3
003b0246 int     3
003b0247 int     3
003b0248 int     3
003b0249 int     3
003b024a int     3
003b024b int     3
003b024c mov     eax,112h
003b0251 call    dword ptr fs:[0C0h]
003b0258 ret     0Ch
003b025b nop
003b025c int     3
003b025d int     3
003b025e int     3
003b025f int     3
003b0260 int     3
003b0261 int     3
003b0262 int     3
003b0263 int     3
003b0264 int     3
003b0265 int     3
003b0266 int     3
003b0267 int     3
003b0268 mov     eax,13Eh
003b026d call    dword ptr fs:[0C0h]
003b0274 ret     0Ch
003b0277 nop
003b0278 int     3
003b0279 int     3
003b027a int     3
003b027b int     3
003b027c int     3
003b027d int     3
003b027e int     3
003b027f int     3
003b0280 int     3
003b0281 int     3
003b0282 int     3
003b0283 int     3
003b0284 mov     eax,24h
003b0289 call    dword ptr fs:[0C0h]
003b0290 ret     14h
003b0293 nop
003b0294 int     3
003b0295 int     3
003b0296 int     3
003b0297 int     3
003b0298 int     3
003b0299 int     3
003b029a int     3
003b029b int     3
003b029c int     3
003b029d int     3
003b029e int     3
003b029f int     3
003b02a0 mov     eax,18h
003b02a5 call    dword ptr fs:[0C0h]
003b02ac ret     14h
003b02af nop
003b02b0 int     3
003b02b1 int     3
003b02b2 int     3
003b02b3 int     3
003b02b4 int     3
003b02b5 int     3
003b02b6 int     3
003b02b7 int     3
003b02b8 int     3
003b02b9 int     3
003b02ba int     3
003b02bb int     3
003b02bc mov     eax,0D0003h
003b02c1 call    dword ptr fs:[0C0h]
003b02c8 ret     0Ch
003b02cb nop
003b02cc int     3
003b02cd int     3
003b02ce int     3
003b02cf int     3
003b02d0 int     3
003b02d1 int     3
003b02d2 int     3
003b02d3 int     3
003b02d4 int     3
003b02d5 int     3
003b02d6 int     3
003b02d7 int     3
003b02d8 add     byte ptr [eax],al
003b02da add     byte ptr [eax],al
003b02dc add     byte ptr [eax],al
003b02de add     byte ptr [eax],al
003b02e0 add     byte ptr [eax],al

Searching for the address of system call points to another executable region:

0:001:x86> s-d 0 L?(FFFFFFFF/4) 003b02bc
00030044 003b02bc 003b0284 71b74be0 0824448b ..;…;..K.q.D$.

0:001:x86> !address 00030044

Usage:                  
Base Address:           00030000
End Address:            00031000
Region Size:            00001000
State:                  00001000	MEM_COMMIT
Protect:                00000020	PAGE_EXECUTE_READ
Type:                   00020000	MEM_PRIVATE
Allocation Base:        00030000
Allocation Protect:     00000040	PAGE_EXECUTE_READWRITE

0:001:x86> dps 00030000 00031000
00030000 cd697e0e
00030004 4b6b72cc
00030008 036f2786
0003000c be5fe321
00030010 00000f5c
00030014 00000038
00030018 00000000
0003001c 00000030
00030020 00000000
00030024 00000001
00030028 003d0000
0003002c 003d0028
00030030 003b0000
00030034 00000000
00030038 77d4ce23 ntdll_77d00000!LdrLoadDll
0003003c 77d62fdd ntdll_77d00000!LdrUnloadDll
00030040 77d6094d ntdll_77d00000!LdrAddRefDll
00030044 003b02bc
00030048 003b0284
0003004c 71b74be0*** ERROR: Symbol file could not be found. Defaulted to export symbols for UMEngx86.dll -
UMEngx86+0×4be0
00030050 0824448b
00030054 00300589
00030058 52b8003d
0003005c e9000700
[…]

In addition to Ldr* Namespace we see a valid symbolic reference (Module Hint) to AV:

0:001:x86> u 71b74be0
UMEngx86+0x4be0:
71b74be0 push    ebp
71b74be1 mov     ebp,esp
71b74be3 push    0FFFFFFFEh
71b74be5 push    offset UMEngx86!RegQueryValueExW+0x29818 (71b9f9b8)
71b74bea push    offset UMEngx86!RegQueryValueExW+0x20b0 (71b78250)
71b74bef mov     eax,dword ptr fs:[00000000h]
71b74bf5 push    eax
71b74bf6 sub     esp,8

0:001:x86> lmv m UMEngx86
start             end                 module name
71b70000 71bae000   UMEngx86   (export symbols)       UMEngx86.dll
    Loaded symbol image file: UMEngx86.dll
    Image path: C:\ProgramData\Symantec\Symantec
        Endpoint Protection\12.1.4100.4126.105\Data\
        Definitions\BASHDefs\20150307.011\UMEngx86.dll
    Image name: UMEngx86.dll
    Timestamp:        Fri Jan 23 00:52:29 2015 (54C19B4D)
    CheckSum:         00045930
    ImageSize:        0003E000
    File version:     9.1.1.4
    Product version:  9.1.1.4
    File flags:       0 (Mask 3F)
    File OS:          4 Unknown Win32
    File type:        2.0 Dll
    File date:        00000000.00000000
    Translations:     0409.04b0
    CompanyName:      Symantec Corporation
    ProductName:      BASH
    InternalName:     UMEngx86
    OriginalFilename: UMEngx86.dll
    ProductVersion:   9.1.1.4
    FileVersion:      9.1.1.4
    FileDescription:  SONAR Engine
    LegalCopyright:   Copyright (C) 2009 - 2014 Symantec
         Corporation. All rights reserved.

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

When analyzing Spiking Threads across Snapshot Collection we are interested in finding a module (or a function) that was most likely responsible (for example, “looping” inside). Here we can compare the same thread stack trace from different memory dumps and find their Variable Subtrace. For such subtraces we have changes in kv-style output: in return addresses, stack frame values, and possible arguments. The call site that starts the variable subtrace is the most likely candidate (subject to the number of snapshots). For example, consider the following pseudo code:

ModuleA!start()
{
    ModuleA!func1();
}

ModuleA!func1()
{
    ModuleB!func2();
}

ModuleB!func2()
{
    while (…)
    {
        ModuleB!func3();
    }
}

ModuleB!func3()
{
    ModuleB!func4();
}

ModuleB!func4()
{
    ModuleB!func5();
}

ModuleB!func5()
{
    // ...
}

Here, the variable stack trace part will correspond to ModuleB frames. The memory dump can be saved anywhere inside the “while” loop and down the calls, and the last variable return address down the stack trace will belong to ModuleB!func2 address range. The non-variable part will start with ModuleA!func1 address range:

// snapshot 1

RetAddr
ModuleB!func4+0×20
ModuleB!func3+0×10
ModuleB!func2+0×40
ModuleA!func1+0×10
ModuleA!start+0×300

// snapshot 2

RetAddr
ModuleB!func2+0×20
ModuleA!func1+0×10
ModuleA!start+0×300

// snapshot 3

RetAddr
ModuleB!func3+0×20
ModuleB!func2+0×40
ModuleA!func1+0×10
ModuleA!start+0×300

To illustrate this analysis pattern we adopted Memory Cell Diagram (MCD) approach from Accelerated Disassembly, Reconstruction and Reversing training and introduce here Abstract Stack Trace Notation (ASTN) diagrams where different colors are used for different modules and changes are highlighted with different fill patterns. The following three ASTN diagrams from subsequently saved process memory dumps illustrate real stack traces we analyzed some time ago. We see that the variable subtrace contains only the 3rd-party ModuleB calls. Moreover, the loop is possibly contained inside ModuleB because all ModuleA frames are non-variable including Child-SP and Args column values.

If we had ASTN diagrams below instead we would have concluded that the loop was in ModuleA with changes in ModuleB columns as an execution side effect:

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

Reading Boris Uspensky’s book “A Poetics of Composition: The Structure of the Artistic Text and Typology of a Compositional Form” (in its original Russian version) led me to borrow the concept of viewpoints. The resulting analysis pattern is called Trace Viewpoints. These viewpoints are, “subjective” (semantically laden from the perspective of a trace and log reader), and can be (not limited to):

- Error viewpoints (see also False Positive Error, Periodic Error, and Error Distribution)

- Use case (functional) viewpoints (see also Use Case Trail)

- Architectural (design) viewpoints (see also Milestones)

- Implementation viewpoints (see also Implementation Discourse, Macrofunctions, and Focus of Tracing)

- Non-functional viewpoints (see also Counter Value and Diegetic Messages)

- Signal / noise viewpoints (see also Background and Foreground Components)

In comparison, Activity Regions, Data Flow, Thread of Activity, and Adjoint Thread of Activity are “objective” (structural, syntactical) viewpoints.

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

One of the common mistakes is not double-checking symbolic output. Another example here is related to Win32 Start Address. In the output of !thread WinDbg command (or !process and !sprocess Stack Trace Collection commands) we can see Win32 Start Address and, in cases of Truncated Stack Traces or No Component Symbols, we may use this information to guess the purpose of the thread. Unfortunately, it is shown without function offsets and may give a false sense of the thread purpose. For example, this Win32 Start Address ModuleA!DoSomething may suggest that the purpose of the thread was to DoSomething:

THREAD fffffa803431cb50 Cid 03e8.2718 Teb: 000007fffff80000 Win32Thread: 0000000000000000 WAIT: (UserRequest) UserMode Non-Alertable
fffffa80330e0500 SynchronizationEvent
Impersonation token: fffff8a00b807060 (Level Impersonation)
Owning Process fffffa8032354c40 Image: ServiceA.exe
Attached Process N/A Image: N/A
Wait Start TickCount 107175 Ticks: 19677 (0:00:05:06.963)
Context Switch Count 2303 IdealProcessor: 1
UserTime 00:00:00.218
KernelTime 00:00:00.109
Win32 Start Address ModuleA!DoSomething (0×000007fef46b4cde)
Stack Init fffff88008e5fdb0 Current fffff88008e5f900
Base fffff88008e60000 Limit fffff88008e5a000 Call 0
Priority 10 BasePriority 10 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Kernel stack not resident.
Child-SP RetAddr Call Site
fffff880`08e5f940 fffff800`01c7cf72 nt!KiSwapContext+0×7a
fffff880`08e5fa80 fffff800`01c8e39f nt!KiCommitThreadWait+0×1d2
fffff880`08e5fb10 fffff800`01f7fe3e nt!KeWaitForSingleObject+0×19f
fffff880`08e5fbb0 fffff800`01c867d3 nt!NtWaitForSingleObject+0xde
fffff880`08e5fc20 00000000`76e5067a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`08e5fc20)
00000000`0427cca8 000007fe`f46a4afe ntdll!NtWaitForSingleObject+0xa
00000000`0427ccb0 000007fe`f46c68d4 ModuleA!DoSomething+0xc68d4
00000000`0427cd60 000007fe`f46c6ade ModuleA!DoSomething+0xc5ee8


But if we look at fragments of the stack trace we see function huge offsets and this means that this function was just some function from ModuleA export table. It was chosen because return addresses fall into an address range between exported functions. Because Win32 Start Address also falls into such an address range it is listed as ModuleA!DoSomething but without an offset. In our case, an engineer made the wrong assumption about the possible root cause and provided unnecessary troubleshooting instructions.

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

Trace Mask is a superposition of two (or many) different traces. This is different from Inter-Correlation pattern where we may only search for certain messages without the synthesis of a new log. The most useful Trace Mask is when we have different time scales (or significantly different Trace Currents). Then we impose an additional structure on the one of the traces:

We got the idea from Narrative Masks discussed in Miroslav Drozda’s book “Narativní masky ruské prózy” (”Narrative Masks in Russian Prose”).

The very simple example of Trace Mask is shown in Debugging TV Episode 0×15.

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

Sometimes we have a uniform stream of messages that belong to some Activity Region, Thread of Activity, or Adjoint Thread of Activity. We can use micro-Discontinuities to structure that message stream into groups of actions, for example, Macrofunctions, especially if semantics of trace messages is not yet fully clear to us. This may also help us to recognize Visitor trace. Originally we wanted to call this pattern Micro Delays, but, after recognizing that such delays only make sense for one activity (since there can be too many of them in the overall log), we named this pattern Punctuated Activity. Usually such delays are small compare to Timeouts and belong to Silent Messages.

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

Sometimes we can see signs of Crashed Processes in kernel and complete memory dumps. By crashes we mean the sudden disappearance of processes from Task Manager, for example. In memory dumps we can still see such processes as Zombie Processes. Special Processes found in the process list may help to select the possible candidate among many Zombie Processes. If a process is supposed to be launched only once (like a service) but found several times as Zombie Process and also as a normal process later in the process list (for example, as Last Object), then this may point to possible past crashes (or silent terminations). We also have a similar trace analysis pattern: Singleton Event. The following example illustrates both signs:

0: kd> !process 0 0

[...]

PROCESS fffffa80088a5640
SessionId: 0 Cid: 2184 Peb: 7fffffd7000 ParentCid: 0888
DirBase: 381b8000 ObjectTable: 00000000 HandleCount: 0.
Image: WerFault.exe

PROCESS fffffa8007254b30
SessionId: 0 Cid: 20ac Peb: 7fffffdf000 ParentCid: 02cc
DirBase: b3306000 ObjectTable: 00000000 HandleCount: 0.
Image: ServiceA.exe

[...]

PROCESS fffffa8007fe2b30
SessionId: 0 Cid: 2a1c Peb: 7fffffdf000 ParentCid: 02cc
DirBase: 11b649000 ObjectTable: fffff8a014939530 HandleCount: 112.
Image: ServiceA.exe

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

When we do tracing and logging much of computational activity is not visible. For live tracing and debugging this can be alleviated by adding Watch Threads. These are selected memory locations that may or may not be formatted according to specific data structures and are inspected at each main trace message occurrence or after specific intervals or events:

This analysis pattern is different from State Dump which is about intrinsic tracing where the developer of logging statements already incorporated variable watch in source code. Watch Threads are completely independent from original tracing and may be added independently. Counter Value is the simplest example of Watch Thread if done externally because the former usually doesn’t require source code and often means some OS or module variable independent of product internals. Watch Thread is also similar to Data Flow pattern where specific data we are interested in is a part of every trace message.

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

Software Exception is added for completeness of pattern discourse. We mentioned it a few times before, for example, in Activation Context, Exception Module, Missing Component (static linkage), Self-Dump, Stack Overflow (software implementation), and Translated Exception patterns. Typical example of software exceptions is C++ Exception pattern.

Software exceptions, such as not enough memory, are different from the so-called hardware exceptions by being predictable, synchronous, and detected by software code itself. Hardware exceptions such as divide by zero, access violation, and memory protection, on the contrary, are unpredictable, and detected by hardware. Of course, it is possible to do some checks before code execution, and then throw a software exception or some diagnostic message for a would be hardware exception. See, for example, Self-Diagnosis pattern for user mode and its corresponding equivalent for kernel mode.

In Windows memory dumps we may see RaiseException call in user space stack trace, such as from Data Correlation pattern example:

0:000> kL
ChildEBP RetAddr
0012e950 78158e89 kernel32!RaiseException+0×53
0012e988 7830770c msvcr80!_CxxThrowException+0×46
0012e99c 783095bc mfc80u!AfxThrowMemoryException+0×19
0012e9b4 02afa8ca mfc80u!operator new+0×27
0012e9c8 02b0992f ModuleA!std::_Allocate<…>+0×1a
0012e9e0 02b09e7c ModuleA!std::vector >::vector >+0×3f
[…]

When looking for Multiple or Hidden Exceptions we may also want to check for such calls.

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

Sometimes we have Basic Facts in a problem description but can’t find messages corresponding to them in a trace or log file but we are sure the tracing (logging) was done correctly. This may be because we have Sparse Trace, or we are not familiar well with product or system tracing messages (such as with Implementation Discourse).

In such a case we for search for Indirect Message of a possible cause:

Having found such a message we may hypothesize that Missing Message should have located nearby (this is based on semantics of both messages), and we then explore corresponding Message Context:

The same analysis strategy is possible for missing causal messages. Here we search for effect or side effect messages:

Having found them we proceed with further analysis:

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

Corrupt Structure is added for completeness of pattern discourse. We mentioned it a few times, for example, in Self-Diagnosis (kernel mode), and Critical Section Corruption. Typical signs of the corrupt structure include:

- Regular Data such as ASCII and UNICODE fragments over substructures and pointer areas
- Large values where you expect small and vice versa
- User space address values where we expect kernel space and vice versa
- Malformed and partially zeroed _LIST_ENTRY data (see exercise C3 for linked list navigation)
- Memory read errors for pointer dereferences or inaccessible memory indicators (??)
- Memory read error at the end of the linked list while traversing structures

0: kd> dt _ERESOURCE ffffd0002299f830
ntdll!_ERESOURCE
+0x000 SystemResourcesList : _LIST_ENTRY [ 0xffffc000`07b64800 - 0xffffe000`02a79970 ]
+0x010 OwnerTable       : 0xffffe000`02a79940 _OWNER_ENTRY
+0x018 ActiveCount      : 0n0
+0x01a Flag             : 0
+0x01a ReservedLowFlags : 0 ''
+0x01b WaiterPriority   : 0 ''
+0x020 SharedWaiters    : 0x00000000`00000001 _KSEMAPHORE
+0x028 ExclusiveWaiters : 0xffffe000`02a79a58 _KEVENT
+0x030 OwnerEntry       : _OWNER_ENTRY
+0x040 ActiveEntries    : 0
+0x044 ContentionCount  : 0
+0×048 NumberOfSharedWaiters : 0×7b64800
+0×04c NumberOfExclusiveWaiters : 0xffffc000
+0×050 Reserved2        : (null)
+0×058 Address          : 0xffffd000`2299f870 Void
+0×058 CreatorBackTraceIndex : 0xffffd000`2299f870
+0×060 SpinLock         : 1

0: kd> dt _ERESOURCE ffffd0002299d830
ntdll!_ERESOURCE
+0×000 SystemResourcesList : _LIST_ENTRY [ 0×000001e0`00000280 - 0×00000000`00000004 ]
+0×010 OwnerTable       : 0×00000000`0000003c _OWNER_ENTRY
+0×018 ActiveCount      : 0n0
+0×01a Flag             : 0
+0×01a ReservedLowFlags : 0 ”
+0×01b WaiterPriority   : 0 ”
+0×020 SharedWaiters    : 0×0000003c`000001e0 _KSEMAPHORE
+0×028 ExclusiveWaiters : (null)
+0×030 OwnerEntry       : _OWNER_ENTRY
+0×040 ActiveEntries    : 0
+0×044 ContentionCount  : 0×7f
+0×048 NumberOfSharedWaiters : 0×7f
+0×04c NumberOfExclusiveWaiters : 0×7f
+0×050 Reserved2        : 0×00000001`00000001 Void
+0×058 Address          : 0×00000000`00000005 Void
+0×058 CreatorBackTraceIndex : 5
+0×060 SpinLock         : 0

However, we need to be sure that we supplied the correct pointer to dt WinDbg command. One of the signs that the pointer was incorrect are memory read errors or all zeroes:

0: kd> dt _ERESOURCE ffffd000229af830
ntdll!_ERESOURCE
+0x000 SystemResourcesList : _LIST_ENTRY [ 0x00000000`00000000 - 0x00000000`00000000 ]
+0x010 OwnerTable : (null)
+0x018 ActiveCount : 0n0
+0x01a Flag : 0
+0x01a ReservedLowFlags : 0 ''
+0x01b WaiterPriority : 0 ''
+0x020 SharedWaiters : (null)
+0x028 ExclusiveWaiters : (null)
+0x030 OwnerEntry : _OWNER_ENTRY
+0x040 ActiveEntries : 0
+0x044 ContentionCount : 0
+0x048 NumberOfSharedWaiters : 0
+0x04c NumberOfExclusiveWaiters : 0
+0x050 Reserved2 : (null)
+0x058 Address : (null)
+0x058 CreatorBackTraceIndex : 0
+0x060 SpinLock : 0

0: kd> dt _ERESOURCE ffffd00022faf830
ntdll!_ERESOURCE
+0x000 SystemResourcesList : _LIST_ENTRY
+0x010 OwnerTable       : ????
+0x018 ActiveCount      : ??
+0x01a Flag             : ??
+0x01a ReservedLowFlags : ??
+0x01b WaiterPriority   : ??
+0x020 SharedWaiters    : ????
+0x028 ExclusiveWaiters : ????
+0x030 OwnerEntry       : _OWNER_ENTRY
+0x040 ActiveEntries    : ??
+0x044 ContentionCount  : ??
+0x048 NumberOfSharedWaiters : ??
+0x04c NumberOfExclusiveWaiters : ??
+0x050 Reserved2        : ????
+0x058 Address          : ????
+0x058 CreatorBackTraceIndex : ??
+0x060 SpinLock         : ??
Memory read error ffffd00022faf890

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

Sometimes, due to optimization or indeterminate stack trace reconstruction, we may not see all stack trace frames. In some case it is possible to reconstruct such Hidden Calls. For example, we have the following unmanaged Stack Trace of CLR Thread:

0:000> k
ChildEBP RetAddr
0011d6b8 66fdee7c mscorwks!JIT_IsInstanceOfClass+0xd
0011d6cc 67578500 PresentationCore_ni!`string'+0x4a2bc
0011d6e0 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778500)
0011d6f4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011d708 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d71c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d730 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d744 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d758 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d76c 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d780 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011d794 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7a8 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7bc 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7d0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7e4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7f8 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d80c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d820 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d834 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d848 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d85c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d870 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d884 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d898 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8ac 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8c0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8d4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8e8 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8fc 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011d910 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d924 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d938 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d94c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d960 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d974 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d988 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d99c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d9b0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d9c4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d9d8 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d9ec 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011da00 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da14 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da28 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da3c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da50 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da64 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da78 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da8c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011daa0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dab4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dac8 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dadc 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011daf0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db04 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db18 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db2c 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db40 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011db54 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db68 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db7c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db90 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dba4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dbb8 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dbcc 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dbe0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dbf4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc08 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc1c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc30 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc44 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc58 66fc3282 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
*** WARNING: Unable to verify checksum for PresentationFramework.ni.dll
0011dd28 662a75e6 PresentationCore_ni!`string'+0x2e6c2
0011de08 662190a0 PresentationFramework_ni+0x2675e6
0011dffc 66fc35e2 PresentationFramework_ni+0x1d90a0
0011e0ec 66fd9dad PresentationCore_ni!`string'+0x2ea22
0011e214 66fe0459 PresentationCore_ni!`string'+0x451ed
0011e238 66fdfd40 PresentationCore_ni!`string'+0x4b899
0011e284 66fdfc9b PresentationCore_ni!`string'+0x4b180
*** WARNING: Unable to verify checksum for WindowsBase.ni.dll
0011e2b0 723ca31a PresentationCore_ni!`string'+0x4b0db
0011e2cc 723ca20a WindowsBase_ni+0x9a31a
0011e30c 723c8384 WindowsBase_ni+0x9a20a
0011e330 723cd26d WindowsBase_ni+0x98384
0011e368 723cd1f8 WindowsBase_ni+0x9d26d
0011e380 72841b4c WindowsBase_ni+0x9d1f8
0011e390 728589ec mscorwks!CallDescrWorker+0x33
0011e410 72865acc mscorwks!CallDescrWorkerWithHandler+0xa3
0011e54c 72865aff mscorwks!MethodDesc::CallDescr+0x19c
0011e568 72865b1d mscorwks!MethodDesc::CallTargetWorker+0x1f
0011e580 728bd9c8 mscorwks!MethodDescCallSite::CallWithValueTypes+0x1a
0011e74c 728bdb1e mscorwks!ExecuteCodeWithGuaranteedCleanupHelper+0x9f
*** WARNING: Unable to verify checksum for mscorlib.ni.dll
0011e7fc 68395887 mscorwks!ReflectionInvocation::ExecuteCodeWithGuaranteedCleanup+0x10f
0011e818 683804b5 mscorlib_ni+0x235887
0011e830 723cd133 mscorlib_ni+0x2204b5
0011e86c 723c7a27 WindowsBase_ni+0x9d133
0011e948 723c7d13 WindowsBase_ni+0x97a27
0011e984 723ca4fe WindowsBase_ni+0x97d13
0011e9d0 723ca42a WindowsBase_ni+0x9a4fe
0011e9f0 723ca31a WindowsBase_ni+0x9a42a
0011ea0c 723ca20a WindowsBase_ni+0x9a31a
0011ea4c 723c8384 WindowsBase_ni+0x9a20a
0011ea70 723c74e1 WindowsBase_ni+0x98384
0011eaac 723c7430 WindowsBase_ni+0x974e1
0011eadc 723c9b6c WindowsBase_ni+0x97430
0011eb2c 757462fa WindowsBase_ni+0x99b6c
0011eb58 75746d3a user32!InternalCallWinProc+0x23
0011ebd0 757477c4 user32!UserCallWinProcCheckWow+0x109
0011ec30 7574788a user32!DispatchMessageWorker+0x3bc
0011ec40 0577304e user32!DispatchMessageW+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
0011ec5c 723c7b24 0x577304e
0011eccc 723c71f9 WindowsBase_ni+0x97b24
0011ecd8 723c719c WindowsBase_ni+0x971f9
0011ece4 6620f07e WindowsBase_ni+0x9719c
0011ecf0 6620e37f PresentationFramework_ni+0x1cf07e
0011ed14 661f56d6 PresentationFramework_ni+0x1ce37f
0011ed24 661f5699 PresentationFramework_ni+0x1b56d6
0011ed80 72841b4c PresentationFramework_ni+0x1b5699
0011eda0 72841b4c mscorwks!CallDescrWorker+0x33
0011edb0 728589ec mscorwks!CallDescrWorker+0x33
0011ee30 72865acc mscorwks!CallDescrWorkerWithHandler+0xa3
0011ef6c 72865aff mscorwks!MethodDesc::CallDescr+0x19c
0011ef88 72865b1d mscorwks!MethodDesc::CallTargetWorker+0x1f
0011efa0 728fef01 mscorwks!MethodDescCallSite::CallWithValueTypes+0x1a
0011f104 728fee21 mscorwks!ClassLoader::RunMain+0x223
0011f36c 728ff33e mscorwks!Assembly::ExecuteMainMethod+0xa6
0011f83c 728ff528 mscorwks!SystemDomain::ExecuteMainMethod+0x45e
0011f88c 728ff458 mscorwks!ExecuteEXE+0x59
0011f8d4 70aef4f3 mscorwks!_CorExeMain+0x15c
0011f90c 70b77efd mscoreei!_CorExeMain+0x10a
0011f924 70b74de3 mscoree!ShellShim__CorExeMain+0x7d
0011f92c 754c338a mscoree!_CorExeMain_Exported+0x8
0011f938 77659f72 kernel32!BaseThreadInitThunk+0xe
0011f978 77659f45 ntdll!__RtlUserThreadStart+0x70
0011f990 00000000 ntdll!_RtlUserThreadStart+0x1b

Its Managed Stack Trace is the following:

0:000> !CLRStack
OS Thread Id: 0x1520 (0)
ESP       EIP
0011e7a0 728493a4 [HelperMethodFrame_PROTECTOBJ: 0011e7a0] System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup(TryCode, CleanupCode, System.Object)
0011e808 68395887 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
0011e824 683804b5 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
0011e83c 723cd133 System.Windows.Threading.DispatcherOperation.Invoke()
0011e874 723c7a27 System.Windows.Threading.Dispatcher.ProcessQueue()
0011e950 723c7d13 System.Windows.Threading.Dispatcher.WndProcHook(IntPtr, Int32, IntPtr, IntPtr, Boolean ByRef)
0011e99c 723ca4fe MS.Win32.HwndWrapper.WndProc(IntPtr, Int32, IntPtr, IntPtr, Boolean ByRef)
0011e9e8 723ca42a MS.Win32.HwndSubclass.DispatcherCallbackOperation(System.Object)
0011e9f8 723ca31a System.Windows.Threading.ExceptionWrapper.InternalRealCall(System.Delegate, System.Object, Boolean)
0011ea1c 723ca20a System.Windows.Threading.ExceptionWrapper.TryCatchWhen(System.Object, System.Delegate, System.Object, Boolean, System.Delegate)
0011ea64 723c8384 System.Windows.Threading.Dispatcher.WrappedInvoke(System.Delegate, System.Object, Boolean, System.Delegate)
0011ea84 723c74e1 System.Windows.Threading.Dispatcher.InvokeImpl(System.Windows.Threading.DispatcherPriority, System.TimeSpan, System.Delegate, System.Object, Boolean)
0011eac8 723c7430 System.Windows.Threading.Dispatcher.Invoke(System.Windows.Threading.DispatcherPriority, System.Delegate, System.Object)
0011eaec 723c9b6c MS.Win32.HwndSubclass.SubclassWndProc(IntPtr, Int32, IntPtr, IntPtr)
0011ec74 00270b04 [NDirectMethodFrameStandalone: 0011ec74] MS.Win32.UnsafeNativeMethods.DispatchMessage(System.Windows.Interop.MSG ByRef)
0011ec84 723c7b24 System.Windows.Threading.Dispatcher.PushFrameImpl(System.Windows.Threading.DispatcherFrame)
0011ecd4 723c71f9 System.Windows.Threading.Dispatcher.PushFrame(System.Windows.Threading.DispatcherFrame)
0011ece0 723c719c System.Windows.Threading.Dispatcher.Run()
0011ecec 6620f07e System.Windows.Application.RunDispatcher(System.Object)
0011ecf8 6620e37f System.Windows.Application.RunInternal(System.Windows.Window)
0011ed1c 661f56d6 System.Windows.Application.Run(System.Windows.Window)
0011ed2c 661f5699 System.Windows.Application.Run()
[...]

Caller-n-Callee traces also don’t reveal anything more:

Thread   0
Current frame: mscorwks!JIT_IsInstanceOfClass+0xd
ChildEBP RetAddr  Caller,Callee
0011d6b8 66fdee7c (MethodDesc 0x66ee2954 +0x3c MS.Internal.DeferredElementTreeState.GetLogicalParent(System.Windows.DependencyObject, MS.Internal.DeferredElementTreeState)), calling mscorwks!JIT_IsInstanceOfClass
0011d6cc 67578500 (MethodDesc 0x66ee1270 +0x110 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee2954 +0 MS.Internal.DeferredElementTreeState.GetLogicalParent(System.Windows.DependencyObject, MS.Internal.DeferredElementTreeState))
0011d6e0 67578527 (MethodDesc 0x66ee1270 +0x137 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee1270 +0 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject))
0011d6f4 6757850d (MethodDesc 0x66ee1270 +0x11d MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee1270 +0 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject))
0011d708 6757850d (MethodDesc 0x66ee1270 +0x11d MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee1270 +0 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject))
0011d71c 6757850d (MethodDesc 0x66ee1270 +0x11d MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee1270 +0 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject))
[...]

However, if we check the return address for Top Module mscorwks (66fdee7c) we will see a call possibly related to 3D processing:

0:000> k
ChildEBP RetAddr
0011d6b8 66fdee7c mscorwks!JIT_IsInstanceOfClass+0xd
0011d6cc 67578500 PresentationCore_ni!`string’+0×4a2bc
0011d6e0 67578527 PresentationCore_ni!`string’ <PERF> (PresentationCore_ni+0×778500)
0011d6f4 6757850d PresentationCore_ni!`string’ <PERF> (PresentationCore_ni+0×778527)
[…]

0:000> ub 66fdee7c
PresentationCore_ni!`string'+0x4a2a2:
66fdee62 740c            je      PresentationCore_ni!`string'+0x4a2b0 (66fdee70)
66fdee64 8bc8            mov     ecx,eax
66fdee66 8b01            mov     eax,dword ptr [ecx]
66fdee68 ff90d8030000    call    dword ptr [eax+3D8h]
66fdee6e 8bf0            mov     esi,eax
66fdee70 8bd7            mov     edx,edi
66fdee72 b998670467      mov     ecx,offset PresentationCore_ni!`string'+0xb1bd8 (67046798)
66fdee77 e82c7afaff      call   PresentationCore_ni!?System.Windows.Media.Media3D.Viewport3DVisual.PrecomputeContent@@200001+0×3c (66f868a8)

The call structure seems to be valid when we check the next return address from the stack trace (67578500):

0:000> ub 67578500
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784e7):
675784e7 e8f4a2a0ff      call    PresentationCore_ni!?System.Windows.Media.Media3D.ScaleTransform3D.UpdateResource@@2002011280M802+0x108 (66f827e0)
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784ec):
675784ec eb05            jmp     PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f3) (675784f3)
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784ee):
675784ee b801000000      mov     eax,1
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f3):
675784f3 85c0            test    eax,eax
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f5):
675784f5 74b1            je      PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784a8) (675784a8)
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f7):
675784f7 8bcb            mov     ecx,ebx
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f9):
675784f9 33d2            xor     edx,edx
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784fb):
675784fb e84069a6ff      call    PresentationCore_ni!`string’+0×4a280 (66fdee40)

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

To complement Module patterns sub-catalogue we introduce Origin Module pattern. This is a module that may have originated the problem behavior. For example, when we look at a stack trace we may skip Top Modules due to our knowledge of the product, for example, if they are not known as Problem Modules or known as Well-Tested Modules. In case of Truncated Stack Traces we may designate bottom modules as possible problem origins. For example, for Reference Leak pattern example we may consider checking reference counting for selected modules such as ModuleA and ModuleB:

ad377ae8 +1 Dflt nt! ?? ::FNODOBFM::`string'+18f1d
nt!ObpCallPreOperationCallbacks+4e
nt!ObpPreInterceptHandleCreate+af
nt! ?? ::NNGAKEGL::`string'+2c31f
nt!ObOpenObjectByPointerWithTag+109
nt!PsOpenProcess+1a2
nt!NtOpenProcess+23
nt!KiSystemServiceCopyEnd+13
nt!KiServiceLinkage+0
ModuleA+dca63
ModuleA+b5bc
ModuleA+c9c2e
ModuleA+bae56
ModuleA+b938d
ModuleA+c0ec6
ModuleA+afce7

ad377aeb -1 Dflt nt! ?? ::FNODOBFM::`string'+4886e
nt!ObpCallPreOperationCallbacks+277
nt!ObpPreInterceptHandleCreate+af
nt! ?? ::NNGAKEGL::`string'+2c31f
nt!ObOpenObjectByPointerWithTag+109
nt!PsOpenProcess+1a2
nt!NtOpenProcess+23
nt!KiSystemServiceCopyEnd+13
nt!KiServiceLinkage+0
ModuleA+dca63
ModuleA+b5bc
ModuleA+c9c2e
ModuleA+bae56
ModuleA+b938d
ModuleA+c0ec6
ModuleA+afce7

ad377af7 +1 Dflt nt! ?? ::NNGAKEGL::`string'+1fb41
nt!ObReferenceObjectByHandle+25
ModuleA+dcade
ModuleA+b5bc
ModuleA+c9c2e
ModuleA+bae56
ModuleA+b938d
ModuleA+c0ec6
ModuleA+afce7
ModuleA+87ca
ModuleA+834a
ModuleA+a522c
ModuleA+a51b6
ModuleA+a4787
ModuleB+19c0c
ModuleB+19b28

ad377afa -1 Dflt nt! ?? ::FNODOBFM::`string'+4886e
ModuleA+dcbbe
ModuleA+b5bc
ModuleA+c9c2e
ModuleA+bae56
ModuleA+b938d
ModuleA+c0ec6
ModuleA+afce7
ModuleA+87ca
ModuleA+834a
ModuleA+a522c
ModuleA+a51b6
ModuleA+a4787
ModuleB+19c0c
ModuleB+19b28
ModuleB+b652

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

Sometimes we need memory reference information not available in software traces and logs, for example, to see pointer dereferences, to follow pointers and linked structures. In such cases memory dumps saved during logging sessions may help. In case of process memory dumps we can even have several Step Dumps. Complete and kernel memory dumps may be forced after saving a log file. We call such pattern Adjoint Space:

Then we can analyze logs and memory dumps together, for example, to follow pointer data further in memory space:

There is also a reverse situation when we use logs to see past data changes before memory snapshot time (Paratext memory analysis pattern):

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

Sometimes specific parts of simultaneous Use Case Trails, blocks of Significant Events or Message Sets in general may overlap. This may point to possible synchronization problems such as race conditions (prognostics) or be visible root causes of them if such problems are reported (diagnostics). We call this pattern Activity Overlap:

For example, a first request may start a new session and we expect the second request to be processed by the same already established session:

However, users report the second session started upon the second request. If we filter execution log by session id and do Intra-Correlational analysis we find out that session initialization prologues are overlapped. The new session started because the first session initialization was not completed:

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

Some Discontinuities may be Periodic as Silent Messages. If such discontinuities belong to the same Thread of Activity and their Time Deltas are constant we may see Timeout pattern. When timeouts are followed by Error Message we can identify them by back tracing. Timeouts are different from Blackouts where the latter are usually Singleton Events and have large time deltas.

Here is a generalized graphical case study. An error message was identified based on incident Basic Facts:

We filtered the trace for error message TID and found 3 timeouts 30 minutes each:

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

Objects such as processes may be referenced internally in addition to using handles. If their reference counts are unbalanced we may have Reference Leak pattern. For example, we have an instance of thousands of Zombie Processes but we don’t see Handle Leaks from their parent processes if we analyze ParentCids:

0: kd> !process 0 0
[...]
PROCESS fffffa801009a060
SessionId: 0 Cid: 2e270 Peb: 7fffffdb000 ParentCid: 032c
DirBase: 12ba37000 ObjectTable: 00000000 HandleCount: 0.
Image: conhost.exe

PROCESS fffffa8009b7e8e0
SessionId: 1 Cid: 2e0c8 Peb: 7fffffd9000 ParentCid: 10a0
DirBase: 21653e000 ObjectTable: 00000000 HandleCount: 0.
Image: taskmgr.exe

PROCESS fffffa8009e7a450
SessionId: 0 Cid: 2e088 Peb: 7efdf000 ParentCid: 0478
DirBase: 107f02000 ObjectTable: 00000000 HandleCount: 0.
Image: AppA.exe

PROCESS fffffa8009e794b0
SessionId: 0 Cid: 2e394 Peb: 7fffffd3000 ParentCid: 032c
DirBase: 210ffc000 ObjectTable: 00000000 HandleCount: 0.
Image: conhost.exe

PROCESS fffffa8009ed4060
SessionId: 0 Cid: 2dee4 Peb: 7efdf000 ParentCid: 0478
DirBase: 11b7c7000 ObjectTable: 00000000 HandleCount: 0.
Image: AppB.exe

PROCESS fffffa800a13bb30
SessionId: 0 Cid: 2e068 Peb: 7fffffd5000 ParentCid: 032c
DirBase: 1bb8c1000 ObjectTable: 00000000 HandleCount: 0.
Image: conhost.exe

PROCESS fffffa80096f26b0
SessionId: 0 Cid: 2e320 Peb: 7efdf000 ParentCid: 0478
DirBase: 6ad4c000 ObjectTable: 00000000 HandleCount: 0.
Image: AppC.exe

PROCESS fffffa8009c44060
SessionId: 0 Cid: 2e300 Peb: 7fffffdd000 ParentCid: 032c
DirBase: 10df06000 ObjectTable: 00000000 HandleCount: 0.
Image: conhost.exe
[...]

0: kd> !object fffffa800a13bb30
Object: fffffa800a13bb30 Type: (fffffa8006cecf30) Process
ObjectHeader: fffffa800a13bb00 (new version)
HandleCount: 0 PointerCount: 1

0: kd> !object fffffa8009b7e8e0
Object: fffffa8009b7e8e0 Type: (fffffa8006cecf30) Process
ObjectHeader: fffffa8009b7e8b0 (new version)
HandleCount: 0 PointerCount: 1

Such number of processes correlates with non-paged pool usage for process structures:

0: kd> !poolused 3
....
Sorting by NonPaged Pool Consumed

NonPaged Paged
Tag Allocs Frees Diff Used Allocs Frees Diff Used

Proc 55488 60 55428 80328320 0 0 0 0 Process objects , Binary: nt!ps
File 51733526 51708737 24789 7150416 0 0 0 0 File objects
[…]

Here we recommend enabling object reference tracing either using gflags.exe or directly modifying registry:

Key: HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Session Manager\kernel
Value: ObTracePoolTags
Type: REG_SZ
Data: Proc

Note: after troubleshooting or debugging please disable tracing because it consumes pool (another variant of Instrumentation Side Effect pattern and may lead to similar Insufficient Memory pattern for stack trace database):

0: kd> !poolused 3
....
Sorting by NonPaged Pool Consumed

NonPaged Paged
Tag Allocs Frees Diff Used Allocs Frees Diff Used

ObRt 5688634 5676109 12525 4817288240 0 0 0 0 object reference stack tracing , Binary: nt!ob
Proc 22120 101 22019 25961168 0 0 0 0 Process objects , Binary: nt!ps
[…]

After enabling tracing we collect a complete memory dump (in case of postmortem debugging) to analyze another variant of Stack Trace pattern using !obtrace WinDbg command:

0: kd> !obtrace fffffa800af9e220
Object: fffffa800af9e220
Image: AppD.exe
Sequence (+/-) Tag Stack
-------- ----- ---- ---------------------------------------------------
ad377858 +1 Dflt nt! ?? ::NNGAKEGL::`string'+21577
nt!PspAllocateProcess+185
nt!NtCreateUserProcess+4a3
nt!KiSystemServiceCopyEnd+13

ad37787d +1 Dflt nt! ?? ::FNODOBFM::`string'+18f1d
nt!NtCreateUserProcess+569
nt!KiSystemServiceCopyEnd+13

ad377882 +1 Dflt nt! ?? ::NNGAKEGL::`string'+1f9d8
nt!NtProtectVirtualMemory+119
nt!KiSystemServiceCopyEnd+13
nt!KiServiceLinkage+0
nt!RtlCreateUserStack+1e4
nt!PspAllocateThread+299
nt!NtCreateUserProcess+65d
nt!KiSystemServiceCopyEnd+13

ad377884 -1 Dflt nt! ?? ::FNODOBFM::`string'+4886e
nt!NtProtectVirtualMemory+161
nt!KiSystemServiceCopyEnd+13
nt!KiServiceLinkage+0
nt!RtlCreateUserStack+1e4
[...]

Analysis of such traces may be complicated due to Truncated Stack Traces. We plan to show one counting trick in the next pattern.

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

Exception Module pattern is an obvious pattern we add for pattern language completeness. It is a module or component where the actual exception happened, for example, ModuleA from this Exception Stack Trace:

9 Id: 1df4.a08 Suspend: -1 Teb: 7fff4000 Unfrozen
ChildEBP RetAddr
1022f5a8 7c90df4a ntdll!KiFastSystemCallRet
1022f5ac 7c8648a2 ntdll!ZwWaitForMultipleObjects+0xc
1022f900 7c83ab50 kernel32!UnhandledExceptionFilter+0×8b9
1022f908 7c839b39 kernel32!BaseThreadStart+0×4d
1022f930 7c9032a8 kernel32!_except_handler3+0×61
1022f954 7c90327a ntdll!ExecuteHandler2+0×26
1022fa04 7c90e48a ntdll!ExecuteHandler+0×24
1022fa04 7c812afb ntdll!KiUserExceptionDispatcher+0xe
1022fd5c 0b82e680 kernel32!RaiseException+0×53
WARNING: Stack unwind information not available. Following frames may be wrong.
1022fd94 0b82d2f2 ModuleA+0×21e640
1022fde8 7753004f ModuleA+0×21d4f2
1022fdfc 7753032f ole32!CClassCache::CDllPathEntry::CanUnload_rl+0×3b
1022ff3c 7753028b ole32!CClassCache::FreeUnused+0×70
1022ff4c 775300b5 ole32!CoFreeUnusedLibrariesEx+0×36
1022ff58 77596af5 ole32!CoFreeUnusedLibraries+0×9
1022ff6c 77566ff9 ole32!CDllHost::MTAWorkerLoop+0×25
1022ff8c 7752687c ole32!CDllHost::WorkerThread+0xc1
1022ff94 774fe3ee ole32!DLLHostThreadEntry+0xd
1022ffa8 774fe456 ole32!CRpcThread::WorkerLoop+0×1e
1022ffb4 7c80b729 ole32!CRpcThreadCache::RpcWorkerThreadEntry+0×1b
1022ffec 00000000 kernel32!BaseThreadStart+0×37

Because we have a software exception we can use backwards disassembly (ub WinDbg command) to check stack trace correctness in case of stack unwind warnings (like in Coincidental Symbolic Information pattern). Here’s another example, for recent MS Paint crash we observed, with msvcrt exception module. However, if we skip it as a Well-Tested Module, the next exception module candidate is mspaint.

0:000> kc
Call Site
ntdll!NtWaitForMultipleObjects
KERNELBASE!WaitForMultipleObjectsEx
kernel32!WaitForMultipleObjectsExImplementation
kernel32!WerpReportFaultInternal
kernel32!WerpReportFault
kernel32!BasepReportFault
kernel32!UnhandledExceptionFilter
ntdll! ?? ::FNODOBFM::`string'
ntdll!_C_specific_handler
ntdll!RtlpExecuteHandlerForException
ntdll!RtlDispatchException
ntdll!KiUserExceptionDispatch
msvcrt!memcpy
mspaint!CImgWnd::CmdCrop
mspaint!CPBView::OnImageCrop
mfc42u!_AfxDispatchCmdMsg
mfc42u!CCmdTarget::OnCmdMsg
mfc42u!CView::OnCmdMsg
mspaint!CPBView::OnCmdMsg
mfc42u!CFrameWnd::OnCmdMsg
mspaint!CGenericCommandSite::XGenericCommandSiteCommandHandler::Execute
UIRibbon!CControlUser::_ExecuteOnHandler
UIRibbon!CGenericControlUser::SetValueImpl
UIRibbon!CGenericDataSource::SetValue
UIRibbon!OfficeSpace::DataSource::SetValue
UIRibbon!OfficeSpace::FSControl::SetValue
UIRibbon!NetUI::DeferCycle::ProcessDataBindingPropertyChangeRecords
UIRibbon!NetUI::DeferCycle::HrAddDataBindingPropertyChangeRecord
UIRibbon!NetUI::Binding::SetDataSourceValue
UIRibbon!NetUI::Bindings::OnBindingPropertyChanged
UIRibbon!NetUI::Node::OnPropertyChanged
UIRibbon!FlexUI::Concept::OnPropertyChanged
UIRibbon!NetUI::Node::FExecuteCommand
UIRibbon!FlexUI::ExecuteAction::OnCommand
UIRibbon!NetUI::Node::FExecuteCommand
UIRibbon!NetUI::SimpleButton::OnEvent
UIRibbon!NetUI::Element::_DisplayNodeCallback
UIRibbon!GPCB::xwInvokeDirect
UIRibbon!GPCB::xwInvokeFull
UIRibbon!DUserSendEvent
UIRibbon!NetUI::Element::FireEvent
UIRibbon!NetUI::_FireClickEvent
UIRibbon!NetUI::SimpleButton::OnInput
UIRibbon!NetUI::Element::_DisplayNodeCallback
UIRibbon!GPCB::xwInvokeDirect
UIRibbon!GPCB::xwInvokeFull
UIRibbon!BaseMsgQ::xwProcessNL
UIRibbon!DelayedMsgQ::xwProcessDelayedNL
UIRibbon!ContextLock::~ContextLock
UIRibbon!HWndContainer::xdHandleMessage
UIRibbon!ExtraInfoWndProc
user32!UserCallWinProcCheckWow
user32!DispatchMessageWorker
mfc42u!CWinThread::PumpMessage
mfc42u!CWinThread::Run
mfc42u!AfxWinMain
mspaint!LDunscale
kernel32!BaseThreadInitThunk
ntdll!RtlUserThreadStart

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