Software Diagnostics Library

Every trace and log has its own set of constants, values that belong to global namespace such as true/false, NULL, Abnormal Values, and common error constants such as “access denied”. Trace Constants may be dependent upon Implementation Discourse. There are also constant values that are local to each trace, for example, user names and IP addresses. They may be constantly repeated in one log but may change for another log. Constants that belong to local namespace may be a part of Vocabulary Index and Basic Facts. Usually Trace Constant is not considered Message Invariant.

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

If we run software with its default configuration and no interaction (input data) we get its Minimal Trace:

Such traces may have their own Master Trace. Also, Minimal Trace is a specific Use Case Trail. Metaphorically, they can be considered as minimal surfaces.

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

Sometimes we see a constantly repeated message throughout a trace or log (a trivial Periodic Message Block) with constant Time Delta. In certain trace forms (without explicit timing information) such messages may indicate internal time references as illustrated in the following diagram:

We name this pattern Drone Message based on analogy with Drone effect in music.

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

Based on a mathematical analogy with critical points in topology (Morse theory) we introduce Critical Points in trace and log analysis where they signify the change of trace or log “shape” (topological or “geometric” properties) as illustrated in the following diagram:

Such a point may be an individual message, its Message Context, or Activity Region.

Critical Points are examples of Intra-Correlation whereas Bifurcation Points are examples of Inter-Correlation.

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

When we have Active Thread:

0:001> kL
# Child-SP RetAddr Call Site
00 (Inline Function) --------`-------- Windows_Web!JsonParser::ParseString+0x96
01 0000007f`56efdb00 00007fff`700198c5 Windows_Web!JsonParser::ParseValue+0x3b7
02 0000007f`56efdb80 00007fff`70018ab3 Windows_Web!JsonParser::ParseArray+0xf5
03 0000007f`56efdbd0 00007fff`70018f72 Windows_Web!JsonParser::ParseValue+0x663
04 0000007f`56efdc50 00007fff`700186fb Windows_Web!JsonParser::ParseObject+0x422
05 0000007f`56efdda0 00007fff`700198c5 Windows_Web!JsonParser::ParseValue+0x2ab
06 0000007f`56efde20 00007fff`70018ab3 Windows_Web!JsonParser::ParseArray+0xf5
07 0000007f`56efde70 00007fff`70018f72 Windows_Web!JsonParser::ParseValue+0x663
08 0000007f`56efdef0 00007fff`700186fb Windows_Web!JsonParser::ParseObject+0x422
09 0000007f`56efe040 00007fff`70018f72 Windows_Web!JsonParser::ParseValue+0x2ab
0a 0000007f`56efe0c0 00007fff`700186fb Windows_Web!JsonParser::ParseObject+0x422
0b 0000007f`56efe210 00007fff`70011a69 Windows_Web!JsonParser::ParseValue+0x2ab
0c 0000007f`56efe290 00007fff`700119d2 Windows_Web!JsonValueImpl::ParseInternal+0x75
0d 0000007f`56efe2d0 00007fff`700118e8 Windows_Web!JsonValueImpl::InitializeFromString+0x16
0e 0000007f`56efe300 00007fff`70011876 Windows_Web!JsonValueFactory::TryParseInternal+0x50
0f 0000007f`56efe330 00007fff`3a6fe48e Windows_Web!JsonValueFactory::TryParse+0x36
10 0000007f`56efe360 00007fff`3a78f95c eModel!JsonUtils::GetJsonObject+0x82
[...]

which is also Spiking Thread:

0:001> !runaway f
User Mode Time
Thread Time
1:1a2c 0 days 0:03:37.562
8:52a8 0 days 0:00:36.890
[…]

Kernel Mode Time
Thread Time
8:52a8 0 days 0:00:10.625
1:1a2c 0 days 0:00:18.078
[...]

we can look at the relative proportion of User Mode / Kernel Mode times to infer Active Space. This can be further confirmed if we have Step Dumps, for example, in our case we had an earlier memory dump with the same Active Thread and Constant Subtrace (with Variable Subtraces in the same Active Space):

0:001> kL
# Child-SP RetAddr Call Site
00 0000007f`56efd8d0 00007fff`a1109453 ntdll!RtlpHpLfhSlotAllocate+0×126
01 0000007f`56efd9c0 00007fff`a110a8db ntdll!RtlpAllocateHeapInternal+0×313
02 0000007f`56efdaa0 00007fff`9ea09960 ntdll!RtlpHpAllocWithExceptionProtection+0×3b
03 0000007f`56efdb70 00007fff`7001ba1b msvcrt!malloc+0×70
04 0000007f`56efdba0 00007fff`700187ca Windows_Web!operator new+0×23
05 (Inline Function) ——–`——– Windows_Web!StringBuilder::EnsureBufferSpace+0×18
06 (Inline Function) ——–`——– Windows_Web!JsonParser::ParseString+0×59
07 0000007f`56efdbd0 00007fff`70018f72 Windows_Web!JsonParser::ParseValue+0×37a
08 0000007f`56efdc50 00007fff`700186fb Windows_Web!JsonParser::ParseObject+0×422
09 0000007f`56efdda0 00007fff`700198c5 Windows_Web!JsonParser::ParseValue+0×2ab
0a 0000007f`56efde20 00007fff`70018ab3 Windows_Web!JsonParser::ParseArray+0xf5
0b 0000007f`56efde70 00007fff`70018f72 Windows_Web!JsonParser::ParseValue+0×663
0c 0000007f`56efdef0 00007fff`700186fb Windows_Web!JsonParser::ParseObject+0×422
0d 0000007f`56efe040 00007fff`70018f72 Windows_Web!JsonParser::ParseValue+0×2ab
0e 0000007f`56efe0c0 00007fff`700186fb Windows_Web!JsonParser::ParseObject+0×422
0f 0000007f`56efe210 00007fff`70011a69 Windows_Web!JsonParser::ParseValue+0×2ab
10 0000007f`56efe290 00007fff`700119d2 Windows_Web!JsonValueImpl::ParseInternal+0×75
11 0000007f`56efe2d0 00007fff`700118e8 Windows_Web!JsonValueImpl::InitializeFromString+0×16
12 0000007f`56efe300 00007fff`70011876 Windows_Web!JsonValueFactory::TryParseInternal+0×50
13 0000007f`56efe330 00007fff`3a6fe48e Windows_Web!JsonValueFactory::TryParse+0×36
14 0000007f`56efe360 00007fff`3a78f95c eModel!JsonUtils::GetJsonObject+0×82
[…]

Even in the absence of Active Threads in process memory dumps it is useful to look at time spent in kernel and user modes to see any anomalies, especially when threads are blocked in System Calls. Then the high value of kernel mode time should suggest to inspect kernel Activity Space (for example, via a kernel dump). If we have an indication of high values of user mode time in a kernel memory dump we may need to obtain process memory Step Dumps.

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

In addition to Exception Thread analysis pattern (or several threads when we have Multiple Exceptions) that we named Exception Stack Trace there may be a separated thread that reports such exceptions (Exception Reporting Thread):

This dump file has an exception of interest stored in it.
The stored exception information can be accessed via .ecxr.
(4a0c.2ab4): Application hang - code cfffffff (first/second chance not available)
win32u!NtUserCreateWindowEx+0x14:

0:002> kc
# Call Site
00 win32u!NtUserCreateWindowEx
01 user32!VerNtUserCreateWindowEx
02 user32!CreateWindowInternal
03 user32!CreateWindowExW
04 CoreMessaging!Microsoft::CoreUI::Dispatch::UserAdapter:: InitializeWindow
05 CoreMessaging!Microsoft::CoreUI::Dispatch::UserAdapter::Initialize
06 CoreMessaging!Microsoft::CoreUI::Dispatch::EventLoop::Callback_Run
07 CoreMessaging!Microsoft::CoreUI::Messaging::MessageSession$R:: Microsoft__CoreUI__IExportMessageSession_Impl::Run
08 CoreMessaging!Microsoft::CoreUI:: IExportMessageSession$X__ExportAdapter::Run
09 CoreMessaging!Windows::System::DispatcherQueue::RunLoop
0a CoreMessaging!Windows::System::DispatcherQueueController:: DispatcherQueueThreadProc
0b kernel32!BaseThreadInitThunk
0c ntdll!RtlUserThreadStart

0:002> ~42kc
# Call Site
00 ntdll!NtWaitForMultipleObjects
01 ntdll!WerpWaitForCrashReporting
02 ntdll!RtlReportExceptionEx
03 eModel!s_ReportAsyncBoundaryHangOnSuspendedThread
04 kernel32!BaseThreadInitThunk
05 ntdll!RtlUserThreadStart

We can spot such a thread in Stack Trace Collection.

Although the example above is for application hang (Blocked Thread) and also illustrates Self-Diagnosis, similar threads may report Handled Exceptions. Usually, Exception Threads are also Exception Reporting Threads as shown in Invalid Parameter analysis pattern example.

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

Sometimes we put trace statements to track responses to certain environmental actions and conditions but surprised to see them in logs when nothing happened outside that could have triggered them:

We call such an analysis pattern Phantom Activity. This is an indicator that internal program state was not updated correctly. The difference between such activities and Defamiliarizing Effect is that the former messages are expected but not in their current Message Context.

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

When we have very large traces (including Split Traces) we can use the concept of sharding to split a log into several shards for parallel processing. However, some patterns may require the analysis across the boundary of shards. Trace Sharding is illustrated in the following diagram:

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

A software trace or log can be analyzed using different Time Scales. The coarser the scale the more messages are included in time intervals. Such per interval Message Sets can be analyzed and transformed into one message using analysis patterns such as Significant Event, Motivic Trace, Background and Foreground Components, and Renormalization. The resulted new trace will be a scaled version of the original trace as depicted in the following diagram:

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

The data in individual messages and in State Dump message blocks may be truncated. This is similar to Visibility Limit at the log message level. When data values are sorted and resorted this may result in “hidden” data replacing the previously “visible” data and vice versa as shown in the following diagram:

This pattern (Truncated Data) was conceived after we observed the change of data key in sequence of a LinkedIn post (not related to firefighting) stats sorted by value and thought that was “strange”:

However, stats from the other post showed the both keys were valid:

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

Insufficient stack memory may not result in Stack Overflow if there are internal thread checks or external watchdog threads. In some way this is a specialization of a more general Insufficient Memory (region) analysis pattern.

Consider this thread stack trace we see when we open a crash dump in WinDbg:

0:003> kc
# Call Site
00 EdgeContent!wil::details::ReportFailure
01 EdgeContent!wil::details::ReportFailure_Hr
02 EdgeContent!wil::details::in1diag3::FailFast_Hr
03 EdgeContent!`anonymous namespace'::MemoryLimitWatchdogThreadProc
04 kernel32!BaseThreadInitThunk
05 ntdll!RtlUserThreadStart

