Allow macros to be more consistent with kvs #476

Merged
KodrAus merged 10 commits from feat/kv-macros into master 2022-01-16 19:25:43 -06:00
KodrAus commented 2021-12-07 06:58:50 -06:00 (Migrated from github.com)

Part of #436

This tweaks the new key-value macro syntax slightly so that it can be more consistent in cases where key-values are supplied and in cases where they're not. All the old syntax is still supported, but we can now write log! macros like:

info!(target = "my_target"; "format {string}");

which then supports key-value pairs as:

info!(target = "my_target"; key1 = value1, key2 = value2; "format {formatted1}", formatted1 = value1);

For key-values, the target = x; form is required. It splits our macro up into 3 logical parts, separated by ;s:

  1. target = "my_target": The portion of the log record that's considered by top-level filtering. It's equivalent to log_enabled!.
  2. key1 = value1, key2 = value2: The structured data associated with the log record.
  3. "format {formatted1}", formatted1 = value1: The unstructured message associated with the log record.

I think for log here we should also remove the capture_* methods on Value for now, because they lead to unpleasant compilation errors when you don't have a &T: 'static around. They're only useful if you want to try downcast to a specific type, like a Uuid or Timestamp.

I'll try flesh out our test coverage even more, since there are a lot of possible permutations of the log macros and their interactions with format_args to consider.

cc @Thomasdezeeuw. What do you think?

Part of #436 This tweaks the new key-value macro syntax slightly so that it can be more consistent in cases where key-values are supplied and in cases where they're not. All the old syntax is still supported, but we can now write `log!` macros like: ```rust info!(target = "my_target"; "format {string}"); ``` which then supports key-value pairs as: ```rust info!(target = "my_target"; key1 = value1, key2 = value2; "format {formatted1}", formatted1 = value1); ``` For key-values, the `target = x;` form is required. It splits our macro up into 3 logical parts, separated by `;`s: 1. `target = "my_target"`: The portion of the log record that's considered by top-level filtering. It's equivalent to `log_enabled!`. 2. `key1 = value1, key2 = value2`: The structured data associated with the log record. 3. `"format {formatted1}", formatted1 = value1`: The unstructured message associated with the log record. I think for `log` here we should also remove the `capture_*` methods on `Value` for now, because they lead to unpleasant compilation errors when you don't have a `&T: 'static` around. They're only useful if you want to try downcast to a specific type, like a `Uuid` or ` Timestamp`. I'll try flesh out our test coverage even more, since there are a lot of possible permutations of the log macros and their interactions with `format_args` to consider. cc @Thomasdezeeuw. What do you think?
Thomasdezeeuw commented 2021-12-07 09:48:41 -06:00 (Migrated from github.com)

Part of #436

This tweaks the new key-value macro syntax slightly so that it can be more consistent in cases where key-values are supplied and in cases where they're not. All the old syntax is still supported, but we can now write log! macros like:

info!(target = "my_target"; "format {string}");

which then supports key-value pairs as:

info!(target = "my_target"; key1 = value1, key2 = value2; "format {formatted1}", formatted1 = value1);

For key-values, the target = x; form is required. It splits our macro up into 3 logical parts, separated by ;s:

1. `target = "my_target"`: The portion of the log record that's considered by top-level filtering. It's equivalent to `log_enabled!`.

2. `key1 = value1, key2 = value2`: The structured data associated with the log record.

3. `"format {formatted1}", formatted1 = value1`: The unstructured message associated with the log record.

Did target: x not work? That is what is currently used.

I think for log here we should also remove the capture_* methods on Value for now, because they lead to unpleasant compilation errors when you don't have a &T: 'static around. They're only useful if you want to try downcast to a specific type, like a Uuid or Timestamp.

And replace them with the from_display! macros?

