Instrumenting a Go application with Zipkin

With the proliferation of microservices, observability got a crucial role in operations and one of the observability means that got more exposure lately was Distributed Tracing.

If you don’t know what it is or, more important, what problem it solves you can watch the talk I gave at microXchg 2018 about the topic:

Slides available at https://speakerdeck.com/jcchavezs/distributed-tracing-understand-how-your-components-work-together

TL;DW: Distributed tracing helps engineering teams with distributed systems to understand their architecture, critical paths for a request across services and observe latencies, it also helps to observe real production requests to understand errors.

A very common question about tracing is how to instrument an application (i.e. how to add observability means to your application). Instrumentation usually starts by adding tracing to common pieces in the code: RPC framework or routing middlewares.

Instrumentation with Zipkin

Before we jump into the actual code I’d mention a couple of rules of thumb for instrumenting applications:

  • As an habit, pass the context.Context as the first parameter in your functions. This is not only a good practice in go but also allow tracer to retrieve information from upper level spans down in the stack.
  • Start with common frameworks (RPC frameworks, HTTP middlewares, etc.), that would make it easier to plug tracing into existing applications.
  • Make all attempts possible to be transparent with regards to library usage: 1. create wrappers (or decorators) that implement the same interface as the originals 2. try to use existing hooks like middlewares or handlers. That would me it easier the adoption.
  • It is discouraged to instrument business logic (domain nor application logic), all tracing data should come from infrastructure.
  • It should not affect the normal flow of the application, errors from instrumentation code should not affect the function’s original output.
  • It should be optimized to add the least overhead possible otherwise you end up in the observer effect.

That said, it is important to differentiate the two main pieces to be instrumented:

In process tracing: Operations taking place inside the service. The most common one is a request being served from the application.

Outbound tracing: Calls to external resources. Most common ones are RPC calls or database operations.

In this example we will instrument a request and a HTTP call to an external resource. We will use the brand new zipkin-go official library.

The first step is to create a tracer instance:

package main

import (
"github.com/openzipkin/zipkin-go"
"github.com/openzipkin/zipkin-go/model"
reporterhttp "github.com/openzipkin/zipkin-go/reporter/http"
)

const endpointURL = "http://localhost:9411/api/v2/spans"

func newTracer() (*zipkin.Tracer, error) {
// The reporter sends traces to zipkin server
reporter := reporterhttp.NewReporter(endpointURL)

// Local endpoint represent the local service information
localEndpoint := &model.Endpoint{ServiceName: "my_service", Port: 8080}

// Sampler tells you which traces are going to be sampled or not. In this case we will record 100% (1.00) of traces.
sampler, err := zipkin.NewCountingSampler(1)
if err != nil {
return nil, err
}

t, err := zipkin.NewTracer(
reporter,
zipkin.WithSampler(sampler),
zipkin.WithLocalEndpoint(localEndpoint),
)
if err != nil {
return nil, err
}

return t, err
}

Once the tracer is in place, we need to add a middleware to the router in order to trace incoming requests. In this case we will use gorilla/mux but the middleware is a http.Handler implementation so it should work in any other router.

package main

import (
"log"
"net/http"

"github.com/gorilla/mux"
"github.com/openzipkin/zipkin-go"
zipkinhttp "github.com/openzipkin/zipkin-go/middleware/http"
)

var tracer *zipkin.Tracer

func main() {
tracer, err := newTracer()
if err != nil {
log.Fatal(err)
}

r := mux.NewRouter()
r.HandleFunc("/foo", FooHandler)
r.Use(zipkinhttp.NewServerMiddleware(
tracer,
zipkinhttp.SpanName("request")), // name for request span
)
log.Fatal(http.ListenAndServe(":8080", r))
}

func FooHandler(w http.ResponseWriter, r *http.Request) {
w.WriteHeader(http.StatusOK)
}

At this point, we should be able to see traces for our requests in zipkin. You can start the zipkin collector by running:

docker run -d -p 9411:9411 openzipkin/zipkin

Once the service is up, if you curl -i http://localhost:8080 you should be able to start a trace for the request received by the router.

The next big piece to be instrumented is a HTTP call to an external service. For that we should first abstract the HTTP call.

package main

import (
"context"
neturl "net/url"

"fmt"
"io"
"net/http"

"github.com/openzipkin/zipkin-go"
)

var tracer *zipkin.Tracer

// It is important to propagate the context down to this call
// because this allows tracer to know that the span being created
// for the HTTP call is a child of the span created when parsing
// the request
func Post(ctx context.Context, url string, contentType string, body io.Reader) (resp *http.Response, err error) {
// By default, the span name is the http method for the request
span, _ := tracer.StartSpanFromContext(ctx, http.MethodPost)
defer span.Finish()

u, err := neturl.Parse(url)
span.Tag(string(zipkin.TagHTTPMethod), http.MethodPost)
span.Tag(string(zipkin.TagHTTPPath), u.Path)

res, err := http.DefaultClient.Post(url, contentType, body)
if err != nil {
span.Tag(string(zipkin.TagError), err.Error())
return nil, err
}

span.Tag(string(zipkin.TagHTTPStatusCode), fmt.Sprint(res.StatusCode))
if res.StatusCode > 399 {
span.Tag(string(zipkin.TagError), fmt.Sprint(res.StatusCode))
}

return res, err
}

And finally we just need to use this instrumented Post function in one of our handlers:

package main

import (
"bytes"
"net/http"
)

func HomeHandler(w http.ResponseWriter, r *http.Request) {
body := bytes.NewBufferString("")
res, err := Post(r.Context(), "http://example.com", "application/json", body)
if err != nil {
w.WriteHeader(http.StatusInternalServerError)
return
}

if res.StatusCode > 399 {
w.WriteHeader(http.StatusInternalServerError)
return
}

w.WriteHeader(http.StatusOK)
}

That’s it. Now you are ready to see your data in zipkin (http://localhost:9411).

“request” one span for the request received and one for the request made.

If you have any doubt on how to use zipkin-go I strongly recommend you to head to the gitter channel where a great community will help you out with the library usage.

What else can I do?

You can improve the instrumentation by using meaningful span names, a common practice among zipkin instrumentations is to use the http.route i.e. the pattern declared in the route. For example GET /foo/{user_id} instead of request :

package main

import (
"context"
"net/http"

"github.com/gorilla/mux"
"github.com/openzipkin/zipkin-go"
)

// ZipkinHTTPRoute sets http.route if a span and gorilla mux
// template path are found.
func ZipkinHTTPRoute(ctx context.Context, r *http.Request) context.Context {
if span := zipkin.SpanFromContext(ctx); span != nil {
if route := mux.CurrentRoute(r); route != nil {
if routePath, err := route.GetPathTemplate(); err == nil {
zipkin.TagHTTPRoute.Set(span, routePath)
span.SetName(r.Method + " " + routePath)
}
}
}
return ctx
}

Enjoy!