tracing
tracing copied to clipboard
Including a `message` field in a log macro leads to weird behavior
### 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.
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...