[tracing-subscriber] Multiple subscriber disabled ansi on file layer, bold still in log file

[orange-pig]

Bug Report

Version

cargo.toml

tracing = "0.1.40"
tracing-subscriber = { version = "0.3.18", features = ["env-filter", "local-time"] }
tracing-appender = "0.2.3"

Platform

Windows 10 Professional 22H2 19045.4894

Crates

tracing-subscriber

Description

I use two subscriber in axum server app, conosle layer & file layer.
And i disabled the ansi on file layer. In log file, color is diabled, the bold chars always there.

I tried this code:

    // ## 1. registry tracing
    let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| {
        // axum logs rejections from built-in extractors with the `axum::rejection`
        // target, at `TRACE` level. `axum::rejection=trace` enables showing those events
        format!(
            "{}=debug,tower_http=debug,axum::rejection=trace",
            env!("CARGO_CRATE_NAME")
        )
        .into()
    });

    // local time
    let time_fmt = format_description::parse(
        "[year]-[month padding:zero]-[day padding:zero] [hour]:[minute]:[second]",
    )
    .unwrap();

    let time_offset = UtcOffset::current_local_offset().unwrap_or_else(|_| UtcOffset::UTC);
    let timer: tracing_subscriber::fmt::time::OffsetTime<Vec<format_description::FormatItem<'_>>> =
        tracing_subscriber::fmt::time::OffsetTime::new(time_offset, time_fmt);

    // output to console
    let console_format_layer = tracing_subscriber::fmt::layer()
        .with_timer(timer.clone());

    // output to file
    let file_appender: rolling::RollingFileAppender = rolling::daily("logs", "server.log");
    let (non_blocking_appender, _guard) = non_blocking(file_appender);
    let file_layer = tracing_subscriber::fmt::layer()
        .with_timer(timer.clone())
        .with_writer(non_blocking_appender)
        .with_ansi(false);

    tracing_subscriber::registry()
        .with(env_filter)
        .with(console_format_layer)
        .with(file_layer)
        .init();

I expected to see this happen:

File server.log

0000-00-00 00:00:00 DEBUG http_request{method=GET matched_path="/user"}:get_user: my_server::handler::user: The request name is Tom

Instead, this happened:

File server.log

0000-00-00 00:00:00 DEBUG http_request{�[3mmethod�[0m�[2m=�[0mGET �[3mmatched_path�[0m�[2m=�[0m"/user"}:get_user: my_server::handler::user: The request name is Tom

I try to remove console layer, it's ok.
I try to disable ansi in console layer, it's ok.
-->

[TheGP]

Wow so many contributors commented lol

[jmg-duarte]

I found "the issue", here's a reproducer:

#[tokio::main]
async fn main() {
    // Logger initialization.
    let file_appender = tracing_appender::rolling::daily("logs", "sp_server.log");
    let (non_blocking, _guard) = tracing_appender::non_blocking(file_appender);

    tracing_subscriber::registry()
        .with(fmt::layer())
        .with(fmt::layer().with_ansi(false).with_writer(non_blocking))  // notice how this is AFTER the first layer
        .with(
            EnvFilter::builder()
                .with_default_directive(LevelFilter::INFO.into())
                .from_env()
                .unwrap(),
        )
        .init();

    log(10).await;
}

#[tracing::instrument] // this causes the bold
async fn log(value: u64) {
    tracing::info!(%value, "hey!");
}

If you apply the following diff:

diff --git a/src/main.rs b/src/main.rs
index e9835cd..9d00c4d 100644
--- a/src/main.rs
+++ b/src/main.rs
@@ -50,8 +50,8 @@ async fn main() {
     let (non_blocking, _guard) = tracing_appender::non_blocking(file_appender);
 
     tracing_subscriber::registry()
-        .with(fmt::layer())
         .with(fmt::layer().with_ansi(false).with_writer(non_blocking))
+        .with(fmt::layer())
         .with(
             EnvFilter::builder()
                 .with_default_directive(LevelFilter::INFO.into())

It stops!

I don't get why (yet) though

[kaffarell]

Duplicate to #3116, this is a known issue. (and #3065.)