Beginner’s Guide to Jaeger + OpenTracing Instrumentation for Go

Instrumenting Jager for Golang

This post aims to provide a very simple beginner’s guide to Jaeger + OpenTracing instrumentation for Go applications (the terms “application” and “service” is used interchangeably in this document) via a working example. If you are new to instrumentation, I recommend that you first read this post for a practical introduction to instrumentation for Jaeger and OpenTracing. You can also get more info on using logs in Go.

This post covers the following topics:

  • Instrumenting Go applications with OpenTracing
  • How to provide the Jaeger tracer (or other concrete tracers) implementing OpenTracing’s APIs
  • Key instrumentation concepts:
    • Starting and finishing spans
    • Injecting and extracting span context into/from requests

The Example

In this example, “service-a” calls “service-b”. The services listen on ports 8081 and 8082, respectively.

The services each have a “/ping” endpoint. This endpoint returns a string response of its own service name that is joined with its downstream response (if there is one). If not, the endpoint simply returns its own service name.

A curl command is used to initiate the “/ping” call to “service-a”, which then calls the “/ping” endpoint of “service-b”.

The expected output after running curl http://localhost:8081/ping is:

service-a -> service-b

Getting Started with Go Instrumentation

The complete example is available on Github.

$ git clone git@github.com:albertteoh/jaeger-go-example.git
$ cd jaeger-go-example

# Start Jaeger all-in-one and microservices
$ make start

# Hit the service-a endpoint to generate the trace
$ curl -w ‘\n’ http://localhost:8081/ping
service-a -> service-b

# Validate everything using the steps in the following section
# Stop and cleanup docker containers
$ make stop

If you could see the output service-a -> service-b, then great! We know the services are running and talking to each other successfully.

Validate the Example

Jaeger UI

The best way to validate that our services are correctly instrumented and Jaeger actually received these spans correctly is to check the Jaeger UI!

Head over to http://localhost:16686. You should see Jaeger’s home screen, consisting of a search page with input fields in the left search pane.

Under “Service”, find and select service-a (you may need to refresh the page if you don’t see it), then click , which displays the trace that we just generated from the curl command:

When we drill down into this trace, we can see the spans and their relationships to each other. Note the highlighted trace-id and span-ids:

..

Code Walkthrough

Having seen the services running and the trace we just produced in Jaeger UI, we can take a deeper dive into the source code to understand what’s required to instrument Go applications.

service-a.go

tracer, closer := tracing.Init(thisServiceName)
defer closer.Close()
opentracing.SetGlobalTracer(tracer)

