From 4a9b9028153c6984b9cf69067cc0a1aa12a00e73 Mon Sep 17 00:00:00 2001 From: Abu Kashem Date: Tue, 1 Feb 2022 15:44:59 -0500 Subject: [PATCH] refactor: rename webhook duration tracker --- .../plugin/webhook/mutating/dispatcher.go | 4 +- .../plugin/webhook/mutating/plugin_test.go | 12 ++--- .../plugin/webhook/validating/dispatcher.go | 4 +- .../plugin/webhook/validating/plugin_test.go | 12 ++--- .../pkg/endpoints/filters/webhook_duration.go | 9 ++-- .../pkg/endpoints/metrics/metrics.go | 4 +- .../pkg/endpoints/request/webhook_duration.go | 53 ++++++++++--------- .../request/webhook_duration_test.go | 28 +++++----- .../src/k8s.io/apiserver/pkg/server/config.go | 2 +- 9 files changed, 67 insertions(+), 61 deletions(-) diff --git a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/dispatcher.go b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/dispatcher.go index 914fe6e0b28..60ecec1098c 100644 --- a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/dispatcher.go +++ b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/dispatcher.go @@ -265,9 +265,9 @@ func (a *mutatingDispatcher) callAttrMutatingHook(ctx context.Context, h *admiss } do := func() { err = r.Do(ctx).Into(response) } - if wd, ok := endpointsrequest.WebhookDurationFrom(ctx); ok { + if wd, ok := endpointsrequest.LatencyTrackersFrom(ctx); ok { tmp := do - do = func() { wd.AdmitTracker.Track(tmp) } + do = func() { wd.MutatingWebhookTracker.Track(tmp) } } do() if err != nil { diff --git a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/plugin_test.go b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/plugin_test.go index dad2a4fd1d5..f776505a7d5 100644 --- a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/plugin_test.go +++ b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/plugin_test.go @@ -274,7 +274,7 @@ func TestWebhookDuration(ts *testing.T) { ts.Run(test.Name, func(t *testing.T) { ctx := context.TODO() if test.InitContext { - ctx = request.WithWebhookDurationAndCustomClock(ctx, &clk) + ctx = request.WithLatencyTrackersAndCustomClock(ctx, &clk) } wh, err := NewMutatingWebhook(nil) if err != nil { @@ -299,7 +299,7 @@ func TestWebhookDuration(ts *testing.T) { } _ = wh.Admit(ctx, webhooktesting.NewAttribute(ns, nil, test.IsDryRun), objectInterfaces) - wd, ok := request.WebhookDurationFrom(ctx) + wd, ok := request.LatencyTrackersFrom(ctx) if !ok { if test.InitContext { t.Errorf("expected webhook duration to be initialized") @@ -310,11 +310,11 @@ func TestWebhookDuration(ts *testing.T) { t.Errorf("expected webhook duration to not be initialized") return } - if wd.AdmitTracker.GetLatency() != test.ExpectedDurationSum { - t.Errorf("expected admit duration %q got %q", test.ExpectedDurationSum, wd.AdmitTracker.GetLatency()) + if wd.MutatingWebhookTracker.GetLatency() != test.ExpectedDurationSum { + t.Errorf("expected admit duration %q got %q", test.ExpectedDurationSum, wd.MutatingWebhookTracker.GetLatency()) } - if wd.ValidateTracker.GetLatency() != 0 { - t.Errorf("expected validate duraion to be equal to 0 got %q", wd.ValidateTracker.GetLatency()) + if wd.ValidatingWebhookTracker.GetLatency() != 0 { + t.Errorf("expected validate duraion to be equal to 0 got %q", wd.ValidatingWebhookTracker.GetLatency()) } }) } diff --git a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/dispatcher.go b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/dispatcher.go index dfa79e8b28d..a11da8b94c0 100644 --- a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/dispatcher.go +++ b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/dispatcher.go @@ -232,9 +232,9 @@ func (d *validatingDispatcher) callHook(ctx context.Context, h *v1.ValidatingWeb } do := func() { err = r.Do(ctx).Into(response) } - if wd, ok := endpointsrequest.WebhookDurationFrom(ctx); ok { + if wd, ok := endpointsrequest.LatencyTrackersFrom(ctx); ok { tmp := do - do = func() { wd.ValidateTracker.Track(tmp) } + do = func() { wd.ValidatingWebhookTracker.Track(tmp) } } do() if err != nil { diff --git a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/plugin_test.go b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/plugin_test.go index af2f92523e3..f4d6b3df7bf 100644 --- a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/plugin_test.go +++ b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/plugin_test.go @@ -236,7 +236,7 @@ func TestValidateWebhookDuration(ts *testing.T) { ts.Run(test.Name, func(t *testing.T) { ctx := context.TODO() if test.InitContext { - ctx = request.WithWebhookDurationAndCustomClock(ctx, &clk) + ctx = request.WithLatencyTrackersAndCustomClock(ctx, &clk) } wh, err := NewValidatingAdmissionWebhook(nil) if err != nil { @@ -261,7 +261,7 @@ func TestValidateWebhookDuration(ts *testing.T) { } _ = wh.Validate(ctx, webhooktesting.NewAttribute(ns, nil, test.IsDryRun), objectInterfaces) - wd, ok := request.WebhookDurationFrom(ctx) + wd, ok := request.LatencyTrackersFrom(ctx) if !ok { if test.InitContext { t.Errorf("expected webhook duration to be initialized") @@ -272,11 +272,11 @@ func TestValidateWebhookDuration(ts *testing.T) { t.Errorf("expected webhook duration to not be initialized") return } - if wd.AdmitTracker.GetLatency() != 0 { - t.Errorf("expected admit duration to be equal to 0 got %q", wd.AdmitTracker.GetLatency()) + if wd.MutatingWebhookTracker.GetLatency() != 0 { + t.Errorf("expected admit duration to be equal to 0 got %q", wd.MutatingWebhookTracker.GetLatency()) } - if wd.ValidateTracker.GetLatency() < test.ExpectedDurationMax { - t.Errorf("expected validate duraion to be greater or equal to %q got %q", test.ExpectedDurationMax, wd.ValidateTracker.GetLatency()) + if wd.ValidatingWebhookTracker.GetLatency() < test.ExpectedDurationMax { + t.Errorf("expected validate duraion to be greater or equal to %q got %q", test.ExpectedDurationMax, wd.ValidatingWebhookTracker.GetLatency()) } }) } diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/webhook_duration.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/webhook_duration.go index e81b340eba7..39747a9996f 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/webhook_duration.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/webhook_duration.go @@ -22,12 +22,13 @@ import ( "k8s.io/apiserver/pkg/endpoints/request" ) -// WithWebhookDuration adds WebhookDuration trackers to the -// context associated with a request. -func WithWebhookDuration(handler http.Handler) http.Handler { +// WithLatencyTrackers adds a LatencyTrackers instance to the +// context associated with a request so that we can measure latency +// incurred in various components within the apiserver. +func WithLatencyTrackers(handler http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { ctx := req.Context() - req = req.WithContext(request.WithWebhookDuration(ctx)) + req = req.WithContext(request.WithLatencyTrackers(ctx)) handler.ServeHTTP(w, req) }) } 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 445dfb1c297..b67e81760bb 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go @@ -482,8 +482,8 @@ func MonitorRequest(req *http.Request, verb, group, version, resource, subresour } } requestLatencies.WithContext(req.Context()).WithLabelValues(reportedVerb, dryRun, group, version, resource, subresource, scope, component).Observe(elapsedSeconds) - if wd, ok := request.WebhookDurationFrom(req.Context()); ok { - sloLatency := elapsedSeconds - (wd.AdmitTracker.GetLatency() + wd.ValidateTracker.GetLatency()).Seconds() + if wd, ok := request.LatencyTrackersFrom(req.Context()); ok { + sloLatency := elapsedSeconds - (wd.MutatingWebhookTracker.GetLatency() + wd.ValidatingWebhookTracker.GetLatency()).Seconds() requestSloLatencies.WithContext(req.Context()).WithLabelValues(reportedVerb, group, version, resource, subresource, scope, component).Observe(sloLatency) } // We are only interested in response sizes of read requests. diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/request/webhook_duration.go b/staging/src/k8s.io/apiserver/pkg/endpoints/request/webhook_duration.go index 209b33cdf11..641e8c7671b 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/request/webhook_duration.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/request/webhook_duration.go @@ -85,38 +85,43 @@ func newMaxLatencyTracker(c clock.Clock) DurationTracker { } } -// WebhookDuration stores trackers used to measure webhook request durations. -// Since admit webhooks are done sequentially duration is aggregated using -// sum function. Validate webhooks are done in parallel so max function -// is used. -type WebhookDuration struct { - AdmitTracker DurationTracker - ValidateTracker DurationTracker +// LatencyTrackers stores trackers used to measure latecny incurred in +// components within the apiserver. +type LatencyTrackers struct { + // MutatingWebhookTracker tracks the latency incurred in mutating webhook(s). + // Since mutating webhooks are done sequentially, latency + // is aggregated using sum function. + MutatingWebhookTracker DurationTracker + + // ValidatingWebhookTracker tracks the latency incurred in validating webhook(s). + // Validate webhooks are done in parallel, so max function is used. + ValidatingWebhookTracker DurationTracker } -type webhookDurationKeyType int +type latencyTrackersKeyType int -// webhookDurationKey is the WebhookDuration (the time the request spent waiting -// for the webhooks to finish) key for the context. -const webhookDurationKey webhookDurationKeyType = iota +// latencyTrackersKey is the key that associates a LatencyTrackers +// instance with the request context. +const latencyTrackersKey latencyTrackersKeyType = iota -// WithWebhookDuration returns a copy of parent context to which the -// WebhookDuration trackers are added. -func WithWebhookDuration(parent context.Context) context.Context { - return WithWebhookDurationAndCustomClock(parent, clock.RealClock{}) +// WithLatencyTrackers returns a copy of parent context to which an +// instance of LatencyTrackers is added. +func WithLatencyTrackers(parent context.Context) context.Context { + return WithLatencyTrackersAndCustomClock(parent, clock.RealClock{}) } -// WithWebhookDurationAndCustomClock returns a copy of parent context to which -// the WebhookDuration trackers are added. Tracers use given clock. -func WithWebhookDurationAndCustomClock(parent context.Context, c clock.Clock) context.Context { - return WithValue(parent, webhookDurationKey, &WebhookDuration{ - AdmitTracker: newSumLatencyTracker(c), - ValidateTracker: newMaxLatencyTracker(c), +// WithLatencyTrackersAndCustomClock returns a copy of parent context to which +// an instance of LatencyTrackers is added. Tracers use given clock. +func WithLatencyTrackersAndCustomClock(parent context.Context, c clock.Clock) context.Context { + return WithValue(parent, latencyTrackersKey, &LatencyTrackers{ + MutatingWebhookTracker: newSumLatencyTracker(c), + ValidatingWebhookTracker: newMaxLatencyTracker(c), }) } -// WebhookDurationFrom returns the value of the WebhookDuration key from the specified context. -func WebhookDurationFrom(ctx context.Context) (*WebhookDuration, bool) { - wd, ok := ctx.Value(webhookDurationKey).(*WebhookDuration) +// LatencyTrackersFrom returns the associated LatencyTrackers instance +// from the specified context. +func LatencyTrackersFrom(ctx context.Context) (*LatencyTrackers, bool) { + wd, ok := ctx.Value(latencyTrackersKey).(*LatencyTrackers) return wd, ok && wd != nil } diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/request/webhook_duration_test.go b/staging/src/k8s.io/apiserver/pkg/endpoints/request/webhook_duration_test.go index f828391cc78..9119047c12a 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/request/webhook_duration_test.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/request/webhook_duration_test.go @@ -24,7 +24,7 @@ import ( clocktesting "k8s.io/utils/clock/testing" ) -func TestWebhookDurationFrom(t *testing.T) { +func TestLatencyTrackersFrom(t *testing.T) { type testCase struct { Durations []time.Duration SumDurations time.Duration @@ -37,37 +37,37 @@ func TestWebhookDurationFrom(t *testing.T) { } t.Run("TestWebhookDurationFrom", func(t *testing.T) { parent := context.TODO() - _, ok := WebhookDurationFrom(parent) + _, ok := LatencyTrackersFrom(parent) if ok { - t.Error("expected WebhookDurationFrom to not be initialized") + t.Error("expected LatencyTrackersFrom to not be initialized") } clk := clocktesting.FakeClock{} - ctx := WithWebhookDurationAndCustomClock(parent, &clk) - wd, ok := WebhookDurationFrom(ctx) + ctx := WithLatencyTrackersAndCustomClock(parent, &clk) + wd, ok := LatencyTrackersFrom(ctx) if !ok { - t.Error("expected webhook duration to be initialized") + t.Error("expected LatencyTrackersFrom to be initialized") } - if wd.AdmitTracker.GetLatency() != 0 || wd.ValidateTracker.GetLatency() != 0 { + if wd.MutatingWebhookTracker.GetLatency() != 0 || wd.ValidatingWebhookTracker.GetLatency() != 0 { t.Error("expected values to be initialized to 0") } for _, d := range tc.Durations { - wd.AdmitTracker.Track(func() { clk.Step(d) }) - wd.ValidateTracker.Track(func() { clk.Step(d) }) + wd.MutatingWebhookTracker.Track(func() { clk.Step(d) }) + wd.ValidatingWebhookTracker.Track(func() { clk.Step(d) }) } - wd, ok = WebhookDurationFrom(ctx) + wd, ok = LatencyTrackersFrom(ctx) if !ok { t.Errorf("expected webhook duration to be initialized") } - if wd.AdmitTracker.GetLatency() != tc.SumDurations { - t.Errorf("expected admit duration: %q, but got: %q", tc.SumDurations, wd.AdmitTracker.GetLatency()) + if wd.MutatingWebhookTracker.GetLatency() != tc.SumDurations { + t.Errorf("expected admit duration: %q, but got: %q", tc.SumDurations, wd.MutatingWebhookTracker.GetLatency()) } - if wd.ValidateTracker.GetLatency() != tc.MaxDuration { - t.Errorf("expected validate duration: %q, but got: %q", tc.MaxDuration, wd.ValidateTracker.GetLatency()) + if wd.ValidatingWebhookTracker.GetLatency() != tc.MaxDuration { + t.Errorf("expected validate duration: %q, but got: %q", tc.MaxDuration, wd.ValidatingWebhookTracker.GetLatency()) } }) } diff --git a/staging/src/k8s.io/apiserver/pkg/server/config.go b/staging/src/k8s.io/apiserver/pkg/server/config.go index fb3179c4628..375c4dc24c5 100644 --- a/staging/src/k8s.io/apiserver/pkg/server/config.go +++ b/staging/src/k8s.io/apiserver/pkg/server/config.go @@ -762,7 +762,7 @@ func BuildHandlerChainWithStorageVersionPrecondition(apiHandler http.Handler, c } func DefaultBuildHandlerChain(apiHandler http.Handler, c *Config) http.Handler { - handler := genericapifilters.WithWebhookDuration(apiHandler) + handler := genericapifilters.WithLatencyTrackers(apiHandler) handler = filterlatency.TrackCompleted(handler) handler = genericapifilters.WithAuthorization(handler, c.Authorization.Authorizer, c.Serializer) handler = filterlatency.TrackStarted(handler, "authorization")