在 http.HandleFunc 中记录对传入 HTTP 请求的响应

Logging responses to incoming HTTP requests inside http.HandleFunc

这是对 的 follow-up 问题,因为那里的解决方案需要伪造请求,这对单元测试非常有用,但不适用于实时服务器。

我想将我的 Web 服务返回的 HTTP 响应转储到日志文件(或控制台)中,以响应它从用户收到的请求。输出应该告诉我 headers 是什么以及 JSON 有效负载。

怎么办?

如果有一个 httputil.DumpResponse 等价物接受 http.ResponseWriter 而不是 http.Response 作为参数,那将是完美的,但目前我只能访问 Header http.ResponseWriter

r = mux.NewRouter()
r.HandleFunc("/path", func (w http.ResponseWriter, r *http.Request) {

    fmt.Printf("r.HandleFunc /path\n")

    resp := server.NewResponse()
    defer resp.Close()

    r.ParseForm()

    // Server does some work here
    // ...

    // Insert debug code here, something like
    //
    // dump = http.DumpResponseFromWriter(w)
    // fmt.Printf("%s\n", dump)
});
http.Handle("/path", r)

这可以通过使用自定义 ServerMux 来实现,该自定义 ServerMux 不进行路由,但会替换响应编写器,然后将请求转发到普通的多路复用器。由于 ResponseWriter 只是一个接口,我们可以很容易地伪造它。

首先,我们用我们自己的响应编写器包装 ResponseWriter 接口,它将记录所有内容并将所有功能传递给真正的响应编写器:

type DumpResponseWriter struct {
    // the underlying writer
    w http.ResponseWriter
    // more stuff you want to use for logging context (ip, headers, etc) here
}


func (w *DumpResponseWriter)Header() http.Header {
    return w.w.Header()
}

func (w *DumpResponseWriter)Write(b []byte) (int, error) {
        // You can add more context about the connection when initializing the writer and log it here
        log.Println("Writing < more context details here> ", string(b) )
        return w.w.Write(b)
}


func (w *DumpResponseWriter)WriteHeader(h int) {
    log.Println("Writing Header< more context details here> ", h)
    w.w.WriteHeader(h)
}

这使我们的处理函数与以前相同,并且不知道我们正在使用 "Fake" 编写器这一事实...

func MyHandler(w http.ResponseWriter, r *http.Request) {

    w.Write([]byte("Hello world"))
}

然后我们简单地用我们自己的代理 mux 替换默认的 mux,它替换了 writer 并让常规的 ServeMux 做它的事情:

func main(){

    // we don't use the default mux, but a custom one
    mux := http.NewServeMux()
    mux.HandleFunc("/", MyHandler)

    // now we intercept each request and forward it to the mux to do    the routing to the handlers.
    err := http.ListenAndServe(":1337", http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
    // we wrap the response writer with our own. Add more context here if you want to the writer's instance
        writer := &DumpResponseWriter{w}

        // and we let our ordinary mux take care of things from here
        mux.ServeHTTP(writer, r)

        // We can also dump the headers after the handler is done. It will not print the standard headers though
        log.Printf("Response headers: %#v", w.Header())

    }))
    if err != nil {
        panic(err)
    }
}

http://play.golang.org/p/hT1PCNxI-V

中间件链接

这个问题的一个常见解决方案是所谓的中间件链。有几个库提供此功能,例如negroni.

这是一种连续传递样式,您可以在其中编写 中间件 函数(摘自 negroni 的自述文件):

func MyMiddleware(rw http.ResponseWriter, r *http.Request, next http.HandlerFunc) {
  // do some stuff before
  next(rw, r)
  // do some stuff after
}

然后 negroni 给你一个 HTTP 处理程序,它以正确的顺序调用你的中间件。

我们可以以稍微不同的方式实现此解决方案,而不是采用不那么神奇但更实用(如 函数式编程)的方法。定义处理程序组合器如下:

func NewFooHandler(next http.HandlerFunc) http.HandlerFunc {
    return func(w http.ResponseWriter, r *http.Request) {
        // do some stuff before
        next(r,w)
        // do some stuff after
    }
}

