Trace Analysis Patterns (Part 207)

April 26th, 2021

Trace Schema can be represented as Schema Trace or, avoiding naming confusion, Definition Trace. The resulting trace looses ordering (similar to unordered Message Set) but allows application of trace and log analysis patterns, especially if some order is fixed, for example, alphabetical for names or original presentation column arrangement. Schema definition Trace Schema can be represented as another Definition Trace as illustrated in the following diagram:

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

Trace Analysis Patterns (Part 206)

April 11th, 2021

Most of trace and log analysis pattern illustrations using Dia|gram language are of these two general forms:

Although the first form represents typical ETW trace attributes, the analysis pattern descriptions are usually independent of attribute name semantics. It, therefore, makes sense to generalize such forms into the following Trace Schema forms, with ATIDs for Adjoint Threads of Activity for the first form, and with FIDs for Features of Activity for the second form:

Such Trace Schemas are useful for various trace and log joins other than Trace Mask.

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

Crash Dump Analysis Patterns (Part 213b)

April 9th, 2021

Previously we introduced Rough Stack Trace analysis pattern for unmanaged space. However, similar collection of symbolic references is possible for managed space (without included unmanaged references we see in Caller-n-Callee). Although the output is noisy, it can be filtered by external tools. The simple WinDbg script outputs managed method descriptors from a stack segment where boundaries were taken from the output of !teb command (this works even for complete memory dumps with .NET Core SOS extension after switching to the appropriate process context):

1: kd> .for (r $t0=000000a7d4d9c000; @$t0 < 000000a7d4db0000; r $t0=@$t0+@$ptrsize) {.if (poi(@$t0) > 7ff000000000) { .printf "---\n"; !IP2MD poi(@$t0) }}
[...]
Failed to request MethodData, not in JIT code range
---
MethodDesc:   00007ff8f7da4fd8
Method Name:          System.Windows.Forms.Application.Run(System.Windows.Forms.Form)
Class:                00007ff8f7d9c1f0
MethodTable:          00007ff8f7da50b0
mdToken:              0000000006000AB8
Module:               00007ff8f7c599a0
IsJitted:             yes
Current CodeAddr:     00007ff953059310
Version History:
ILCodeVersion:      0000000000000000
ReJIT ID:           0
IL Addr:            00007ff952a055d7
CodeAddr:           00007ff953059310  (ReadyToRun)
NativeCodeVersion:  0000000000000000

MethodDesc:   00007ff8f7c26d98
Method Name:          LINQPad.UIProgram.Run()
Class:                00007ff8f7c32d30
MethodTable:          00007ff8f7c28280
mdToken:              00000000060001AF
Module:               00007ff8f7bc2780
IsJitted:             yes
Current CodeAddr:     00007ff8f8328c50
Version History:
ILCodeVersion:      0000000000000000
ReJIT ID:           0
IL Addr:            000002316969a53c
CodeAddr:           00007ff8f8328c50  (MinOptJitted)
NativeCodeVersion:  0000000000000000

MethodDesc:   00007ff8f7c26c60
Method Name:          LINQPad.UIProgram.Go(System.String[])
Class:                00007ff8f7c32d30
MethodTable:          00007ff8f7c28280
mdToken:              00000000060001A4
Module:               00007ff8f7bc2780
IsJitted:             yes
Current CodeAddr:     00007ff8f7f23890
Version History:
ILCodeVersion:      0000000000000000
ReJIT ID:
IL Addr:            0000023169699840
CodeAddr:           00007ff8f7f23890  (MinOptJitted)
NativeCodeVersion:  0000000000000000

Failed to request MethodData, not in JIT code range

MethodDesc:   00007ff8f7c26c00
Method Name:          LINQPad.UIProgram.Start(System.String[])
Class:                00007ff8f7c32d30
MethodTable:          00007ff8f7c28280
mdToken:              00000000060001A0
Module:               00007ff8f7bc2780
IsJitted:             yes
Current CodeAddr:     00007ff8f7b2fce0
Version History:
ILCodeVersion:      0000000000000000
ReJIT ID:           0
IL Addr:            00000231696996fc
CodeAddr:           00007ff8f7b2fce0  (MinOptJitted)
NativeCodeVersion:  0000000000000000

MethodDesc:   00007ff8f7bc64d8
Method Name:          LINQPad.UI.Loader.Main(System.String[])
Class:                00007ff8f7c09508
MethodTable:          00007ff8f7bc64f0
mdToken:              0000000006000346
Module:               00007ff8f7bc2780
IsJitted:             yes
Current CodeAddr:     00007ff8f7b26400
Version History:
ILCodeVersion:      0000000000000000
ReJIT ID:           0
IL Addr:            00000231696ab048
CodeAddr:           00007ff8f7b26400  (MinOptJitted)
NativeCodeVersion:  0000000000000000

Failed to request MethodData, not in JIT code range

Failed to request MethodData, not in JIT code range

Failed to request MethodData, not in JIT code range

Failed to request MethodData, not in JIT code range

[…]

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

Trace Analysis Patterns (Part 205)

April 4th, 2021

When looking at trace and log messages we are usually interested in some features (for example, when doing feature engineering, but not limited to) which can be labelled via Feature IDs (FID). Messages that have the same FID value constitute Feature of Activity, similar to Thread of Activity (or Adjoint Thread of Activity).

Such Features of Activity can span several (A)TIDs in contrast to Fibers of Activity which are confined to the same (A)TID and may have different FID values. Therefore, inside (A)TID there can be several Features of Activity having different FID values.

This analysis pattern serves as a base for other data science analysis patterns we add next.

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

Crash Dump Analysis Patterns (Part 276)

April 3rd, 2021

In simple exception cases, we have exception record, for example from Stored Exception corresponding to exception context, for example:

0:000> .exr -1
ExceptionAddress: 00000001400247ae (TestWER64!CTestDefaultDebuggerDlg::OnBnClickedButton1+0×000000000000007e)
ExceptionCode: c0000005 (Access violation)
ExceptionFlags: 00000000
NumberParameters: 2
Parameter[0]: 0000000000000001
Parameter[1]: 0000000000000000
Attempt to write to address 0000000000000000

0:000> .ecxr
rax=0000000000000000 rbx=0000000000000001 rcx=000000000014fd20
rdx=00000000000003e8 rsi=000000000014fd20 rdi=000000014002daa0
rip=00000001400247ae rsp=000000000014efd0 rbp=0000000000000111
r8=0000000000000000  r9=0000000140024730 r10=0000000140024730
r11=000000000014f0d0 r12=0000000000000000 r13=00000000000003e8
r14=0000000000000110 r15=0000000000000001
iopl=0         nv up ei pl zr na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010246
TestWER64!CTestDefaultDebuggerDlg::OnBnClickedButton1+0×7e:
00000001`400247ae
c704250000000000000000 mov dword ptr [0],0 ds:00000000`00000000=????????

In other cases, we may have missing context:

0:000> .excr
Minidump doesn't have an exception context
Unable to get exception context, HRESULT 0x80004002

