Archive for the ‘Software Trace Reading’ Category

Trace Analysis Patterns (Part 92)

Sunday, November 9th, 2014

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

Trace Analysis Patterns (Part 88)

Tuesday, June 24th, 2014

The previous patterns such as Basic Facts and Vocabulary Index address the mapping of a problem description to software execution artefacts such traces and logs. Indirect Facts analysis pattern addresses the problem of an incomplete problem description. However, we need another pattern for completeness that addresses the mapping from a log to troubleshooting and debugging recommendations. We call it Hidden Facts which are uncovered by trace analysis. Of course, there can be many such hidden facts and usually they are uncovered after narrowing down analysis to particular Threads of Activity, Adjoint Threads, Message Context, Message Set, or Data Flow. The need for that pattern had arisen during the pattern-oriented analysis of the trace case study from Malcolm McCaffery and can be illustrated on this diagram:

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 86)

Tuesday, May 20th, 2014

When we see Error Message or Exception Stack Trace in a log file we might want to explore the sequence of messages from the same Thread of Activity that led to the error. Such Message Set has an analogy with memory analysis patterns such as Execution Residue (of partial stack traces without overwrites) and Stack Trace (where the error message is a top stack frame) and we call this pattern Error Thread:

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 85)

Monday, May 12th, 2014

Most of the time, especially for large software logs, we need to select messages based on some criteria be it a set of Error Messages, a set of messages containing Basic Facts, or some other predicate. Then we can use selected messages from that Message Set as Anchor Messages or reverse Pivot Messages as an aid in further analysis.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 82)

Monday, May 5th, 2014

So far we have been discussing trace analysis patterns related to execution of a particular software version. However, software code changes and also its tracing and logging output: from large scale changes where components are replaced to small scale code refactoring affecting message structure and format. On a software narratological level this corresponds to a narrative about a software trace or log, it evolution. Such Meta Trace analysis pattern is different from Master Trace pattern where the latter is similar to what Metanarrative is usually meant in narratology: a master or grand idea - an expected trace if all functional requirements were correctly identified and implemented during software construction and non-functional ones are met during software execution.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 81)

Friday, May 2nd, 2014

Sometimes we are interested in changes in particular {property, value} pairs or in tuples {x1,x2,x3,…) in general where xi can be a number or a substring. This is more general pattern than Message Change because such tuples can be from different sources and belong to different messages:

This pattern is also different from Data Flow where a value stays constant across different sources and messages. It is also different from Gossip pattern which involves more semantic changes. Metaphorically we can think of Data Association pattern as a partial derivative.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 80)

Monday, April 21st, 2014

Sometimes we know from Basic Facts some data or activity we seek to identify in different traces collected together to perform inter-correlational analysis. It can be a shared file name, a named synchronization object, a locked file with sharing violations, a common virtual address in kernel space, or just some activity notification. We call this pattern Shared Point by analogy with intersecting curves in some abstract space.

It is similar to Linked Messages pattern but is more high level and not confined to a common parameter (can be an action description).

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 74)

Friday, July 19th, 2013

Most of the time when we look at software trace fragments we recognize certain Motifs* such as client-server interaction, publisher-subscriber notifications, database queries, plugin sequence initialization, etc. This pattern is different from Master Trace which corresponds to a normal use-case or working software scenario and may actually contain several Motifs as it is usually happens in complex software environments. On the other side of the spectrum there are software narremes (basic narrative units) and Macrofunctions (single semantic units). Motifs help to further bridge the great divide between software construction and software diagnostics with software narremes corresponding to implementation patterns, macrofunctions to design patterns, and motifs to architectural patterns although an overlap between these categories is possible.

* The idea of a pattern name comes from motives in mathematics.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 72)

Tuesday, May 21st, 2013

Sometimes we look at a trace or log and instead of Error Messages we only see their “signs” such as a DLL load event for an error or fault reporting module or a module that is related to symbol files such diasymreader.dll. We call this pattern Hidden Error by an analogy to Hidden Exception in memory dump analysis pattern catalogue although sometimes we can see such modules in memory dump Module Collection. For example, the presence of diasymreader module may signify an unreported .NET exception and suggest a dump collection strategy.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 71)

Sunday, May 12th, 2013

Sometimes we need to analyse Last Activity before Significant Event or Discontinuity. By this pattern we mean a loose semantic collection of messages before process exit, for example. This might give some clues to further troubleshooting. In one incident a process was suddenly exiting. Its own detailed trace didn’t have any messages explaining that probably due to insufficient tracing coverage (Sparse Trace). Fortunately, a different external trace (from Process Monitor) was collected (Inter-Correlation) and it had LDAP network communication messages just before thread and process exit events.

- Dmitry Vostokov @ + -   

Trace Analysis Patterns (Part 70)

Saturday, May 4th, 2013

