Software Diagnostics Library

Status updates, error message boxes, and even abort errors can all be considered as examples of software traces and logs. We call such a log with one message only Singleton Trace. Please don’t confuse it with Singleton Event analysis pattern which is trivial for Singleton Traces. We illustrate this pattern with this picture of error message (in Russian it means “The machine doesn’t work. Code: SB”) from a lemonade-dispensing machine:

The message in such a trace may contain the associated stack trace as a trivial example of Fiber Bundle.

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

When doing Inter-Correlational analysis between different traces and logs we can move simultaneously along time direction or backwards (Back Tracing). In some cases we may start our analysis with the identification of Significant Events in both logs and then move in opposite directions finding another pair of messages that can be useful for diagnostic identification. We call this analysis pattern Galois Trace by analogy with Galois connection in mathematics. In our case moving from trace A to trace B and back corresponds to F and G functions with a and b as individual trace messages or their Message Contexts (as per monotone definition). The analysis pattern is illustrated in the following diagram:

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

For completeness, we add Aggregated Frames analysis pattern implemented as “aggregated stack trace” in various software performance profiling tools. Such tools periodically record CPU Stack Trace Collection. Other tools profile memory allocations and their stack traces. By aggregation we mean summing up occurrences of modules and functions from all collected stack traces similar to this table:

ModuleA         88%
   +0x234          42%
   +0x123           8%
   !foo            38%
      +0xd            30%
      +0x56            2%
   !bar             6%
      +0x18            6%
ModuleB         12%
   !export         12%
      +0x2380          1%
      +0x1224          6%
      +0x3812          5%

Related to memory dump analysis we can either use Stack Trace Collection to detect Ubiquitous Component in user and kernel spaces, or database Stack Traces, for example, used in detection of process heap, handle, and reference Memory Leaks.

We do not include “stack” in the name of this pattern because frames are not sorted by the execution direction compared to Unified Stack Trace analysis pattern where we have some notion of aggregation depicted as multiplicities.

We can also name it as Frame Usage Signature similar to Stack Trace Signature.

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

We can apply Message Set trace and log analysis pattern to itself and build multilevel Message Directory. The pattern name come from the analogy with memory management page tables, where we can select every 10th message to build a smaller Message Set, and then select every 10th message from it to build another Message Set, and so on. When looking at a higher level Message Set we can select a trace message and then look at its Message Context in the lower level Message Sets:

Message Directory is similar to Trace Frames analysis pattern but is fine-grained, and more individual message oriented than the latter analysis pattern. However, the former pattern can be used to implement the latter one.

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

The dual analysis technique to Adjoint Spaces trace and log analysis pattern is called Memory Fibration (by analogy with fibrations in mathematics). Certain process spaces may have associated external logs so the dynamics of memory can be examined backwards. Such traces and logs may be the parts of just one bigger log as Adjoint Threads of Activity with their PIDs as ATIDs.

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

Having chosen a trace message, we are interested in its Message Context which can span all “continuous” messages before and after from the same Thread of Activity. We it Activity Quantum which is variable and independent from the so-called CPU quantums. Different messages from Activity Quantum may be executed on different CPUs. The following diagram depicts this analysis pattern:

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

Here we introduce Delay Dynamics analysis pattern. It is not an oxymoron and dynamics is referred to by what actually happens during the delay (Discontinuity with Time Delta) in other Threads of Activity as depicted in the following diagram:

Instead of threads various Adjoint Threads of Activity may also be inspected.

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

One of the trace attributes we didn’t pay much attention to in the past is CPU. This column is present in some ETW-based trace implementations such as Citrix CDF traces. As any trace attribute, it can be used to form Adjoint Thread of Activity (as all messages from code executed on that particular CPU). As we already considered threads as braids, we use braid groups as a further metaphor. In our case we combine CPUs and threads into one group which uses permutation for CPU scheduling. Instead of permutations, twists may be modeled as changes of threads. The Braid Group analysis pattern is illustrated in the following diagram:

This is a preliminary description of the analysis pattern. We plan to elaborate on it in further case studies. For example, instead of multithreading we can use multibraiding.

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