invalid context (see also Invalid Exception Information) in the output of !analyze -v command:

CONTEXT:  00007ffb54bd1e60 -- (.cxr 0x7ffb54bd1e60)
rax=15ff480001191885 rbx=ff48c88b48000000 rcx=00441f0f00044c3c
rdx=08ba3824448d4c00 rsi=4838244c8b480001 rdi=0058b9413024448d
rip=00441f0f00044a04 rsp=441f0f00044bd315 rbp=18e4840fc0850000
r8=4c20244489480000  r9=244c89444024448d r10=15ff48a9518d4130
r11=00441f0f00044ebc r12=0118c1840fc08500 r13=8b4840244c8b4800
r14=d88b0000003ee8d7 r15=15ff4838244c8b48
iopl=0 vip vif ov dn ei pl nz na pe nc
cs=2183  ss=044c  ds=4800  es=f98b  fs=ff48  gs=5315             efl=441f0f00
00441f0f`00044a04 ??              ???
Resetting default scope

and valid context but not corresponding to stored exception record:

0:000> .ecxr
rax=00007ffe0a6a9618 rbx=0000024a3aa44020 rcx=0000000100000001
rdx=0000000000000001 rsi=0000024a3abff3e8 rdi=0000024a3abfb5c8
rip=00007ffe9768d759 rsp=000000dc0fd7caf0 rbp=000000dc0fd7d160
r8=0000024a00000007  r9=0000024a5ce8bc80 r10=0000000000000000
r11=0000000000000000 r12=0000024a3abfad90 r13=0000024a3aa44020
r14=0000000000000000 r15=0000024a3abfb5e0
iopl=0         nv up ei pl nz na pe nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000202
KERNELBASE!RaiseException+0x69:
00007ffe`9768d759 0f1f440000      nop     dword ptr [rax+rax]

0:000> .exr -1
ExceptionAddress: 00007ffe0a6a9609
ExceptionCode: c0000005 (Access violation)
ExceptionFlags: 00000000
NumberParameters: 2
Parameter[0]: 0000000000000001
Parameter[1]: 0000000000000000
Attempt to write to address 0000000000000000

However, Exception Stack Trace may be available with JIT Code address :

0:000> kL
# Child-SP          RetAddr           Call Site
00 000000dc`0fd7b558 00007ffe`976b0d40 ntdll!NtWaitForMultipleObjects+0x14
01 000000dc`0fd7b560 00007ffe`976b0c3e KERNELBASE!WaitForMultipleObjectsEx+0xf0
02 000000dc`0fd7b850 00007ffe`994cf6aa KERNELBASE!WaitForMultipleObjects+0xe
03 000000dc`0fd7b890 00007ffe`994cf0e6 kernel32!WerpReportFaultInternal+0x58a
04 000000dc`0fd7b9b0 00007ffe`9776c439 kernel32!WerpReportFault+0xbe
05 000000dc`0fd7b9f0 00007ffe`99cd4b63 KERNELBASE!UnhandledExceptionFilter+0x3d9
06 000000dc`0fd7bb10 00007ffe`99cbbb16 ntdll!RtlUserThreadStart$filt$0+0xa2
07 000000dc`0fd7bb50 00007ffe`99cd130f ntdll!_C_specific_handler+0x96
08 000000dc`0fd7bbc0 00007ffe`99c7b5e4 ntdll!RtlpExecuteHandlerForException+0xf
09 000000dc`0fd7bbf0 00007ffe`99c7b335 ntdll!RtlDispatchException+0x244
0a 000000dc`0fd7c300 00007ffe`9768d759 ntdll!RtlRaiseException+0x185
0b 000000dc`0fd7caf0 00007ffe`6986b259 KERNELBASE!RaiseException+0x69
0c 000000dc`0fd7cbd0 00007ffe`6986b28b coreclr!NakedThrowHelper2+0x9
0d 000000dc`0fd7cc00 00007ffe`6986b295 coreclr!NakedThrowHelper_RspAligned+0x1e
0e 000000dc`0fd7d128 00007ffe`0a6a9609 coreclr!NakedThrowHelper_FixRsp+0×5
0f 000000dc`0fd7d130 00007ffe`0a548023 0×00007ffe`0a6a9609
10 000000dc`0fd7d170 00007ffe`0a547734 0×00007ffe`0a548023
11 000000dc`0fd7d230 00000000`627311e5 0×00007ffe`0a547734
12 000000dc`0fd7d290 00007ffe`62b50fe7 PresentationCore+0×4011e5
13 000000dc`0fd7d2d0 00007ffe`62a35840 PresentationFramework+0xbb0fe7
14 000000dc`0fd7d310 00007ffe`62b51a60 PresentationFramework+0xa95840
15 000000dc`0fd7d350 00000000`62732e22 PresentationFramework+0xbb1a60
16 000000dc`0fd7d390 00000000`62757c42 PresentationCore+0×402e22
17 000000dc`0fd7d3d0 00007ffe`0a5448f3 PresentationCore+0×427c42
18 000000dc`0fd7d410 00007ffe`0a548023 0×00007ffe`0a5448f3
19 000000dc`0fd7d450 00000000`62740e19 0×00007ffe`0a548023
1a 000000dc`0fd7d510 00000000`62732b6a PresentationCore+0×410e19
1b 000000dc`0fd7d580 00000000`62757c42 PresentationCore+0×402b6a
1c 000000dc`0fd7d5c0 00007ffe`0a5448f3 PresentationCore+0×427c42
1d 000000dc`0fd7d600 00007ffe`0a548023 0×00007ffe`0a5448f3
1e 000000dc`0fd7d640 00007ffe`0a547734 0×00007ffe`0a548023
1f 000000dc`0fd7d700 00007ffe`0a550211 0×00007ffe`0a547734
20 000000dc`0fd7d760 00007ffe`0a558efd 0×00007ffe`0a550211
21 000000dc`0fd7d7a0 00007ffe`0a55ebb1 0×00007ffe`0a558efd
22 000000dc`0fd7d860 00007ffe`0a564474 0×00007ffe`0a55ebb1
23 000000dc`0fd7d8b0 00007ffe`0a550eff 0×00007ffe`0a564474
24 000000dc`0fd7d9e0 00007ffe`0a550692 0×00007ffe`0a550eff
25 000000dc`0fd7da70 00007ffe`0a54967d 0×00007ffe`0a550692
26 000000dc`0fd7dae0 00007ffe`0a549596 0×00007ffe`0a54967d
27 000000dc`0fd7db70 00007ffe`0a548ac7 0×00007ffe`0a549596
28 000000dc`0fd7dbc0 00007ffe`0a5488f5 0×00007ffe`0a548ac7
29 000000dc`0fd7dc20 00007ffe`0a54920c 0×00007ffe`0a5488f5
2a 000000dc`0fd7dc70 00007ffe`0a548f07 0×00007ffe`0a54920c
2b 000000dc`0fd7dd00 00007ffe`09d2d772 0×00007ffe`0a548f07
2c 000000dc`0fd7de00 00007ffe`995ae858 0×00007ffe`09d2d772
2d 000000dc`0fd7de80 00007ffe`995ae299 user32!UserCallWinProcCheckWow+0×2f8
2e 000000dc`0fd7e010 00007ffe`0a18011b user32!DispatchMessageWorker+0×249
2f 000000dc`0fd7e090 00007ffe`69557ec3 0×00007ffe`0a18011b
30 000000dc`0fd7e150 00007ffe`695553a1 WindowsBase+0×197ec3
31 000000dc`0fd7e1e0 00007ffe`6955534e WindowsBase+0×1953a1
32 000000dc`0fd7e210 00007ffe`6276966c WindowsBase+0×19534e
33 000000dc`0fd7e240 00007ffe`62767ccd PresentationFramework+0×7c966c
34 000000dc`0fd7e270 00007ffe`62764c5c PresentationFramework+0×7c7ccd
35 000000dc`0fd7e2c0 00007ffe`09d1618e PresentationFramework+0×7c4c5c
36 000000dc`0fd7e2f0 00007ffe`6986a2f3 0×00007ffe`09d1618e
37 000000dc`0fd7e340 00007ffe`697a2fcc coreclr!CallDescrWorkerInternal+0×83
38 000000dc`0fd7e380 00007ffe`697c22b3 coreclr!MethodDescCallSite::CallTargetWorker+0×268
39 (Inline Function) ——–`——– coreclr!MethodDescCallSite::Call+0xb
3a 000000dc`0fd7e4c0 00007ffe`697c207e coreclr!RunMainInternal+0×11f
3b 000000dc`0fd7e5f0 00007ffe`697c1be1 coreclr!RunMain+0xd2
3c 000000dc`0fd7e6a0 00007ffe`697c1908 coreclr!Assembly::ExecuteMainMethod+0×1cd
3d 000000dc`0fd7ea30 00007ffe`69789ad2 coreclr!CorHost2::ExecuteAssembly+0×1c8
3e 000000dc`0fd7eba0 00007ffe`7d502c72 coreclr!coreclr_execute_assembly+0xe2
3f (Inline Function) ——–`——– hostpolicy!coreclr_t::execute_assembly+0×2b
40 000000dc`0fd7ec40 00007ffe`7d502ed7 hostpolicy!run_app_for_context+0×3be
41 000000dc`0fd7edd0 00007ffe`7d503b6b hostpolicy!run_app+0×37
42 000000dc`0fd7ee10 00007ffe`7d5839ea hostpolicy!corehost_main+0xfb
43 000000dc`0fd7efd0 00007ffe`7d587358 hostfxr!execute_app+0×206
44 (Inline Function) ——–`——– hostfxr!?A0×83a23e19::read_config_and_execute+0×10a
45 000000dc`0fd7f0c0 00007ffe`7d585b5f hostfxr!fx_muxer_t::handle_exec_host_command+0×214
46 000000dc`0fd7f1b0 00007ffe`7d582029 hostfxr!fx_muxer_t::execute+0×39b
47 000000dc`0fd7f2f0 00007ff6`3aede0b0 hostfxr!hostfxr_main_startupinfo+0×89
48 000000dc`0fd7f3f0 00007ff6`3aede418 ApplicationA_exe!exe_start+0×620
49 000000dc`0fd7f5d0 00007ff6`3aedfef8 ApplicationA_exe!wmain+0×124
4a (Inline Function) ——–`——– ApplicationA_exe!invoke_main+0×22
4b 000000dc`0fd7f740 00007ffe`99477034 ApplicationA_exe!__scrt_common_main_seh+0×10c
4c 000000dc`0fd7f780 00007ffe`99c7d0d1 kernel32!BaseThreadInitThunk+0×14
4d 000000dc`0fd7f7b0 00000000`00000000 ntdll!RtlUserThreadStart+0×21

0:000> u 00007ffe`0a6a9609
00007ffe`0a6a9609 c70001000000    mov     dword ptr [rax],1

00007ffe`0a6a960f 90              nop
00007ffe`0a6a9610 90              nop
00007ffe`0a6a9611 488d6500        lea     rsp,[rbp]
00007ffe`0a6a9615 5d              pop     rbp
00007ffe`0a6a9616 c3              ret
00007ffe`0a6a9617 0019            add     byte ptr [rcx],bl
00007ffe`0a6a9619 0502000552      add     eax,52050002h

