Traceon - trace on

An easy to use log and tracing formatter with a flattened json or pretty output.

It builds on and simplifies the tracing crate, which adds context to log messages for better observability especially in async or multithreaded contexts, it focuses on logging all the associated context in flattened json or pretty print for every event, and is not concerned with span timings which can be done in a separate layer such as opentelemtry if required

the detailed tracing docs are here.

You can write your first trace with:

rust traceon::on(); traceon::info!("a simple message");

text 12:12:37 INFO a simple message

To capture the arguments used in a function:

```rust

[traceon::instrument]

fn add(a: i32, b: i32) { traceon::info!("result = {}", a + b); }

fn main() { traceon::on(); add(5, 10); } ```

Output:

text 09:52:33 INFO result = 15 a: 5 b: 10 span: add

To use json output instead:

rust traceon::json();

Outputs one line of flattened json per event, this example is prettified:

json { "time": "2023-01-01T05:28:13.447Z", "level": "INFO", "message": "result: 15", "a": 5, "b": 10, "span": "add" }

It's configurable through the builder if you want to change any of the defaults

``rust use traceon::{Case, JoinFields, LevelFormat, SecondsFormat, SpanFormat, TimeFormat, TimeZone, info}; fn main() { traceon::builder() // Add field with source code filename and line number e.g. src/main.rs:10 .file() // Add field with target and module path e.g. mybinary::mymodule::submodule .module() // Turn off field with joined span name where the event occured e.g. parentspan::childspan .span(SpanFormat::None) // If the time is recorded in local system timezone or UTC .timezone(TimeZone::UTC) // Change the formatting of the time to RFC3339 with Seconds and Zulu .time(TimeFormat::RFC3339Options(SecondsFormat::Secs, true)) // Change the casing of all the key names e.g.camelCasetosnakecase .case(Case::Snake) // The characters used to concatenate field values that repeat in nested spans. Defaults to overwrite. .join_fields(JoinFields::All("::")) // Turn on json formatting instead of pretty output .json() // Change level value formatting to numbers for easier filtering // trace: 10 // debug: 20 // info: 30 // warn: 40 // error: 50 .level(LevelFormat::Number) // Put anything that implementsWrite` here to redirect output .writer(std::io::stderr()) // on() activates it globally on all threads and panic if a global subcriber is already set // tryon() will return an error if a global subscriber is already set // on_thread() will return a guard so the subscriber will only be active in the current scope and thread .on();

info!("a simple message");

} ```

Output

json { "timestamp": "2023-01-01T03:26:48Z", "level": 30, "module": "builder", "file": "examples/builder.rs:27", "message": "a simple message" }

env-filter is used by default at the info level to filter any messages out at the debug or trace level, to change the level you can set an environment variable e.g. RUST_LOG=warn which would filter out info level as well, or RUST_LOG=trace to show all events. There are many options detailed here

Examples

#[instrument] macro

You can use the traceon::instrument macro with both async and normal functions to capture the arguments used in each function call:

```rust use traceon::{instrument, info};

[instrument]

async fn add(a: i32, b: i32) { info!("result: {}", a + b); }

[tokio::main]

async fn main() { traceon::builder().on(); add(5, 10).await; } ```

text 06:16:30 INFO result: 15 a: 5 b: 10 span: add

Instrument trait

If you need to add additional context to an async function, you can create a span and instrument it:

```rust use tracing::{Instrument, info};

async fn add(a: i32, b: i32) { tracing::info!("result: {}", a + b); }

[tokio::main]

async fn main() { traceon::builder().on(); let span = tracing::infospan!("mathfunctions", packagename = env!("CARGOPKG_NAME",)); add(5, 10).instrument(span).await; } ```

text 06:18:55 INFO result: 15 package_name: traceon span: math_functions The above package_name comes from Cargo.toml at compile time and is saved to the binary for runtime: toml [package] name = "traceon"

Entered spans

This creates a span and returns a guard, as long as that guard is in scope the span will be active: ```rust fn add(a: i32, b: i32) { tracing::info!("result: {}", a + b); }

fn main() { traceon::builder().on(); let guard = tracing::infospan!("math", packagename = env!("CARGOPKG_NAME")).entered(); add(5, 10); } ```

text 06:26:21 INFO result: 15 package_name: traceon span: math

Warning If add() was an async fn, holding onto the guard would cause memory leaks and information loss, you must use the above instrument macro or trait instead, more details here

Note Just remember don't call .await while holding onto a guard

Nested spans

By default the span name will be joined with the characters :: for nested spans: ```rust use traceon::{instrument, info};

[instrument]

fn add(a: i32, b: i32) { tracing::info!("result: {}", a + b); }

