Crash Dump Analysis Patterns (Part 264)

February 27th, 2020

Interrupts can happen in either kernel or user mode. In the latter case, upon transition to kernel mode, a special memory region in is used for interrupt processing in kernel space, distinct from the thread’s kernel stack, that we call Interrupt Stack. It can also be used for mining Execution Residue.

2: kd> !thread -1 1f
THREAD fffffa801a9fa3e0  Cid 0f74.0804  Teb: 000007ffffdf8000 Win32Thread: 0000000000000000 RUNNING on processor 2
Not impersonating
DeviceMap                 fffff88000007400
Owning Process            fffffa801a949c10       Image:         App.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      81642662       Ticks: 0
Context Switch Count      58671950       IdealProcessor: 4
UserTime                  01:33:39.702
KernelTime                00:01:11.401
Win32 Start Address 0x000007fef9b1050c
Stack Init fffffa6005af4db0 Current fffffa6005af4950
Base fffffa6005af5000 Limit fffffa6005aef000 Call 0

Priority 8 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffffa60`01793b98 fffff800`01a58eee nt!KeBugCheckEx
fffffa60`01793ba0 fffff800`01a57dcb nt!KiBugCheckDispatch+0×6e
fffffa60`01793ce0 fffffa60`00eb279b nt!KiPageFault+0×20b (TrapFrame @ fffffa60`01793ce0)
fffffa60`01793e70 fffffa60`00e62739 tcpip! ?? ::FNODOBFM::`string’+0×3883b
fffffa60`01794020 fffffa60`00e62194 tcpip!TcpMatchReceive+0×1b9
fffffa60`01794120 fffffa60`00e52ddd tcpip!TcpPreValidatedReceive+0×2e4
fffffa60`017941c0 fffffa60`00e52e89 tcpip!IppDeliverListToProtocol+0×4d
fffffa60`01794280 fffffa60`00e52463 tcpip!IppProcessDeliverList+0×59
fffffa60`017942f0 fffffa60`00e5176c tcpip!IppReceiveHeaderBatch+0×223
fffffa60`017943d0 fffffa60`00e50d54 tcpip!IpFlcReceivePackets+0×8dc
fffffa60`017945d0 fffffa60`00e61133 tcpip!FlpReceiveNonPreValidatedNetBufferListChain+0×264
fffffa60`017946b0 fffffa60`009a40bc tcpip!FlReceiveNetBufferListChain+0xd3
fffffa60`01794700 fffffa60`0096c8c9 NDIS!ndisMIndicateNetBufferListsToOpen+0xac
fffffa60`01794750 fffffa60`008016f7 NDIS!ndisMDispatchReceiveNetBufferLists+0×1d9
fffffa60`01794bd0 fffffa60`02b4e2d3 NDIS!NdisMIndicateReceiveNetBufferLists+0×67
fffffa60`01794c10 fffffa60`02b3de0c Driver+0×152d3
fffffa60`01794de0 fffffa60`02b3df6b Driver+0×4e0c
fffffa60`01794e20 fffffa60`02b3e0b3 Driver+0×4f6b
fffffa60`01794e60 fffffa60`00801670 Driver+0×50b3
fffffa60`01794ec0 fffff800`01a5d367 NDIS!ndisInterruptDpc+0xc0
fffffa60`01794f40 fffff800`01a5bc35 nt!KiRetireDpcList+0×117
fffffa60`01794fb0 fffff800`01a5ba47 nt!KyRetireDpcList+0×5 (TrapFrame @ fffffa60`01794e70)
fffffa60`05af4bf0 fffff800`01aa1b28 nt!KiDispatchInterruptContinue
fffffa60`05af4c20 000007fe`f7e5c55a nt!KiDpcInterrupt+0xf8 (TrapFrame @ fffffa60`05af4c20)
00000000`4deae430 00000000`00000000 0×000007fe`f7e5c55a

2: kd> !address fffffa60`01794e60
Usage:
Base Address:           fffffa60`011ff000
End Address:            fffffa60`019dc000
Region Size:            00000000`007dd000

VA Type:                SystemDynamicSpace
VAD Address:            0×27676e69727473
Commit Charge:          0×244a0f51940
Protection:             0×244a0f51940 []
Memory Usage:           Private
No Change:              yes
More info:              !vad 0xfffffa60011ff000

2: kd> !address fffffa60`05af4c20
Usage:                  Stack
Base Address:           fffffa60`05aef000
End Address:            fffffa60`05af5000
Region Size:            00000000`00006000

VA Type:                SystemDynamicSpace

2: kd> dpS fffffa60`01793b98 fffffa60`01794fb0
[…]
fffffa60`05657c3f Driver2+0×4c3f
fffffa60`05656369 Driver2+0×3369

[…]
fffffa60`00801670 NDIS!ndisInterruptDpc+0xc0
fffff800`01a5d367 nt!KiRetireDpcList+0×117
fffff800`01a5bc35 nt!KyRetireDpcList+0×5
fffffa60`008015b0 NDIS!ndisInterruptDpc

2: kd> ub fffffa60`05657c3f
Driver2+0×4c25:
fffffa60`05657c25 8bf2            mov     esi,edx
fffffa60`05657c27 33d2            xor     edx,edx
fffffa60`05657c29 418be8          mov     ebp,r8d
fffffa60`05657c2c 488bd9          mov     rbx,rcx
fffffa60`05657c2f 448d4240        lea     r8d,[rdx+40h]
fffffa60`05657c33 488d48b8        lea     rcx,[rax-48h]
fffffa60`05657c37 418bf9          mov     edi,r9d
fffffa60`05657c3a e8010e0000      call    Driver2+0×5a40 (fffffa60`05658a40)

2: kd> ub fffffa60`05656369
Driver2+0×334d:
fffffa60`0565634d cc              int     3
fffffa60`0565634e cc              int     3
fffffa60`0565634f cc              int     3
fffffa60`05656350 4889542410      mov     qword ptr [rsp+10h],rdx
fffffa60`05656355 48894c2408      mov     qword ptr [rsp+8],rcx
fffffa60`0565635a 4883ec58        sub     rsp,58h
fffffa60`0565635e 488d4c2428      lea     rcx,[rsp+28h]
fffffa60`05656363 ff15972c0000    call    qword ptr [Driver2+0×6000 (fffffa60`05659000)]

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

Hidden Artifact Patterns

February 23rd, 2020

A page to reference all different kinds of patterns related to uncovering hidden entities, artifacts, and actions 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 -

Crash Dump Analysis Patterns (Part 263)

February 21st, 2020

Sometimes, when we have One-Thread Process memory dumps, it is possible to get other stack regions indirectly through the analysis of virtual memory regions. Consider, for example, this dump that has only one process exit thread:

0:000> kL
# Child-SP          RetAddr           Call Site
00 000000f1`828ff848 00007ff9`d29aa9b8 ntdll!NtTerminateProcess+0x14
01 000000f1`828ff850 00007ff9`d113cd8a ntdll!RtlExitUserProcess+0xb8
02 000000f1`828ff880 00007ff7`fbb91231 kernel32!ExitProcessImplementation+0xa
03 000000f1`828ff8b0 00007ff7`fbb9125f HiddenStack!bar1+0x41
04 000000f1`828ffa80 00007ff7`fbb91cb5 HiddenStack!foo1+0x1f
05 000000f1`828ffc40 00007ff7`fbb91b1b HiddenStack!std::_Invoker_functor::_Call<void (__cdecl*)(void)>+0x15
06 000000f1`828ffc70 00007ff7`fbb917c4 HiddenStack!std::invoke<void (__cdecl*)(void)>+0x1b
07 000000f1`828ffca0 00007ff7`fbb99728 HiddenStack!std::thread::_Invoke<std::tuple<void (__cdecl*)(void)>,0>+0x64
08 000000f1`828ffcf0 00007ff9`d1137bd4 HiddenStack!thread_start<unsigned int (__cdecl*)(void *),1>+0x50
09 000000f1`828ffd20 00007ff9`d29aced1 kernel32!BaseThreadInitThunk+0x14
0a 000000f1`828ffd50 00000000`00000000 ntdll!RtlUserThreadStart+0x21

There are no more thread stack traces:

0:000> ~
. 0 Id: 27d4.22a4 Suspend: -1 Teb: 000000f1`8266a000 Unfrozen

However, in addition to thread #0, we can find several regions having PAGE_GUARD protection:

0:000> !address
[...]
+       f1`82800000       f1`828fb000        0`000fb000 MEM_PRIVATE MEM_RESERVE                                    Stack      [~0; 27d4.22a4]
f1`828fb000       f1`828fe000        0`00003000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE|PAGE_GUARD          Stack      [~0; 27d4.22a4]
f1`828fe000       f1`82900000        0`00002000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE                     Stack      [~0; 27d4.22a4]
+       f1`82900000       f1`829fb000        0`000fb000 MEM_PRIVATE MEM_RESERVE                                    <unknown>
f1`829fb000       f1`829fe000        0`00003000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE|PAGE_GUARD          <unknown>
f1`829fe000       f1`82a00000        0`00002000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE                     <unknown>  […………….]
+       f1`82a00000       f1`82afc000        0`000fc000 MEM_PRIVATE MEM_RESERVE                                    <unknown>
f1`82afc000       f1`82aff000        0`00003000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE|PAGE_GUARD          <unknown>
f1`82aff000       f1`82b00000        0`00001000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE                     <unknown>  […………….]
+       f1`82b00000       f1`82bfb000        0`000fb000 MEM_PRIVATE MEM_RESERVE                                    <unknown>
f1`82bfb000       f1`82bfe000        0`00003000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE|PAGE_GUARD          <unknown>
f1`82bfe000       f1`82c00000        0`00002000 MEM_PRIVATE MEM_COMMIT  PAGE_READWRITE                     <unknown>  […………….]
+       f1`82c00000      1fe`828f0000      10c`ffcf0000             MEM_FREE    PAGE_NOACCESS                      Free
[…]

We then can get Rough Stack Traces out of them:

0:000> .lines -d
Line number information will not be loaded

0:000> dpS f1`829fe000       f1`82a00000
00007ff9`d2986139 ntdll!RtlpFindEntry+0×4d
00007ff9`d297dbea ntdll!RtlpAllocateHeap+0xcfa
00007ff9`d297babb ntdll!RtlpAllocateHeapInternal+0×1cb
00007ff9`d297babb ntdll!RtlpAllocateHeapInternal+0×1cb
00007ff9`d2a463fa ntdll!RtlpValidateHeap+0×32
00007ff9`d2a44b25 ntdll!RtlDebugAllocateHeap+0×35d
00007ff9`d29f49d6 ntdll!RtlpAllocateHeap+0×77ae6
00007ff9`d29f49d6 ntdll!RtlpAllocateHeap+0×77ae6
00007ff9`d0070000 KERNELBASE!UrlHashW <PERF> (KERNELBASE+0×0)
00007ff9`d007b4b1 KERNELBASE!SetTEBLangID+0×2d
00007ff9`d007ac70 KERNELBASE!_KernelBaseBaseDllInitialize+0×90
00007ff9`d297babb ntdll!RtlpAllocateHeapInternal+0×1cb
00007ff9`d297babb ntdll!RtlpAllocateHeapInternal+0×1cb
00007ff9`d19e7890 msvcrt!CRTDLL_INIT
00007ff9`d29db5a3 ntdll!RTL_BINARY_ARRAY<RTLP_FLS_SLOT,8,4>::ChunkAllocate+0×67
00007ff9`d19e0000 msvcrt!`dynamic initializer for ‘__ExceptionPtr::m_badAllocExceptionPtr” <PERF> (msvcrt+0×0)
00007ff9`d29db65d ntdll!RTL_BINARY_ARRAY<RTLP_FLS_SLOT,8,4>::SetValue+0×39
00007ff9`d2964ef7 ntdll!RtlDeactivateActivationContextUnsafeFast+0xc7
00007ff9`d299439c ntdll!RtlFlsSetValue+0xec
00007ff9`d2986139 ntdll!RtlpFindEntry+0×4d
00000000`7ffe0301 SharedUserData+0×301
00007ff9`d297dbea ntdll!RtlpAllocateHeap+0xcfa
00000000`7ffe0358 SharedUserData+0×358
00007ff7`fbb923ca HiddenStack!std::chrono::duration_cast<std::chrono::duration<double,
std::ratio<1,1000000000> >,__int64,std::ratio<1,1000000000>,void>+0×4a
00000000`7ffe0358 SharedUserData+0×358
00007ff9`d294bb47 ntdll!RtlGetSystemTimePrecise+0×57
00007ff9`d00b6931 KERNELBASE!SleepEx+0xa1
00007ff9`d00d3890 KERNELBASE!GetSystemTimePreciseAsFileTime+0×10
00007ff7`fbb931b4 HiddenStack!_Thrd_sleep+0×3c
00007ff7`fbb916c5 HiddenStack!std::this_thread::sleep_until<std::chrono::steady_clock,
std::chrono::duration<__int64,std::ratio<1,1000000000> > >+0×65
00007ff7`fbb91651 HiddenStack!std::chrono::operator+<std::chrono::steady_clock,
std::chrono::duration<__int64,std::ratio<1,1000000000> >,__int64,std::ratio<1,1> >+0×41
00007ff7`fbb913fd HiddenStack!std::this_thread::sleep_for<__int64,std::ratio<1,1> >+0×2d
00007ff7`fbb912a9 HiddenStack!bar2+0×39
00007ff7`fbb912df HiddenStack!foo2+0×1f
00007ff7`fbb91cb5 HiddenStack!std::_Invoker_functor::_Call<void (__cdecl*)(void)>+0×15
00007ff7`fbb91aec HiddenStack!std::unique_ptr<std::tuple<void (__cdecl*)(void)>,std::default_delete<std::tuple<void (__cdecl*)(void)> > >::unique_ptr<std::tuple<void (__cdecl*)(void)>,std::default_delete<std::tuple<void (__cdecl*)(void)> > ><std::default_delete<std::tuple<void (__cdecl*)(void)> >,0>+0×2c
00007ff7`fbb91b1b HiddenStack!std::invoke<void (__cdecl*)(void)>+0×1b
00007ff7`fbb917c4 HiddenStack!std::thread::_Invoke<std::tuple<void (__cdecl*)(void)>,0>+0×64
00007ff7`fbb9c1d7 HiddenStack!__acrt_getptd+0xb3
00007ff7`fbb99728 HiddenStack!thread_start<unsigned int (__cdecl*)(void *),1>+0×50
00007ff9`d1137bd4 kernel32!BaseThreadInitThunk+0×14
00007ff9`d29aced1 ntdll!RtlUserThreadStart+0×21

0:000> dpS f1`82aff000       f1`82b00000
00007ff9`d2986139 ntdll!RtlpFindEntry+0×4d
00007ff9`d297dbea ntdll!RtlpAllocateHeap+0xcfa
00007ff9`d297dbea ntdll!RtlpAllocateHeap+0xcfa
00007ff9`d297babb ntdll!RtlpAllocateHeapInternal+0×1cb
00007ff9`d2a463fa ntdll!RtlpValidateHeap+0×32
00007ff9`d2a463fa ntdll!RtlpValidateHeap+0×32
00007ff9`d2a44b25 ntdll!RtlDebugAllocateHeap+0×35d
00007ff9`d29f49d6 ntdll!RtlpAllocateHeap+0×77ae6
00007ff9`d2962da8 ntdll!LdrpInitializeThread+0×40
00007ff9`d297562f ntdll!TppCallbackCheckThreadAfterCallback+0×9f
00007ff9`d29700e5 ntdll!RtlRegisterThreadWithCsrss+0×35
00007ff9`d29b18f5 ntdll!_LdrpInitialize+0×89
00007ff9`d2975394 ntdll!TppCallbackEpilog+0×144
00007ff9`d29701d6 ntdll!TppCritSetThread+0×7a
00007ff9`d2973155 ntdll!TppWorkCallbackPrologRelease+0×1c9
00007ff9`d296e2c3 ntdll!LdrpWorkCallback+0×63
00007ff9`d2aa52f0 ntdll!LdrpWorkQueue
00007ff9`d29708a2 ntdll!TppWorkpExecuteCallback+0xb2
00000000`7ffe0386 SharedUserData+0×386
00007ff9`d2974060 ntdll!TppWorkerThread+0×300
00007ff9`d1137bd4 kernel32!BaseThreadInitThunk+0×14
00007ff9`d29aced1 ntdll!RtlUserThreadStart+0×21

0:000> dpS f1`82bfe000       f1`82c00000
00007ff9`d2986139 ntdll!RtlpFindEntry+0×4d
00007ff9`d297dbea ntdll!RtlpAllocateHeap+0xcfa
00007ff9`d297dbea ntdll!RtlpAllocateHeap+0xcfa
00007ff9`d297babb ntdll!RtlpAllocateHeapInternal+0×1cb
00007ff9`d2a463fa ntdll!RtlpValidateHeap+0×32
00007ff9`d2a463fa ntdll!RtlpValidateHeap+0×32
00007ff9`d2a44b25 ntdll!RtlDebugAllocateHeap+0×35d
00007ff9`d29f49d6 ntdll!RtlpAllocateHeap+0×77ae6
00007ff9`d2962da8 ntdll!LdrpInitializeThread+0×40
00007ff9`d29700e5 ntdll!RtlRegisterThreadWithCsrss+0×35
00007ff9`d29b18f5 ntdll!_LdrpInitialize+0×89
00007ff9`d297babb ntdll!RtlpAllocateHeapInternal+0×1cb
00007ff9`d29701d6 ntdll!TppCritSetThread+0×7a
00007ff9`d2970098 ntdll!TppPoolAddWorker+0×68
00007ff9`d2974060 ntdll!TppWorkerThread+0×300
00007ff9`d1137bd4 kernel32!BaseThreadInitThunk+0×14
00007ff9`d29aced1 ntdll!RtlUserThreadStart+0×21

We call such analysis pattern Hidden Stack as another way to get Historical Information from memory dumps.

The example memory dump, the application PDB file, and source code can be downloaded from here.

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

Crash Dump Analysis Patterns (Part 262)

November 30th, 2019

Full symbol files usually include source code information for UI debugging. Debuggers, like WinDbg, may show it for each relevant stack trace frame:

0:001> k
# Child-SP          RetAddr           Call Site
00 00000074`fe5fe3c8 00007ff9`72937ff7 ntdll!NtWaitForMultipleObjects+0x14
01 00000074`fe5fe3d0 00007ff9`72937ede KERNELBASE!WaitForMultipleObjectsEx+0x107
02 00000074`fe5fe6d0 00007ff9`74a671fb KERNELBASE!WaitForMultipleObjects+0xe
03 00000074`fe5fe710 00007ff9`74a66ca8 kernel32!WerpReportFaultInternal+0x51b
04 00000074`fe5fe830 00007ff9`729df848 kernel32!WerpReportFault+0xac
05 00000074`fe5fe870 00007ff9`75304af2 KERNELBASE!UnhandledExceptionFilter+0x3b8
06 00000074`fe5fe990 00007ff9`752ec6d6 ntdll!RtlUserThreadStart$filt$0+0xa2
07 00000074`fe5fe9d0 00007ff9`753011ff ntdll!_C_specific_handler+0x96
08 00000074`fe5fea40 00007ff9`752ca289 ntdll!RtlpExecuteHandlerForException+0xf
09 00000074`fe5fea70 00007ff9`752ffe6e ntdll!RtlDispatchException+0x219
0a 00000074`fe5ff180 00007ff7`bbd51cb0 ntdll!KiUserExceptionDispatch+0x2e
0b 00000074`fe5ff930 00007ff7`bbd51983 SourceStackTrace!std::_Deque_unchecked_const_iterator<std::_Deque_val< std::_Deque_simple_types<int> > >::operator*+0x50 [C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\VC\Tools\MSVC\14.23.28105\include\deque @ 55]
0c 00000074`fe5ff970 00007ff7`bbd51883 SourceStackTrace!std::_Deque_unchecked_iterator<std::_Deque_val< std::_Deque_simple_types<int> > >::operator*+0×13 [C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\VC\Tools\MSVC\14.23.28105\include\deque @ 175]
0d 00000074`fe5ff9a0 00007ff7`bbd515f6 SourceStackTrace!std::deque<int,std::allocator<int> >::back+0×33 [C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\VC\Tools\MSVC\14.23.28105\include\deque @ 1091]
0e 00000074`fe5ff9f0 00007ff7`bbd5156c SourceStackTrace!std::stack<int,std::deque<int,std::allocator<int> > >::top+0×16 [C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\VC\Tools\MSVC\14.23.28105\include\stack @ 66]
0f 00000074`fe5ffa20 00007ff7`bbd521a3 SourceStackTrace!Info::gather+0×3c [C:\NewWork\SourceStackTrace\InfoGather.cpp @ 9]
10 00000074`fe5ffa90 00007ff7`bbd5108d SourceStackTrace!Info::scatter+0×13 [C:\NewWork\SourceStackTrace\InfoScatter.cpp @ 6]
11 00000074`fe5ffac0 00007ff7`bbd510a9 SourceStackTrace!worker_bar+0×1d [C:\NewWork\SourceStackTrace\bar.cpp @ 10]
12 00000074`fe5ffb00 00007ff7`bbd522b9 SourceStackTrace!worker_foo+0×9 [C:\NewWork\SourceStackTrace\foo.cpp @ 6]
13 00000074`fe5ffb30 00007ff7`bbd526b5 SourceStackTrace!worker+0×9 [C:\NewWork\SourceStackTrace\SourceStackTrace.cpp @ 8]
14 00000074`fe5ffb60 00007ff7`bbd5269b SourceStackTrace!std::_Invoker_functor::_Call<void (__cdecl*)(void)>+0×15 [C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\VC\Tools\MSVC\14.23.28105\include\type_traits @ 1571]
15 00000074`fe5ffb90 00007ff7`bbd525d4 SourceStackTrace!std::invoke<void (__cdecl*)(void)>+0×1b [C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\VC\Tools\MSVC\14.23.28105\include\type_traits @ 1571]
16 00000074`fe5ffbc0 00007ff7`bbd59784 SourceStackTrace!std::thread::_Invoke<std::tuple<void (__cdecl*)(void)>,0>+0×64 [C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\VC\Tools\MSVC\14.23.28105\include\thread @ 40]
17 00000074`fe5ffc10 00007ff9`74a17bd4 SourceStackTrace!thread_start<unsigned int (__cdecl*)(void *),1>+0×50 [minkernel\crts\ucrt\src\appcrt\startup\thread.cpp @ 97]
18 00000074`fe5ffc40 00007ff9`752cced1 kernel32!BaseThreadInitThunk+0×14
19 00000074`fe5ffc70 00000000`00000000 ntdll!RtlUserThreadStart+0×21

Such Source Stack Trace frames has a similar structure as native module!function+offset format and can be mined as well including most of traditional stack trace patterns:

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

Trace Analysis Patterns (Part 181)

November 6th, 2019

Message Flow trace and log analysis pattern generalizes NetFlow to software narratives. We count messages based on the set of Adjoint Threads of Activity, for example PID.TID. This also subsumes network traces aggregated by Src.Dst. Individual single attributes can also be used, for example, aggregation by Thread of Activity, and also by Message Sets.

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

Trace Analysis Patterns (Part 180)

October 17th, 2019

Traces and logs may show drastic qualitative and quantitative pattern changes. We call this analysis pattern Phase Transition by analogy with phase transitions in physical, biological and other complex systems. Usually the goal of the analysis is to find a parameter that caused such transition. Here are a few examples which are self-explanatory.

Change in Statement Density and Current:

Sudden proliferation of (Adjoint) Threads of Activity:

Discontinuity of Activity Region with only Drone Messages left:

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

Crash Dump Analysis Patterns (Part 261)

October 13th, 2019

Raw stack memory region analysis is more productive with Region Clusters analysis pattern. Here we apply simple clustering techniques to organize various region values into disjoint sets with chosen semantics. For our purposes simple sort suffices to generate such clusters that can be visually inspected. We take the same stack.csv file from Region Profile analysis pattern. It’s values are sorted and the results are shown in sorted order with corresponding count of occurrences and symbolic references (we use the internal version of Narrascope written in C++, a narrative debugger, but you can use your favorite scripting language here):

0 count: 13718
1 count: 273
2 count: 23
3 count: 22
4 count: 28
5 count: 9
6 count: 5
7 count: 18
8 count: 35
9 count: 5
a count: 24
b count: 12
c count: 4
d count: 3
e count: 1
f count: 28
10 count: 14
...
c0000034 count: 2
c0000388 count: 2
c01c0001 count: 1
c0a70000 count: 1
d0908070 count: 1
dcae0fa0 count: 1
e30000e3 count: 1
f80004fc count: 2
ffff5815 count: 2
fffffed3 count: 2
fffffffd count: 2
ffffffff count: 18
100000000 count: 6
100000001 count: 4
100001f80 count: 1
100001fa0 count: 16
100001fa4 count: 2
100003033 count: 2
100010000 count: 1
...
7ff700000000 count: 1
7ff700000001 count: 2
7ff70000000d count: 1
7ff747390000 Photoshop_exe count: 1
7ff74ebd4ec0 Photoshop_exe+0x7844ec0 count: 1
7ff74ef351c7 Photoshop_exe+0x7ba51c7 count: 1
7ff74ef4e2f0 Photoshop_exe+0x7bbe2f0 count: 1
7ff74ef4e5a9 Photoshop_exe+0x7bbe5a9 count: 1
...
7fff00000000 count: 21
7fff00000001 count: 7
7fff00000002 count: 1
7fff00000003 count: 1
7fff00000004 count: 1
7fff00000011 count: 1
7fff00000020 count: 1
7fff00000040 count: 3
7fff00000102 count: 1
7fff0000029e count: 3
7fff00140000 count: 1
7fff02000002 count: 1
7fff4782c33b libcef!GetHandleVerifier+0x61d7b count: 1
7fff4782c884 libcef!GetHandleVerifier+0x622c4 count: 1
7fff493749cc libcef!cef_time_to_timet+0x1a9228 count: 2
...
7fff9a0c1e57 GdiPlus!GpGraphics::MeasureString+0x333 count: 1
7fff9a128c2a GdiPlus!FastTextImager::MeasureString+0x32 count: 1
7fff9a174e18 GdiPlus!GpFontFamily::vftable' count: 2
7fff9b6055b3 DWrite!FontFace::GetDesignGlyphAdvances+0x57 count: 1
7fffa7e6c260 comctl32!ListBox_WndProc count: 5
7fffa7e6c357 comctl32!ListBox_WndProc+0xf7 count: 2
7fffb1373c18 npmproxy!INotifyNetworkListManagerEventsProxyVtbl+0x1b8 count: 1
7fffb2c14e96 msvcp140!_Mbrtowc+0x66 [f:\dd\vctools\crt\crtw32\stdcpp\xmbtowc.c @ 156] count: 1
...
7fffc09f0359 ntdll!qsort+0x379 count: 1
7fffc09fa1e4 ntdll!woutput_s+0x8e8 count: 1
7fffc09fa297 ntdll!write_string+0x3f count: 1
7fffc09fbd30 ntdll!NtdllDefWindowProc_W count: 2
7fffc09fbf10 ntdll!NtdllDispatchHook_W count: 2
7fffc09ffc54 ntdll!KiUserCallForwarder+0x24 count: 1
7fffc09ffdb4 ntdll!KiUserCallbackDispatcherContinue count: 2
800000000000 count: 1
800000000001 count: 2
800063640000 count: 36
800066660000 count: 38
80006f6f0000 count: 2
800072720000 count: 8
800075750000 count: 1
974b00000000 count: 1
974b8118d10d count: 1
a76b00000000 count: 1
a76bb8365307 count: 1
a76bb8378c47 count: 1
a76bb8378f77 count: 1
a76bb837bfd7 count: 1
a8c300000000 count: 1
a8c311cf265f count: 1
...
30000000000000 count: 1
30000000310030 count: 1
30000300470048 count: 1
30002000100000 count: 1
3000300030007b count: 1
3000300031002d count: 1
30003000310031 count: 2
300031002d0037 count: 1
30003800390032 count: 3
31000000000000 count: 1
310000007d0036 count: 1
31002d00310037 count: 1
310032002d0035 count: 1
...
7fdf7fbd7f9c7f7b count: 2
8000800000000001 count: 1
8000800000001fa0 count: 1
8000800080000000 count: 6
8000800080008000 count: 52
80121a254b25250a count: 1
923800003f000000 count: 2
bf000000bf000000 count: 1
bff0000000000000 count: 2
e5b2a56118358cbe count: 2
ffff0072656c6c6f count: 1
fffffdb773438b57 count: 3
ffffff0000000005 count: 1
ffffff7bc010786f count: 1
ffffff7bc010787f count: 1
fffffffb00000000 count: 1
ffffffff00000000 count: 4
ffffffff00000001 count: 3
ffffffff00000005 count: 1
ffffffff00001fa0 count: 2
ffffffff4c494146 count: 2
ffffffffffffc3ce count: 1
fffffffffffffef6 count: 1
ffffffffffffff00 count: 2
ffffffffffffff01 count: 2
fffffffffffffffe count: 166
ffffffffffffffff count: 38

We can easily identify error values, module boundaries, and Regular Data. The sorting can also be done for double word or word values, for example to isolate errors or wide character values, but this will have to be seen whether it is useful.

This clustering approach can be depicted in the following idealized diagram:

The full output can be found here: stack-clusters.txt for stack.csv file.

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

Trace Analysis Patterns (Part 179)

October 2nd, 2019

Depending on tracing architecture we may have trace or log messages split into several statements. For example, some API and library tracing tools may log a function call after it returns with a result, but some tools or tracing libraries may log calls in the context of corresponding threads and, therefore, be preempted by other tracing and logging threads, and even interrupted. In the latter cases we may have Split Message like depicted in the following diagram:

Typical example here is Linux strace. We can recognize such messages by their Message Invariant and Ornament.

Split Message is different from Opposition Messages analysis pattern where we have messages logged from different source code tracing statements, when, for example, a function call result is logged separately. But, in the same vein, when we see an unfinished Split Message we may assume some sort of Discontinuity.

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

Crash Dump Analysis Patterns (Part 260)

September 27th, 2019

Manual analysis of Execution Residue in stack regions can be quite daunting so some basic statistics on the distribution of address, value, and symbolic information can be useful. To automate this process we use Pandas python library and interpret preprocessed WinDbg output of dps and dpp commands as DataFrame object:

import pandas as pd
import pandas_profiling

df = pd.read_csv("stack.csv")
html_file = open("stack.html", "w")
html_file.write (pandas_profiling.ProfileReport(df).to_html())
html_file.close()

We get a rudimentary profile report: stack.html for stack.csv file. The same was also done for Address, Address/Value, Value, Symbol output of dpp command: stack4columns.html for stack4columns.csv file.

We call this analysis pattern Region Profile since any Memory Region can be used. This analysis pattern is not limited to Python/Pandas and different libraries/scripts/script languages can also be used for statistical and correlational profiling. We plan to provide more examples here in the future.

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

Trace Analysis Patterns (Part 178)

September 15th, 2019

When we analyze a trace or log we may produce CoTrace of analyzed messages and visited regions. But the ultimate goal of any trace and log analysis is to construct the explanation of the observed behavoir to justify the root cause analysis and the proposed mechanism. There may be several proposed explanations each having a different set of messages from the analyzed trace that illustrate them. We call them Explanation Traces. This is illustrated in the picture where we use the same trace from CoTrace analysis pattern.

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

Crash Dump Analysis Patterns (Part 259)

September 1st, 2019

Sometimes we have complex plugins or subsystems consisting from several modules that are loaded in the same process address space (and this is also possible in kernel space as well). Usually subsystem components reside in the same persistent folder (including its possible subfolders):

0:000> lmf
start             end                 module name
...
00007fff`46ee0000 00007fff`4cde8000 libcef C:\Program Files\Adobe\Adobe Photoshop CC 2019\Required\Plug-ins\Spaces\libcef.dll

00007fff`7fa40000 00007fff`7fbc2000 Spaces C:\Program Files\Adobe\Adobe Photoshop CC 2019\Required\Plug-ins\Spaces\Spaces.8li

00007fff`8ba50000 00007fff`8bae3000 chrome_elf C:\Program Files\Adobe\Adobe Photoshop CC 2019\Required\Plug-ins\Spaces\chrome_elf.dll

When we know product architecture we can group modules according to the known design not only by their physical locations.

This analysis pattern, that we call Subsystem Modules, is useful for the analysis of possibles relationships of Stack Traces from Stack Trace Collections and other Historical Information during the root cause analysis of various crash and hang issues. This can also be applicable to .NET managed space analysis that includes various multi-file assemblies.

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

Trace Analysis Patterns (Part 177)

July 30th, 2019

Trace Similarity analysis pattern uses various similarity measures to assess the closeness of one trace or log to another. Here we provide an illustrative example using Jaccard index. Consider three simple logs where sample sets consist from Activity Regions:

The following table shows calculation of similarity between A and B, A and C, and B and C:

It’s possible to use sample sets consisting of messages instead. For our toy example we get similar index numbers:

We get different indexes though for individual regions and messages, for example:

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

Trace Analysis Patterns (Part 176)

July 27th, 2019

In addition to Declarative Trace we have code statements that may be intercepted by external API tracing tools (CreateFile, CloseHandle):

In the sample code above we have different logs resulted from Declarative Trace (DebugLog, OutputDebugString):


In addition, we have a log saved by an external tracing tool (for example, Process Monitor) that includes our API calls:

All such trace-generating source code statements form Moduli Trace as soon as they are executed:

Such a trace can also be analyzed using trace and log analysis patterns like other trace types. We took the idea of this analysis pattern from moduli spaces in mathematics that parametrize other spaces.

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

Trace Analysis Patterns (Part 175)

July 21st, 2019

When we do trace and log analysis (and software data in general) we look at specific messages found from search (Message Patterns), Error Messages, Significant Events, visit Activity Regions, filter Message Sets, walk through (Adjoint) Threads of Activity, and do other actions necessitated by trace and log analysis patterns. All these can be done in random order (starting from some analysis point), not necessarily representing the flow of Time or some other metric:

Analyzed messages form their own analysis trace that we call CoTrace (CoLog, CoData) where the prefix Co- denotes a space dual to trace (log, data) space:

Instead of messages (or in addition to) we can also form CoTraces consisting of visited Activity Regions or some other areas:

We can apply trace analysis patterns to CoTraces as well. The latter can also be used in creation of higher-order pattern narratives.

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

Trace Analysis Patterns (Part 174)

July 20th, 2019

Message Annotations analysis pattern was on our list for years so it’s time to add it to trace and log analysis pattern catalog. We also allow several annotations per trace message done at different times and annotating different parts depending on the analysis flow (the topic of the next analysis pattern). Attached to log messages annotations form their own Adjoint Thread of Activity. However, sorted by their annotation time or sequence we get a different trace that we call Annotation Trace (an example of analysis narrative). We can apply all relevant analysis patterns to both traces. A sketch of this pattern is depicted in the following diagram:

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

Trace Analysis Patterns (Part 173)

July 16th, 2019

Cartesian Trace analysis pattern has its analogical roots in Cartesian product. It covers a case where we have a long trace and a few Small DA+TA configuration traces (files). The former trace messages are associated with the latter messages (content or content changes) as depicted in the following diagram:

Think about a rectangle as a product of two line fragments or a cylinder as a product of a circle and a line fragment. Both traces are completely independent in comparison to Fiber Bundle, Trace Presheaf, or Trace Extension.

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

Trace Analysis Patterns (Part 172)

July 14th, 2019

Some trace and log messages may have different grammatical structure and content but similar semantics. Therefore, we can create a table listing equivalent messages (using some equivalence relation) and use it to construct simpler traces and logs as depicted in this picture:

One trivial example of Equivalent Messages analysis pattern is Quotient Trace. Another example is Inter-Correlational analysis of logs that have different structure and format. In such a case Equivalent Messages simplify the analysis of higher Trace Dimensions.

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

Trace Analysis Patterns (Part 171)

July 10th, 2019

Log message “frequencies” in time domain (Statement Current part) are addressed by Fourier Activity analysis pattern. However, we may have varying message density (Statement Density part) across different trace runs (space domain, irrespective of time irregularities):

According to OED, in computing and mathematics a string means “a linear sequence of records or data” and “a sequence of symbols or linguistic elements in a definite order”. So we propose to name this pattern that analyzes densities of messages or Activity Regions as Trace String. Such longitudinal “vibrations” can be compared and analyzed for anomalies across different log runs (Inter-Correlation) or across similar regions in the same log (Intra-Correlation). Here we consider message density change as a one-dimensional displacement. The analogy for this pattern came from one-dimensional vibrating strings (dual resonance model from 1969-70 by Nambu, Nielsen, and Leonard Susskind).

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

Trace Analysis Patterns (Part 170)

May 27th, 2019

The advent of virtualization simplified the debugging of complex issues by allowing to save the snapshot of the execution environment and then resume it from the save point of execution. This allows continuing tracing using a different set of environmental conditions and input data. New tracing continuations constitute a network that we call Polytrace:

Bifurcation Point for two identical trace beginnings may be considered as an example of a simple Polytrace.

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

Crash Dump Analysis Patterns (Part 16d)

May 23rd, 2019

Stack Overflow (user mode) analysis pattern relied on prominent stack trace signs. However, in cases of low memory condition there may not be an opportunity to create a new guard page for the expanding stack region and the exception itself may be Hidden Exception:

0:003> kc
# Call Site
00 KERNELBASE!GetModuleHandleExW
01 EdgeContent!wil::details::GetModuleInformation
02 EdgeContent!wil::details::GetCurrentModuleName
03 EdgeContent!wil::details::LogFailure
04 EdgeContent!wil::details::ReportFailure
05 EdgeContent!wil::details::ReportFailure_Hr
06 EdgeContent!wil::details::in1diag3::FailFast_Hr
07 EdgeContent!`anonymous namespace'::MemoryLimitWatchdogThreadProc
08 kernel32!BaseThreadInitThunk
09 ntdll!RtlUserThreadStart

0:003> .exr -1
ExceptionAddress: 00007ff992f6391b (KERNELBASE!GetModuleHandleExW+0x000000000000007b)
ExceptionCode: c00000fd (Stack overflow)
ExceptionFlags: 00000000
NumberParameters: 2
Parameter[0]: 0000000000000001
Parameter[1]: 000000fe709fdfc8

0:003> r
rax=0000000000000001 rbx=0000000000000006 rcx=00007ff945e3fa80
rdx=000000fe709fe020 rsi=00007ff945e3fa80 rdi=000000fe709fe030
rip=00007ff992f6391b rsp=000000fe709fdfd0 rbp=0000000000000040
r8=000000fe709fe030  r9=0000000000000040 r10=00000fff28bc7dba
r11=0440000001000010 r12=00007ff94606be60 r13=000000000000013f
r14=0000000000000003 r15=0000000000000000
iopl=0         nv up ei pl nz na pe nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010200
KERNELBASE!GetModuleHandleExW+0x7b:
00007ff9`92f6391b ff1597f31200    call    qword ptr [KERNELBASE!_imp_RtlPcToFileHeader (00007ff9`93092cb8)] ds:00007ff9`93092cb8={ntdll!RtlPcToFileHeader (00007ff9`960d0f50)}