The reported error is related to general security checks and doesn’t reveal much:

0:003> .lastevent
Last event: 10e0.25fc: Security check failure or stack buffer overrun - code c0000409 (first/second chance not available)
debugger time: Sat Sep 29 21:30:31.531 2018 (UTC + 1:00)

However, from Stack Trace Motif we may infer that the failure was related to some memory limit.

When looking at Stack Trace Collection we notice the thread #11 which has the long sequence of frames:

11 Id: 10e0.d68 Suspend: 2 Teb: 000000ca`e96e3000 Unfrozen
# Call Site
00 ntdll!NtWaitForSingleObject
01 KERNELBASE!WaitForSingleObjectEx
02 Chakra!Memory::Recycler::WaitForConcurrentThread
03 Chakra!Memory::Recycler::FinishConcurrentCollect
04 Chakra!ThreadContext::ExecuteRecyclerCollectionFunction
05 Chakra!Memory::Recycler::FinishConcurrentCollectWrapped
06 Chakra!Memory::Recycler::LargeAlloc<0>
07 Chakra!Memory::Recycler::AllocLeaf
08 Chakra!Js::CompoundString::GetSz
09 Chakra!Js::JSONStringifier::ReadProperty
0a Chakra!Js::JSONStringifier::ReadObject
0b Chakra!Js::JSONStringifier::ReadProperty
0c Chakra!Js::JSONStringifier::Stringify
0d Chakra!JSON::Stringify
0e Chakra!amd64_CallFunction
0f Chakra!Js::InterpreterStackFrame::OP_CallCommon<Js::OpLayoutDynamicProfile<
Js::OpLayoutT_CallIWithICIndex<Js::LayoutSizePolicy<0> > > >
10 Chakra!Js::InterpreterStackFrame::ProcessUnprofiled
11 Chakra!Js::InterpreterStackFrame::Process
12 Chakra!Js::InterpreterStackFrame::InterpreterHelper
13 Chakra!Js::InterpreterStackFrame::InterpreterThunk
[...]
fa Chakra!ThreadContext::ExecuteImplicitCall<<
lambda_5a46706206cf607f01fe0fb33b6e8acf> >
fb Chakra!Js::DynamicObject::CallToPrimitiveFunction
fc Chakra!Js::DynamicObject::ToPrimitiveImpl<409>
fd Chakra!Js::DynamicObject::ToPrimitive
fe Chakra!Js::JavascriptConversion::OrdinaryToPrimitive
ff Chakra!Js::JavascriptConversion::MethodCallToPrimitive

It looks like the thread stack is really long that we suspect the possibility of overflow:

0:003> ~11kc 0xffff
[...]
c473 Chakra!amd64_CallFunction
c474 Chakra!Js::JavascriptFunction::CallFunction<1>
c475 Chakra!Js::JavascriptFunction::CallRootFunctionInternal
c476 Chakra!Js::JavascriptFunction::CallRootFunction
c477 Chakra!ScriptSite::CallRootFunction
c478 Chakra!ScriptSite::Execute
c479 Chakra!ScriptEngineBase::Execute
c47a edgehtml!CMutationObserver::PerformMicrotaskCheckpoint
c47b edgehtml!CObserverManager::InvokeObserversForCheckpoint
c47c edgehtml!CObserverManager::MicroTaskExecutionCallback
c47d edgehtml!HTML5TaskScheduler::RunReadiedTask
c47e edgehtml!HTML5TaskScheduler::PerformMicrotaskCheckpoint
c47f edgehtml!CJScript9Holder::ExecuteCallback
c480 edgehtml!CScriptTimer::ExecuteTimer
c481 edgehtml!CScriptTimerManager::OnTick
c482 edgehtml!CPaintAlignedTimerManager<CPaintBeat>::ProcessTimers
c483 edgehtml!CPaintBeat::OnProcessTimersTask
c484 edgehtml!GWndAsyncTask::Run
c485 edgehtml!HTML5TaskScheduler::RunReadiedTask
c486 edgehtml!TaskSchedulerBase::RunReadiedTasksInTaskQueueWithCallback
c487 edgehtml!HTML5TaskScheduler::RunReadiedTasks
c488 edgehtml!HTML5EventLoopDriver::DriveLowPriorityTaskExecution
c489 edgehtml!GlobalWndOnPaintPriorityMethodCall
c48a edgehtml!GlobalWndProc
c48b user32!FilteredProcessRedirectingWndProcW
c48c user32!UserCallWinProcCheckWow
c48d user32!DispatchClientMessage
c48e user32!_fnDWORD
c48f ntdll!KiUserCallbackDispatcherContinue
c490 win32u!NtUserDispatchMessage
c491 user32!DispatchMessageWorker
c492 EdgeContent!CBrowserTab::_TabWindowThreadProc
c493 EdgeContent!LCIETab_ThreadProc
c494 edgeIso!_IsoThreadProc_WrapperToReleaseScope
c495 kernel32!BaseThreadInitThunk
c496 ntdll!RtlUserThreadStart

However, the current stack pointer is the way above the stack region limit:

0:003> ~11s
ntdll!NtWaitForSingleObject+0x14:
00007ffa`b0d99f74 c3              ret

