Software Diagnostics Library

Source code can be considered as a type of a general trace from a corresponding generative narrative plane. We call it Generative Trace since it can generate different traces of execution. If such a trace contains logging code statements, then they form Declarative Trace as a subset of messages. Generative Trace also overlaps with the corresponding Moduli Trace. We can apply many trace and log analysis patterns and even consider line number axis as pseudo-time. The following diagram illustrates Linked Messages analysis pattern in the context of Generative Trace and generated traces:

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

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 -

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 -

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 -

Adjoint Space and Trace Fibration analysis patterns may be useful in cases where complementing traces with memory dumps and vice versa provides better insight into software behavior. Ideally, every trace statement should have Adjoint Space but this is not feasible practically. The solution is to save memory regions surrounding trace message data, for example, structures referenced by pointers. This can be done either for each message or for selected Message Sets. Such memory data can be embedded inside logs as State Dump, Trace Extension or Inter-Correlation with a binary log of such memory fragments. This looks like a mapping between trace messages and memory objects. We call this analysis pattern Trace Presheaf by analogy with presheaves in mathematics. In case Adjoint Spaces are available (for example, memory dumps) such memory buffers can be written to memory by a debugger (in Windows by .readmem WinDbg command) and examined in association with the rest of Adjoint Space. This is illustrated in the following diagram:

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

We do not write a special pattern for individual stowed exceptions (0xC000027B, an application-internal exception) because we consider them examples of Mixed Exceptions (for example, as Managed Code Exceptions enveloped by unmanaged code Software Exception, see stowed exception examples here). However, we introduce a variant of Multiple Exceptions analysis patterns for them because the default analysis WinDbg command (!analyze -v) only shows the first exception or error message stored in the array of stowed exception information structures. The following example shows 3 exceptions. When we load the dump we get this indication of the stowed exceptions:

This dump file has an exception of interest stored in it.
The stored exception information can be accessed via .ecxr.
(2784.2068): Unknown exception - code c000027b (first/second chance not available)
eax=059be538 ebx=00000000 ecx=00000000 edx=00000000 esi=059be898 edi=059be538
eip=750510c0 esp=059be81c ebp=059be940 iopl=0 nv up ei pl nz ac po nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000212
combase!RoFailFastWithErrorContextInternal2+0×109 [inlined in combase!RoFailFastWithErrorContextInternal+0×240]:
750510c0 6a03 push 3

0:008> !error c000027b
Error code: (NTSTATUS) 0xc000027b (3221226107) - An application-internal exception has occurred.

We check Stored Exception:

0:008> .exr -1
ExceptionAddress: 66fc2408 (Windows_UI_Xaml!DirectUI::ErrorHelper::ProcessUnhandledError+0x00432e07)
ExceptionCode: c000027b
ExceptionFlags: 00000001
NumberParameters: 2
Parameter[0]: 08d9bfa8
Parameter[1]: 00000003

We see it has 3 stowed exceptions pointed to by array elements:

0:008> dp 08d9bfa8 L3
08d9bfa8 08d8e084 08d928a8 08d928d0

We check what kind of stowed information structures they point to:

0:008> dt -a3 08d9bfa8 _STOWED_EXCEPTION_INFORMATION_HEADER*
[0] @ 08d9bfa8
———————————————
0×08d8e084
+0×000 Size : 0×28
+0×004 Signature : 0×53453032

[1] @ 08d9bfac
---------------------------------------------
0x08d928a8
+0x000 Size : 0x28
+0×004 Signature : 0×53453032

[2] @ 08d9bfb0
---------------------------------------------
0x08d928d0
+0x000 Size : 0x28
+0×004 Signature : 0×53453032

0:008> .formats 0x53453032
Evaluate expression:
Hex: 53453032
Decimal: 1397043250
Octal: 12321230062
Binary: 01010011 01000101 00110000 00110010
Chars: SE02
Time: Wed Apr 09 12:34:10 2014
Float: low 8.46917e+011 high 0
Double: 6.90231e-315

Since these are version 2 stowed information structures we use this command:

0:008> dt -a3 08d9bfa8 _STOWED_EXCEPTION_INFORMATION_V2*
[0] @ 08d9bfa8
———————————————
0×08d8e084
+0×000 Header : _STOWED_EXCEPTION_INFORMATION_HEADER
+0×008 ResultCode : 802b000a
+0×00c ExceptionForm : 0y01
+0×00c ThreadId : 0y000000000000000000100000011010 (0×81a)
+0×010 ExceptionAddress : 0×74f562f2 Void
+0×014 StackTraceWordSize : 4
+0×018 StackTraceWords : 0×3c
+0×01c StackTrace : 0×07731c08 Void
+0×010 ErrorText : 0×74f562f2 “趍ﯰ???”
+0×020 NestedExceptionType : 0
+0×024 NestedException : (null)

[1] @ 08d9bfac
---------------------------------------------
0x08d928a8
+0x000 Header : _STOWED_EXCEPTION_INFORMATION_HEADER
+0×008 ResultCode : 80004001
+0×00c ExceptionForm : 0y01
+0×00c ThreadId : 0y000000000000000000000000000000 (0)
+0×010 ExceptionAddress : (null)
+0×014 StackTraceWordSize : 4
+0×018 StackTraceWords : 0×3c
+0×01c StackTrace : 0×077d5d4c Void
+0×010 ErrorText : (null)
+0×020 NestedExceptionType : 0
+0×024 NestedException : (null)

[2] @ 08d9bfb0
---------------------------------------------
0x08d928d0
+0x000 Header : _STOWED_EXCEPTION_INFORMATION_HEADER
+0×008 ResultCode : 80004005
+0×00c ExceptionForm : 0y01
+0×00c ThreadId : 0y000000000000000000000000000000 (0)
+0×010 ExceptionAddress : (null)
+0×014 StackTraceWordSize : 4
+0×018 StackTraceWords : 0×19
+0×01c StackTrace : 0×0772df74 Void
+0×010 ErrorText : (null)
+0×020 NestedExceptionType : 0
+0×024 NestedException : (null)

Now we check Stack Traces for individual entries and their error codes:

0:008> !error 802b000a
Error code: (HRESULT) 0×802b000a (2150301706) - <Unable to get error code text>

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

