How to Inject a Logger into Go's HTTP Handlers

Assigning loggers to package-level variables is an anti-pattern. When you declare var log = mylogger.New() in the package namespace, you create a tight compile-time dependency on the particular brand of logger you use. It makes your program brittle, hard to change.

The solution is to pass an interface that describes the capabilities of a compatible logger but ignores its identity until runtime. But what does that look like? Specifically, what does it look like when you want to pass a logger to a function whose signature is not under your control?

The http.HandlerFunc is a type where logging is essential but unintuitive:

type HandlerFunc(ResponseWriter, *Request)

Confronted with this signature, a package-level logger that you can access from inside the HandlerFunc seems like an easy solution, but it’ll come back to bite you as your program evolves. Our mission: to inject a logging interface into something that looks and behaves like the mighty HandlerFunc.

Build Your Own HandlerFactory

First up, the type declarations:

package routing

import (
    "errors"
    "net/http"

    "github.com/gorilla/mux"
)

type logger interface {
    Printf(format string, v ...interface{})
}

type loggingHandlerFunc = func(w http.ResponseWriter, r *http.Request, l logger)

type loggingHandler struct {
    logger
    handlerFunc loggingHandlerFunc
}

The interface logger defines what any logger we choose to inject must be capable of, in this case, Printf. The concrete type of the logger is unimportant; we only care about what it can do.

loggingHandlerFunc is the centrepiece of this solution — a type that looks a lot like http.HandlerFunc but which also accepts an argument that implements our logger interface.

But how do we “forward” an incoming *http.Request to a loggingHandlerFunc? That’s what loggingHandler does. loggingHandler embeds both a logger and a loggingHandlerFunc, and defines a familiar method:

func (lh *loggingHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
    lh.handlerFunc(w, r, lh.logger)
}

Thus, our loggingHandler implements http.Handler, which requires the single method ServeHTTP(w http.ResponseWriter, r *http.Request). We can now pass a *loggingHandler to an http.ServeMux (or any mux package of your choice), and traffic to the route you specify will be passed through the *loggingHandler to the embedded loggingHandlerFunc, picking up a logger along the way.

func homepageHandler(w http.ResponseWriter, r *http.Request, log logger) {
    err := errors.New("This will be logged")
    log.Printf("%-8s %s: %v", "INFO", "homepageHandler", err)
    http.Error(w, http.StatusText(http.StatusInternalServerError),
        http.StatusInternalServerError)
}

However, this approach leads to a lot of manual *loggingHandler creation, and in the likely event that you want to use the same logger across a number of routes, you’ll find yourself repeatedly constructing *loggingHandlers with similar inputs. Let’s streamline this with a factory.

func loggingHandlerFactory(l logger) func(loggingHandlerFunc) *loggingHandler {
    return func(hf loggingHandlerFunc) *loggingHandler {
        return &loggingHandler{l, hf}
    }
}

func Router(l logger) *mux.Router {
    router := mux.NewRouter()
    withLogger := loggingHandlerFactory(l)
    router.Handle("/", withLogger(homepageHandler)).Methods(http.MethodGet)
    return router
}

loggingHandlerFactory takes in a logger and returns a closure that, when called with a loggingHandlerFunc, returns a new *loggingHandler with the correct logger baked in.

Using a loggingHandlerFunc in a route becomes as simple as passing it to the factory. Better yet, the loggingHandlerFuncs you write are embeddable in whatever struct you like, not just the loggingHandler defined here. This configuration is easy to change and has no knock-on effects outside of the package.

That contrasts somewhat with an approach that’s more straightforward but may restrict your freedom to change:

type logger interface {
    Printf(format string, v ...interface{})
}

type loggingHandler struct {
    logger
}

func Router(l logger) *mux.Router {
    router := mux.NewRouter()
    lh := &loggingHandler{l}
    router.HandleFunc("/", lh.homepageHandler).Methods(http.MethodGet)
    return router
}

func (lh *loggingHandler) homepageHandler(w http.ResponseWriter, r *http.Request) {
    err := errors.New("This will be logged")
    lh.Printf("%-8s %s: %v", "INFO", "homepageHandler", err)
    http.Error(w, http.StatusText(http.StatusInternalServerError),
        http.StatusInternalServerError)
}

Here, the loggingHandler embeds only a logger, and plain old http.HandlerFuncs are declared as methods on *loggingHandler, giving them access to its logger field.

I find this easier to intuit, but it binds your http.HandlerFuncs to a single implementation of loggingHandler. If the loggingHandler has to change, it could impact every HandlerFunc attached to it. Contrast this with the first approach, where a loggingHandlerFunc doesn’t care where its logger comes from, only that it’s passed as an argument. It ensures that our package is not just loosely coupled to the outside world, it’s loosely coupled inside too.

Here’s the example in full.

An Honourable(?) Mention

There’s one school of thought that suggests you could stash error events in the Values of a handlerFunc's request Context. When your http.HandlerFuncs return, the one at the top of the chain would be responsible for getting them out again and logging a unified report about everything that happened during the request.

There’s another school that would have me hunted for suggesting it to you.

The first contention is that Values is an amorphous sack of interface{}: interface{} pairs that invite a wealth of lurking bugs through the type assertions required to get data out again. The second is that having this bag of formless data persist for the lifetime of the request amounts to thread-local storage, which is inimical to the Go concurrency model.

Nevertheless, if you’re curious about how such heresy would be implemented (I know, you’re asking for a friend), Peter Bourgon’s ctxdata is the code to see.

The debate surrounding logging in Go is fascinating (no, really). I highly recommend catching up on it.

Thanks go to Dave Cheney and Peter Bourgon for their help in wrapping my head around this.