davidbarsky / tracing-tree

Apache License 2.0
123 stars 31 forks source link

Logging events printed at incorrect indentation level #72

Closed obsgolem closed 5 months ago

obsgolem commented 10 months ago

Logging events are printed two indentation level deeper than the scope that produced them rather than one. Minimal example:

use tracing::instrument;
use tracing_subscriber::{prelude::__tracing_subscriber_SubscriberExt, EnvFilter, Registry};
use tracing_tree::HierarchicalLayer;

fn main() {
    let subscriber = Registry::default()
        .with(
            HierarchicalLayer::new(2)
                .with_bracketed_fields(true)
                .with_wraparound(100),
        )
        .with(EnvFilter::from_default_env());
    tracing::subscriber::set_global_default(subscriber).expect("Failed to initialize logging.");

    inst();
}

#[instrument(level = "debug", ret)]
fn inst() -> Result<(), ()> {
    inst2()?;
    tracing::error!("temp");
    Ok(())
}

#[instrument(level = "debug", ret)]
fn inst2() -> Result<(), ()> {
    tracing::error!("temp2");
    Ok(())
}

produces the following output for me:

 inst{}
   inst2{}
       0ms ERROR temp2
       0ms DEBUG return=Ok(())
     0ms ERROR temp
     0ms DEBUG return=Ok(())

In deeply nested logs, this makes it highly non-obvious which events correspond with which span. Furthermore, this doesn't play well with indentation based folding.