panic emitting span events with format::json

[blinsay]

Bug Report

Version

$ cargo tree | grep tracing
tracing-example v0.1.0 (/Users/benl/src/tracing-example)
├── tracing v0.1.36
│   ├── tracing-attributes v0.1.22 (proc-macro)
│   └── tracing-core v0.1.29
└── tracing-subscriber v0.3.15
    ├── tracing v0.1.36 (*)
    ├── tracing-core v0.1.29 (*)
    ├── tracing-log v0.1.3
    │   └── tracing-core v0.1.29 (*)
    └── tracing-serde v0.1.3
        └── tracing-core v0.1.29 (*)

Platform

$ uname -a
Darwin bivalve.local 20.6.0 Darwin Kernel Version 20.6.0: Wed Jan 12 22:22:42 PST 2022; root:xnu-7195.141.19~2/RELEASE_X86_64 x86_64

Crates

tracing-subscriber

Description

Following the docs for customizing formatters I managed to get a panic with the message this is a bug when using the JSON formatter.

Here's a repro:

use tracing_subscriber::fmt::format::FmtSpan;

fn main() {
    tracing::subscriber::set_global_default(subscriber()).expect("failed to set up tracing");
    tracing::info_span!("hello dude");
}

fn subscriber() -> impl tracing::Subscriber {
    let format = tracing_subscriber::fmt::format::json();

    tracing_subscriber::fmt()
        .event_format(format)
        .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
        .finish()
}

And here's the panic. Let me know if the full backtrace would be useful.

$ RUST_LOG=info cargo run -q
thread 'main' panicked at 'span 'hello dude' had malformed fields! this is a bug.
  error: EOF while parsing a value at line 1 column 0
  fields: FormattedFields { fields: "", formatter: tracing_subscriber::fmt::format::DefaultFields, was_ansi: true }', /Users/benl/.cargo/registry/src/github.com-1ecc6299db9ec823/tracing-subscriber-0.3.15/src/fmt/format/json.rs:197:49
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

[davidbarsky]

You'll need to specify the the JsonField formatter as well:

    tracing_subscriber::fmt()
        .event_format(format)
        .fmt_fields(tracing_subscriber::fmt::format::JsonFields::new())
        .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
        .finish()

(This was previously reported in #1776 and is an unfortunate consequence of having separate field and event formatters.)

[blinsay]

Oh, thanks for the tip. It definitely wasn't clear from the docs or the error message - if there's any way I could contribute to better docs or improving the error message, let me know!

[davidbarsky]

It's a bit tricky to provide better panic messages, but PR to change the panic message to say something along the lines of "this a bug or the appropriate field formatter wasn't used" would be welcome if it was made against the master branch :)

(sorry this is a bit curt, i'm on mobile right now.)