Software Diagnostics Library

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 -

Several Strands of Activity from different types of ATIDs (Adjoint Threads of Activity) combine into Cord of Activity:

Between cord and rope analogies we chose cord as having “ord” (ordinal) in it (and c as cardinal). It is also possible to combine several Cords of Activity from different traces (Trace Dimension) to form a “cable-laid rope”. We don’t introduce a separate pattern here since in the resulting Trace Mask we have new Cord of Activity due to the additionally created ATID type referencing former separate traces and logs. Data references in messages may provide additional braiding via Braids of Activity.

We started with strands (we got the idea from the discussion of ethnomathematics where strand analysis was mentioned) but then we found the following useful discussion on rope terminology: “Art and Science of Rope“.

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

Strand of Activity combines different Threads of Activity or Adjoint Threads of Activity of the same type.

Strands extend cable and rope composition metaphors that start with Fibers of Activity, and continue with threads and Braids of Activity.

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

A page to reference all different kinds of stack trace frames is necessary, so I created this post:

• Coincidental Frames
• Least Common Frame
• Foreign Module Frame
• Aggregated Frames
• Frame Regularity
• Frame Trace
• False Frame

I’ll update it as soon as I add more similar patterns.

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

Often a debugger is not able to reconstruct a stack trace correctly, for example, when symbols to guide the process are not available due to Reduced Symbol Information or complete absence due to Unloaded Module:

0:008> k
# ChildEBP RetAddr
00 0250f4b8 76d21775 ntdll!NtWaitForMultipleObjects+0x15
01 0250f554 75c419fc KERNELBASE!WaitForMultipleObjectsEx+0x100
02 0250f59c 75c4268c kernel32!WaitForMultipleObjectsExImplementation+0xe0
03 0250f5b8 75c681fc kernel32!WaitForMultipleObjects+0x18
04 0250f624 75c680bb kernel32!WerpReportFaultInternal+0x186
05 0250f638 75c679b0 kernel32!WerpReportFault+0x70
06 0250f648 75c6792f kernel32!BasepReportFault+0x20
07 0250f6d4 00e21e86 kernel32!UnhandledExceptionFilter+0x1af
08 0250f6f0 75c803cf ModuleA!UnhandledExceptionFilter+0x3d
09 0250f778 77e250d7 kernel32!UnhandledExceptionFilter+0x127
0a 0250f780 77e24fb4 ntdll!__RtlUserThreadStart+0x62
0b 0250f794 77e24e59 ntdll!_EH4_CallFilterFunc+0x12
0c 0250f7bc 77e134a1 ntdll!_except_handler4+0x8e
0d 0250f7e0 77e13473 ntdll!ExecuteHandler2+0x26
0e 0250f804 77e13414 ntdll!ExecuteHandler+0x24
0f 0250f890 77dc0133 ntdll!RtlDispatchException+0x127
10 0250f890 68a8e0ca ntdll!KiUserExceptionDispatcher+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
11 0250fd58 02c45f58 <Unloaded_ModuleB.dll>+0x1e0ca
12 0250fd84 75c4343d 0×2c45f58
13 0250fd90 77de9812 kernel32!BaseThreadInitThunk+0xe
14 0250fdd0 77de97e5 ntdll!__RtlUserThreadStart+0×70
15 0250fde8 00000000 ntdll!_RtlUserThreadStart+0×1b

The address may be the valid return address from Execution Residue, but may also be completely random, non-executable:

0:008> ub 0×2c45f58
^ Unable to find valid previous instruction for ‘ub 0×2c45f58′

0:008> !address 0×2c45f58

Usage: Free
Base Address: 02bb0000
End Address: 02cb0000
Region Size: 00100000 ( 1.000 MB)
State: 00010000 MEM_FREE
Protect: 00000001 PAGE_NOACCESS
Type: <info not present at the target>

In our case, we have symbol files for ModuleB.dll but they don’t help.

0:008> .sympath+ C:\MemoryDumps\Modules\PDBs

If we have normal Manual Dumps we can compare Stack Trace Collections and take the advantage of existing Thread Posets to get the correct stack trace.

