Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add support for Key-Value data in log records. #137

Merged
merged 3 commits into from
Mar 5, 2024

Conversation

tmccombs
Copy link
Contributor

@tmccombs tmccombs commented Jul 2, 2019

src/fmt/mod.rs Outdated Show resolved Hide resolved
src/fmt/mod.rs Outdated Show resolved Hide resolved
@simao
Copy link

simao commented Mar 29, 2022

Any news on this? Could we at least merge it behind a feature flag or something? Does this need any changes besides a rebase?

tmccombs referenced this pull request in rust-lang/log Mar 30, 2022
@tmccombs tmccombs marked this pull request as ready for review March 30, 2022 08:58
@hendrikmaus
Copy link

I would also love to start using it.

One good addition to the pull-request would probably be a usage example.

@simao
Copy link

simao commented Apr 1, 2022

I tried these changes and they work well. As far as usage examples go, I think that is done in the log crate? https://docs.rs/log/0.4.16/log/#structured-logging

Users of env_log would just need to use the log/kv_unstable feature, which I suppose should be mentioned somewhere?

One thing I noticed is maybe the target should be written after the kv pairs. Currently we get:

[2022-04-01T08:52:43Z INFO  tide::server] Server listening on http://0.0.0.0:8080
[2022-04-01T08:52:50Z INFO  method=POST path=/sensors/inside_weather status=200 - OK duration=11.487824ms tide::log::middleware] --> Response sent

But IMO the following looks cleaner, since target stays aligned with lines that do not have kv pairs:

[2022-04-01T08:54:12Z INFO  tide::log::middleware method=POST path=/sensors/inside_weather status=200 - OK duration=10.166265ms] --> Response sent

Also wanted to mentioned that it might be worth it to consider putting the structured data in different lines, to improve readability. At least for development, IMO the following looks better:

[2022-04-01T08:57:16Z INFO  tide::server] Server listening on http://0.0.0.0:8080
[2022-04-01T08:57:19Z INFO  tide::log::middleware
    method POST
    path /sensors/inside_weather] <-- Request received
[2022-04-01T08:57:19Z INFO  tide::log::middleware
    method POST
    path /sensors/inside_weather
    status 200 - OK
    duration 10.842409ms] --> Response sent

This is what femme does, and it's just using write!(self.0, "\n {} {}", key, value) in visit_pairs.

Though in production we'd probably want everything on the same line.

@hendrikmaus
Copy link

Thanks for pointing to the examples in the log crate. That makes sense.

As to your other points: I'd second both of them.

@svanharmelen
Copy link

I was just about to open an issue when I found this PR... It would be awesome if this could be merged so I can keep using env_logger and start using structured logging!

@svanharmelen
Copy link

svanharmelen commented Dec 22, 2022

Thanks for the rebase @tmccombs! After using this a little I'm thinking that it would (maybe) be good to make it configurable where the K/V's are written? As I'm used that they are written behind the actual log message instead of in front of it.

When reading a lot of log files that all log a different number of K/V's, you really have to scan al lot to find where the actual message is. If the K/V's are added at the end, all the messages are (more or less) directly above each other 🤷🏻‍♂️

@tmccombs
Copy link
Contributor Author

I added a commit that moves the Key values behind the rest of the option, and made it configurable whether it is on a single line or on separate lines, as @simao suggested.

@svanharmelen
Copy link

svanharmelen commented Dec 24, 2022

Looks really good!! Thanks for your efforts, I'll be using your branch until this gets (hopefully) merged 👍🏻

@prasannavl
Copy link

Any reason on what this is blocked on? Would be great to get this merged, even until an experimental flag.

@Fishrock123
Copy link

@epage could you enable CI runs on this?

src/fmt/mod.rs Fixed Show fixed Hide fixed
src/fmt/mod.rs Fixed Show fixed Hide fixed
@SVilgelm SVilgelm mentioned this pull request Jan 9, 2024
@tmccombs tmccombs force-pushed the structured branch 2 times, most recently from 549fcda to b5f0ea0 Compare January 10, 2024 09:02
@epage
Copy link
Contributor

epage commented Jan 12, 2024

@tmccombs at this point my thoughts are

  • Mirror what tracing-subscriber does for formatting and control of it
  • Rename the feature to unstable-kv, other features are using dashes at this point and I tend to put unstable- first.

@tmccombs
Copy link
Contributor Author

Mirror what tracing-subscriber does for formatting and control of it

I could use a little more direction on what you are looking for here. I'm guessing you mean have something like the FormatFields trait that would allow custom formatting of the fields?

Should I keep an implementation that uses newlines between each field? It looks liek tracing-subscriber always just includes all the fields on the same line as the main message.

Full and Compact use basically the same syntax for displaying fields, but Pretty is sligtly different (it i uses ": " instead of "=", is that a distinction worth having?)?

@epage
Copy link
Contributor

epage commented Jan 15, 2024

Hadn't looked into that before. Thanks for listing those considerations. As this is unstable, let's focus on an MVP and just use the formatting they do by default and not provide any configuration. We can then explore in an Issue what our formatting configuration options are, both those from the two PRs and from tracing-subscriber.

src/fmt/kv.rs Show resolved Hide resolved
@epage
Copy link
Contributor

epage commented Jan 23, 2024

KvFormatFn also works and fits within the style of the existing API. Thanks!

@tmccombs
Copy link
Contributor Author

I've resolved conflicts and squashed the commits.

src/fmt/mod.rs Outdated
/// The values can be suppressed, included in a trailer at the end of the line, or
/// included as multiple lines after the message.
#[derive(Copy, Clone, Debug, PartialEq, Eq)]
pub enum KVStyle {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this a zombie from resolving the merge conflicts?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ah, yes it is

Comment on lines +70 to +80
#[cfg(feature = "unstable-kv")]
pub use self::kv::*;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If you are already going back to make a change, can you you check this on RUSTDOCFLAGS=--cfg=docsrs cargo +nightly doc --all-features (I'm hoping that is correct).

Each API item behind a cfg should have a note in the documentation, like clap::command requiring cargo.

Most likely, you'll need to either duplicate this cfg on the items or move the cfg into the kv mod.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks like it works as is:

image

image

@tmccombs tmccombs force-pushed the structured branch 3 times, most recently from b40e990 to 29e378d Compare January 29, 2024 04:16
examples/direct_logger.rs Fixed Show fixed Hide fixed
@KodrAus
Copy link
Collaborator

KodrAus commented Feb 27, 2024

Hey all! 👋

Firstly, thank you for picking up and carrying this project forwards 🙏

We're (finally) about to stabilize the key-value support in log (see rust-lang/log#617), making this possible to support in env_logger without needing to fiddle with any unstable feature flags. If you'd like any help finishing off support here please do let me know.

@tmccombs
Copy link
Contributor Author

tmccombs commented Mar 4, 2024

I've updated to use the stable version of the log kv feature. Fixed merge conflicts, and fixed the compilation error when the color option is not enabled.

@epage epage merged commit e55af6f into rust-cli:main Mar 5, 2024
15 checks passed
@tmccombs tmccombs deleted the structured branch March 5, 2024 16:52
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

8 participants