Software Diagnostics Library

When analysing Inter-Correlation or Intra-Correlation and finding Discontinuities in one part or in a different trace (for example, in client-server environments) it is useful to see if there are corresponding Correlated Discontinuities in another part of the same trace (for example, a different Thread of Activity) or in a different trace. Such pattern may point to the underlying communication problem and may suggest to gather a different trace (for example, a network trace) for further analysis.

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

While working on Mobile Software Diagnostics webinar and exploring the richness of Android platform and similarity of its LogCat traces (Eclipse representation) to Minimal Trace Graphs (see a corresponding slide in trace analysis pattern reference) we recognized the time has come to provide a Java implementation for a general software narratological pattern-oriented trace analysis approach and also see what memory analysis patterns can also be applied there. Here by implementation we mean concrete platform examples. For example, in the past we did similar implementations of memory analysis patterns (originally developed for unmanaged and native Windows code) for .NET (WinDbg) and Mac OS X (GDB). The first trace analysis pattern we cover here is very obvious and simple and is called Exception Stack Trace. In the original pattern example a stack trace was inside a single trace message but can also be split such as each frame has its own message (date and time columns were removed for clarity):

E/AndroidRuntime(31416): java.lang.NullPointerException
E/AndroidRuntime(31416):  at android.view.MotionEvent.writeToParcel(MotionEvent.java:1596)
E/AndroidRuntime(31416):  at com.example.nullpointer.FullscreenActivity$1.onTouch(FullscreenActivity.java:139)
E/AndroidRuntime(31416):  at android.view.View.dispatchTouchEvent(View.java:3881)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at com.android.internal.policy.impl.PhoneWindow$DecorView. superDispatchTouchEvent(PhoneWindow.java:1750)
E/AndroidRuntime(31416):  at com.android.internal.policy.impl.PhoneWindow. superDispatchTouchEvent(PhoneWindow.java:1135)
E/AndroidRuntime(31416):  at android.app.Activity.dispatchTouchEvent(Activity.java:2096)
E/AndroidRuntime(31416):  at com.android.internal.policy.impl.PhoneWindow$DecorView. dispatchTouchEvent(PhoneWindow.java:1734)
E/AndroidRuntime(31416):  at android.view.ViewRoot.deliverPointerEvent(ViewRoot.java:2216)
E/AndroidRuntime(31416):  at android.view.ViewRoot.handleMessage(ViewRoot.java:1887)
E/AndroidRuntime(31416):  at android.os.Handler.dispatchMessage(Handler.java:99)
E/AndroidRuntime(31416):  at android.os.Looper.loop(Looper.java:130)
E/AndroidRuntime(31416):  at android.app.ActivityThread.main(ActivityThread.java:3687)
E/AndroidRuntime(31416):  at java.lang.reflect.Method.invokeNative(Native Method)
E/AndroidRuntime(31416):  at java.lang.reflect.Method.invoke(Method.java:507)
E/AndroidRuntime(31416):  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:867)
E/AndroidRuntime(31416):  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:625)
E/AndroidRuntime(31416):  at dalvik.system.NativeStart.main(Native Method)

Since many memory analysis patterns are based on stack traces here we also have similarity with the following patterns names as Managed Code Exception and Managed Stack Trace. We hope that in the subsequent pattern implementation examples we show more complex patterns of abnormal software behaviour and may also discover any missing ones.

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

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 @ DumpAnalysis.org + TraceAnalysis.org -

Dialogue is an important pattern especially in network trace analysis. It usually involves a message source, a different message target (although both can be the same) and some alternation between them as shown on this abstract trace diagram:

Message and source are not only IP addresses or port numbers. They can be window handles, for example. Sometimes, the roles of source and target play different Process ID and Thread ID combinations (Client ID, CID). In such cases some parts of a message text may signify reply and response as shown graphically:

The similar illustration can be done for multi-computer trace, for example, when several traces from different servers are combined into one, where a combination of CID and a computer ID (Co) or just Co can play the roles of source and target.

Note that on all illustrations above the 3rd request doesn’t have a reply message: a possible Incomplete History pattern.

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

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 @ DumpAnalysis.org + TraceAnalysis.org -

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 @ DumpAnalysis.org + TraceAnalysis.org -   

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 @ DumpAnalysis.org + TraceAnalysis.org -

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 @ DumpAnalysis.org + TraceAnalysis.org -

