From 932d2c3c62051c24fb78d1162de43202ff1d3a2e Mon Sep 17 00:00:00 2001 From: Anis Elleuch Date: Tue, 6 Dec 2022 18:27:26 +0100 Subject: [PATCH] Add X-Amz-Request-Id to internode calls (#16146) --- cmd/auth-handler.go | 15 +++++++------- cmd/generic-handlers.go | 41 ++++++++++++++++++++------------------- cmd/http-tracer.go | 38 ++++++++++++++---------------------- cmd/metrics-v2.go | 13 +++++++------ cmd/metrics.go | 17 ++++++++-------- cmd/utils.go | 15 ++++++++++++-- internal/mcontext/ctxt.go | 40 ++++++++++++++++++++++++++++++++++++++ internal/rest/client.go | 5 +++++ 8 files changed, 118 insertions(+), 66 deletions(-) create mode 100644 internal/mcontext/ctxt.go diff --git a/cmd/auth-handler.go b/cmd/auth-handler.go index d99bd2665..01d9918cc 100644 --- a/cmd/auth-handler.go +++ b/cmd/auth-handler.go @@ -39,6 +39,7 @@ import ( xhttp "github.com/minio/minio/internal/http" xjwt "github.com/minio/minio/internal/jwt" "github.com/minio/minio/internal/logger" + "github.com/minio/minio/internal/mcontext" "github.com/minio/pkg/bucket/policy" iampolicy "github.com/minio/pkg/iam/policy" ) @@ -544,7 +545,7 @@ func isSupportedS3AuthType(aType authType) bool { func setAuthHandler(h http.Handler) http.Handler { // handler for validating incoming authorization headers. return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - tc, ok := r.Context().Value(contextTraceReqKey).(*traceCtxt) + tc, ok := r.Context().Value(mcontext.ContextTraceKey).(*mcontext.TraceCtxt) aType := getRequestAuthType(r) if aType == authTypeSigned || aType == authTypeSignedV2 || aType == authTypeStreamingSigned { @@ -552,8 +553,8 @@ func setAuthHandler(h http.Handler) http.Handler { amzDate, errCode := parseAmzDateHeader(r) if errCode != ErrNone { if ok { - tc.funcName = "handler.Auth" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.Auth" + tc.ResponseRecorder.LogErrBody = true } // All our internal APIs are sensitive towards Date @@ -568,8 +569,8 @@ func setAuthHandler(h http.Handler) http.Handler { curTime := UTCNow() if curTime.Sub(amzDate) > globalMaxSkewTime || amzDate.Sub(curTime) > globalMaxSkewTime { if ok { - tc.funcName = "handler.Auth" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.Auth" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponse(r.Context(), w, errorCodes.ToAPIErr(ErrRequestTimeTooSkewed), r.URL) @@ -583,8 +584,8 @@ func setAuthHandler(h http.Handler) http.Handler { } if ok { - tc.funcName = "handler.Auth" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.Auth" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponse(r.Context(), w, errorCodes.ToAPIErr(ErrSignatureVersionNotSupported), r.URL) diff --git a/cmd/generic-handlers.go b/cmd/generic-handlers.go index 2a731a95a..6529d4067 100644 --- a/cmd/generic-handlers.go +++ b/cmd/generic-handlers.go @@ -37,6 +37,7 @@ import ( xhttp "github.com/minio/minio/internal/http" "github.com/minio/minio/internal/http/stats" "github.com/minio/minio/internal/logger" + "github.com/minio/minio/internal/mcontext" ) const ( @@ -101,13 +102,13 @@ func isHTTPHeaderSizeTooLarge(header http.Header) bool { // Limits body and header to specific allowed maximum limits as per S3/MinIO API requirements. func setRequestLimitHandler(h http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - tc, ok := r.Context().Value(contextTraceReqKey).(*traceCtxt) + tc, ok := r.Context().Value(mcontext.ContextTraceKey).(*mcontext.TraceCtxt) // Reject unsupported reserved metadata first before validation. if containsReservedMetadata(r.Header) { if ok { - tc.funcName = "handler.ValidRequest" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.ValidRequest" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponse(r.Context(), w, errorCodes.ToAPIErr(ErrUnsupportedMetadata), r.URL) @@ -116,8 +117,8 @@ func setRequestLimitHandler(h http.Handler) http.Handler { if isHTTPHeaderSizeTooLarge(r.Header) { if ok { - tc.funcName = "handler.ValidRequest" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.ValidRequest" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponse(r.Context(), w, errorCodes.ToAPIErr(ErrMetadataTooLarge), r.URL) @@ -378,12 +379,12 @@ func hasMultipleAuth(r *http.Request) bool { // any malicious requests. func setRequestValidityHandler(h http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - tc, ok := r.Context().Value(contextTraceReqKey).(*traceCtxt) + tc, ok := r.Context().Value(mcontext.ContextTraceKey).(*mcontext.TraceCtxt) if err := hasBadHost(r.Host); err != nil { if ok { - tc.funcName = "handler.ValidRequest" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.ValidRequest" + tc.ResponseRecorder.LogErrBody = true } invalidReq := errorCodes.ToAPIErr(ErrInvalidRequest) @@ -396,8 +397,8 @@ func setRequestValidityHandler(h http.Handler) http.Handler { // Check for bad components in URL path. if hasBadPathComponent(r.URL.Path) { if ok { - tc.funcName = "handler.ValidRequest" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.ValidRequest" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponse(r.Context(), w, errorCodes.ToAPIErr(ErrInvalidResourceName), r.URL) @@ -409,8 +410,8 @@ func setRequestValidityHandler(h http.Handler) http.Handler { for _, v := range vv { if hasBadPathComponent(v) { if ok { - tc.funcName = "handler.ValidRequest" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.ValidRequest" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponse(r.Context(), w, errorCodes.ToAPIErr(ErrInvalidResourceName), r.URL) @@ -421,8 +422,8 @@ func setRequestValidityHandler(h http.Handler) http.Handler { } if hasMultipleAuth(r) { if ok { - tc.funcName = "handler.Auth" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.Auth" + tc.ResponseRecorder.LogErrBody = true } invalidReq := errorCodes.ToAPIErr(ErrInvalidRequest) @@ -436,8 +437,8 @@ func setRequestValidityHandler(h http.Handler) http.Handler { if isMinioReservedBucket(bucketName) || isMinioMetaBucket(bucketName) { if !guessIsRPCReq(r) && !guessIsBrowserReq(r) && !guessIsHealthCheckReq(r) && !guessIsMetricsReq(r) && !isAdminReq(r) && !isKMSReq(r) { if ok { - tc.funcName = "handler.ValidRequest" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.ValidRequest" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponse(r.Context(), w, errorCodes.ToAPIErr(ErrAllAccessDisabled), r.URL) return @@ -447,15 +448,15 @@ func setRequestValidityHandler(h http.Handler) http.Handler { if !globalIsTLS && (crypto.SSEC.IsRequested(r.Header) || crypto.SSECopy.IsRequested(r.Header)) { if r.Method == http.MethodHead { if ok { - tc.funcName = "handler.ValidRequest" - tc.responseRecorder.LogErrBody = false + tc.FuncName = "handler.ValidRequest" + tc.ResponseRecorder.LogErrBody = false } writeErrorResponseHeadersOnly(w, errorCodes.ToAPIErr(ErrInsecureSSECustomerRequest)) } else { if ok { - tc.funcName = "handler.ValidRequest" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.ValidRequest" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponse(r.Context(), w, errorCodes.ToAPIErr(ErrInsecureSSECustomerRequest), r.URL) diff --git a/cmd/http-tracer.go b/cmd/http-tracer.go index 3ec33382b..52ba67892 100644 --- a/cmd/http-tracer.go +++ b/cmd/http-tracer.go @@ -31,6 +31,7 @@ import ( "github.com/minio/madmin-go" "github.com/minio/minio/internal/handlers" xhttp "github.com/minio/minio/internal/http" + "github.com/minio/minio/internal/mcontext" ) var ldapPwdRegex = regexp.MustCompile("(^.*?)LDAPPassword=([^&]*?)(&(.*?))?$") @@ -62,18 +63,6 @@ func getOpName(name string) (op string) { return op } -type contextTraceReqType string - -const contextTraceReqKey = contextTraceReqType("request-trace-info") - -// Hold related tracing data of a http request, any handler -// can modify this struct to modify the trace information . -type traceCtxt struct { - requestRecorder *xhttp.RequestRecorder - responseRecorder *xhttp.ResponseRecorder - funcName string -} - // 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 { @@ -84,16 +73,19 @@ func httpTracer(h http.Handler) http.Handler { } // Create tracing data structure and associate it to the request context - tc := traceCtxt{} - ctx := context.WithValue(r.Context(), contextTraceReqKey, &tc) + tc := mcontext.TraceCtxt{ + AmzReqID: r.Header.Get(xhttp.AmzRequestID), + } + + ctx := context.WithValue(r.Context(), mcontext.ContextTraceKey, &tc) r = r.WithContext(ctx) // Setup a http request and response body recorder reqRecorder := &xhttp.RequestRecorder{Reader: r.Body} respRecorder := xhttp.NewResponseRecorder(w) - tc.requestRecorder = reqRecorder - tc.responseRecorder = respRecorder + tc.RequestRecorder = reqRecorder + tc.ResponseRecorder = respRecorder // Execute call. r.Body = reqRecorder @@ -103,7 +95,7 @@ func httpTracer(h http.Handler) http.Handler { reqEndTime := time.Now().UTC() tt := madmin.TraceInternal - if strings.HasPrefix(tc.funcName, "s3.") { + if strings.HasPrefix(tc.FuncName, "s3.") { tt = madmin.TraceS3 } // No need to continue if no subscribers for actual type... @@ -141,7 +133,7 @@ func httpTracer(h http.Handler) http.Handler { } // Calculate function name - funcName := tc.funcName + funcName := tc.FuncName if funcName == "" { funcName = "" } @@ -185,17 +177,17 @@ func httpTracer(h http.Handler) http.Handler { func httpTrace(f http.HandlerFunc, logBody bool) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { - tc, ok := r.Context().Value(contextTraceReqKey).(*traceCtxt) + tc, ok := r.Context().Value(mcontext.ContextTraceKey).(*mcontext.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 + 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) } diff --git a/cmd/metrics-v2.go b/cmd/metrics-v2.go index 472096649..1231538a0 100644 --- a/cmd/metrics-v2.go +++ b/cmd/metrics-v2.go @@ -31,6 +31,7 @@ import ( "github.com/minio/madmin-go" "github.com/minio/minio/internal/bucket/lifecycle" "github.com/minio/minio/internal/logger" + "github.com/minio/minio/internal/mcontext" "github.com/minio/minio/internal/rest" "github.com/prometheus/client_golang/prometheus" dto "github.com/prometheus/client_model/go" @@ -2395,10 +2396,10 @@ func metricsServerHandler() http.Handler { } return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - tc, ok := r.Context().Value(contextTraceReqKey).(*traceCtxt) + tc, ok := r.Context().Value(mcontext.ContextTraceKey).(*mcontext.TraceCtxt) if ok { - tc.funcName = "handler.MetricsCluster" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.MetricsCluster" + tc.ResponseRecorder.LogErrBody = true } mfs, err := gatherers.Gather() @@ -2442,10 +2443,10 @@ func metricsNodeHandler() http.Handler { registry, } return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - tc, ok := r.Context().Value(contextTraceReqKey).(*traceCtxt) + tc, ok := r.Context().Value(mcontext.ContextTraceKey).(*mcontext.TraceCtxt) if ok { - tc.funcName = "handler.MetricsNode" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.MetricsNode" + tc.ResponseRecorder.LogErrBody = true } mfs, err := gatherers.Gather() diff --git a/cmd/metrics.go b/cmd/metrics.go index bf44e9a62..a35defffb 100644 --- a/cmd/metrics.go +++ b/cmd/metrics.go @@ -23,6 +23,7 @@ import ( "time" "github.com/minio/minio/internal/logger" + "github.com/minio/minio/internal/mcontext" iampolicy "github.com/minio/pkg/iam/policy" "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/common/expfmt" @@ -569,10 +570,10 @@ func metricsHandler() http.Handler { } return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - tc, ok := r.Context().Value(contextTraceReqKey).(*traceCtxt) + tc, ok := r.Context().Value(mcontext.ContextTraceKey).(*mcontext.TraceCtxt) if ok { - tc.funcName = "handler.MetricsLegacy" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.MetricsLegacy" + tc.ResponseRecorder.LogErrBody = true } mfs, err := gatherers.Gather() @@ -602,13 +603,13 @@ func metricsHandler() http.Handler { // AuthMiddleware checks if the bearer token is valid and authorized. func AuthMiddleware(h http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - tc, ok := r.Context().Value(contextTraceReqKey).(*traceCtxt) + tc, ok := r.Context().Value(mcontext.ContextTraceKey).(*mcontext.TraceCtxt) claims, groups, owner, authErr := metricsRequestAuthenticate(r) if authErr != nil || !claims.VerifyIssuer("prometheus", true) { if ok { - tc.funcName = "handler.MetricsAuth" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.MetricsAuth" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponseJSON(r.Context(), w, toAdminAPIErr(r.Context(), errAuthentication), r.URL) @@ -624,8 +625,8 @@ func AuthMiddleware(h http.Handler) http.Handler { Claims: claims.Map(), }) { if ok { - tc.funcName = "handler.MetricsAuth" - tc.responseRecorder.LogErrBody = true + tc.FuncName = "handler.MetricsAuth" + tc.ResponseRecorder.LogErrBody = true } writeErrorResponseJSON(r.Context(), w, toAdminAPIErr(r.Context(), errAuthentication), r.URL) diff --git a/cmd/utils.go b/cmd/utils.go index 5465ad585..76d16be8f 100644 --- a/cmd/utils.go +++ b/cmd/utils.go @@ -59,6 +59,7 @@ import ( ioutilx "github.com/minio/minio/internal/ioutil" "github.com/minio/minio/internal/logger" "github.com/minio/minio/internal/logger/message/audit" + "github.com/minio/minio/internal/mcontext" "github.com/minio/pkg/certs" "github.com/minio/pkg/env" xnet "github.com/minio/pkg/net" @@ -915,12 +916,14 @@ func updateReqContext(ctx context.Context, objects ...ObjectV) context.Context { // Returns context with ReqInfo details set in the context. func newContext(r *http.Request, w http.ResponseWriter, api string) context.Context { + reqID := w.Header().Get(xhttp.AmzRequestID) + vars := mux.Vars(r) bucket := vars["bucket"] object := likelyUnescapeGeneric(vars["object"], url.PathUnescape) reqInfo := &logger.ReqInfo{ DeploymentID: globalDeploymentID, - RequestID: w.Header().Get(xhttp.AmzRequestID), + RequestID: reqID, RemoteHost: handlers.GetSourceIP(r), Host: getHostName(r), UserAgent: r.UserAgent(), @@ -929,7 +932,15 @@ func newContext(r *http.Request, w http.ResponseWriter, api string) context.Cont ObjectName: object, VersionID: strings.TrimSpace(r.Form.Get(xhttp.VersionID)), } - return logger.SetReqInfo(r.Context(), reqInfo) + + ctx := context.WithValue(r.Context(), + mcontext.ContextTraceKey, + &mcontext.TraceCtxt{ + AmzReqID: reqID, + }, + ) + + return logger.SetReqInfo(ctx, reqInfo) } // Used for registering with rest handlers (have a look at registerStorageRESTHandlers for usage example) diff --git a/internal/mcontext/ctxt.go b/internal/mcontext/ctxt.go new file mode 100644 index 000000000..719b83fde --- /dev/null +++ b/internal/mcontext/ctxt.go @@ -0,0 +1,40 @@ +// Copyright (c) 2015-2022 MinIO, Inc. +// +// This file is part of MinIO Object Storage stack +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU Affero General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU Affero General Public License for more details. +// +// You should have received a copy of the GNU Affero General Public License +// along with this program. If not, see . + +package mcontext + +// Share a common context information between different +// packages in github.com/minio/minio + +import ( + xhttp "github.com/minio/minio/internal/http" +) + +// ContextTraceType represents the type of golang Context key +type ContextTraceType string + +// ContextTraceKey is the key of TraceCtxt saved in a Golang context +const ContextTraceKey = ContextTraceType("ctx-trace-info") + +// TraceCtxt holds related tracing data of a http request. +type TraceCtxt struct { + RequestRecorder *xhttp.RequestRecorder + ResponseRecorder *xhttp.ResponseRecorder + + FuncName string + AmzReqID string +} diff --git a/internal/rest/client.go b/internal/rest/client.go index c2e43992f..4967d3f59 100644 --- a/internal/rest/client.go +++ b/internal/rest/client.go @@ -34,6 +34,7 @@ import ( xhttp "github.com/minio/minio/internal/http" "github.com/minio/minio/internal/logger" + "github.com/minio/minio/internal/mcontext" xnet "github.com/minio/pkg/net" ) @@ -194,6 +195,10 @@ func (c *Client) newRequest(ctx context.Context, u *url.URL, body io.Reader) (*h req.Header.Set("Expect", "100-continue") } + if tc, ok := ctx.Value(mcontext.ContextTraceKey).(*mcontext.TraceCtxt); ok { + req.Header.Set(xhttp.AmzRequestID, tc.AmzReqID) + } + return req, nil }