> Part of #436 > > This tweaks the new key-value macro syntax slightly so that it can be more consistent in cases where key-values are supplied and in cases where they're not. All the old syntax is still supported, but we can now write `log!` macros like: > > ```rust > info!(target = "my_target"; "format {string}"); > ``` > > which then supports key-value pairs as: > > ```rust > info!(target = "my_target"; key1 = value1, key2 = value2; "format {formatted1}", formatted1 = value1); > ``` > > For key-values, the `target = x;` form is required. It splits our macro up into 3 logical parts, separated by `;`s: > > 1. `target = "my_target"`: The portion of the log record that's considered by top-level filtering. It's equivalent to `log_enabled!`. > > 2. `key1 = value1, key2 = value2`: The structured data associated with the log record. > > 3. `"format {formatted1}", formatted1 = value1`: The unstructured message associated with the log record. Did `target: x` not work? That is what is currently used. > I think for `log` here we should also remove the `capture_*` methods on `Value` for now, because they lead to unpleasant compilation errors when you don't have a `&T: 'static` around. They're only useful if you want to try downcast to a specific type, like a `Uuid` or ` Timestamp`. And replace them with the `from_display!` macros?
KodrAus commented 2021-12-07 16:14:43 -06:00 (Migrated from github.com)

Did target: x not work? That is what is currently used.

It does work, but when I started using it I found the inconsistency with key values and named format args a bit jarring. We’ll probably want some err = expr syntax too at some point so thought starting to try normalize everything would be good.

And replace them with the from_display! macros?

Those methods and direct downcasting will just go away, unless it’s something you’re currently using? Speaking of, what do you think of those little macros? The alternative is something like tracing’s flags, which are similar to format_args.

> Did target: x not work? That is what is currently used. It does work, but when I started using it I found the inconsistency with key values and named format args a bit jarring. We’ll probably want some `err = expr` syntax too at some point so thought starting to try normalize everything would be good. > And replace them with the from_display! macros? Those methods and direct downcasting will just go away, unless it’s something you’re currently using? Speaking of, what do you think of those little macros? The alternative is something like `tracing`’s flags, which are similar to `format_args`.
Thomasdezeeuw commented 2021-12-09 07:45:02 -06:00 (Migrated from github.com)

Did target: x not work? That is what is currently used.

It does work, but when I started using it I found the inconsistency with key values and named format args a bit jarring. We’ll probably want some err = expr syntax too at some point so thought starting to try normalize everything would be good.

I'm not sure. One the one hand I can see your argument, on the other target it is different from the key-values as it has its own method to access it (not via Record::key_values, but via Record::target). Being inconsistent with the non-kvs macros could be annoying. For example when you quickly want to add a kv pair to a message you now also have to consider the target. But I don't know how munch of an annoyance that will be.

And replace them with the from_display! macros?

Those methods and direct downcasting will just go away, unless it’s something you’re currently using?

I do use the downcasting but I'll switch to the visitor API introduces in https://github.com/rust-lang/log/pull/467, so a nice deprecation period would be appreciated.

Speaking of, what do you think of those little macros? The alternative is something like tracing’s flags, which are similar to format_args.

I could either way. The way the tracing crate does is a bit unusual on first sight, but I image you get used to it. So it's a question of being more explicit (macros) vs quicker to write (tracing like flags). I'm with either.

> > Did target: x not work? That is what is currently used. > > It does work, but when I started using it I found the inconsistency with key values and named format args a bit jarring. We’ll probably want some `err = expr` syntax too at some point so thought starting to try normalize everything would be good. > I'm not sure. One the one hand I can see your argument, on the other target it is different from the key-values as it has its own method to access it (not via `Record::key_values`, but via `Record::target`). Being inconsistent with the non-kvs macros could be annoying. For example when you quickly want to add a kv pair to a message you now also have to consider the target. But I don't know how munch of an annoyance that will be. > > And replace them with the from_display! macros? > > Those methods and direct downcasting will just go away, unless it’s something you’re currently using? I do use the downcasting but I'll switch to the visitor API introduces in https://github.com/rust-lang/log/pull/467, so a nice deprecation period would be appreciated. > Speaking of, what do you think of those little macros? The alternative is something like `tracing`’s flags, which are similar to `format_args`. I could either way. The way the tracing crate does is a bit unusual on first sight, but I image you get used to it. So it's a question of being more explicit (macros) vs quicker to write (tracing like flags). I'm with either.
KodrAus commented 2021-12-11 19:12:08 -06:00 (Migrated from github.com)