In the case of .NET Core dump, we can use Saved Exception Context to get the original exception:

0:000> dp coreclr!g_SavedExceptionInfo
00007ffe`69bd57f0  00000000`c0000005 00000000`00000000
00007ffe`69bd5800  00007ffe`0a6a9609 00000000`00000002
00007ffe`69bd5810  00000000`00000001 00000000`00000000
00007ffe`69bd5820  00000000`00000000 00000000`00000000
00007ffe`69bd5830  00000000`00000000 00000000`00000000
00007ffe`69bd5840  00000000`00000000 00000000`00000000
00007ffe`69bd5850  00000000`00000000 00000000`00000000
00007ffe`69bd5860  00000000`00000000 00000000`00000000

0:000> dt coreclr!g_SavedExceptionInfo
+0x000 m_ExceptionRecord : _EXCEPTION_RECORD
+0x0a0 m_ExceptionContext : _CONTEXT
+0x570 m_Crst           : CrstStatic

0:000> .cxr coreclr!g_SavedExceptionInfo+a0
rax=0000000000000000 rbx=0000024a3aa44020 rcx=0000024a3aa1d210
rdx=0000024a3aa44020 rsi=0000024a3abff3e8 rdi=0000024a3abfb5c8
rip=00007ffe0a6a9609 rsp=000000dc0fd7d130 rbp=000000dc0fd7d160
r8=0000024a3abff3e8  r9=0000000000000000 r10=0000000000000000
r11=000000dc0fd7d090 r12=0000024a3abfad90 r13=0000024a3aa44020
r14=0000000000000000 r15=0000024a3abfb5e0
iopl=0         nv up ei pl zr na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010246
00007ffe`0a6a9609 c70001000000    mov     dword ptr [rax],1 ds:00000000`00000000=????????

This may also work in the case of invalid or missing exception information in .NET Core dumps:

0:000> .exr -1
ExceptionAddress: 0000000000000000
ExceptionCode: 80000003 (Break instruction exception)
ExceptionFlags: 00000000
NumberParameters: 0

0:000> .excr
Minidump doesn't have an exception context
Unable to get exception context, HRESULT 0x80004002

0:000> .cxr coreclr!g_SavedExceptionInfo+a0
rax=0000000000000000 rbx=0000024a3aa44020 rcx=0000024a3aa1d210
rdx=0000024a3aa44020 rsi=0000024a3abff3e8 rdi=0000024a3abfb5c8
rip=00007ffe0a6a9609 rsp=000000dc0fd7d130 rbp=000000dc0fd7d160
r8=0000024a3abff3e8  r9=0000000000000000 r10=0000000000000000
r11=000000dc0fd7d090 r12=0000024a3abfad90 r13=0000024a3aa44020
r14=0000000000000000 r15=0000024a3abfb5e0
iopl=0         nv up ei pl zr na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010246
00007ffe`0a6a9609 c70001000000    mov     dword ptr [rax],1 ds:00000000`00000000=????????

