Opentelemetry-go: Update SpanProcessor.OnStart to conform with specification

Created on 2 Nov 2020  路  9Comments  路  Source: open-telemetry/opentelemetry-go

The SDK SpanProcessor.OnStart method needs to be updated to follow the specification

OnStart

OnStart is called when a span is started. This method is called synchronously
on the thread that started the span, therefore it should not block or throw
exceptions.

Parameters:

  • span - a read/write span object for the started span.
    It SHOULD be possible to keep a reference to this span object and updates to the span
    SHOULD be reflected in it.
    For example, this is useful for creating a SpanProcessor that periodically
    evaluates/prints information about all active span from a background thread.
  • parentContext - the parent Context of the span that the SDK determined
    (the explicitly passed Context, the current Context or an empty Context
    if that was explicitly requested).
  • Instead of passing export.SpanData we need to pass a read/write form of the SDK span. Given it is not an exported type the method should accept the otel trace API Span type which can be read and updated.
  • Additionally, the full context.Context from the parent of the Span needs to be added as a parameter. This is to allow non-traced propagation values and other details about the parent to be passed to the method.
trace help wanted SDK p1 required-for-ga

All 9 comments

Happy to pick this one up @MrAlias.

The change is simple enough and I have a WIP here, however as @krnowak helpfully pointed out to me, looks like we need to discuss our handling of OnStart more broadly:

  • Right now we pass an export.SpanData rather than a Span to OnStart, which doesn't seem to follow the spec.
  • export.SpanData already contains a parent span ID, which makes passing the SpanContext redundant.
  • I couldn't figure out from the history why SpanData was used in OnStart rather than Span.
  • I guess at least some of the implementations of the SpanProcessor interface should do something with SpanContext (otherwise why is it necessary?). Right now we don't seem to be doing anything with this argument. I've looked at the Python and Java libraries but I can't figure out what is actually being done with SpanContext. The spec also didn't help me understand this.

@MrAlias (or anybody else!) - do you have any thoughts on this?

  • Right now we pass an export.SpanData rather than a Span to OnStart, which doesn't seem to follow the spec.
  • I couldn't figure out from the history why SpanData was used in OnStart rather than Span.

As far as I can tell this is a bug, we should be passing a Span to OnStart. We should include this fix in this issue.

  • export.SpanData already contains a parent span ID, which makes passing the SpanContext redundant.
  • I guess at least _some_ of the implementations of the SpanProcessor interface should do something with SpanContext (otherwise why is it necessary?). Right now we don't seem to be doing anything with this argument. I've looked at the Python and Java libraries but I can't figure out what is actually being done with SpanContext. The spec also didn't help me understand this.

I think the confusion is coming from SpanContext and context.Context. My understanding of the specification is that it wants the full parent context.Context to be passed to the OnStart method. This will allow the method to look at the full set of context the span was created from including missing elements like baggage, trace-context, and other non-standard tracing propagation flags. This was taken from the rationale of the PR that updated the specification:

This [Context] is required to actually transport arbitrary custom context attributes from inject through to extract. Previously the only way to do that was to encode them in TraceContext (which has length limitations and only supports string-encoded data).

Great @MrAlias, will refactor accordingly.

@MrAlias @krnowak changing OnStart and OnEnd to accept an otel.Span instead of *export.SpanData breaks the following:

https://github.com/open-telemetry/opentelemetry-go/blob/386331a472deda26020f125501cba346cacf0193/sdk/trace/span_processor_test.go#L84

We don't have a way to read span attributes via the API, only set them (which is intentional AFAIK and follows the spec). In order to preserve this sort of tests I would likely have to one of the following:

  • Convert span_processor_test.go (and other similar test files) to span_processor_internal_test.go and change the package from trace_test to trace so that the test can get access to the internal SDK span struct.
  • Make makeSpanData exported, which I don't like as it exposes SDK internals to callers.

I'm gonna go with the first option for now. Please feel free to share your thoughts.

As far as I can tell this is a bug, we should be passing a Span to OnStart. We should include this fix in this issue.

Following the above, I assumed we want to pass a Span (rather than an export.SpanData) to OnEnd, too.

When implementing this change I've encountered the following problem:

In span.End in the SDK, we set the span's end time in sd which is a copy of the span's data field:

https://github.com/open-telemetry/opentelemetry-go/blob/27aa1f601124468cde6c796935460435b6723700/sdk/trace/span.go#L146-L154

We then pass sd to any registered span processors via OnEnd.

The copying happens here:

https://github.com/open-telemetry/opentelemetry-go/blob/27aa1f601124468cde6c796935460435b6723700/sdk/trace/span.go#L253-L272

If we now change OnEnd to accept a Span and pass s rather than sd, the span passed to OnEnd doesn't have the end time in its internal state, which in turn breaks tests like this one:

https://github.com/open-telemetry/opentelemetry-go/blob/27aa1f601124468cde6c796935460435b6723700/sdk/trace/trace_test.go#L340-L351

Here endSpan expects the end time to be reflected in the span, however since we set it in a copy of the span's SpanData the end time seen by endSpan is zero.

Are we intentionally copying the SpanData? The name makeSpanData kind of suggests it. If we actually want to copy the data, having span.End set a span's end time in the copy doesn't make sense to me because then anything which reads the original span struct after it had ended doesn't see the end time.

I suspect this could be a bug which hasn't been uncovered until now because we used to pass the modified SpanData to the span processors.

For now I'll assume the copying is a bug and will include a fix as part of this issue. @krnowak @MrAlias please tell me if you think we should do otherwise.

We've discussed this problem in the Go SIG meeting and realized that the scope of this problem is wider than this issue. We've decided to take another look at the way we implement the read-only vs. read/writable span from the spec and potentially refactor this aspect of the SDK. Specifically, we should re-evaluate the design choices behind our usage of export.SpanData in the SDK's trace package.

We've agreed to keep using SpanData in both OnStart and OnEnd for now and only change the parent context argument to context.Context. I'll open an new issue to track the refactoring task.

Was this page helpful?
0 / 5 - 0 ratings

Related issues

MrAlias picture MrAlias  路  6Comments

MrAlias picture MrAlias  路  7Comments

paivagustavo picture paivagustavo  路  8Comments

MrAlias picture MrAlias  路  5Comments

MrAlias picture MrAlias  路  4Comments