Alternatively, we can either use manual stack trace reconstruction techniques or use Injected Symbols:

0:008> lm
[...]
Unloaded modules:
[...]
68a70000 68ac0000 ModuleB.dll
[…]

0:008> .reload /f /i ModuleB.dll=68a70000
*** WARNING: Unable to verify timestamp for ModuleB.dll

0:008> kL
# ChildEBP RetAddr
00 0250f4b8 76d21775 ntdll!NtWaitForMultipleObjects+0x15
01 0250f554 75c419fc KERNELBASE!WaitForMultipleObjectsEx+0x100
02 0250f59c 75c4268c kernel32!WaitForMultipleObjectsExImplementation+0xe0
03 0250f5b8 75c681fc kernel32!WaitForMultipleObjects+0x18
04 0250f624 75c680bb kernel32!WerpReportFaultInternal+0x186
05 0250f638 75c679b0 kernel32!WerpReportFault+0x70
06 0250f648 75c6792f kernel32!BasepReportFault+0x20
07 0250f6d4 00e21e86 kernel32!UnhandledExceptionFilter+0x1af
08 0250f6f0 75c803cf ModuleA!UnhandledExceptionFilter+0x3d
09 0250f778 77e250d7 kernel32!UnhandledExceptionFilter+0x127
0a 0250f780 77e24fb4 ntdll!__RtlUserThreadStart+0x62
0b 0250f794 77e24e59 ntdll!_EH4_CallFilterFunc+0x12
0c 0250f7bc 77e134a1 ntdll!_except_handler4+0x8e
0d 0250f7e0 77e13473 ntdll!ExecuteHandler2+0x26
0e 0250f804 77e13414 ntdll!ExecuteHandler+0x24
0f 0250f890 77dc0133 ntdll!RtlDispatchException+0x127
10 0250f890 68a8e0ca ntdll!KiUserExceptionDispatcher+0xf
11 0250fd64 68a8f284 ModuleB!foo+0x5a
12 0250fd84 75c4343d ModuleB!bar+0xf4
13 0250fd90 77de9812 kernel32!BaseThreadInitThunk+0xe
14 0250fdd0 77de97e5 ntdll!__RtlUserThreadStart+0×70
15 0250fde8 00000000 ntdll!_RtlUserThreadStart+0×1b

We call this analysis pattern False Frame. Although we have Incorrect Stack Trace, just one stack trace frame is wrong. Sometimes, if there is Coincidental Symbolic Information available we get Coincidental Frames.

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

Sometimes we may want to Flag a message or Activity Region, for example, using Message Annotations. In other cases we may have Activity Regions are sorted by their coordinate-wise inclusion. Or we have inclusion of Message Sets. The analysis pattern name is borrowed from flag filtration in mathematics, where we consider subsets of messages and Activity Regions as subspaces. Dia|gram pictures of Flags may even resemble flags of some countries.

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

It is possible to foliate traces into separate traces having the same structure and scale (we also show corresponding Trace Fabric for the original trace):

In the diagram above Trace Foliation was done for message type, for example, error and normal messages. The reverse operation of Trace Mask would produce the same original trace.

Correspondingly Trace Fabric can be foliated too giving rise to “orchestra” representation and vice versa via Trace Mask:

Bars can be added with the help of Silent Messages.

The name of this analysis pattern was also inspired by foliations in mathematics.

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

Semantic Field is a set of messages that belong to particular category or subject:

It is different from Trace Field which is a function, not an already prepared codomain of mapping.

Some Semantic Fields may be formed by the analysis of Implementation Discourse, for example using machine learning techniques.

The pattern name was inspired by semantic field in linguistics and came to our attention when reading “German Loanwords in English: An Historical Dictionary” book.

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

If we take Combed Trace for Thread of Activity or some Adjoint Thread of Activity and strip other message content like we did for Trace Contour log analysis pattern we get individual braids that form Trace Fabric:

We can also get a stave representation of individual braids after a counter clockwise 90 degree rotation:

Bars can be added with the help of Silent Messages. Conversely, a musical piece can be transformed into some trace.

We mentioned “fabric” metaphor already when we introduced multibraiding.

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