In some other unmanaged cases, we can use probe Execution Residue values around some exception processing symbols as in the case of Hidden Exceptions, but this may not work if such values are overwritten or no longer available.

A similar approach is available for .NET Framework despite the type not available:

0:000> x clr!g_SavedExceptionInfo
00007ffc`efc01f40 clr!g_SavedExceptionInfo = <no type information>

0:000> dt clr!g_SavedExceptionInfo
Symbol clr!g_SavedExceptionInfo not found.

0:000> .cxr clr!g_SavedExceptionInfo+a0
rax=0000000000000000 rbx=0000000002f8b8a0 rcx=0000000002f27ee8
rdx=0000000002f8a598 rsi=0000000002f8a598 rdi=0000000002fa1028
rip=00007ffc8fcb0829 rsp=000000000113e5b0 rbp=000000000113e5e0
r8=0000000002fa1028  r9=0000000000000000 r10=00007ff480140018
r11=00007ffc8fba8ae8 r12=0000000000000002 r13=0000000000000202
r14=0000000000000001 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=00010246
00007ffc`8fcb0829 c70001000000    mov     dword ptr [rax],1 ds:00000000`00000000=????????

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

Trace Analysis Patterns (Part 204)

March 7th, 2021

Trace Intra-Correlation may be quite elaborate and include analysis of 2-dimensional Weaves of Activity. A similar 2-dimensional metaphor can be applied to Inter-Correlation between several artefacts such as traces and logs, configuration information including infrastructure as code (Small DA+TA), telemetry and event streams, memory dumps (Adjoint Spaces, Trace Presheaf, Memory Fibration, State Dump). All these memory patches, layers, and Trace Fabrics are “sewn” together by Braids, Threads, Adjoint Threads, Strands, Cords, and Weaves of Activities. We call this pattern Trace Quilt but analogy with quilting and quilts.

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

Crash Dump Analysis Patterns (Part 275)

March 3rd, 2021

If we have Step Dumps or Evental Dumps or simply some different memory dumps, for example, from Fiber Bundle and Orbifold memory spaces, we may run debugger commands across them. Then we can track changes in their output like we did in Stack Trace Change analysis pattern. We call the generalization of the latter pattern Structure Sheaf by analogy with structure sheaves of ringed spaces in mathematics. Here we metaphorically treat sequences of debugger commands applied to memory areas (memory structures) as rings of functions on open subsets. We originally wanted to call this analysis pattern Stack Trace (command) for one command and Stack Trace Collection (commands) for a set of commands but realized that the stack trace analogy here makes sense only for sequential memory dumps ordered in time and not for memory dumps taken from different sources.

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

Crash Dump Analysis Patterns (Part 274)

January 31st, 2021

COM Exceptions are Software Exceptions and their information can be extracted from C++ Exception record as shown in this post. Here we show the case of Nested and Hidden Exceptions.

We see a COM exception raising function on Exception Stack Trace:

0:008> .exr -1
ExceptionAddress: 00007ff97800cadf (ntdll!LdrpICallHandler+0x000000000000000f)
ExceptionCode: c0000409 (Security check failure or stack buffer overrun)
ExceptionFlags: 00000001
NumberParameters: 1
Parameter[0]: 000000000000000a
Subcode: 0xa FAST_FAIL_GUARD_ICALL_CHECK_FAILURE

0:008> kL
*** Stack trace for last set context - .thread/.cxr resets it
# Child-SP          RetAddr           Call Site
00 0000009e`393f9e78 00007ff9`7802184f ntdll!LdrpICallHandler+0xf
01 0000009e`393f9e80 00007ff9`77fea889 ntdll!RtlpExecuteHandlerForException+0xf
02 0000009e`393f9eb0 00007ff9`780204be ntdll!RtlDispatchException+0x219
03 0000009e`393fa5c0 00007ff9`7800cb9e ntdll!KiUserExceptionDispatch+0x2e
04 0000009e`393fad78 00007ff9`72591030 ntdll!LdrpDispatchUserCallTarget+0xe
05 0000009e`393fad80 00007ff9`72594a52 VCRUNTIME140_APP!_CallSettingFrame+0x20
06 0000009e`393fadb0 00007ff9`7259e514 VCRUNTIME140_APP!__FrameHandler3::FrameUnwindToState+0x112
07 0000009e`393fae20 00007ff9`72593cc8 VCRUNTIME140_APP!__FrameHandler3::FrameUnwindToEmptyState+0x54
08 0000009e`393fae50 00007ff9`7259ee51 VCRUNTIME140_APP!__InternalCxxFrameHandler<__FrameHandler3>+0x10c
09 0000009e`393faeb0 00007ff8`f83ea850 VCRUNTIME140_APP!__CxxFrameHandler3+0x71
0a 0000009e`393faf00 00007ff9`780218cf PaintStudio_ViewModel!DllGetActivationFactory+0x100
0b 0000009e`393faf30 00007ff9`77f9d9b2 ntdll!RtlpExecuteHandlerForUnwind+0xf
0c 0000009e`393faf60 00007ff9`7259e9de ntdll!RtlUnwindEx+0x522
0d 0000009e`393fb670 00007ff9`72592955 VCRUNTIME140_APP!__FrameHandler3::UnwindNestedFrames+0xee
0e 0000009e`393fb760 00007ff9`72592d81 VCRUNTIME140_APP!CatchIt<__FrameHandler3>+0xb9
0f 0000009e`393fb800 00007ff9`72593dc4 VCRUNTIME140_APP!FindHandler<__FrameHandler3>+0x33d
10 0000009e`393fb970 00007ff9`7259ee51 VCRUNTIME140_APP!__InternalCxxFrameHandler<__FrameHandler3>+0x208
11 0000009e`393fb9d0 00007ff9`7802184f VCRUNTIME140_APP!__CxxFrameHandler3+0x71
12 0000009e`393fba20 00007ff9`77fea889 ntdll!RtlpExecuteHandlerForException+0xf
13 0000009e`393fba50 00007ff9`77fea643 ntdll!RtlDispatchException+0x219
14 0000009e`393fc160 00007ff9`759d3b29 ntdll!RtlRaiseException+0×153
15 0000009e`393fc9d0 00007ff9`72596220 KERNELBASE!RaiseException+0×69
16 0000009e`393fcab0 00007ff9`4919a58c VCRUNTIME140_APP!_CxxThrowException+0×90
17 0000009e`393fcb10 00007ff8`f8057628 vccorlib140_app!__abi_WinRTraiseCOMException+0×2c
18 0000009e`393fcb40 00007ff8`f8093e81 PaintStudio_ViewModel+0×7628
19 0000009e`393fcb70 00007ff8`f818f27f PaintStudio_ViewModel+0×43e81
1a 0000009e`393fcbc0 00007ff8`f818c26f PaintStudio_ViewModel+0×13f27f
1b 0000009e`393fcc90 00007ff8`f811935a PaintStudio_ViewModel+0×13c26f
1c 0000009e`393fcd40 00007ff8`f827ce8e PaintStudio_ViewModel+0xc935a
1d 0000009e`393fd110 00007ff8`f82723ab PaintStudio_ViewModel+0×22ce8e
1e 0000009e`393fd5c0 00007ff8`f83bf09d PaintStudio_ViewModel+0×2223ab
1f 0000009e`393fd7b0 00007ff8`f83c16bd PaintStudio_ViewModel+0×36f09d
20 0000009e`393fdc60 00007ff8`f80e1331 PaintStudio_ViewModel+0×3716bd
21 0000009e`393fdd10 00007ff7`2030d3b9 PaintStudio_ViewModel+0×91331
22 0000009e`393fdd50 00007ff7`202f772f PaintStudio_View+0×2d3b9
23 0000009e`393fddb0 00007ff7`202f702b PaintStudio_View+0×1772f
24 0000009e`393fdee0 00007ff7`202f520e PaintStudio_View+0×1702b
25 0000009e`393fe010 00007ff7`203266d6 PaintStudio_View+0×1520e
26 0000009e`393fe100 00007ff9`4af9d25b PaintStudio_View+0×466d6
27 0000009e`393fe140 00007ff9`4af9d1ce Windows_UI_Xaml!DirectUI::FrameworkApplicationGenerated:: OnActivatedProtected+0×4b
28 0000009e`393fe170 00007ff9`4af9ebe6 Windows_UI_Xaml!DirectUI::FrameworkApplication::DispatchGenericActivation+0×4a
29 0000009e`393fe1a0 00007ff9`4aeb39eb Windows_UI_Xaml!DirectUI::FrameworkView::OnActivated+0×186
2a (Inline Function) ——–`——– Windows_UI_Xaml!Microsoft::WRL::Callback::__l2::<lambda_772c64e6f5ddba6f719dbbabda2a0901>::operator()+0×15
2b 0000009e`393fe220 00007ff9`72cd55cf Windows_UI_Xaml!Microsoft::WRL::Details::DelegateArgTraits<long (__cdecl Windows::Foundation:: ITypedEventHandler_impl<Windows::Foundation::Internal:: AggregateType<Windows::UI::Core::CoreWindow *,Windows::UI::Core::ICoreWindow *>,IInspectable *>::*)(Windows::UI::Core::ICoreWindow *,IInspectable *)>::DelegateInvokeHelper<Windows::Foundation:: ITypedEventHandler<Windows::UI::Core::CoreWindow *,IInspectable *>,<lambda_772c64e6f5ddba6f719dbbabda2a0901>,-1,Windows::UI::Core::ICoreWindow *,IInspectable *>::Invoke+0×1b
2c 0000009e`393fe250 00007ff9`72cd8a22 twinapi_appcore!Microsoft::WRL::InvokeTraits<-2>:: InvokeDelegates<<lambda_3ad0adb09957fd62cbc86618ebbeb8fa>,Windows::Foundation:: ITypedEventHandler<Windows::ApplicationModel::Core::CoreApplicationView *,Windows::ApplicationModel::Activation::IActivatedEventArgs *> >+0×67
2d 0000009e`393fe2c0 00007ff9`76cb6a63 twinapi_appcore!Windows::ApplicationModel::Core:: CoreApplicationView::Activate+0×3d2
2e 0000009e`393fe430 00007ff9`76d1a036 rpcrt4!Invoke+0×73
2f 0000009e`393fe490 00007ff9`76c783b9 rpcrt4!Ndr64StubWorker+0xb56
30 0000009e`393feb30 00007ff9`76fd5d13 rpcrt4!NdrStubCall3+0xc9
31 0000009e`393feb90 00007ff9`76c99bab combase!CStdStubBuffer_Invoke+0×73
32 0000009e`393febd0 00007ff9`76fbd0e3 rpcrt4!CStdStubBuffer_Invoke+0×3b
33 (Inline Function) ——–`——– combase!InvokeStubWithExceptionPolicyAndTracing::__l6:: <lambda_c9f3956a20c9da92a64affc24fdd69ec>::operator()+0×18
34 0000009e`393fec00 00007ff9`76fbced3 combase!ObjectMethodExceptionHandlingAction< <lambda_c9f3956a20c9da92a64affc24fdd69ec> >+0×43
35 (Inline Function) ——–`——– combase!InvokeStubWithExceptionPolicyAndTracing+0xa8
36 0000009e`393fec60 00007ff9`76fd9556 combase!DefaultStubInvoke+0×1c3
37 (Inline Function) ——–`——– combase!SyncStubCall::Invoke+0×22
38 0000009e`393fedb0 00007ff9`76fba4fa combase!SyncServerCall::StubInvoke+0×26
39 (Inline Function) ——–`——– combase!StubInvoke+0×259
3a 0000009e`393fedf0 00007ff9`76fda81b combase!ServerCall::ContextInvoke+0×42a
3b (Inline Function) ——–`——– combase!CServerChannel::ContextInvoke+0xc0
3c (Inline Function) ——–`——– combase!DefaultInvokeInApartment+0xc0
3d 0000009e`393ff1f0 00007ff9`76f701ac combase!ASTAInvokeInApartment+0×15b
3e 0000009e`393ff400 00007ff9`76f70a11 combase!AppInvoke+0×1ec
3f 0000009e`393ff490 00007ff9`76f918c2 combase!ComInvokeWithLockAndIPID+0×681
40 (Inline Function) ——–`——– combase!ComInvoke+0×1c1
41 0000009e`393ff7c0 00007ff9`76f90a99 combase!ThreadDispatch+0×272
42 0000009e`393ff890 00007ff9`76f947ba combase!ModernSTAState::HandleMessage+0×51
43 0000009e`393ff8e0 00007ff9`4eac92f5 combase!ModernSTAWaitContext::HandlePriorityEventsFromMessagePump+0×66
44 0000009e`393ff910 00007ff9`4eac8fee Windows_UI!Windows::UI::Core::CDispatcher::ProcessMessage+0×1b5
45 0000009e`393ff9c0 00007ff9`4eac8f21 Windows_UI!Windows::UI::Core::CDispatcher::WaitAndProcessMessagesInternal+0xae
46 0000009e`393ffad0 00007ff9`72cea89f Windows_UI!Windows::UI::Core::CDispatcher::WaitAndProcessMessages+0×31
47 0000009e`393ffb00 00007ff9`76eac235 twinapi_appcore!<lambda_643db08282a766b00cec20194396f531>::operator()+0xff
48 0000009e`393ffbf0 00007ff9`77aa7c24 SHCore!_WrapperThreadProc+0xf5
49 0000009e`393ffcd0 00007ff9`77fed4d1 kernel32!BaseThreadInitThunk+0×14
4a 0000009e`393ffd00 00000000`00000000 ntdll!RtlUserThreadStart+0×21

We dump doubly dereferenced raw stack region around such exception processing calls:

0:008> dpp 0000009e`393fc160 0000009e`393fcb70
[…]
0000009e`393fcb38 00007ff8`f8057628 cc003f4c`6115ffcc
0000009e`393fcb40 0000009e`393fcb88 0000009e`393fcb98
0000009e`393fcb48 000001e8`69af9450 00007ff9`491c6170 vccorlib140_app!Platform::COMException::`vftable’
0000009e`393fcb50 000001e8`69af9450 00007ff9`491c6170 vccorlib140_app!Platform::COMException::`vftable’
[…]

We see C++ Object references and apply object structure to them:

0:008> dt vccorlib140_app!Platform::COMException 000001e8`69af9450
+0×000 __VFN_table : 0×00007ff9`491c6170
+0×008 __VFN_table : 0×00007ff9`491c5bf8
+0×010 __VFN_table : 0×00007ff9`491c5e20
+0×018 __VFN_table : 0×00007ff9`491c5ec0
+0×020 __description    : 0×000001e8`5e1e30a8 Void
+0×028 __restrictedErrorString : 0×000001e8`5ba83728 Void