The stack trace is short and the exception seem happened during call so we examine the stack pointer:

0:003> !address 000000fe709fdfd0
Usage:                  Stack
Base Address:           000000fe`709fb000
End Address:            000000fe`70a00000
Region Size:            00000000`00005000 (  20.000 kB)
State:                  00001000          MEM_COMMIT

Protect:                00000004          PAGE_READWRITE
Type:                   00020000          MEM_PRIVATE
Allocation Base:        000000fe`70900000
Allocation Protect:     00000004          PAGE_READWRITE

The committed stack region is very small so we expect its surrounding from the output of !address WinDbg command (without any address parameters):

Opened log file 'c:\MemoryDumps\stack.txt'
0:003> !address 000000fe709fdfd0
[...]
+ fe`70600000 fe`706fb000 0`000fb000 MEM_PRIVATE MEM_RESERVE Stack [~1; 1f50.21d4]
fe`706fb000 fe`706fe000 0`00003000 MEM_PRIVATE MEM_COMMIT PAGE_READWRITE|PAGE_GUARD Stack [~1; 1f50.21d4]
fe`706fe000 fe`70700000 0`00002000 MEM_PRIVATE MEM_COMMIT PAGE_READWRITE Stack [~1; 1f50.21d4]
+ fe`70700000 fe`70800000 0`00100000 MEM_FREE PAGE_NOACCESS Free
+ fe`70800000 fe`708f9000 0`000f9000 MEM_PRIVATE MEM_RESERVE Stack [~2; 1f50.460c]
fe`708f9000 fe`708fc000 0`00003000 MEM_PRIVATE MEM_COMMIT PAGE_READWRITE|PAGE_GUARD Stack [~2; 1f50.460c]
fe`708fc000 fe`70900000 0`00004000 MEM_PRIVATE MEM_COMMIT PAGE_READWRITE Stack [~2; 1f50.460c]
+ fe`70900000 fe`709fb000 0`000fb000 MEM_PRIVATE MEM_RESERVE Stack [~3; 1f50.4f80]
fe`709fb000 fe`70a00000 0`00005000 MEM_PRIVATE MEM_COMMIT PAGE_READWRITE Stack [~3; 1f50.4f80]

+ fe`70a00000 fe`70afc000 0`000fc000 MEM_PRIVATE MEM_RESERVE Stack [~4; 1f50.4ff4]
fe`70afc000 fe`70aff000 0`00003000 MEM_PRIVATE MEM_COMMIT PAGE_READWRITE|PAGE_GUARD Stack [~4; 1f50.4ff4]
fe`70aff000 fe`70b00000 0`00001000 MEM_PRIVATE MEM_COMMIT PAGE_READWRITE Stack [~4; 1f50.4ff4]
+ fe`70b00000 fe`70bf9000 0`000f9000 MEM_PRIVATE MEM_RESERVE Stack [~5; 1f50.5ea0]
fe`70bf9000 fe`70bfc000 0`00003000 MEM_PRIVATE MEM_COMMIT PAGE_READWRITE|PAGE_GUARD Stack [~5; 1f50.5ea0]
fe`70bfc000 fe`70c00000 0`00004000 MEM_PRIVATE MEM_COMMIT PAGE_READWRITE Stack [~5; 1f50.5ea0]
[…]

We see that there is no guard page for the stack ~3 compared to other stacks and there is plenty of reserved space before that to create a new guard page in the normal circumstances. We also recall that the stack overflow exception is about the inability to create a guard page:

0:003> !error c00000fd
Error code: (NTSTATUS) 0xc00000fd (3221225725) - A new guard page for the stack cannot be created.

Looking at Stack Trace Collection we find the thread ~11 that was doing System Call:

0:003> ~*kc
[...]

11  Id: 1f50.2424 Suspend: 1 Teb: 000000fe`6fec8000 Unfrozen
# Call Site
00 ntdll!NtAllocateVirtualMemory
01 KERNELBASE!VirtualAlloc
02 eShims!NS_ACGLockdownTelemetry::APIHook_VirtualAlloc
03 Chakra!Memory::VirtualAllocWrapper::AllocPages
[…]

