Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Add support for instrumented functions which return Result #28

Merged
merged 2 commits into from
Sep 29, 2023

Conversation

valkum
Copy link
Contributor

@valkum valkum commented Jun 22, 2023

Motivation

Currently, the tracing instrumentation macro emits a single event after the function call, but in the current span, with just a field named error set.

For example:

#[instrument(err)]
fn test() -> Result<(), ()> {
...body
}

gets roughly expanded to

fn test() -> Result<(), ()> {
  let span = span!("test")
  fn inner() -> Result<(), ()> {
  ...body
  }
  match inner() {
    Ok(x) => Ok(x),
    Err(err) => {
    error!(error=%err)
    Err(err)
  }
}

In the error case of the result, the macro will emit an error level event with just an error field set to the display (or debug) value of the returned error.

While there exists support for the Error primitive in tracing, the primitive only supports 'static Errors. See tokio-rs/tracing#1308

Solution

This PR adds support to use this event to fill the span status error description with the content of the error field of this event. Additionally, this ass support to emit these events (or manually created ones that follow the same format) as OTel events following the exception convention.
The operation is optional and can be configured using the ErrorFieldConfig.

This seems like another hack similar to otel.* fields, but should reduce some boilerplate in existing codebases.
I propose to keep this until tracing improves support for Error fields.

@valkum valkum requested a review from jtescher as a code owner June 22, 2023 18:19
@valkum valkum force-pushed the improve-instrumented-errors branch from 37ec0bc to 9e15628 Compare June 22, 2023 18:22
@jtescher
Copy link
Collaborator

jtescher commented Aug 1, 2023

hm, little unfortunate to have a third error handling config (on top of the otel.* and exception field config).

Looks like the error macro does at least currently result in the span state being set to error, is this change then mostly renaming the recorded otel event name from error to exception to comply with this exception spec? https://github.com/open-telemetry/opentelemetry-specification/blob/v1.21.0/specification/trace/exceptions.md#attributes

Maybe we could add that option to the exception field config to include that?

@valkum
Copy link
Contributor Author

valkum commented Aug 1, 2023

Yeah, currently the span is set to error but the status.message (or Description) is not set. I think the emitted error tracing event, created by the macro, is the best fit for the status.message.

Additionally, as it also fits the exception convention, it is duplicated into an exception field. Note that you can configure both things independently.

The current exception_config only covers the record_error fn. These are not executed for most of the Errors (anyhow, etc). This new one handles events and has full support for the instrument macro, which emits the error via %e.

We could use the same config option struct, but I would rename the fields to better reflect the outcome. If you are okay with this breaking change.

I would propose:

struct Config {
  /// If a function is instrumented and returns a `Result`, should the error
  /// value be propagated to the span status.
  ///
  /// Without this enabled, the span status will be "Error" with an empty description
  /// when at least one error event is recorded in the span.
  error_events_to_status: bool,
  /// If an event with an empty name and a field named `error` is recorded,
  /// should the event be rewritten to have the name `exception` and the field `exception.message`
  ///
  /// Follows the semantic conventions for exceptions.
  error_events_to_exceptions: bool, 
  /// If an error value is recorded on an event, should the otel fields be
  /// added to the corresponding span.
  ///
  /// Note that this uses tracings `record_error` which is only implemented for `(dyn Error + 'static)`.
  error_records_to_exceptions: bool,
  /// If an error value is recorded on an event/span, should the otel 
  /// semantic convention for execptions be added. 
  ///
  /// Note that this uses tracings `record_error` which is only implemented for `(dyn Error + 'static)`.
  error_fields_to_exceptions: bool,
}

@jtescher
Copy link
Collaborator

jtescher commented Aug 1, 2023

I think the internal config struct update makes sense to consolidate and as it's not public there is no breaking change. I think the larger question is what config to expose via the with_* options on the layer.

Are there use cases for the full 4x4 matrix of options? or could the options be slimmed down to just 1) do error events apply semantic conventions, 2) does record_error apply semantic conventions 3) do event attributes get set on the span as well.

@jtescher
Copy link
Collaborator

jtescher commented Aug 1, 2023

Could help reduce the conceptual overhead of using this library. Basically have semantic conventions added by default with opt-out via config, and if you want to customize specific behavior, use the otel.* escape hatch or span extension trait.

@valkum valkum force-pushed the improve-instrumented-errors branch from 9e15628 to 15e1507 Compare August 21, 2023 14:44
@valkum
Copy link
Contributor Author

valkum commented Aug 21, 2023

I enabled the SemConv mappings by default now, changed the names to better reflect the purpose (with backwards depreciation warning) too.
Changing the defaults is a breaking change, though.

Regarding slimming it down:
We currently already update the status.code when builder.status is unset and the event is Level::ERROR. I think it's reasonable to drop the config for error_events_to_status in favor of adding the status.description every time. I don't see any benefit of only exposing the status.code and no drawback of attaching the error from the instrument macro in every case.

I think error_events_to_exceptions could be merged into error_records_to_exceptions

Copy link
Collaborator

@jtescher jtescher left a comment

Choose a reason for hiding this comment

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

@valkum apologies for the delay, I think this is a reasonable step forward. I think we can merge this once rebased

Renames the config struct in preparation of adding more config fields.
@valkum valkum force-pushed the improve-instrumented-errors branch 2 times, most recently from b57678a to e6330d6 Compare September 29, 2023 16:10
@valkum
Copy link
Contributor Author

valkum commented Sep 29, 2023

Sorry, missed the example check error. cargo clippy --all-targets and cargo +nightly clippy --all-targets pas locally now.
Edit: the tests fail, though. Having a look right now.

Currently, the instrumentation macro emits a single event after the
function call, but in the current span, with just a field named error
set.
This commit adds support to use this event to fill the span status error
description with the content of the error field of this event.
The mapping is optional and can be configured using the
ErrorFieldConfig.
@valkum valkum force-pushed the improve-instrumented-errors branch from e6330d6 to d5bc52c Compare September 29, 2023 16:55
@jtescher
Copy link
Collaborator

Looks great thanks @valkum

@jtescher jtescher merged commit bddef29 into tokio-rs:v0.1.x Sep 29, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants