Bug Report

Version

-> % cargo tree | grep tracing
├── tracing v0.1.13
│   ├── tracing-attributes v0.1.7
│   └── tracing-core v0.1.10
├── tracing-futures v0.2.4
│   └── tracing v0.1.13 (*)
├── tracing-log v0.1.1
│   └── tracing-core v0.1.10 (*)
├── tracing-subscriber v0.2.5
│   ├── tracing-core v0.1.10 (*)
│   ├── tracing-log v0.1.1 (*)
│   └── tracing-serde v0.1.1
│       └── tracing-core v0.1.10 (*)

Platform

-> % uname -a
Darwin xxxxx.local 19.4.0 Darwin Kernel Version 19.4.0: Wed Mar  4 22:28:40 PST 2020; root:xnu-6153.101.6~15/RELEASE_X86_64 x86_64

Crates

• tracing-subscriber I believe

Description

Nesting spans - specifically I'm using #[instrument] but I assume any method is the same - works great when using the normal text subscriber. But when using the JSON subscriber, only the innermost span details get returned.

For example, in the following:

#[tracing::instrument]
fn outer(a: u16) {
    inner(a);
}

#[tracing::instrument]
fn inner(b: u16) {
    log::info!("Hello from Log");
    tracing::info!("Hello from Tracing");
}

If I call this from a main function as follows:

fn main() {
    tracing_subscriber::fmt().init();
    outer(1);
}

Then the log outputs are:

May 03 17:57:47.336  INFO outer{a=1}:inner{b=1}: xxx: Hello from Log    
May 03 17:57:47.338  INFO outer{a=1}:inner{b=1}: xxx: Hello from Tracing

Which is exactly as expected. But if I instead use this:

fn main() {
    tracing_subscriber::fmt().json().flatten_event(false).init();
    outer(1);
}

Then the output becomes:

{"timestamp":"May 03 17:58:33.534","level":"INFO","span":{"b":"1","name":"inner"},"target":"xxx","fields":{"message":"Hello from Log","log.target":"xxx","log.module_path":"xxx","log.file":"src/main.rs","log.line":64}}
{"timestamp":"May 03 17:58:33.535","level":"INFO","span":{"b":"1","name":"inner"},"target":"xxx","fields":{"message":"Hello from Tracing"}}

Note that the span element contains "inner" but not "outer".

Since JSON logging is especially useful in production environments where you might want to have tooling running off of the structured logs, this is especially frustrating.

Cheers