← Back to LTTng's blog

Babeltrace 2 begins the project's new scope for tailor-made trace analyses

Babeltrace 2.0 was released on 22 January 2020 and it includes some major changes. We've realized that users need a simple way to work with traces, so we're expanding the project's scope to make that possible, and also to encourage sharing of tracing analysis tools. Starting with Babeltrace 2.0, the project has switched from a trace converter to a trace manipulation tool.

We're introducing a whole new architecture for Babeltrace based on the concept of a filter graph. This new model allows connecting components to build a modular trace analysis pipeline. Users can share individual components in a pipeline to build on each other's work. While this new architecture comes with a new set of APIs for libbabeltrace and its Python bindings, the legacy Babeltrace 1 Python package, babeltrace, will continue to exist and work for backward compatibility, while the legacy libbabeltrace C API reaches the end of its life.

This isn't the first time we've added features to make it easier to work with traces: in 2012, we introduced Python bindings after it became clear that users needed a way to prototype using a high-level programming language. And the CTF (Common Trace Format) production library (CTF writer) was created in 2013 for perf to convert traces to CTF. But the new architecture is by far the most radical change ever made to the project. And it's one that we think will make it even better.

(This post expands on the talk (slides here) Jérémie Galarneau gave at the Tracing Summit 2017.)

Introducing processing graphs

We've moved to a pluggable graph model in Babeltrace 2. This makes it possible to assemble blocks of components to build custom trace analyses, and importantly, support more trace input and output formats.

Graphs are made up of sources (inputs), sinks (outputs), and filters (inputs/outputs). All of these pieces together are called components and they're instantiated from component classes which are provided by plugins. Components produce and consume messages, to deal with actual event records. An important message type is the trace event message, but other types exist to accommodate various trace formats, for example packet beginning and end messages.

Apart from needing a pluggable architecture, one crucial part of supporting out-of-tree plugins was missing in Babeltrace 1: a stable ABI. This is fixed in 2.0 and the plugin API is now frozen. This way, any out-of-tree plugin for proprietary trace formats (such as in-house hardware protocols) will be guaranteed to work as changes are made to the Babeltrace project. We hope this will encourage contributions for new trace formats and even useful filters.

Making it easier to work with traces

You can build a processing graph with the babeltrace2 command-line application which loads plugins explicitly with the --component parameter or implicitly with options like --debug-info and --clock-cycles. Babeltrace 2.0 comes with a number of plugins that make it easier to work with traces. You can see which plugins are available with the list-plugins command:

$

babeltrace2 list-plugins

From the following plugin paths:

  - /home/user/.local/lib/babeltrace2/plugins
  - /test/src/tools/babeltrace2/plugins

Found 11 component classes in 4 plugins.

text:
  Path: /test/src/tools/babeltrace2/plugins/babeltrace-plugin-text.so
  Description: Plain text input and output
  Author: EfficiOS <https://www.efficios.com/>
  License: MIT
  Source component classes:
    'source.text.dmesg': Read Linux ring buffer lines (dmesg(1) output) from a file or from standard input.
  Filter component classes: (none)
  Sink component classes:
    'sink.text.pretty': Pretty-print messages (`text` format of Babeltrace 1).
    'sink.text.details': Print messages with details.

utils:
  Path: /test/src/tools/babeltrace2/plugins/babeltrace-plugin-utils.so
  Description: Common graph utilities
  Author: EfficiOS <https://www.efficios.com/>
  License: MIT
  Source component classes: (none)
  Filter component classes:
    'filter.utils.trimmer': Discard messages that occur outside a specific time range.
    'filter.utils.muxer': Sort messages from multiple input ports to a single output port by time.
  Sink component classes:
    'sink.utils.dummy': Consume messages and discard them.
    'sink.utils.counter': Count messages and print the statistics.

ctf:
  Path: /test/src/tools/babeltrace2/plugins/babeltrace-plugin-ctf.so
  Description: CTF input and output
  Author: EfficiOS <https://www.efficios.com/>
  License: MIT
  Source component classes:
    'source.ctf.fs': Read CTF traces from the file system.
    'source.ctf.lttng-live': Connect to an LTTng relay daemon and receive CTF streams.
  Filter component classes: (none)
  Sink component classes:
    'sink.ctf.fs': Write CTF traces to the file system.

lttng-utils:
  Path: /test/src/tools/babeltrace2/plugins/babeltrace-plugin-lttng-utils.so
  Description: LTTng-specific graph utilities
  Author: EfficiOS <https://www.efficios.com/>
  License: MIT
  Source component classes: (none)
  Filter component classes:
    'filter.lttng-utils.debug-info': Augment compatible events with debugging information.
  Sink component classes: (none)

