OTEP: Recording exceptions as log based events

[lmolkova]

Related to open-telemetry/semantic-conventions#1536

Changes

Recording exceptions as span events is problematic since it

• ties recording exceptions to tracing/sampling
• duplicates exceptions recorded by instrumented libraries on logs
• does not leverage log features such as typical log filtering based on severity

This OTEP provides guidance on how to record exceptions using OpenTelemetry logs focusing on minimizing duplication and providing context to reduce the noise.

If accepted, the follow-up spec changes are expected to replace existing (stable) documents:

• https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/exceptions.md
• https://github.com/open-telemetry/semantic-conventions/blob/main/docs/exceptions/exceptions-spans.md

---

• Related issues Document generic approach for span status (code + description) and exception event when instrumented code throws semantic-conventions#1536
• Related OTEP(s) #
• Links to the prototypes (when adding or changing features)
• CHANGELOG.md file updated for non-trivial changes
• spec-compliance-matrix.md updated if necessary

[pellared]

I think this is a related issue:

• Define whether instrumentations can emit non-event log records #4234

[carlosalberto]

A small doubt:

If this instrumentation supports tracing, it should capture the error in the scope of the processing span.

Although (I think) it's not called out, I'm understanding exceptions should now be explicitly reported as both 1) Span.Event and 2) Log/Event? i.e. coding wise you should do this:

currentSpan.recordException(e);
logger.logRecordBuilder
    .addException(e);

Is this the case?

[jsuereth]

Overall I'm very supportive. Just some nits and one mitigation I'd like to see called out/addressed.

[jsuereth]

What's an example of this? I'm struggling to understand when this would be used.

[lmolkova]

Most popular is exception-driven logic - you check that something is available and it throws if it's not. You try to delete something and it throws if someone concurrently deleted it.
You send a request, it times-out, you retry and get 'already exists', etc.

It's not always the best development style, but there are plenty of real-life examples. Adding one to the text.

[jsuereth]

How do you know an error is transient when writing instrumentation? I think you mean errors that you KNOW the application will attempt to handle / retry, right?

I'd suggest rewording (or defining the meaning of transient).

[lmolkova]

updated to

• Errors that are expected to be retried or handled by the caller or another
  layer of the component SHOULD be recorded with severity not higher than Warn.

with additional explanations and examples.

[jsuereth]

I like the goal of the taxonomy, but think we need to crisp up the language around Info/Warning

[lmolkova]

makes sense, updated each severity bullet with examples and some criteria related to error impact. PTAL

[jsuereth]

Two things:

1. SHOULD is normative, so please capatilize (and I think IS a normative statement here).
2. This may not be language neutral, so I think SHOULD is the right guidance here. For example, in Rust, stack traces are something you can opt-in on an error. They leave some details to libraries (see Rust Backtrace/Source capabilities on https://docs.rs/thiserror/latest/thiserror/ e.g. or C++ [prior to 23] https://github.com/jeremy-rifkin/cpptrace).
   Additionally, in some highly green-thread/async APIs, I've seen custom stack traces created (e.g. Scala's ZIO where they try to preserve logical stack when physical stack is a confusing mess of work-stealing green-threads. We should allow these to interact with exception reporting in OTEL in some fashion.

I agree with the sentiment, I'd expand the wording though to allow languages like Rust/C++ (and Java ecosystem) to provide stack trace compatibility with their library ecosystem.

[lmolkova]

updated to use normative language. Also added

The signature of the method is to be determined by each language
and can be overloaded as appropriate including ability to customize stack trace
collection.

It MUST be possible to efficiently set exception information on a log record based on configuration
and without using the setException method.

[jsuereth]

I think we should also call out the fact that now we have two channels of exporting/batching/recording information of exceptions and Traces. In this new world, you may see a trace before an exception or vice versa, and one may be dropped where the other is not.

We probably need some other mitigatioin should that requiring knowledge of an exception event under a Span is no longer needed (e.g. more aggressively using Span.status and attributes around "transient failures" as we discussed in Semconv SIG.

[lmolkova]

Added a clarification in the OTEP that logs are intended to replace span events (gracefully). I.e. there should be just one channel of communication at a time.

[pellared]

👍

[pellared]

I think these indicate actual issues and could be reported with Warn severity. Minor impact is still some impact and multiple minor issues could multiply to be a major issue. Maybe better remove this sentence?

[lmolkova]

which ones?

this section talks about

• Exceptions or errors that don't indicate actual issues SHOULD be recorded with
  severity not higher than Info.

  Such exceptions can be used to control application logic and have a minor impact, if any,
  on application functionality, availability, or performance.

  Examples:

  • exception is thrown when checking optional dependency or resource existence.
  • exception thrown when client disconnects before reading full response from the server

[pellared]

If it has non-zero impact then in my opinion it can be Warn as well.

References:

• https://www.crowdstrike.com/en-us/cybersecurity-101/next-gen-siem/logging-levels
• https://sematext.com/blog/logging-levels/
• https://github.com/serilog/serilog/wiki/configuration-basics
• https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/logs/data-model.md#field-severitynumber

[pellared]

One could mitigate it with https://github.com/open-telemetry/opentelemetry-collector-contrib/tree/main/processor/logdedupprocessor. The SDK all Contrib could also provide something similar for each language.

[lmolkova]

That's less about identical log records and more about writing code that writes multiple different log records as exception propagates through the stack, but stamps exception info on all of them

[pellared]

I am not sure why it is in "Prior art and alternatives" and not in "Open questions" or "Future possibilities".
I also think that this description could be clarified as I would never guess what it was about. I thought this is more about deduplicating e.g. callstack information.

[lmolkova]

Although (I think) it's not called out, I'm understanding exceptions should now be explicitly reported as both 1) Span.Event and 2) Log/Event? i.e. coding wise you should do this:

@carlosalberto thanks for the clarification! The intent here is to eventually replace span events with logs in the instrumentations (in non-breaking manner for existing ones).

I clarified it in the text, PTAL.

[trask]

github u/x is showing a weird diff, have seen this before, may be worth trying to rebase and force push

[pellared]

Isn't the description here: https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/logs/data-model.md#field-severitynumber good enough?