fn main() { traceon::builder().on(); let guard = tracing::infospan!("math", packagename = env!("CARGOPKGNAME")).entered(); add(5, 10); } text 06:33:57 INFO result: 15 a: 5 b: 10 packagename: traceon span: math::add ```

You can set this to overwrite if you prefer: rust use traceon::SpanFormat; traceon::builder().span(SpanFormat::Overwrite).on();

text 06:36:00 INFO result: 15 a: 5 b: 10 package_name: traceon span: add

By default all the other fields overwrite if a nested span has the same field name, you can join all fields or specific fields if you prefer (this only effects text values):

```rust use traceon::{JoinFields, info, infospan}; traceon::builder() .joinfields(JoinFields::Some("||", &["field_b"])) .on();

let span1 = infospan!("span1", fielda = "original", fieldb = "original").entered(); let span2 = infospan!("span2", fielda = "changed", fieldb = "changed").entered();

info!("testing field join"); ```

output: text 12:44:12 INFO testing field join field_a: changed field_b: original||changed span: span_1::span_1

Change the case of keys

Often you'll be consuming different crates that implement their own traces and you need all their keys to match a certain format, this example also demonstrates how to use different instances of traceon for a given scope with on_thread(), which returns a guard so the subscriber is only running on the current thread, and will be turned off when the guard is dropped.

examples/casing.rs ```rust use traceon::{Case, Level, event};

fn main() { let guard = traceon::builder().case(Case::Pascal).onthread(); event!( Level::INFO, message = "PascalCase", PascalCase = "test", camelCase = "test", snakecase = "test", SCREAMINGSNAKE_CASE = "test", );

let _guard = traceon::builder().case(Case::Camel).on_thread();
event!(
    Level::INFO,
    message = "camelCase",
    PascalCase = "test",
    camelCase = "test",
    snake_case = "test",
    SCREAMING_SNAKE_CASE = "test",
);

let _guard = traceon::builder().case(Case::Snake).on_thread();
event!(
    Level::INFO,
    message = "snake_case",
    PascalCase = "test",
    camelCase = "test",
    snake_case = "test",
    SCREAMING_SNAKE_CASE = "test",
);

} Output: text 10:06:38 INFO PascalCase CamelCase: test PascalCase: test ScreamingSnakeCase: test SnakeCase: test

10:06:38 INFO camelCase camelCase: test pascalCase: test screamingSnakeCase: test snakeCase: test

10:06:38 INFO snakecase camelcase: test pascalcase: test screamingsnakecase: test snakecase: test ```

Event

tracing::event! allows you to add fields to message without having to create a span, just remember to put the level e.g. tracing::Level::INFO as the first parameter, this also shows how to create a custom message in an event, and how to output a Debug implementation:

```rust use tracing::{Level, event};

fn main() { traceon::builder().on();

event!(
    Level::INFO,
    event_example = "add field and log it without a span"
);

let vector = vec![10, 15, 20];
event!(
    Level::WARN,
    message = "overwrite message, and debug a vector",
    ?vector,
);

} text 06:47:00 INFO event triggered event_example: add field and log it without a span

06:47:00 WARN overwrite message, and debug a vector vector: [10, 15, 20] ```

Write to a file

If you wanted to write to log files instead of std, it's as simple adding the dependency to Cargo.toml: toml [dependencies] tracing-appender = "0.2.2" And initializing it via the builder:

examples/file_writer.rs ```rust use traceon::info;

let fileappender = tracingappender::rolling::hourly("./", "test.log"); traceon::builder().json().writer(file_appender).on(); info!("wow cool!"); `` The writer accepts anything that implements theWritetrait, if you want to hold onto a buffer wrapped in anArcandMutexthere isbuffer()` method on the builder.

Compose with other layers

You can also use the formatting layer with other tracing layers as you get more comfortable with the tracing ecosystem, for example to add opentelemtry and change the filter:

```rust use opentelemetry::global; use traceon::{error, info}; use tracing_subscriber::{prelude::*, EnvFilter};

fn main() { let tracer = opentelemetryjaeger::newagentpipeline() .withservicename("traceonjaeger") .installsimple() .unwrap(); let opentelemetry = tracingopentelemetry::layer().withtracer(tracer); tracingsubscriber::registry() .with(traceon::builder()) .with(EnvFilter::new("debug")) .with(opentelemetry) .init();

info!("info messages will be filtered out");
error!("only error messages will write to stdout");
global::shutdown_tracer_provider();

} ```

Performance

This crate uses the idea originated from: LukeMathWalker/tracing-bunyan-formatter of storing fields from visited spans in a HashMap instead of a BTreeMap which is more suited for flattening fields, and results in very similar performance to the json formatter in tracing-subcriber:

logging to a sink

units = nanosecond or billionth of a second

logging to stdout

units = microsecond or millionth of a second

Nested spans three levels deep with concatenated fields: