gh-rust-lang/log
Watch
1
0
Fork
You've already forked log
 0
Code Issues 16 Pull requests 2 Releases Activity

Tracking issue for kv_unstable (structured logging) #328

New issue
Closed
opened 2019-04-28 23:30:06 -05:00 by KodrAus · 50 comments
KodrAus commented 2019-04-28 23:30:06 -05:00 (Migrated from github.com)

Tracking issue for the implementation of #296. See also #149

Tracking issue for the implementation of #296. See also #149 - [x] Initial implementation (#324) - [ ] Integration with frameworks and loggers: - [x] [`slog`](https://github.com/slog-rs/slog) - [x] Zero-allocation conversion between `slog::Value` and `log::kv::Value`. We should be able to do zero-allocation conversion from `log` to `slog`, but may need to allocate from `slog` to `log`. - [ ] [`tracing`](https://github.com/tokio-rs/tracing) (https://github.com/tokio-rs/tracing/issues/341) - [x] Zero-allocation conversion between `tracing::Value` and `log::kv::Value` in the `event!` macro (#339) - [x] Capture `std::error::Error`s as `Value`s - [ ] [`fern`](https://github.com/daboross/fern) - [ ] [`async-log`](https://github.com/rustasync/async-log) - [x] [`std-logger`](https://github.com/Thomasdezeeuw/std-logger) (https://github.com/Thomasdezeeuw/std-logger/pull/14) - [x] Some way to tell whether a `Source` has any key-value pairs (#329) - [ ] [`femme`](https://github.com/lrlna/femme) - [ ] [`env_logger`](https://github.com/sebasmagri/env_logger) (https://github.com/sebasmagri/env_logger/pull/137) - [x] [`antlog`](https://github.com/KodrAus/antlog) (an experimental wrapper to prove out requirements) - [x] A way to get specific values (#335) - [x] A way to coerce a value to a common type (#379) - _Please suggest others to track!_ - [x] Explore macro support (#343) - [x] `log!("msg {}", interpolated, { key: value })` (#353) - We ended up having to revert this in `log`, but are experimenting externally - [x] [`log_kv_macro`](https://docs.rs/kv-log-macro/1.0.6/kv_log_macro/) - [x] [`log_macros`](https://github.com/KodrAus/log_macros) - [x] Integration with serialization frameworks: - [x] `serde` - [x] Conversion between `serde::Serialize` and `std::fmt::Debug` (https://github.com/rust-lang/rfcs/pull/2696). See [`serde_fmt`](https://github.com/KodrAus/serde_fmt). - [x] `sval` (#342) - [ ] Micro benchmarks - [ ] Documentation and examples - [ ] Stabilization review - [ ] Open questions - [ ] Should `Source::count` return a `Result<usize>` instead of a plain `usize`?
👍 26 ❤️ 31
yoshuawuyts commented 2019-07-02 07:04:22 -05:00 (Migrated from github.com)

@KodrAus thanks for all the work you've put into this (and linking to this issue from a forum post).

I was curious: is there a release planned that includes the beta version of kv? I actually wanted to use the beta for async-log, but given there wasn't any release yet it wasn't possible 😅

@KodrAus thanks for all the work you've put into this (and linking to this issue from a forum post). I was curious: is there a release planned that includes the beta version of `kv`? I actually wanted to use the beta for `async-log`, but given there wasn't any release yet it wasn't possible :sweat_smile:
KodrAus commented 2019-07-03 21:43:54 -05:00 (Migrated from github.com)

Hi @yoshuawuyts! 👋

Right now any release of log we publish will include this API under the kv_unstable feature gate, but we're not ready to commit to backwards compatibility just yet. So if you depend on log from git then you can access the API:

[dependencies.log]
git = "https://github.com/rust-lang-nursery/log.git"
features = ["kv_unstable"]

I think what we need are a few draft PRs in some of these log frameworks that tease out any breaking changes we should make, and then will be able to publish a release that replaces the kv_unstable feature gate with a kv one.

Hi @yoshuawuyts! :wave: Right now any release of `log` we publish will include this API under the `kv_unstable` feature gate, but we're not ready to commit to backwards compatibility just yet. So if you depend on `log` from `git` then you can access the API: ```rust [dependencies.log] git = "https://github.com/rust-lang-nursery/log.git" features = ["kv_unstable"] ``` I think what we need are a few draft PRs in some of these log frameworks that tease out any breaking changes we should make, and then will be able to publish a release that replaces the `kv_unstable` feature gate with a `kv` one.
yoshuawuyts commented 2019-07-04 04:56:30 -05:00 (Migrated from github.com)

Right now any release of log we publish will include this API under the kv_unstable feature gate,

Oh oops, maybe I was being a bit vague. The last release on crates.io was done in October 2018, which means currently no releases ship with kv_unstable on crates.io. Which in turn (I believe) means we can't ship any versions to crates.io.

In order to help test this feature, it would be nice if there was a release on crates.io with the ["kv_unstable"] feature available. For experimental technology such as async-log I think we can get away with publishing a version that directly depends on this feature, and keep updating it as it's polished.

So my question is: could a version be of log be published to crates.io that includes the experimental flag?

P.S. Thanks for taking time out of your day to reply to my questions!

