Getting Started

Getting Started

Setup

Preparing an application for tracing using the tracing-tape format is straightforward. First, you need to add the dependencies tracing, tracing_subscriber, and tracing-tape-recorder to your application using:

cargo add tracing tracing-subscriber tracing-tape-recorder

The tracing-tape-recorder builds on the tracing_subscriber crate which basically provides a flexible way to forward traces to multiple endpoints using layers. For more information, see its documentation. All that is left to do is to create a subscriber with the TapeRecorder layer and set it as the global default subscriber:

use tracing::trace_span;
use tracing_subscriber::{fmt, layer::SubscriberExt, Registry};
use tracing_tape_recorder::TapeRecorder;

let subscriber = Registry::default().with(TapeRecorder::default());
let guard = tracing::subscriber::set_default(subscriber);

// ...

drop(guard);

That's it, all traces will now be recorded to a file called {crate_name}-{timestamp}.tape in the current working directory.

Note: it is preferred to use set_default instead of set_global_default to ensure the subsriber is dropped when the guard goes out of scope. See #7 for more information.

Simple Example

Let's assume we have the followig (somewhat trivial) program for calculating a bunch of Fibonacci numbers:

fn fib(n: u64) -> u64 {
    if n == 0 || n == 1 {
        n
    } else {
        fib(n - 1) + fib(n - 2)
    }
}

fn main() {
    for i in 0..20 {
        let result = fib(i);
    }
}

In order to trace it's execution, we can modify the program as follows:

use tracing::trace_span;
use tracing_subscriber::{fmt, layer::SubscriberExt, Registry};
use tracing_tape_recorder::TapeRecorder;

#[tracing::instrument]
fn fib(n: u64) -> u64 {
    if n == 0 || n == 1 {
        trace_span!("base case").in_scope(|| n)
    } else {
        trace_span!("recursion").in_scope(|| fib(n - 1) + fib(n - 2))
    }
}

fn main() {
    let subscriber = Registry::default()
        .with(TapeRecorder::default())
        .with(fmt::Layer::default());
    let guard = tracing::subscriber::set_default(subscriber);

    let result = fib(20);
    tracing::info!(result, fib = 20, "calculated fib");

    drop(guard);
}

Notice the #[tracing::instrument] attribute on the fib function which automatically creates a span for each invocation of the function that automatically captures its arguments. Additionally, I added trace_span! calls to create spans for the base case and the recursive case and log messages to capture the result of the calculation using the tracing::info! macro. For more information on how you can use the tracing crate, have a look at its documentation.

Trace Deck

Trace Deck is the GUI for viewing trace files. It can be installed locally using

cargo install trace-deck

or you can use the web application deployed at https://trace-deck.oehrl.dev. Trace files can be loaded by either dragging them into the application or, when installed locally, using the

trace-deck <filename>

command. After loading the trace you are greeted with the following view: The following section will describe the individual panes in more detail.

Tape Timeline

In the middle of the window, you can find the Tape Timeline which shows a flame graph of all recorded spans. You can drag the timeline using the left mouse button and zoom in and out using your mouse wheel or by doing a pinch gesture on your trackpad. The currently visible range is displayed at the top of the timeline and is additionally visualized in the global timeline. Changing the visible tine span here also affects the shown log messages. Hovering a span displays additional information such as its duration and parameters. Clicking a span with the left mouse button selects it and displays its information in the details pane.

Global Timeline

The global timeline is located at the bottom of the window and displays all loaded tapes and highlights the currently visible range in the tape timeline.

Log Messages

On the right of the window you can find the log messages that occurred within the current the currently visible time range.

Callsites

The callsite pane can be found in the top right and displays all types of log messages and spans. Selecting a callsite will reveal more information in the details pane.

Details

The details pane can be found in the bottom left of the window and displays information based in the currently selected item.

Callsite Details

When selecting a callsite the details pane will show information about the source code location and the associated fields. You can also change the color of callsites here. For spans it also shows additional statistics and a button that will plot the span durations in a new window.

Span Duration Plot

Span duration plots are opened using the Plot button in the details pane of the corresponding callsite. It shows a bar plot of all spans of the corresponding type within the currently selected time range. Clicking on a bar will change the currently selected time range to its duration. This way, you can click on an outlier in this plot and see what caused this in the tape timeline.

Advanced

Multiple Threads

When spans are recorded on multiple threads the tape timeline will show a separate row for each thread. Currently, thread names are not yet recorded (example using multiple threads).

Multiple Tapes

You can load multiple tape file simultaneously by dragging multiple files into the trace-deck window or calling the trace-deck command with multiple files. In that case, the global timeline will show an overview of all tape time ranges and the application will open a timeline and message pane for all tapes. The individual timelines are synced, it is easy to correlate the events of multiple applications which can be very useful for client/server applications. Such an example configuration can be found in the examples folder (fib_server, fib_client).