certificates/logging/handler.go
2022-08-11 17:47:58 -07:00

125 lines
3.3 KiB
Go

package logging
import (
"net"
"net/http"
"os"
"strconv"
"strings"
"time"
"github.com/sirupsen/logrus"
)
// LoggerHandler creates a logger handler
type LoggerHandler struct {
name string
logger *logrus.Logger
options options
next http.Handler
}
// options encapsulates any overriding parameters for the logger handler
type options struct {
// onlyTraceHealthEndpoint determines if the kube-probe requests to the /health
// endpoint should only be logged at the TRACE level in the (expected) HTTP
// 200 case
onlyTraceHealthEndpoint bool
}
// NewLoggerHandler returns the given http.Handler with the logger integrated.
func NewLoggerHandler(name string, logger *Logger, next http.Handler) http.Handler {
h := RequestID(logger.GetTraceHeader())
onlyTraceHealthEndpoint, _ := strconv.ParseBool(os.Getenv("STEP_LOGGER_ONLY_TRACE_HEALTH_ENDPOINT"))
return h(&LoggerHandler{
name: name,
logger: logger.GetImpl(),
options: options{
onlyTraceHealthEndpoint: onlyTraceHealthEndpoint,
},
next: next,
})
}
// ServeHTTP implements the http.Handler and call to the handler to log with a
// custom http.ResponseWriter that records the response code and the number of
// bytes sent.
func (l *LoggerHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
t := time.Now()
rw := NewResponseLogger(w)
l.next.ServeHTTP(rw, r)
d := time.Since(t)
l.writeEntry(rw, r, t, d)
}
// writeEntry writes to the Logger writer the request information in the logger.
func (l *LoggerHandler) writeEntry(w ResponseLogger, r *http.Request, t time.Time, d time.Duration) {
var reqID, user string
ctx := r.Context()
if v, ok := ctx.Value(RequestIDKey).(string); ok && v != "" {
reqID = v
}
if v, ok := ctx.Value(UserIDKey).(string); ok && v != "" {
user = v
}
// Remote hostname
addr, _, err := net.SplitHostPort(r.RemoteAddr)
if err != nil {
addr = r.RemoteAddr
}
// From https://github.com/gorilla/handlers
uri := r.RequestURI
// Requests using the CONNECT method over HTTP/2.0 must use
// the authority field (aka r.Host) to identify the target.
// Refer: https://httpwg.github.io/specs/rfc7540.html#CONNECT
if r.ProtoMajor == 2 && r.Method == "CONNECT" {
uri = r.Host
}
if uri == "" {
uri = sanitizeLogEntry(r.URL.RequestURI())
}
status := w.StatusCode()
fields := logrus.Fields{
"request-id": reqID,
"remote-address": addr,
"name": l.name,
"user-id": user,
"time": t.Format(time.RFC3339),
"duration-ns": d.Nanoseconds(),
"duration": d.String(),
"method": r.Method,
"path": uri,
"protocol": r.Proto,
"status": status,
"size": w.Size(),
"referer": sanitizeLogEntry(r.Referer()),
"user-agent": sanitizeLogEntry(r.UserAgent()),
}
for k, v := range w.Fields() {
fields[k] = v
}
switch {
case status < http.StatusBadRequest:
if l.options.onlyTraceHealthEndpoint && uri == "/health" {
l.logger.WithFields(fields).Trace()
} else {
l.logger.WithFields(fields).Info()
}
case status < http.StatusInternalServerError:
l.logger.WithFields(fields).Warn()
default:
l.logger.WithFields(fields).Error()
}
}
func sanitizeLogEntry(s string) string {
escaped := strings.ReplaceAll(s, "\n", "")
return strings.ReplaceAll(escaped, "\r", "")
}