Errors are silently discarded if tracing event gets converted to a message and in breadcrumbs

[thomaseizinger]

Environment

• Version 0.34.0

Steps to Reproduce

1. Create an event-filter that maps WARN logs to Sentry events: https://github.com/firezone/firezone/blob/51d92265f4163967c0045f67495954515da15c62/rust/logging/src/lib.rs#L102-L115
2. Attach errors as &dyn std::error::Error in a WARN log as advised in the documentation: https://github.com/firezone/firezone/blob/51d92265f4163967c0045f67495954515da15c62/rust/gateway/src/eventloop.rs#L80

Expected Result

To receive a Sentry event that contains the error.

Actual Result

A Sentry event that only contains the log message but not the error:

---

I've been digging through the source code here and the problem is that when a tracing event gets converted to a Sentry event, all fields apart from what is prefixed with tags. gets silently dropped: https://github.com/getsentry/sentry-rust/blob/a1481d42ae7a9a1f3f396d6948b0e61354a20ba4/sentry-tracing/src/converters.rs#L212-L230

This is pretty confusing because the documentation clearly states:

To track error structs, assign a reference to error trait object as field in one of the logging macros. By convention, it is recommended to use the ERROR level and assign it to a field called error, although the integration will also work with all other levels and field names.

What is perhaps missing here is a foot-note that it will work with all levels as long as you configure an event filter that converts the event to a sentry exception! However, instead of fixing the documentation here, I think the proper fix is to actually make this work the way the documentation states and attach the exception to the message, even if the log level is not ERROR.

[thomaseizinger]

However, instead of fixing the documentation here, I think the proper fix is to actually make this work the way the documentation states and attach the exception to the message, even if the log level is not ERROR.

I tried to fix this but realised that this essentially just makes "messages" and "exceptions" the same?

[thomaseizinger]

However, instead of fixing the documentation here, I think the proper fix is to actually make this work the way the documentation states and attach the exception to the message, even if the log level is not ERROR.

I tried to fix this but realised that this essentially just makes "messages" and "exceptions" the same?

The other issue here is that the field does not become a context because it is recorded in the FieldVisitor as an exceptions and therefore not grouped with the other fields.

[DoumanAsh]

I think everything is geared towards errors being treated as exceptions hence non-exception events are treated as informational I usually use empty span fields to record error information and keep context via https://docs.rs/sentry-tracing/0.34.0/sentry_tracing/struct.SentryLayer.html#method.enable_span_attributes

[thomaseizinger]

This is also a problem for breadcrumbs. There, any recorded "errors" on the way are also discarded because only the json_values are captured, see https://github.com/getsentry/sentry-rust/blob/a1481d42ae7a9a1f3f396d6948b0e61354a20ba4/sentry-tracing/src/converters.rs#L142-L153.

The real foot-gun here is that this basically makes it really dangerous to apply a blanket rule of "we will just record all errors as Error within tracing". Arguably, that is what applications should do in order to preserve as much type-information as possible for as long as possible. Sentry discourages that because it will silently drop all of them unless they get reported as exceptions to Sentry.

[DoumanAsh]

You do not necessary need to record everything in error As I mentioned you can use span's fields (initially initialized with tracing::field::Emtpy) and the fill it on demand

[thomaseizinger]

You do not necessary need to record everything in error

Why wouldn't I though? This is like saying: "You know need to pass fields to tracing, just format everything as a string". Yeah I can do that, but what is the point of using a library that supported structured logging then? I would like to record errors as std::error::Error and Sentry should walk through the source chain and display all of them.

[DoumanAsh]

I believe you're not listening to me What I mean is that if you do not want to aggregate everything tracing::error! you can do it as follows:

#[tracing::insturment(fields(extr_error = tracing::field::Empy))]
fn my_work() {
   tracing::Span::current().record("extr_error", "whatever I want");
   tracing::error!("my error");
}

This is just suggestion if you want to make current layer work for you better But otherwise you can continue with issue

[thomaseizinger]

Unless I am missing something, this doesn't solve the issue though, does it? I haven't tried it but from reading the code, the following should happen:

1. Errors set on the span are recorded as debug because SpanFieldVisitor doesn't override the default implementation of record_error.
2. Additional fields recorded in the span later ignore all std::error::Errors: https://github.com/getsentry/sentry-rust/blob/a1481d42ae7a9a1f3f396d6948b0e61354a20ba4/sentry-tracing/src/layer.rs#L270-L272

if you do not want to aggregate everything tracing::error!

What I want to do is record information in a tracing-idiomatic way without having to implement workarounds because sentry-tracing decides to silently drop certain fields.

[DoumanAsh]

This will work under assumption you use https://docs.rs/sentry-tracing/0.34.0/sentry_tracing/struct.SentryLayer.html#method.enable_span_attributes because it should attach span fields associated with the event (but not to breadcrumb)

But yes, it is not ideal that event doesn't record all non tag fields