2 id: viewing-and-analyzing-your-traces
5 This section describes how to visualize the data gathered after tracing
6 the Linux kernel or a user space application.
8 Many ways exist to read your LTTng traces:
10 * **`babeltrace`** is a command line utility which converts trace formats;
11 it supports the format used by LTTng,
12 <abbr title="Common Trace Format">CTF</abbr>, as well as a basic
13 text output which may be `grep`ed. The `babeltrace` command is
15 <a href="http://www.efficios.com/babeltrace" class="ext">Babeltrace</a> project.
16 * Babeltrace also includes a **Python binding** so that you may
17 easily open and read an LTTng trace with your own script, benefiting
18 from the power of Python.
19 * The **<a href="https://eclipse.org/downloads/packages/eclipse-ide-cc-developers/lunar" class="ext">
20 Eclise IDE for C/C++ Developers</a>**
21 includes the Tracing and Monitoring Framework (TMF) plugin which
22 supports LTTng traces, amongst others.
23 * <a href="http://projects.eclipse.org/projects/tools.tracecompass">Trace Compass</a>
24 is an Eclipse plugin, the TMF plugin mentioned above moved to its own
25 project, used to visualize and analyze various types of traces,
26 including LTTng. It also comes as a standalone application and can be
28 <a href="http://secretaire.dorsal.polymtl.ca/~gbastien/TracingRCP/TraceCompass/">here</a>
29 for a daily build of the latest source code. A version containing some
30 experimental features like Virtual Machine analysis and Critical Path
31 analysis is also available
32 <a href="http://secretaire.dorsal.polymtl.ca/~gbastien/TracingRCP/DorsalExperimental/">here</a>.
34 LTTng trace files are usually recorded in the `~/lttng-traces` directory.
35 Let's now view the trace and perform a basic analysis using
38 The simplest way to list all the recorded events of a trace is to pass its
39 path to `babeltrace` with no options:
42 babeltrace ~/lttng-traces/my-session
45 `babeltrace` will find all traces within the given path recursively and
46 output all their events, merging them intelligently.
48 Listing all the system calls of a Linux kernel trace with their arguments is
49 easy with `babeltrace` and `grep`:
52 babeltrace ~/lttng-traces/my-kernel-session | grep sys_
55 Counting events is also straightforward:
58 babeltrace ~/lttng-traces/my-kernel-session | grep sys_read | wc -l
61 The text output of `babeltrace` is useful for isolating events by simple
62 matching using `grep` and similar utilities. However, more elaborate filters
63 such as keeping only events with a field value falling within a specific range
64 are not trivial to write using a shell. Moreover, reductions and even the
65 most basic computations involving multiple events are virtually impossible
68 Fortunately, Babeltrace ships with a Python 3 binding which makes it
69 really easy to read the events of an LTTng trace sequentially and compute
70 the desired information.
72 Here's a simple example using the Babeltrace Python binding. The following
73 script accepts an LTTng Linux kernel trace path as its first argument and
74 outputs the short names of the top 5 running processes on CPU 0 during the
79 from collections import Counter
84 if len(sys.argv) != 2:
85 msg = 'Usage: python {} TRACEPATH'.format(sys.argv[0])
88 # a trace collection holds one to many traces
89 col = babeltrace.TraceCollection()
91 # add the trace provided by the user
92 # (LTTng traces always have the 'ctf' format)
93 if col.add_trace(sys.argv[1], 'ctf') is None:
94 raise RuntimeError('Cannot add trace')
96 # this counter dict will hold execution times:
98 # task command name -> total execution time (ns)
99 exec_times = Counter()
101 # this holds the last `sched_switch` timestamp
105 for event in col.events:
106 # keep only `sched_switch` events
107 if event.name != 'sched_switch':
110 # keep only events which happened on CPU 0
111 if event['cpu_id'] != 0:
115 cur_ts = event.timestamp
121 # previous task command (short) name
122 prev_comm = event['prev_comm']
124 # initialize entry in our dict if not yet done
125 if prev_comm not in exec_times:
126 exec_times[prev_comm] = 0
128 # compute previous command execution time
129 diff = cur_ts - last_ts
131 # update execution time of this command
132 exec_times[prev_comm] += diff
134 # update last timestamp
138 for name, ns in exec_times.most_common()[:5]:
140 print('{:20}{} s'.format(name, s))
143 if __name__ == '__main__':
147 Save this script as `top5proc.py` and run it with Python 3, providing the
148 path to an LTTng Linux kernel trace as the first argument:
151 python3 top5proc.py ~/lttng-sessions/my-session-.../kernel
154 Make sure the path you provide is the directory containing actual trace
155 files (`channel0_0`, `metadata`, etc.): the `babeltrace` utility recurses
156 directories, but the Python binding does not.
158 Here's an example of output:
161 swapper/0 48.607245889 s
162 chromium 7.192738188 s
163 pavucontrol 0.709894415 s
164 Compositor 0.660867933 s
165 Xorg.bin 0.616753786 s
168 Note that `swapper/0` is the "idle" process of CPU 0 on Linux; since we
169 weren't using the CPU that much when tracing, its first position in the list