+0×030 __restrictedErrorReference : (null)
+0×038 __capabilitySid  : (null)
+0×040 __hresult        : 0n-2147024894
+0×048 __restrictedInfo : 0×000001e8`699f4308 Void
+0×050 __throwInfo      : 0×00007ff9`491baf60 Void
+0×058 __size           : 0×40
+0×060 __prepare        : Platform::IntPtr
+0×068 __abi_reference_count : __abi_FTMWeakRefData
+0×078 __abi_disposed   : 0
+0×080 __abi_disposed   : 0

0:008> du 0x000001e8`5e1e30a8
000001e8`5e1e30a8  "The system cannot find the file "
000001e8`5e1e30e8  "specified..."

0:008> du 0x000001e8`5ba83728
000001e8`5ba83728  "Error trying to initialize appli"
000001e8`5ba83768  "cation data storage folder"

0:008> !error 0n-2147024894
Error code: (HRESULT) 0x80070002 (2147942402) - The system cannot find the file specified.

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

Crash Dump Analysis Patterns (Part 273)

January 25th, 2021

C++ Objects may leave virtual function table pointer traces in Execution Residue and, therefore, their adjacent data can be inspected:

0:000> !teb
TEB at 0000000000306000
ExceptionList: 0000000000000000
StackBase: 0000000000150000
StackLimit: 000000000014d000

