Logging outputs invalid JSON

[edmellum]

Logging in release mode outputs unquoted strings several places (level, method, duration are some). I saw an issue on femme that might be related?

This becomes more of a problem when you use a log centralization tool like Splunk that tries to parse your JSON logs. Could a solution be to downgrade log or femme to a version that outputs valid JSON? I'm open to contributing here, but I'm not exactly sure where to start.

Thanks for all the amazing work on Tide! 😄

[Fishrock123]

Yeah that's a bug in femme. We should fix it, but something like https://crates.io/crates/json_env_logger should work.

if you need custom keys you will probably need to write your own.

[edmellum]

I tried using json_env_logger and method and duration are still unquoted. Almost seems like neither femme nor json_env_logger supports extra fields without manually adding quotes. I haven't really kept up with structured logging in Rust, is the new interface breaking all the structured logging libraries? Am I just confused or do both libraries need the same fix you've proposed in femme? 😄

I realize I'm getting a little off track for this issue, but I'm thinking it might be useful to people in my shoes googling around. If you feel this discussion doesn't fit this issue, just delete it. I really appreciate Tide, your help and the fix for femme! 😄

[Fishrock123]

Oh, you are right, json_env_logger also doesn't do this correctly anymore. I forgot about that since I had to re-write that logger for internal use anyways (we wanted different field names).

For now you could pin a git dependency on my branch or use [patch-crates.io] in Cargo.toml to do so.

[edmellum]

Using a patch pointing to your branch fixes the unquoted strings, but now I get two level fields like this:

{"level":30,"time":1606482508910,"msg":"Logger started","level":"INFO"}

I can't quite figure out why though. 🤔

[Fishrock123]

Is that message from log::info! or trace::info!?

[edmellum]

I believe it's from this line. I've reproduced the bug with a hello world Tide app with patch.crates-io pointing to your fix-kv-ndjson femme branch doing tide::log::start();

[Fishrock123]

Oh. I suppose that could be something like log_level.

[edmellum]

Or fixing this this bug you've reported might let Tide stop logging a level field altogether?

[AlyoshaVasilieva]

This is apparently fixed in femme v2.1.2 but that version is yanked (another change somehow broke WASM support) and there's no newer release. (Manually editing Cargo.lock to use it is an option if you're an end user and just want something working.)