Module tracing_subscriber::fmt

A Subscriber for formatting and logging tracing data.

Overview

tracing is a framework for instrumenting Rust programs with context-aware, structured, event-based diagnostic information. This crate provides an implementation of the Subscriber trait that records tracing’s Events and Spans by formatting them as text and logging them to stdout.

Usage

First, add this to your Cargo.toml file:

[dependencies]
tracing-subscriber = "0.2"

Compiler support: requires rustc 1.39+

Add the following to your executable to initialize the default subscriber:

use tracing_subscriber;

tracing_subscriber::fmt::init();

Filtering Events with Environment Variables

The default subscriber installed by init enables you to filter events at runtime using environment variables (using the EnvFilter).

The filter syntax is a superset of the env_logger syntax.

For example:

• Setting RUST_LOG=debug enables all Spans and Events set to the log level DEBUG or higher
• Setting RUST_LOG=my_crate=trace enables Spans and Events in my_crate at all log levels

Note: This should not be called by libraries. Libraries should use tracing to publish tracing Events.

Configuration

You can configure a subscriber instead of using the defaults with the following functions:

Subscriber

The FmtSubscriber formats and records tracing events as line-oriented logs. You can create one by calling:

let subscriber = tracing_subscriber::fmt()
    // ... add configuration
    .finish();

You can find the configuration methods for FmtSubscriber in SubscriberBuilder.

Formatters

The output format used by the layer and subscriber in this module is represented by implementing the FormatEvent trait, and can be customized. This module provides a number of formatter implementations:

• format::Full: The default formatter. This emits human-readable, single-line logs for each event that occurs, with the current span context displayed before the formatted representation of the event.

  For example:

      Finished dev [unoptimized + debuginfo] target(s) in 1.59s
       Running `target/debug/examples/fmt`
  Oct 24 12:55:47.814  INFO fmt: preparing to shave yaks number_of_yaks=3
  Oct 24 12:55:47.814  INFO shaving_yaks{yaks=3}: fmt::yak_shave: shaving yaks
  Oct 24 12:55:47.814 TRACE shaving_yaks{yaks=3}:shave{yak=1}: fmt::yak_shave: hello! I'm gonna shave a yak excitement="yay!"
  Oct 24 12:55:47.814 TRACE shaving_yaks{yaks=3}:shave{yak=1}: fmt::yak_shave: yak shaved successfully
  Oct 24 12:55:47.814 DEBUG shaving_yaks{yaks=3}: yak_events: yak=1 shaved=true
  Oct 24 12:55:47.814 TRACE shaving_yaks{yaks=3}: fmt::yak_shave: yaks_shaved=1
  Oct 24 12:55:47.815 TRACE shaving_yaks{yaks=3}:shave{yak=2}: fmt::yak_shave: hello! I'm gonna shave a yak excitement="yay!"
  Oct 24 12:55:47.815 TRACE shaving_yaks{yaks=3}:shave{yak=2}: fmt::yak_shave: yak shaved successfully
  Oct 24 12:55:47.815 DEBUG shaving_yaks{yaks=3}: yak_events: yak=2 shaved=true
  Oct 24 12:55:47.815 TRACE shaving_yaks{yaks=3}: fmt::yak_shave: yaks_shaved=2
  Oct 24 12:55:47.815 TRACE shaving_yaks{yaks=3}:shave{yak=3}: fmt::yak_shave: hello! I'm gonna shave a yak excitement="yay!"
  Oct 24 12:55:47.815  WARN shaving_yaks{yaks=3}:shave{yak=3}: fmt::yak_shave: could not locate yak
  Oct 24 12:55:47.815 DEBUG shaving_yaks{yaks=3}: yak_events: yak=3 shaved=false
  Oct 24 12:55:47.815 ERROR shaving_yaks{yaks=3}: fmt::yak_shave: failed to shave yak yak=3 error=missing yak
  Oct 24 12:55:47.815 TRACE shaving_yaks{yaks=3}: fmt::yak_shave: yaks_shaved=2
  Oct 24 12:55:47.815  INFO fmt: yak shaving completed all_yaks_shaved=false
  