SubSystemTib: 0000000000000000
FiberData: 0000000000001e00
ArbitraryUserPointer: 0000000000000000
Self: 0000000000306000
EnvironmentPointer: 0000000000000000
ClientId: 0000000000000214 . 00000000000011b0
RpcHandle: 0000000000000000
Tls Storage: 0000000000306058
PEB Address: 0000000000305000
LastErrorValue: 0
LastStatusValue: c0000034
Count Owned Locks: 0
HardErrorMode: 0

0:000> dps 000000000014d000 0000000000150000
00000000`0014d000 00000000`00000000
00000000`0014d008 00000000`00000000
00000000`0014d010 00000000`00000000
00000000`0014d018 00000000`00000000
00000000`0014d020 00000000`00000000
[…]
00000000`0014fe08 00000000`00000000
00000000`0014fe10 00000000`005d4550
00000000`0014fe18 00000000`00000000
00000000`0014fe20 00000000`005cd7e0
00000000`0014fe28 00000000`005cd7e0
00000000`0014fe30 00000000`005cd7e0
00000000`0014fe38 00000001`40017778 ExecutionResidueC__Objects!CObject::`vftable’
00000000`0014fe40 624f206f`6c6c6548
00000000`0014fe48 00000021`7463656a

00000000`0014fe50 00000000`00000000
00000000`0014fe58 00000000`00000000
00000000`0014fe60 00000000`00000000
00000000`0014fe68 00000000`00000000
00000000`0014fe70 00000000`00000000
00000000`0014fe78 00000000`00000000
00000000`0014fe80 00000000`00000000
00000000`0014fe88 00000000`00000000
00000000`0014fe90 00000000`00000000
00000000`0014fe98 00000000`00000000
00000000`0014fea0 00000000`00000000
00000000`0014fea8 00000000`00000000
00000000`0014feb0 00000001`40017778 ExecutionResidueC__Objects!CObject::`vftable’
00000000`0014feb8 624f206f`6c6c6548
00000000`0014fec0 00000021`7463656a

00000000`0014fec8 00000000`00000000
00000000`0014fed0 00000000`00000000
00000000`0014fed8 0000e111`9d4d4b61
[…]

0:000> dps 00000001`40017778
00000001`40017778 00000001`40001040 ExecutionResidueC__Objects!CObject::`scalar deleting destructor’
00000001`40017780 00000001`40001020 ExecutionResidueC__Objects!CObject::foo
00000001`40017788 00000001`40001030 ExecutionResidueC__Objects!CObject::bar
00000001`40017790 600e149f`00000000
00000001`40017798 00000002`00000000
00000001`400177a0 00017c6c`00000069
00000001`400177a8 00000000`00016e6c
00000001`400177b0 00000000`600e149f
00000001`400177b8 00000014`0000000c
00000001`400177c0 00016ed8`00017cd8
00000001`400177c8 600e149f`00000000
00000001`400177d0 0000000d`00000000
00000001`400177d8 00017cec`000002f0
00000001`400177e0 00000000`00016eec
00000001`400177e8 00000000`600e149f
00000001`400177f0 00000000`0000000e

0:000> da 00000000`0014feb8
00000000`0014feb8 “Hello Object!”

0:000> dt ExecutionResidueC__Objects!CObject 00000000`0014feb0
+0×000 __VFN_table : 0×00000001`40017778
+0×008 data : [32] “Hello Object!”

We see that two objects were allocated on the stack. However, finding dynamically allocated objects may require another level of pointer redirection when pointers to such objects are stored on the stack, for example with dpp WinDbg command:

