Skip to content

interactive_trace_reader(1) Interactively analyze a trace file

yotamr edited this page May 5, 2012 · 6 revisions

interactive_trace_reader(1) -- Interactively analyze a trace file

SYNOPSIS

python interactive_trace_reader/ui.py <filename>

Description

interactive_trace_reader is a console application for the analyzing of trace files written by trace_dumper. The interactive reader has the following features:

  • Filters: Filter the trace file according to a match expression
  • Searches: Search records according to text, time or match expression
  • Tab completion: Metadata (function names, constant values, etc') is tab-completable

KEY MAPPING

Table 1. Viewing and Navigation

Key Description
DOWN Scroll down a single record
UP Scroll up a single record
PAGE-DOWN Scroll down a screenful of records
PAGE-UP Scroll up a screenful of records
END Go to end of file
HOME Go to beginning of file
x Toggle display of field names
q Exit the reader

Table 2. Searching and filtering

Key Description
f Enter a filter expression, using the last filter as base
F Enter a filter expression from scratch
s/S Perform a forward/backward search
n Repeat the last command (either search or filter)
e/E Search for the next/previous ERROR record
w/W Search for the next/previous WARN record
i/I Search for the next/previous INFO record
d/D Search for the next/previous DEBUG record
c/C Search for caller leave/entry
l Search for current function leave

Match expressions

Match expressions are used to specify both filter and search expressions. Filters limit the records displayed to those matched by the filter expression. Searches operate within the current filter-expression. Match expressions are valid Python expressions. Some examples:

Match records whose name is process_1

_procname("process_1")

Match any record with severity WARN or ERROR:

severity == WARN or severity == ERROR

Match any entry/leaving of the function my_strcmp():

my_strcmp()

Match any record that contains the constant substring message:

message

Match any record that contains the constant substring long message "long message"

Match expressions are boolean expressions with support for not, and and or boolean operations.
The following table lists the support match constructs:

Table 3. Match expression construct examples

Description Example
Match process name _procname("process_name")
Match function name _call("my_strcmp") or my_strcmp()
Match function name and parameter value _call("add_value", 5) or add_value(5)
Match function name and named parameter value _call("add_value", input = 5) or add_value(input = 5)
Match value in record _(10)
Match named value in record _(some_value = 25)
Match typename in record _typename("enum my_enum")
Match tid tid == 5124
Match pid pid == 2345
Match severity severity == WARN
Match time range '14:23' < ts < '14:50'
Match constant substring somestring or "some string"

Notes:

  • When using _call() or func_name() to match functions, both function entry and leave will be matched. For example, the expression my_calculation(5) matches a call to the function my_calculation with the value '5' passed to any of its parameters as well as a return from my_calculation() in which the value 5 was returned.
  • The _(...) construct is used to match explicit log lines and will not match function entries.
Time formats

In the above example, the time matching construct specified included an hour and a minute, rather than a full date. When specifying time formats (both in search and filters), if the time specified is not complete, the incomplete fields will be deduced from the current record. The following time formats are supported:

Format Description
%d/%m Day in month (1-31) and month (1-12)
%H/%M Hour (0-24) and minute (0-60)
%H/%M:%S Hour (0-24) and minute (0-60) and seconds (0-60)
%H/%M:%S:%f Hour (0-24) and minute (0-60) and seconds (0-60) and nanoseconds
:%f microseconds in current second
%d/%m %H:%M:%S:%f day in month, month, hour, minute, second nanoseconds
Match expression examples

Match a call to the function multiply whose multiplier parameter equals 5 and that occurred in the process process_1:

multiply(multiplier = 5) and _procname("process_1")

Don't show function traces, only debug lines:

not severity == FUNC_TRACE

Show all error records that occurred between 14:00:11 and 14:00:15:

'14:00:11' < ts < '14:00:15' and severity == ERROR

Show all INFO records of the process "demo" whose constant string contains the word 'overflow'

_procname("demo") and severity == INFO and overflow

Arbitrarily complex boolean expression:

tid == 4515 or (_procname("foo") and not tid == 512)

Searching

Filters only accept valid match expressions. Search expressions (invoked by pressing s) accept three types of expressions:

  • Match expressions
  • Timestamps
  • Simple text

Match expressions will match records as described in the above section. Timestamps conform the timestamp format specified in the above section. Searching a timestamp will navigate the file to the closest time specified by the timestamp. If the user does not specify a valid match expression or timestamp, the reader will try to find an expression that contains text specified by the user. This is an extremely slow approach, because the reader will parser and format every record being searched, rather than use fast binary methods.

COPYRIGHT

Traces is Copyright (C) 2012 Yotam Rubin yotamrubin@gmail.com
Traces is sponsored by Infinidat http://infinidat.com

SEE ALSO

trace_dumper(1), interactive_trace_reader(1)