From 54fde5d119f8bb55aec18cb5aef01b6ea58dfea0 Mon Sep 17 00:00:00 2001 From: Daniel Smith Date: Wed, 16 Jun 2021 17:08:54 -0700 Subject: [PATCH] Make logged verbs match metric-reported verbs --- .../pkg/endpoints/metrics/metrics.go | 22 ++++++++++++++----- .../src/k8s.io/apiserver/pkg/server/config.go | 2 +- .../apiserver/pkg/server/httplog/httplog.go | 14 +++++++++++- 3 files changed, 30 insertions(+), 8 deletions(-) diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go b/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go index 97985992083..1640ce38611 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go @@ -370,7 +370,7 @@ func RecordRequestAbort(req *http.Request, requestInfo *request.RequestInfo) { } scope := CleanScope(requestInfo) - reportedVerb := cleanVerb(canonicalVerb(strings.ToUpper(req.Method), scope), req) + reportedVerb := cleanVerb(CanonicalVerb(strings.ToUpper(req.Method), scope), req) resource := requestInfo.Resource subresource := requestInfo.Subresource group := requestInfo.APIGroup @@ -393,7 +393,7 @@ func RecordRequestTermination(req *http.Request, requestInfo *request.RequestInf // InstrumentRouteFunc which is registered in installer.go with predefined // list of verbs (different than those translated to RequestInfo). // However, we need to tweak it e.g. to differentiate GET from LIST. - reportedVerb := cleanVerb(canonicalVerb(strings.ToUpper(req.Method), scope), req) + reportedVerb := cleanVerb(CanonicalVerb(strings.ToUpper(req.Method), scope), req) if requestInfo.IsResourceRequest { requestTerminationsTotal.WithContext(req.Context()).WithLabelValues(reportedVerb, requestInfo.APIGroup, requestInfo.APIVersion, requestInfo.Resource, requestInfo.Subresource, scope, component, codeToString(code)).Inc() @@ -415,7 +415,7 @@ func RecordLongRunning(req *http.Request, requestInfo *request.RequestInfo, comp // InstrumentRouteFunc which is registered in installer.go with predefined // list of verbs (different than those translated to RequestInfo). // However, we need to tweak it e.g. to differentiate GET from LIST. - reportedVerb := cleanVerb(canonicalVerb(strings.ToUpper(req.Method), scope), req) + reportedVerb := cleanVerb(CanonicalVerb(strings.ToUpper(req.Method), scope), req) if requestInfo.IsResourceRequest { g = longRunningRequestGauge.WithContext(req.Context()).WithLabelValues(reportedVerb, requestInfo.APIGroup, requestInfo.APIVersion, requestInfo.Resource, requestInfo.Subresource, scope, component) @@ -434,7 +434,7 @@ func MonitorRequest(req *http.Request, verb, group, version, resource, subresour // InstrumentRouteFunc which is registered in installer.go with predefined // list of verbs (different than those translated to RequestInfo). // However, we need to tweak it e.g. to differentiate GET from LIST. - reportedVerb := cleanVerb(canonicalVerb(strings.ToUpper(req.Method), scope), req) + reportedVerb := cleanVerb(CanonicalVerb(strings.ToUpper(req.Method), scope), req) dryRun := cleanDryRun(req.URL) elapsedSeconds := elapsed.Seconds() @@ -526,7 +526,9 @@ func CleanScope(requestInfo *request.RequestInfo) string { return "" } -func canonicalVerb(verb string, scope string) string { +// CanonicalVerb distinguishes LISTs from GETs (and HEADs). It assumes verb is +// UPPERCASE. +func CanonicalVerb(verb string, scope string) string { switch verb { case "GET", "HEAD": if scope != "resource" && scope != "" { @@ -538,7 +540,9 @@ func canonicalVerb(verb string, scope string) string { } } -func cleanVerb(verb string, request *http.Request) string { +// CleanVerb returns a normalized verb, so that it is easy to tell WATCH from +// LIST and APPLY from PATCH. +func CleanVerb(verb string, request *http.Request) string { reportedVerb := verb if verb == "LIST" { // see apimachinery/pkg/runtime/conversion.go Convert_Slice_string_To_bool @@ -555,6 +559,12 @@ func cleanVerb(verb string, request *http.Request) string { if verb == "PATCH" && request.Header.Get("Content-Type") == string(types.ApplyPatchType) && utilfeature.DefaultFeatureGate.Enabled(features.ServerSideApply) { reportedVerb = "APPLY" } + return reportedVerb +} + +// cleanVerb additionally ensures that unknown verbs don't clog up the metrics. +func cleanVerb(verb string, request *http.Request) string { + reportedVerb := CleanVerb(verb, request) if validRequestMethods.Has(reportedVerb) { return reportedVerb } diff --git a/staging/src/k8s.io/apiserver/pkg/server/config.go b/staging/src/k8s.io/apiserver/pkg/server/config.go index b30cd66eece..27ee09b4825 100644 --- a/staging/src/k8s.io/apiserver/pkg/server/config.go +++ b/staging/src/k8s.io/apiserver/pkg/server/config.go @@ -765,7 +765,6 @@ func DefaultBuildHandlerChain(apiHandler http.Handler, c *Config) http.Handler { handler = genericapifilters.WithRequestDeadline(handler, c.AuditBackend, c.AuditPolicyChecker, c.LongRunningFunc, c.Serializer, c.RequestTimeout) handler = genericfilters.WithWaitGroup(handler, c.LongRunningFunc, c.HandlerChainWaitGroup) - handler = genericapifilters.WithRequestInfo(handler, c.RequestInfoResolver) if c.SecureServing != nil && !c.SecureServing.DisableHTTP2 && c.GoawayChance > 0 { handler = genericfilters.WithProbabilisticGoaway(handler, c.GoawayChance) } @@ -774,6 +773,7 @@ func DefaultBuildHandlerChain(apiHandler http.Handler, c *Config) http.Handler { handler = genericapifilters.WithCacheControl(handler) handler = genericfilters.WithHSTS(handler, c.HSTSDirectives) handler = genericfilters.WithHTTPLogging(handler) + handler = genericapifilters.WithRequestInfo(handler, c.RequestInfoResolver) handler = genericapifilters.WithRequestReceivedTimestamp(handler) handler = genericfilters.WithPanicRecovery(handler, c.RequestInfoResolver) handler = genericapifilters.WithAuditID(handler) diff --git a/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go b/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go index 5650a80600a..89ba28a9ecc 100644 --- a/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go +++ b/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go @@ -26,6 +26,7 @@ import ( "strings" "time" + "k8s.io/apiserver/pkg/endpoints/metrics" "k8s.io/apiserver/pkg/endpoints/request" "k8s.io/klog/v2" ) @@ -184,8 +185,19 @@ func AddInfof(ctx context.Context, format string, data ...interface{}) { func (rl *respLogger) Log() { latency := time.Since(rl.startTime) auditID := request.GetAuditIDTruncated(rl.req) + + verb := rl.req.Method + if requestInfo, ok := request.RequestInfoFrom(rl.req.Context()); ok { + // If we can find a requestInfo, we can get a scope, and then + // we can convert GETs to LISTs when needed. + scope := metrics.CleanScope(requestInfo) + verb = metrics.CanonicalVerb(strings.ToUpper(verb), scope) + } + // mark APPLY requests and WATCH requests correctly. + verb = metrics.CleanVerb(verb, rl.req) + keysAndValues := []interface{}{ - "verb", rl.req.Method, + "verb", verb, "URI", rl.req.RequestURI, "latency", latency, "userAgent", rl.req.UserAgent(),