If we take Combed Trace for Thread of Activity or some Adjoint Thread of Activity, strip other message content, and then trace all non-empty values we get Trace Contour:

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

Traces and logs from diverse software systems doing different things may have similar Trace Shape despite completely different message content, especially for specific Threads of Activity or Adjoint Threads of Activity:

This may be apparent when we compare Trace Shape of Quotient Trace.

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

If we have an attribute we can sort messages based on that attribute values and get Sorted Trace. If that attribute is TID or ATID we get the sequence of Threads of Activity or Adjoint Threads of Activity:

If we sort by message types or Message Invariants or some message data we get a sequence of Fibers of Activity.

The diagram above also shows on the right Quotient Trace by message type equivalence after additional sorting inside each Adjoint Thread of Activity.

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

Causal History messages (black circles) pass through Activity Regions which can be marked as hollow circles:

We call this analysis pattern Trace D’Enfant by analogy with dessin d’enfant in mathematics, a bipartite graph embedded in an oriented surface, so in theory Traces D’Enfants can be studied algebraically.

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

The relations between Causal History messages (0-chains) can be abstracted as Causal Chains (1-chains). Two relations can be linked if an endpoint of one is also a beginning point of another:

The relations of 1-chains can be abstracted as 2-chains and so on (n-chains):

We took the idea of relation spaces and chains from already quoted “Discreet Causal Theory” book. Causal chain terminology is also used in philosophy.

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

When looking at Causal History we can choose Causal Messages (not necesseraly the top ones):

Causal Messages may not overlap with the trace Defect Group which may not have any causal relevance being only correlation messages.

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

Trace Paths and Back Traces form Causal History of the log where arrows point in the direction of possible causation:

Here we borrow the notion of causal sets from physics and corresponding mathematics. The left diagramming idea was taken from Discrete Causal Theory book and Hasse diagrams (which is inverted in our picture). Also, such graphs are internal to software narratives compared to the more general external space we proposed earlier.

We omit Time arrow as it is possible to consider general traces and logs with their causality markers.

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

Some trace acquisition methods and analysis workflows may require Trace Summaries having some timing and other statistical information to play the role of Indexical Trace when combined together:

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

Trace analysis gestures that result in CoTrace also produce Trace Path between messages of interest:

Such Trace Paths can also be useful for Trace Homotopy analysis. They also provide the basis for Explanation Traces.

Note that Trace Path is also a reverse for Back Trace analysis pattern. Both are usually selected from Working Set.

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

We call the association of external global variables, for example, the number of threads in the system and context switches, Trace Flux analysis pattern. Such variables can be discreet or continuous. Here we adopt the definition of flux as “a global physical variable associated with a surface and a time instant” from Enzo Tonti’s book “The Mathematical Structure of Classical and Relativistic Physics”.

This is different than the internal functional association, Thread Field.

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

One of the earliest memory analysis patterns, Lateral Damage now has a specialization for CPU mode. Due to some reasons, we may get a dump with a different default CPU mode, for example, WOW64 or even V86 segmented memory addressing mode. In such a case, most commands will not work or give incorrect output.

In one such a dump we see 32-bit bugcheck parameters in !analyze -v command output:

CRITICAL_OBJECT_TERMINATION (f4)
A process or thread crucial to system operation has unexpectedly exited or been
terminated.
Several processes and threads are necessary for the operation of the
system; when they are terminated (for any reason), the system can no
longer function.
Arguments:
Arg1: 00000003, Process
Arg2: 054d0450, Terminating object
Arg3: 054d0730, Process image file name
Arg4: 02b90db0, Explanatory message (ascii)

But the dump itself from x64 Windows:

Kernel base = 0xfffff800`0280d000 PsLoadedModuleList = 0xfffff800`02a52e90

We notice WOW64 prompt:

16.1: kd:x86> k
# ChildEBP          RetAddr
WARNING: Frame IP not in any known module. Following frames may be wrong.
00 00000000 00000000 0x0

We switch to x64 mode:

16.1: kd:x86> .effmach AMD64
Effective machine: x64 (AMD64)

Now we get correct bugcheck parameters:

