5

Premise: I've found a similar issue but not working in my case, so please do not mark this as a duplicate.

I've a HTTP server in Go and I've created a middleware to log the request, the response time and I would like to log the response too.

I've used httputil.DumpRequest in a function called HTTPRequest under the package log. How can I correctly get the response body and status and headers from the w http.ResponseWriter and log them together with the other data?

My ISSUE is: I would like to intercept the Response Headers, Status and Body and to log the together with the Request and Response Time

Here's the code:

log "core/logger"
...
func RequestLoggerMiddleware(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        start := time.Now()

        defer func() {
            log.Info(
                fmt.Sprintf(
                    "[Request: %s] [Execution time: %v] [Response: %s]",
                    log.HTTPRequest(r),
                    time.Since(start),
                    // RESPONSE DATA HERE !!!!!!!
                ))
        }()
        next.ServeHTTP(w, r)
    })
}
Alessandro Argentieri
  • 2,901
  • 3
  • 32
  • 62

2 Answers2

10

Thanks, @Sivachandran for the response. It was almost perfect, only it didn't implement the http.ResponseWriter because of the pointers.

For the sake of completeness, I post here the correct solution code, because it's not easy to find any documentation on it, even if this question has been given a negative score.

Stackoverflow is a good place to exchange questions and this, in my opinion, was a very good and difficult question, either for a middle lever Golang programmer, so it didn't deserve a negative score at all!

That's the solution, enjoy:

// RequestLoggerMiddleware is the middleware layer to log all the HTTP requests
func RequestLoggerMiddleware(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        start := time.Now()
        rww := NewResponseWriterWrapper(w)
        w.Header()
        defer func() {
            log.Info(
                fmt.Sprintf(
                    "[Request: %s] [Execution time: %v] [Response: %s]",
                    log.HTTPRequest(r),
                    time.Since(start),
                    rww.String(),
                ))
        }()
        next.ServeHTTP(rww, r)
    })
}

// ResponseWriterWrapper struct is used to log the response
type ResponseWriterWrapper struct {
    w          *http.ResponseWriter
    body       *bytes.Buffer
    statusCode *int
}

// NewResponseWriterWrapper static function creates a wrapper for the http.ResponseWriter
func NewResponseWriterWrapper(w http.ResponseWriter) ResponseWriterWrapper {
    var buf bytes.Buffer
    var statusCode int = 200
    return ResponseWriterWrapper{
        w:          &w,
        body:       &buf,
        statusCode: &statusCode,
    }
}

func (rww ResponseWriterWrapper) Write(buf []byte) (int, error) {
    rww.body.Write(buf)
    return (*rww.w).Write(buf)
}

// Header function overwrites the http.ResponseWriter Header() function
func (rww ResponseWriterWrapper) Header() http.Header {
    return (*rww.w).Header()

}

// WriteHeader function overwrites the http.ResponseWriter WriteHeader() function
func (rww ResponseWriterWrapper) WriteHeader(statusCode int) {
    (*rww.statusCode) = statusCode
    (*rww.w).WriteHeader(statusCode)
}

func (rww ResponseWriterWrapper) String() string {
    var buf bytes.Buffer

    buf.WriteString("Response:")

    buf.WriteString("Headers:")
    for k, v := range (*rww.w).Header() {
        buf.WriteString(fmt.Sprintf("%s: %v", k, v))
    }

    buf.WriteString(fmt.Sprintf(" Status Code: %d", *(rww.statusCode)))

    buf.WriteString("Body")
    buf.WriteString(rww.body.String())
    return buf.String()
}
Alessandro Argentieri
  • 2,901
  • 3
  • 32
  • 62
4

You need to wrap the ResponseWriter to capture the response data.

type ResponseWriterWrapper struct {
  w           http.ResponseWriter
  body        bytes.Buffer
  statusCode  int
}

func (i *ResponseWriterWrapper) Write(buf []byte) (int, error) {
  i.body.Write(buf)
  return i.w.Write(buf)
}

func (i *ResponseWriterWrapper) WriteHeader(statusCode int) {
  i.statusCode = statusCode
  i.w.WriteHeader(statusCode)
}

func (i *ResponseWriterWrapper) String() {
  var buf bytes.Buffer

  buf.WriteString("Response:")

  buf.WriteString("Headers:")
  for k, v := range i.w.Header() {
    buf.WriteString(fmt.Sprintf("%s: %v", k, v))
  }

  buf.WriteString(fmt.Sprintf("Status Code: %d", i.statusCode))

  buf.WriteString("Body")
  buf.WriteString(i.body.String())
}

Pass the wrapper to ServeHTTP and log captured response data.

func RequestLoggerMiddleware(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        start := time.Now()
        rww := ResponseWriterWrapper{ w: w }

        defer func() {
            log.Info(
                fmt.Sprintf(
                    "[Request: %s] [Execution time: %v] [Response: %s]",
                    log.HTTPRequest(r),
                    time.Since(start),
                    log.Info(rww.String())
                ))
        }()
        next.ServeHTTP(rww, r)
    })
}
Sivachandran
  • 787
  • 7
  • 21