One new provided plugin, utils, offers the trimmer filter component class. A trimmer component allows traces to be trimmed (handy when you're working with very large trace data). Here's an example of how to build a graph that trims a CTF trace named mytrace:

$

babeltrace2 mytrace --begin=22:14:38 --end=22:15:07 --output-format=ctf --output=new-mytrace

Behind the scenes, babeltrace2 instantiates a sink.utils.trimmer component class to discard trace data outside the range described by the --begin and --end arguments.

Babeltrace 2.0 comes with the ability to record an LTTng live trace on the file system, thanks to an LTTng live source and a CTF sink:

$

babeltrace2 --input-format=lttng-live net://localhost/my_host/my_session --output-format=ctf --output=/path/to/trace

This is not possible with Babeltrace 1: you can only use the lttng-live input format with the text output format.

Of course, the real benefit comes from the ability to write plugins that work with whatever input/output format you're using.

A simple stack trace plugin example

You can write plugins using either the C API (with libbabeltrace) or the Python bindings, but the latter are the quickest way to prototype new components.

Here's an example of a stack trace sink component class written in Python that consumes the lttng_ust_cyg_profile_fast:func_entry and lttng_ust_cyg_profile_fast:func_exit events from the LTTng-UST function tracing helper. You need to compile your application with CFLAGS="-finstrument-functions -g" and preload LTTng's “liblttng-ust-cygprofile-fast.so” shared library to trace these events, which is explained in detail in the LTTng Documentation.

import bt2
import datetime
from termcolor import colored


@bt2.plugin_component_class
class stacktrace(bt2._UserSinkComponent):
    def __init__(self, config, params, obj):
        self._indent = 0
        self._add_input_port('my_input_port')
        self._last_timestamp = None

    def _on_entry(self, message):
        self._indent += 1
        self._print_time(message)
        print(
            colored(message.event['debug_info']['func'][:-2], attrs=['bold']) + '() {'
        )

    def _on_exit(self, message):
        self._print_time(message)
        print('}')
        self._indent -= 1

    def _print_time(self, message):
        timestamp_ns = message.default_clock_snapshot.ns_from_origin
        if self._last_timestamp is None:
            time_ui = str(datetime.datetime.fromtimestamp(timestamp_ns / 1e9))
        else:
            delta = timestamp_ns - self._last_timestamp
            time_ui = '+{} ns'.format(delta)
            time_ui = '{:>26}'.format(time_ui)
            if delta >= 2000:
                time_ui = colored(time_ui, 'red', attrs=['bold'])

        print(time_ui + '  ' * self._indent, end='')
        self._last_timestamp = timestamp_ns

    def _user_graph_is_configured(self):
        self._iterator = self._create_message_iterator(
            self._input_ports['my_input_port']
        )

    def _user_consume(self):
        message = next(self._iterator)
        if type(message) is not bt2._EventMessageConst:
            return

        if message.event.name in [
            'lttng_ust_cyg_profile:func_entry',
            'lttng_ust_cyg_profile_fast:func_entry',
        ]:
            self._on_entry(message)
        elif message.event.name in [
            'lttng_ust_cyg_profile:func_exit',
            'lttng_ust_cyg_profile_fast:func_exit',
        ]:
            self._on_exit(message)


bt2.register_plugin(__name__, 'demo')

The most important parts of the plugin are the _user_consume() and _on_entry() methods. The first processes the next message and the second extracts the function name from the application's debugging information. The rest of the code is for pretty-printing the stack trace.

Base classes are provided in the Python bindings for source, filter, and sink components. Inheriting one of them fills out boilerplate code, which means it's quick and easy to begin writing a custom plugin.

The register_plugin() function takes a couple of mandatory parameters that specify the module and plugin names.

Before you use this plugin, you need to save it to a file prefixed by the bt_plugin_ string such as bt_plugin_demo.py. You then need to generate trace data that the example plugin can convert. You can use LTTng to set up a tracing session, and record function entry and exit events for a utility like ls(1). For example:

1. Create a tracing session:

   $

   lttng create my-session

2. Create an event rule to enable all user space events:

   $

   lttng enable-event --userspace --all

3. Add instruction pointer and process ID context fields to the default user space channel:

   $

   lttng add-context --userspace --type ip --type vpid

4. Start tracing:

   $

   lttng start

5. Launch `ls(1)` with debugging information enabled:

   $

   LD_PRELOAD=liblttng-ust-cyg-profile-fast.so ls

6. Stop and destroy the tracing session:

   $

   lttng stop

   $

   lttng destroy

With the trace data available, you're now ready to try out the demo plugin.

The --plugin-path parameter for the babeltrace2 tool is required so that the example plugin can be found, and the --component argument instantiates one sink.demo.stacktrace component within the conversion graph. Since debugging information is required for the stack trace component to resolve addresses to symbol names, you also need the --debug-info parameter, which inserts a filter.lttng-utils.debug-info component into the conversion graph.

$

babeltrace2 --plugin-path=/path/to/plugin --debug-info --component=sink.demo.stacktrace /tmp/path/to/trace

The following screenshot shows the kind of output you will see.

Screenshot of demo plugin

Another useful view for this plugin (and arguably one that is more typical for stack trace tools) would be to print the time spent in a given function on a given stack level. But this demo plugin is just an example to show how the simple APIs in Babeltrace 2 make it easy to perform useful trace analysis.

We want your feedback

A lot has changed from Babeltrace 1 to Babeltrace 2. We believe the changes provide more flexibility for analyzing trace data and a small, sensible API for writing new plugins.

However, there are still lots of improvements we want to make. Our current plan is to make it easier to create iterators that need to modify or augment event messages, add a filter component class that uses expressions to filter out messages, add support for CTF 2, and various optimizations for component classes.

We're always looking for more testers, and for more people to read the documentation and try things out. The babeltrace-intro(7) man page introduces the Babeltrace 2 concepts and parts. You can clone the project’s repository and build it to get the man pages.

If you want to share feedback, please join us on the lttng-dev mailing list or on OFTC’s #lttng IRC channel. We'd love to hear from you.