16.1: kd> !analyze -v
[...]
Arguments:
Arg1: 0000000000000003, Process
Arg2: fffffa80054d0450, Terminating object
Arg3: fffffa80054d0730, Process image file name
Arg4: fffff80002b90db0, Explanatory message (ascii)
[…]

However, the stack trace is not available, all registers are zeroed, and stack region memory is not accessible:

16.1: kd> k
# Child-SP          RetAddr           Call Site
00 00000000`00000000 00000000`00000000 0x0

16.1: kd> !thread
THREAD fffffa800b2c6b60  Cid 0998.1a58  Teb: 000007ffffeee000 Win32Thread: 0000000000000000 RUNNING on processor 1
Not impersonating
DeviceMap                 fffff8a000008aa0
Owning Process            fffffa800425b820       Image:         App.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      28317542       Ticks: 0
Context Switch Count      2              IdealProcessor: 0
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address 0x000007feee8080ec
Stack Init fffff880066f3c70 Current fffff880066f3440
Base fffff880066f4000 Limit fffff880066ee000 Call 0000000000000000
Priority 8 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Args to Child                                                           : Call Site
00000000`00000000 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : 0×0

16.1: kd> r
rax=0000000000000000 rbx=0000000000000000 rcx=0000000000000000
rdx=0000000000000000 rsi=0000000000000000 rdi=0000000000000000
rip=0000000000000000 rsp=0000000000000000 rbp=0000000000000000
r8=0000000000000000  r9=0000000000000000 r10=0000000000000000
r11=0000000000000000 r12=0000000000000000 r13=0000000000000000
r14=0000000000000000 r15=0000000000000000
iopl=0         nv up di pl nz na pe nc
cs=0000  ss=0000  ds=0000  es=0000  fs=0000  gs=0000             efl=00000000
00000000`00000000 ??              ???

16.1: kd> dp fffff880066f3440
0000:3440  ????????`???????? ????????`????????
0000:3450  ????????`???????? ????????`????????
0000:3460  ????????`???????? ????????`????????
0000:3470  ????????`???????? ????????`????????
0000:3480  ????????`???????? ????????`????????
0000:3490  ????????`???????? ????????`????????
0000:34a0  ????????`???????? ????????`????????
0000:34b0  ????????`???????? ????????`????????

We notice segmented memory addressing and apply .segmentation command that is still available (the hint is taken from here):

16.1: kd> .segmentation /V /X /a
In x86 v86 code: no
In x86 16-bit code: no
In amd64 64-bit code: yes

Although stack trace is not available we see the normal prompt and can get look at stack region Execution Residue and get Rough Stack Trace:

1: kd> k
# Child-SP          RetAddr           Call Site
00 00000000`00000000 00000000`00000000 0x0