For this thread the last error value show that there was low memory condition, perhaps the page file was full to create new committed pages:

0:003> ~11s
ntdll!NtAllocateVirtualMemory+0x14:
00007ff9`9615aca4 c3              ret

0:011> !teb
TEB at 000000fe6fec8000
ExceptionList:        0000000000000000
StackBase:            000000fe71e00000
StackLimit:           000000fe7140a000
SubSystemTib:         0000000000000000
FiberData:            0000000000001e00
ArbitraryUserPointer: 0000000000000000
Self:                 000000fe6fec8000
EnvironmentPointer:   0000000000000000
ClientId:             0000000000001f50 . 0000000000002424
RpcHandle:            0000000000000000
Tls Storage:          0000023c84be2c70
PEB Address:          000000fe6fe97000
LastErrorValue:       1455
LastStatusValue:      c000012d
Count Owned Locks:    0
HardErrorMode:        0

0:011> !error c000012d
Error code: (NTSTATUS) 0xc000012d (3221225773) - {Out of Virtual Memory}  Your system is low on virtual memory. To ensure that Windows runs properly, increase the size of your virtual memory paging file. For more information, see Help.

0:011> !error 0n1455
Error code: (Win32) 0x5af (1455) - The paging file is too small for this operation to complete.

Because the original analysis you see above was done on the memory dump from the working computer we are not able to provide that memory dump for security reasons. So, to model this behavior, we created an application that has two threads: one leaks committed virtual memory and when the next allocation fails it creates a separate thread that attempts to do stack overflow. We then launched 20 copies of that process to limit the size of the individual crash dump. The example memory dump and the application PDB file can be downloaded from here.

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