0:011> r rsp
rsp=000000caeb033348

0:011> !teb
TEB at 000000cae96e3000
ExceptionList:        0000000000000000
StackBase:            000000caeba00000
StackLimit:           000000caeb00b000
SubSystemTib:         0000000000000000
FiberData:            0000000000001e00
ArbitraryUserPointer: 0000000000000000
Self:                 000000cae96e3000
EnvironmentPointer:   0000000000000000
ClientId:             00000000000010e0 . 0000000000000d68
RpcHandle:            0000000000000000
Tls Storage:          000001e915185590
PEB Address:          000000cae96a8000
LastErrorValue:       1455
LastStatusValue:      c000012d
Count Owned Locks:    0
HardErrorMode:        0

The last error code shows possible Insufficient Memory (committed memory) pattern but there were enough space in the page file and the same crashes were observed in a much more spacious memory environments:

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.

When we look at a raw stack trace region though, we see it was used to the fullest:

0:011> dps 000000caeb00b000 L30
000000ca`eb00b000 00000000`00000000
000000ca`eb00b008 00000000`00000000
000000ca`eb00b010 00000000`00000000
000000ca`eb00b018 00000000`00000000
000000ca`eb00b020 00000000`00000000
000000ca`eb00b028 00000000`00000000
000000ca`eb00b030 00000000`00000000
000000ca`eb00b038 00000000`00000000
000000ca`eb00b040 00000000`00000000
000000ca`eb00b048 00000000`00000000
000000ca`eb00b050 00000000`00000000
000000ca`eb00b058 00000000`00000000
000000ca`eb00b060 00000000`00000000
000000ca`eb00b068 00000000`00000000
000000ca`eb00b070 00000000`00000000
000000ca`eb00b078 00000000`00000000
000000ca`eb00b080 00000000`00000000
000000ca`eb00b088 00000000`00000000
000000ca`eb00b090 00000000`00000000
000000ca`eb00b098 000001e9`258805c0
000000ca`eb00b0a0 00000000`00000000
000000ca`eb00b0a8 00000000`00000000
000000ca`eb00b0b0 00000000`00000131
000000ca`eb00b0b8 00007ffa`8de137a9 Chakra!Js::DictionaryTypeHandlerBase<unsigned>::GetProperty+0×119
000000ca`eb00b0c0 00000000`00000006
000000ca`eb00b0c8 000001e9`258805c0
000000ca`eb00b0d0 000001e9`258805c0
000000ca`eb00b0d8 000001e9`283d4e70
000000ca`eb00b0e0 000000ca`eb00b210
000000ca`eb00b0e8 00000000`00000000
000000ca`eb00b0f0 00000000`00000131
000000ca`eb00b0f8 000001f1`71863c70
000000ca`eb00b100 00007ffa`8e3cd468 Chakra!Js::BuiltInPropertyRecords::number
000000ca`eb00b108 00000000`00000000
000000ca`eb00b110 000001f1`71863c70
000000ca`eb00b118 000000ca`eb00b210
000000ca`eb00b120 000001e9`258805c0
000000ca`eb00b128 00007ffa`8de103d3 Chakra!Js::DynamicObject::GetPropertyQuery+0×53
000000ca`eb00b130 000001e9`24cc65b0
000000ca`eb00b138 000001e9`258805c0
000000ca`eb00b140 000001e9`258805c0
000000ca`eb00b148 00000000`00000131
000000ca`eb00b150 000000ca`eb00b210
000000ca`eb00b158 00000000`00000000
000000ca`eb00b160 000001f1`71863c70
000000ca`eb00b168 00000000`00000000
000000ca`eb00b170 00000000`00000000
000000ca`eb00b178 00007ffa`8df79864 Chakra!Js::JavascriptOperators::GetProperty_InternalSimple+0×64

