#tokio-task #tracing-subscriber #tokio #tracing #async

ari-subscriber

Async Executor Instrumentation Observability Utility A tracing subscriber layer that outputs Tokio's tracing instrumentation to the terminal in a format conducive to debugging

2 releases

0.0.2 Mar 11, 2024
0.0.1 Nov 29, 2023

#831 in Debugging

MIT license

40KB
464 lines

Async Runtime Instrumentation Subscriber

The Async Runtime Instrumentation Subscriber (ari-subscriber) is a tracing-subscriber optimized for visually debugging Tokio tracing instrumentation.

This crate provides a Layer which writes tracing information to stdout. It colorizes the traces that result from the tracing instrumentation in Tokio to make identifying them easier.

Usage

This example will set up a formatting tracing_subscriber::Layer which is then added to the registry. The output from the task spawned afterwards will be seen in stdout.

use tracing_subscriber::prelude::*;

#[tokio::main]
async fn main() {
    let layer = ari_subscriber::layer();

    tracing_subscriber::registry().with(layer).init();

    tokio::spawn(async {
        tokio::time::sleep(std::time::Duration::from_millis(100)).await;
    })
    .await
    .unwrap();
}

A common use case is to use ari-subscriber together with the console-subscriber, which aggregates the same Tokio tracing instrumentation to be visualized in Tokio Console.

use tracing_subscriber::prelude::*;

#[tokio::main]
async fn main() {
    let fmt_layer = ari_subscriber::layer();
    let console_layer = console_subscriber::spawn();

    tracing_subscriber::registry()
        .with(fmt_layer)
        .with(console_layer)
        .init();

    tokio::spawn(async {
        tokio::time::sleep(std::time::Duration::from_millis(100)).await;
    })
    .await
    .unwrap();
}

Example output

The beginning of the output of the above program would be:

 2023-11-28T10:06:44.746508Z TRACE runtime.spawn[1]{kind=task, task.name=, task.id=18, loc.file="examples/tokio-task.rs", loc.line=14, loc.col=5} new
 2023-11-28T10:06:44.747110Z TRACE runtime.spawn[1]{kind=task, task.name=, task.id=18, loc.file="examples/tokio-task.rs", loc.line=14, loc.col=5} enter
 2023-11-28T10:06:44.747340Z TRACE runtime.spawn[1]{kind=task, task.name=, task.id=18, loc.file="examples/tokio-task.rs", loc.line=14, loc.col=5} runtime.resource[274877906945]{concrete_type="Sleep", kind="timer", loc.file="examples/tokio-task.rs", loc.line=15, loc.col=9} new
 2023-11-28T10:06:44.747539Z TRACE runtime.spawn[1]{kind=task, task.name=, task.id=18, loc.file="examples/tokio-task.rs", loc.line=14, loc.col=5} runtime.resource[274877906945]{concrete_type="Sleep", kind="timer", loc.file="examples/tokio-task.rs", loc.line=15, loc.col=9} enter
 2023-11-28T10:06:44.747683Z TRACE runtime.spawn[1]{kind=task, task.name=, task.id=18, loc.file="examples/tokio-task.rs", loc.line=14, loc.col=5} runtime.resource[274877906945]{concrete_type="Sleep", kind="timer", loc.file="examples/tokio-task.rs", loc.line=15, loc.col=9} runtime::resource::state_update: duration=101, duration.unit="ms", duration.op="override"
 2023-11-28T10:06:44.747854Z TRACE runtime.spawn[1]{kind=task, task.name=, task.id=18, loc.file="examples/tokio-task.rs", loc.line=14, loc.col=5} runtime.resource[274877906945]{concrete_type="Sleep", kind="timer", loc.file="examples/tokio-task.rs", loc.line=15, loc.col=9} runtime.resource.async_op[274877906946]{source="Sleep::new_timeout"} new
 2023-11-28T10:06:44.747991Z TRACE runtime.spawn[1]{kind=task, task.name=, task.id=18, loc.file="examples/tokio-task.rs", loc.line=14, loc.col=5} runtime.resource[274877906945]{concrete_type="Sleep", kind="timer", loc.file="examples/tokio-task.rs", loc.line=15, loc.col=9} exit
 2023-11-28T10:06:44.748118Z TRACE runtime.spawn[1]{kind=task, task.name=, task.id=18, loc.file="examples/tokio-task.rs", loc.line=14, loc.col=5} runtime.resource[274877906945]{concrete_type="Sleep", kind="timer", loc.file="examples/tokio-task.rs", loc.line=15, loc.col=9} runtime.resource.async_op[274877906946]{source="Sleep::new_timeout"} enter
 2023-11-28T10:06:44.748196Z TRACE runtime.spawn[1]{kind=task, task.name=, task.id=18, loc.file="examples/tokio-task.rs", loc.line=14, loc.col=5} runtime.resource[274877906945]{concrete_type="Sleep", kind="timer", loc.file="examples/tokio-task.rs", loc.line=15, loc.col=9} runtime.resource.async_op[274877906946]{source="Sleep::new_timeout"} runtime.resource.async_op.poll[274877906947]{} new
 

Comparison with tracing-subscriber

ari-subscriber is built on top of tracing-subscriber and uses its registry (as do the majority of tracing subscribers). It offers an alternative to the fmt::Subscriber and underlying fmt::Layer in that crate.

If you are in doubt about which format subscriber to use, pick the one from tracing-subscriber. It is more flexible and without a doubt, much more performant.

You would only use the ari-subscriber format Layer if you have a specific need to visualize the tracing instrumentation built into Tokio.

Supported Rust Versions

ari-subscriber is built against the latest stable release. The minimum supported version is 1.65. The current version of ari-subscriber is not guaranteed to build on Rust versions earlier than the minimum supported version.

License

This project is licensed under the MIT license.

Contribution

Unless you explicitly state otherwise, any contribution intentionally submitted for inclusion in ari-subscriber by you, shall be licensed as MIT, without any additional terms or conditions.

Dependencies

~2–12MB
~83K SLoC