• format::Pretty: Emits excessively pretty, multi-line logs, optimized for human readability. This is primarily intended to be used in local development and debugging, or for command-line applications, where automated analysis and compact storage of logs is less of a priority than readability and visual appeal.

  For example:

      Finished dev [unoptimized + debuginfo] target(s) in 1.61s
       Running `target/debug/examples/fmt-pretty`
  Oct 24 12:57:29.386 fmt_pretty: preparing to shave yaks, number_of_yaks: 3
    at examples/examples/fmt-pretty.rs:16 on main
  
  Oct 24 12:57:29.386 fmt_pretty::yak_shave: shaving yaks
    at examples/examples/fmt/yak_shave.rs:38 on main
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: hello! I'm gonna shave a yak, excitement: "yay!"
    at examples/examples/fmt/yak_shave.rs:14 on main
    in fmt_pretty::yak_shave::shave with yak: 1
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: yak shaved successfully
    at examples/examples/fmt/yak_shave.rs:22 on main
    in fmt_pretty::yak_shave::shave with yak: 1
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 yak_events: yak: 1, shaved: true
    at examples/examples/fmt/yak_shave.rs:43 on main
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: yaks_shaved: 1
    at examples/examples/fmt/yak_shave.rs:52 on main
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: hello! I'm gonna shave a yak, excitement: "yay!"
    at examples/examples/fmt/yak_shave.rs:14 on main
    in fmt_pretty::yak_shave::shave with yak: 2
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: yak shaved successfully
    at examples/examples/fmt/yak_shave.rs:22 on main
    in fmt_pretty::yak_shave::shave with yak: 2
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 yak_events: yak: 2, shaved: true
    at examples/examples/fmt/yak_shave.rs:43 on main
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: yaks_shaved: 2
    at examples/examples/fmt/yak_shave.rs:52 on main
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: hello! I'm gonna shave a yak, excitement: "yay!"
    at examples/examples/fmt/yak_shave.rs:14 on main
    in fmt_pretty::yak_shave::shave with yak: 3
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: could not locate yak
    at examples/examples/fmt/yak_shave.rs:16 on main
    in fmt_pretty::yak_shave::shave with yak: 3
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 yak_events: yak: 3, shaved: false
    at examples/examples/fmt/yak_shave.rs:43 on main
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: failed to shave yak, yak: 3, error: missing yak
    at examples/examples/fmt/yak_shave.rs:48 on main
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty::yak_shave: yaks_shaved: 2
    at examples/examples/fmt/yak_shave.rs:52 on main
    in fmt_pretty::yak_shave::shaving_yaks with yaks: 3
  
  Oct 24 12:57:29.387 fmt_pretty: yak shaving completed, all_yaks_shaved: false
    at examples/examples/fmt-pretty.rs:19 on main
  

