Instrument not showing spans as expected

[bkolligs]

Code is this:

#[tracing::instrument]
fn trace_me(a: u32, b: u32) -> u32 {
    a + b
}

fn main() {
    tracing_subscriber::fmt::init();

    trace_me(2, 3);
    tracing::debug!("HEY");
}

I would expect a span printed for the trace_me function but nothing is printed when I run RUST_LOG=trace cargo run:

Finished dev [unoptimized + debuginfo] target(s) in 0.01s
Running target/debug/rust-tracing
2023-06-28T01:17:09.065954Z DEBUG rust_tracing: HEY

Tracing versions:

[dependencies]
tracing = "0.1.37"
tracing-subscriber = { version = "0.3.17", features = ["env-filter"] }

Rust toolchain:

Default host: x86_64-unknown-linux-gnu
rustup home:  /home/$USER/.rustup

installed toolchains
--------------------

stable-x86_64-unknown-linux-gnu (default)
nightly-2021-09-29-x86_64-unknown-linux-gnu
nightly-x86_64-unknown-linux-gnu

installed targets for active toolchain
--------------------------------------

wasm32-unknown-unknown
x86_64-unknown-linux-gnu

active toolchain
----------------

stable-x86_64-unknown-linux-gnu (default)
rustc 1.70.0 (90c541806 2023-05-31)

[bkolligs]

I think this is related here:
#2290
The tracing::instrument macro does not emit an event by itself.

[bkolligs]

Yes, an event must be emitted in order for the macro to log, so this code works:

#[tracing::instrument]
fn trace_me(a: u32, b: u32) -> u32 {
    tracing::info!("Hello");
    a + b
}

fn main() {
    tracing_subscriber::fmt::init();

    trace_me(2, 3);
    tracing::debug!("HEY");
}

[bkolligs]

Produces this output:

    Finished dev [unoptimized + debuginfo] target(s) in 0.18s
     Running `target/debug/rust-tracing`
2023-06-28T01:30:55.371776Z  INFO trace_me{a=2 b=3}: rust_tracing: Hello
2023-06-28T01:30:55.371808Z DEBUG rust_tracing: HEY

[davidbarsky]

The behavior you're seeing isn't occurring because of #[instrument] per-se, but rather, tracing_subscriber::fmt's default behavior to only write when an event occurs. You can change this behavior with fmt::Layer::with_span_event()/fmt::Subscriber::with_span_events.

(Note that there is basically no meaningful distinction between fmt::Layer and fmt::Subscriber except the former is more composable with other Layers. We'll probably get rid of fmt::Subscriber in a future release.)

[bkolligs]

Great thank you!