> Right now any release of log we publish will include this API under the kv_unstable feature gate, Oh oops, maybe I was being a bit vague. The last release on crates.io was done in [October 2018](https://crates.io/crates/log), which means currently no releases ship with `kv_unstable` on crates.io. Which in turn (I believe) means we can't ship any versions to crates.io. In order to help test this feature, it would be nice if there was a release on crates.io with the `["kv_unstable"]` feature available. For experimental technology such as `async-log` I think we can get away with publishing a version that directly depends on this feature, and keep updating it as it's polished. So my question is: could a version be of `log` be published to crates.io that includes the experimental flag? P.S. Thanks for taking time out of your day to reply to my questions!
KodrAus commented 2019-07-05 20:36:05 -05:00 (Migrated from github.com)

In order to help test this feature, it would be nice if there was a release on crates.io with the ["kv_unstable"] feature available. For experimental technology such as async-log I think we can get away with publishing a version that directly depends on this feature, and keep updating it as it's polished.

Ah this sounds fair enough. I think we can get pretty far without needing to break anything, but it's probably going to happen at some point. But right now it is harder for folks to get started with these new APIs, so once #339 lands I'll put together a release so you can depend on it from crates.io and browse the docs on docs.rs.

> In order to help test this feature, it would be nice if there was a release on crates.io with the ["kv_unstable"] feature available. For experimental technology such as async-log I think we can get away with publishing a version that directly depends on this feature, and keep updating it as it's polished. Ah this sounds fair enough. I think we can get pretty far without needing to break anything, but it's probably going to happen at some point. But right now it is harder for folks to get started with these new APIs, so once #339 lands I'll put together a release so you can depend on it from `crates.io` and browse the docs on `docs.rs`.
❤️ 1
yoshuawuyts commented 2019-07-21 09:08:37 -05:00 (Migrated from github.com)

@KodrAus in the top-level post there's an entry about "Explore macro support". Do you have any plans to experiment with this?

We've integrated key-value logging in https://github.com/lrlna/femme/pull/1; all that's missing now is a way to create key-value pairs and send them to a logger. Even a small code example would be helpful, but ideally there'd be a small log crate that could work with this.

Also: is it perhaps useful to open a separate issue to track/discuss logging macros?

edit 2019-07-21:
Ah, I think I figured out how to log a kv-pair!

let record = log::Record::builder().key_values(kv_pairs).build();
log::logger().log(&record);
@KodrAus in the top-level post there's an entry about "Explore macro support". Do you have any plans to experiment with this? We've integrated key-value logging in https://github.com/lrlna/femme/pull/1; all that's missing now is a way to create key-value pairs and send them to a logger. Even a small code example would be helpful, but ideally there'd be a small log crate that could work with this. Also: is it perhaps useful to open a separate issue to track/discuss logging macros? --- __edit 2019-07-21:__ Ah, I think I figured out how to log a kv-pair! ```rust let record = log::Record::builder().key_values(kv_pairs).build(); log::logger().log(&record); ```
KodrAus commented 2019-07-21 16:20:50 -05:00 (Migrated from github.com)

Ah yes that Record::key_values method is the way you can attach key-value pairs to a record in the absence of macro support. It needs to be a &dyn Source.

Opening a separate issue to design macro support sounds like a good idea! We’ve got a couple of constraints but also plenty of opportunity to improve things.

Ah yes that `Record::key_values` method is the way you can attach key-value pairs to a record in the absence of macro support. It needs to be a `&dyn Source`. Opening a separate issue to design macro support sounds like a good idea! We’ve got a couple of constraints but also plenty of opportunity to improve things.
yoshuawuyts commented 2019-07-22 05:27:00 -05:00 (Migrated from github.com)

Macro issue created: https://github.com/rust-lang-nursery/log/issues/343

Macro issue created: https://github.com/rust-lang-nursery/log/issues/343
👍 1
yoshuawuyts commented 2019-09-01 04:49:33 -05:00 (Migrated from github.com)

Created a crate for shared types in key-value logs (to mark pairs of logs) -- https://github.com/yoshuawuyts/log-types. Not sure yet how useful this is, but I think it might be a fun reference of how to create source/key/value structs, and probably a useful experiment (:

Created a crate for shared types in key-value logs (to mark pairs of logs) -- https://github.com/yoshuawuyts/log-types. Not sure yet how useful this is, but I think it might be a fun reference of how to create source/key/value structs, and probably a useful experiment (:
❤️ 1
KodrAus commented 2019-09-01 17:46:06 -05:00 (Migrated from github.com)

Having some standards around well-known key-value pairs is something I've also been exploring in a little wrapper. It seems like it'll be useful for a more composable logging ecosystem.

Having some standards around well-known key-value pairs is something I've also been exploring in [a little wrapper](https://github.com/KodrAus/antlog). It seems like it'll be useful for a more composable logging ecosystem.
❤️ 1
yoshuawuyts commented 2019-09-01 18:31:49 -05:00 (Migrated from github.com)

@KodrAus Yeah for sure! -- I wonder which others to add; I only really thought of spans::{start,end} and http::{request,response}. Though I guess timestamps, host, ip might be common too?

Oh also, I saw femme is not listed yet; could we perhaps add it to the tracking issue?

@KodrAus Yeah for sure! -- I wonder which others to add; I only really thought of `spans::{start,end}` and `http::{request,response}`. Though I guess timestamps, host, ip might be common too? Oh also, I saw [femme](https://github.com/lrlna/femme) is not listed yet; could we perhaps add it to the tracking issue?
👍 1
atroche commented 2019-09-17 08:46:24 -05:00 (Migrated from github.com)

I'm hesitant to add to the list of todos because I really want this feature, but it might be worth adding fern as another crate to integrate with. I don't use it (I use slog), but it seems like it has quite a lot of usage (600,000+ all time downloads on crates.io).

I'm hesitant to add to the list of todos because I really want this feature, but it might be worth adding [fern](https://crates.io/crates/fern) as another crate to integrate with. I don't use it (I use slog), but it seems like it has quite a lot of usage (600,000+ all time downloads on crates.io).
MOZGIII commented 2019-10-16 17:58:20 -05:00 (Migrated from github.com)

Should Source::count return a Result<usize> instead of a plain usize?
What if we move the Source::count to a separate trait:

trait SourceCount: Source {
    fn count(&self) -> usize;
}

Rationale is it looks more reasonable to just make it a type-system question whether a certain type has a notion of a count of it's kvs or not.

And if that's not the desired use case for making count return Result<usize> - then what is? What do you see as possible error values? Why not just Option<usize>? Some lazy-evaluated kv sources might not have count known upfront, i.e. something like processes list (ps ax) might be collected on demand.

> Should `Source::count` return a `Result<usize>` instead of a plain `usize`? What if we move the `Source::count` to a separate trait: ```rust trait SourceCount: Source { fn count(&self) -> usize; } ``` Rationale is it looks more reasonable to just make it a type-system question whether a certain type has a notion of a count of it's `kv`s or not. And if that's not the desired use case for making `count` return `Result<usize>` - then what is? What do you see as possible error values? Why not just `Option<usize>`? Some lazy-evaluated `kv` sources might not have count known upfront, i.e. something like processes list (`ps ax`) might be collected on demand.
KodrAus commented 2019-10-16 19:14:37 -05:00 (Migrated from github.com)

What if we move the Source::count to a separate trait

@MOZGIII unfortunately a separate trait wouldn't really work because we'd lose the implementation when erasing as dyn Source.

What do you see as possible error values?

The desire for Result would just be to be able to pass through any errors from the default implementation that calls the fallible visit_pair method. But Option seems worthwhile!

Some lazy-evaluated kv sources might not have count known upfront

Hmm, I don't think the current implementation really supports this kind of scenario because pairs can be visited and fetched at any point. I also don't think it's really desirable to support either, because pairs may be inspected and visited multiple times any expensive work or externally changing information could be confusing to end consumers.

> What if we move the Source::count to a separate trait @MOZGIII unfortunately a separate trait wouldn't really work because we'd lose the implementation when erasing as `dyn Source`. > What do you see as possible error values? The desire for `Result` would just be to be able to pass through any errors from the default implementation that calls the fallible `visit_pair` method. But `Option` seems worthwhile! > Some lazy-evaluated kv sources might not have count known upfront Hmm, I don't think the current implementation really supports this kind of scenario because pairs can be visited and fetched at any point. I also don't think it's really desirable to support either, because pairs may be inspected and visited multiple times any expensive work or externally changing information could be confusing to end consumers.
MOZGIII commented 2019-10-17 04:56:19 -05:00 (Migrated from github.com)

Given all that, I'm having hard time imagining a case when the count would be None (or Err). Do you have an example in mind?
How is the count used? Is it like iterator's size_hint?

Given all that, I'm having hard time imagining a case when the `count` would be `None` (or `Err`). Do you have an example in mind? How is the `count` used? Is it like iterator's `size_hint`?
MOZGIII commented 2019-10-17 05:54:59 -05:00 (Migrated from github.com)

Hmm, I don't think the current implementation really supports this kind of scenario because pairs can be visited and fetched at any point. I also don't think it's really desirable to support either, because pairs may be inspected and visited multiple times any expensive work or externally changing information could be confusing to end consumers.

From how the code is set up, it looks fine: the Source can be used at any time to collect values via Source::visit. There is an implementation note on visit fn A source should yield the same key-value pairs to a subsequent visitor unless that visitor itself fails. that advocates against sources being dynamic. After looking around the documentation more, I found the uses for Source, and it makes a lot of sense for it to be required to not be dynamic. 👍

> Hmm, I don't think the current implementation really supports this kind of scenario because pairs can be visited and fetched at any point. I also don't think it's really desirable to support either, because pairs may be inspected and visited multiple times any expensive work or externally changing information could be confusing to end consumers. From how the code is set up, it looks fine: the `Source` can be used at any time to collect values via `Source::visit`. There is an implementation note on visit fn `A source should yield the same key-value pairs to a subsequent visitor unless that visitor itself fails.` that advocates against sources being dynamic. After looking around the documentation more, I found the uses for `Source`, and it makes a lot of sense for it to be required to not be dynamic. :+1:
👍 1
KodrAus commented 2020-01-30 23:35:08 -06:00 (Migrated from github.com)

I've spent a little time looking at how we could support attempting to coerce structured values to concrete types. This is something that would make logging frameworks that want to enrich log::Records with their own well-known types nicer. There's a PR in #379

Once we have that and #378, we can add support for std::error::Error to structured values too. It might look something like:

impl<'v> Value<'v> {
    pub fn from_error<E>(err: &'v E) -> Self
    where
        E: Error + 'static;

    pub fn get_error(&self) -> Option<&(dyn Error + 'static)>;
}
I've spent a little time looking at how we could support attempting to coerce structured values to concrete types. This is something that would make logging frameworks that want to enrich `log::Record`s with their own well-known types nicer. There's a PR in #379 Once we have that and #378, we can add support for `std::error::Error` to structured values too. It might look something like: ```rust impl<'v> Value<'v> { pub fn from_error<E>(err: &'v E) -> Self where E: Error + 'static; pub fn get_error(&self) -> Option<&(dyn Error + 'static)>; } ```
❤️ 2
softprops commented 2020-06-28 17:26:56 -05:00 (Migrated from github.com)

I see there's a 'kv_unstable' feature flag in the latest version of the log crate but it's unclear how to interface with in from an application. Is this not something we can do today?

I see there's a 'kv_unstable' feature flag in the latest version of the `log` crate but it's unclear how to interface with in from an application. Is this not something we can do today?
softprops commented 2020-06-28 17:31:58 -05:00 (Migrated from github.com)

I found this commit which seems like it reverted an interface users could leverage is https://docs.rs/kv-log-macro the crate users should be guided towards?

I found [this commit](https://github.com/rust-lang/log/commit/c3a9a14c580e57840d6cf0861774681def5805c5) which seems like it reverted an interface users could leverage is https://docs.rs/kv-log-macro the crate users should be guided towards?
yoshuawuyts commented 2020-06-30 02:20:56 -05:00 (Migrated from github.com)

@softprops yeah, we're still in the process of figuring out the macros. Currently kv-log-macro is one of the most convenient ways to use the kv feature, but the goal is to eventually have this functionality in log's macros itself.

@softprops yeah, we're still in the process of figuring out the macros. Currently `kv-log-macro` is one of the most convenient ways to use the kv feature, but the goal is to eventually have this functionality in `log`'s macros itself.
👍 1
pickfire commented 2020-06-30 09:18:21 -05:00 (Migrated from github.com)

Have we figured out other ways to preserve states? The current log!("", { key: value }) will be quite duplicated when the same { key: value } needs to be reused in different scopes.

Have we figured out other ways to preserve states? The current `log!("", { key: value })` will be quite duplicated when the same `{ key: value }` needs to be reused in different scopes.
👍 1
KodrAus commented 2020-06-30 18:17:49 -05:00 (Migrated from github.com)

@yoshuawuyts and I discussed the path to stabilization for the kv support and came to the conclusion that there's really not much blocking calling the kv module stable and continuing to work on it without breakage. I think we've explored enough of the design space to cover macro support and integration with tracing properly.

What about macros?

We don't currently have macro support in log itself, but since we're bound to std::fmt the macros we can provide in here in a backwards compatible way can't be as capable as what we produce externally. We will still provide macro support in log itself, but that doesn't need to block removing the kv_unstable feature gate.

Right now, if you want macro support you can check out kv_log_macro. It's an almost drop-in replacement for the existing macros.

I'm also experimenting with something completely greenfield for macros that I hope to talk about more when it's fleshed out.

So what's left?

I'd like to get #396 merged, which lets us capture values using a trait bound like impl Display + 'static but still determine at compile-time whether the actual value is one of a number of primitives like i32. Until 1.46.0 is released in August it'll have a small runtime hit though. I think that's the last breaking behavioural change we need to make then can do a thorough API review.

What's after stabilization?

@yoshuawuyts brought up the possibility of adding logging/tracing support into std, which I think is worth exploring. I've been framing it as a structured/contextual enhancement to std::fmt but going down that route might be the best possible way to make the existing log macros natively structured.

@yoshuawuyts and I discussed the path to stabilization for the kv support and came to the conclusion that there's really not much blocking calling the `kv` module stable and continuing to work on it without breakage. I think we've explored enough of the design space to cover macro support and integration with `tracing` properly. ## What about macros? We don't currently have macro support in `log` itself, but since we're bound to `std::fmt` the macros we can provide in here in a backwards compatible way can't be as capable as what we produce externally. We will still provide macro support in `log` itself, but that doesn't need to block removing the `kv_unstable` feature gate. Right now, if you want macro support you can check out [`kv_log_macro`](https://docs.rs/kv-log-macro/1.0.6/kv_log_macro/). It's an almost drop-in replacement for the existing macros. I'm also experimenting with something completely greenfield for macros that I hope to talk about more when it's fleshed out. ## So what's left? I'd like to get #396 merged, which lets us capture values using a trait bound like `impl Display + 'static` but still determine at compile-time whether the actual value is one of a number of primitives like `i32`. Until 1.46.0 is released in August it'll have a small runtime hit though. I think that's the last breaking behavioural change we need to make then can do a thorough API review. ## What's after stabilization? @yoshuawuyts brought up the possibility of adding logging/tracing support into `std`, which I think is worth exploring. I've been framing it as a structured/contextual enhancement to `std::fmt` but going down that route might be the best possible way to make the existing log macros natively structured.
🚀 3
softprops commented 2020-07-06 00:08:43 -05:00 (Migrated from github.com)

What's the story for the kv visitor trait and serde. It seems today the visit api gives you a access to a Key and Value. You can get the &str value of a Key but values are a bit opaque. I know that they implement Display and Debug but i'd rather depend on their serde::Serialize impl when serializing them out.

What's the story for the kv visitor trait and serde. It seems today the visit api gives you a access to a [Key and Value](https://github.com/rust-lang/log/blob/813b6ce4793b50d4a60aa28c057f79902c8dfbe0/src/kv/source.rs#L191). You can get the `&str` value of a `Key` but values are a bit opaque. I know that they implement `Display` and `Debug` but i'd rather depend on their serde::Serialize impl when serializing them out.
KodrAus commented 2020-07-06 08:00:15 -05:00 (Migrated from github.com)

Hey @softprops 👋

It would be pretty unfortunate for structured values to only support the unstructured Debug or Display outputs. I wrote a bit about serde in https://github.com/rust-lang/log/issues/388#issuecomment-629572564.

The gist of it is we currently support serde in a roundabout way using a different structured framework, but should definitely add first-class serde support using erased-serde (we could fall back to the alternative framework when alloc isn’t available). There’s nothing blocking this and it can be implemented at any time.

Hey @softprops 👋 It would be pretty unfortunate for structured values to only support the unstructured `Debug` or `Display` outputs. I wrote a bit about `serde` in https://github.com/rust-lang/log/issues/388#issuecomment-629572564. The gist of it is we currently support `serde` in a roundabout way using a different structured framework, but should definitely add first-class `serde` support using `erased-serde` (we could fall back to the alternative framework when `alloc` isn’t available). There’s nothing blocking this and it can be implemented at any time.
👍 1
softprops commented 2020-07-06 08:06:08 -05:00 (Migrated from github.com)

@KodrAus that's awesome! Is anyone actively working on this? I'd love to help but am not caught up on all the current and prior discussion.

@KodrAus that's awesome! Is anyone actively working on this? I'd love to help but am not caught up on all the current and prior discussion.
KodrAus commented 2020-07-12 16:09:22 -05:00 (Migrated from github.com)

@softprops As far as I know it’s not something being actively worked on yet. If you’d like to take a look that would be great! Otherwise it was next on my list after #396, since that changes the shape of the value internals a bit.

To add serde support we’ll effectively add the following public API:

impl<‘v> Value<‘v> {
    pub fn from_serde(value: &’v (impl serde::Serialize + ‘static)) -> Self;
}

impl<‘v> serde::Serialize for Value<‘v> {}

The things we’d need to do internally would be:

  • Add optional dependencies on erased-serde and serde-fmt
  • Add a kv_unstable_serde feature that pulls in the std feature, sval/serde, serde-fmt and serde
  • Add a new kv::value::internal::serde module, probably following a similar structure to internal::sval
  • When both kv_unstable_sval and kv_unstable_serde are available, we can use sval‘s serde bridge to implement the Visitor::sval method in the serde module and the Visitor::serde method in the sval module
  • Use serde-fmt to implement the Visitor::debug and Visitor::display methods in the serde module
  • Add a new Serde variant to internal::Inner
  • Add a new serde method to internal::Visitor
  • Add kv_unstable_serde to our GitHub Actions on its own and combined with kv_unstable_sval

But if anybody waned to dig in I’d be happy to help! The best place to reach out would probably be on Zulip.

@softprops As far as I know it’s not something being actively worked on yet. If you’d like to take a look that would be great! Otherwise it was next on my list after #396, since that changes the shape of the value internals a bit. To add `serde` support we’ll effectively add the following public API: ```rust impl<‘v> Value<‘v> { pub fn from_serde(value: &’v (impl serde::Serialize + ‘static)) -> Self; } impl<‘v> serde::Serialize for Value<‘v> {} ``` The things we’d need to do internally would be: - Add optional dependencies on `erased-serde` and `serde-fmt` - Add a `kv_unstable_serde` feature that pulls in the `std` feature, `sval/serde`, `serde-fmt` and `serde` - Add a new `kv::value::internal::serde` module, probably following a similar structure to [`internal::sval`](https://github.com/rust-lang/log/blob/master/src/kv/value/internal/sval.rs) - When both `kv_unstable_sval` and `kv_unstable_serde` are available, we can use [`sval`‘s `serde` bridge](https://docs.rs/sval/0.5.2/sval/serde/index.html) to implement the `Visitor::sval` method in the `serde` module and the `Visitor::serde` method in the `sval` module - Use `serde-fmt` to implement the `Visitor::debug` and `Visitor::display` methods in the `serde` module - Add a new `Serde` variant to [`internal::Inner`](https://github.com/rust-lang/log/blob/master/src/kv/value/internal/mod.rs#L17) - Add a new `serde` method to [`internal::Visitor`](https://github.com/rust-lang/log/blob/master/src/kv/value/internal/mod.rs#L47) - Add `kv_unstable_serde` to our GitHub Actions on its own and combined with `kv_unstable_sval` But if anybody waned to dig in I’d be happy to help! The best place to reach out would probably be [on Zulip](https://forge.rust-lang.org/libs/index.html#where-to-find-us).
👍 1
softprops commented 2020-07-12 16:12:04 -05:00 (Migrated from github.com)

This sounds great. I'll be sure to drop a note here if I start anything.

This sounds great. I'll be sure to drop a note here if I start anything.
🎉 3
uazu commented 2020-10-08 15:31:38 -05:00 (Migrated from github.com)

I had some issues getting 0.4.11 structured logging working. I've written my own logging macros because I have some specific requirements, and I'm also writing my own Logger to receive all this data because the outgoing logging channels I have to interface to are custom. I chose to put it all through log crate because I also want to capture unstructured logging. Some observations/questions:

  • If the Visitor only has one method, it would be better to just replace it with a FnMut, making Logger code simpler
  • However right now to get a binary value out, the Visitor has to call various different to_* methods in turn on the Value to find what type it contains, so wouldn't it be better to turn that around and have several different methods on the Visitor which would be called according to the type of the value? e.g. visit_pair_u64, visit_pair_str, etc. The types handled by OpenTelemetry for example are limited to i64, bool, f64 and str, plus arrays and tables. So ignoring the nested values for the moment, and adding u64, that requires just five visitor methods to cover it.
  • It might be good to point people to the fact that Value implements Display, because for text-log output, I started out by querying the different to_* methods and formatting for each one. However this didn't work because I couldn't find a way to get a value created with Value::from_display out using the to_* methods. So maybe it would be best to have two visit calls, one for text-style output, which just takes a FnMut and gives it a &str for each value (which would point to either the original value or else an internal temporary format buffer), and another for getting binary data out, which has a Visitor with multiple entry-points (for i64/u64/f64/bool/str/etc). I haven't implemented binary output yet, but it seems like right now I'll have to try various to_* methods in turn, and then finally try a format!("{}", val). This doesn't seem very efficient. (The log crate is advertised as "lightweight".)

I was trying to understand the current code. There is a lot of dynamic dispatch going on, and a lot of type machinery. Is all this necessary? If it is, then fine. However did you consider something like a HCons-style approach? i.e. construct a nested type which would result in all the heterogenous keys/values being stored sequentially in stack memory with minimal padding (e.g. KvInt(("key", 123, KvStr(("key2", &strvar, KvEnd))))), and let the compiler build a single visit function for it all that accepts a Visitor and visits them all (where the Visitor has an entry-point for each fundamental supported type). That would make good use of static knowledge from the callsite to optimise at least the first level of processing. (Nested arrays or tables would need some kind of dynamic approach.) I can provide some prototype code if this isn't clear.

I had some issues getting 0.4.11 structured logging working. I've written my own logging macros because I have some specific requirements, and I'm also writing my own Logger to receive all this data because the outgoing logging channels I have to interface to are custom. I chose to put it all through **log** crate because I also want to capture unstructured logging. Some observations/questions: - If the Visitor only has one method, it would be better to just replace it with a FnMut, making Logger code simpler - However right now to get a binary value out, the Visitor has to call various different `to_*` methods in turn on the Value to find what type it contains, so wouldn't it be better to turn that around and have several different methods on the Visitor which would be called according to the type of the value? e.g. visit_pair_u64, visit_pair_str, etc. The [types handled by OpenTelemetry](https://github.com/open-telemetry/opentelemetry-proto/blob/master/opentelemetry/proto/common/v1/common.proto#L24) for example are limited to `i64`, `bool`, `f64` and `str`, plus arrays and tables. So ignoring the nested values for the moment, and adding `u64`, that requires just five visitor methods to cover it. - It might be good to point people to the fact that `Value` implements `Display`, because for text-log output, I started out by querying the different `to_*` methods and formatting for each one. However this didn't work because I couldn't find a way to get a value created with `Value::from_display` out using the `to_*` methods. So maybe it would be best to have two `visit` calls, one for text-style output, which just takes a FnMut and gives it a `&str` for each value (which would point to either the original value or else an internal temporary format buffer), and another for getting binary data out, which has a Visitor with multiple entry-points (for i64/u64/f64/bool/str/etc). I haven't implemented binary output yet, but it seems like right now I'll have to try various `to_*` methods in turn, and then finally try a `format!("{}", val)`. This doesn't seem very efficient. (The **log** crate is advertised as "lightweight".) I was trying to understand the current code. There is a lot of dynamic dispatch going on, and a lot of type machinery. Is all this necessary? If it is, then fine. However did you consider something like a HCons-style approach? i.e. construct a nested type which would result in all the heterogenous keys/values being stored sequentially in stack memory with minimal padding (e.g. `KvInt(("key", 123, KvStr(("key2", &strvar, KvEnd))))`), and let the compiler build a single `visit` function for it all that accepts a Visitor and visits them all (where the Visitor has an entry-point for each fundamental supported type). That would make good use of static knowledge from the callsite to optimise at least the first level of processing. (Nested arrays or tables would need some kind of dynamic approach.) I can provide some prototype code if this isn't clear.
uazu commented 2020-10-09 05:41:08 -05:00 (Migrated from github.com)

Actually, thinking about it some more, would it be possible to make it work with a closure like this:

logger.log(&Record::builder()
           .whatever(...)
           .key_values(|visitor| {
               Value::from(&myvar1).visit(visitor, "key1");
               Value::from(&myvar2).visit(visitor, "key2");
               /// etc
           })
           .build());

That way, assuming all the Value-related calls are marked #[inline] it should all get inlined to produce flat code that just executes a series of calls on the visitor instance. This assumes that the Visitor has separate entry points for major types (u64, i64, f64, bool, str). The closure will build a hidden structure on the stack which contains the references to all the variables being logged. So this should be really efficient and lightweight. I could prototype this if it is of any interest.

Actually, thinking about it some more, would it be possible to make it work with a closure like this: ``` logger.log(&Record::builder() .whatever(...) .key_values(|visitor| { Value::from(&myvar1).visit(visitor, "key1"); Value::from(&myvar2).visit(visitor, "key2"); /// etc }) .build()); ``` That way, assuming all the Value-related calls are marked `#[inline]` it should all get inlined to produce flat code that just executes a series of calls on the `visitor` instance. This assumes that the Visitor has separate entry points for major types (`u64`, `i64`, `f64`, `bool`, `str`). The closure will build a hidden structure on the stack which contains the references to all the variables being logged. So this should be really efficient and lightweight. I could prototype this if it is of any interest.
KodrAus commented 2020-12-20 19:02:48 -06:00 (Migrated from github.com)

Hey @uazu! 👋

Sorry for taking so long to circle back and thanks for putting together your thoughts 😃

If the Visitor only has one method, it would be better to just replace it with a FnMut, making Logger code simpler

The reason Visitor is a trait instead of just a FnMut is that it gives us a place to add provided methods like get and count, so Visitor::visit_pair is like Iterator::next. You only implement that one method but get all the other combinators on top. For your last example, you can already do this:

logger.log(&Record::builder()
           .whatever(...)
           .key_values(&[
               ("key1", Value::from(&myvar1)),
               ("key2", Value::from(&myvar2)),
               /// etc
           ])
           .build());

However right now to get a binary value out, the Visitor has to call various different to_* methods in turn on the Value to find what type it contains, so wouldn't it be better to turn that around and have several different methods on the Visitor which would be called according to the type of the value? e.g. visit_pair_u64, visit_pair_str, etc. The types handled by OpenTelemetry for example are limited to i64, bool, f64 and str, plus arrays and tables. So ignoring the nested values for the moment, and adding u64, that requires just five visitor methods to cover it.

The goal of the Value::to_* methods is for more ad-hoc inspection. If you're writing a log sink that wants to do something particular with a timestamp or trace identifier for instance you can check whether the key-value pairs you're given contains a value called timestamp, and then check whether that timestamp is a string or a chrono::DateTime<Utc>. They're really inconvenient for trying to serialize structured values directly. In order to visit all pairs and serialize them you use either the sval::Value or serde::Serialize implementations which have the API you're describing.

The kicker for the visitor API is the plus arrays and tables part. Once you have to support complex datastructures the API becomes a lot more complex and the open design space a lot bigger than just simple primitives. Not supporting arrays and maps isn't really an option because you certainly want to log them. So we offer two options in log for properly serializing values: there's sval for no-std serialization and serde for wider compatibility. Both can handle any shaped datastructures and require fairly large APIs to do so.

There is a lot of dynamic dispatch going on, and a lot of type machinery. Is all this necessary? If it is, then fine. However did you consider something like a HCons-style approach?

I'd be interested to see a HCons-style approach! My experience with H-lists in Rust has been that they're somewhat going against the grain of the language and so require a lot more type machinery, various hacks, and tend to produce large and incomprehensible error messages. One of the goals of log as well is to generate as little code in callsites as possible, ideally just a single function call. But that doesn't mean exploring different approaches isn't worthwhile! We settled on trait objects fairly early and never deeply considered trying to go the other way into fully generic code.

Hey @uazu! :wave: Sorry for taking so long to circle back and thanks for putting together your thoughts 😃 > If the Visitor only has one method, it would be better to just replace it with a FnMut, making Logger code simpler The reason `Visitor` is a trait instead of just a `FnMut` is that it gives us a place to add provided methods like `get` and `count`, so `Visitor::visit_pair` is like `Iterator::next`. You only implement that one method but get all the other combinators on top. For your last example, you can already do this: ```rust logger.log(&Record::builder() .whatever(...) .key_values(&[ ("key1", Value::from(&myvar1)), ("key2", Value::from(&myvar2)), /// etc ]) .build()); ``` > However right now to get a binary value out, the Visitor has to call various different to_* methods in turn on the Value to find what type it contains, so wouldn't it be better to turn that around and have several different methods on the Visitor which would be called according to the type of the value? e.g. visit_pair_u64, visit_pair_str, etc. The types handled by OpenTelemetry for example are limited to i64, bool, f64 and str, plus arrays and tables. So ignoring the nested values for the moment, and adding u64, that requires just five visitor methods to cover it. The goal of the `Value::to_*` methods is for more ad-hoc inspection. If you're writing a log sink that wants to do something particular with a timestamp or trace identifier for instance you can check whether the key-value pairs you're given contains a value called `timestamp`, and then check whether that timestamp is a string or a `chrono::DateTime<Utc>`. They're really inconvenient for trying to serialize structured values directly. In order to visit all pairs and serialize them you use either the `sval::Value` or `serde::Serialize` implementations which have the API you're describing. The kicker for the visitor API is the _plus arrays and tables_ part. Once you have to support complex datastructures the API becomes a lot more complex and the open design space a lot bigger than just simple primitives. Not supporting arrays and maps isn't really an option because you certainly want to log them. So we offer two options in `log` for properly serializing values: there's [`sval`](https://docs.rs/sval/1.0.0-alpha.4/sval/index.html) for no-std serialization and [`serde`](docs.rs/serde) for wider compatibility. Both can handle any shaped datastructures and require fairly large APIs to do so. > There is a lot of dynamic dispatch going on, and a lot of type machinery. Is all this necessary? If it is, then fine. However did you consider something like a HCons-style approach? I'd be interested to see a HCons-style approach! My experience with H-lists in Rust has been that they're somewhat going against the grain of the language and so require a lot more type machinery, various hacks, and tend to produce large and incomprehensible error messages. One of the goals of `log` as well is to generate as little code in callsites as possible, ideally just a single function call. But that doesn't mean exploring different approaches isn't worthwhile! We settled on trait objects fairly early and never deeply considered trying to go the other way into fully generic code.
uazu commented 2020-12-21 14:20:38 -06:00 (Migrated from github.com)

@KodrAus Thanks for replying.

In my opinion, since 'log' is supposed to be a lightweight logging crate, the key-value logging mechanism should be lightweight too. It doesn't need to support everything -- a superset of JSON and OpenTelemetry style values would be enough. It should be streamlined for dumping the data to a stream, since that's the most common operation.

In case it's of interest: My original reason to look into this was to add minimal key-value logging support to my Stakker crate. In the end I implemented my own minimal logging interface directly in Stakker, with the logging macros in a separate crate: stakker_log. This was done because none of the crates out there did quite what I needed. Also because I needed to transparently pass through a span ID (which is effectively an actor number) with the log records, to support span-based logging. Also, since Stakker is single-threaded, it's more efficient to log within the same thread, rather than to something which then has to use a Mutex or whatever. The intention is that the user-provided logging handler could either dump out directly, or forward logging to whatever logging crate the user prefers. This does also handle nested values (arrays and maps), although in a very minimal visitor style: just a closure at the point of logging which dumps the data as calls to a visitor closure which outputs it.

@KodrAus Thanks for replying. In my opinion, since 'log' is supposed to be a lightweight logging crate, the key-value logging mechanism should be lightweight too. It doesn't need to support everything -- a superset of JSON and OpenTelemetry style values would be enough. It should be streamlined for dumping the data to a stream, since that's the most common operation. In case it's of interest: My original reason to look into this was to add minimal key-value logging support to my Stakker crate. In the end I implemented my own [minimal logging interface](https://docs.rs/stakker/0.2.0/stakker/struct.Stakker.html#method.set_logger) directly in Stakker, with the logging macros in a separate crate: [stakker_log](https://docs.rs/stakker_log/0.0.2/stakker_log/). This was done because none of the crates out there did quite what I needed. Also because I needed to transparently pass through a span ID (which is effectively an actor number) with the log records, to support span-based logging. Also, since Stakker is single-threaded, it's more efficient to log within the same thread, rather than to something which then has to use a Mutex or whatever. The intention is that the user-provided logging handler could either dump out directly, or forward logging to whatever logging crate the user prefers. This does also handle nested values (arrays and maps), although in a very minimal visitor style: just a closure at the point of logging which dumps the data as calls to a visitor closure which outputs it.
KodrAus commented 2020-12-23 16:58:38 -06:00 (Migrated from github.com)

since 'log' is supposed to be a lightweight logging crate, the key-value logging mechanism should be lightweight too.

That's absolutely important! One of the balancing acts we're playing in log is that it needs to be lightweight, but because it exists between other libraries and frameworks it also needs to be permissive enough to retain as much context as it can when dealing with data from other sources. So by default it supports visiting pairs of displayable key-value pairs and additional features let it integrate with more feature-full serialization frameworks. Your thoughts did end up prompting #426, which makes it easier to serialize the complete set of key-value pairs as either a map or list.

In the end I implemented my own minimal logging interface directly in Stakker

Ah it's nice to see the kind of API you've been talking about in practice there. Your LogVisitor trait actually looks pretty similar to what I ended up with in sval. That library was actually spiked out within log originally, but I pulled it out because it become too big to maintain inline. That's the same story with value-bag, which is the basis of log's value API.

> since 'log' is supposed to be a lightweight logging crate, the key-value logging mechanism should be lightweight too. That's absolutely important! One of the balancing acts we're playing in `log` is that it needs to be lightweight, but because it exists between other libraries and frameworks it also needs to be permissive enough to retain as much context as it can when dealing with data from other sources. So by default it supports visiting pairs of displayable key-value pairs and additional features let it integrate with more feature-full serialization frameworks. Your thoughts did end up prompting #426, which makes it easier to serialize the complete set of key-value pairs as either a map or list. > In the end I implemented my own minimal logging interface directly in Stakker Ah it's nice to see the kind of API you've been talking about in practice there. Your `LogVisitor` trait actually looks pretty similar to what I [ended up with in `sval`](https://docs.rs/sval/1.0.0-alpha.4/sval/stream/index.html). That library was actually spiked out within `log` originally, but I pulled it out because it become too big to maintain inline. That's the same story with [`value-bag`](https://docs.rs/value-bag/1.0.0-alpha.5/value_bag/struct.ValueBag.html), which is the basis of `log`'s value API.
👍 2
tmccombs commented 2022-12-28 01:49:13 -06:00 (Migrated from github.com)

Zero-allocation conversion between slog::Value and log::kv::Value. We should be able to do zero-allocation conversion from log to slog, but may need to allocate from slog to log

I've started working on improving the implementation of translating strucuted data between log and slog (and just implementing it to begin with in the slog -> log direction).

For log-> slog, I don't think it can be completely allocation free, because the slog Key type internally uses a Cow<'static, str>, but the log Key type can have a narrower lifetime than 'static, so it is necessary to allocate new strings for the keys. See https://github.com/slog-rs/stdlog/pull/25/files#diff-2f5dbd891ecf8d768b1b394d2138b2c244bd8dc54ff8ad4b16325877f3709eb7R46

For slog-> log, I ran into a more difficult hurdle. I can't directly create a slog::Serializer that forwards calls to a log::kv::Visitor, because the lifetimes don't work out. Fine, I can build up a data structure containing the key values, like a Vec<(String, Value<'static>)>. And that almost works, unless the value is a string, because there is no implementation of From<String> for Value<'a> . I don't think it is completely unsolveable, I could instead use Vec<(String, Box<dyn ToValue>)>, but that then requires boxing everything. Or I could create a new Source that contains both a Vec<(String, String)> and a Vec<(String, Value<'static>)>, but that is more complicated. It would be a lot simpler if there was a way to create a Value<'static> that includes an owned copy of a String. That might require a change in the upstream value_bag crate.

> Zero-allocation conversion between slog::Value and log::kv::Value. We should be able to do zero-allocation conversion from log to slog, but may need to allocate from slog to log I've started working on improving the implementation of translating strucuted data between log and slog (and just implementing it to begin with in the slog -> log direction). For log-> slog, I don't think it can be completely allocation free, because the slog `Key` type internally uses a `Cow<'static, str>`, but the log `Key` type can have a narrower lifetime than `'static`, so it is necessary to allocate new strings for the keys. See https://github.com/slog-rs/stdlog/pull/25/files#diff-2f5dbd891ecf8d768b1b394d2138b2c244bd8dc54ff8ad4b16325877f3709eb7R46 For slog-> log, I ran into a more difficult hurdle. I can't directly create a `slog::Serializer` that forwards calls to a `log::kv::Visitor`, because the lifetimes don't work out. Fine, I can build up a data structure containing the key values, like a `Vec<(String, Value<'static>)>`. And that almost works, unless the value is a string, because there is no implementation of `From<String> for Value<'a>` . I don't think it is completely unsolveable, I could instead use `Vec<(String, Box<dyn ToValue>)>`, but that then requires boxing everything. Or I could create a new `Source` that contains both a `Vec<(String, String)>` and a `Vec<(String, Value<'static>)>`, but that is more complicated. It would be a lot simpler if there was a way to create a `Value<'static>` that includes an owned copy of a `String`. That might require a change in the upstream `value_bag` crate.
❤️ 1
tmccombs commented 2022-12-28 02:42:29 -06:00 (Migrated from github.com)

u128 and i128 have a similar issue. Although, in that case falling back to representing them as a string probably isn't terrible.

u128 and i128 have a similar issue. Although, in that case falling back to representing them as a string probably isn't terrible.
Thomasdezeeuw commented 2023-01-01 09:42:08 -06:00 (Migrated from github.com)

I've started working on improving the implementation of translating strucuted data between log and slog (and just implementing it to begin with in the slog -> log direction).

For log-> slog, I don't think it can be completely allocation free, because the slog Key type internally uses a Cow<'static, str>, but the log Key type can have a narrower lifetime than 'static, so it is necessary to allocate new strings for the keys. See https://github.com/slog-rs/stdlog/pull/25/files#diff-2f5dbd891ecf8d768b1b394d2138b2c244bd8dc54ff8ad4b16325877f3709eb7R46

I imagine most keys being 'static, e.g. when creating using of the macros, so perhaps we can use MaybeStaticStr internally? Same as what we do for a Record's module and file? Then we can provide fn as_static_str(&self) -> Option<&'static str>. That avoid a good number of allocation in slog I think.

For slog-> log, I ran into a more difficult hurdle. I can't directly create a slog::Serializer that forwards calls to a log::kv::Visitor, because the lifetimes don't work out. Fine, I can build up a data structure containing the key values, like a Vec<(String, Value<'static>)>. And that almost works, unless the value is a string, because there is no implementation of From<String> for Value<'a> . I don't think it is completely unsolveable, I could instead use Vec<(String, Box<dyn ToValue>)>, but that then requires boxing everything. Or I could create a new Source that contains both a Vec<(String, String)> and a Vec<(String, Value<'static>)>, but that is more complicated. It would be a lot simpler if there was a way to create a Value<'static> that includes an owned copy of a String. That might require a change in the upstream value_bag crate.

I think kv::Value, and thus the value_bag crate, was designed with borrowing instead of owning value in mind. But I'll defer that to @KodrAus. We could do a simple pointer tagging to indicate an owned string, but that we would have to drop the capacity I think.

u128 and i128 have a similar issue. Although, in that case falling back to representing them as a string probably isn't terrible.

Does slog not support 128 bit integers? If so, that's a limitation in slog, not so much in log.

> I've started working on improving the implementation of translating strucuted data between log and slog (and just implementing it to begin with in the slog -> log direction). > > For log-> slog, I don't think it can be completely allocation free, because the slog `Key` type internally uses a `Cow<'static, str>`, but the log `Key` type can have a narrower lifetime than `'static`, so it is necessary to allocate new strings for the keys. See https://github.com/slog-rs/stdlog/pull/25/files#diff-2f5dbd891ecf8d768b1b394d2138b2c244bd8dc54ff8ad4b16325877f3709eb7R46 I imagine most keys being `'static`, e.g. when creating using of the macros, so perhaps we can use `MaybeStaticStr` internally? Same as what we do for a `Record`'s module and file? Then we can provide `fn as_static_str(&self) -> Option<&'static str>`. That avoid a good number of allocation in slog I think. > For slog-> log, I ran into a more difficult hurdle. I can't directly create a `slog::Serializer` that forwards calls to a `log::kv::Visitor`, because the lifetimes don't work out. Fine, I can build up a data structure containing the key values, like a `Vec<(String, Value<'static>)>`. And that almost works, unless the value is a string, because there is no implementation of `From<String> for Value<'a>` . I don't think it is completely unsolveable, I could instead use `Vec<(String, Box<dyn ToValue>)>`, but that then requires boxing everything. Or I could create a new `Source` that contains both a `Vec<(String, String)>` and a `Vec<(String, Value<'static>)>`, but that is more complicated. It would be a lot simpler if there was a way to create a `Value<'static>` that includes an owned copy of a `String`. That might require a change in the upstream `value_bag` crate. I think `kv::Value`, and thus the `value_bag` crate, was designed with borrowing instead of owning value in mind. But I'll defer that to @KodrAus. We could do a simple pointer tagging to indicate an owned string, but that we would have to drop the capacity I think. > u128 and i128 have a similar issue. Although, in that case falling back to representing them as a string probably isn't terrible. Does slog not support 128 bit integers? If so, that's a limitation in slog, not so much in log.
tmccombs commented 2023-01-01 11:42:51 -06:00 (Migrated from github.com)

Slog does support u128 and i128, but there isn't a way to store them as owned values in Value, because value_bag just stores a reference to them (I assume to keep the size small... although &str is a fat pointer right, so on 64-bit architectures it would already need 128 bits 🤔 ). I did figure out a way to solve this by making a wrapper type that holds the owned value. See https://github.com/slog-rs/stdlog/pull/26.

However, I couldn't figure out a way to preserve a &dyn (Error +'static), because the lifetime isn't long enough, and there isn't any way to convert to an owned type. To resolve that, there would probably need to be a breaking change in either slog (change it to use references that are tied to the Serializer type, similar to log's Visitor or add a Clone trait bound to the error type) or log (relax the lifetime).The former would probably be better, since it could allow less allocations in other serializers for slog as well. But I'm not sure that's worth the churn.

Slog does support u128 and i128, but there isn't a way to store them as owned values in `Value`, because value_bag just stores a reference to them (I assume to keep the size small... although `&str` is a fat pointer right, so on 64-bit architectures it would already need 128 bits 🤔 ). I did figure out a way to solve this by making a wrapper type that holds the owned value. See https://github.com/slog-rs/stdlog/pull/26. However, I couldn't figure out a way to preserve a `&dyn (Error +'static)`, because the lifetime isn't long enough, and there isn't any way to convert to an owned type. To resolve that, there would probably need to be a breaking change in either slog (change it to use references that are tied to the `Serializer` type, similar to log's `Visitor` or add a Clone trait bound to the error type) or log (relax the lifetime).The former would probably be better, since it could allow less allocations in other serializers for slog as well. But I'm not sure that's worth the churn.
loganmzz commented 2023-08-16 03:26:24 -05:00 (Migrated from github.com)

Any plan to make this stable ? More than 4 years since issue opening. This feature is mandatory for attaching contextual information to logs (user, error id, use case, etc.) that can then be passed as kv to logging/event ingestion systems (ELK, Loki, InfluxDB, etc.).

Or any workaround ?

Any plan to make this stable ? More than 4 years since issue opening. This feature is mandatory for attaching contextual information to logs (user, error id, use case, etc.) that can then be passed as kv to logging/event ingestion systems (ELK, Loki, InfluxDB, etc.). Or any workaround ?
👍 3
tmccombs commented 2023-08-16 10:05:32 -05:00 (Migrated from github.com)

The workaround is to use the unstable feature, or use the slog crate.

The workaround is to use the unstable feature, or use the slog crate.
👍 1
8573 commented 2023-08-16 13:26:23 -05:00 (Migrated from github.com)

tracing is quite popular and was designed for structured logging. It can catch the (unstructured) log events of log and turn them into tracing events. I don't know whether it's more stable than this, though.

[`tracing`](https://lib.rs/crates/tracing) is quite popular and was designed for structured logging. It can catch the (unstructured) log events of `log` and turn them into `tracing` events. I don't know whether it's more stable than this, though.
👍 2 😕 1
jmjoy commented 2023-08-16 20:07:03 -05:00 (Migrated from github.com)

It is better to have a unified log library. I know that the popular ones are log, slog, and tracing. It is better to add log to the standard library, like log/slog in golang.

It is better to have a unified log library. I know that the popular ones are `log`, `slog`, and `tracing`. It is better to add log to the standard library, like [`log/slog`](https://pkg.go.dev/log/slog@go1.21.0#Debug) in golang.
jmjoy commented 2023-08-17 02:34:55 -05:00 (Migrated from github.com)

For structured logging, format strings seem less important, for example:

error!("something failed: {:?}", err);

The following one is better (syntax of tracing):

error!(?err, "something failed");

Forgoing format strings makes macros a lot more pleasant to design.

For structured logging, format strings seem less important, for example: ```rust error!("something failed: {:?}", err); ``` The following one is better (syntax of tracing): ```rust error!(?err, "something failed"); ``` Forgoing format strings makes macros a lot more pleasant to design.
KodrAus commented 2023-08-19 05:10:58 -05:00 (Migrated from github.com)

Any plan to make this stable ? More than 4 years since issue opening.

It would be great to have a fresh look at anything blocking this and I can't really think of any left 👍 The macros are a bit rough-and-ready, but I think suitable for most use cases. We really should get this out the door.

Before stabilizing, I think the next step would be running through a full API review with @Thomasdezeeuw, @JohnTitor and anybody else who might want to participate.

For structured logging, format strings seem less important

Yeh, I think the issue here is format args producing a string and throwing away its interpolated arguments. It's nice and intuitive to be able to both describe your event and some of the structured data attached to it using some kind of interpolation. This practice is popular in .NET for example, but Rust's format_args! is just geared towards string construction.

> Any plan to make this stable ? More than 4 years since issue opening. It would be great to have a fresh look at anything blocking this and I can't really think of any left :+1: The macros are a bit rough-and-ready, but I think suitable for most use cases. We really should get this out the door. Before stabilizing, I think the next step would be running through a full API review with @Thomasdezeeuw, @JohnTitor and anybody else who might want to participate. > For structured logging, format strings seem less important Yeh, I think the issue here is format args producing a string and throwing away its interpolated arguments. It's nice and intuitive to be able to both describe your event and some of the structured data attached to it using some kind of interpolation. This practice is popular in .NET for example, but Rust's `format_args!` is just geared towards string construction.
👍 1
Thomasdezeeuw commented 2023-08-19 06:07:41 -05:00 (Migrated from github.com)

Any plan to make this stable ? More than 4 years since issue opening.

It would be great to have a fresh look at anything blocking this and I can't really think of any left 👍 The macros are a bit rough-and-ready, but I think suitable for most use cases. We really should get this out the door.

I can only think of two things that we should think about of the top of my head, but neither should block stabilisation:

Before stabilizing, I think the next step would be running through a full API review with @Thomasdezeeuw, @JohnTitor and anybody else who might want to participate.

I can do that next weekend 👍

For structured logging, format strings seem less important

Yeh, I think the issue here is format args producing a string and throwing away its interpolated arguments. It's nice and intuitive to be able to both describe your event and some of the structured data attached to it using some kind of interpolation. This practice is popular in .NET for example, but Rust's format_args! is just geared towards string construction.

Since we're really dependant on rust std lib on this you could ask in https://github.com/rust-lang/rust/issues/99012 for this. Though it might conflict with https://github.com/rust-lang/rust/issues/78356 which was stabilised in 1.71.

> > Any plan to make this stable ? More than 4 years since issue opening. > > It would be great to have a fresh look at anything blocking this and I can't really think of any left 👍 The macros are a bit rough-and-ready, but I think suitable for most use cases. We really should get this out the door. I can only think of two things that we should think about of the top of my head, but neither should block stabilisation: * Decide if we want to support tracing like short-hand for `as_debug!` (so `?my_value`) and related. * Integration of serde and sval into the `Visit` trait. Here is for example a concrete `Visit` implementation that outputs JSON: https://github.com/Thomasdezeeuw/std-logger/blob/eff67f4c33b89c8debd325c1ad79724e6cd6af2c/src/format/json.rs#L167, but it doesn't handle serde or sval based values. > Before stabilizing, I think the next step would be running through a full API review with @Thomasdezeeuw, @JohnTitor and anybody else who might want to participate. I can do that next weekend 👍 > > For structured logging, format strings seem less important > > Yeh, I think the issue here is format args producing a string and throwing away its interpolated arguments. It's nice and intuitive to be able to both describe your event and some of the structured data attached to it using some kind of interpolation. This practice is popular in .NET for example, but Rust's `format_args!` is just geared towards string construction. Since we're really dependant on rust std lib on this you could ask in https://github.com/rust-lang/rust/issues/99012 for this. Though it might conflict with https://github.com/rust-lang/rust/issues/78356 which was stabilised in 1.71.
👍 2
KodrAus commented 2023-08-28 05:28:30 -05:00 (Migrated from github.com)

Decide if we want to support tracing like short-hand for as_debug! (so ?my_value) and related.

I think this is something that would be reasonable to do 👍 tracing has already set a bit of a precedent that would be good to respect.

Integration of serde and sval into the Visit trait.

Ah, I think this highlights one thing we definitely need to work on; documentation. You should be able to support serde or sval in your visit_any implementation. The Value type always implements serde::Serialize or sval::Value when the kv_unstable_serde or kv_unstable_sval features are enabled. So if you add, say, a serde feature to std-logger you should be able to just pass the Value you're given directly to serde_json::to_string and it'll "just work".

Since we're really dependant on rust std lib on this you could ask in https://github.com/rust-lang/rust/issues/99012 for this

Personally, I think it's ok for format_args to optimize for string construction. That lets it consider optimizations like pre-formatting constants that it otherwise couldn't do.

I can do that next weekend 👍

If you have the bandwidth to run over things sometime that would be amazing! I'd be happy to do something a bit more synchronous too or at least do a pass over our docs if that would be helpful?

> Decide if we want to support tracing like short-hand for as_debug! (so ?my_value) and related. I think this is something that would be reasonable to do :+1: `tracing` has already set a bit of a precedent that would be good to respect. > Integration of serde and sval into the Visit trait. Ah, I think this highlights one thing we _definitely_ need to work on; documentation. You should be able to support `serde` or `sval` in your [`visit_any`](https://github.com/Thomasdezeeuw/std-logger/blob/eff67f4c33b89c8debd325c1ad79724e6cd6af2c/src/format/json.rs#L168C73-L174) implementation. The `Value` type always implements `serde::Serialize` or `sval::Value` when the `kv_unstable_serde` or `kv_unstable_sval` features are enabled. So if you add, say, a `serde` feature to `std-logger` you should be able to just pass the `Value` you're given directly to `serde_json::to_string` and it'll "just work". > Since we're really dependant on rust std lib on this you could ask in https://github.com/rust-lang/rust/issues/99012 for this Personally, I think it's ok for `format_args` to optimize for string construction. That lets it consider optimizations like pre-formatting constants that it otherwise couldn't do. > I can do that next weekend 👍 If you have the bandwidth to run over things sometime that would be amazing! I'd be happy to do something a bit more synchronous too or at least do a pass over our docs if that would be helpful?
Thomasdezeeuw commented 2023-08-29 03:48:35 -05:00 (Migrated from github.com)

I've done a review of the key-value feature in the log crate and opened https://github.com/rust-lang/log/pull/584 to discuss some things. Overall I think it looks pretty good and I think we're close to stabilisation. I still want to review the valuebag crate (added dependency), I think I'm going to skip serde and sval as they are much larger and more widely used already.

I've also opened https://github.com/rust-lang/log/pull/583 containing some small fixes and additions.

I've done a review of the key-value feature in the log crate and opened https://github.com/rust-lang/log/pull/584 to discuss some things. Overall I think it looks pretty good and I think we're close to stabilisation. I still want to review the valuebag crate (added dependency), I think I'm going to skip serde and sval as they are much larger and more widely used already. I've also opened https://github.com/rust-lang/log/pull/583 containing some small fixes and additions.
❤️ 3
KodrAus commented 2023-08-29 03:58:43 -05:00 (Migrated from github.com)

Thanks @Thomasdezeeuw!

A good review of value-bag would be much appreciated too. It originally started as the infrastructure here in log, but became a bit heavy so I pulled it out. Its public API is very similar to log::kv::Value. For the review of log::kv itself, maybe we can use #584 so discussion isn't split here?

Thanks @Thomasdezeeuw! A good review of `value-bag` would be much appreciated too. It originally started as the infrastructure here in `log`, but became a bit heavy so I pulled it out. Its public API is very similar to `log::kv::Value`. For the review of `log::kv` itself, maybe we can use #584 so discussion isn't split here?
👍 1
Thomasdezeeuw commented 2023-09-04 03:40:44 -05:00 (Migrated from github.com)

@KodrAus I took a look at value-bag (from the perspective of using it in the log crate). Overall I think it looks good 👍

For the capture_* and from_* methods I have the same comment as I made here: https://github.com/rust-lang/log/pull/584#discussion_r1308453837 (so let's continue the discussion about this there).

We could get the size down from 3 to 2 words (on 64 bit) by using tagged pointers, but I don't know if that is worth all the unsafe code.

One final note is around the Fill trait, which isn't used by the log crate, but it was a little surprising to me that the Fill::fill method seems to be called multiple times on every access (?). That wasn't clear to me by (quickly) scanning the Fill docs. Maybe a note in the docs would be sufficient.

@KodrAus I took a look at value-bag (from the perspective of using it in the log crate). Overall I think it looks good :+1: For the `capture_*` and `from_*` methods I have the same comment as I made here: https://github.com/rust-lang/log/pull/584#discussion_r1308453837 (so let's continue the discussion about this there). We *could* get the size down from 3 to 2 words (on 64 bit) by using tagged pointers, but I don't know if that is worth all the `unsafe` code. One final note is around the `Fill` trait, which isn't used by the log crate, but it was a little surprising to me that the `Fill::fill` method seems to be called multiple times on every access (?). That wasn't clear to me by (quickly) scanning the `Fill` docs. Maybe a note in the docs would be sufficient.
👍 1
scripturial commented 2023-09-15 09:58:31 -05:00 (Migrated from github.com)

We could get the size down from 3 to 2 words (on 64 bit) by using tagged pointers, but I don't know if that is worth all the unsafe code.

Thanks for this work. Looking forward to it being released proper.

Some systems generate a significant amount of log data in debug mode, so it might be worth the effort, but personally I wouldn't want a change at this point to hold up release of this feature. It seems more important that structured logging become a stable feature sooner rather than later.

> We could get the size down from 3 to 2 words (on 64 bit) by using tagged pointers, but I don't know if that is worth all the unsafe code. Thanks for this work. Looking forward to it being released proper. Some systems generate a significant amount of log data in debug mode, so it might be worth the effort, but personally I wouldn't want a change at this point to hold up release of this feature. It seems more important that structured logging become a stable feature sooner rather than later.
zopsicle commented 2024-01-09 06:45:03 -06:00 (Migrated from github.com)

log is used by over 50000 crates, which means you'll inevitably pull it in as a transitive dependency. I'm therefore concerned about value-bag being added as a dependency here. Will this remain an optional, non-default feature?

log is used by over 50000 crates, which means you'll inevitably pull it in as a transitive dependency. I'm therefore concerned about value-bag being added as a dependency here. Will this remain an optional, non-default feature?
Thomasdezeeuw commented 2024-01-09 06:59:19 -06:00 (Migrated from github.com)

log is used by over 50000 crates, which means you'll inevitably pull it in as a transitive dependency. I'm therefore concerned about value-bag being added as a dependency here. Will this remain an optional, non-default feature?

I'm afraid not, it's the core of the Value type (about 50% of this feature ;) )

Maybe we can move it to the rust-lang org? /cc @KodrAus

> log is used by over 50000 crates, which means you'll inevitably pull it in as a transitive dependency. I'm therefore concerned about value-bag being added as a dependency here. Will this remain an optional, non-default feature? I'm afraid not, it's the core of the `Value` type (about 50% of this feature ;) ) Maybe we can move it to the rust-lang org? /cc @KodrAus
KodrAus commented 2024-01-31 00:50:53 -06:00 (Migrated from github.com)

@chloekek I think that's a reasonable concern. In fact, in #613 I've made that dependency fully optional for structured logging, so if you just want to log simple primitives, like numbers, strings, booleans, or formattable values, you won't pull it in.

For some background on what that value-bag library is (as well as a serialization framework called sval), they all started out as the implementation directly here in log, but grew in complexity to a point where it seemed best to split them out. I didn't originally try move them to a repository in the rust-lang organization I think because I didn't want it to carry any sense of being an "official" solution to dynamic values. So I created an organization: https://github.com/sval-rs and it's been living and continuing to evolve there.

I would happily move that repository anywhere or add any collaborators of log to that organization 🙂

@chloekek I think that's a reasonable concern. In fact, in #613 I've made that dependency fully optional for structured logging, so if you _just_ want to log simple primitives, like numbers, strings, booleans, or formattable values, you won't pull it in. For some background on what that `value-bag` library is (as well as a serialization framework called `sval`), they all started out as the implementation directly here in `log`, but grew in complexity to a point where it seemed best to split them out. I didn't originally try move them to a repository in the `rust-lang` organization I think because I didn't want it to carry any sense of being an "official" solution to dynamic values. So I created an organization: https://github.com/sval-rs and it's been living and continuing to evolve there. I would happily move that repository anywhere or add any collaborators of `log` to that organization 🙂
👍 1
Sign in to join this conversation.
No Branch/Tag specified
Branches Tags
master
archive/20261005T153738Z-deleted/ci/msrv-build-vs-test
archive/20260925T210104Z-rescue/djugei/dyn_downcast
fix/lifetime-rules
0.3.x
0.4.34
0.4.33
0.4.32
0.4.31
0.4.30
0.4.29
0.4.28
0.4.27
0.4.26
0.4.25
0.4.24
0.4.23
0.4.22
0.4.21
0.4.20
0.4.19
0.4.18
0.4.17
0.4.15
0.4.14
0.4.13
0.4.12
0.4.11
0.4.10
0.4.9
0.4.8
0.4.7
0.4.6
0.4.5
0.4.4
0.4.3
0.4.2
0.4.1
0.3.9
0.4.0
0.4.0-rc.1
env_logger-0.4.3
0.3.8
0.3.7
env_logger-0.4.2
env_logger-0.4.1
env_logger-0.4.0
env_logger-0.3.5
env_logger-0.3.4
env_logger-0.3.3
0.3.6
Labels
Clear labels   
bug

   
duplicate

   
easy

   
enhancement

   
help wanted

   
invalid

   
question

   
rfc

   
structured-logging

   
wontfix
No labels
bug
duplicate
easy
enhancement
help wanted
invalid
question
rfc
structured-logging
wontfix
Milestone
Clear milestone
No items
No milestone
Assignees
Clear assignees
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
gh-rust-lang/log#328
No description provided.