l.go

package main

import (
	"bytes"
	"log"
	"net/http"
	"os"
	"time"

	"github.com/pressly/chi"
	"github.com/pressly/chi/middleware"
)

func main() {
	r := chi.NewRouter()

	r.Use(middleware.RequestID)
	r.Use(Logger)

	r.Get("/", func(w http.ResponseWriter, r *http.Request) {
		w.Write([]byte("welcome"))
	})
	http.ListenAndServe(":3333", r)
}

//------

var LoggerCtxKey = &contextKey{"Logger"}

var (
	defaultLogger = FormattedLogger(&DefaultLogger{logger: log.New(os.Stdout, "", 0)})
)

func Logger(next http.Handler) http.Handler {
	return defaultLogger(next)
}

func FormattedLogger(f LogFormatter) func(next http.Handler) http.Handler {
	return func(next http.Handler) http.Handler {
		fn := func(w http.ResponseWriter, r *http.Request) {
			logger := f.NewLogEntry(r)
			lw := wrapWriter(w)

			t1 := time.Now()
			defer func() {
				t2 := time.Now()
				logger.Write(lw.Status(), lw.BytesWritten(), t2.Sub(t1))
			}()

			next.ServeHTTP(lw, r)
		}
		return http.HandlerFunc(fn)
	}
}

type LogFormatter interface {
	NewLogEntry(r *http.Request) LogEntry
}

type LogEntry interface {
	Write(status, bytes int, elapsed time.Duration)
}

type DefaultLogger struct {
	logger *log.Logger
}

func (l *DefaultLogger) NewLogEntry(r *http.Request) LogEntry {
	entry := &defaultLoggerEntry{DefaultLogger: l, buf: &bytes.Buffer{}}

	reqID := middleware.GetReqID(r.Context())
	if reqID != "" {
		cW(entry.buf, nYellow, "[%s] ", reqID)
	}
	cW(entry.buf, nCyan, "\"")
	cW(entry.buf, bMagenta, "%s ", r.Method)

	scheme := "http"
	if r.TLS != nil {
		scheme = "https"
	}
	cW(entry.buf, nCyan, "%s://%s%s %s\" ", scheme, r.Host, r.RequestURI, r.Proto)

	entry.buf.WriteString("from ")
	entry.buf.WriteString(r.RemoteAddr)
	entry.buf.WriteString(" - ")

	return entry
}

type defaultLoggerEntry struct {
	*DefaultLogger
	buf *bytes.Buffer
}

func (l *defaultLoggerEntry) Write(status, bytes int, elapsed time.Duration) {
	if status == middleware.StatusClientClosedRequest {
		cW(l.buf, bRed, "[disconnected]")
	} else {
		switch {
		case status < 200:
			cW(l.buf, bBlue, "%03d", status)
		case status < 300:
			cW(l.buf, bGreen, "%03d", status)
		case status < 400:
			cW(l.buf, bCyan, "%03d", status)
		case status < 500:
			cW(l.buf, bYellow, "%03d", status)
		default:
			cW(l.buf, bRed, "%03d", status)
		}
	}

	cW(l.buf, bBlue, " %dB", bytes)

	l.buf.WriteString(" in ")
	if elapsed < 500*time.Millisecond {
		cW(l.buf, nGreen, "%s", elapsed)
	} else if elapsed < 5*time.Second {
		cW(l.buf, nYellow, "%s", elapsed)
	} else {
		cW(l.buf, nRed, "%s", elapsed)
	}

	l.logger.Print(l.buf.String())
}