From b7230e0bdc3479b867acd2fd0d7192b1182c59d4 Mon Sep 17 00:00:00 2001 From: alex <8968914+acpana@users.noreply.github.com> Date: Tue, 30 May 2023 16:56:19 -0700 Subject: [PATCH] refactor: loggers in webhook handlers (#2786) Signed-off-by: Alex Pana <8968914+acpana@users.noreply.github.com> --- pkg/webhook/mutation.go | 19 +++++++++++-------- pkg/webhook/mutation_test.go | 2 ++ pkg/webhook/mutator_validation_test.go | 4 ++-- pkg/webhook/policy.go | 25 ++++++++++++++----------- pkg/webhook/policy_benchmark_test.go | 1 + pkg/webhook/policy_test.go | 11 ++++++++--- 6 files changed, 38 insertions(+), 24 deletions(-) diff --git a/pkg/webhook/mutation.go b/pkg/webhook/mutation.go index 8631b568827..cf6ffcfa0df 100644 --- a/pkg/webhook/mutation.go +++ b/pkg/webhook/mutation.go @@ -18,6 +18,7 @@ import ( "net/http" "time" + "github.com/go-logr/logr" "github.com/open-policy-agent/cert-controller/pkg/rotator" "github.com/open-policy-agent/gatekeeper/v3/apis" "github.com/open-policy-agent/gatekeeper/v3/pkg/controller/config/process" @@ -63,6 +64,7 @@ func AddMutatingWebhook(mgr manager.Manager, deps Dependencies) error { eventBroadcaster := record.NewBroadcaster() kubeClient := kubernetes.NewForConfigOrDie(mgr.GetConfig()) + log := log.WithValues("hookType", "mutation") eventBroadcaster.StartRecordingToSink(&clientcorev1.EventSinkImpl{Interface: kubeClient.CoreV1().Events("")}) recorder := eventBroadcaster.NewRecorder( scheme.Scheme, @@ -80,6 +82,7 @@ func AddMutatingWebhook(mgr manager.Manager, deps Dependencies) error { }, mutationSystem: deps.MutationSystem, deserializer: codecs.UniversalDeserializer(), + log: log, }, } @@ -99,12 +102,12 @@ type mutationHandler struct { webhookHandler mutationSystem *mutation.System deserializer runtime.Decoder + log logr.Logger } // Handle the mutation request // nolint: gocritic // Must accept admission.Request to satisfy interface. func (h *mutationHandler) Handle(ctx context.Context, req admission.Request) admission.Response { - log := log.WithValues("hookType", "mutation") timeStart := time.Now() if isGkServiceAccount(req.AdmissionRequest.UserInfo) { @@ -124,7 +127,7 @@ func (h *mutationHandler) Handle(ctx context.Context, req admission.Request) adm defer func() { if h.reporter != nil { if err := h.reporter.ReportMutationRequest(ctx, requestResponse, time.Since(timeStart)); err != nil { - log.Error(err, "failed to report request") + h.log.Error(err, "failed to report request") } } }() @@ -132,7 +135,7 @@ func (h *mutationHandler) Handle(ctx context.Context, req admission.Request) adm // namespace is excluded from webhook using config isExcludedNamespace, err := h.skipExcludedNamespace(&req.AdmissionRequest, process.Mutation) if err != nil { - log.Error(err, "error while excluding namespace") + h.log.Error(err, "error while excluding namespace") } if isExcludedNamespace { @@ -164,13 +167,13 @@ func (h *mutationHandler) mutateRequest(ctx context.Context, req *admission.Requ case req.AdmissionRequest.Namespace != "": if err := h.client.Get(ctx, types.NamespacedName{Name: req.AdmissionRequest.Namespace}, ns); err != nil { if !k8serrors.IsNotFound(err) { - log.Error(err, "error retrieving namespace", "name", req.AdmissionRequest.Namespace) + h.log.Error(err, "error retrieving namespace", "name", req.AdmissionRequest.Namespace) return admission.Errored(int32(http.StatusInternalServerError), err) } // bypass cached client and ask api-server directly err = h.reader.Get(ctx, types.NamespacedName{Name: req.AdmissionRequest.Namespace}, ns) if err != nil { - log.Error(err, "error retrieving namespace from API server", "name", req.AdmissionRequest.Namespace) + h.log.Error(err, "error retrieving namespace from API server", "name", req.AdmissionRequest.Namespace) return admission.Errored(int32(http.StatusInternalServerError), err) } } @@ -180,7 +183,7 @@ func (h *mutationHandler) mutateRequest(ctx context.Context, req *admission.Requ obj := unstructured.Unstructured{} err := obj.UnmarshalJSON(req.Object.Raw) if err != nil { - log.Error(err, "failed to unmarshal", "object", string(req.Object.Raw)) + h.log.Error(err, "failed to unmarshal", "object", string(req.Object.Raw)) return admission.Errored(int32(http.StatusInternalServerError), err) } @@ -198,7 +201,7 @@ func (h *mutationHandler) mutateRequest(ctx context.Context, req *admission.Requ } mutated, err := h.mutationSystem.Mutate(mutable) if err != nil { - log.Error(err, "failed to mutate object", "object", string(req.Object.Raw)) + h.log.Error(err, "failed to mutate object", "object", string(req.Object.Raw)) return admission.Errored(int32(http.StatusInternalServerError), err) } if !mutated { @@ -209,7 +212,7 @@ func (h *mutationHandler) mutateRequest(ctx context.Context, req *admission.Requ newJSON, err := mutable.Object.MarshalJSON() if err != nil { - log.Error(err, "failed to marshal mutated object", "object", obj) + h.log.Error(err, "failed to marshal mutated object", "object", obj) return admission.Errored(int32(http.StatusInternalServerError), err) } resp := admission.PatchResponseFromRaw(req.Object.Raw, newJSON) diff --git a/pkg/webhook/mutation_test.go b/pkg/webhook/mutation_test.go index 1af76a452f3..de25e294478 100644 --- a/pkg/webhook/mutation_test.go +++ b/pkg/webhook/mutation_test.go @@ -64,6 +64,7 @@ func TestWebhookAssign(t *testing.T) { }, mutationSystem: sys, deserializer: codecs.UniversalDeserializer(), + log: log, } raw := []byte(`{"apiVersion": "v1", "kind": "Pod", "metadata": {"name": "acbd","namespace": "ns1"}}`) @@ -130,6 +131,7 @@ func TestWebhookAssignMetadata(t *testing.T) { }, mutationSystem: sys, deserializer: codecs.UniversalDeserializer(), + log: log, } raw := []byte(`{"apiVersion": "v1", "kind": "Pod", "metadata": {"name": "acbd","namespace": "ns1"}}`) diff --git a/pkg/webhook/mutator_validation_test.go b/pkg/webhook/mutator_validation_test.go index 2238999956f..ac222cf8402 100644 --- a/pkg/webhook/mutator_validation_test.go +++ b/pkg/webhook/mutator_validation_test.go @@ -97,7 +97,7 @@ spec: } for _, tt := range tc { t.Run(tt.Name, func(t *testing.T) { - handler := validationHandler{webhookHandler: webhookHandler{}} + handler := validationHandler{webhookHandler: webhookHandler{}, log: log} b, err := yaml.YAMLToJSON([]byte(tt.AssignMeta)) if err != nil { t.Fatalf("Error parsing yaml: %s", err) @@ -348,7 +348,7 @@ spec: } for _, tt := range tc { t.Run(tt.Name, func(t *testing.T) { - handler := validationHandler{webhookHandler: webhookHandler{}} + handler := validationHandler{webhookHandler: webhookHandler{}, log: log} b, err := yaml.YAMLToJSON([]byte(tt.Assign)) if err != nil { t.Fatalf("Error parsing yaml: %s", err) diff --git a/pkg/webhook/policy.go b/pkg/webhook/policy.go index 2babf24d425..37e8bd88b09 100644 --- a/pkg/webhook/policy.go +++ b/pkg/webhook/policy.go @@ -25,6 +25,7 @@ import ( "strings" "time" + "github.com/go-logr/logr" "github.com/open-policy-agent/cert-controller/pkg/rotator" externaldataUnversioned "github.com/open-policy-agent/frameworks/constraint/pkg/apis/externaldata/unversioned" constraintclient "github.com/open-policy-agent/frameworks/constraint/pkg/client" @@ -92,6 +93,7 @@ func AddPolicyWebhook(mgr manager.Manager, deps Dependencies) error { if err != nil { return err } + log := log.WithValues("hookType", "validation") eventBroadcaster := record.NewBroadcaster() kubeClient := kubernetes.NewForConfigOrDie(mgr.GetConfig()) eventBroadcaster.StartRecordingToSink(&clientcorev1.EventSinkImpl{Interface: kubeClient.CoreV1().Events("")}) @@ -110,6 +112,7 @@ func AddPolicyWebhook(mgr manager.Manager, deps Dependencies) error { eventRecorder: recorder, gkNamespace: util.GetNamespace(), }, + log: log, } threadCount := *maxServingThreads if threadCount < 1 { @@ -134,13 +137,12 @@ type validationHandler struct { mutationSystem *mutation.System expansionSystem *expansion.System semaphore chan struct{} + log logr.Logger } // Handle the validation request // nolint: gocritic // Must accept admission.Request as a struct to satisfy Handler interface. func (h *validationHandler) Handle(ctx context.Context, req admission.Request) admission.Response { - log := log.WithValues("hookType", "validation") - timeStart := time.Now() if isGkServiceAccount(req.AdmissionRequest.UserInfo) { @@ -171,7 +173,7 @@ func (h *validationHandler) Handle(ctx context.Context, req admission.Request) a isDryRun = "true" } if err := h.reporter.ReportValidationRequest(ctx, requestResponse, isDryRun, time.Since(timeStart)); err != nil { - log.Error(err, "failed to report request") + h.log.Error(err, "failed to report request") } } }() @@ -179,7 +181,7 @@ func (h *validationHandler) Handle(ctx context.Context, req admission.Request) a // namespace is excluded from webhook using config isExcludedNamespace, err := h.skipExcludedNamespace(&req.AdmissionRequest, process.Webhook) if err != nil { - log.Error(err, "error while excluding namespace") + h.log.Error(err, "error while excluding namespace") } if isExcludedNamespace { @@ -189,7 +191,7 @@ func (h *validationHandler) Handle(ctx context.Context, req admission.Request) a resp, err := h.reviewRequest(ctx, &req) if err != nil { - log.Error(err, "error executing query") + h.log.Error(err, "error executing query") requestResponse = errorResponse return admission.Errored(http.StatusInternalServerError, err) } @@ -197,7 +199,7 @@ func (h *validationHandler) Handle(ctx context.Context, req admission.Request) a if *logStatsAdmission { logging.LogStatsEntries( h.opa, - log.WithValues( + h.log.WithValues( logging.Process, "admission", logging.EventType, "review_response_stats", logging.ResourceGroup, req.AdmissionRequest.Kind.Group, @@ -266,7 +268,7 @@ func (h *validationHandler) getValidationMessages(res []*rtypes.Result, req *adm continue } if *logDenies { - log.WithValues( + h.log.WithValues( logging.Process, "admission", logging.EventType, "violation", logging.ConstraintName, r.Constraint.GetName(), @@ -280,7 +282,8 @@ func (h *validationHandler) getValidationMessages(res []*rtypes.Result, req *adm logging.ResourceNamespace, req.AdmissionRequest.Namespace, logging.ResourceName, resourceName, logging.RequestUsername, req.AdmissionRequest.UserInfo.Username, - ).Info(fmt.Sprintf("denied admission: %s", r.Msg)) + ).Info( + fmt.Sprintf("denied admission: %s", r.Msg)) } if *emitAdmissionEvents { annotations := map[string]string{ @@ -603,14 +606,14 @@ func (h *validationHandler) reviewRequest(ctx context.Context, req *admission.Re func (h *validationHandler) review(ctx context.Context, review interface{}, trace bool, dump bool) (*rtypes.Responses, error) { resp, err := h.opa.Review(ctx, review, drivers.Tracing(trace), drivers.Stats(*logStatsAdmission)) if resp != nil && trace { - log.Info(resp.TraceDump()) + h.log.Info(resp.TraceDump()) } if dump { dump, err := h.opa.Dump(ctx) if err != nil { - log.Error(err, "dump error") + h.log.Error(err, "dump error") } else { - log.Info(dump) + h.log.Info(dump) } } diff --git a/pkg/webhook/policy_benchmark_test.go b/pkg/webhook/policy_benchmark_test.go index 1905bc5f927..e3bd8de937b 100644 --- a/pkg/webhook/policy_benchmark_test.go +++ b/pkg/webhook/policy_benchmark_test.go @@ -308,6 +308,7 @@ func BenchmarkValidationHandler(b *testing.B) { client: c, injectedConfig: cfg, }, + log: log, } // create T templates diff --git a/pkg/webhook/policy_test.go b/pkg/webhook/policy_test.go index 2830ef73ec1..ae10f619304 100644 --- a/pkg/webhook/policy_test.go +++ b/pkg/webhook/policy_test.go @@ -242,7 +242,7 @@ func TestTemplateValidation(t *testing.T) { if err != nil { t.Fatalf("Could not initialize OPA: %s", err) } - handler := validationHandler{opa: opa, webhookHandler: webhookHandler{}} + handler := validationHandler{opa: opa, webhookHandler: webhookHandler{}, log: log} b, err := json.Marshal(tt.Template) if err != nil { @@ -359,6 +359,7 @@ func TestReviewRequest(t *testing.T) { client: tt.CachedClient, reader: tt.APIReader, }, + log: log, } if maxThreads > 0 { handler.semaphore = make(chan struct{}, maxThreads) @@ -431,6 +432,7 @@ func TestReviewDefaultNS(t *testing.T) { reader: &nsGetter{}, processExcluder: pe, }, + log: log, } if maxThreads > 0 { handler.semaphore = make(chan struct{}, maxThreads) @@ -522,6 +524,7 @@ func TestConstraintValidation(t *testing.T) { opa: opa, expansionSystem: expansion.NewSystem(mutation.NewSystem(mutation.SystemOpts{})), webhookHandler: webhookHandler{}, + log: log, } b, err := yaml.YAMLToJSON([]byte(tt.Constraint)) if err != nil { @@ -649,6 +652,7 @@ func TestTracing(t *testing.T) { opa: opa, expansionSystem: expansion.NewSystem(mutation.NewSystem(mutation.SystemOpts{})), webhookHandler: webhookHandler{injectedConfig: tt.Cfg}, + log: log, } if maxThreads > 0 { handler.semaphore = make(chan struct{}, maxThreads) @@ -825,6 +829,7 @@ func TestGetValidationMessages(t *testing.T) { opa: opa, expansionSystem: expansion.NewSystem(mutation.NewSystem(mutation.SystemOpts{})), webhookHandler: webhookHandler{}, + log: log, } if maxThreads > 0 { handler.semaphore = make(chan struct{}, maxThreads) @@ -875,7 +880,7 @@ func TestValidateConfigResource(t *testing.T) { for _, tt := range tc { t.Run(tt.TestName, func(t *testing.T) { - handler := validationHandler{} + handler := validationHandler{log: log} req := &admission.Request{ AdmissionRequest: admissionv1.AdmissionRequest{ Name: tt.Name, @@ -922,7 +927,7 @@ func TestValidateProvider(t *testing.T) { } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - h := &validationHandler{} + h := &validationHandler{log: log} b, err := yaml.YAMLToJSON([]byte(tt.provider)) if err != nil { t.Fatalf("Error parsing yaml: %s", err)