fmt: `with_ansi(false)` doesn't affect function parameter from #[instrument] while `pretty()`

[Cielquan]

Bug Report

Version

$ cargo tree | grep tracing ├── tracing v0.1.25 │ ├── tracing-attributes v0.1.15 (proc-macro) │ └── tracing-core v0.1.17 └── tracing-subscriber v0.2.17 ├── tracing v0.1.25 () ├── tracing-core v0.1.17 () ├── tracing-log v0.1.2 │ └── tracing-core v0.1.17 () └── tracing-serde v0.1.2 └── tracing-core v0.1.17 ()

Platform

Linux mayumi 5.4.0-67-generic #75-Ubuntu SMP Fri Feb 19 18:03:38 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

Crates

I assume tracing-subscriber and/or tracing-attributes.

Description

I wanted to implement tracing-appender to write to a file so I deactivated ANSI, but still got ANSI sequences in my log files. I tracked it down to parameters from functions with the #[instrument] attribute in combination with pretty().

Example main.rs:

extern crate tracing;
extern crate tracing_subscriber;
use tracing::*;

fn main() {
    tracing_subscriber::fmt()
        .pretty()
        // .compact()
        .with_ansi(false)
        .with_thread_names(true)
        .init();
    error!("Starting");
    func(1);
    error!("Finishing");
}

#[instrument]
fn func (param1: i32) -> i32 {
    error!("Inside func");
    param1
}

One can see that the param1 is fat when run with pretty().

I let the output write to a file for easier showing using the example here: https://docs.rs/tracing-appender/0.1.2/tracing_appender/#non-blocking-rolling-file-appender

Output with pretty():

  Mar 17 22:45:09.288 ERRORrulaub_backend: Starting
    at rust_backend/src/main.rs:12 on main

  Mar 17 22:45:09.288 ERRORrulaub_backend: Inside func
    at rust_backend/src/main.rs:19 on main
    in rulaub_backend::func with param1: 1

  Mar 17 22:45:09.288 ERRORrulaub_backend: Finishing
    at rust_backend/src/main.rs:14 on main

Output with compact():

Mar 17 22:45:16.708 ERROR main rulaub_backend:Starting
Mar 17 22:45:16.708 ERROR main func: rulaub_backend:Inside func{param1}
Mar 17 22:45:16.709 ERROR main rulaub_backend:Finishing

[tyan-boot]

This has been fixed in 8985d976c94a22120ff7d73f7c9c062227504a1f

[Cielquan]

Thanks for the info, but the issue is not or not entirely fixed by the mentioned commit. My issue was out of scope for this commit, but a workaround is mentioned which does work for me.

In my interpretation of the commit message (below) I assume that #658 could fix this issue? I'll let this issue open as of now as the issue is not entirely fixed.

Out of Scope

One detail worth nothing is that this does not solve the problem of fields being formatted without ANSI codes. Configuring a subscriber using this snippet would still lead to bolded fields in parent spans.

tracing_subscriber::fmt()
   .pretty()
   .with_ansi(false)
   .with_level(false)
   .with_max_level(tracing::Level::TRACE)
   .init();

This can be worked around by using a different field formatter, via .fmt_fields(tracing_subscriber::fmt::format::DefaultFields::new()) in the short-term.

In the long-term, #658 is worth investigating further.

EDIT: Reworked comment completely