In the past we viewed software traces and logs as temporarily ordered event sequences. Since events are just memory data we have a map

T  -> M

as can be seen in the definition of a software trace. Here we generalize the domain to any arbitrary set, for example, it can be a list of indexes or pointers or even memory itself. The latter map can give us narrative chains such as

M -> M -> M -> M

and even give us a grand unification of memory and log analysis and the possibility to apply software narratology to memory dump analysis as well. We talk about it soon and provide some generalized software narrative examples.

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

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 @ DumpAnalysis.org + TraceAnalysis.org -

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 @ DumpAnalysis.org + TraceAnalysis.org -

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 @ DumpAnalysis.org + TraceAnalysis.org -

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 @ DumpAnalysis.org + TraceAnalysis.org -

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 @ DumpAnalysis.org + TraceAnalysis.org -

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 @ DumpAnalysis.org + TraceAnalysis.org -

Static program analysis is used to eliminate certain coding errors that may lead to abnormal software behaviour. So it is naturally a part of software diagnostics but at source code level. Our goal here is to identify certain patterns directly linkable to patterns we see in memory dumps and software logs and collect them into a catalog. One such pattern candidate is called Loop Construct. It covers conditional and unconditional loops, for example, in one of modern languages:

extern bool soonToBeTrue; 

int mediumValue = ...;

while (true)

{

  TRACE("Waiting");

  sleep(mediumValue);

  if (soonToBeTrue)

  {

    break;

  }

  doHeavyWork();

}

while (--pControl->aFewPasses)

{

  TRACE("Waiting");

  sleep(mediumValue);

  doHeavyWork();

}

Such loops may potentially lead to Spiking Thread memory dump analysis and High Message Current and Density trace analysis patterns. Of course, we shouldn’t suspect every loop but only some that have potential to be altered by Local Buffer Overflow (for mediumValue) or Shared Buffer Overwrite (for Control.aFewPasses) or by a race condition (soonToBeTrue).

We expect things to get more interesting when we start associating source code that uses certain API with patterns of abnormal behavior.

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

If you need to get various real life software traces with millions of lines from complex software environments to learn pattern-driven software log analysis you can us Process Monitor as a modeling tool. Here you can abstract from their “monitoring” and API interception context and consider trace messages as emitted from various processes and threads (like Citrix CDF traces). This approach was used in Accelerated Windows Software Trace Analysis training and Debugging TV Frames episode 0×19.

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

Before deciding on whether to retrospect on 2012 we found that since March 14, 2008 this site has had more than 1 million visitors with more than 33% returning. So instead of just 2012 we decided to retrospect on that interval up to December 31, 2012. Google Analytics has improved since last January, 2012 and now made our task easier. So we start with the first one hundred sites referring to us:

Next table is distribution of visits among countries:

Then the first 100 network locations:

Then the first 100 search keywords and phrases that led to us:

Then browser stats (we have never thought that there are so many of them):

