package middleware import ( "bytes" "context" "log" "net/http" "os" "time" ) var ( // LogEntryCtxKey is the context.Context key to store the request log entry. LogEntryCtxKey = &contextKey{"LogEntry"} // DefaultLogger is called by the Logger middleware handler to log each request. // Its made a package-level variable so that it can be reconfigured for custom // logging configurations. DefaultLogger = RequestLogger(&DefaultLogFormatter{Logger: log.New(os.Stdout, "", log.LstdFlags), NoColor: false}) ) // Logger is a middleware that logs the start and end of each request, along // with some useful data about what was requested, what the response status was, // and how long it took to return. When standard output is a TTY, Logger will // print in color, otherwise it will print in black and white. Logger prints a // request ID if one is provided. // // Alternatively, look at https://github.com/goware/httplog for a more in-depth // http logger with structured logging support. func Logger(next http.Handler) http.Handler { return DefaultLogger(next) } // RequestLogger returns a logger handler using a custom LogFormatter. func RequestLogger(f LogFormatter) func(next http.Handler) http.Handler { return func(next http.Handler) http.Handler { fn := func(w http.ResponseWriter, r *http.Request) { entry := f.NewLogEntry(r) ww := NewWrapResponseWriter(w, r.ProtoMajor) t1 := time.Now() defer func() { entry.Write(ww.Status(), ww.BytesWritten(), ww.Header(), time.Since(t1), nil) }() next.ServeHTTP(ww, WithLogEntry(r, entry)) } return http.HandlerFunc(fn) } } // LogFormatter initiates the beginning of a new LogEntry per request. // See DefaultLogFormatter for an example implementation. type LogFormatter interface { NewLogEntry(r *http.Request) LogEntry } // LogEntry records the final log when a request completes. // See defaultLogEntry for an example implementation. type LogEntry interface { Write(status, bytes int, header http.Header, elapsed time.Duration, extra interface{}) Panic(v interface{}, stack []byte) } // GetLogEntry returns the in-context LogEntry for a request. func GetLogEntry(r *http.Request) LogEntry { entry, _ := r.Context().Value(LogEntryCtxKey).(LogEntry) return entry } // WithLogEntry sets the in-context LogEntry for a request. func WithLogEntry(r *http.Request, entry LogEntry) *http.Request { r = r.WithContext(context.WithValue(r.Context(), LogEntryCtxKey, entry)) return r } // LoggerInterface accepts printing to stdlib logger or compatible logger. type LoggerInterface interface { Print(v ...interface{}) } // DefaultLogFormatter is a simple logger that implements a LogFormatter. type DefaultLogFormatter struct { Logger LoggerInterface NoColor bool } // NewLogEntry creates a new LogEntry for the request. func (l *DefaultLogFormatter) NewLogEntry(r *http.Request) LogEntry { useColor := !l.NoColor entry := &defaultLogEntry{ DefaultLogFormatter: l, request: r, buf: &bytes.Buffer{}, useColor: useColor, } reqID := GetReqID(r.Context()) if reqID != "" { cW(entry.buf, useColor, nYellow, "[%s] ", reqID) } cW(entry.buf, useColor, nCyan, "\"") cW(entry.buf, useColor, bMagenta, "%s ", r.Method) scheme := "http" if r.TLS != nil { scheme = "https" } cW(entry.buf, useColor, 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 defaultLogEntry struct { *DefaultLogFormatter request *http.Request buf *bytes.Buffer useColor bool } func (l *defaultLogEntry) Write(status, bytes int, header http.Header, elapsed time.Duration, extra interface{}) { switch { case status < 200: cW(l.buf, l.useColor, bBlue, "%03d", status) case status < 300: cW(l.buf, l.useColor, bGreen, "%03d", status) case status < 400: cW(l.buf, l.useColor, bCyan, "%03d", status) case status < 500: cW(l.buf, l.useColor, bYellow, "%03d", status) default: cW(l.buf, l.useColor, bRed, "%03d", status) } cW(l.buf, l.useColor, bBlue, " %dB", bytes) l.buf.WriteString(" in ") if elapsed < 500*time.Millisecond { cW(l.buf, l.useColor, nGreen, "%s", elapsed) } else if elapsed < 5*time.Second { cW(l.buf, l.useColor, nYellow, "%s", elapsed) } else { cW(l.buf, l.useColor, nRed, "%s", elapsed) } l.Logger.Print(l.buf.String()) } func (l *defaultLogEntry) Panic(v interface{}, stack []byte) { PrintPrettyStack(v) }