0:000> dpp 000000000014d000 0000000000150000
00000000`0014d000 00000000`00000000
00000000`0014d008 00000000`00000000
00000000`0014d010 00000000`00000000
00000000`0014d018 00000000`00000000
00000000`0014d020 00000000`00000000
[…]
00000000`0014fe08 00000000`00000000
00000000`0014fe10 00000000`005d4550 00000000`005d4560
00000000`0014fe18 00000000`00000000
00000000`0014fe20 00000000`005cd7e0 00000001`40017778 ExecutionResidueC__Objects!CObject::`vftable’
00000000`0014fe28 00000000`005cd7e0 00000001`40017778 ExecutionResidueC__Objects!CObject::`vftable’
00000000`0014fe30 00000000`005cd7e0 00000001`40017778 ExecutionResidueC__Objects!CObject::`vftable’
00000000`0014fe38 00000001`40017778 00000001`40001040 ExecutionResidueC__Objects!CObject::`scalar deleting destructor’
00000000`0014fe40 624f206f`6c6c6548
00000000`0014fe48 00000021`7463656a

00000000`0014fe50 00000000`00000000
00000000`0014fe58 00000000`00000000
00000000`0014fe60 00000000`00000000
00000000`0014fe68 00000000`00000000
00000000`0014fe70 00000000`00000000
00000000`0014fe78 00000000`00000000
00000000`0014fe80 00000000`00000000
00000000`0014fe88 00000000`00000000
00000000`0014fe90 00000000`00000000
00000000`0014fe98 00000000`00000000
00000000`0014fea0 00000000`00000000
00000000`0014fea8 00000000`00000000
00000000`0014feb0 00000001`40017778 00000001`40001040 ExecutionResidueC__Objects!CObject::`scalar deleting destructor’
00000000`0014feb8 624f206f`6c6c6548
00000000`0014fec0 00000021`7463656a

00000000`0014fec8 00000000`00000000
00000000`0014fed0 00000000`00000000
00000000`0014fed8 0000e111`9d4d4b61
[…]

0:000> !address 00000000`005cd7e0

Usage: Heap
Base Address: 00000000`005c0000
End Address: 00000000`005d8000
Region Size: 00000000`00018000 ( 96.000 kB)
State: 00001000 MEM_COMMIT
Protect: 00000004 PAGE_READWRITE
Type: 00020000 MEM_PRIVATE
Allocation Base: 00000000`005c0000
Allocation Protect: 00000004 PAGE_READWRITE
More info: heap owning the address: !heap 0×5c0000
More info: heap segment
More info: heap entry containing the address: !heap -x 0×5cd7e0

0:000> dps 00000000`005cd7e0
00000000`005cd7e0 00000001`40017778 ExecutionResidueC__Objects!CObject::`vftable’
00000000`005cd7e8 624f206f`6c6c6548
00000000`005cd7f0 00000021`7463656a

00000000`005cd7f8 00000000`00000000
00000000`005cd800 00000000`00000000
00000000`005cd808 93002500`6c5ec8a3
00000000`005cd810 4f535345`434f5250
00000000`005cd818 54494843`52415f52
00000000`005cd820 413d4552`55544345
00000000`005cd828 00000000`3436444d
00000000`005cd830 00000000`00000000
00000000`005cd838 92002600`6c5bc8a0
00000000`005cd840 576d6172`676f7250
00000000`005cd848 5c3a433d`32333436
00000000`005cd850 206d6172`676f7250
00000000`005cd858 00000073`656c6946

0:000> da 00000000`005cd7e8
00000000`005cd7e8 “Hello Object!”

0:000> dps 00000001`40017778
00000001`40017778 00000001`40001040 ExecutionResidueC__Objects!CObject::`scalar deleting destructor’
00000001`40017780 00000001`40001020 ExecutionResidueC__Objects!CObject::foo
00000001`40017788 00000001`40001030 ExecutionResidueC__Objects!CObject::bar
00000001`40017790 600e149f`00000000
00000001`40017798 00000002`00000000
00000001`400177a0 00017c6c`00000069
00000001`400177a8 00000000`00016e6c
00000001`400177b0 00000000`600e149f
00000001`400177b8 00000014`0000000c
00000001`400177c0 00016ed8`00017cd8
00000001`400177c8 600e149f`00000000
00000001`400177d0 0000000d`00000000
00000001`400177d8 00017cec`000002f0
00000001`400177e0 00000000`00016eec
00000001`400177e8 00000000`600e149f
00000001`400177f0 00000000`0000000e

0:000> dt ExecutionResidueC__Objects!CObject 00000000`005cd7e0
+0×000 __VFN_table : 0×00000001`40017778
+0×008 data : [32] “Hello Object!”

We created a modeling C++ program for better illustration:

struct CObject
{
    virtual ~CObject() {};
    virtual int foo() { return 1; };
    virtual int bar() { return 2; };

    char data[32] = "Hello Object!";
};

int main()
{
    CObject  localObj;
    int      _[20]{};	// padding the stack
    CObject* dynamicObj{new CObject};

    throw CObject();
}

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

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

Trace Analysis Patterns (Part 203)

January 10th, 2021

Various metrics are covered by Counter Value trace and log analysis pattern. However, metric labels or metric metadata as implemented by monitoring tools such as Prometheus can be mapped directly to Adjoint Threads of Activity in our trace and log analysis pattern catalog:

<Metric Name>{<Label Name>=<Label Value>, ...}=<Metric Value> (from Prometheus data model)

{<Metric Name ATID>=<ATID Value>, <ATID Name>=<ATID Value>, ..., <Message (Metric Value)>}

This allows the application of many trace and log analysis patterns related to threading and adjoint threading (multibraiding).

We call this analysis pattern Message Metadata. It is illustrated for time series in the following diagram where we have the same Labels for all metric names (in general labels may be different):

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

Theoretical Software Diagnostics

November 9th, 2020

Theoretical content is available in edited and revised PDF format:

http://www.patterndiagnostics.com/theoretical-software-diagnostics-book

Trace, Log, Text, Narrative

November 9th, 2020

The content of trace analysis patterns is available in edited and revised PDF format:

https://www.patterndiagnostics.com/trace-log-analysis-pattern-reference

Encyclopedia of Crash Dump Analysis Patterns

November 9th, 2020

The content of crash dump analysis patterns is available in edited and revised PDF format:

https://www.patterndiagnostics.com/encyclopedia-crash-dump-analysis-patterns

Memory Dump Analysis Anthology

November 9th, 2020

The content of this site is available in edited and revised PDF format with a significant discount for volume set:

https://www.patterndiagnostics.com/mdaa-volumes

Alternatively, analysis pattern and theoretical content is included in Pattern-Oriented Software Diagnostics and Anomaly Detection Reference Set:

https://www.patterndiagnostics.com/pattern-oriented-software-diagnostics-reference-set

Software Narratology (Literary Theory Terms, Part 2): abstract, accent, act, action, adaptation, address

November 8th, 2020

Abstract is usually the summary of an artifact (see Trace Summary analysis pattern) or not concrete description (see Analysis Pattern Square diagram).

Accent as stress in a line of verse has its correspondence to data in Message Pattern, which can be seen as a sequence of variables and Message Invariants.

Act as a play division corresponds to Activity Regions (see also trace partitioning and Activity Theatre analysis patterns).

Action as the main story of a narrative artifact may involve a sequence of selected Significant Events, Macrofunctions, Activity Regions with Motives. In a software narratological framework for presenting software storiesaction is a sequence of selected messages that constitutes a software plot (an acquired software artifact that may not be complete/full due to abridgment like restricting tracing/logging to selected components).

Adaptation as interpreting an artifact as a different one (from one media to another, or a different structure) is similar to treating memory dumps as traces/logs or vice versa as Projective Debugging.