http.HandleFunc("/ping", func(w http.ResponseWriter, r *http.Request) {

  span := tracing.StartSpanFromRequest(tracer, r)
  defer span.Finish()

  ctx := opentracing.ContextWithSpan(context.Background(), span)
  ... 

We first initialize our OpenTracing-compliant tracer implementation (in our case, Jaeger) and ensure that the tracer is closed, to flush out any spans that need reporting, etc.

In order for the tracer to be accessible everywhere without significant code changes (via  GlobalTracer()), SetGlobalTracer is called.

If this isn’t done, the SDK will use a “NoopTracer” which does not send spans, and we would not see traces/spans in Jaeger UI.

Within the http.HandlerFunc, a new span is created and started based on the incoming request so that causality relationships (parent-child) are correctly set. That is, this HTTP request handler span is a child of the upstream caller who made the HTTP request. We’ll go into more detail into what StartSpanFromRequest does later on. Conventionally, this span is called the “server” span.

The astute reader will notice that this is the first span created and hence, has no parent span. This is called the “root” span.

The call to defer span.Finish() is very important, which closes the span and emits it to the agent/collector. Without this call, we would not see traces/spans in Jaeger UI.

When making a downstream call to service-b, a new context instance is created using the ContextWithSpan function which copies the “server” span’s details into the new context. This is very important, as it ensures the continued lineage of parent-child relationships between the “server” span and downstream outbound HTTP requests to service-b/ping. This new span for the downstream call is, by convention, called a “client” span.

There’s a lot going on in the above explanation. The following diagram aims to diagrammatically summarize when tracers and spans are created along with how they relate to each other.

tracing/init.go

In service-a, tracing.Init(...) is called to initialize a new tracer that implements the OpenTracing API. In this case, it creates and initializes an instance of the Jaeger Tracer.

func Init(service string) (opentracing.Tracer, io.Closer) {
  cfg := &config.Configuration{
     ServiceName: service,
     Sampler: &config.SamplerConfig{
        Type:  "const",
        Param: 1,
     },
     Reporter: &config.ReporterConfig{
        LogSpans: true,
     },
  }
  tracer, closer, err := cfg.NewTracer(config.Logger(jaeger.StdLogger))
  ...
}

We first configure the Tracer with the service name (e.g. service-a or service-b), tell is to always sample (“const”: 1) and log the span identity when emitted for diagnostic purposes (LogSpans: true).

ping/ping.go

This provides the “Ping” function used by our services to make outbound calls to downstream services. Specifically, the “Ping” function is what service-a uses to call service-b’s /ping endpoint as we saw earlier.

func Ping(ctx context.Context, hostPort string) (string, error) {
  span, _ := opentracing.StartSpanFromContext(ctx, "ping-send")
  defer span.Finish()
  ...

  if err := tracing.Inject(span, req); err != nil {
  ...
}

Firstly, a new child span is created with the operation name ping-send, using the caller’s context to establish a causal relationship with the caller (the parent span); that is, the caller of this Ping function.

As we learned earlier, it is very important to ensure span.Finish() is called to ensure it is emitted.

tracing/span.go

tracing.StartSpanFromRequest(...) is a convenience function used by our services to start a new span as soon as the HTTP request is handled.

func StartSpanFromRequest(tracer opentracing.Tracer, r *http.Request) opentracing.Span {
  spanCtx, _ := Extract(tracer, r)
  return tracer.StartSpan("ping-receive", ext.RPCServerOption(spanCtx))
}

The parent span context is first extracted from the inbound HTTP request, then a new child or root (if no parent) span is created with the operation name “ping-receive”.

ext.RPCServerOption(spanCtx) tells the tracer to make the new span a ChildOf the parent span and set this child span.kind tag to “server”, then return the new child span to the function caller. The latter tag is some additional metadata on the span indicating if it is handling inbound RPC requests (“server”) or sending outbound RPC requests to downstream services (“client”). This is particularly useful for some Jaeger UI features such as the System Architecture diagram.

Additionally, StartSpan does a few other important things:

  • Randomly generates a 64-bit SpanID and assigns this to the newly created span.
  • If the HTTP request header contained no span context information, this span is a root span, and hence, its SpanID is used as the TraceID.
  • Makes a sampling decision (head-based sampling), where the decision is stored in the Span itself.

tracing/interceptors.go

There were a couple of references earlier to Inject and Extract functions.

func Inject(span opentracing.Span, request *http.Request) error {
  return span.Tracer().Inject(
     span.Context(),
     opentracing.HTTPHeaders,
     opentracing.HTTPHeadersCarrier(request.Header))
}

func Extract(tracer opentracing.Tracer, r *http.Request) (opentracing.SpanContext, error) {
  return tracer.Extract(
     opentracing.HTTPHeaders,
     opentracing.HTTPHeadersCarrier(r.Header))
}

The Inject function adds the current span context to the HTTP request header before the request is sent.

The downstream services that receive the request can then associate the resulting spans as children of the current span.

On receiving the incoming RPC request, the Extract function obtains the injected span context from the HTTP header.

Conclusion

Congratulations!  You’ve made it this far, so you should have no troubles instrumenting (and troubleshooting) your Go application.

More precisely, we have covered:

  • How to instrument Go applications with OpenTracing.
  • How to provide a concrete tracer, such as Jaeger, that implements OpenTracing’s APIs.
    • Exercise: could you see any Jaeger-specific references anywhere outside of tracing/init.go?
  • Key instrumentation concepts:
    • Starting & Finishing spans
    • Injecting & Extracting span context
  • How to validate our instrumentation by:
    • Checking the Jaeger UI and understanding how to find traces

For a more comprehensive coverage of other Jaeger client features such as logging, and baggage, refer to Yuri’s excellent github tutorial on Jaeger instrumentation which you can find in the additional references below. It covers a number of other languages besides Go.

Get started for free

Completely free for 14 days, no strings attached.