Software Diagnostics Library

Today we introduce an icon for OMAP Code Optimization pattern:

B/W

Color

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

“Capturing delicate moments, one gives birth to a poetry of traces …”

Ange Leccia, Motionless Journeys, by Fabien Danesi

More patterns from software narratology. Now we illustrate Defamiliarizing Effect where we see sudden unfamiliar trace statements across familiar landscape of characteristic blocks and activity regions:

/familar traces/

/new trace from a problem system/

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

Metaphorical bijection from literary narratology to software narratology provides a pattern of Background and Foreground Components. This can be easily illustrated on pseudo-trace color diagrams. Suppose we troubleshoot a graphical issue using an ETW trace containing the output from all components of the problem system. Graphic components and their messages are foreground for a trace viewer (a person) against numerous background components (for example, database, file and registry access, shown in shades of green):

Trace viewers (for example, CDFAnalyzer) can filter out background component messages and present only foreground components (that I propose to call component foregrounding):

Of course, this process is iterative and parts of what once was foreground become background and candidates for further filtering:

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

This is a new open source tool similar to PDBFinder in functionality but with much simpler interface and internal implementation (based on the file name structure of the certain classes of TMF files for ETW). To be released this month on TraceAnalysis.org.

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

Today we introduce an icon for Incorrect Stack Trace pattern:

B/W

Color

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

Previously introduced Coupled Processes pattern involves an active request (or an action) and an active wait for a response (or the action status):

It is illustrated on this simple UML sequence diagram (process timeline represent collective request-response threads):

However, there is so called weak coupling when a process subscribes for notifications. Such threads most of the time are passive and processes are not blocked:

The coupling manifests itself when notifier threads start spiking CPU and bring their share of CPU consumption to the notified threads:

Here is an example of such threads from the forthcoming pattern interaction case study:

   5  Id: 61018.dbec Suspend: 1 Teb: 7ffae000 Unfrozen
ChildEBP RetAddr
01e3fa68 7c82787b ntdll!KiFastSystemCallRet
01e3fa6c 77c80a6e ntdll!NtRequestWaitReplyPort+0xc
01e3fab8 77c7fcf0 rpcrt4!LRPC_CCALL::SendReceive+0x230
01e3fac4 77c80673 rpcrt4!I_RpcSendReceive+0x24
01e3fad8 77ce315a rpcrt4!NdrSendReceive+0x2b
01e3fec0 771f4fbd rpcrt4!NdrClientCall2+0x22e
01e3fed8 771f4f60 winsta!RpcWinStationWaitSystemEvent+0x1c
01e3ff20 6582116c winsta!WinStationWaitSystemEvent+0x51
[...]
01e3ffec 00000000 kernel32!BaseThreadStart+0x34

In cases of synchronous notifications if a notified thread is blocked we have an instance of a reversed strong coupling.

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

Today we introduce an icon for Changed Environment pattern:

B/W

Color

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

Typical software narrative history consists of requests and responses, for example, function or object method calls and returns:

#     Module PID  TID  Time         File    Function Message
[...]
26060 dllA   1604 7108 10:06:21.746 fileA.c foo      Calling bar
[...]
26232 dllA   1604 7108 10:06:22.262 fileA.c foo      bar returns 0x5
[...]

The code that generates execution history is response-complete if it traces both requests and responses. For such code (except in cases where tracing is stopped before a response) the absence of expected responses could be a sign of blocked threads or quiet exception processing. The code that generates execution history is exception-complete if it also traces exception processing. Response-complete and exception-complete code is called call-complete. If we don’t see response messages for call-complete code we have Incomplete History.

In general, we can talk about the absence of certain messages in a trace as a deviation from the standard trace sequence template corresponding to a use case. The difference there is in a missing request too. This is a topic for next patterns.

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

I’m very pleased to announce that the Korean edition is available:

The book can be found on: 

• Acorn (The Korean translation publisher)
• Kyobo book
• Yes24.com

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

After this 1st of April evening spent in circus with my family I approached a PC to check my blog (seen from the window) and found a number format exception on a side bar currency conversion widget:

At first I panicked but then recalled that I already encountered some currency conversion problems with that widget. At the time of this writing, it is no long a local April Fool’s day but the problem persists.

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

Today we introduce an icon for Deadlock (mixed objects, kernel space) pattern:

B/W

Color

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

A silicon based company announced a new product called GoToMyBug for remote viewing of bugs ……fff.fff.f.H.A…t….H..H%….u…A..H.EA.u.H……….ff.L..A…I..A.B..t-I..I.R.L..I..t.I….H..f…I…u.I..[.A…I..L..I……t.I…I..H…..f..H……H…I…u………fff.fff.ff.S…L..H..L..I..I.R…t…L..A…M..H…….I…u.I..[…%…..u.

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

Today we introduce an icon for Deadlock (LPC) pattern:

B/W

Color

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

Today we introduce an icon for Deadlock (mixed objects, user space) pattern:

B/W

Color

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

Today we introduce an icon for Deadlock (executive resources) pattern:

B/W

Color

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

Today we introduce an icon for Deadlock (critical sections) pattern:

B/W

Color

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

Today we introduce an icon for Hidden Exception pattern:

B/W

Color

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

Here is one of the first case studies in pattern-driven software trace analysis. A user starts printing but nothing comes out. However, if the older printer driver is installed everything works as expected. We suspect that print spooler crashes if the newer printer driver is used. Based on known module name in ETW trace we find PID for print spooler process (19984) and immediately see discontinuity in the trace with the large time delta between the last PID message and the last trace statement (almost 4 minutes): 

No   Source        PID   TID   Time         Message
712  \src\print\ui 19984 16200 12:22:31.571 PropertySheet returns 1
[… no messages for PID 19984 …]
5103　\src\mgmt　　 1292  7604  12:26:11.659 WaitAction

If we select the adjoint thread of source \src\print\driver (in other words, filter only its messages) we would see discontinuity with the similar time delta. We know that printer driver runs in print spooler context. However, PID had changed and that means print spooler was restarted (perhaps after a crash):

No   Source            PID   TID   Time         Message
557  \src\print\driver 19984 16200 12:22:28.069 DisableDevice returns
[… discontinuity for \print\driver …]
1462 \src\print\driver 10828 17584 12:26:03.854 DllMain

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

Today we introduce an icon for Inconsistent Dump pattern:

B/W

Color

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

Today we introduce an icon for NULL Pointer (data) pattern:

B/W

Color

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