Address as a story written for a specific group of people could be a software execution artifact explicitly acquired and adapted to some external users or Declarative Trace messages crafted for a specific team in mind (see also Embedded Comment analysis pattern).

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

Software Narratology (Literary Theory Terms, Part 1): ab ovo, in medias res, flashback, abridged edition

November 5th, 2020

Ab ovo is a software story (for example, a trace or log, a problem description, see software narratology square) that starts from the beginning of the use case events it narrates (see also Use Case Trail analysis patterns) or the start of software execution (see also Visibility Limit analysis pattern). Logging may start from some middle event of a use case, source code (see also Declarative Trace analysis pattern), or a log may be a part of a larger full trace (see also a software narratological framework for presenting software stories): in medias res. Such software stories may also have flashbacks, for example, stack traces, especially in software problem descriptions. Often, flashbacks are the only available software stories. Some tracing and logging sessions may be deliberately shortened to save space, communication throughput, or other reasons like security, similar to abridged editions of literary works (see also Abridged Dump and Missing Component analysis patterns). Such editions of software execution artifacts often hinder analysis (see Lateral Damage analysis pattern).

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

Trace Analysis Patterns (Part 202)

October 25th, 2020

Ideally a trace or log message should contain only one piece of information including associated data. However, some Multidimensional Messages may contain unrelated information, including several Message Invariants and variable data places, for example: “Entry GetData. Error opening file: 0×5″ or “Window handle: 0xa60834 pHandler: 0×456210F0″. Such messages may be split into several independent messages and, if necessary, additional ATIDs (new Adjoint Threads of Activity) may be added like depicted in this diagram of Combed Trace:

Another example is Exception Stack Trace messages in some logging implementations.

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

Trace Analysis Patterns (Part 201)

September 19th, 2020

If messages from (Adjoint) Thread of Activity also have associated traces (Fiber Bundle) then the latter messages data, for example, module names, can be interlinked with corresponding Adjoint Threads of Activity, thus forming “two-dimensional” Weave of Activity.

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

Crash Dump Analysis Patterns (Part 272)

September 18th, 2020

We introduced Procedure Call Chain in Stack Trace Collection and Coupled Processes analysis patterns. It is a stack trace formed by gluing stack trace fragments (for example, from LPC/ALPC and RPC Wait Chains) after removing middleware subtraces. For example, we use the following case study (32-bit for less space), follow its Wait Chain, and construct Procedure Call Chain (we use different colors to show gluing):

b88dccb8 804e1bf2 nt!KiSwapContext+0×2f
b88dccc4 804e1c3e nt!KiSwapThread+0×8a
b88dccec 8056dff6 nt!KeWaitForSingleObject+0×1c2
b88dcd50 804dd99f nt!NtWaitForSingleObject+0×9a
b88dcd50 7c90e514 nt!KiFastCallEntry+0xfc (TrapFrame @ b88dcd64)
036ef714 7c90df5a ntdll!KiFastSystemCallRet
036ef718 7c91b24b ntdll!ZwWaitForSingleObject+0xc
036ef7a0 7c901046 ntdll!RtlpWaitForCriticalSection+0×132
036ef7a8 6648a33b ntdll!RtlEnterCriticalSection+0×46
036ef7b0 6648c2ed ipnathlp!FwLock+0xa
036ef808 6648c705 ipnathlp!FwDynPortAdd+0×1d
036ef8c4 77e799f4 ipnathlp!FwOpenDynamicFwPort+0×125
00a9ef9c 662dafa9 hnetcfg!FwOpenDynamicFwPort+0×1b
00a9f048 71a55025 hnetcfg!IcfOpenDynamicFwPort+0×6a
00a9f0e4 71a590f2 mswsock!WSPBind+0×332
00a9f200 71ab2fd7 mswsock!WSPSendTo+0×230
00a9f250 76f252c0 WS2_32!sendto+0×88
00a9f280 76f251ea DNSAPI!SendMessagePrivate+0×18d
00a9f2a0 76f2517c DNSAPI!SendUsingServerInfo+0×33
00a9f2c8 76f25436 DNSAPI!SendUdpToNextDnsServers+0×80
00a9f314 76f24dec DNSAPI!Dns_SendAndRecvUdp+0×121
00a9f34c 76f24d20 DNSAPI!Dns_SendAndRecv+0×7b
00a9f37c 76f24a7d DNSAPI!Query_SingleName+0×8b
00a9f3b0 7677373a DNSAPI!Query_Main+0×11a
00a9f3c8 7677303f dnsrslvr!ResolverQuery+0×48
00a9f8bc 77e799f4 dnsrslvr!R_ResolverQuery+0×111
00a8f4c4 76f2357b DNSAPI!R_ResolverQuery+0×1b
00a8f520 71a526c6 DNSAPI!DnsQuery_W+0×14f
00a8f554 71a5266f mswsock!HostentBlob_Query+0×29
00a8f580 71a51b0a mswsock!Rnr_DoDnsLookup+0×7d
00a8f9c8 71ab32b0 mswsock!NSPLookupServiceNext+0×533
00a8f9e0 71ab3290 WS2_32!NSPROVIDER::NSPLookupServiceNext+0×17
00a8f9fc 71ab325a WS2_32!NSPROVIDERSTATE::LookupServiceNext+0×1c
00a8fa28 71ab31f8 WS2_32!NSQUERY::LookupServiceNext+0xae
00a8fa48 76f775eb WS2_32!WSALookupServiceNextW+0×78
00a8faec 76f6a9d2 WLDAP32!GetHostByNameW+0xef
00a8fb38 76f6667b WLDAP32!OpenLdapServer+0×435
00a8fb58 76f6fb05 WLDAP32!LdapConnect+0×169
00a8fef8 76f704f3 WLDAP32!LdapBind+0×34
00a8ff20 5e95651a WLDAP32!ldap_bind_sW+0×2c
00a8ff68 5e95a887 PAUTOENR!AERobustLdapBind+0xc9
00a8ffb4 7c80b729 PAUTOENR!AEMainThreadProc+0xef
00a8ffec 00000000 kernel32!BaseThreadStart+0×37

This similar to Glued Stack Trace which is produced from fragments that belong to one stack region.

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

Trace Analysis Patterns (Part 200)

September 13th, 2020

Trace and log analysis patterns may be additionally applied not only to a database like tables but also to texts (as an example of general trace and log analysis). Sentences may form trace messages with paragraphs and chapters corresponding to traditional ATIDs (IDs for Adjoint Threads of Activity) such as TID and PID in the most simple syntax mapping case, and certain sentences may be interpreted as Silent Messages.

Different attribute generation schemas may be used, for example, selected vocabulary may be used to assign TID numbers. More complex cases may require paratexts, supplementary texts providing additional structure and semantic information like in the case of Paratext memory analysis pattern, the case of extended traces.

The opposite process of converting traces and logs to text is also possible with additional paratext generation if necessary. We call this two-way analysis pattern Text Trace. After converting texts to logs it is possible to apply the majority of trace and log analysis patterns from the catalog.

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