How to get the values in current span?

[tisonkun]

I'm porting code from slog to tracing. Here is the slog part:

macro_rules! fatal {
    ($logger:expr, $msg:expr) => {{
        let owned_kv = ($logger).list();
        let s = crate::util::format_kv_list(&owned_kv);
        if s.is_empty() {
            panic!("{}", $msg)
        } else {
            panic!("{}, {}", $msg, s)
        }
    }};
    ($logger:expr, $fmt:expr, $($arg:tt)+) => {{
        fatal!($logger, format_args!($fmt, $($arg)+))
    }};
}

fatal!(logger, "cannot find correspond read state from pending map");

where format_kv_list get OwnedKVList of current logger to format and display.

I learned that Span can be a counterpart to slog's Logger and thus write code like:

pub(crate) fn current_span_fields() -> String {
    let span = Span::current();
    match span.metadata() {
        None => "".to_owned(),
        Some(metadata) => {
            let fields = metadata.fields();
        }
    }
}

macro_rules! fatal {
    ($msg:expr) => {{
        let s = crate::util::current_span_fields();
        if s.is_empty() {
            panic!("{}", $msg)
        } else {
            panic!("{}, {}", $msg, s)
        }
    }};
    ($fmt:expr, $($arg:tt)+) => {{
        fatal!(format_args!($fmt, $($arg)+))
    }};
}

But it doesn't seems we have the counterpart to Logger::list for getting current (kv) values.

[davidbarsky]

But it doesn't seems we have the counterpart to Logger::list for getting current (kv) values.

You're not incorrect. The reason you've run into this limitation is that tracing Layers and Subscribers aren't required to record the key/value pairs in a span or event. For a demonstration, take a look at this example. I can say, with some pretty high confidence, that tracing will never implement this feature because it imposes a performance cost onto users who are not interested

• Exposing something like Logger::list requires recording the values, which tracing-core and tracing will not do on the user's behalf.
• Even if tracing did record the values, there is no clear format in which those values might be stored in—a JSON-based logger might want different formatting than a layer that exports a flamegraph.

With all that being said, I suspect that tracing-error or eyre with a custom spantrace formatter might get you close to what you're looking to accomplish.

[tisonkun]

Thank you! Interesting I found there is master and 0.1.x while 0.1.x is ahead of master - what is the version strategy here.

[tisonkun]

And you're right that a tracing context can be even a struct to "amend". I already did some like:

    fn span(&self) -> Span {
        trace_span!("connection", ?self.address)
    }

[davidbarsky]

Thank you! Interesting I found there is master and 0.1.x while 0.1.x is ahead of master - what is the version strategy here.

We've been meaning to to launch tracing 0.2 for a while. Generally speaking, new PRs are committed against master and we then backport changes to v0.1.x, so GitHub saying that master is "behind" is not entirely correct.

[tisonkun]

But the valuable feature is on v0.1.x branch only?

[davidbarsky]

that's because the plan is to make Valuable the default on 0.2, replacing the current tracing::Value trait.

[tisonkun]

@davidbarsky I found that it's actually the nested spans capture key values already. I write my own fatal like:

#[macro_export]
macro_rules! fatal {
    ($($arg:tt)*) => {{
        let prev = std::panic::take_hook();
        std::panic::set_hook(Box::new(move |info| {
            tracing::error!("{info}");
            prev(info);
        }));
        panic!($($arg)*);
    }};
}

[tisonkun]

Test case:

tracing_subscriber::fmt()
            .with_max_level(Level::TRACE)
            .init();
        error_span!("outer", id = 42).in_scope(|| {
            error_span!("inner", hey = "hey").in_scope(|| {
                fatal!("42");
            });
        });

output:

2023-07-18T09:04:30.904590Z ERROR outer{id=42}:inner{hey="hey"}: kalpas_roast::tests: panicked at '42', src/roast/src/lib.rs:35:17

42
thread 'tests::test_fatal' panicked at '42', src/roast/src/lib.rs:35:17
stack backtrace:
   0: rust_begin_unwind
             at /rustc/7bd81ee1902c049691d0a1f03be5558bee51d100/library/std/src/panicking.rs:593:5
   1: core::panicking::panic_fmt
             at /rustc/7bd81ee1902c049691d0a1f03be5558bee51d100/library/core/src/panicking.rs:67:14
   2: kalpas_roast::tests::test_fatal::{{closure}}::{{closure}}
             at ./src/lib.rs:35:17
   3: tracing::span::Span::in_scope
             at /Users/tison/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.37/src/span.rs:1102:9
   4: kalpas_roast::tests::test_fatal::{{closure}}
             at ./src/lib.rs:34:13
   5: tracing::span::Span::in_scope
             at /Users/tison/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.37/src/span.rs:1102:9
   6: kalpas_roast::tests::test_fatal
             at ./src/lib.rs:33:9
   7: kalpas_roast::tests::test_fatal::{{closure}}
             at ./src/lib.rs:29:21
   8: core::ops::function::FnOnce::call_once
             at /rustc/7bd81ee1902c049691d0a1f03be5558bee51d100/library/core/src/ops/function.rs:250:5
   9: core::ops::function::FnOnce::call_once
             at /rustc/7bd81ee1902c049691d0a1f03be5558bee51d100/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

[davidbarsky]

I'm glad this works!