• format::Json: Outputs newline-delimited JSON logs. This is intended for production use with systems where structured logs are consumed as JSON by analysis and viewing tools. The JSON output, as seen below, is not optimized for human readability.

  For example:

      Finished dev [unoptimized + debuginfo] target(s) in 1.58s
       Running `target/debug/examples/fmt-json`
  {"timestamp":"Oct 24 13:00:00.873","level":"INFO","fields":{"message":"preparing to shave yaks","number_of_yaks":3},"target":"fmt_json"}
  {"timestamp":"Oct 24 13:00:00.874","level":"INFO","fields":{"message":"shaving yaks"},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"}]}
  {"timestamp":"Oct 24 13:00:00.874","level":"TRACE","fields":{"message":"hello! I'm gonna shave a yak","excitement":"yay!"},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"},{"yak":"1","name":"shave"}]}
  {"timestamp":"Oct 24 13:00:00.874","level":"TRACE","fields":{"message":"yak shaved successfully"},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"},{"yak":"1","name":"shave"}]}
  {"timestamp":"Oct 24 13:00:00.874","level":"DEBUG","fields":{"yak":1,"shaved":true},"target":"yak_events","spans":[{"yaks":3,"name":"shaving_yaks"}]}
  {"timestamp":"Oct 24 13:00:00.874","level":"TRACE","fields":{"yaks_shaved":1},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"}]}
  {"timestamp":"Oct 24 13:00:00.874","level":"TRACE","fields":{"message":"hello! I'm gonna shave a yak","excitement":"yay!"},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"},{"yak":"2","name":"shave"}]}
  {"timestamp":"Oct 24 13:00:00.874","level":"TRACE","fields":{"message":"yak shaved successfully"},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"},{"yak":"2","name":"shave"}]}
  {"timestamp":"Oct 24 13:00:00.874","level":"DEBUG","fields":{"yak":2,"shaved":true},"target":"yak_events","spans":[{"yaks":3,"name":"shaving_yaks"}]}
  {"timestamp":"Oct 24 13:00:00.874","level":"TRACE","fields":{"yaks_shaved":2},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"}]}
  {"timestamp":"Oct 24 13:00:00.874","level":"TRACE","fields":{"message":"hello! I'm gonna shave a yak","excitement":"yay!"},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"},{"yak":"3","name":"shave"}]}
  {"timestamp":"Oct 24 13:00:00.875","level":"WARN","fields":{"message":"could not locate yak"},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"},{"yak":"3","name":"shave"}]}
  {"timestamp":"Oct 24 13:00:00.875","level":"DEBUG","fields":{"yak":3,"shaved":false},"target":"yak_events","spans":[{"yaks":3,"name":"shaving_yaks"}]}
  {"timestamp":"Oct 24 13:00:00.875","level":"ERROR","fields":{"message":"failed to shave yak","yak":3,"error":"missing yak"},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"}]}
  {"timestamp":"Oct 24 13:00:00.875","level":"TRACE","fields":{"yaks_shaved":2},"target":"fmt_json::yak_shave","spans":[{"yaks":3,"name":"shaving_yaks"}]}
  {"timestamp":"Oct 24 13:00:00.875","level":"INFO","fields":{"message":"yak shaving completed","all_yaks_shaved":false},"target":"fmt_json"}
  

Filters

If you want to filter the tracing Events based on environment variables, you can use the EnvFilter as follows:

use tracing_subscriber::EnvFilter;

let filter = EnvFilter::from_default_env();

As mentioned above, the EnvFilter allows Spans and Events to be filtered at runtime by setting the RUST_LOG environment variable.

You can find the other available filters in the documentation.

Using Your Subscriber

Finally, once you have configured your Subscriber, you need to configure your executable to use it.

A subscriber can be installed globally using:

use tracing;
use tracing_subscriber::FmtSubscriber;

let subscriber = FmtSubscriber::new();

tracing::subscriber::set_global_default(subscriber)
    .map_err(|_err| eprintln!("Unable to set global default subscriber"));
// Note this will only fail if you try to set the global default
// subscriber multiple times

Composing Layers

Composing an EnvFilter Layer and a format Layer:

use tracing_subscriber::{fmt, EnvFilter};
use tracing_subscriber::prelude::*;

let fmt_layer = fmt::layer()
    .with_target(false);
let filter_layer = EnvFilter::try_from_default_env()
    .or_else(|_| EnvFilter::try_new("info"))
    .unwrap();

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

Modules

• format
  Formatters for logging tracing events.
• time
  Formatters for event timestamps.
• writer
  Abstractions for creating io::Write instances.

Structs

• FmtContext
  Provides the current span context to a formatter.
• FormattedFields
  A formatted representation of a span’s fields stored in its extensions.
• Layer
  A Layer that logs formatted representations of tracing events.
• Subscriber
  A Subscriber that logs formatted representations of tracing events.
• SubscriberBuilder
  Configures and constructs Subscribers.
• TestWriter
  A writer intended to support libtest’s output capturing for use in unit tests.

Traits

• FormatEvent
  A type that can format a tracing Event for a fmt::Write.
• FormatFields
  A type that can format a set of fields to a fmt::Write.
• MakeWriter
  A type that can create io::Write instances.

Functions

• fmt
  Returns a new SubscriberBuilder for configuring a formatting subscriber.
• format
  Returns the default configuration for an [event formatter].
• init
  Install a global tracing subscriber that listens for events and filters based on the value of the RUST_LOG environment variable.
• layer
  Returns a new formatting layer that can be composed with other layers to construct a Subscriber.
• time
  Returns a new SystemTime timestamp provider.
• try_init
  Install a global tracing subscriber that listens for events and filters based on the value of the RUST_LOG environment variable, if one is not already set.

Type Definitions

• Formatter
  A Subscriber that logs formatted representations of tracing events. This type only logs formatted events; it does not perform any filtering.
• LayerBuilderDeprecated
  A builder for Layer that logs formatted representations of tracing events and spans.