Logging std::error::Errors #357

Closed
opened 2019-09-08 15:03:11 -05:00 by theduke · 15 comments
theduke commented 2019-09-08 15:03:11 -05:00 (Migrated from github.com)

It would be really nice to have a specialized way of logging errors that implement std::error::Error.

This would allow automatically capturing detailed information about an error, including the Display and Debug representations, and especially backtraces via the new Error::backtrace, which has an open PR.

The main purpose is to give the backend implementation the option to extract all desired information about an error and use it as appropriate for the output.

Not sure how this could fit into the current design, but I'd imagine an additional method on Log and a macro.

trait Log {
  ...
  // The record serves the purpose of providing the location, and optionally an additional error message / metadata.
  // Question: Should the record be optional or required?
  fn error(&self, error: &dyn std::error::Error,  record: Option<&Record>);
}

Plus a macro.

Naming for that macro would of course be somewhat awkward, considering error! exists. Maybe with_error!(). Also there could be a variant of error! that allows specifying an error value.

One could of course ask if this is really necessary, since you could already write a custom macro or method that captures the required information as a Record. But I'd like to see a standardized way of doing this that gives the logger implementation the power to do what it wants, without forcing the user to make a decision here up-front.

It would be really nice to have a specialized way of logging errors that implement `std::error::Error`. This would allow automatically capturing detailed information about an error, including the `Display` and `Debug` representations, and especially backtraces via the new `Error::backtrace`, which has an open PR. The main purpose is to give the backend implementation the option to extract all desired information about an error and use it as appropriate for the output. Not sure how this could fit into the current design, but I'd imagine an additional method on `Log` and a macro. ```rust trait Log { ... // The record serves the purpose of providing the location, and optionally an additional error message / metadata. // Question: Should the record be optional or required? fn error(&self, error: &dyn std::error::Error, record: Option<&Record>); } ``` Plus a macro. Naming for that macro would of course be somewhat awkward, considering `error!` exists. Maybe `with_error!()`. Also there could be a variant of `error!` that allows specifying an error value. One could of course ask if this is really necessary, since you could already write a custom macro or method that captures the required information as a `Record`. But I'd like to see a standardized way of doing this that gives the logger implementation the power to do what it wants, without forcing the user to make a decision here up-front.
KodrAus commented 2019-09-08 17:23:32 -05:00 (Migrated from github.com)

Personally, I think treating errors as first-class concepts in logs is a worthwhile thing to do. It looks like we might not have given this too much thought in the past, but now that the std::error::Error type is more useful and backtrace support is in the works it could be a good time to consider it.