0:008> dps 0×07731c08 L3c
07731c08  74fba2be combase!RoOriginateErrorW+0×3e
07731c0c  66b900d7 Windows_UI_Xaml!DirectUI::ErrorHelper::OriginateError+0×8d
07731c10  66b8fe5f Windows_UI_Xaml!CJupiterErrorServiceListener::NotifyErrorAdded+0xaf
07731c14  66b8fd60 Windows_UI_Xaml!CErrorService::AddError+0×130
07731c18  66b8f0f8 Windows_UI_Xaml!CErrorService::ReportParserError+0×88
07731c1c  66b8f000 Windows_UI_Xaml!ParserErrorService::ReportError+0xd0
07731c20  670f9654 Windows_UI_Xaml!ParserErrorReporter::SetError+0×61
07731c24  670fbe70 Windows_UI_Xaml!XamlBinaryMetadataReader2::LogError+0×6c
07731c28  670fbd37 Windows_UI_Xaml!<lambda_1d4791754290213f1bf5bc456a504cc5>::operator()+0×41
07731c2c  67032601 Windows_UI_Xaml!XamlBinaryMetadataReader2::LoadProperty+0×1f7e82
07731c30  66cab9d9 Windows_UI_Xaml!XamlBinaryMetadataReader2::GetProperty+0×5c
07731c34  66d528e0 Windows_UI_Xaml!XamlBinaryFormatSubReader2::ReadXamlProperty+0×1d0
07731c38  66d520cc Windows_UI_Xaml!XamlBinaryFormatSubReader2::ReadSetValueConstantNode+0×3c
07731c3c  66d53b55 Windows_UI_Xaml!XamlBinaryFormatSubReader2::TryRead+0×135
07731c40  66d539ec Windows_UI_Xaml!XamlBinaryFormatSubReader2::TryReadHRESULT+0×3c
07731c44  66ca329e Windows_UI_Xaml!CParser::LoadXamlCore+0×5ae
07731c48  66da83d2 Windows_UI_Xaml!CCoreServices::ParseXamlWithExistingFrameworkRoot+0×100
07731c4c  66da8131 Windows_UI_Xaml!CApplication::LoadComponent+0×261
07731c50  66da7e56 Windows_UI_Xaml!Application_LoadComponent+0xaa
07731c54  66da7cfc Windows_UI_Xaml!DirectUI::FrameworkApplication::LoadComponent+0xc2
07731c58  66dab49d Windows_UI_Xaml!DirectUI::FrameworkApplicationFactory::LoadComponentWithResourceLocationImpl+0×6a
07731c5c  66dab418 Windows_UI_Xaml!DirectUI::FrameworkApplicationFactory::LoadComponentWithResourceLocation+0×28
07731c60  6c186b95*** WARNING: Unable to verify checksum for Microsoft.Msn.Weather.dll
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for Microsoft.Msn.Weather.dll -
Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×1b2515
07731c64  6c186af1 Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×1b2471
07731c68  6c199d37 Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×1c56b7
07731c6c  6c366cd8 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xaf038
07731c70  6c366c8d Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xaefed
07731c74  6c366b4d Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xaeead
07731c78  6c365b50 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xadeb0
07731c7c  6c3cc1d7 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0×114537
07731c80  6c3cbb9a Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0×113efa
07731c84  6c3cb9c0 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0×113d20
07731c88  6c35a658 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xa29b8
07731c8c  6c0fd56e Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×128eee
07731c90  6c21e3d5 Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×249d55
07731c94  66e50d37 Windows_UI_Xaml!DirectUI::FrameworkApplicationGenerated::OnLaunchedProtected+0×47
07731c98  66e509d0 Windows_UI_Xaml!DirectUI::FrameworkView::OnActivated+0×240
07731c9c  66cf4b28 Windows_UI_Xaml!`Microsoft::WRL::Callback< Windows::Foundation::ITypedEventHandler< Windows::UI::Core::CoreWindow *,IInspectable *>,DirectUI::Page,Windows::UI::Core::ICoreWindow *,IInspectable *>’::`2′::ComObject::Invoke+0×28
07731ca0  7035361e twinapi_appcore!Microsoft::WRL::InvokeTraits<-2>::InvokeDelegates< <lambda_45dc3980e5a5ff53a9eb289d8a61b7e3>, Windows::Foundation::ITypedEventHandler< Windows::ApplicationModel::Core::CoreApplicationView *,Windows::ApplicationModel::Activation::IActivatedEventArgs *> >+0×4f
07731ca4  70353493 twinapi_appcore!Microsoft::WRL::EventSource< Windows::Foundation::ITypedEventHandler< Windows::ApplicationModel::Core::CoreApplicationView *,Windows::ApplicationModel::Activation::IActivatedEventArgs *>,Microsoft::WRL::InvokeModeOptions<-2> >::DoInvoke< <lambda_45dc3980e5a5ff53a9eb289d8a61b7e3> >+0×42
07731ca8  70342a06 twinapi_appcore!Windows::ApplicationModel::Core::CoreApplicationView::Activate+0×296
07731cac  77425ebc rpcrt4!Invoke+0×34
07731cb0  773f37e3 rpcrt4!NdrStubCall2+0×2e3
07731cb4  74efc1ce combase!CStdStubBuffer_Invoke+0xde
07731cb8  7742364c rpcrt4!CStdStubBuffer_Invoke+0×2c
07731cbc  74fb659b combase!ObjectMethodExceptionHandlingAction< <lambda_adf5d6ba83bff890864fd80ca2bbf1eb> >+0×7b
07731cc0  74f83091 combase!DefaultStubInvoke+0×211
07731cc4  74f8d59e combase!ServerCall::ContextInvoke+0×38e
07731cc8  74f8ecc5 combase!AppInvoke+0xb75
07731ccc  74f81c8c combase!ComInvokeWithLockAndIPID+0×62c
07731cd0  74f66d72 combase!CComApartment::ASTAHandleMessage+0×2c2
07731cd4  74f65bfa combase!ASTAWaitContext::Wait+0×47a
07731cd8  74fbb1b4 combase!ASTAWaitInNewContext+0×81
07731cdc  74fbb0ee combase!ASTAThreadWaitForHandles+0×4e
07731ce0  74fbaf1a combase!CoWaitForMultipleHandles+0xaa
07731ce4  7035772d twinapi_appcore!CTSimpleArray<COSTaskCompletion::TaskContext *,4294967294, CTPolicyCoTaskMem<COSTaskCompletion::TaskContext *>,CSimpleArrayStandardCompareHelper<COSTaskCompletion::TaskContext *>,CSimpleArrayStandardMergeHelper<COSTaskCompletion::TaskContext *> >::RemoveAt+0×9f
07731ce8  747d3bea SHCore!CTSimpleArray<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener>,4294967294, CTPolicyCoTaskMem<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> >,CSimpleArrayStandardCompareHelper<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> >,CSimpleArrayStandardMergeHelper<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> > >::_Add<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> const &>+0×120
07731cec  75423744 kernel32!BaseThreadInitThunk+0×24
07731cf0  776d9e54 ntdll!__RtlUserThreadStart+0×2f
07731cf4  776d9e1f ntdll!_RtlUserThreadStart+0×1b