For event- or message-driven architectures it is important to differentiate between event and state messages (including state transition). For example, a system may be doing some work while being in some particular state with a lot of tracing and respond to various external events with each of them having a corresponding trace message. Upon such an event the system transitions to some other state with its own set of possible trace messages. We call such a pattern State and Event. Typical example here is a windowing terminal services system and WM_ENDSESSION event illustrated in the following abstract trace diagram with a corresponding state transition diagram below it:

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 69)

Thursday, April 25th, 2013

Sometimes in the case of missing Basic Facts we can discern Indirect Facts from message text and even from other patterns. For example, in one incident we were interested in all messages from the certain process name but its PID was missing from the problem description. Fortunately we were able to get its PID from one of individual messages from completely different source:

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 68)

Saturday, March 23rd, 2013

While preparing a presentation on malware narratives we found that one essential pattern is missing from the current log analysis pattern catalog. Most of the time we see some abnormal or unexpected value in a software trace or log such as a network address outside expected range and this triggers further investigation. The message structure may be the same having the same Message Invariant but variable part may contain such values as depicted graphically:

We call this pattern Abnormal Value and plan to add the similar one to memory dump analysis pattern catalog. Please not that we also have Significant Event pattern that is more general and also covers messages without variable part or just suspicious log entries.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 67)

Wednesday, March 20th, 2013

Sometimes we have insufficiently detailed problem description and/or there are several similar parallel user activities going on simultaneously, for example, several session are launched in a terminal services environment. In such cases when tracing is done for the duration of specific user activity Dominant Event Sequence pattern may help. Here we select the most full sequence of events or event sequence based on some Basic Facts. For example, if session id was missing in problem description we can choose the most long and full process launch seqence and assume that its session id was the one missing:

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 66)

Saturday, March 16th, 2013

Suppose we form an adjoint thread based on some message or operation type or some other attribute:

But we do not know where to start to look backwards for any anomalies relevant to our problem:

We go back to our full trace and find a problem message:

Although it is not in our adjoint thread we formed previously it is still considered as Pivot Message helping us to go backwards there:

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 65)

Thursday, March 14th, 2013

If Implementation Discourse focuses on objective technology specific discourse then Traces of Individuality pattern focuses on subjective elements in a software log and its messages. Here we mean some specific naming or tracing conventions either from an individual engineer habit or from some corporate coding standard. As an example of it consider a trace message from a catch statement:

"Surprise, surprise, should have never been caught"

More examples for this pattern will be added later.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 64)

Friday, February 15th, 2013

Inter-Correlation analysis between a normal and a problem logs to find a Bifurcation Point (and a possible root cause) becomes a difficult task when both traces come from different environments with widely differing Background Components. Here a new analysis pattern called Sheaf of Activities (borrowed from sheaves from mathematics) can help. Basically this pattern is also a tool in tracking properties of trace message subsets. First we find out important message types around some Activity Region where we hope to find a difference between two traces:

Then we create several Adjoint Threads from different message types, for example, based on operation type or function name:

Then we analyze subtraces separately to find out a bifurcation point in each of them and then use this knowledge to find out differences between the original full traces.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 63)

Friday, February 8th, 2013

Indexical Trace pattern describes an Inter-Correlation pattern variant when we have a trace that has messages of interest pointing to specific activity regions in another trace. The latter trace can be very huge, from another computer and split into many parts (Split Trace). This pattern is very helpful when the problem needs to be diagnosed in the large split trace but we don’t know when it happened. Then an index trace that may have recorded software execution account (for example, in the case of a broker-like architecture) and can point to the right trace fragment from the split trace.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 62)

Friday, December 14th, 2012

This pattern is called Opposition Messages (borrowed from binary opposition originated in Saussure’s structuralism). It covers the following pairs of messages usually found in software traces and logs such as:

  • open / close
  • create / destroy
  • allocate / free (deallocate)
  • call / return
  • enter / exit (leave)
  • load / unload
  • save / load
  • lock / unlock
  • map / unmap

The absence of an opposite may point to some problems such as synchronization and leaks or Incomplete History (wait chains). There can always be a possibility that a second term is missing due to Sparse Trace but this is a poor implementation choice that leads to confusion during troubleshooting and debugging.

- Dmitry Vostokov @ + -

Trace Analysis Patterns (Part 61)

Thursday, December 13th, 2012

Some tracing tools such as Citrix CDFControl have an option to split software traces and logs into several files during long recording. Although this should be done judiciously it is really necessary sometimes. We call this pattern Split Trace. What to do if we get several trace files and we want to use some other analysis tool such as Citrix CDFAnalyzer? If we know that the problem happened just before the tracing was stopped we can look at the last few such files from the file sequence (although we recommend a circular trace here). Otherwise we can convert them into CVS files and import into Excel which also supports adjoint threading.

- Dmitry Vostokov @ + -