tokio-rs / tracing

Application level tracing for Rust.
https://tracing.rs
MIT License
5.19k stars 677 forks source link

Bug: In some scenarios, log content is lost. #2901

Open karellincoln opened 4 months ago

karellincoln commented 4 months ago

Bug Report

Version

tracing = "0.1.40"

│   │   └── tracing v0.1.40
│   │       ├── tracing-attributes v0.1.27 (proc-macro)
│   │       └── tracing-core v0.1.32
│   │   │   │   └── tracing v0.1.40 (*)
│   │   │   └── tracing v0.1.40 (*)
│   │   └── tracing v0.1.40 (*)
│   └── tracing v0.1.40 (*)
│   └── tracing v0.1.40 (*)
├── tracing v0.1.40 (*)
└── tracing-subscriber v0.3.18
    ├── tracing v0.1.40 (*)
    ├── tracing-core v0.1.32 (*)
    └── tracing-log v0.2.0
        └── tracing-core v0.1.32 (*)
│   │   └── tracing v0.1.40 (*)
│   │   ├── tracing v0.1.40 (*)

Platform

Mac Mini M1

Description

code:

    #[test]
    fn log_test() {
        tracing_subscriber::registry()
            .with(
                tracing_subscriber::EnvFilter::try_from_default_env()
                    .unwrap_or_else(|_| "info".into()),
            )
            .with(tracing_subscriber::fmt::layer())
            .init();

        info!("{}", "{}".to_string());
        info!("finished!!!");

        info!("{}", "{\"a\":\"a\"}".to_string());
        info!("finished!!!");

        info!("---- {}", "{\"a\":\"a\"}".to_string());
        info!("finished!!!");
    }

image

kaffarell commented 4 months ago

I am on the exact same versions and executed exactly the same code as you and get the correct output:

2024-03-06T14:48:58.857352Z  INFO rust_test: {}
2024-03-06T14:48:58.857418Z  INFO rust_test: finished!!!
2024-03-06T14:48:58.857426Z  INFO rust_test: {"a":"a"}
2024-03-06T14:48:58.857432Z  INFO rust_test: finished!!!
2024-03-06T14:48:58.857438Z  INFO rust_test: ---- {"a":"a"}
2024-03-06T14:48:58.857443Z  INFO rust_test: finished!!!

But as you use the EnvFilter you are setting a filter according to your RUST_LOG environment variable. Please post that one as well :)

mladedav commented 4 months ago

What rust/cargo version are you using? If it's possible, can you try your repro on the latest stable?

The arguments you're passing into the macro invocation should all be passed to format_args! so it's possible there was a bug or there is one on your platform. Does the same code work for you when you use println! instead of tracing::info!?

I wasn't able to reproduce it either.