Recently we found a correlation between software trace with high Statement Density and Current of Periodic Error with uniform Error Distribution and process heap Memory Leak suspected from  memory dump analysis. If we metaphorically view periodic errors as “frequency” and the size of a heap as “mass” we may see that the growth of “frequency” correlates with the growth of “mass” and vice versa. Since frequency is inversely proportional to wave length we see a metaphorical analog to Louis de Broglie’s wave-particle duality. In general, as we already pointed in the discussion of narrativity and spatiality of software execution artifacts (see also Software Trace and Memory Dump Analysis seminar), software traces / logs and memory dumps can be seen as “dual” to each other according (metaphorically again) to de Broglie’s “duality of the laws of nature”. So we name this analysis pattern De Broglie Trace Duality since some memory dump regions can be considered of a general trace nature. Our correlation can be depicted in this diagram:

Practically, when we see Memory Consumption Patterns (but don’t know their source / root cause yet) we can ask for traces and logs, and in the case of frequent Periodic Errors found there we can suggest troubleshooting steps that may serve as a resolution or workaround.

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

Considering and extending Trace Dimension to TID, ATID, and Time we use Poincaré section and Poincaré map analogies to introduce Poincaré Trace analysis pattern. We choose a value of one “coordinate”, for example, Time, and then form the new trace that consists of messages from different (A)TIDs that have the same timestamp as Time value or the last message(s) from other different ATIDs if they happened before section Time:

If we choose a different ATID than Time and TID, then Poincare Trace is equivalent to Adjoint Thread of Activity. If ATID is TID we have Thread of Activity as a trivial case. If we have Thread of Activity, we can choose some ATID and get Poincaré Trace as illustrated in the following diagram where the thick black line in the right Poincaré Trace represents Discontinuity and its Time Delta:

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

There are messages in traces and logs that alone do not have useful information. These are adornments or ornamentation messages that we initially called Delineator or Separator messages that structure message stream or Figural Events (where we borrowed the name figural from Lyotard) such as formatting the next message with { }. Such messages only make meaning with other meaningful messages. We call this pattern Ornament. It helps in using trace analysis patterns and trace pattern identification.

Ornament can also be present inside individual messages, for example, as a character prefix. It can be a part of Message Invariant or variable itself. Some ornamentation can play a rhetorical function.

Although ornament is present in non-software architecture this concept has never been explored in pattern–oriented software architecture and construction. We propose similar concept for source code (software construction) in addition to ornamentation of its Declarative Trace. For software post-construction, we also add ornament part to software structure and behavior parts.

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

When we have hundreds of separate trace files from Split Trace and a smaller Split Trace with fewer files or just a single trace file that was recorded simultaneously (for example, a client from client-server environment) we can “project” the smaller Message Space into the larger Message Space as depicted in the following diagram:

This Projective Space analysis pattern can be used in conjunction with Indexical Trace where time interval can be used as an index into the larger Split Trace. Such projection may not be accurate but, assuming that the target trace Statement Current is uniform on average, can still be a very good heuristic instead of a binary search. For example, recently we had 4 sequential trace files for the client and 36 sequential files for the server. The software problem interval was specified in Basic Facts. We found that it in the second path of the 4th client trace. We, therefore, only inspected the last 4 traces of the 36 server sequential trace set and found it contained in the 35th server trace.

This pattern uses projective space metaphor from mathematics.

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

Long time go we introduced the notion of Collapsed Stack Trace (Volume 3, page 381) when all functions are removed from Stack Trace (for example, kc WinDbg command) and remaining repeated modules are removed similar to Quotient Trace analysis pattern. It is similar to Stack Trace Signature with frame count set to 1. We originally planned to call this pattern Compact Stack (Trace) and it was on our list of possible future analysis patterns. This came to our attention again while preparing “Theoretical Software Diagnostics” book and we decided to publish it under the name Quotient Stack Trace as a specialization of the more general trace and log analysis pattern.

Such a pattern may be useful for the analysis of module Wait Chains.

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

In Adjoint Message analysis pattern description we mentioned compressing message sequences having the same message attribute into one message. Considering the trace as “topological” space and message attribute as “equivalence” relation we introduce Quotient Trace analysis pattern by analogy with quotient space in topology. By endowing message sequences having the same attribute with some “metric” such as cardinality of Message Set we can also visually distinguish resulted quotient messages if they have the same attribute but from different sequences at different times. All this is illustrated in the following diagram:

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

