tracing icon indicating copy to clipboard operation
tracing copied to clipboard

Including a `message` field in a log macro leads to weird behavior

Open hrxi opened this issue 2 years ago • 1 comments

### Version
tracing-test v0.1.0 (/tmp/tracing-test)
├── tracing v0.1.34
│   ├── tracing-attributes v0.1.21 (proc-macro)
│   └── tracing-core v0.1.26
└── tracing-subscriber v0.3.11
    ├── tracing-core v0.1.26 (*)
    └── tracing-log v0.1.3
        └── tracing-core v0.1.26 (*)

Platform

$ uname -a
Linux arch7 5.17.5-arch1-1 #1 SMP PREEMPT Wed, 27 Apr 2022 20:56:11 +0000 x86_64 GNU/Linux

Description

use tracing::info;

fn main() {
    tracing_subscriber::fmt().init();
    let request_id = 1;
    let peer_id = 2;
    info!(%request_id, %peer_id, note = "Now you see me!", "Just an ordinary log message");
    info!(%request_id, %peer_id, message = "Now you don't!", "Another ordinary log message?");
}
2022-05-16T15:08:13.134059Z  INFO tracing_test: Just an ordinary log message request_id=1 peer_id=2 note="Now you see me!"
2022-05-16T15:08:13.134105Z  INFO tracing_test: Another ordinary log message? request_id=1 peer_id=2 Now you don't!

In the second example, you see Now you don't! but no field it belongs to. It is mentioned somewhere in the documentation that the message field is special, but this is still weird behavior. I'd expect it to either: 1) actually show me the message field 2) rename the message field automatically to message_ or so 3) panic or 4) give a compile-time error.

hrxi avatar May 16 '22 15:05 hrxi

Hmm, yeah, the current behavior isn't really ideal. We should probably try to make a compile-time error if there are any duplicate field names. Unfortunately, that might be a bit complicated to do with declarative macros...

hawkw avatar May 16 '22 17:05 hawkw