I do use the downcasting but I'll switch to the visitor API

Ah that's right, you've been forced to use a nasty chain of if lets haven't you because that visitor API wasn't available. I'll make sure it doesn't disappear on you in the meantime.

when you quickly want to add a kv pair to a message you now also have to consider the target.

You can still specify key-value pairs without having to specify a target:

info!(cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello {world}", world = "world");

...but that does raise an interesting forwards compatibility hazard. Say you write:

info!(target = "kv_target", cat_1 = "chashu", cat_2 = "nori"; "hello {}", "world");

In this scheme, that target will end up as a key-value pair instead of as the target. Since we then default the target to module_path!() you'll end up with record.target() returning something else. This is solvable with a bit more macro work.

The way the tracing crate does is a bit unusual on first sight, but I image you get used to it.

Yeh, I think once you learn the scheme it's not too bad. My main reason not for trying to pursue it here is that I think formatting flags are a bit of a dead end. They're crafted for the needs of format_args, but once we're outside their use-case we need to pick new arbitrary characters for new things, like capturing with serde, and those new things don't necessarily integrate with any other flags (what would it mean to capture with serde and also pad with spaces?). But if we want to come up with a nice shorthand scheme we could deprecate these as_* macros pretty easily.

I don't want to keep you blocked on this for much longer though, so maybe after we're sure we're not painted into any corners (which I don't think we are this time) we can create a bit of a checklist on #343 of incomplete parts in the macros so they don't need to hold up getting something out?

> I do use the downcasting but I'll switch to the visitor API Ah that's right, you've been forced to use a nasty chain of `if let`s haven't you because that visitor API wasn't available. I'll make sure it doesn't disappear on you in the meantime. > when you quickly want to add a kv pair to a message you now also have to consider the target. You can still specify key-value pairs without having to specify a target: ```rust info!(cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello {world}", world = "world"); ``` ...but that does raise an interesting forwards compatibility hazard. Say you write: ```rust info!(target = "kv_target", cat_1 = "chashu", cat_2 = "nori"; "hello {}", "world"); ``` In this scheme, that `target` will end up as a key-value pair instead of as the `target`. Since we then default the target to `module_path!()` you'll end up with `record.target()` returning something else. This is solvable with a bit more macro work. > The way the tracing crate does is a bit unusual on first sight, but I image you get used to it. Yeh, I think once you learn the scheme it's not too bad. My main reason not for trying to pursue it here is that I think formatting flags are a bit of a dead end. They're crafted for the needs of `format_args`, but once we're outside their use-case we need to pick new arbitrary characters for new things, like capturing with `serde`, and those new things don't necessarily integrate with any other flags (what would it mean to capture with `serde` and also pad with spaces?). But if we want to come up with a nice shorthand scheme we could deprecate these `as_*` macros pretty easily. I don't want to keep you blocked on this for much longer though, so maybe after we're sure we're not painted into any corners (which I don't think we are this time) we can create a bit of a checklist on #343 of incomplete parts in the macros so they don't need to hold up getting something out?
Thomasdezeeuw commented 2021-12-12 10:47:32 -06:00 (Migrated from github.com)

when you quickly want to add a kv pair to a message you now also have to consider the target.

You can still specify key-value pairs without having to specify a target:

info!(cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello {world}", world = "world");

I meant going from a log with a target to a log with a target and key-values, for example:

// Original:
info!(target: "yak_events", "Commencing yak shaving for {:?}", yak);

// New
info!(target: "yak_events", key = value; "Commencing yak shaving for {:?}", yak); // This won't work.
info!(target = "yak_events", key = value; "Commencing yak shaving for {:?}", yak); // This will.

Or am I mistaken here?

...but that does raise an interesting forwards compatibility hazard. Say you write:

info!(target = "kv_target", cat_1 = "chashu", cat_2 = "nori"; "hello {}", "world");

In this scheme, that target will end up as a key-value pair instead of as the target. Since we then default the target to module_path!() you'll end up with record.target() returning something else. This is solvable with a bit more macro work.

I was saying it could be confusing. With your example above it's not clear that target is "special" (in the sense it can be retrieved using Record.target instead of being another key-value pair). Keeping the ":" syntax might make it clearer?

And it allows people to use target as a key in a key-value pair.

The way the tracing crate does is a bit unusual on first sight, but I image you get used to it.

Yeh, I think once you learn the scheme it's not too bad. My main reason not for trying to pursue it here is that I think formatting flags are a bit of a dead end. They're crafted for the needs of format_args, but once we're outside their use-case we need to pick new arbitrary characters for new things, like capturing with serde, and those new things don't necessarily integrate with any other flags (what would it mean to capture with serde and also pad with spaces?). But if we want to come up with a nice shorthand scheme we could deprecate these as_* macros pretty easily.

👍

I don't want to keep you blocked on this for much longer though, so maybe after we're sure we're not painted into any corners (which I don't think we are this time) we can create a bit of a checklist on #343 of incomplete parts in the macros so they don't need to hold up getting something out?

I think the only decision we need to make is for taget ":" vs "=". We can use macros for formatting and add special tracing-like flags later without breaking compatibility right?

> > when you quickly want to add a kv pair to a message you now also have to consider the target. > > You can still specify key-value pairs without having to specify a target: > > ```rust > info!(cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello {world}", world = "world"); > ``` I meant going from a log with a target to a log with a target and key-values, for example: ```rust // Original: info!(target: "yak_events", "Commencing yak shaving for {:?}", yak); // New info!(target: "yak_events", key = value; "Commencing yak shaving for {:?}", yak); // This won't work. info!(target = "yak_events", key = value; "Commencing yak shaving for {:?}", yak); // This will. ``` Or am I mistaken here? > ...but that does raise an interesting forwards compatibility hazard. Say you write: > > ```rust > info!(target = "kv_target", cat_1 = "chashu", cat_2 = "nori"; "hello {}", "world"); > ``` > > In this scheme, that `target` will end up as a key-value pair instead of as the `target`. Since we then default the target to `module_path!()` you'll end up with `record.target()` returning something else. This is solvable with a bit more macro work. I was saying it could be confusing. With your example above it's not clear that target is "special" (in the sense it can be retrieved using `Record.target` instead of being another key-value pair). Keeping the ":" syntax might make it clearer? And it allows people to use `target` as a key in a key-value pair. > > The way the tracing crate does is a bit unusual on first sight, but I image you get used to it. > > Yeh, I think once you learn the scheme it's not too bad. My main reason not for trying to pursue it here is that I think formatting flags are a bit of a dead end. They're crafted for the needs of `format_args`, but once we're outside their use-case we need to pick new arbitrary characters for new things, like capturing with `serde`, and those new things don't necessarily integrate with any other flags (what would it mean to capture with `serde` and also pad with spaces?). But if we want to come up with a nice shorthand scheme we could deprecate these `as_*` macros pretty easily. 👍 > I don't want to keep you blocked on this for much longer though, so maybe after we're sure we're not painted into any corners (which I don't think we are this time) we can create a bit of a checklist on #343 of incomplete parts in the macros so they don't need to hold up getting something out? I think the only decision we need to make is for taget ":" vs "=". We can use macros for formatting and add special tracing-like flags later without breaking compatibility right?
KodrAus commented 2021-12-16 23:43:12 -06:00 (Migrated from github.com)