0:008> !error 80004001
Error code: (HRESULT) 0×80004001 (2147500033) - Not implemented

0:008> dps 0×077d5d4c L3c
077d5d4c  66f42bbe Windows_UI_Xaml!DirectUI::MetadataAPI::ImportClassInfo+0×2ed89e
077d5d50  66e451ce Windows_UI_Xaml!DirectUI::MetadataAPI::ImportClassInfoFromMetadataProvider+0×86
077d5d54  66c87bf9 Windows_UI_Xaml!DirectUI::MetadataAPI::GetClassInfoByTypeName+0×219
077d5d58  66c55ea0 Windows_UI_Xaml!DirectUI::MetadataAPI::GetClassInfoByXamlType+0×50
077d5d5c  66c5365d Windows_UI_Xaml!DirectUI::MetadataAPI::ImportPropertyInfo+0×8a
077d5d60  66c542a0 Windows_UI_Xaml!DirectUI::MetadataAPI::TryImportPropertyInfoFromMetadataProvider+0×9f
077d5d64  66c53f94 Windows_UI_Xaml!DirectUI::MetadataAPI::TryGetPropertyByName+0xde
077d5d68  66c564e7 Windows_UI_Xaml!XamlManagedTypeInfoProvider::ResolvePropertyName+0×47
077d5d6c  66c930c2 Windows_UI_Xaml!XamlType::GetProperty+0×1a2
077d5d70  66e3a830 Windows_UI_Xaml!XamlBinaryMetadataReader2::LoadProperty+0xb1
077d5d74  66cab9d9 Windows_UI_Xaml!XamlBinaryMetadataReader2::GetProperty+0×5c
077d5d78  66d528e0 Windows_UI_Xaml!XamlBinaryFormatSubReader2::ReadXamlProperty+0×1d0
077d5d7c  66d520cc Windows_UI_Xaml!XamlBinaryFormatSubReader2::ReadSetValueConstantNode+0×3c
077d5d80  66d53b55 Windows_UI_Xaml!XamlBinaryFormatSubReader2::TryRead+0×135
077d5d84  66d539ec Windows_UI_Xaml!XamlBinaryFormatSubReader2::TryReadHRESULT+0×3c
077d5d88  66ca329e Windows_UI_Xaml!CParser::LoadXamlCore+0×5ae
077d5d8c  66da83d2 Windows_UI_Xaml!CCoreServices::ParseXamlWithExistingFrameworkRoot+0×100
077d5d90  66da8131 Windows_UI_Xaml!CApplication::LoadComponent+0×261
077d5d94  66da7e56 Windows_UI_Xaml!Application_LoadComponent+0xaa
077d5d98  66da7cfc Windows_UI_Xaml!DirectUI::FrameworkApplication::LoadComponent+0xc2
077d5d9c  66dab49d Windows_UI_Xaml!DirectUI::FrameworkApplicationFactory::LoadComponentWithResourceLocationImpl+0×6a
077d5da0  66dab418 Windows_UI_Xaml!DirectUI::FrameworkApplicationFactory::LoadComponentWithResourceLocation+0×28
077d5da4  6c186b95 Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×1b2515
077d5da8  6c186af1 Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×1b2471
077d5dac  6c199d37 Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×1c56b7
077d5db0  6c366cd8 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xaf038
077d5db4  6c366c8d Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xaefed
077d5db8  6c366b4d Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xaeead
077d5dbc  6c365b50 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xadeb0
077d5dc0  6c3cc1d7 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0×114537
077d5dc4  6c3cbb9a Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0×113efa
077d5dc8  6c3cb9c0 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0×113d20
077d5dcc  6c35a658 Microsoft_Msn_Weather_6bb10000!DllGetActivationFactory+0xa29b8
077d5dd0  6c0fd56e Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×128eee
077d5dd4  6c21e3d5 Microsoft_Msn_Weather_6bb10000!RHBinder__ShimExeMain+0×249d55
077d5dd8  66e50d37 Windows_UI_Xaml!DirectUI::FrameworkApplicationGenerated::OnLaunchedProtected+0×47
077d5ddc  66e509d0 Windows_UI_Xaml!DirectUI::FrameworkView::OnActivated+0×240
077d5de0  66cf4b28 Windows_UI_Xaml!`Microsoft::WRL::Callback< Windows::Foundation::ITypedEventHandler< Windows::UI::Core::CoreWindow *,IInspectable *>,DirectUI::Page,Windows::UI::Core::ICoreWindow *,IInspectable *>’::`2′::ComObject::Invoke+0×28
077d5de4  7035361e twinapi_appcore!Microsoft::WRL::InvokeTraits<-2>::InvokeDelegates< <lambda_45dc3980e5a5ff53a9eb289d8a61b7e3>, Windows::Foundation::ITypedEventHandler< Windows::ApplicationModel::Core::CoreApplicationView *,Windows::ApplicationModel::Activation::IActivatedEventArgs *> >+0×4f
077d5de8  70353493 twinapi_appcore!Microsoft::WRL::EventSource< Windows::Foundation::ITypedEventHandler< Windows::ApplicationModel::Core::CoreApplicationView *,Windows::ApplicationModel::Activation::IActivatedEventArgs *>,Microsoft::WRL::InvokeModeOptions<-2> >::DoInvoke< <lambda_45dc3980e5a5ff53a9eb289d8a61b7e3> >+0×42
077d5dec  70342a06 twinapi_appcore!Windows::ApplicationModel::Core::CoreApplicationView::Activate+0×296
077d5df0  77425ebc rpcrt4!Invoke+0×34
077d5df4  773f37e3 rpcrt4!NdrStubCall2+0×2e3
077d5df8  74efc1ce combase!CStdStubBuffer_Invoke+0xde
077d5dfc  7742364c rpcrt4!CStdStubBuffer_Invoke+0×2c
077d5e00  74fb659b combase!ObjectMethodExceptionHandlingAction< <lambda_adf5d6ba83bff890864fd80ca2bbf1eb> >+0×7b
077d5e04  74f83091 combase!DefaultStubInvoke+0×211
077d5e08  74f8d59e combase!ServerCall::ContextInvoke+0×38e
077d5e0c  74f8ecc5 combase!AppInvoke+0xb75
077d5e10  74f81c8c combase!ComInvokeWithLockAndIPID+0×62c
077d5e14  74f66d72 combase!CComApartment::ASTAHandleMessage+0×2c2
077d5e18  74f65bfa combase!ASTAWaitContext::Wait+0×47a
077d5e1c  74fbb1b4 combase!ASTAWaitInNewContext+0×81
077d5e20  74fbb0ee combase!ASTAThreadWaitForHandles+0×4e
077d5e24  74fbaf1a combase!CoWaitForMultipleHandles+0xaa
077d5e28  7035772d twinapi_appcore!CTSimpleArray<COSTaskCompletion::TaskContext *,4294967294, CTPolicyCoTaskMem<COSTaskCompletion::TaskContext *>,CSimpleArrayStandardCompareHelper<COSTaskCompletion::TaskContext *>,CSimpleArrayStandardMergeHelper<COSTaskCompletion::TaskContext *> >::RemoveAt+0×9f
077d5e2c  747d3bea SHCore!CTSimpleArray<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener>,4294967294, CTPolicyCoTaskMem<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> >,CSimpleArrayStandardCompareHelper<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> >,CSimpleArrayStandardMergeHelper<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> > >::_Add<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> const &>+0×120
077d5e30  75423744 kernel32!BaseThreadInitThunk+0×24
077d5e34  776d9e54 ntdll!__RtlUserThreadStart+0×2f
077d5e38  776d9e1f ntdll!_RtlUserThreadStart+0×1b