We also see Execution Residue possibly indicating catch exception processing:

0:011> dpS 000000caeb00b000 L100
00007ffa`8de137a9 Chakra!Js::DictionaryTypeHandlerBase<unsigned short>::GetProperty+0x119
00007ffa`8e3cd468 Chakra!Js::BuiltInPropertyRecords::number
00007ffa`8de103d3 Chakra!Js::DynamicObject::GetPropertyQuery+0x53
00007ffa`8df79864 Chakra!Js::JavascriptOperators::GetProperty_InternalSimple+0x64
00007ffa`b0d470d0 ntdll!RtlSetLastWin32Error+0x40
00007ffa`b0d470d0 ntdll!RtlSetLastWin32Error+0x40
00007ffa`b048a5da msvcrt!getptd_noexit+0x6e
00007ffa`8dfb36d6 Chakra!`Js::JavascriptExceptionOperators::StackTraceAccessor'::`1'::catch$8
+0x50
00007ffa`b048a553 msvcrt!getptd+0xb
00007ffa`b045aad6 msvcrt!_DestructExceptionObject+0x46
00007ffa`b0463798 msvcrt!_CxxCallCatchBlock+0x1e8
00007ffa`8ddb6d54 Chakra!Js::JavascriptExceptionOperators::StackTraceAccessor+0x2a4
00007ffa`8e324798 Chakra!ValueType::PrimitiveOrObject+0xa80
00007ffa`8dfb3686 Chakra!`Js::JavascriptExceptionOperators::StackTraceAccessor'::`1'::catch$8
00007ffa`8dd20000 Chakra!_jscriptinfo_IID_Lookup <PERF> (Chakra+0x0)
00007ffa`b04635b0 msvcrt!_CxxCallCatchBlock
00007ffa`b0d9e2b3 ntdll!RcConsolidateFrames+0x3
00007ffa`8ddb6d54 Chakra!Js::JavascriptExceptionOperators::StackTraceAccessor+0x2a4
00007ffa`8de137a9 Chakra!Js::DictionaryTypeHandlerBase<unsigned short>::GetProperty+0x119
00007ffa`8e3cd468 Chakra!Js::BuiltInPropertyRecords::number
00007ffa`8de103d3 Chakra!Js::DynamicObject::GetPropertyQuery+0x53
00007ffa`8df79864 Chakra!Js::JavascriptOperators::GetProperty_InternalSimple+0x64
00007ffa`b0d470d0 ntdll!RtlSetLastWin32Error+0x40
00007ffa`b0d470d0 ntdll!RtlSetLastWin32Error+0x40
00007ffa`b048a5da msvcrt!getptd_noexit+0x6e
00007ffa`8dfb36d6 Chakra!`Js::JavascriptExceptionOperators::StackTraceAccessor'::`1'::catch$8
+0x50
00007ffa`b048a553 msvcrt!getptd+0xb
00007ffa`b045aad6 msvcrt!_DestructExceptionObject+0x46
00007ffa`b0463798 msvcrt!_CxxCallCatchBlock+0x1e8
00007ffa`8ddb6d54 Chakra!Js::JavascriptExceptionOperators::StackTraceAccessor+0x2a4

Another similar crash on a different machine with much more memory available had Active Thread Exception Stack Trace:

0:013> kc
# Call Site
00 ntdll!NtQueryWnfStateNameInformation
01 ntdll!SignalStartWerSvc
02 ntdll!SendMessageToWERService
03 ntdll!ReportExceptionInternal
04 kernel32!WerpReportFaultInternal
05 kernel32!WerpReportFault
06 KERNELBASE!UnhandledExceptionFilter
07 Chakra!FatalExceptionFilter
08 Chakra!ReportFatalException$filt$0
09 msvcrt!_C_specific_handler
0a ntdll!RtlpExecuteHandlerForException
0b ntdll!RtlDispatchException
0c ntdll!RtlRaiseException
0d KERNELBASE!RaiseException
0e Chakra!ReportFatalException
0f Chakra!OutOfMemory_fatal_error
10 Chakra!Js::Exception::RaiseIfScriptActive
11 Chakra!Js::Throw::OutOfMemory
12 Chakra!Memory::Recycler::LargeAlloc<0>
13 Chakra!Memory::Recycler::AllocLeaf
14 Chakra!Js::LazyJSONString::GetSz
15 Chakra!Js::CompoundString::AppendGeneric<Js::CompoundString>
16 Chakra!Js::JavascriptExceptionOperators::StackTraceAccessor
17 Chakra!Js::InlineCache::TryGetProperty<1,1,1,1,0>
18 Chakra!Js::CacheOperators::TryGetProperty<1,1,1,1,1,1,1,0,0>
19 Chakra!Js::JavascriptOperators::PatchGetValue<1,Js::InlineCache>
1a js!d.toString
[...]

which actually showed the Javascript URL:

0:013> .frame 1a
1a 00000037`4671e5e0 00007ffe`1753f1a1 js!d.toString [https://yastatic.net/awaps-ad-sdk-js-bundles/1.0-889/bundles/inpage.bundle.js @ 8,36454]

The stack region was also almost full with execution residue including exception catch processing. But this time it show “stack space” hint:

0:013> !teb
TEB at 00000037456dc000
ExceptionList:        0000000000000000
StackBase:            0000003747100000
StackLimit:           000000374670a000
SubSystemTib:         0000000000000000
FiberData:            0000000000001e00
ArbitraryUserPointer: 0000000000000000
Self:                 00000037456dc000
EnvironmentPointer:   0000000000000000
ClientId:             0000000000005914 . 0000000000001150
RpcHandle:            0000000000000000
Tls Storage:          000001a5bcfd88d0
PEB Address:          00000037456bd000
LastErrorValue:       0
LastStatusValue:      c000012d
Count Owned Locks:    0
HardErrorMode:        0

0:013> s-su 000000374670a000 00000037`46720000
[…]
00000037`4670d210 “tack space”
[…]

Note: Regardless of the actual root cause and mechanism for these crash dumps, such stack region monitoring can also be used for software prognostics purposes.

The example dump can be downloaded from here.

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

Trace and log message text usually consists of constant unchanging Message Invariants and some varying data. The latter can be classified into Random Data such as memory addresses, especially when ASLR is enabled, Counter Values, and variable data but constant in nature, such as error values and NULL pointer. Individual values from Signals are not considered random but their sequence can be. This analysis pattern is depicted in the following diagram (adopted from Data Association analysis pattern):

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

Sometimes, we ask for a log file to see State and Event pattern, and see it there, only to find that we cannot do Back Trace of State Dumps from some Significant Event for Inter-Correlation analysis because our Data Interval is truncated (Truncated Trace). This highlights the importance of proper tracing intervals that we call Significant Interval analysis pattern by analogy with significant digits in scientific measurements. The following diagram illustrate the pattern:

If you find out you get truncated traces and logs often you may want to increase Statement Current for state logging.

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

We can “integrate” trace message stream into another, smaller trace. By analogy with motivic integration in contemporary mathematics we call this analysis pattern Motivic Trace. There can be border cases where the whole trace is reduced to one message or every message is associated with a different message (perhaps shorter or a number). Message Sets that are integrated into Motivic Trace can be completely different (for example, based on Motives) in comparison with Quotient Trace where we reduce Message Sets that have the same common attribute.

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

For completion, we introduce a managed space version of Hidden Exception in addition to user and kernel space variants.

0:000> ~*kL
[...]
13 Id: 1b70.1c2c Suspend: 0 Teb: 00446000 Unfrozen
# ChildEBP RetAddr
00 08e7ec4c 755e1cf3 ntdll!NtWaitForMultipleObjects+0xc
01 08e7ede0 6ef8bc6e KERNELBASE!WaitForMultipleObjectsEx+0x133
02 08e7ee30 6ef8b9b3 clr!WaitForMultipleObjectsEx_SO_TOLERANT+0x3c
03 08e7eebc 6ef8baa4 clr!Thread::DoAppropriateWaitWorker+0x237
04 08e7ef28 6ef8bc14 clr!Thread::DoAppropriateWait+0x64
05 08e7ef74 6eef648b clr!CLREventBase::WaitEx+0x128
06 08e7ef8c 6f0058f6 clr!CLREventBase::Wait+0x1a
07 08e7f018 6f005834 clr!AwareLock::EnterEpilogHelper+0xa8
08 08e7f060 6f005980 clr!AwareLock::EnterEpilog+0x48
09 08e7f078 6f00662c clr!AwareLock::Enter+0x4a
0a 08e7f104 08d71d79 clr!JITutil_MonEnterWorker+0x9c
WARNING: Frame IP not in any known module. Following frames may be wrong.
0b 08e7f120 6dd9608d 0x8d71d79
0c 08e7f12c 6ddc2925 mscorlib_ni+0x3c608d
0d 08e7f190 6ddc2836 mscorlib_ni+0x3f2925
0e 08e7f1a4 6ddc27f1 mscorlib_ni+0x3f2836
0f 08e7f1c0 6dd95fe8 mscorlib_ni+0x3f27f1
10 08e7f1d8 6ee6eaf6 mscorlib_ni+0x3c5fe8
11 08e7f1e4 6ee71d50 clr!CallDescrWorkerInternal+0x34
12 08e7f238 6ee77764 clr!CallDescrWorkerWithHandler+0x6b
13 08e7f2a0 6eef4d2d clr!MethodDescCallSite::CallTargetWorker+0x16a
14 08e7f414 6efae269 clr!ThreadNative::KickOffThread_Worker+0x173
15 08e7f428 6efae2d3 clr!ManagedThreadBase_DispatchInner+0x71
16 08e7f4cc 6efae3a0 clr!ManagedThreadBase_DispatchMiddle+0x7e
17 08e7f528 6ee7af05 clr!ManagedThreadBase_DispatchOuter+0x5b
18 08e7f534 6ee7aea2 clr!ManagedThreadBase_DispatchInCorrectAD+0x15
19 08e7f600 6ee7af4d clr!Thread::DoADCallBack+0x328
1a 08e7f624 6efae2d3 clr!ManagedThreadBase_DispatchInner+0x4e
1b 08e7f6c8 6efae3a0 clr!ManagedThreadBase_DispatchMiddle+0x7e
1c 08e7f724 6efae40f clr!ManagedThreadBase_DispatchOuter+0x5b
1d 08e7f748 6eef4be2 clr!ManagedThreadBase_FullTransitionWithAD+0x2f
1e 08e7f7c4 6eef62d1 clr!ThreadNative::KickOffThread+0x256
1f 08e7fbe4 76c28484 clr!Thread::intermediateThreadProc+0x55
20 08e7fbf8 77842fea kernel32!BaseThreadInitThunk+0x24
21 08e7fc40 77842fba ntdll!__RtlUserThreadStart+0x2f
22 08e7fc50 00000000 ntdll!_RtlUserThreadStart+0x1b
[...]

0:000> ~13s
eax=00000000 ebx=00000001 ecx=00000000 edx=00000000 esi=00000001 edi=00000001
eip=7784a7bc esp=08e7ec50 ebp=08e7ede0 iopl=0 nv up ei pl nz ac pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000216
ntdll!NtWaitForMultipleObjects+0xc:
7784a7bc c21400 ret 14h

0:013> !CLRStack
OS Thread Id: 0x1c2c (13)
Child SP IP Call Site
08e7efb4 7784a7bc [GCFrame: 08e7efb4]
08e7f094 7784a7bc [HelperMethodFrame_1OBJ: 08e7f094] System.Threading.Monitor.Enter(System.Object)
08e7f10c 08d71d79 UserQuery+ClassMain.thread_proc_1()
08e7f128 6dd9608d *** ERROR: Module load completed but symbols could not be loaded for mscorlib.ni.dll
System.Threading.ThreadHelper.ThreadStart_Context(System.Object)
08e7f134 6ddc2925 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
08e7f1a0 6ddc2836 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
08e7f1b4 6ddc27f1 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
08e7f1cc 6dd95fe8 System.Threading.ThreadHelper.ThreadStart()
08e7f308 6ee6eaf6 [GCFrame: 08e7f308]
08e7f4e8 6ee6eaf6 [DebuggerU2MCatchHandlerFrame: 08e7f4e8]
08e7f554 6ee6eaf6 [ContextTransitionFrame: 08e7f554]
08e7f6e4 6ee6eaf6 [DebuggerU2MCatchHandlerFrame: 08e7f6e4]

0:013> !teb
TEB at 00446000
ExceptionList: 08e7edd0
StackBase: 08e80000
StackLimit: 08e7a000
SubSystemTib: 00000000
FiberData: 00001e00
ArbitraryUserPointer: 00000000
Self: 00446000
EnvironmentPointer: 00000000
ClientId: 00001b70 . 00001c2c
RpcHandle: 00000000
Tls Storage: 008eb8e8
PEB Address: 0040a000
LastErrorValue: 0
LastStatusValue: c0000034
Count Owned Locks: 0
HardErrorMode: 0

0:013> !DumpStackObjects 08e7a000 08e80000
OS Thread Id: 0×1c2c (13)
ESP/REG Object Name
08E7DD18 0270f714 LINQPad.ExecutionModel.OutPipe
08E7DD20 02736ca8 LINQPad.Disposable
08E7DD2C 0270f714 LINQPad.ExecutionModel.OutPipe
08E7DD3C 02736ca8 LINQPad.Disposable
08E7DD40 02736c88 System.Action
08E7DD44 02736ca8 LINQPad.Disposable
08E7DD64 0270f714 LINQPad.ExecutionModel.OutPipe
08E7DD98 02736ca8 LINQPad.Disposable
08E7DDB8 0270f714 LINQPad.ExecutionModel.OutPipe
08E7DE78 0270f9ec System.Object
08E7DE7C 0270f990 LINQPad.ObjectGraph.Formatters.HtmlWriter
08E7DEAC 0270f990 LINQPad.ObjectGraph.Formatters.HtmlWriter
08E7DEE4 0262e16c System.String
08E7DEF8 026aa9d0 System.String
08E7DF04 0270f990 LINQPad.ObjectGraph.Formatters.HtmlWriter
08E7E054 02724ecc System.Threading.ThreadHelper
08E7E058 026fad7c System.Threading.ContextCallback
08E7E06C 026fad7c System.Threading.ContextCallback
08E7E074 02724ecc System.Threading.ThreadHelper
08E7E0A8 0272fb68 System.NullReferenceException
08E7E0AC 026fad7c System.Threading.ContextCallback
08E7E0B8 02724ecc System.Threading.ThreadHelper
08E7E340 0272fcc0 System.Runtime.CompilerServices.RuntimeHelpers+TryCode
08E7E344 0272fce0 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode
08E7E348 0272fca4 System.Environment+ResourceHelper+GetResourceStringUserData
08E7E35C 0272fce0 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode
08E7E378 0272fca4 System.Environment+ResourceHelper+GetResourceStringUserData
08E7E37C 0272fc0c System.Environment+ResourceHelper
08E7E964 0272fb68 System.NullReferenceException
08E7EB3C 02724ecc System.Threading.ThreadHelper
08E7ECCC 02724ecc System.Threading.ThreadHelper
08E7ECD0 026fad7c System.Threading.ContextCallback
08E7ECD8 0272fa88 System.String critical section 1
08E7EFE8 0272fabc System.String critical section 2
08E7F034 026fad7c System.Threading.ContextCallback
08E7F088 02724ecc System.Threading.ThreadHelper
08E7F08C 026fad7c System.Threading.ContextCallback
08E7F0B8 02724ecc System.Threading.ThreadHelper
08E7F0C0 026fad7c System.Threading.ContextCallback
08E7F0F0 0272fabc System.String critical section 2
08E7F11C 026fad7c System.Threading.ContextCallback
08E7F128 02724f00 System.Threading.ExecutionContext
08E7F134 02724e98 System.Threading.Thread
08E7F144 02724e98 System.Threading.Thread
08E7F188 02724f00 System.Threading.ExecutionContext
08E7F18C 026fad7c System.Threading.ContextCallback
08E7F19C 02724ecc System.Threading.ThreadHelper
08E7F1B0 02724ecc System.Threading.ThreadHelper
08E7F1B8 02724ecc System.Threading.ThreadHelper
08E7F1BC 02724f00 System.Threading.ExecutionContext
08E7F1C8 02724ecc System.Threading.ThreadHelper
08E7F244 02724ee0 System.Threading.ThreadStart
08E7F2C4 02724ee0 System.Threading.ThreadStart
08E7F2D8 02724ee0 System.Threading.ThreadStart

The example dump can be downloaded from here.

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

Backwards disassembling used in memory analysis patterns such as Coincidental Symbolic Information may be ambiguous and can show Wild Code output. This may also be debugger disassembling algorithm dependent. For example, default 8-instruction backwards disassembly shows this code:

0:011> ub 00007ff8`cdc9b4bf
00007ff8`cdc9b4ab 855948 test dword ptr [rcx+48h],ebx
00007ff8`cdc9b4ae b988bf03a8 mov ecx,0A803BF88h
00007ff8`cdc9b4b3 f4 hlt
00007ff8`cdc9b4b4 0100 add dword ptr [rax],eax
00007ff8`cdc9b4b6 00488b add byte ptr [rax-75h],cl
00007ff8`cdc9b4b9 09e8 or eax,ebp
00007ff8`cdc9b4bb 117236 adc dword ptr [rdx+36h],esi
00007ff8`cdc9b4be 5f pop rdi

However, if we specify the number of instructions to disassemble except 7 and 8 we get a different result (which is more correct from the forward code execution view since we disassembled the saved return address from the stack region):

0:011> ub 00007ff8`cdc9b4bf L1
00007ff8`cdc9b4ba e81172365f call clr!JIT_MonEnter (00007ff9`2d0026d0)

