net/http/httptrace: add ServerTrace hooks

[joeshaw]

Problem

A very common pattern in Go HTTP servers is to implement an http.ResponseWriter that wraps another http.ResponseWriter and captures the status code. This is often used for logging and metrics collection.

For example,

type statusCaptureWriter struct {
    http.ResponseWriter
    status int
}

func (scw *statusCaptureWriter) WriteHeader(status int) {
    scw.status = status
    scw.ResponseWriter.WriteHeader(status)
}

type loggedHandler struct {
    handler http.Handler
    logger SomeLogger
}

func (h *loggedHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
    scw := &statusCaptureWriter{ResponseWriter: w}
    h.handler.ServeHTTP(scw, r)
    h.logger.Logf("status=%d ...", scw.status)
}

I've written something like this a bunch of times. You can find examples in nearly every Go web framework out there. One example is https://github.com/urfave/negroni/blob/master/response_writer.go#L13-L26.

There are some issues with this approach. For instance, my statusCaptureWriter doesn't implement other interfaces like http.Flusher, http.CloseNotifier or http.Pusher. I can't determine at compile time whether the underlying http.ResponseWriter implementation implements any of these interfaces, so if I choose to implement them I might lie to callers at higher levels of the stack and inadvertently break things. (This particularly a problem with CloseNotifier.)

Proposal (rejected, see below)

I'd like to propose an additional interface, http.Statuser (better name welcome) that exposes the status code within a http.ResponseWriter implementation. The internal http.(*response) implementation already tracks the status code written, so this can just be exposed and it will automatically implement this interface.

Software could avoid wrapping the http.ResponseWriter by instead type asserting it to http.Statuser and getting the status as needed there. (And it could optionally continue to wrap the ResponseWriter as needed until this is widely deployed.)

type loggedHandler struct {
    handler http.Handler
    logger SomeLogger
}

func (h *loggedHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
    // Could check for http.Statuser implementation here and wrap http.ResponseWriter 
    // if necessary, but omitting for brevity

    h.handler.ServeHTTP(w, r)

    status := 0
    if s, ok := w.(http.Statuser); ok {
        status = s.Status()
    }

    h.logger.Logf("status=%d ...", status)
}

Alternative proposal

Implement an httptrace.ServerTrace struct that is analogous to the ClientTrace already there. See #18997 (comment) for more info.

[joeshaw]

More examples:

https://github.com/gobuffalo/buffalo/blob/5b5e01469cfd064cad0a56b1eee4728a41d2ec46/response.go

https://github.com/gin-gonic/gin/blob/2dae550eb5392006a4582ce9c90016a9b5a74e8b/response_writer.go#L19-L48

https://github.com/goji/glogrus2/blob/master/writer_proxy.go

https://github.com/rikonor/go-status-code-tracker

[bradfitz]

These exist apparently, but why?

Code should know what it did previously.

[joeshaw]

@bradfitz The example I posted is a simplified instance: you create a wrapper that handles logging of all requests and then the individual handlers don't need to do or understand logging themselves. They are free to just call w.WriteHeader(http.StatusOK) and things get logged at a higher level. This plays nicely with middleware, too.

Other things that might get logged there are the URL/path, the duration of the call, etc. It would be a pain to have to do that at essentially every exit site of every middleware or handler. I think it's also a valid separation of concerns.

[joeshaw]

Another example beyond logging is collection of metrics. You need to know when you serve 5xx errors, for instance. Again, you don't necessarily want to be doing this everywhere it happens (and in the case of panics, I'm not sure offhand it's possible.)

[bradfitz]

Rather than a dozen optional methods, then, I'd prefer to see something like a State() method that returned a concrete struct type to which we could add fields over time.

[gopherbot]

CL https://golang.org/cl/36647 mentions this issue.

[urandom]

Given that the primary target of this feature is logging, I suggest that the length of the response body would be a good addition to the output of State()

[bradfitz]

What if we just provide one canonical ResponseWriter wrapper instead?

And if this is about logging, we should (re-)consider the HTTP logging issues/proposals.

[joeshaw]

@bradfitz the thing that worries me about providing a wrapper type is also wrapping the other interfaces that may optionally be supported by the underlying type. For instance, http.Pusher is something that's only supported by the http2 ResponseWriters. This wrapper type either has to eschew support for Pusher or it has to "lie" about supporting it.