Record span-ending exceptions as span attributes instead of span event or log

[alexmojaki]

Somewhat continuing from #4333 (comment)

My understanding is that:

• The plan is to get rid of (or at least deprecate, which is close) span events and this is unlikely to change.
• Since exceptions on spans are recorded as span events, the current plan for that is to instead record them as logs that are children of the span.

My proposal is that when a span ends with an exception, the usual attributes exception.type/message/stacktrace should be recorded directly on the span instead of creating a child log. Ways this could look:

• Allow passing an exception object to Span.End
• Change Span.RecordException to record attributes on the span instead of creating an event. This assumes that Span.RecordException is only called when the span is ending, which IIUC is now the recommendation.

Reasons to use exception.* span attributes instead of a child log:

1. It's not clear to me how Span.RecordException will work in the SDK if it has to create a log. Will creating a tracer provider require passing a logging provider?
2. Backends won't need to support logs to support working with exceptions on spans.
3. Users won't have to join multiple records in a query to e.g. find spans which match some predicate and had an exception.
4. Very simple to implement, document, and understand.
5. When a single exception bubbles through multiple nested spans, by default each one would create a child log and would have no way of knowing that this would be redundant. This results in the tree of spans and logs looking very ugly:

span1:
    span2:
        span3:
            exception-log3
        exception-log2
    exception-log1

