Trace all http requests (#15064)

Add a generic handler that adds a new tracing context to the request if
tracing is enabled. Other handlers are free to modify the tracing
context to update information on the fly, such as, func name, enable
body logging etc..

With this commit, requests like this 

```
curl -H "Host: ::1:3000" http://localhost:9000/
```

will be traced as well.
This commit is contained in:
Anis Elleuch 2022-06-24 07:19:24 +01:00 committed by GitHub
parent e1afac9439
commit 4fd1986885
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 143 additions and 111 deletions

View File

@ -357,30 +357,6 @@ func extractPostPolicyFormValues(ctx context.Context, form *multipart.Form) (fil
return filePart, fileName, fileSize, formValues, nil return filePart, fileName, fileSize, formValues, nil
} }
// Log headers and body.
func httpTraceAll(f http.HandlerFunc) http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) {
if globalTrace.NumSubscribers() == 0 {
f.ServeHTTP(w, r)
return
}
trace := Trace(f, true, w, r)
globalTrace.Publish(trace)
}
}
// Log only the headers.
func httpTraceHdrs(f http.HandlerFunc) http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) {
if globalTrace.NumSubscribers() == 0 {
f.ServeHTTP(w, r)
return
}
trace := Trace(f, false, w, r)
globalTrace.Publish(trace)
}
}
func collectAPIStats(api string, f http.HandlerFunc) http.HandlerFunc { func collectAPIStats(api string, f http.HandlerFunc) http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) { return func(w http.ResponseWriter, r *http.Request) {
globalHTTPStats.currentS3Requests.Inc(api) globalHTTPStats.currentS3Requests.Inc(api)

View File

@ -19,6 +19,7 @@ package cmd
import ( import (
"bytes" "bytes"
"context"
"io" "io"
"net" "net"
"net/http" "net/http"
@ -43,8 +44,6 @@ type recordRequest struct {
logBody bool logBody bool
// Internal recording buffer // Internal recording buffer
buf bytes.Buffer buf bytes.Buffer
// request headers
headers http.Header
// total bytes read including header size // total bytes read including header size
bytesRead int bytesRead int
} }
@ -67,12 +66,8 @@ func (r *recordRequest) Read(p []byte) (n int, err error) {
return n, err return n, err
} }
func (r *recordRequest) Size() int { func (r *recordRequest) BodySize() int {
sz := r.bytesRead return r.bytesRead
for k, v := range r.headers {
sz += len(k) + len(v)
}
return sz
} }
// Return the bytes that were recorded. // Return the bytes that were recorded.
@ -113,85 +108,143 @@ func getOpName(name string) (op string) {
return op return op
} }
// Trace gets trace of http request type contextTraceReqType string
func Trace(f http.HandlerFunc, logBody bool, w http.ResponseWriter, r *http.Request) madmin.TraceInfo {
name := getOpName(runtime.FuncForPC(reflect.ValueOf(f).Pointer()).Name())
// Setup a http request body recorder const contextTraceReqKey = contextTraceReqType("request-trace-info")
reqHeaders := r.Header.Clone()
reqHeaders.Set("Host", r.Host)
if len(r.TransferEncoding) == 0 {
reqHeaders.Set("Content-Length", strconv.Itoa(int(r.ContentLength)))
} else {
reqHeaders.Set("Transfer-Encoding", strings.Join(r.TransferEncoding, ","))
}
reqBodyRecorder := &recordRequest{Reader: r.Body, logBody: logBody, headers: reqHeaders} // Hold related tracing data of a http request, any handler
r.Body = reqBodyRecorder // can modify this struct to modify the trace information .
type traceCtxt struct {
now := time.Now().UTC() requestRecorder *recordRequest
t := madmin.TraceInfo{TraceType: madmin.TraceHTTP, FuncName: name, Time: now} responseRecorder *logger.ResponseWriter
funcName string
t.NodeName = r.Host }
if globalIsDistErasure {
t.NodeName = globalLocalNodeName // If trace is enabled, execute the request if it is traced by other handlers
} // otherwise, generate a trace event with request information but no response.
func httpTracer(h http.Handler) http.Handler {
if t.NodeName == "" { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
t.NodeName = globalLocalNodeName if globalTrace.NumSubscribers() == 0 {
} h.ServeHTTP(w, r)
return
// strip only standard port from the host address }
if host, port, err := net.SplitHostPort(t.NodeName); err == nil {
if port == "443" || port == "80" { // Create tracing data structure and associate it to the request context
t.NodeName = host tc := traceCtxt{}
} ctx := context.WithValue(r.Context(), contextTraceReqKey, &tc)
} r = r.WithContext(ctx)
rq := madmin.TraceRequestInfo{ // Setup a http request and response body recorder
Time: now, reqRecorder := &recordRequest{Reader: r.Body}
Proto: r.Proto, respRecorder := logger.NewResponseWriter(w)
Method: r.Method,
RawQuery: redactLDAPPwd(r.URL.RawQuery), tc.requestRecorder = reqRecorder
Client: handlers.GetSourceIP(r), tc.responseRecorder = respRecorder
Headers: reqHeaders,
} // Execute call.
r.Body = reqRecorder
path := r.URL.RawPath
if path == "" { reqStartTime := time.Now().UTC()
path = r.URL.Path h.ServeHTTP(respRecorder, r)
} reqEndTime := time.Now().UTC()
rq.Path = path
// Calculate input body size with headers
rw := logger.NewResponseWriter(w) reqHeaders := r.Header.Clone()
rw.LogErrBody = true reqHeaders.Set("Host", r.Host)
rw.LogAllBody = logBody if len(r.TransferEncoding) == 0 {
reqHeaders.Set("Content-Length", strconv.Itoa(int(r.ContentLength)))
// Execute call. } else {
f(rw, r) reqHeaders.Set("Transfer-Encoding", strings.Join(r.TransferEncoding, ","))
}
rs := madmin.TraceResponseInfo{ inputBytes := reqRecorder.BodySize()
Time: time.Now().UTC(), for k, v := range reqHeaders {
Headers: rw.Header().Clone(), inputBytes += len(k) + len(v)
StatusCode: rw.StatusCode, }
Body: rw.Body(),
} // Calculate node name
nodeName := r.Host
// Transfer request body if nodeName == "" || globalIsDistErasure {
rq.Body = reqBodyRecorder.Data() nodeName = globalLocalNodeName
}
if rs.StatusCode == 0 { if host, port, err := net.SplitHostPort(nodeName); err == nil {
rs.StatusCode = http.StatusOK if port == "443" || port == "80" {
} nodeName = host
}
t.ReqInfo = rq }
t.RespInfo = rs
// Calculate reqPath
t.CallStats = madmin.TraceCallStats{ reqPath := r.URL.RawPath
Latency: rs.Time.Sub(rw.StartTime), if reqPath == "" {
InputBytes: reqBodyRecorder.Size(), reqPath = r.URL.Path
OutputBytes: rw.Size(), }
TimeToFirstByte: rw.TimeToFirstByte,
} // Calculate function name
return t funcName := tc.funcName
if funcName == "" {
funcName = "<unknown>"
}
rq := madmin.TraceRequestInfo{
Time: reqStartTime,
Proto: r.Proto,
Method: r.Method,
RawQuery: redactLDAPPwd(r.URL.RawQuery),
Client: handlers.GetSourceIP(r),
Headers: reqHeaders,
Path: reqPath,
Body: reqRecorder.Data(),
}
rs := madmin.TraceResponseInfo{
Time: reqEndTime,
Headers: respRecorder.Header().Clone(),
StatusCode: respRecorder.StatusCode,
Body: respRecorder.Body(),
}
cs := madmin.TraceCallStats{
Latency: rs.Time.Sub(respRecorder.StartTime),
InputBytes: inputBytes,
OutputBytes: respRecorder.Size(),
TimeToFirstByte: respRecorder.TimeToFirstByte,
}
t := madmin.TraceInfo{
TraceType: madmin.TraceHTTP,
FuncName: funcName,
NodeName: nodeName,
Time: reqStartTime,
ReqInfo: rq,
RespInfo: rs,
CallStats: cs,
}
globalTrace.Publish(t)
})
}
func httpTrace(f http.HandlerFunc, logBody bool) http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) {
tc, ok := r.Context().Value(contextTraceReqKey).(*traceCtxt)
if !ok {
// Tracing is not enabled for this request
f.ServeHTTP(w, r)
return
}
tc.funcName = getOpName(runtime.FuncForPC(reflect.ValueOf(f).Pointer()).Name())
tc.requestRecorder.logBody = logBody
tc.responseRecorder.LogAllBody = logBody
tc.responseRecorder.LogErrBody = true
f.ServeHTTP(w, r)
}
}
func httpTraceAll(f http.HandlerFunc) http.HandlerFunc {
return httpTrace(f, true)
}
func httpTraceHdrs(f http.HandlerFunc) http.HandlerFunc {
return httpTrace(f, false)
} }

View File

@ -40,6 +40,9 @@ func registerDistErasureRouters(router *mux.Router, endpointServerPools Endpoint
// List of some generic handlers which are applied for all incoming requests. // List of some generic handlers which are applied for all incoming requests.
var globalHandlers = []mux.MiddlewareFunc{ var globalHandlers = []mux.MiddlewareFunc{
// The generic tracer needs to be the first handler
// to catch all requests returned early by any other handler
httpTracer,
// Auth handler verifies incoming authorization headers and // Auth handler verifies incoming authorization headers and
// routes them accordingly. Client receives a HTTP error for // routes them accordingly. Client receives a HTTP error for
// invalid/unsupported signatures. // invalid/unsupported signatures.