0:011> ub 00007ff8`cdc9b4bf L2
00007ff8`cdc9b4b7 488b09 mov rcx,qword ptr [rcx]
00007ff8`cdc9b4ba e81172365f call clr!JIT_MonEnter (00007ff9`2d0026d0)

0:011> k L10
# Child-SP RetAddr Call Site
00 0000002a`fc23e308 00007ff9`53d06099 ntdll!NtWaitForMultipleObjects+0x14
01 0000002a`fc23e310 00007ff9`2d1a96be KERNELBASE!WaitForMultipleObjectsEx+0xf9
02 0000002a`fc23e610 00007ff9`2d1a951c clr!WaitForMultipleObjectsEx_SO_TOLERANT+0x62
03 0000002a`fc23e670 00007ff9`2d1a9315 clr!Thread::DoAppropriateWaitWorker+0x1e4
04 0000002a`fc23e770 00007ff9`2d0c2b7f clr!Thread::DoAppropriateWait+0x7d
05 0000002a`fc23e7f0 00007ff9`2d1aa491 clr!CLREventBase::WaitEx+0xc4
06 0000002a`fc23e880 00007ff9`2d1aa39e clr!AwareLock::EnterEpilogHelper+0xc2
07 0000002a`fc23e940 00007ff9`2d1c1a92 clr!AwareLock::EnterEpilog+0x62
08 0000002a`fc23e9a0 00007ff8`cdc9b4bf clr!JITutil_MonEnterWorker+0xe2
09 0000002a`fc23eb40 00007ff9`275231d3 0×00007ff8`cdc9b4bf
0a 0000002a`fc23eb80 00007ff9`27523064 mscorlib_ni+0×5031d3
0b 0000002a`fc23ec50 00007ff9`27523032 mscorlib_ni+0×503064
0c 0000002a`fc23ec80 00007ff9`2751c812 mscorlib_ni+0×503032
0d 0000002a`fc23ecd0 00007ff9`2d006bb3 mscorlib_ni+0×4fc812
0e 0000002a`fc23ed10 00007ff9`2d006a70 clr!CallDescrWorkerInternal+0×83
0f 0000002a`fc23ed50 00007ff9`2d00735d clr!CallDescrWorkerWithHandler+0×4e

We call this analysis pattern Disassembly Ambiguity. The example dump can be downloaded from here.

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

Using the metaphor of renormalization from physics we introduce Renormalization trace and log analysis pattern where a selected message and its Message Context are replaced by a single message:

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

According to the definition in “Topological Signal Processing” by Michael Robinson (ISBN: 978-3662522844) “a signal consists of a collection of related measurements” (p. 5). For traces and logs we can apply the similar definition and consider Signal as a collection of local messages having the same Message Invariant and related variable data values. Signals are examples of Message Sets. The typical example are sets of related Counter Value messages. Signals can be obtained by obtaining Adjoint Thread of Activity of a specific message (to filter out Background Components “noise”) as illustrated in the following diagram:

Generally, the variable “measurement” part can form Braid of Activity.

We introduce Signal analysis pattern to bridge the gap between Software Narratology and Hardware Narratology.

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

A virtual memory may contain regions that are memories of some other processes or systems. We do not consider the ordinary case of memory-mapped regions here but the case of type 2 hypervisor. In such a case, memory regions may be “physical memories” of Virtualized Systems. For example, we discovered such a region in crashed vmware-vmx.exe process memory dump:

0:007> !address -summary

--- Usage Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
Free 231 7ffe`d009b000 ( 127.995 TB) 100.00%
<unknown> 518 1`2508e000 ( 4.579 GB) 96.41% 0.00%
Image 547 0`07056000 ( 112.336 MB) 2.31% 0.00%
Heap 73 0`0216a000 ( 33.414 MB) 0.69% 0.00%
Stack 81 0`01b00000 ( 27.000 MB) 0.56% 0.00%
Other 11 0`001d0000 ( 1.813 MB) 0.04% 0.00%
TEB 27 0`00036000 ( 216.000 kB) 0.00% 0.00%
PEB 1 0`00001000 ( 4.000 kB) 0.00% 0.00%

--- Type Summary (for busy) ------ RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_MAPPED 88 1`0e25a000 ( 4.221 GB) 88.88% 0.00%
MEM_PRIVATE 623 0`1aca5000 ( 428.645 MB) 8.81% 0.00%
MEM_IMAGE 547 0`07056000 ( 112.336 MB) 2.31% 0.00%

