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