6. https://opentelemetry.io/docs/specs/semconv/general/recording-errors/#recording-exceptions recommends recording some information directly on the span, but:
   1. It doesn't recommend recording exceptions that are handled, especially because the exception message is meant to be recorded as the status description, which requires setting the status code to error. However it's useful to record exceptions that ended the span even if they're expected to be handled and thus the span should not be marked as an error. This is even acknowledged in the proposal to record exceptions as logs:

      opentelemetry-specification/oteps/4333-recording-exceptions-on-logs.md

      Lines 155 to 159 in db2b647

      	Note: some frameworks use exceptions as a communication mechanism when a request fails. For example,
      	Spring users can throw a [ResponseStatusException](https://docs.spring.io/spring-framework/docs/current/javadoc-api/org/springframework/web/server/ResponseStatusException.html)
      	exception to return an unsuccessful status code. Such exceptions represent errors already handled by the application code.
      	Application code, in this case, is expected to log this at the appropriate severity.
      	General-purpose instrumentation MAY record such errors, but at a severity not higher than `Warn`.

   2. error.type and the status description are very generic places to put information, so in some situations they would be better used by something other than the exception. For example, an HTTP client for a specific service might raise a generic APIError which is recorded as exception.type on the span, while the more specific error code contained within could be used for error.type. In general, error.type and the status description shouldn't be overridden when the already present, but that shouldn't mean that the precise technical exception data gets discarded.
   3. There's currently no way to know if error.type represents the type of an exception that ended a span, or something else. Same with the span status description.
   4. This isn't clear to users. For example, a user may see the error.type attribute on a span and expect to find an attribute like error.message next to it. They have no way of knowing if the exception message is anywhere to be found in the span data if they don't know where to look.
7. There's currently no apparent way to know whether or not a span ended with an exception. As mentioned above, error.type and the span status are ambiguous. The presence of a child log with an exception (which is nontrivial to check) isn't conclusive either, because the exception could have been handled and the span ended normally. exception.* attributes can solve this.

Responses to possible objections:

• What about exceptions that are handled within the span and don't end it?
  • I think the plan to use logs in that situation is fine. I see it as different because:
    • If users want to log such exceptions then the implication is that they're interesting events in their own right and would likely be worth logging even without the parent span, and OTel doesn't seem to have a good alternative recommendation for that. A span-ending exception is much more like a property of the span itself.
    • If there are 1000 such exceptions, putting them all inside the span somehow is likely to be a problem.
    • The timestamp of a handled exception is potentially much more interesting, since it's not necessarily at the end of the span.
• What about exceptions that aren't errors, i.e. are expected to be handled outside the span? Logs can have a severity to indicate this.
  • An attribute like exception.severity can deal with this.
• Stacktraces can be very big.
  • If the size of a stacktrace is problematic in a span attribute, it will probably be problematic in a log too.
• Logs can be configured to e.g. not record certain exceptions.
  • Generically reusable wrapper tracer providers can be created to make this kind of configuration easy.

[pellared]

Logs can be configured to e.g. not record certain exceptions.

This does not look to be currently possible as there is no way to alter a span event or create a new span inside a span processor.

[alexmojaki]

This does not look to be currently possible as there is no way to alter a span event or create a new span inside a span processor.

I don't see any reason that the spec needs to keep this limitation. In any case a wrapper tracer or tracer provider that's spec compliant should still be possible.

[pellared]

I don't see any reason that the spec needs to keep this limitation.

The fact that you do not see a reason does not mean that there are no reasons. Please create an issue if you want to validate your proposal. As of now the description has a false statement which should be updated. You can always refer to the created issue in this issue description.

In any case a wrapper tracer or tracer provider that's spec compliant should still be possible.

You can do anything wrapping the API implementations. The fact that something is possible does not mean that it should be done.

[alexmojaki]

I've removed the mention of span processors so that there is no false statement.

The fact that something is possible does not mean that it should be done.

This isn't an argument.

[pellared]

I've removed the mention of span processors so that there is no false statement.

Could you please rephrase and leave it as a "drawback"? Providing only benefits on proposed solution is not a fair and accurate design description. Please also describe other drawbacks.

In any case a wrapper tracer or tracer provider that's spec compliant should still be possible.

The fact that something is possible does not mean that it should be done.

This isn't an argument.

Fair. Let me expand on this. If you add such things on the API layer then you are not able to have fine-grained control on the processor level. For instance, a user may want to export spans to two destination and only one of it should have attributes/span events redacted. It would be also less performant than doing it on lower (SDK) level. For reference, I was also looking as wrapping logger and logger provider to support multi log processing pipelines: open-telemetry/opentelemetry-go#5830 and it was quite quickly rejected as a bad design.

[alexmojaki]

It would be also less performant than doing it on lower (SDK) level.

I don't know if this is true. A provider can intercept Span.RecordException (while adding trivial overhead elsewhere) and prevent the stacktrace from being computed in the first place, which can be expensive. So it could be significantly more efficient than a log processor working on existing logs.

[pellared]

What about exceptions that are handled within the span and don't end it?

I think the plan to use logs in that situation is fine. I see it as different because:

Having two places ways to record errors/exceptions depending on how they affect the span does not seem like a design which is

Very simple to implement, document, and understand.

In most cases, the span ended because of an exception/error already has Error status and a description containing the exception/error details. The information added to attributes (or span events) would be redundant to the information already provided in the span description (and logs if exported).

Still, we can have a semantic convention for distinguishing these kinds of exceptions/errors then we could provide a LogRecordProcessor which adds the exception attributes to the span when an exception/error ends the span.

[cijothomas]

It's not clear to me how Span.RecordException will work in the SDK if it has to create a log. Will creating a tracer provider require passing a logging provider?

Where is the recommendation that Span.RecordException has to create a log?
(Of course, if there were such a specification, then I can see it'll challenging to implement for the exact reason you raised - how does Tracer obtain a LoggerProvider!)

[adriangb]

In most cases, the span ended because of an exception/error already has Error status and a description containing the exception/error details. The information added to attributes (or span events) would be redundant to the information already provided in the span description

Is there a spec for the format of the data in the message or the exception/error? The ask here is for more structured and formal inclusion of this information in the span itself. I agree it would be nice if the information is not duplicated but ultimately it serves somewhat different purposes (I think of the message as something nice to display while the attributes are more structured and intended for querying). IMO it should also be possible to include the stack trace of the exception as seen by the span at least as an opt-in configuration: the stack trace changes as the exception bubbles up through the program so if users are willing to accept the cost it can be worth it to record more than once; it's not strictly duplication.

[alexmojaki]

What about exceptions that are handled within the span and don't end it?

I think the plan to use logs in that situation is fine. I see it as different because:

Having two places ways to record errors/exceptions depending on how they affect the span does not seem like a design which is

Very simple to implement, document, and understand.

There is no reason for handled errors/exceptions to get any kind of special treatment in relation to the outer span. In this code:

with tracer.start_as_current_span("outer span"):
    with tracer.start_as_current_span("inner span"):
        ...
    print("...")
    log.info("...")
    log.error("...")
    log.exception("...")

we would not consider storing the inner span, the printed message, or the info log directly on the span. The error log just has a different level from the info log. The exception log just has more info than the error log. It's good to have specifications and semantic conventions about things like the names of the exception attributes in the log. But none of these things should affect the outer span, nor should they be affected by the outer span except to set the parent trace/span ID. They are independent signals. The question "what about handled exceptions in a span" doesn't really make sense. Why should the span care?

Now suppose an unhandled exception is raised. The outer span sees it and has an opportunity to record it somewhere, and it should. Should it record it by emitting a log? Why? Just because users have the option to manually catch and log handled exceptions? How is that relevant to this decision?

In most cases, the span ended because of an exception/error already has Error status and a description containing the exception/error details. The information added to attributes (or span events) would be redundant to the information already provided in the span description (and logs if exported).

I have explained why the error status and description are insufficient. If it often turns out to be redundant, I don't think that's a significant problem, it's not that much data.

Still, we can have a semantic convention for distinguishing these kinds of exceptions/errors then we could provide a LogRecordProcessor which adds the exception attributes to the span when an exception/error ends the span.

What would be the benefit of doing things this way? Why should the tracing SDK automatically emit a log when a span ends with an exception? Again, this is a very different and separate thing from users or instrumentations explicitly logging specific exceptions.

[alexmojaki]

It's not clear to me how Span.RecordException will work in the SDK if it has to create a log. Will creating a tracer provider require passing a logging provider?

Where is the recommendation that Span.RecordException has to create a log?

In #4430 it looks like the plan is to allow opting in to such:

opentelemetry-specification/oteps/4430-span-event-deprecation-plan.md

Lines 67 to 68 in 8a276ac

	The tracing SDK SHOULD provide an opt-in mechanism that allows
	users to emit span events as (log-based) events.

and that the recommendation will be to create a log instead of calling Span.RecordException:

opentelemetry-specification/oteps/4430-span-event-deprecation-plan.md

Lines 52 to 55 in 8a276ac

	The [Span RecordException](../specification/trace/api.md#record-exception) API
	SHOULD be marked as
	[deprecated](../specification/versioning-and-stability.md#deprecated),
	recommending that people use the OpenTelemetry Log API instead.

I guess that answers point 1. So in this part of my proposal:

Ways this could look:

• Allow passing an exception object to Span.End
• Change Span.RecordException to record attributes on the span instead of creating an event. This assumes that Span.RecordException is only called when the span is ending, which IIUC is now the recommendation.

I now suggest forgetting the second option. I'm proposing allowing Span.End(exception). Then the plan to deprecate Span.RecordException can continue, and if using it emits a warning, that warning should recommend using logs for handled exceptions and Span.End(exception) for unhandled ones. Using it is already not recommended for handled exceptions:

opentelemetry-specification/specification/trace/exceptions.md

Lines 16 to 17 in d5fed63

	An exception SHOULD be recorded as an `Event` on the span during which it occurred
	if and only if it remains unhandled when the span ends and causes the span status

@pellared please take note of that: there's already a difference in the recommendations for handled vs unhandled exceptions.

[lmolkova]

I'm supportive of recording the (terminal) exception on the span attributes and introducing Span.End(Exception | Error):

• very clean API story - you could only set one exception and it's unhandled when the span ends.
• it's effectively a convenience on top of End(Status.Error, ex.getMessage()) (with more features).
• it hides complexity away from users/instrumentations and helps everyone report exceptions consistently.
• it allows to evolve the implementation details (config options, details captured) inside OTel SDKs vs every instrumentation out there
• most importantly it allows users to see "why this span failed" right on that span - this is better than span events - some backends store them separately from spans

I have some minor/resolvable (I believe) concerns:

• should we record stack trace on span at all?

  • Not by default, but opt-in sounds ok

• should instrumentations report exception on the span and exception on the log?

  • I believe yes, combined with OTEP: Recording exceptions as log records #4333 we get the following experience:
    • by default:
      • exception message and type are duplicated (when log is recorded)
      • stacktrace appears on the log only when severity is high and does not appear on spans
    • users can customize: choose the threshold for stacktrace on logs or can choose to report them on spans regardless of severity

• can we reuse existing attributes/properties:

  • error.type for exception.type - no, they are somewhat different. You can have error.type = VersionNegotiationError and exception.type = HttpRequestException or error.type = 404 and no exception.type
  • span status description for exception.message - yes and I think we should do it.