0:008> ub 66f42bbe
Windows_UI_Xaml!DirectUI::MetadataAPI::ImportClassInfo+0×2ed87f:
66f42b9f 8bce            mov     ecx,esi
66f42ba1 e8b96ecfff      call    Windows_UI_Xaml!OnFailure<1354> (66c39a5f)
66f42ba6 e92d2bd1ff      jmp     Windows_UI_Xaml!DirectUI::MetadataAPI::ImportClassInfo+0×3b8 (66c556d8)
66f42bab 8bce            mov     ecx,esi
66f42bad e8ad6ecfff      call    Windows_UI_Xaml!OnFailure<1354> (66c39a5f)
66f42bb2 e9212bd1ff      jmp     Windows_UI_Xaml!DirectUI::MetadataAPI::ImportClassInfo+0×3b8 (66c556d8)
66f42bb7 8bce            mov     ecx,esi
66f42bb9 e8a16ecfff      call    Windows_UI_Xaml!OnFailure<1354> (66c39a5f)

0:008> !error 80004005
Error code: (HRESULT) 0×80004005 (2147500037) - Unspecified error

0:008> dps 0×0772df74 L19
0772df74  66bc3963 Windows_UI_Xaml!CWindowsServices::CreatePalAppChromeProxy+0×23
0772df78  66bc3912 Windows_UI_Xaml!AppChromeProxy::EnsureAppChromeProxy+0×44
0772df7c  66bc38b6 Windows_UI_Xaml!AppChromeProxy::SetThemeOverride+0xf
0772df80  66e51074 Windows_UI_Xaml!DirectUI::DXamlCore::ConfigureCoreWindow+0×95
0772df84  66e50e6f Windows_UI_Xaml!DirectUI::FrameworkView::SetWindow+0×1f
0772df88  70342def twinapi_appcore!Windows::ApplicationModel::Core::CoreApplicationView::SetWindowAndGetDispatcher + 0×20f
0772df8c  77425ebc rpcrt4!Invoke+0×34
0772df90  773f37e3 rpcrt4!NdrStubCall2+0×2e3
0772df94  74efc1ce combase!CStdStubBuffer_Invoke+0xde
0772df98  7742364c rpcrt4!CStdStubBuffer_Invoke+0×2c
0772df9c  74fb659b combase!ObjectMethodExceptionHandlingAction<
<lambda_adf5d6ba83bff890864fd80ca2bbf1eb> >+0×7b
0772dfa0 74f83091 combase!DefaultStubInvoke+0×211
0772dfa4 74f8d59e combase!ServerCall::ContextInvoke+0×38e
0772dfa8 74f8ecc5 combase!AppInvoke+0xb75
0772dfac 74f81c8c combase!ComInvokeWithLockAndIPID+0×62c
0772dfb0 74f66d72 combase!CComApartment::ASTAHandleMessage+0×2c2
0772dfb4 74f65bfa combase!ASTAWaitContext::Wait+0×47a
0772dfb8 74fbb1b4 combase!ASTAWaitInNewContext+0×81
0772dfbc 74fbb0ee combase!ASTAThreadWaitForHandles+0×4e
0772dfc0 74fbaf1a combase!CoWaitForMultipleHandles+0xaa
0772dfc4 7035772d twinapi_appcore!CTSimpleArray<COSTaskCompletion::TaskContext *,4294967294, CTPolicyCoTaskMem<COSTaskCompletion::TaskContext *>,CSimpleArrayStandardCompareHelper<COSTaskCompletion::TaskContext *>,CSimpleArrayStandardMergeHelper<COSTaskCompletion::TaskContext *> >::RemoveAt+0×9f
0772dfc8 747d3bea SHCore!CTSimpleArray<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener>,4294967294, CTPolicyCoTaskMem<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> >,CSimpleArrayStandardCompareHelper<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> >,CSimpleArrayStandardMergeHelper<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> > >::_Add<Microsoft::WRL::ComPtr< IWindowMonitorChangeListener> const &>+0×120
0772dfcc 75423744 kernel32!BaseThreadInitThunk+0×24
0772dfd0 776d9e54 ntdll!__RtlUserThreadStart+0×2f
0772dfd4 776d9e1f ntdll!_RtlUserThreadStart+0×1b

0:008> ub 66bc3963
Windows_UI_Xaml!CWindowsServices::CreatePalAppChromeProxy+0×5:
66bc3945 56              push    esi
66bc3946 8b7508          mov     esi,dword ptr [ebp+8]
66bc3949 832600          and     dword ptr [esi],0
66bc394c e83ebd2d00      call    Windows_UI_Xaml!IsConfigureStatusBarDefaultsPresent (66e9f68f)
66bc3951 84c0            test    al,al
66bc3953 0f856c1a4100    jne     Windows_UI_Xaml!CWindowsServices::CreatePalAppChromeProxy+0×411a85 (66fd53c5)
66bc3959 be05400080      mov     esi,80004005h
66bc395e e80c000000      call    Windows_UI_Xaml!OnFailure<91> (66bc396f)

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

This is Linux variant of Paratext pattern for Mac OS X. Because of debugger tool limitations additional software logs and the output of other tools may help in memory dump analysis. Typical examples of such pattern usage can be the list of modules with version and path info, application crash specific information from instrumentation tools such as valgrind, memory region names with attribution and boundaries, and CPU usage information. For example, top and pmap commands output:

14039: ./App1.shared
0000000000400000 4K r-x-- /home/training/ALCDA/App1/App1.shared
0000000000600000 4K rw--- /home/training/ALCDA/App1/App1.shared
0000000000611000 132K rw--- [ anon ]
00007fe8999a6000 4K ----- [ anon ]
00007fe8999a7000 8192K rw--- [ anon ]
00007fe89a1a7000 4K ----- [ anon ]
00007fe89a1a8000 8192K rw--- [ anon ]
00007fe89a9a8000 4K ----- [ anon ]
00007fe89a9a9000 8192K rw--- [ anon ]
00007fe89b1a9000 4K ----- [ anon ]
00007fe89b1aa000 8192K rw--- [ anon ]
00007fe89b9aa000 4K ----- [ anon ]
00007fe89b9ab000 8192K rw--- [ anon ]
00007fe89c1ab000 1540K r-x-- /lib/x86_64-linux-gnu/libc-2.13.so
00007fe89c32c000 2048K ----- /lib/x86_64-linux-gnu/libc-2.13.so
00007fe89c52c000 16K r---- /lib/x86_64-linux-gnu/libc-2.13.so
00007fe89c530000 4K rw--- /lib/x86_64-linux-gnu/libc-2.13.so
00007fe89c531000 20K rw--- [ anon ]
00007fe89c536000 92K r-x-- /lib/x86_64-linux-gnu/libpthread-2.13.so
00007fe89c54d000 2044K ----- /lib/x86_64-linux-gnu/libpthread-2.13.so
00007fe89c74c000 4K r---- /lib/x86_64-linux-gnu/libpthread-2.13.so
00007fe89c74d000 4K rw--- /lib/x86_64-linux-gnu/libpthread-2.13.so
00007fe89c74e000 16K rw--- [ anon ]
00007fe89c752000 128K r-x-- /lib/x86_64-linux-gnu/ld-2.13.so
00007fe89c966000 12K rw--- [ anon ]
00007fe89c96f000 8K rw--- [ anon ]
00007fe89c971000 4K r---- /lib/x86_64-linux-gnu/ld-2.13.so
00007fe89c972000 4K rw--- /lib/x86_64-linux-gnu/ld-2.13.so
00007fe89c973000 4K rw--- [ anon ]
00007ffd458c1000 132K rw--- [ stack ]
00007ffd459e9000 4K r-x-- [ anon ]
ffffffffff600000 4K r-x-- [ anon ]
total 47208K

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

We resume our workaround patterns for common reusable solutions to common software execution problems. In the past we proposed a general pattern of Axed Code for removing problem software behavior. The Shadow File blog post about fixing free() crashes by introducing heap metadata header with a data length set to zero led me to generalize and introduce a complementary Axed Data pattern. Such a pattern suggests cutting the data size specified in metadata memory plane (which may be separate from the data plane). In some cases, it may avoid buffer overwrites including Local and Shared in addition to Dynamic Memory Corruption (process heap and kernel pool). The following picture illustrates this general pattern approach.

Sometimes, it may even be possible to provide a workaround by cutting real file data, for example, by changing its file or database record size. But this is also done conceptually by changing file or database system metadata.

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

General traces and logs may have Message Space regions “surrounded” by the so-called Interspace. Such Interspace regions may link individual Message Space regions like in this diagram generalizing WinDbg !process 0 3f command output:

- 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 -

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 -

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 -

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 -

We recently encountered Invalid Handle pattern in the context of .NET program execution. We decided to model it and wrote a small C# program:

namespace SafeHandle
{
    class Program
    {
        static void Main(string[] args)
        {
            SafeFileHandle hFile =
                 new SafeFileHandle(new IntPtr(0xDEAD), true);
            Console.WriteLine("About to close");
            Console.ReadKey();
        }
    }
}

Of course, when we execute it nothing happens. Invalid handles are ignored by default. However, to change the behavior we enabled “Enable close exception” in glags.exe:

And if we run it we get this Managed Stack Trace:

We could have detected invalid handle if we enabled Application Verifier but then we wouldn’t have Managed Code Exception.

So we load a crash dump (saved because we enabled LocalDumps) and load SOS extension:

0:002> lmv m clr
start end module name
000007fe`ed880000 000007fe`ee1eb000 clr (pdb symbols)
Loaded symbol image file: clr.dll
Image path: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
[...]

0:002> .load C:\Windows\Microsoft.NET\Framework64\v4.0.30319\sos

0:002> !pe
Exception object: 0000000002ab5fe8
Exception type: System.Runtime.InteropServices.SEHException
Message: External component has thrown an exception.
InnerException:
StackTrace (generated):
SP IP Function
000000001B40EDD0 0000000000000000 mscorlib_ni!Microsoft.Win32.Win32Native.CloseHandle(IntPtr)+0×1
000000001B40F2F0 0000000000000000 mscorlib_ni!System.Runtime.InteropServices.SafeHandle.InternalFinalize()+0×1
000000001B40F2F0 000007FEEC62F7A6 mscorlib_ni!System.Runtime.InteropServices.SafeHandle.Finalize()+0×26

StackTraceString:
HResult: 80004005

Our unmanaged CLR Thread Exception Stack Trace is quite simple:

0:002> k
Child-SP RetAddr Call Site
00000000`1b40d6e8 000007fe`fd651430 ntdll!NtWaitForMultipleObjects+0xa
00000000`1b40d6f0 00000000`77621723 KERNELBASE!WaitForMultipleObjectsEx+0xe8
00000000`1b40d7f0 00000000`7769b5e5 kernel32!WaitForMultipleObjectsExImplementation+0xb3
00000000`1b40d880 00000000`7769b767 kernel32!WerpReportFaultInternal+0x215
00000000`1b40d920 00000000`7769b7bf kernel32!WerpReportFault+0x77
00000000`1b40d950 00000000`7769b9dc kernel32!BasepReportFault+0x1f
00000000`1b40d980 00000000`778b3398 kernel32!UnhandledExceptionFilter+0x1fc
00000000`1b40da60 00000000`778385c8 ntdll! ?? ::FNODOBFM::`string'+0x2365
00000000`1b40da90 00000000`77849d2d ntdll!_C_specific_handler+0x8c
00000000`1b40db00 00000000`778391cf ntdll!RtlpExecuteHandlerForException+0xd
00000000`1b40db30 00000000`778397c8 ntdll!RtlDispatchException+0x45a
00000000`1b40e210 00000000`778712c7 ntdll!RtlRaiseException+0x22f
00000000`1b40ebc0 000007fe`fd651873 ntdll!KiRaiseUserExceptionDispatcher+0×3a
00000000`1b40ec90 00000000`77621991 KERNELBASE!CloseHandle+0×13
00000000`1b40ecc0 000007fe`ec720418 kernel32!CloseHandleImplementation+0×3d
00000000`1b40edd0 000007fe`ed8e9e03 mscorlib_ni+0×580418
00000000`1b40eea0 000007fe`ed8e9e7e clr!CallDescrWorkerInternal+0×83
00000000`1b40eee0 000007fe`ed8ec860 clr!CallDescrWorkerWithHandler+0×4a
00000000`1b40ef20 000007fe`ed8f1a1d clr!DispatchCallSimple+0×85
00000000`1b40efb0 000007fe`ed8f19ac clr!SafeHandle::RunReleaseMethod+0×69
00000000`1b40f050 000007fe`ed8f180a clr!SafeHandle::Release+0×122
00000000`1b40f120 000007fe`eda4863e clr!SafeHandle::Dispose+0×36
00000000`1b40f190 000007fe`ec62f7a6 clr!SafeHandle::Finalize+0xa2
00000000`1b40f2f0 000007fe`ed8e9d56 mscorlib_ni+0×48f7a6
00000000`1b40f330 000007fe`eda83c4e clr!FastCallFinalizeWorker+0×6
00000000`1b40f360 000007fe`eda83bc3 clr!MethodDesc::RequiresFullSlotNumber+0×72
00000000`1b40f3a0 000007fe`eda83b0f clr!MethodTable::CallFinalizer+0xa3
00000000`1b40f3e0 000007fe`ed9fee46 clr!SVR::CallFinalizer+0×5f
00000000`1b40f420 000007fe`ed9aac5b clr!SVR::CallFinalizer+0×102
00000000`1b40f4e0 000007fe`ed8f458c clr!WKS::GCHeap::IsPromoted+0xee
00000000`1b40f520 000007fe`ed8f451a clr!Frame::Pop+0×50
00000000`1b40f560 000007fe`ed8f4491 clr!COMCustomAttribute::PopSecurityContextFrame+0×192
00000000`1b40f660 000007fe`ed9d1bfe clr!COMCustomAttribute::PopSecurityContextFrame+0xbd
00000000`1b40f6f0 000007fe`ed9d1e59 clr!ManagedThreadBase_NoADTransition+0×3f
00000000`1b40f750 000007fe`ed9533de clr!WKS::GCHeap::FinalizerThreadStart+0×193
00000000`1b40f790 00000000`776159ed clr!Thread::intermediateThreadProc+0×7d
00000000`1b40f850 00000000`7784c541 kernel32!BaseThreadInitThunk+0xd
00000000`1b40f880 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

We see that exception processing happened during object finalization. We can infer the value of the handle (may be Small Value) via disassembly if this is possible:

0:002> kn
# Child-SP RetAddr Call Site
00 00000000`1b40d6e8 000007fe`fd651430 ntdll!NtWaitForMultipleObjects+0xa
01 00000000`1b40d6f0 00000000`77621723 KERNELBASE!WaitForMultipleObjectsEx+0xe8
02 00000000`1b40d7f0 00000000`7769b5e5 kernel32!WaitForMultipleObjectsExImplementation+0xb3
03 00000000`1b40d880 00000000`7769b767 kernel32!WerpReportFaultInternal+0x215
04 00000000`1b40d920 00000000`7769b7bf kernel32!WerpReportFault+0x77
05 00000000`1b40d950 00000000`7769b9dc kernel32!BasepReportFault+0x1f
06 00000000`1b40d980 00000000`778b3398 kernel32!UnhandledExceptionFilter+0x1fc
07 00000000`1b40da60 00000000`778385c8 ntdll! ?? ::FNODOBFM::`string'+0x2365
08 00000000`1b40da90 00000000`77849d2d ntdll!_C_specific_handler+0x8c
09 00000000`1b40db00 00000000`778391cf ntdll!RtlpExecuteHandlerForException+0xd
0a 00000000`1b40db30 00000000`778397c8 ntdll!RtlDispatchException+0x45a
0b 00000000`1b40e210 00000000`778712c7 ntdll!RtlRaiseException+0x22f
0c 00000000`1b40ebc0 000007fe`fd651873 ntdll!KiRaiseUserExceptionDispatcher+0x3a
0d 00000000`1b40ec90 00000000`77621991 KERNELBASE!CloseHandle+0×13
0e 00000000`1b40ecc0 000007fe`ec720418 kernel32!CloseHandleImplementation+0×3d
0f 00000000`1b40edd0 000007fe`ed8e9e03 mscorlib_ni+0×580418
10 00000000`1b40eea0 000007fe`ed8e9e7e clr!CallDescrWorkerInternal+0×83
11 00000000`1b40eee0 000007fe`ed8ec860 clr!CallDescrWorkerWithHandler+0×4a
12 00000000`1b40ef20 000007fe`ed8f1a1d clr!DispatchCallSimple+0×85
13 00000000`1b40efb0 000007fe`ed8f19ac clr!SafeHandle::RunReleaseMethod+0×69
14 00000000`1b40f050 000007fe`ed8f180a clr!SafeHandle::Release+0×122
15 00000000`1b40f120 000007fe`eda4863e clr!SafeHandle::Dispose+0×36
16 00000000`1b40f190 000007fe`ec62f7a6 clr!SafeHandle::Finalize+0xa2
17 00000000`1b40f2f0 000007fe`ed8e9d56 mscorlib_ni+0×48f7a6
18 00000000`1b40f330 000007fe`eda83c4e clr!FastCallFinalizeWorker+0×6
19 00000000`1b40f360 000007fe`eda83bc3 clr!MethodDesc::RequiresFullSlotNumber+0×72
1a 00000000`1b40f3a0 000007fe`eda83b0f clr!MethodTable::CallFinalizer+0xa3
1b 00000000`1b40f3e0 000007fe`ed9fee46 clr!SVR::CallFinalizer+0×5f
1c 00000000`1b40f420 000007fe`ed9aac5b clr!SVR::CallFinalizer+0×102
1d 00000000`1b40f4e0 000007fe`ed8f458c clr!WKS::GCHeap::IsPromoted+0xee
1e 00000000`1b40f520 000007fe`ed8f451a clr!Frame::Pop+0×50
1f 00000000`1b40f560 000007fe`ed8f4491 clr!COMCustomAttribute::PopSecurityContextFrame+0×192
20 00000000`1b40f660 000007fe`ed9d1bfe clr!COMCustomAttribute::PopSecurityContextFrame+0xbd
21 00000000`1b40f6f0 000007fe`ed9d1e59 clr!ManagedThreadBase_NoADTransition+0×3f
22 00000000`1b40f750 000007fe`ed9533de clr!WKS::GCHeap::FinalizerThreadStart+0×193
23 00000000`1b40f790 00000000`776159ed clr!Thread::intermediateThreadProc+0×7d
24 00000000`1b40f850 00000000`7784c541 kernel32!BaseThreadInitThunk+0xd
25 00000000`1b40f880 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

