« Trace Analysis Patterns (Part 15)
Project CARE Update (14.02.10) »

Trace Analysis Patterns (Part 16)

Another useful pattern is called Time Delta. This is a time interval between significant events. For example,

#     Module PID  TID  Time         File    Function Message
1                      10:06:18.994                  (Start)
[...]
6060  dllA   1604 7108 10:06:21.746 fileA.c DllMain  DLL_PROCESS_ATTACH
[…]
24480 dllA   1604 7108 10:06:32.262 fileA.c Exec     Path: C:\Program Files\CompanyA\appB.exe
[…]
24550 dllB   1604 9588 10:06:32.362 fileB.c PostMsg  Event Q
[…]
28230                  10:07:05.170                  (End)

Such deltas are useful in examining delays. In the trace fragment above we are interested in dllA activity from its load until it launches appB.exe. We see that the time delta was only 10 seconds. The message #24550 was the last message from the process ID 1604 and after that we didn’t “hear” from that PID for more than 30 seconds until the tracing was stopped.

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

This entry was posted on Saturday, February 13th, 2010 at 1:52 am and is filed under CDF Analysis Tips and Tricks, Debugging, Software Trace Analysis, Trace Analysis Patterns. You can follow any responses to this entry through the RSS 2.0 feed. You can leave a response, or trackback from your own site.

One Response to “Trace Analysis Patterns (Part 16)”

  1. Crash Dump Analysis » Blog Archive » Adjoint threads, discontinuity and time delta: software trace pattern cooperation Says:
    March 24th, 2010 at 11:11 pm

    […] 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 […]

Leave a Reply

You must be logged in to post a comment.