Request logging middleware

requestlog.go

package handlers

import (
	"fmt"
	"log"
	"net/http"
	"os"
	"time"
)

type responseLogger struct {
	w      http.ResponseWriter
	status int
	size   int
}

func (r *responseLogger) Header() http.Header {
	return r.w.Header()
}

func (r *responseLogger) Write(b []byte) (int, error) {
	if r.status == 0 {
		// Status will be StatusOK if WriteHeader not called yet
		r.status = http.StatusOK
	}

	size, err := r.w.Write(b)
	r.size += size
	return size, err
}

func (r *responseLogger) WriteHeader(s int) {
	r.w.WriteHeader(s)
	r.status = s
}

func (r *responseLogger) Status() int {
	return r.status
}

func (r *responseLogger) Size() int {
	return r.size
}

// RequestLogHandler logs request to output logger using Apache Combined Log Format
//
// Log Format:
//   [:req-id] :remote-addr - :remote-user [:date[clf]] ":method :url HTTP/:http-version" :status :res[content-length] ":referrer" ":user-agent" :response-time ms
//
// Example log line:
//      [dc6efe7f-cfe7-418c-baa3-7c0f80334572] 127.0.0.1 - frank [10/Oct/2000:13:55:36 -0700] "GET /apache_pb.gif HTTP/1.0" 200 2326 "http://www.example.com/start.html" "Mozilla/4.08 [en] (Win98; I ;Nav)" 237ms
//
// References:
//     https://httpd.apache.org/docs/1.3/logs.html
func RequestLogHandler(h http.Handler, out *log.Logger) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		start := time.Now()
		rw := &responseLogger{w: w}
		h.ServeHTTP(rw, r)
		line := logLine(r, start, time.Since(start), rw.Status(), rw.Size())
		out.Print(line)
	})
}

// RequestLogDefaultHandler logs requests to the standard logger.
func RequestLogDefaultHandler(h http.Handler) http.Handler {
	// Standard logger configuration
	logger := log.New(os.Stderr, "", 0)
	return RequestLogHandler(h, logger)
}

// logLine formats a line for printing to the log
// Log Format:
//   [:req-id] :remote-addr - :remote-user [:date[clf]] ":method :url HTTP/:http-version" :status :res[content-length] ":referrer" ":user-agent" :response-time ms
func logLine(r *http.Request, start time.Time, reqtime time.Duration, status, contentLength int) string {
	rid := r.Header.Get("X-Request-ID")
	if rid != "" {
		rid = fmt.Sprintf("[%s] ", rid)
	}

	raddr := r.Header.Get("X-Forwarded-For")
	if raddr == "" {
		raddr = r.RemoteAddr
	}

	ruser := "-"
	startstr := start.Format("02/01/2006:15:04:05 -0700")
	method := r.Method
	url := r.URL.String()
	proto := r.Proto
	referrer := "-"
	userAgent := "-"

	return fmt.Sprintf("%s%s - %s [%s] \"%s %s %s\" %d %d %s %s %s",
		rid, raddr, ruser, startstr, method, url, proto,
		status, contentLength, referrer, userAgent, reqtime)
}