All log/tracing-log outputs have 4 spaces on the end

[Porges]

trafficstars

Bug Report

When writing to tracing via log (using default-installed tracing-log handler), messages from the log macros have an additional 4 spaces appended. Messages sent via the tracing macros do not.

When using env_logger instead this does not happen.

When using json or pretty this does not happen, it only happens with full or compact.

Version

repro-tracing v0.1.0 (D:\git\repro-tracing)
├── log v0.4.21
├── tracing v0.1.40
│   ├── pin-project-lite v0.2.14
│   ├── tracing-attributes v0.1.27 (proc-macro)
│   │   ├── proc-macro2 v1.0.83
│   │   │   └── unicode-ident v1.0.12
│   │   ├── quote v1.0.36
│   │   │   └── proc-macro2 v1.0.83 (*)
│   │   └── syn v2.0.65
│   │       ├── proc-macro2 v1.0.83 (*)
│   │       ├── quote v1.0.36 (*)
│   │       └── unicode-ident v1.0.12
│   └── tracing-core v0.1.32
│       └── once_cell v1.19.0
└── tracing-subscriber v0.3.18
    ├── nu-ansi-term v0.46.0
    │   ├── overload v0.1.1
    │   └── winapi v0.3.9
    ├── sharded-slab v0.1.7
    │   └── lazy_static v1.4.0
    ├── smallvec v1.13.2
    ├── thread_local v1.1.8
    │   ├── cfg-if v1.0.0
    │   └── once_cell v1.19.0
    ├── tracing-core v0.1.32 (*)
    └── tracing-log v0.2.0
        ├── log v0.4.21
        ├── once_cell v1.19.0
        └── tracing-core v0.1.32 (*)

Platform

Windows (64-bit)

Crates

tracing-log?

Description

Repro:

main.rs:

use tracing_subscriber::{fmt, layer::SubscriberExt, util::SubscriberInitExt};

fn main() {
    tracing_subscriber::registry()
        .with(fmt::layer().with_ansi(false))
        .init();
    log::info!("Hello from log");
    tracing::info!("Hello from tracing");
    log::info!("Hello again from log");
    tracing::info!("Hello again from tracing");
}

Cargo.toml:

[package]
name = "repro-tracing"
version = "0.1.0"
edition = "2021"

[dependencies]
tracing = "0.1.40"
tracing-subscriber = "0.3.18"
log = "0.4.21"

Output (end-of-line spaces represented by X):

2024-05-22T22:39:16.301618Z  INFO repro_tracing: Hello from logXXXX
2024-05-22T22:39:16.301684Z  INFO repro_tracing: Hello from tracing
2024-05-22T22:39:16.301690Z  INFO repro_tracing: Hello again from logXXXX
2024-05-22T22:39:16.301695Z  INFO repro_tracing: Hello again from tracing

[Porges]

I have a fix and will send a PR shortly.

[OliverGavin]

Awesome find - I've been going in circles trying to figure out what was broken. Leaving this here for the google bot to find :)

I am using the metrics-cloudwatch-embedded crate and publishing logs to CloudWatch using tracing-cloudwatch. I was pretty sure my EMF json/log line was correctly formatted until I copy pasted somebody else's into the console and eventually realized my logs were appearing in CloudWatch with an additional 4 spaces at the end. This gets rejected by CloudWatch and metrics are not generated and do not show up in the metrics console/view and there is no evidence of this failure anywhere.

Anybody trying to use tracing with log macros would have this issue when writing EMF logs for CloudWatch.