0:002> .frame /c d
0d 00000000`1b40ec90 00000000`77621991 KERNELBASE!CloseHandle+0x13
rax=00000000c0000001 rbx=000000000000dead rcx=00000000009a0000
rdx=0000000000000001 rsi=000000001b40efd0 rdi=000000001b40eff8
rip=000007fefd651873 rsp=000000001b40ec90 rbp=000000001b40edf0
r8=000000001b40ce08 r9=000000001b40cf70 r10=0000000000000000
r11=0000000000000246 r12=0000000000000001 r13=0000000040000000
r14=000000001b40ef40 r15=0000000000000000
iopl=0 nv up ei pl zr na po nc
cs=0033 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000246
KERNELBASE!CloseHandle+0×13:
000007fe`fd651873 85c0 test eax,eax

0:002> ub 00000000`77621991
kernel32!CloseHandleImplementation+0×1e:
00000000`7762196e 83f9f4 cmp ecx,0FFFFFFF4h
00000000`77621971 0f83952e0100 jae kernel32!TlsGetValue+0×3ef0 (00000000`7763480c)
00000000`77621977 488bc3 mov rax,rbx
00000000`7762197a 2503000010 and eax,10000003h
00000000`7762197f 4883f803 cmp rax,3
00000000`77621983 0f847f8dfeff je kernel32!CloseHandleImplementation+0×56 (00000000`7760a708)
00000000`77621989 488bcb mov rcx,rbx
00000000`7762198c e81f000000 call kernel32!CloseHandle (00000000`776219b0)

Here we also check the value from the managed stack trace or from Execution Residue:

0:002> !CLRStack -a
OS Thread Id: 0x1390 (2)
Child SP IP Call Site
000000001b40edf8 000000007787186a [InlinedCallFrame: 000000001b40edf8] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
000000001b40edf8 000007feec720418 [InlinedCallFrame: 000000001b40edf8] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
000000001b40edd0 000007feec720418 DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr)
PARAMETERS:
<no data>

000000001b40eff8 000007feed8e9e03 [GCFrame: 000000001b40eff8]
000000001b40f148 000007feed8e9e03 [GCFrame: 000000001b40f148]
000000001b40f1f8 000007feed8e9e03 [HelperMethodFrame_1OBJ: 000000001b40f1f8] System.Runtime.InteropServices.SafeHandle.InternalFinalize()
000000001b40f2f0 000007feec62f7a6 System.Runtime.InteropServices.SafeHandle.Finalize()
PARAMETERS:
this (0x000000001b40f330) = 0×0000000002ab2d78

000000001b40f6a8 000007feed8e9d56 [DebuggerU2MCatchHandlerFrame: 000000001b40f6a8]

0:002> !dso
OS Thread Id: 0x1390 (2)
RSP/REG Object Name
000000001B40EEA0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40EFD0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F038 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F050 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F090 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F120 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F190 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F1B8 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F240 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F2F8 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F330 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F360 0000000002ab5e10 System.Threading.Thread
000000001B40F390 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F3E0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F3F0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F430 0000000002ab58a8 Microsoft.Win32.SafeHandles.SafeViewOfFileHandle
000000001B40F4E0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle

0:002> !do 0000000002ab2d78
Name: Microsoft.Win32.SafeHandles.SafeFileHandle
MethodTable: 000007feec88a260
EEClass: 000007feec34d340
Size: 32(0x20) bytes
File: C:\windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
000007feec88a338 400060d 8 System.IntPtr 1 instance dead handle
000007feec8892b8 400060e 10 System.Int32 1 instance 3 _state
000007feec887de0 400060f 14 System.Boolean 1 instance 1 _ownsHandle
000007feec887de0 4000610 15 System.Boolean 1 instance 1 _fullyInitialized

Please note that we don’t have global application flags:

0:002> !gflag
Current NtGlobalFlag contents: 0x00000000

Here is the exception stack trace from a different crash dump when we enable Application Verifier:

0:002> !gflag
Current NtGlobalFlag contents: 0x02000100
vrf - Enable application verifier
hpa - Place heap allocations at ends of pages

0:002> k
Child-SP RetAddr Call Site
00000000`24bac4a8 00000000`77cd3072 ntdll!NtWaitForSingleObject+0xa
00000000`24bac4b0 00000000`77cd32b5 ntdll!RtlReportExceptionEx+0x1d2
00000000`24bac5a0 000007fe`fa2c26fb ntdll!RtlReportException+0xb5
00000000`24bac620 00000000`77c2a5db verifier!AVrfpVectoredExceptionHandler+0x26b
00000000`24bac6b0 00000000`77c28e62 ntdll!RtlpCallVectoredHandlers+0xa8
00000000`24bac720 00000000`77c61248 ntdll!RtlDispatchException+0x22
00000000`24bace00 000007fe`fa2bae03 ntdll!KiUserExceptionDispatch+0x2e
00000000`24bad500 000007fe`fa2c268a verifier!VerifierStopMessageEx+0x6fb
00000000`24bad850 00000000`77c2a5db verifier!AVrfpVectoredExceptionHandler+0x1fa
00000000`24bad8e0 00000000`77c28e62 ntdll!RtlpCallVectoredHandlers+0xa8
00000000`24bad950 00000000`77c297c8 ntdll!RtlDispatchException+0x22
00000000`24bae030 00000000`77c612c7 ntdll!RtlRaiseException+0x22f
00000000`24bae9e0 000007fe`fa2d2386 ntdll!KiRaiseUserExceptionDispatcher+0x3a
00000000`24baeab0 000007fe`fdbd1873 verifier!AVrfpNtClose+0xbe
00000000`24baeae0 000007fe`fa2d4031 KERNELBASE!CloseHandle+0x13
00000000`24baeb10 000007fe`fa2d40cb verifier!AVrfpCloseHandleCommon+0x95
00000000`24baeb40 00000000`77a11991 verifier!AVrfpKernelbaseCloseHandle+0x23
00000000`24baeb80 000007fe`fa2d4031 kernel32!CloseHandleImplementation+0x3d
00000000`24baec90 000007fe`fa2d409c verifier!AVrfpCloseHandleCommon+0x95
*** WARNING: Unable to verify checksum for mscorlib.ni.dll
00000000`24baecc0 000007fe`e6a40418 verifier!AVrfpKernel32CloseHandle+0x2c
00000000`24baed00 000007fe`ec0e9e03 mscorlib_ni+0x580418
00000000`24baedd0 000007fe`ec0e9e7e clr!CallDescrWorkerInternal+0x83
00000000`24baee10 000007fe`ec0ec860 clr!CallDescrWorkerWithHandler+0x4a
00000000`24baee50 000007fe`ec0f1a1d clr!DispatchCallSimple+0x85
00000000`24baeee0 000007fe`ec0f19ac clr!SafeHandle::RunReleaseMethod+0x69
00000000`24baef80 000007fe`ec0f180a clr!SafeHandle::Release+0x122
00000000`24baf050 000007fe`ec24863e clr!SafeHandle::Dispose+0x36
00000000`24baf0c0 000007fe`e694f7a6 clr!SafeHandle::Finalize+0xa2
00000000`24baf220 000007fe`ec0e9d56 mscorlib_ni+0x48f7a6
00000000`24baf260 000007fe`ec283c4e clr!FastCallFinalizeWorker+0x6
00000000`24baf290 000007fe`ec283bc3 clr!MethodDesc::RequiresFullSlotNumber+0x72
00000000`24baf2d0 000007fe`ec283b0f clr!MethodTable::CallFinalizer+0xa3
00000000`24baf310 000007fe`ec1fee46 clr!SVR::CallFinalizer+0x5f
00000000`24baf350 000007fe`ec1aac5b clr!SVR::CallFinalizer+0x102
00000000`24baf410 000007fe`ec0f458c clr!WKS::GCHeap::IsPromoted+0xee
00000000`24baf450 000007fe`ec0f451a clr!Frame::Pop+0x50
00000000`24baf490 000007fe`ec0f4491 clr!COMCustomAttribute::PopSecurityContextFrame+0x192
00000000`24baf590 000007fe`ec1d1bfe clr!COMCustomAttribute::PopSecurityContextFrame+0xbd
00000000`24baf620 000007fe`ec1d1e59 clr!ManagedThreadBase_NoADTransition+0x3f
00000000`24baf680 000007fe`ec1533de clr!WKS::GCHeap::FinalizerThreadStart+0x193
00000000`24baf6c0 000007fe`fa2d4b87 clr!Thread::intermediateThreadProc+0x7d
00000000`24baf780 00000000`77a059ed verifier!AVrfpStandardThreadFunction+0x2b
00000000`24baf7c0 00000000`77c3c541 kernel32!BaseThreadInitThunk+0xd
00000000`24baf7f0 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

0:002> !pe
There is no current managed exception on this thread

0:002> !CLRStack
OS Thread Id: 0x51e4 (2)
Child SP IP Call Site
0000000024baed28 0000000077c612fa [InlinedCallFrame: 0000000024baed28] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
0000000024baed28 000007fee6a40418 [InlinedCallFrame: 0000000024baed28] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
0000000024baed00 000007fee6a40418 DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr)
0000000024baef28 000007feec0e9e03 [GCFrame: 0000000024baef28]
0000000024baf078 000007feec0e9e03 [GCFrame: 0000000024baf078]
0000000024baf128 000007feec0e9e03 [HelperMethodFrame_1OBJ: 0000000024baf128] System.Runtime.InteropServices.SafeHandle.InternalFinalize()
0000000024baf220 000007fee694f7a6 System.Runtime.InteropServices.SafeHandle.Finalize()
0000000024baf5d8 000007feec0e9d56 [DebuggerU2MCatchHandlerFrame: 0000000024baf5d8]