然后将您的链定义为组合:

h := NewFooHandler(NewBarHandler(NewBazHandler(Sink)))

现在 h 是一个 http.HandlerFunc 执行 foo,然后是 bar,然后是 baz。 Sink 只是一个空的最后一个处理程序,它什么都不做(对 "finish" 链。)

将此解决方案应用于您的问题

定义处理程序组合器:

func NewResponseLoggingHandler(next http.HandlerFunc) http.HandlerFunc {
    return func(w http.ResponseWriter, r *http.Request) {

        // switch out response writer for a recorder
        // for all subsequent handlers
        c := httptest.NewRecorder()
        next(c, r)

        // copy everything from response recorder
        // to actual response writer
        for k, v := range c.HeaderMap {
            w.Header()[k] = v
        }
        w.WriteHeader(c.Code)
        c.Body.WriteTo(w)

    }
}

现在问题归结为处理程序管理。您可能希望将此处理程序应用于特定类别中的所有链。为此,您可以再次使用组合器(这有点等同于 negroni 的 Classic() 方法):

func NewDefaultHandler(next http.HandlerFunc) http.HandlerFunc {
    return NewResponseLoggingHandler(NewOtherStuffHandler(next))
}

在此之后,每当您像这样启动链时:

h := NewDefaultHandler(...)

它将自动包含响应日志记录和您在 NewDefaultHandler 中定义的所有默认内容。

使用基于 httptest.ResponseRecorder

的日志记录请求 ID 实施 Mat Ryer 的 approach

使用httptest.ResponseRecorder的缺点:

  • HTTP/1.1 只
  • 不支持 ReadFrom()、Hijack()、Flush() 可能还有其他东西
  • Headers 像 Content-LengthDate 在录音机中不可用

代码:

import (
    "fmt"
    "github.com/google/uuid"
    "log"
    "net/http"
    "net/http/httptest"
    "net/http/httputil"
    "strings"
)

func main() {
    logger := log.New(os.Stdout, "server: ", log.Lshortfile)
    http.HandleFunc("/api/smth", Adapt(smth, httpLogger(quips.logger)))
    panic(http.ListenAndServe(":8080", nil))
}

type Adapter func(http.HandlerFunc) http.HandlerFunc

func Adapt(h http.HandlerFunc, adapters ...Adapter) http.HandlerFunc {
    for _, adapter := range adapters {
        h = adapter(h)
    }
    return h
}

func httpLogger(logger *log.Logger) Adapter {
    return func(h http.HandlerFunc) http.HandlerFunc {
        return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
            dumpBody := true
            if r.ContentLength > 1024 {
                dumpBody = false
            }
            dump, err := httputil.DumpRequest(r, dumpBody)
            if err != nil {
                http.Error(w, fmt.Sprint(err), http.StatusInternalServerError)
                return
            }

            reqId, err := uuid.NewRandom()
            if err != nil {
                http.Error(w, fmt.Sprint(err), http.StatusInternalServerError)
                return
            }

            logger.Printf("<<<<< Request %s\n%s\n<<<<<", reqId.String(), string(dump))

            recorder := httptest.NewRecorder()
            defer func() {
                var sb strings.Builder
                fmt.Fprintf(&sb, "%s %d\n", recorder.Result().Proto, recorder.Result().StatusCode)

                for h, v := range recorder.Result().Header {
                    w.Header()[h] = v
                    for _, headerValue := range v {
                        fmt.Fprintf(&sb, "%s: %s\n", h, headerValue)
                    }
                }
                w.Header().Set("X-Request-Id", reqId.String())
                fmt.Fprintf(&sb, "X-Request-Id: %s\n", reqId.String())
                fmt.Fprintf(&sb, "Content-Length: %d\n", recorder.Body.Len())
                fmt.Fprint(&sb, "\n")
                sb.Write(recorder.Body.Bytes())

                logger.Printf(">>>>> Response %s\n%s\n>>>>>", reqId.String(), sb.String())

                w.WriteHeader(recorder.Result().StatusCode)
                recorder.Body.WriteTo(w)
            }()
            h.ServeHTTP(recorder, r)
        })
    }
}