--- State Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
MEM_FREE 231 7ffe`d009b000 ( 127.995 TB) 100.00%
MEM_COMMIT 1185 1`27657000 ( 4.616 GB) 97.18% 0.00%
MEM_RESERVE 73 0`088fe000 ( 136.992 MB) 2.82% 0.00%

--- Protect Summary (for commit) - RgnCount ----------- Total Size -------- %ofBusy %ofTotal
PAGE_READWRITE 473 1`1f38b000 ( 4.488 GB) 94.49% 0.00%
PAGE_READONLY 400 0`04a05000 ( 74.020 MB) 1.52% 0.00%
PAGE_EXECUTE_READ 196 0`0367a000 ( 54.477 MB) 1.12% 0.00%
PAGE_WRITECOPY 59 0`001de000 ( 1.867 MB) 0.04% 0.00%
PAGE_READWRITE|PAGE_GUARD 27 0`00051000 ( 324.000 kB) 0.01% 0.00%
PAGE_NOACCESS 27 0`0001b000 ( 108.000 kB) 0.00% 0.00%
PAGE_EXECUTE_READWRITE 3 0`00003000 ( 12.000 kB) 0.00% 0.00%

--- Largest Region by Usage ----------- Base Address -------- Region Size ----------
Free 290`ffe50000 7d66`9b210000 ( 125.401 TB)
<unknown> 28f`f8f90000 1`00000000 ( 4.000 GB)
Image 7ffa`9969f000 0`00e47000 ( 14.277 MB)
Heap 28f`95c7b000 0`00ae4000 ( 10.891 MB)
Stack b8`f7b00000 0`000fc000 (1008.000 kB)
Other 28f`f2050000 0`00181000 ( 1.504 MB)
TEB b8`f7147000 0`00002000 ( 8.000 kB)
PEB b8`f7146000 0`00001000 ( 4.000 kB)

The size of the region is 4 GB which coincides with the size of Windows VM:

We assume that the whole VM physical space was placed there and we had an instance of a physical memory dump inside a process memory dump. Whatever is such a physical memory dump internal organization, most likely the pages correspond to 4 Kb memory chunks inside. We can employ WinDbg commands that allow the address parameter. For example, we can look for Hidden Modules:

0:007> .imgscan /r 28f`f8f90000 L?1`00000000
[…]
MZ at 00000290`f5867000 - size 7f000
Name: HAL.dll
[…]
MZ at 00000290`a089b000 - size 3000
Name: TDI.SYS
[…]