Sounds good 👍

I’m not too strongly tied to my = preference, possibly because I just don’t ever set target myself when logging. We could accept both forms still if we wanted to. I was thinking of working towards unifying key values with other pieces of metadata we associate with a log record so there isn’t a distinction in the end between target and anything else.

I would be ok with keeping target using : and deprecate it by making a key-value pair called target just work in the future.

Sounds good 👍 I’m not too strongly tied to my `=` preference, possibly because I just don’t ever set `target` myself when logging. We could accept both forms still if we wanted to. I was thinking of working towards unifying key values with other pieces of metadata we associate with a log record so there isn’t a distinction in the end between target and anything else. I would be ok with keeping target using `:` and deprecate it by making a key-value pair called `target` just work in the future.
Thomasdezeeuw commented 2021-12-17 07:49:13 -06:00 (Migrated from github.com)

Sounds good 👍

I’m not too strongly tied to my = preference, possibly because I just don’t ever set target myself when logging. We could accept both forms still if we wanted to. I was thinking of working towards unifying key values with other pieces of metadata we associate with a log record so there isn’t a distinction in the end between target and anything else.

I would be ok with keeping target using : and deprecate it by making a key-value pair called target just work in the future.

Sounds good. I think for backwards compatibility we want to keep : for now.

> Sounds good 👍 > > I’m not too strongly tied to my `=` preference, possibly because I just don’t ever set `target` myself when logging. We could accept both forms still if we wanted to. I was thinking of working towards unifying key values with other pieces of metadata we associate with a log record so there isn’t a distinction in the end between target and anything else. > > I would be ok with keeping target using `:` and deprecate it by making a key-value pair called `target` just work in the future. Sounds good. I think for backwards compatibility we want to keep `:` for now.
Thomasdezeeuw (Migrated from github.com) approved these changes 2021-12-17 07:52:24 -06:00
KodrAus commented 2021-12-22 23:12:29 -06:00 (Migrated from github.com)

Ok, I've reverted the need to make use the target = form in kv-enabled macros to avoid churning things. We can now technically write this though:

info!(target = "my_target", cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello {}", "world");

In this case we'll interpret target as a key-value pair. This is how I think we'll be able to get away from target: in the future, by making the macro effectively:

$lvl:expr, $($key:ident = $value:expr),+; $($arg:tt)+

where we can use a tt-muncher to unpack the key-value pairs and pick off a target, error etc if we find them, but don't have any special syntax for declaring them apart from any other piece of data you might want to associate with your record.

Once this is green I'll merge it in and give it a smoke test in any candidate libraries to make sure it doesn't regress things and then get it out the door.

Ok, I've reverted the need to make use the `target =` form in kv-enabled macros to avoid churning things. We can now technically write this though: ```rust info!(target = "my_target", cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello {}", "world"); ``` In this case we'll interpret `target` as a key-value pair. This is how I think we'll be able to get away from `target:` in the future, by making the macro effectively: ```rust $lvl:expr, $($key:ident = $value:expr),+; $($arg:tt)+ ``` where we can use a tt-muncher to unpack the key-value pairs and pick off a `target`, `error` etc if we find them, but don't have any special syntax for declaring them apart from any other piece of data you might want to associate with your record. Once this is green I'll merge it in and give it a smoke test in any candidate libraries to make sure it doesn't regress things and then get it out the door.
Thomasdezeeuw (Migrated from github.com) approved these changes 2021-12-23 07:04:36 -06:00
Thomasdezeeuw (Migrated from github.com) commented 2021-12-23 07:03:44 -06:00

Nit: is using target here maybe confusing for new users?

Nit: is using target here maybe confusing for new users?
Thomasdezeeuw (Migrated from github.com) commented 2021-12-23 07:04:31 -06:00

This needs to be reverted to : to fix the CI.

This needs to be reverted to `:` to fix the CI.
Sign in to join this conversation.
No reviewers
No milestone
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!476
No description provided.