Browser	Visits
Internet Explorer	446051
Firefox	356686
Chrome	184535
Opera	45787
Safari	24123
Mozilla	3780
Mozilla Compatible Agent	2401
Android Browser	1337
Konqueror	1057
IE with Chrome Frame	982
Opera Mini	705
SeaMonkey	503
Safari (in-app)	197
Lunascape	144
BlackBerry8900	128
Camino	126
RockMelt	124
(not set)	96
Netscape	72
Playstation 3	36
IUC	34
Googlebot	29
Lynx	24
Unsupported Browser Version	22
BlackBerry9630	21
NetFront	17
BlackBerry9700	15
Microsoft-Symbol-Server	14
BlackBerry9000	12
Galeon	11
Midori	9
NokiaE63	9
Yahoo! Slurp	9
BlackBerry8530	8
BlackBerry8520	7
PagePeeker.com	7
SAMSUNG-SGH-I617	7
BlackBerry9530	6
JUC	6
MSR-ISRCCrawler	6
OpenWave	6
anonimo	5
BlackBerry9300	5
HTC_HD2_T8585 Opera	5
Nokia5233	5
Space Bison	5
-Vasya	4
Blazer	4
Uzbl	4
-^_^- Hello	3
<?echo ‘<pre>’; system	3
12345	3
BlackBerry9330	3
BlackBerry9650	3
HTC_P3700 Opera	3
HTC_TyTN_II Mozilla	3
NOKIAN78	3
Playstation Portable	3
PPC; 240×320; HTC_P3450	3
undefined GoogleToolbarBB	3
anonymous	2
Empty	2
GreatBrowse	2
Helyi user agent	2
HTC_Touch_Pro2_T7373 Opera	2
HTC_Touch2_T3333 Opera	2
J2ME	2
Mozilla 5.0	2
NokiaC1-01	2
NokiaC3-00	2
NokiaC7-00	2
NokiaX2-01	2
nwzfq	2
test	2
—	1
?M5	1
“PagePeeker.com”	1
<?include	1
<script>alert	1
<SCRIPT>window.location=’http:	1
2.0.0.11	1
31337′	1
8900b	1
AltaVista Intranet V2.0 evreka.com crawler@evreka.com	1
annoying	1
AppEngine-Google;	1
BlackBerry9500	1
BlackBerry9550	1
bwh3_user_agent	1
Citrix	1
EBABrowser	1
EY	1
fake_user_agent Mozilla	1
FAST Enterprise Crawler 6 used by Reed Exhibitions	1
foo	1
General Browser	1
GOOGLEBOT	1
HD_mini_T5555 Opera	1
Hellbrowser 6.66	1
holy_teacher FirePHP	1
HTC_P3490 Opera	1
HTC_P4550 Mozilla	1
HTC_Polaris Mozilla	1
HTC_Touch_3G_T3232 Opera	1
HTC_Touch_HD_T8282 Opera	1
HTC_Touch_Pro_T7272 Opera	1
HTC_Touch2_T3320 Opera	1
HTC-8900	1
IE 8	1
IE6	1
iTunes	1
Keep Out	1
KraftwayBrowser2	1
Links	1
Maemo Browser	1
Medusa	1
MERONG	1
Motorola_ES405B	1
mozilla	1
Mozilla Firefox	1
MS-OC 4.0	1
msie	1
NCSA Mosaic	1
NightDynamo AdminPanel v0.2.1	1
Nokia2700c-2	1
Nokia2730c-1	1
Nokia305	1
Nokia5230	1
Nokia5310XpressMusic	1
Nokia5800 XpressMusic	1
Nokia6300	1
Nokia6700c-1	1
NokiaC2-01	1
NokiaC2-02	1
NokiaC2-03	1
NokiaC5-03	1
nokiac6-00	1
NokiaC6-00	1
NOKIAE65	1
NokiaE66	1
NokiaE71	1
NokiaE71-2;Mozilla	1
NokiaE72-1	1
NokiaN-GageQD	1
NokiaN70-1	1
NokiaNokia 6210s	1
NoneOfYourBusiness	1
nothisname_wangxiaoyang3	1
OmniWeb	1
Palm750	1
Peeplo Screenshot Bot	1
PerTrUsTsQuiD	1
pippos.7	1
PPC; 480×800; HTC_Touch_HD_T8282; OpVer 34.159.1.612	1
PriceGoblin User Agent	1
Private	1
Privoxy	1
Read Later	1
SAMSUNG-GT-E2222	1
samsung-gt-s3653	1
samsung-gt-s3653 UNTRUSTED	1
SAMSUNG-S8000	1
SAMSUNG-SGH-I637	1
Samsung-SPHM540 Polaris	1
SmallProxy 3.5.4	1
SonyEricssonK750	1
Surf	1
tdhbrowser	1
TiFiC Client Z	1
union update table sd_users set userid=9 where username=’coco	1
unknown	1
Unknown	1
UNTRUSTED	1
Updownerbot	1
WIN	1
WinXP SP2	1
Wlwap	1
WM5 PIE	1
Xda_orbit_2; 240×320	1
Xyi znat kakoi browser MRA 5.7	1
ZooShot 0.1a	1
ZooShot 0.42	1

and finally mobile devices stats (you may find your own device there):

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

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 @ DumpAnalysis.org + TraceAnalysis.org -

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 @ DumpAnalysis.org + TraceAnalysis.org -