0:007> !dh 00000290`a089b000

File Type: DLL
FILE HEADER VALUES
14C machine (i386)
2 number of sections
592AD310 time date stamp Sun May 28 06:39:28 2017

0 file pointer to symbol table
0 number of symbols
E0 size of optional header
2122 characteristics
Executable
App can handle >2gb addresses
32 bit word machine
DLL

OPTIONAL HEADER VALUES
10B magic #
9.00 linker version
A00 size of code
400 size of initialized data
0 size of uninitialized data
0 address of entry point
1000 base of code
----- new -----
ffffffff8a7d0000 image base
1000 section alignment
200 file alignment
3 subsystem (Windows CUI)
10.00 operating system version
10.00 image version
5.01 subsystem version
3000 size of image
400 size of headers
10F33 checksum
0000000000040000 size of stack reserve
0000000000001000 size of stack commit
0000000000100000 size of heap reserve
0000000000001000 size of heap commit
540 DLL characteristics
Dynamic base
NX compatible
No structured exception handler
1140 [ 73A] address [size] of Export Directory
0 [ 0] address [size] of Import Directory
2000 [ 3E8] address [size] of Resource Directory
0 [ 0] address [size] of Exception Directory
0 [ 0] address [size] of Security Directory
0 [ 0] address [size] of Base Relocation Directory
1000 [ 1C] address [size] of Debug Directory
0 [ 0] address [size] of Description Directory
0 [ 0] address [size] of Special Directory
0 [ 0] address [size] of Thread Storage Directory
0 [ 0] address [size] of Load Configuration Directory
0 [ 0] address [size] of Bound Import Directory
0 [ 0] address [size] of Import Address Table Directory
0 [ 0] address [size] of Delay Import Directory
0 [ 0] address [size] of COR20 Header Directory
0 [ 0] address [size] of Reserved Directory

SECTION HEADER #1
.text name
87A virtual size
1000 virtual address
A00 size of raw data
400 file pointer to raw data
0 file pointer to relocation table
0 file pointer to line numbers
0 number of relocations
0 number of line numbers
60000020 flags
Code
(no align specified)
Execute Read

Debug Directories(1)
Type Size Address Pointer
cv 20 101c 41c Format: RSDS, guid, 1, tdi.pdb

SECTION HEADER #2
.rsrc name
3E8 virtual size
2000 virtual address
400 size of raw data
E00 file pointer to raw data
0 file pointer to relocation table
0 file pointer to line numbers
0 number of relocations
0 number of line numbers
40000040 flags
Initialized Data
(no align specified)
Read Only
[...]

We call such pattern Hyperdump:

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

Sometimes we can diagnose potential data races by looking at Stack Trace Collection (from all processes and threads or from CPUs). For example, if we have one Exception Stack Trace and a very similar stack trace, for example, with Constant Subtrace and the same Stack Trace Motif, it may point to such a situation with potential diagnosis of related components. Here’s an example from a kernel memory dump where it was suggested as a workaround to close ProcessA before hibernating a system (the problem repeatedly happened on wake up):

0: kd> !analyze -v

[...]

KERNEL_SECURITY_CHECK_FAILURE (139)
A kernel component has corrupted a critical data structure. The corruption
could potentially allow a malicious user to gain control of this machine.
Arguments:
Arg1: 0000000000000003, A LIST_ENTRY has been corrupted (i.e. double remove).
Arg2: ffff8900ea8fae40, Address of the trap frame for the exception that caused the bugcheck
Arg3: ffff8900ea8fad98, Address of the exception record for the exception that caused the bugcheck
Arg4: 0000000000000000, Reserved

[...]

EXCEPTION_RECORD: ffff8900ea8fad98 -- (.exr 0xffff8900ea8fad98)
ExceptionAddress: fffff8034a9e2e93 (nt!CmpFreeKeyControlBlock+0x0000000000106a73)
ExceptionCode: c0000409 (Security check failure or stack buffer overrun)
ExceptionFlags: 00000001
NumberParameters: 1
Parameter[0]: 0000000000000003
Subcode: 0x3 FAST_FAIL_CORRUPT_LIST_ENTRY

[...]

0: kd> k
# Child-SP RetAddr Call Site
00 ffff8900`ea8fab18 fffff803`4a576ba9 nt!KeBugCheckEx
01 ffff8900`ea8fab20 fffff803`4a576f50 nt!KiBugCheckDispatch+0x69
02 ffff8900`ea8fac60 fffff803`4a575286 nt!KiFastFailDispatch+0xd0
03 ffff8900`ea8fae40 fffff803`4a9e2e93 nt!KiRaiseSecurityCheckFailure+0x3c6
04 ffff8900`ea8fafd0 fffff803`4a8c444b nt!CmpFreeKeyControlBlock+0×106a73
05 ffff8900`ea8fb000 fffff803`4a8e1392 nt!CmpDoParseKey+0×2adb
06 ffff8900`ea8fb3d0 fffff803`4a8bdd61 nt!CmpParseKey+0×302
07 ffff8900`ea8fb570 fffff803`4a8d3a2d nt!ObpLookupObjectName+0xb71
08 ffff8900`ea8fb740 fffff803`4a8d370d nt!ObOpenObjectByNameEx+0×1dd
09 ffff8900`ea8fb880 fffff803`4a8cfc5f nt!CmOpenKey+0×29d
0a ffff8900`ea8fba40 fffff803`4a576683 nt!NtOpenKeyEx+0xf
0b ffff8900`ea8fba80 00007ffc`ac3b82b4 nt!KiSystemServiceCopyEnd+0×13
0c 00000001`2c0feb28 00000000`00000000 0×00007ffc`ac3b82b4

0: kd> !stacks 2 nt!Cmp

[...]

[ffffaa0a35ccb2c0 winlogon.exe]
13dc.002668 ffffaa0a37e02080 fff4e8f4 RUNNING nt!KeBugCheckEx
nt!KiBugCheckDispatch+0×69
nt!KiFastFailDispatch+0xd0
nt!KiRaiseSecurityCheckFailure+0×3c6
nt!CmpFreeKeyControlBlock+0×106a73
nt!CmpDoParseKey+0×2adb
nt!CmpParseKey+0×302
nt!ObpLookupObjectName+0xb71
nt!ObOpenObjectByNameEx+0×1dd
nt!CmOpenKey+0×29d
nt!NtOpenKeyEx+0xf
nt!KiSystemServiceCopyEnd+0×13
+0×7ffcac3b82b4

[...]

[ffffaa0a35bda780 ProcessA.exe]
1794.0017e4 ffffaa0a35c06080 fff4e8f4 RUNNING nt!CmpLockKcbStackShared+0×2
nt!CmpWalkOneLevel+0×93
nt!CmpDoParseKey+0×1c36
nt!CmpParseKey+0×302
nt!ObpLookupObjectName+0xb71
nt!ObOpenObjectByNameEx+0×1dd
nt!CmOpenKey+0×29d
nt!NtOpenKeyEx+0xf
nt!KiSystemServiceCopyEnd+0×13
+0×7ffcac3b82b4

[...]

[ffffaa0a35bb8780 svchost.exe]
1754.001fec ffffaa0a3636a7c0 fff4e8f4 READY nt!KxDispatchInterrupt+0x122
nt!KiDpcInterrupt+0x3a6
nt!KeAbPreAcquire+0xd7
nt!ExfAcquirePushLockExclusiveEx+0x10b
nt!CmpDoParseKey+0×294e
nt!CmpParseKey+0×302
nt!ObpLookupObjectName+0xb71
nt!ObOpenObjectByNameEx+0×1dd
nt!CmOpenKey+0×29d
nt!NtOpenKeyEx+0xf
nt!KiSystemServiceCopyEnd+0×13
+0×7ffcac3b82b4

[...]

We call this pattern Stack Trace Race.

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