From f791717aad8fc3ad6171ff88bdedfaac7162b077 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Charles-Edouard=20Br=C3=A9t=C3=A9ch=C3=A9?= Date: Thu, 8 Sep 2022 09:34:55 +0200 Subject: [PATCH] refactor: webhook propagate start time along handlers (#4529) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Charles-Edouard Brétéché Signed-off-by: Charles-Edouard Brétéché --- pkg/webhooks/handlers/admission.go | 10 +++++----- pkg/webhooks/policy/handlers.go | 10 ++-------- pkg/webhooks/resource/handlers.go | 12 +++++------- pkg/webhooks/resource/handlers_test.go | 15 ++++++++------- pkg/webhooks/server.go | 8 ++++---- 5 files changed, 24 insertions(+), 31 deletions(-) diff --git a/pkg/webhooks/handlers/admission.go b/pkg/webhooks/handlers/admission.go index ae5ba54bf4..08f9ad2a4e 100644 --- a/pkg/webhooks/handlers/admission.go +++ b/pkg/webhooks/handlers/admission.go @@ -16,7 +16,7 @@ import ( admissionv1 "k8s.io/api/admission/v1" ) -type AdmissionHandler func(logr.Logger, *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse +type AdmissionHandler func(logr.Logger, *admissionv1.AdmissionRequest, time.Time) *admissionv1.AdmissionResponse func Admission(logger logr.Logger, inner AdmissionHandler) http.HandlerFunc { return func(writer http.ResponseWriter, request *http.Request) { @@ -57,7 +57,7 @@ func Admission(logger logr.Logger, inner AdmissionHandler) http.HandlerFunc { Allowed: true, UID: admissionReview.Request.UID, } - adminssionResponse := inner(logger, admissionReview.Request) + adminssionResponse := inner(logger, admissionReview.Request, startTime) if adminssionResponse != nil { admissionReview.Response = adminssionResponse } @@ -91,16 +91,16 @@ func Admission(logger logr.Logger, inner AdmissionHandler) http.HandlerFunc { } func Filter(c config.Configuration, inner AdmissionHandler) AdmissionHandler { - return func(logger logr.Logger, request *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse { + return func(logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse { if c.ToFilter(request.Kind.Kind, request.Namespace, request.Name) { return nil } - return inner(logger, request) + return inner(logger, request, startTime) } } func Verify(m *webhookconfig.Monitor) AdmissionHandler { - return func(logger logr.Logger, request *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse { + return func(logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse { logger.V(6).Info("incoming request", "last admission request timestamp", m.Time()) return admissionutils.Response(true) } diff --git a/pkg/webhooks/policy/handlers.go b/pkg/webhooks/policy/handlers.go index e4ea9d647e..d0d8428db8 100644 --- a/pkg/webhooks/policy/handlers.go +++ b/pkg/webhooks/policy/handlers.go @@ -28,7 +28,7 @@ func NewHandlers(client dclient.Interface, openAPIController *openapi.Controller } } -func (h *handlers) Validate(logger logr.Logger, request *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse { +func (h *handlers) Validate(logger logr.Logger, request *admissionv1.AdmissionRequest, _ time.Time) *admissionv1.AdmissionResponse { if request.SubResource != "" { logger.V(4).Info("skip policy validation on status update") return admissionutils.Response(true) @@ -38,9 +38,6 @@ func (h *handlers) Validate(logger logr.Logger, request *admissionv1.AdmissionRe logger.Error(err, "failed to unmarshal policies from admission request") return admissionutils.ResponseWithMessage(true, fmt.Sprintf("failed to validate policy, check kyverno controller logs for details: %v", err)) } - startTime := time.Now() - logger.V(3).Info("start policy change validation") - defer logger.V(3).Info("finished policy change validation", "time", time.Since(startTime).String()) response, err := policyvalidate.Validate(policy, h.client, false, h.openAPIController) if err != nil { logger.Error(err, "policy validation errors") @@ -52,7 +49,7 @@ func (h *handlers) Validate(logger logr.Logger, request *admissionv1.AdmissionRe return admissionutils.Response(true) } -func (h *handlers) Mutate(logger logr.Logger, request *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse { +func (h *handlers) Mutate(logger logr.Logger, request *admissionv1.AdmissionRequest, _ time.Time) *admissionv1.AdmissionResponse { if toggle.AutogenInternals.Enabled() { return admissionutils.Response(true) } @@ -65,9 +62,6 @@ func (h *handlers) Mutate(logger logr.Logger, request *admissionv1.AdmissionRequ logger.Error(err, "failed to unmarshal policies from admission request") return admissionutils.ResponseWithMessage(true, fmt.Sprintf("failed to default value, check kyverno controller logs for details: %v", err)) } - startTime := time.Now() - logger.V(3).Info("start policy change mutation") - defer logger.V(3).Info("finished policy change mutation", "time", time.Since(startTime).String()) if patches, updateMsgs := policymutation.GenerateJSONPatchesForDefaults(policy, logger); len(patches) != 0 { return admissionutils.ResponseWithMessageAndPatch(true, strings.Join(updateMsgs, "'"), patches) } diff --git a/pkg/webhooks/resource/handlers.go b/pkg/webhooks/resource/handlers.go index 55c98d005b..d9ee093e47 100644 --- a/pkg/webhooks/resource/handlers.go +++ b/pkg/webhooks/resource/handlers.go @@ -98,7 +98,7 @@ func NewHandlers( } } -func (h *handlers) Validate(logger logr.Logger, request *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse { +func (h *handlers) Validate(logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse { if request.Operation == admissionv1.Delete { h.handleDelete(logger, request) } @@ -110,7 +110,6 @@ func (h *handlers) Validate(logger logr.Logger, request *admissionv1.AdmissionRe logger.V(4).Info("received an admission request in validating webhook") // timestamp at which this admission request got triggered - requestTime := time.Now() policies := h.pCache.GetPolicies(policycache.ValidateEnforce, kind, request.Namespace) mutatePolicies := h.pCache.GetPolicies(policycache.Mutate, kind, request.Namespace) generatePolicies := h.pCache.GetPolicies(policycache.Generate, kind, request.Namespace) @@ -143,14 +142,14 @@ func (h *handlers) Validate(logger logr.Logger, request *admissionv1.AdmissionRe prGenerator: h.prGenerator, } - ok, msg, warnings := vh.handleValidation(h.metricsConfig, request, policies, policyContext, namespaceLabels, requestTime) + ok, msg, warnings := vh.handleValidation(h.metricsConfig, request, policies, policyContext, namespaceLabels, startTime) if !ok { logger.Info("admission request denied") return admissionutils.ResponseFailure(msg) } h.auditHandler.Add(request.DeepCopy()) - go h.createUpdateRequests(logger, request, policyContext, generatePolicies, mutatePolicies, requestTime) + go h.createUpdateRequests(logger, request, policyContext, generatePolicies, mutatePolicies, startTime) if warnings != nil { return admissionutils.ResponseSuccessWithWarnings(warnings) @@ -160,7 +159,7 @@ func (h *handlers) Validate(logger logr.Logger, request *admissionv1.AdmissionRe return admissionutils.ResponseSuccess() } -func (h *handlers) Mutate(logger logr.Logger, request *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse { +func (h *handlers) Mutate(logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse { if webhookutils.ExcludeKyvernoResources(request.Kind.Kind) { return admissionutils.ResponseSuccess() } @@ -176,7 +175,6 @@ func (h *handlers) Mutate(logger logr.Logger, request *admissionv1.AdmissionRequ kind := request.Kind.Kind logger = logger.WithValues("kind", kind) logger.V(4).Info("received an admission request in mutating webhook") - requestTime := time.Now() mutatePolicies := h.pCache.GetPolicies(policycache.Mutate, kind, request.Namespace) verifyImagesPolicies := h.pCache.GetPolicies(policycache.VerifyImagesMutate, kind, request.Namespace) if len(mutatePolicies) == 0 && len(verifyImagesPolicies) == 0 { @@ -193,7 +191,7 @@ func (h *handlers) Mutate(logger logr.Logger, request *admissionv1.AdmissionRequ if err := enginectx.MutateResourceWithImageInfo(request.Object.Raw, policyContext.JSONContext); err != nil { logger.Error(err, "failed to patch images info to resource, policies that mutate images may be impacted") } - mutatePatches, mutateWarnings, err := h.applyMutatePolicies(logger, request, policyContext, mutatePolicies, requestTime) + mutatePatches, mutateWarnings, err := h.applyMutatePolicies(logger, request, policyContext, mutatePolicies, startTime) if err != nil { logger.Error(err, "mutation failed") return admissionutils.ResponseFailure(err.Error()) diff --git a/pkg/webhooks/resource/handlers_test.go b/pkg/webhooks/resource/handlers_test.go index cbf35d1298..9b183e49ea 100644 --- a/pkg/webhooks/resource/handlers_test.go +++ b/pkg/webhooks/resource/handlers_test.go @@ -4,6 +4,7 @@ import ( "context" "encoding/json" "testing" + "time" kyverno "github.com/kyverno/kyverno/api/kyverno/v1" "github.com/kyverno/kyverno/pkg/policycache" @@ -175,18 +176,18 @@ func Test_AdmissionResponseValid(t *testing.T) { }, } - response := handlers.Mutate(logger, request) + response := handlers.Mutate(logger, request, time.Now()) assert.Assert(t, response != nil) assert.Equal(t, response.Allowed, true) - response = handlers.Validate(logger, request) + response = handlers.Validate(logger, request, time.Now()) assert.Equal(t, response.Allowed, true) assert.Equal(t, len(response.Warnings), 0) validPolicy.Spec.ValidationFailureAction = kyverno.Enforce policyCache.Set(key, &validPolicy) - response = handlers.Validate(logger, request) + response = handlers.Validate(logger, request, time.Now()) assert.Equal(t, response.Allowed, false) assert.Equal(t, len(response.Warnings), 0) @@ -219,7 +220,7 @@ func Test_AdmissionResponseInvalid(t *testing.T) { invalidPolicy.Spec.ValidationFailureAction = kyverno.Enforce policyCache.Set(keyInvalid, &invalidPolicy) - response := handlers.Validate(logger, request) + response := handlers.Validate(logger, request, time.Now()) assert.Equal(t, response.Allowed, false) assert.Equal(t, len(response.Warnings), 0) @@ -227,7 +228,7 @@ func Test_AdmissionResponseInvalid(t *testing.T) { invalidPolicy.Spec.FailurePolicy = &ignore policyCache.Set(keyInvalid, &invalidPolicy) - response = handlers.Validate(logger, request) + response = handlers.Validate(logger, request, time.Now()) assert.Equal(t, response.Allowed, true) assert.Equal(t, len(response.Warnings), 1) } @@ -260,7 +261,7 @@ func Test_ImageVerify(t *testing.T) { policy.Spec.ValidationFailureAction = kyverno.Enforce policyCache.Set(key, &policy) - response := handlers.Mutate(logger, request) + response := handlers.Mutate(logger, request, time.Now()) assert.Equal(t, response.Allowed, false) assert.Equal(t, len(response.Warnings), 0) @@ -268,7 +269,7 @@ func Test_ImageVerify(t *testing.T) { policy.Spec.FailurePolicy = &ignore policyCache.Set(key, &policy) - response = handlers.Mutate(logger, request) + response = handlers.Mutate(logger, request, time.Now()) assert.Equal(t, response.Allowed, false) assert.Equal(t, len(response.Warnings), 0) } diff --git a/pkg/webhooks/server.go b/pkg/webhooks/server.go index 1416cdab76..234da103a5 100644 --- a/pkg/webhooks/server.go +++ b/pkg/webhooks/server.go @@ -29,9 +29,9 @@ type Server interface { type Handlers interface { // Mutate performs the mutation of policy resources - Mutate(logr.Logger, *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse + Mutate(logr.Logger, *admissionv1.AdmissionRequest, time.Time) *admissionv1.AdmissionResponse // Validate performs the validation check on policy resources - Validate(logr.Logger, *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse + Validate(logr.Logger, *admissionv1.AdmissionRequest, time.Time) *admissionv1.AdmissionResponse } type server struct { @@ -124,7 +124,7 @@ func (s *server) cleanup(ctx context.Context) { } func protect(inner handlers.AdmissionHandler) handlers.AdmissionHandler { - return func(logger logr.Logger, request *admissionv1.AdmissionRequest) *admissionv1.AdmissionResponse { + return func(logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse { if toggle.ProtectManagedResources.Enabled() { newResource, oldResource, err := utils.ExtractResources(nil, request) if err != nil { @@ -141,7 +141,7 @@ func protect(inner handlers.AdmissionHandler) handlers.AdmissionHandler { } } } - return inner(logger, request) + return inner(logger, request, startTime) } }