Tracing in Go
by January 21, 2014

Filed under: Performance Monitoring

AppNeta no longer blogs on DevOps topics like this one.

Feel free to enjoy it, and check out what we can do for monitoring end user experience of the apps you use to drive your business at www.appneta.com.

Hey!  Before you read the following post, you should know that we now have official Golang support.  The following examples are deprecated.

Dave’s explorations turned into monitoring that we now use on a large part of our infrastructure, and we’ve opened it up to our customers as well.

 

The original post

Over the past couple of months, I have been experimenting with Go in my spare time.  It interests me due to its strong concurrency support, concise syntax, overall performance, fast compilation, and ease of deployment through statically linked binaries.  It also has a standard library that makes it well suited to building server-side applications.

I wondered, how would we trace a Go application? Tracing allows us to follow requests through a distributed system, through the generation of metadata (events). Events are generated as the request traverses the various layers that make up a web application: HTTP server, app server, DB calls, etc. More detailed explanation can be found in a previous blog post describing X-Trace.

Though TraceView doesn’t directly support Go, we do have a C library that exists at the core of most of our instrumentation. This library implements X-Trace, allowing events to be sent and processed by TraceView.  This seemed like a perfect opportunity to learn more about Go’s support for C and hopefully prototype some instrumentation.

Calling C From Go

Using “cgo”, C code can be included in a Go module by placing the C code in a comment block, then immediately importing a pseudo-package named “C”.  References to C types and functions can then be made from within Go code by prefixing it with “C.”  Shared libraries and other linker-related parameters can be specified through #cgo preprocessor directives.  A small example from https://github.com/appneta/go-traceview/blob/master/traceview/context.go :

/*
#cgo pkg-config: openssl
#cgo LDFLAGS: -loboe
#include <stdlib.h>
#include <oboe/oboe.h>
*/
import "C"

type Context struct {
    metadata C.oboe_metadata_t
}

func NewContext() *Context {
    ctx := &Context{}
    C.oboe_metadata_init(&ctx.metadata)
    C.oboe_metadata_random(&ctx.metadata)
    return ctx
}

This code references the liboboe shared library and header file, which is installed during TraceView instrumentation, as part of the liboboe-dev package (under Debian/Ubuntu) and liboboe-devel package (under Redhat/CentOS.)  It defines a Go function that initializes a metadata structure using C function calls.  This metadata structure contains the X-Trace task and operation identifiers, which are used to identify events during instrumentation and is required by most other calls in the oboe library.

While the liboboe library is not publicly documented (yet!), there are public data structures and functions defined in oboe.h. And by taking a look at AppNeta’s open source projects, such as the Ruby instrumentation (specifically the SWIG wrappers), it is possible to figure out what you need to call.  I was able to wrap enough of the C library to allow for basic, low-level instrumentation support from within Go: sending events, metadata (X-Trace ID), and context management.

Instrumenting an HTTP server

With low-level support in place, I was set to move on to higher level instrumentation. I felt a good place to start would be HTTP support. Go includes the “net/http” package for implementing web servers, and there are many third party web app libraries and frameworks that use this package as a foundation. The package supports the concept of a handler, which ties a URL path to a function that processes a request and generates a response.

I wanted to write a wrapper that would take an existing handler and add instrumentation to it, with minimal code changes.

The goal would be to change this:

http.HandleFunc("/", hello_handler)

into this:

http.HandleFunc("/", traceview.InstrumentedHttpHandler(hello_handler))

InstrumentedHttpHandler takes a handler function, and returns a new handler function that sends an entry event, calls the original handler, then sends an exit event.  These events contain information about the HTTP request and response, such as method, URL path, query string, host header, status code, etc.  The HTTP response also contains an X-Trace header that can be used by a calling layer, such as a front-end web or proxy server, to tie the Go HTTP call to the rest of the request.  Code for this function is available at https://github.com/appneta/go-traceview/blob/master/traceview/http_instrumentation.go

Challenges

One key piece of data we like to provide with our HTTP instrumentation is the status code. This allows us to detect if a request was processed normally (“200”), a redirect (“301”, “302”), or error (“500”), etc.

Go did not provide a direct way to read a status code from the HTTP response interface, only write it. To figure out how to read the status code, I had to dig around a bit in the internals of the net/http server code.  I found that the status code  was available in a private structure. Unfortunately, since this data is private, I could not simply read it from our instrumentation code.

However, using reflection, which allows us to inspect and manipulate objects at run time, I was able to access it indirectly.  We are able to examine the structure associated with the response interface and retrieve the status field based on name. Example code:

func getStatusCode(w http.ResponseWriter) int64 {
    var status int64 = -1

    ptr := reflect.ValueOf(w)
    if ptr.Kind() == reflect.Ptr {
        val := ptr.Elem()
        if val.Kind() == reflect.Struct {
            field := val.FieldByName("status")
            if field.Kind() == reflect.Int {
                status = field.Int()
            }
        }
    }
    return status
}

It was interesting looking through the server code, and figuring out how to retrieve this value. Developing instrumentation is full of these sorts of puzzles, which is what makes it challenging.

Try it Out

The code is available on GitHub at https://github.com/appneta/go-traceview

To install, you should first sign up for a TraceView account, if you don’t have one already.

Follow the instructions during signup to install the Host Agent (“tracelyzer”). This will also install the liboboe and liboboe-dev dependencies.

Then, install the following (which assumes you are running Ubuntu/Debian):

If all goes well, you can run the sample “web app” included with go-traceview:

cd $GOPATH/src/github.com/appneta/go-traceview/sample_app
go run main.go

A web server will run on port 8899. It doesn’t do much, except wait a bit and echo back your URL path:

$ curl http://localhost:8899/hello
Slow request... Path: /hello

You will see these requests appear on your TraceView dashboard.   If you want to get fancy, you can set up nginx or Apache in front of this web server to proxy requests. You’ll then be able to see requests that flow through a front-end web server before being processed by Go. This generates traces that look like this:

monitoring golang

Next Steps

Though this is just a prototype, it shows that we can easily integrate TraceView with Go.  Future work could involve instrumenting some higher level web frameworks, by wrapping those handlers.

One thing we have not addressed is how to manage the context, which stores the trace task ID and event ID associated with the current request.  In this prototype, the context only exists inside the wrapped HTTP handler, meaning it would not be available to other calls occurring during the request. This makes it difficult to develop deeper instrumentation.

In other languages, we typically achieve this by storing the context in a thread-local variable (either with pthreads or Java thread locals.) Thread local variables are not available in Go, and since it does its own lightweight threading using “go routines”, we cannot use pthread thread locals from C in this way.  One approach we could take is storing the context by HTTP request and look it up, though this assumes the HTTP request is always available from the caller, which may be too simplistic. Another approach would be to modify the Go runtime to keep track of the context. This sounds quite complicated, though we have done similar work in other environments (such as gevent.)

All in all, this was a fun prototype to develop!

  • Looks interesting, I’ll be following your blog. Have been experimenting with Golang these past years.