Stack traces resemble functions: they have prolog, body, and epilog. Frame trace is also similar to trace Partition analysis pattern. Bottom stack subtrace plays the role of prolog, for example, thread initialization and RPC call stub dispatch. Middle stack subtrace plays the role of body or core, for example, application specific function calls invoked by RPC. Top stack subtrace plays the role of epilogue, for example, system calls. Such stack trace partition is useful for stack trace matching, especially when symbols are not available. In such a case Stack Trace Signature of module names and their frame counts may help (together with Crash Signature where appropriate):

The following stack trace may be split into TMB (pronounced Tomb):

0:001> kc
# Call Site
00 ntdll!RtlEnterCriticalSection
01 ModuleA
02 ModuleA
03 ModuleA
04 ModuleA
05 ModuleA
06 ModuleA
07 ModuleA
08 ModuleA
09 ModuleA
0a ModuleA
0b ModuleA
0c ModuleA
0d ModuleA
0e ModuleA
0f ModuleA
10 rpcrt4!Invoke
11 rpcrt4!NdrStubCall2
12 rpcrt4!NdrServerCall2
13 rpcrt4!DispatchToStubInCNoAvrf
14 rpcrt4!RPC_INTERFACE::DispatchToStubWorker
15 rpcrt4!RPC_INTERFACE::DispatchToStub
16 rpcrt4!RPC_INTERFACE::DispatchToStubWithObject
17 rpcrt4!LRPC_SCALL::DispatchRequest
18 rpcrt4!LRPC_SCALL::HandleRequest
19 rpcrt4!LRPC_SASSOCIATION::HandleRequest
1a rpcrt4!LRPC_ADDRESS::HandleRequest
1b rpcrt4!LRPC_ADDRESS::ProcessIO
1c rpcrt4!LrpcIoComplete
1d ntdll!TppAlpcpExecuteCallback
1e ntdll!TppWorkerThread
1f kernel32!BaseThreadInitThunk
20 ntdll!RtlUserThreadStart

It has the following signature:

T<ntdll,1>M<ModuleA,15>B<rpcrt4,13>B<ntdll,2>B<kernel32,1>B<ntdll,1>

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

Sometimes log messages are formatted with mistakes, buffers are not cleared before copying, copied strings are truncated, tracing implementation and presentation contains coding defects. There can be internal corruption when messages are formed or “corruption” during presentation, for example, default field conversion rules (like in Excel). We call this pattern Corrupt Message. Such messages may affect trace and log analysis where data search may not show full relevant results. We then recommend to double check findings by using Data Flow of a different Message Invariant.

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

Sometimes, the presence of some messages in a trace or log shows that some other tracing or logging tool was running or that some process was also doing tracing. We call this analysis pattern Surveyor. Such discovered tracing may not be related to the trace we are looking at (compare to Trace Extension) but may help with finding additional traces in the system as illustrated in the following diagram:

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

Recently we performed the diagnostic analysis of a software incident where certain functionality was not available to users and provided the report based on analysis patterns such as Focus of Tracing and Opposition Messages. We also conjectured some hypotheses explaining the observed abnormal behaviour. However, at the end, the problem was solved not by the analysis of a lengthy software execution log but by looking at the small configuration INI file where not working functionality was simply disabled in one line:

EnableFunctionality = 0

Even before that analysis we were thinking about the importance of Small DA+TA such as configuration files and registry details that can be considered as general software traces. Here DA+TA means Dump Artefact + Trace Artefact and Big DA+TA refers to software execution memory dump artefacts and trace artefacts that can be really huge. The analysis pattern is illustrated in the following diagram where we see no difference between working and non-working scenarios due to insufficient trace coverage (Sparse Trace):

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

In addition to Message Patterns there are higher level patterns of specific activities and Motives. Such activities may or may not coincide with specific components (modules) because they may be grouped based on implementation messages, software internals semantics and not on architectural and design entities (as in Use Case Trail analysis pattern). Moreover, he same components may “play” different activity roles. Once assigned, Activity Theatre “scripts” can be compared with “scripts” from other traces and logs (Inter-Correlation) or different parts of the same log (Intra-Correlation). This pattern is illustrated in the following diagram:

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