-
Notifications
You must be signed in to change notification settings - Fork 157
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
logging tweaks to improve usability #1235
Changes from 2 commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -20,7 +20,9 @@ package restapi | |
import ( | ||
"context" | ||
"crypto/tls" | ||
"fmt" | ||
"net/http" | ||
"net/http/httputil" | ||
"strconv" | ||
"time" | ||
|
||
|
@@ -33,6 +35,8 @@ import ( | |
"github.com/mitchellh/mapstructure" | ||
"github.com/rs/cors" | ||
"github.com/spf13/viper" | ||
"go.uber.org/zap" | ||
"go.uber.org/zap/zapcore" | ||
|
||
pkgapi "github.com/sigstore/rekor/pkg/api" | ||
"github.com/sigstore/rekor/pkg/generated/restapi/operations" | ||
|
@@ -174,21 +178,81 @@ func setupMiddlewares(handler http.Handler) http.Handler { | |
return handler | ||
} | ||
|
||
type httpRequestFields struct { | ||
requestMethod string | ||
requestURL string | ||
requestSize string | ||
status int | ||
responseSize string | ||
userAgent string | ||
remoteIP string | ||
latency string | ||
protocol string | ||
} | ||
|
||
func (h httpRequestFields) MarshalLogObject(enc zapcore.ObjectEncoder) error { | ||
enc.AddString("requestMethod", h.requestMethod) | ||
enc.AddString("requestUrl", h.requestURL) | ||
enc.AddString("requestSize", h.requestSize) | ||
enc.AddInt("status", h.status) | ||
enc.AddString("responseSize", h.responseSize) | ||
enc.AddString("userAgent", h.userAgent) | ||
enc.AddString("remoteIP", h.remoteIP) | ||
enc.AddString("latency", h.latency) | ||
enc.AddString("protocol", h.protocol) | ||
bobcallaway marked this conversation as resolved.
Show resolved
Hide resolved
|
||
return nil | ||
} | ||
|
||
// We need this type to act as an adapter between zap and the middleware request logger. | ||
type logAdapter struct { | ||
type zapLogEntry struct { | ||
r *http.Request | ||
} | ||
|
||
func (l *logAdapter) Print(v ...interface{}) { | ||
log.Logger.Info(v...) | ||
func (z *zapLogEntry) Write(status, bytes int, header http.Header, elapsed time.Duration, extra interface{}) { | ||
var fields []interface{} | ||
bobcallaway marked this conversation as resolved.
Show resolved
Hide resolved
|
||
|
||
// follows https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry as a convention | ||
// append HTTP Request / Response Information | ||
scheme := "http" | ||
if z.r.TLS != nil { | ||
scheme = "https" | ||
} | ||
httpRequestObj := httpRequestFields{ | ||
requestMethod: z.r.Method, | ||
requestURL: fmt.Sprintf("%s://%s%s", scheme, z.r.Host, z.r.RequestURI), | ||
requestSize: fmt.Sprintf("%d", z.r.ContentLength), | ||
status: status, | ||
responseSize: fmt.Sprintf("%d", bytes), | ||
userAgent: z.r.Header.Get("User-Agent"), | ||
remoteIP: z.r.RemoteAddr, | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Any reason to log IP? Some PII risk of being able to correlate requests across artifacts, gather usage data, etc |
||
latency: fmt.Sprintf("%.9fs", elapsed.Seconds()), | ||
protocol: z.r.Proto, | ||
} | ||
fields = append(fields, zap.Object("httpRequest", httpRequestObj)) | ||
if extra != nil { | ||
fields = append(fields, zap.Any("extra", extra)) | ||
} | ||
|
||
log.ContextLogger(z.r.Context()).With(fields...).Info("completed request") | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. If the There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
|
||
} | ||
|
||
func (z *zapLogEntry) Panic(v interface{}, stack []byte) { | ||
fields := []interface{}{zap.String("message", fmt.Sprintf("%v\n%v", v, string(stack)))} | ||
log.ContextLogger(z.r.Context()).With(fields...).Errorf("panic detected: %v", v) | ||
} | ||
|
||
type logFormatter struct{} | ||
|
||
func (l *logFormatter) NewLogEntry(r *http.Request) middleware.LogEntry { | ||
return &zapLogEntry{r} | ||
} | ||
|
||
// The middleware configuration happens before anything, this middleware also applies to serving the swagger.json document. | ||
// So this is a good place to plug in a panic handling middleware, logging and metrics | ||
func setupGlobalMiddleware(handler http.Handler) http.Handler { | ||
middleware.DefaultLogger = middleware.RequestLogger( | ||
&middleware.DefaultLogFormatter{Logger: &logAdapter{}}) | ||
returnHandler := middleware.Logger(handler) | ||
returnHandler = middleware.Recoverer(returnHandler) | ||
returnHandler := recoverer(handler) | ||
middleware.DefaultLogger = middleware.RequestLogger(&logFormatter{}) | ||
returnHandler = middleware.Logger(returnHandler) | ||
returnHandler = middleware.Heartbeat("/ping")(returnHandler) | ||
returnHandler = serveStaticContent(returnHandler) | ||
|
||
|
@@ -296,3 +360,29 @@ func serveStaticContent(handler http.Handler) http.Handler { | |
handler.ServeHTTP(w, r) | ||
}) | ||
} | ||
|
||
// recoverer | ||
func recoverer(next http.Handler) http.Handler { | ||
fn := func(w http.ResponseWriter, r *http.Request) { | ||
defer func() { | ||
if rvr := recover(); rvr != nil && rvr != http.ErrAbortHandler { | ||
var fields []interface{} | ||
|
||
// get context before dump request in case there is an error | ||
ctx := r.Context() | ||
request, err := httputil.DumpRequest(r, false) | ||
if err == nil { | ||
fields = append(fields, zap.ByteString("request_headers", request)) | ||
} | ||
|
||
log.ContextLogger(ctx).With(fields...).Errorf("panic detected: %v", rvr) | ||
|
||
errors.ServeError(w, r, nil) | ||
} | ||
}() | ||
|
||
next.ServeHTTP(w, r) | ||
} | ||
|
||
return http.HandlerFunc(fn) | ||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
enc.AddDuration("latency", h.latency)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#HttpRequest wants this represented as a string in units of seconds, so that's why I formatted it the way I did