1: kd> dpS fffff880066ee000 fffff880066f4000
fffff800`02b7e79e nt!PspGetSetContextInternal+0×2c6
fffff800`02b7e8e5 nt!PspGetSetContextInternal+0×40d
fffff800`0289e11e nt!MiResolveDemandZeroFault+0×3be
fffff800`02e04245 hal!HalpPCIPerformConfigAccess+0×55
fffff800`02e04b32 hal!HalpPciAccessMmConfigSpace+0×196
fffff880`051f224f dump_diskdump!WorkHorseDpc+0×18f
fffff800`02e04000 hal!HalpPCIConfig+0×70
fffff880`051f3dbb dump_diskdump!ScsiPortNotification+0×107
fffff880`04c0386f dump_LSI_SAS!BuildScatterGather+0xcf [e:\win7\drivers\oem\src\storage\lsi_sas\ca_init.c @ 2468]
fffff880`04c086c2 dump_LSI_SAS!CheckInqFlagReplies+0×42e [e:\win7\drivers\oem\src\storage\lsi_sas\ca_util.c @ 6455]
fffff800`028cdf7e nt!iswctype_l+0xce
fffff880`051f224f dump_diskdump!WorkHorseDpc+0×18f
fffff800`028cde19 nt!output_l+0×6e1
fffff880`051e9110 crashdmp!StrBeginningDump
fffff880`051f3dbb dump_diskdump!ScsiPortNotification+0×107
fffff800`028cde19 nt!output_l+0×6e1
fffff880`04c0386f dump_LSI_SAS!BuildScatterGather+0xcf [e:\win7\drivers\oem\src\storage\lsi_sas\ca_init.c @ 2468]
fffff880`04c12090 dump_LSI_SAS!LSImpiMSIIsr+0xf4 [e:\win7\drivers\oem\src\storage\lsi_sas\ca_int.c @ 208]
fffff880`04c0386f dump_LSI_SAS!BuildScatterGather+0xcf [e:\win7\drivers\oem\src\storage\lsi_sas\ca_init.c @ 2468]
fffff880`051f224f dump_diskdump!WorkHorseDpc+0×18f
fffff800`02e072ec hal!HalpTscStallExecutionProcessor+0xe8
fffff880`051f2401 dump_diskdump!AllocateScatterGatherList+0×5d
fffff880`051f257c dump_diskdump!ExecuteSrb+0×68
fffff880`051e9370 crashdmp!Context+0×30
fffff880`051e9370 crashdmp!Context+0×30
fffff800`0292810c nt!DisplayCharacter+0×5c
fffff880`051f3a9d dump_diskdump!ScsiPortInitialize+0×805
fffff880`051e9370 crashdmp!Context+0×30
fffff800`02929c33 nt!VidDisplayString+0×73
fffff880`051e9370 crashdmp!Context+0×30
fffff880`051e6440 crashdmp!IsBufferValid+0×28
fffff880`051e5f7a crashdmp!FilterCallback+0xae
fffff880`051f2a79 dump_diskdump!DiskDumpWrite+0×1a9
fffff880`051e5d76 crashdmp!CrashdmpWriteRoutine+0×4a
fffff880`051e4f48 crashdmp!WritePageSpanToDisk+0×180
fffff880`051e9370 crashdmp!Context+0×30
fffff880`051e9370 crashdmp!Context+0×30
fffff880`051e4c95 crashdmp!WriteKernelDump+0×12d
fffff880`051e5d2c crashdmp!CrashdmpWriteRoutine
fffff800`02a85b60 nt!KeBugCheckAddPagesCallbackListHead
fffff880`051e4ac5 crashdmp!DumpWrite+0×145
fffff880`051e9370 crashdmp!Context+0×30
fffff880`051e4187 crashdmp!CrashdmpWrite+0×57
fffff880`051e9a30 crashdmp!ContextCopy
fffff800`02a85b60 nt!KeBugCheckAddPagesCallbackListHead
fffff800`02974bc1 nt!IoWriteCrashDump+0×391
fffff800`02a898a0 nt!IopTriageDumpDataBlocks
fffff800`02a85b60 nt!KeBugCheckAddPagesCallbackListHead
fffff800`02a85b60 nt!KeBugCheckAddPagesCallbackListHead
fffff800`02936de0 nt!IoSetDumpRange
fffff800`02936d30 nt!IoFreeDumpRange
fffff800`02abe900 nt!KiProcessorBlock
fffff800`0280d000 nt!KiSelectNextThread <PERF> (nt+0×0)
fffff800`02975f26 nt!KeBugCheck2+0xac6
fffff800`02b90db0 nt! ?? ::NNGAKEGL::`string’
fffff800`028a051e nt!SepNormalAccessCheck+0×18e
fffff800`02b90db0 nt! ?? ::NNGAKEGL::`string’
fffff800`02e0a501 hal!HalpSendFlatIpi+0×92
fffff800`02b90db0 nt! ?? ::NNGAKEGL::`string’
fffff800`0288d744 nt!KeBugCheckEx+0×104
fffff800`02b90db0 nt! ?? ::NNGAKEGL::`string’
fffff800`02c15982 nt!PspCatchCriticalBreak+0×92
fffff800`02b90db0 nt! ?? ::NNGAKEGL::`string’
fffff800`02bc30ab nt! ?? ::NNGAKEGL::`string’+0×17ad6
fffff800`02b46698 nt!NtTerminateProcess+0xf4
fffff800`0288c8d3 nt!KiSystemServiceCopyEnd+0×13
????????`????????

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