0:002> !dso
OS Thread Id: 0x51e4 (2)
RSP/REG Object Name
0000000024BAEDD0 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAEF00 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAEF68 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAEF80 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAEFC0 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF050 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF0C0 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF0E8 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF170 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF228 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF260 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF290 000000000c285e10 System.Threading.Thread
0000000024BAF2C0 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF310 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF320 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF360 000000000c2858a8 Microsoft.Win32.SafeHandles.SafeViewOfFileHandle
0000000024BAF410 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle

0:002> !CLRStack -a
OS Thread Id: 0x51e4 (2)
Child SP               IP Call Site
0000000024baed28 0000000077c612fa [InlinedCallFrame: 0000000024baed28] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
0000000024baed28 000007fee6a40418 [InlinedCallFrame: 0000000024baed28] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
0000000024baed00 000007fee6a40418 DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr)
PARAMETERS:
<no data>

0000000024baef28 000007feec0e9e03 [GCFrame: 0000000024baef28]
0000000024baf078 000007feec0e9e03 [GCFrame: 0000000024baf078]
0000000024baf128 000007feec0e9e03 [HelperMethodFrame_1OBJ: 0000000024baf128] System.Runtime.InteropServices.SafeHandle.InternalFinalize()
0000000024baf220 000007fee694f7a6 System.Runtime.InteropServices.SafeHandle.Finalize()
PARAMETERS:
this (0x0000000024baf260) = 0×000000000c282d78

0000000024baf5d8 000007feec0e9d56 [DebuggerU2MCatchHandlerFrame: 0000000024baf5d8]

0:002> !do 0x000000000c282d78
Name: Microsoft.Win32.SafeHandles.SafeFileHandle
MethodTable: 000007fee6baa260
EEClass: 000007fee666d340
Size: 32(0x20) bytes
File: C:\windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
000007fee6baa338 400060d 8 System.IntPtr 1 instance dead handle
000007fee6ba92b8 400060e 10 System.Int32 1 instance 3 _state
000007fee6ba7de0 400060f 14 System.Boolean 1 instance 1 _ownsHandle
000007fee6ba7de0 4000610 15 System.Boolean 1 instance 1 _fullyInitialized

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

Use cases are implemented in various components such as subsystems, processes, modules, and source code files. Most of the time with good tracing implementation we are able to see Use Case Trails: log messages corresponding to use case scenarios. For simple systems one log may fully correspond to just one use case, but for complex systems, especially distributed client-server ones, there may be several use case instances present simultaneously in one log. One way to disentangle them in the absence of UCID (Use Case ID) or some other grouping tag is to use Event Sequence Phase, the subject of the next pattern.

Master Traces may also correspond to use cases but they should ideally correspond to only one use case instance.

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

Sometimes the absence of messages, for example, errors and exceptions, may save time during troubleshooting and debugging by pointing to what wasn’t happening and provide additional insight. For example, on the picture below we see the same exceptions in the new and old incidents. However, in the old incident we see another exception that was linked to one unavailable server in a distributed broker architecture. Therefore, we can assume provisionally that all servers were operational when the new incident happened.

Missing Message pattern is different from Missing Component pattern where the latter may point to the component that was not loaded or executed, or simply that it wasn’t selected for tracing.

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