We could add something like a fn source(&self) -> Option<&(dyn Error + 'static)> method to Record along with macro support similar to how target was added:

error!(source: err, "Something didn't work {}", err);

Alternatively we could design support into the key-values API and leave it up to convention to capture an error with a common key name. That would probably be my preferred approach, because it would avoid creating too many parallel syntaxes in the log! macros.

Personally, I think treating errors as first-class concepts in logs is a worthwhile thing to do. It looks like we might not have given this too much thought in the past, but now that the `std::error::Error` type is more useful and backtrace support is in the works it could be a good time to consider it. We could add something like a `fn source(&self) -> Option<&(dyn Error + 'static)>` method to `Record` along with macro support similar to how `target` was added: ```rust error!(source: err, "Something didn't work {}", err); ``` Alternatively we could design support into the key-values API and leave it up to convention to capture an error with a common key name. That would probably be my preferred approach, because it would avoid creating too many parallel syntaxes in the `log!` macros.
theduke commented 2019-09-08 17:59:47 -05:00 (Migrated from github.com)

I like the source: err syntax. Together with adding Record::source() this would also enable attaching an error to all the macros, and prevent clutter.

The ability to log an error without providing an additional message would also be nice though.

I like the `source: err` syntax. Together with adding `Record::source()` this would also enable attaching an error to all the macros, and prevent clutter. The ability to log an error without providing an additional message would also be nice though.
sfackler commented 2019-09-08 18:45:09 -05:00 (Migrated from github.com)

Yep, I definitely agree that it makes sense to allow Errors to be tacked onto log records - it will be a field that's only available with the std feature, but that should be fine.

Yep, I definitely agree that it makes sense to allow Errors to be tacked onto log records - it will be a field that's only available with the `std` feature, but that should be fine.
theduke commented 2019-09-09 04:09:37 -05:00 (Migrated from github.com)

I thought a missing Send bound on the Error could be a problem for async loggers that ship the record to a different thread. But then I noticed that Record already is not Send.

How is that dealt with in, eg, slog? (cc @dpc)

I thought a missing `Send` bound on the `Error` could be a problem for async loggers that ship the record to a different thread. But then I noticed that `Record` already is not `Send`. How is that dealt with in, eg, `slog`? (cc @dpc)
dpc commented 2019-09-09 14:07:19 -05:00 (Migrated from github.com)

I've explicitly mentioned that Send and Sync is something to consider for the future, but I don't think anyone followed up on that. In slog there are these explicitly built contexts that are Arced so they can be sent cheaply. The idea is that they are more permanent, so they take an upfront cost during creation to be cheaper during normal operations. The immediate key-values and stuff in Records are borrowed, but slog requires them to be Send and just clones/copies/kind-of-serializes them. The idea here is that they are more ad-hoc and should be generally smaller, so cost of the clone is OK.

I think it is worthwhile to investigate and built an async logger for log to iron out the async story. If Record had an explicit field for errors, then it could require them to be sync and avoid copying. Similiarily if log had more general way to group borrowed ad-hoc vs owned and Arced more persistent data, then some optimizations around these would be possible.

For reference: github.com/slog-rs/async@e33823ceb8/lib.rs (L448)

I've explicitly mentioned that Send and Sync is something to consider for the future, but I don't think anyone followed up on that. In `slog` there are these explicitly built contexts that are Arced so they can be sent cheaply. The idea is that they are more permanent, so they take an upfront cost during creation to be cheaper during normal operations. The immediate key-values and stuff in `Record`s are borrowed, but `slog` ~~requires them to be Send and~~ just clones/copies/kind-of-serializes them. The idea here is that they are more ad-hoc and should be generally smaller, so cost of the clone is OK. I think it is worthwhile to investigate and built an async logger for `log` to iron out the async story. If `Record` had an explicit field for errors, then it could require them to be sync and avoid copying. Similiarily if `log` had more general way to group borrowed ad-hoc vs owned and Arced more persistent data, then some optimizations around these would be possible. For reference: https://github.com/slog-rs/async/blob/e33823ceb8e7af9e0874262e1e57845bd5f30249/lib.rs#L448
yoshuawuyts commented 2019-09-12 05:13:41 -05:00 (Migrated from github.com)

Alternatively we could design support into the key-values API and leave it up to convention to capture an error with a common key name.

This seems reasonable approach that could be done without additional support from the log crate (pending #353). I've been exploring some other conventions in log-types, and this seems like it would work as part of that.

> Alternatively we could design support into the key-values API and leave it up to convention to capture an error with a common key name. This seems reasonable approach that could be done without additional support from the `log` crate (pending #353). I've been exploring some other conventions in [`log-types`](https://docs.rs/log-types/1.0.1/log_types/), and this seems like it would work as part of that.
KodrAus commented 2020-01-30 20:49:26 -06:00 (Migrated from github.com)

We're on board with adding specific support for std::error::Error to log. There's a PR open at #378 with some initial support that allows you to attach an error to a Record.

For Send, since log already makes no direct concessions to allowing Records to be passed across thread boundaries it isn't going to be required here. You can, however, downcast a std::error::Error, so if your application needed to capture a sendable structured representation of the record then you could downcast it to the kind of error you expect to see at that point.

There is some space to explore about macro support though. I think all log levels should support accepting an error, because not every error you encounter is necessarily an error-worthy log. You might want to log them as warnings or debug if they're non-critical. We could follow the same approach as target, by allowing another kind of optional special field before the format arguments:

if let Err(e) = fallible() {
    debug!(error: e, "it didn't work, but that's ok");
    debug!(target: "something", error: e, "it didn't work, but that's ok");

    error!(error: e, "it didn't work");
    error!(target: "something", error: e, "it didn't work");

    // Could use `err` instead of `error`
    error!(err: e, "it didn't work");

    // Would we also want this to work?
    error!(err: e);
}
We're on board with adding specific support for `std::error::Error` to `log`. There's a PR open at #378 with some initial support that allows you to attach an error to a `Record`. For `Send`, since `log` already makes no direct concessions to allowing `Record`s to be passed across thread boundaries it isn't going to be required here. You can, however, downcast a `std::error::Error`, so if your application needed to capture a sendable structured representation of the record then you could downcast it to the kind of error you expect to see at that point. There is some space to explore about macro support though. I think all log levels should support accepting an error, because not every error you encounter is necessarily an error-worthy log. You might want to log them as warnings or debug if they're non-critical. We could follow the same approach as `target`, by allowing another kind of optional special field before the format arguments: ```rust if let Err(e) = fallible() { debug!(error: e, "it didn't work, but that's ok"); debug!(target: "something", error: e, "it didn't work, but that's ok"); error!(error: e, "it didn't work"); error!(target: "something", error: e, "it didn't work"); // Could use `err` instead of `error` error!(err: e, "it didn't work"); // Would we also want this to work? error!(err: e); } ```
rimutaka commented 2020-07-20 18:08:57 -05:00 (Migrated from github.com)

We are looking at adding error logging inside AWS Lambda Runtime for Rust (https://github.com/awslabs/aws-lambda-rust-runtime/issues/241). The plan was to use Display trait, but that means the user would have to implement it, potentially more than once. Having a standard way of logging std::error::Error would make it easier for our users.

Looks like the work on this issue stalled.
Is there something I can help with to get it released?

We are looking at adding error logging inside AWS Lambda Runtime for Rust (https://github.com/awslabs/aws-lambda-rust-runtime/issues/241). The plan was to use _Display_ trait, but that means the user would have to implement it, potentially more than once. Having a standard way of logging `std::error::Error` would make it easier for our users. Looks like the work on this issue stalled. Is there something I can help with to get it released?
softprops commented 2020-07-20 18:18:52 -05:00 (Migrated from github.com)

Could some of this now be handled with log's builtin structured logging interfaces?

Could some of this now be handled with log's builtin structured logging interfaces?
KodrAus commented 2020-07-22 22:19:50 -05:00 (Migrated from github.com)

Hey @rimutaka 👋

The blocker for log’s stable API is macro support. To fit in with the existing syntax it would probably look something like:

error!(source: e, “Oh no!”);

we could cobble that in with some liberal duplication to the macros, but would be better off converting log! to a tt muncher that could handle any combination of target, source and level. In the past we’ve found changing the macros to be tricky, but the scope of this should be reasonably small.

There’s nothing blocking support in the unstable structured API, like @softprops mentioned. We could add Value::from_error and Value::as_error methods at any time.

Hey @rimutaka 👋 The blocker for `log`’s stable API is macro support. To fit in with the existing syntax it would probably look something like: ```rust error!(source: e, “Oh no!”); ``` we could cobble that in with some liberal duplication to the macros, but would be better off converting `log!` to a tt muncher that could handle any combination of `target`, `source` and `level`. In the past we’ve found changing the macros to be tricky, but the scope of this should be reasonably small. There’s nothing blocking support in the unstable structured API, like @softprops mentioned. We could add `Value::from_error` and `Value::as_error` methods at any time.
softprops commented 2020-07-22 22:26:29 -05:00 (Migrated from github.com)

The latter seems to keep the surface area small.

error!("whoops", { error: e }) you get the reuse the same syntax for the same semantic purpose, annotating a log message with additional information. You get to pick the name for that information, log serializes it

The latter seems to keep the surface area small. `error!("whoops", { error: e })` you get the reuse the same syntax for the same semantic purpose, annotating a log message with additional information. You get to pick the name for that information, `log` serializes it
KodrAus commented 2020-07-23 17:07:35 -05:00 (Migrated from github.com)

@softprops That would be much nicer, but we've had trouble in the past attempting to wrangle new syntax into the macros, especially after the message string, because currently that whole lot is shelled straight off to format_args as a bag of tokens. Things break in strange ways.

Until we can come up with entirely new macros (I've been prototyping some stuff in this repo) I think we'll have to attach the error at the front, before the message.

@softprops That would be much nicer, but we've had trouble in the past attempting to wrangle new syntax into the macros, especially after the message string, because currently that whole lot is shelled straight off to `format_args` as a bag of tokens. Things break in strange ways. Until we can come up with entirely new macros (I've been prototyping some stuff in [this repo](https://github.com/KodrAus/antlog)) I think we'll have to attach the error at the front, before the message.
Kixunil commented 2021-01-12 13:04:39 -06:00 (Migrated from github.com)

Heads up: I've recently contributed std::error::Error implementation into slog unaware of this issue here. I hope log can be interoperable with that and I didn't cause some catastrophic incompatibility.

Heads up: I've recently [contributed `std::error::Error` implementation](https://github.com/slog-rs/slog/pull/274) into `slog` unaware of this issue here. I hope `log` can be interoperable with that and I didn't cause some catastrophic incompatibility.
KodrAus commented 2021-01-12 20:18:53 -06:00 (Migrated from github.com)

@Kixunil No sweat! It looks like the &dyn (std::error::Error + 'static) type you've used in slog should be compatible with both log and tracing, which also use &dyn (Error + 'static).

@Kixunil No sweat! It looks like the `&dyn (std::error::Error + 'static)` type you've used in `slog` should be compatible with both `log` and `tracing`, which also use `&dyn (Error + 'static)`.
Kixunil commented 2021-01-13 02:22:13 -06:00 (Migrated from github.com)

That's great! I don't follow slog/log interop efforts closely, which one will be responsible for connecting them together?

That's great! I don't follow `slog`/`log` interop efforts closely, which one will be responsible for connecting them together?
Sign in to join this conversation.
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#357
No description provided.