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

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:

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