Dissecting OpenTelemetry Go Tracing

OpenTelemetry is a quite new tool meant to provide a standard interface to for handling metrics and traces.

It provides libraries in all main languages, and its collector component allows receiving data from any app in any language, and transmitting them to any observability platform.

In this article, much like I did with prometheus and kubernetes deployments, I am going to go through the code path for sending a trace in the OpenTelemetry Go library.

This article assumes you have knowledge of Go.

The OpenTelemetry API vs SDK

The OpenTelemetry API is meant to change very unfrequently (if not never), and to implement the public interfaces of the library.

We can for example see that it defines a tracer interface:

// Tracer is the creator of Spans.
type Tracer interface {
  // Start creates a span.
  Start(ctx context.Context, spanName string, opts ...SpanOption) (context.Context, Span)
}

As that’s an interface, it doesn’t do much though, outside of defining the way you will use the library.

Whether you should use the API or SDK from OpenTelemetry really depends on what you need to do.

But as a rule of thumb, if you are writing a library with instrumentation (say a database client which creates traces for every query being made), you should be using the API interfaces, and never the SDK.

If you are instrumenting your own application, you will also need the SDK, as we will see later.

A first look

If you create a new trace in your application, the syntax is going to be the following:

otel.Tracer("").Start(context.Background(), "traceName")

Let’s start there. The Tracer() method is defined in trace.go:

func Tracer(name string) trace.Tracer {
  return GetTracerProvider().Tracer(name)
}

This brings us outside of the public API right away, as we go into the internal/global package.

internal packages in Go can only be imported by a parent package. They can be seen as private packages which cannot be used externally.

This package holds a global variable globalTracer which allows keeping a global tracer provider across the entire program, so we can create new traces without requiring any context.

The defaultTracerValue method stores a binary-wide tracer:

func defaultTracerValue() *atomic.Value {
  v := &atomic.Value{}
  v.Store(tracerProviderHolder{tp: &tracerProvider{}})
  return v
}

From there, we can see that Tracer() in the tracerProvider struct initialized above creates a new trace{} struct, which implements our public interface tracer.Trace.

// Tracer implements TracerProvider.
func (p *tracerProvider) Tracer(name string, opts ...trace.TracerOption) trace.Tracer {
  p.mtx.Lock()
  defer p.mtx.Unlock()

  if p.delegate != nil {
    return p.delegate.Tracer(name, opts...)
  }

  t := &tracer{name: name, opts: opts}
  p.tracers = append(p.tracers, t)
  return t
}

However, we don’t have any delegated tracer, or trace. So we will get the private struct defined in that same file

If you look at that struct’s Start() method, you will see that is starts a new trace from the noop internal tracer.

// Start implements trace.Tracer by forwarding the call to t.delegate if
// set, otherwise it forwards the call to a NoopTracer.
func (t *tracer) Start(ctx context.Context, name string, opts ...trace.SpanOption) (context.Context, trace.Span) {
  if t.delegate != nil {
    return t.delegate.Start(ctx, name, opts...)
  }
  return noop.Tracer.Start(ctx, name, opts...)
}

That package redirects us to yet another one, which brings us back to the public API, otel/trace/noop.go.

I won’t give you the full package code in here. But its name probably got you the gist of it. That tracer does nothing.

So, to do something, we’ll have to do some configuration.

Configuring a tracer provider

Now that we have seen the path taken to start a new dummy trace, let’s setup a Tracer Provider, which will allow us to make our traces actually do something.

We can configure our tracer provider with the following:

import (
  "go.opentelemetry.io/otel"
  "go.opentelemetry.io/otel/exporters/stdout"
  sdktrace "go.opentelemetry.io/otel/sdk/trace"
)

func main() {
  // Create an STDOUT exporter, so our traces are sent somewhere
  logExp, _ := stdout.NewExporter()

  // Create and configure our new tracer
  tp := sdktrace.NewTracerProvider(
    sdktrace.WithSyncer(logExp),
  )
  defer tp.Shutdown()

  // Tell OpenTelemetry to use this Trace Provider
  otel.SetTracerProvider(tp)
}

We will come back to the TracerProvider interface later. But we can see that SetTracerProvider bring us back to the internal/global package again:

// SetTracerProvider registers `tp` as the global trace provider.
func SetTracerProvider(tp trace.TracerProvider) {
  global.SetTracerProvider(tp)
}

In that global package, we can see the internal SetTracerProvider method, which makes our Tracer Provider as the global default one.

// SetTracerProvider is the internal implementation for global.SetTracerProvider.
func SetTracerProvider(tp trace.TracerProvider) {
  // [...] This removed section makes sure the TracerProvider isn't set twice
  globalTracer.Store(tracerProviderHolder{tp: tp})
}

To do so in a concurrently-safe way, it is stored in an atomic.Value struct, which we saw defined earlier in defaultTracerValue.

atomic.Value is a Go-provided struct which allows atomically storing and retrieving (but not copying) values. It is a pretty great way to store configuration and safely retrieve it in multiple goroutines.

If we come back to our previous call starting a new trace:

otel.Tracer("").Start(context.Background(), "traceName")

You may remember that otel.Tracer() retrieves the Tracer from our default TracerProvider, which defaulted to a noop.

Well, we just changed the TracerProvider to something different than the default, something configured to actually do something!

The Tracer Provider

As we have seen before, Tracer and TracerProvider are defined as interfaces:

// Tracer is the creator of Spans.
type Tracer interface {
  // Start creates a span.
  Start(ctx context.Context, spanName string, opts ...SpanOption) (context.Context, Span)
}

// TracerProvider provides access to instrumentation Tracers.
type TracerProvider interface {
  // Tracer creates an implementation of the Tracer interface.
  // The instrumentationName must be the name of the library providing
  // instrumentation. This name may be the same as the instrumented code
  // only if that code provides built-in instrumentation. If the
  // instrumentationName is empty, then a implementation defined default
  // name will be used instead.
  Tracer(instrumentationName string, opts ...TracerOption) Tracer
}

Configuring a TracerProvider as we did earlier allows us to get our Traces to do something. While we could implement those interfaces ourselves, that would be a pretty bad idea, as OpenTelemetry does that for us.

When we called NewTracerProvider, as new instance of the TracerProvider struct was created for us.

Within that TracerProvider, the Tracer method will create a new tracer for us:

// Tracer with the given name. If a tracer for the given name does not exist,
// it is created first. If the name is empty, DefaultTracerName is used.
func (p *TracerProvider) Tracer(name string, opts ...trace.TracerOption) trace.Tracer {
  c := trace.NewTracerConfig(opts...)

  p.mu.Lock()
  defer p.mu.Unlock()
  if name == "" {
    name = defaultTracerName
  }
  il := instrumentation.Library{
    Name:    name,
    Version: c.InstrumentationVersion,
  }
  t, ok := p.namedTracer[il]
  if !ok {
    t = &tracer{
      provider:               p,
      instrumentationLibrary: il,
    }
    p.namedTracer[il] = t
  }
  return t
}

If we didn’t specify any name (by sending an empty string as the name), defaultTracerName will be used:

defaultTracerName = "go.opentelemetry.io/otel/sdk/tracer"

No matter what we did, if a tracer with the provided name exists, it will be returned. Otherwise, a new one will be created, stored and returned.

So, if you call Tracer() with the same name twice in your application, you will always get the same Tracer.

Creating a Trace

The SDK’s tracer is a private struct, as we never need to initialize it ourselves:

type tracer struct {
  provider               *TracerProvider
  instrumentationLibrary instrumentation.Library
}

When calling Start on it, the tracer will do a number of things:

// Start starts a Span and returns it along with a context containing it.
//
// The Span is created with the provided name and as a child of any existing
// span context found in the passed context. The created Span will be
// configured appropriately by any SpanOption passed. Any Timestamp option
// passed will be used as the start time of the Span's life-cycle.
func (tr *tracer) Start(ctx context.Context, name string, options ...trace.SpanOption) (context.Context, trace.Span) {
  config := trace.NewSpanConfig(options...)

  parentSpanContext, remoteParent, links := parent.GetSpanContextAndLinks(ctx, config.NewRoot)

  if p := trace.SpanFromContext(ctx); p != nil {
    if sdkSpan, ok := p.(*span); ok {
      sdkSpan.addChild()
    }
  }

  span := startSpanInternal(ctx, tr, name, parentSpanContext, remoteParent, config)
  for _, l := range links {
    span.addLink(l)
  }
  for _, l := range config.Links {
    span.addLink(l)
  }
  span.SetAttributes(config.Attributes...)

  span.tracer = tr

  if span.IsRecording() {
    sps, _ := tr.provider.spanProcessors.Load().(spanProcessorStates)
    for _, sp := range sps {
      sp.sp.OnStart(ctx, span)
    }
  }

  ctx, end := startExecutionTracerTask(ctx, name)
  span.executionTracerTaskEnd = end
  return trace.ContextWithSpan(ctx, span), span
}

It will first try to fetch a parent span:

parentSpanContext, remoteParent, links := parent.GetSpanContextAndLinks(ctx, config.NewRoot)

This allows setting up new spans as being childs of another span defined before and stored in the context.

It will then call startSpanInterval, which creates a new span and configure it with all the data we already have.

The next interesting thing, which you may have noticed in the struct definition is that the tracer is stored within the span. This is essential so when End() is called on that span, we will need the tracer (and tracer provider) to be able to call the exporters.

There are a few more configurations happening for each span, as well as calling OnStart from each processor. We will see what a processor is down below.

Finishing a Span

Let’s now finish our Trace.
At this stage, we hold a span from the SDK, which obviously implements the Trace interface.

When we call End() on our span, we close it, and our processors will receive it for transmit it to their exporters:

// End ends the span.
//
// The only SpanOption currently supported is WithTimestamp which will set the
// end time for a Span's life-cycle.
//
// If this method is called while panicking an error event is added to the
// Span before ending it and the panic is continued.
func (s *span) End(options ...trace.SpanOption) {
  // [...] Check for s being different than nil removed

  // Store the end time as soon as possible to avoid artificially increasing
  // the span's duration in case some operation below takes a while.
  et := internal.MonotonicEndTime(s.startTime)

  // [...] Panic recovery and logging removed

  // [...] Couple sanity checks removed

  config := trace.NewSpanConfig(options...)

  s.mu.Lock()
  if config.Timestamp.IsZero() {
    s.endTime = et
  } else {
    s.endTime = config.Timestamp
  }
  s.mu.Unlock()

  sps, ok := s.tracer.provider.spanProcessors.Load().(spanProcessorStates)
  mustExportOrProcess := ok && len(sps) > 0
  if mustExportOrProcess {
    for _, sp := range sps {
      sp.sp.OnEnd(s)
    }
  }
}

First of all, End will do some cleanup, such as preventing us from ending a span twice, and setting the span’s end time to now (or a custom value if we defined it).
I have removed those from the example above to make the code easier to read.

You may remember that we stored the Tracer within the span earlier. So the span will retrieve all processors, and call OnEnd on each of them.

There, our trace is finished!

Sending the Span data

We have now seen that whenever we create and end a span, its data is transmitted synchronously to all configured processors.

However, we haven’t even seen what a processor is so far!

A SpanProcessor is an SDK interface that allows storing an exporter, or any other logic needed to be performed before or after spans are started or stopped:

// SpanProcessor is interface to add hooks to start and end method invocations.
type SpanProcessor interface {

  // OnStart method is invoked when span is started. It is a synchronous call
  // and hence should not block.
  OnStart(parent context.Context, s ReadWriteSpan)

  // OnEnd method is invoked when span is finished. It is a synchronous call
  // and hence should not block.
  OnEnd(s ReadOnlySpan)

  // Shutdown is invoked when SDK shuts down. Use this call to cleanup any processor
  // data. No calls to OnStart and OnEnd method is invoked after Shutdown call is
  // made. It should not be blocked indefinitely.
  Shutdown(ctx context.Context) error

  // ForceFlush exports all ended spans to the configured Exporter that have not yet
  // been exported.  It should only be called when absolutely necessary, such as when
  // using a FaaS provider that may suspend the process after an invocation, but before
  // the Processor can export the completed spans.
  ForceFlush()
}

The idea is that exporters will implement the SpanExporter interface, and be instantiated within the processor:

// SpanExporter handles the delivery of SpanSnapshot structs to external
// receivers. This is the final component in the trace export pipeline.
type SpanExporter interface {
  // ExportSpans exports a batch of SpanSnapshots.
  //
  // This function is called synchronously, so there is no concurrency
  // safety requirement. However, due to the synchronous calling pattern,
  // it is critical that all timeouts and cancellations contained in the
  // passed context must be honored.
  //
  // Any retry logic must be contained in this function. The SDK that
  // calls this function will not implement any retry logic. All errors
  // returned by this function are considered unrecoverable and will be
  // reported to a configured error Handler.
  ExportSpans(ctx context.Context, ss []*SpanSnapshot) error
  // Shutdown notifies the exporter of a pending halt to operations. The
  // exporter is expected to preform any cleanup or synchronization it
  // requires while honoring all timeouts and cancellations contained in
  // the passed context.
  Shutdown(ctx context.Context) error
}

OpenTelemetry includes two default processors: SimpleSpanProcessor and BatchSpanProcessor.

SimpleSpanProcessor will send the span data to the exporter synchronously. So if your exporter needs to make an HTTP call, that will happen synchronously to the method which finished the span:

// OnEnd method exports a ReadOnlySpan using the associated exporter.
func (ssp *SimpleSpanProcessor) OnEnd(s ReadOnlySpan) {
  if ssp.e != nil && s.SpanContext().IsSampled() {
    ss := s.Snapshot()
    if err := ssp.e.ExportSpans(context.Background(), []*export.SpanSnapshot{ss}); err != nil {
      otel.Handle(err)
    }
  }
}

BatchSpanProcessor will enqueue all spans to a channel:

// OnEnd method enqueues a ReadOnlySpan for later processing.
func (bsp *BatchSpanProcessor) OnEnd(s ReadOnlySpan) {
  // Do not enqueue spans if we are just going to drop them.
  if bsp.e == nil {
    return
  }
  bsp.enqueue(s.Snapshot())
}

func (bsp *BatchSpanProcessor) enqueue(sd *export.SpanSnapshot) {
  // [...] Error handling removed for clarity
  // [...] Check to not enqueue if the processor is closed removed

  if bsp.o.BlockOnQueueFull {
    bsp.queue <- sd
    return
  }

  select {
    case bsp.queue <- sd:
    default:
      atomic.AddUint32(&bsp.dropped, 1)
  }
}

Then, in a gorouting started to process that channel. It processes spans asynchronously:

func NewBatchSpanProcessor(exporter export.SpanExporter, options ...BatchSpanProcessorOption) *BatchSpanProcessor {
  // [...] Other initialization code removed

  bsp := &BatchSpanProcessor{
    [...]
  }

  go func() {
    defer bsp.stopWait.Done()
    bsp.processQueue()
    bsp.drainQueue()
  }()

  return bsp
}

// processQueue removes spans from the `queue` channel until processor
// is shut down. It calls the exporter in batches of up to MaxExportBatchSize
// waiting up to BatchTimeout to form a batch.
func (bsp *BatchSpanProcessor) processQueue() {
  defer bsp.timer.Stop()

  for {
    select {
    case <-bsp.stopCh:
      return
    case <-bsp.timer.C:
      bsp.exportSpans()
    case sd := <-bsp.queue:
      bsp.batchMutex.Lock()
      bsp.batch = append(bsp.batch, sd)
      shouldExport := len(bsp.batch) == bsp.o.MaxExportBatchSize
      bsp.batchMutex.Unlock()
      if shouldExport {
        if !bsp.timer.Stop() {
          <-bsp.timer.C
        }
        bsp.exportSpans()
      }
    }
  }
}

This batching logic is pretty great to look at if you’re interested in Go concurrency.

We can see it creates a for/select loop, which pretty standard.
The first case looks whether the processor has stopped, in which case the loop will stop.

The second case will export spans if a timer has been reached. This ensures queued spans are sent at regular intervals.

The last case will fetch any new span, and enqueue them to be batch-sent. Then, if the number of batched spans is higher than a maximum we want to export, it triggers one right away.

So with this batch mechanism, our spans will be exported either at regular interval (5000 milliseconds by default), or when we have too many queued spans.

Configuring the exporter

Let’s look at part of our configuration example from earlier:

// Create and configure our new tracer
tp := sdktrace.NewTracerProvider(
  sdktrace.WithSyncer(logExp),
)

WithSyncer creates a new SimpleSpanProcessor with our exporter, and adds that processor to the TracerProvider’s configuration:

// WithSyncer registers the exporter with the TracerProvider using a
// SimpleSpanProcessor.
func WithSyncer(e export.SpanExporter) TracerProviderOption {
  return WithSpanProcessor(NewSimpleSpanProcessor(e))
}

If we wanted to configure a BatchSpanProcessor instead, we could have used WithBatcher instead:

// WithBatcher registers the exporter with the TracerProvider using a
// BatchSpanProcessor configured with the passed opts.
func WithBatcher(e export.SpanExporter, opts ...BatchSpanProcessorOption) TracerProviderOption {
  return WithSpanProcessor(NewBatchSpanProcessor(e, opts...))
}

Conclusion

I am finding OpenTelemetry to be quite straightforward and nicely thought out. Everything is right where I would expect it to be, which is a quite nice feeling when digging through a codebase.

It is also extremely extensible. It would be very straightforward to write a new TracerProvider, a new Tracer, a new SpanProcessor, or a SpanExporter.
Of course, with great power comes great responsibility. And writing a new TracerProvider is very likely to be an extremely bad idea. But a custom SpanProcessor seems very nice. And if for some reason (say you work at a very large company which uses its own internal metrics platform) you need a custom SpanExporter, that straightforwardness is there too.