From 9a1089dbabd89b69dbbf67af7d9faa9982746b97 Mon Sep 17 00:00:00 2001 From: Christian Heike Date: Wed, 9 Jun 2021 14:05:00 +0200 Subject: [PATCH] Improvements for logging --- pkg/webhook/facade/api.go | 8 ++++++-- pkg/webhook/facade/v1_admission_review.go | 8 +++++++- pkg/webhook/facade/v1_admission_review_test.go | 7 ++++++- pkg/webhook/facade/v1beta1_admission_review.go | 8 +++++++- pkg/webhook/facade/v1beta1_admission_review_test.go | 7 ++++++- pkg/webhook/handler/api.go | 2 +- pkg/webhook/handler/mutator.go | 10 +++++----- pkg/webhook/handler/validator.go | 12 ++++++------ pkg/webhook/server.go | 10 +++++++++- 9 files changed, 53 insertions(+), 19 deletions(-) diff --git a/pkg/webhook/facade/api.go b/pkg/webhook/facade/api.go index cde2442..aec7af0 100644 --- a/pkg/webhook/facade/api.go +++ b/pkg/webhook/facade/api.go @@ -5,6 +5,8 @@ import ( "fmt" "reflect" + "k8s.io/apimachinery/pkg/types" + v1 "k8s.io/api/admission/v1" "k8s.io/api/admission/v1beta1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -50,8 +52,10 @@ type AdmissionRequest interface { Object() *runtime.RawExtension // OldObject returns the runtime.RawExtension representing the request old object OldObject() *runtime.RawExtension - // Resource returns the metav1.GroupVersionResource for the request object - Resource() metav1.GroupVersionResource + // ResourceKind returns the metav1.GroupVersionResource for the request object + ResourceKind() metav1.GroupVersionResource + // ResourceId returns the namespaced name of the requested resource + ResourceID() types.NamespacedName // Namespace returns the name of the namespace which is source to this request Namespace() string } diff --git a/pkg/webhook/facade/v1_admission_review.go b/pkg/webhook/facade/v1_admission_review.go index 264e3fd..39b4a9a 100644 --- a/pkg/webhook/facade/v1_admission_review.go +++ b/pkg/webhook/facade/v1_admission_review.go @@ -4,6 +4,8 @@ package facade import ( "encoding/json" + "k8s.io/apimachinery/pkg/types" + "github.com/pkg/errors" v1 "k8s.io/api/admission/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -58,6 +60,10 @@ type v1AdmissionReviewRequest struct { target *v1.AdmissionRequest } +func (v *v1AdmissionReviewRequest) ResourceID() types.NamespacedName { + return types.NamespacedName{Namespace: v.target.Namespace, Name: v.target.Name} +} + func (v *v1AdmissionReviewRequest) Namespace() string { return v.target.Namespace } @@ -74,7 +80,7 @@ func (v *v1AdmissionReviewRequest) OldObject() *runtime.RawExtension { return &v.target.OldObject } -func (v *v1AdmissionReviewRequest) Resource() metav1.GroupVersionResource { +func (v *v1AdmissionReviewRequest) ResourceKind() metav1.GroupVersionResource { return v.target.Resource } diff --git a/pkg/webhook/facade/v1_admission_review_test.go b/pkg/webhook/facade/v1_admission_review_test.go index e79186f..815f926 100644 --- a/pkg/webhook/facade/v1_admission_review_test.go +++ b/pkg/webhook/facade/v1_admission_review_test.go @@ -9,6 +9,7 @@ import ( . "github.com/onsi/gomega" v1 "k8s.io/api/admission/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + "k8s.io/apimachinery/pkg/types" ) var _ = Describe("v1AdmissionReview test", func() { @@ -35,7 +36,11 @@ var _ = Describe("v1AdmissionReview test", func() { Expect(sut.Request().Kind()).To(BeEquivalentTo(expected.Kind)) Expect(sut.Request().Object()).To(BeEquivalentTo(&expected.Object)) Expect(sut.Request().OldObject()).To(BeEquivalentTo(&expected.OldObject)) - Expect(sut.Request().Resource()).To(BeEquivalentTo(expected.Resource)) + Expect(sut.Request().ResourceKind()).To(BeEquivalentTo(expected.Resource)) + Expect(sut.Request().ResourceID()).To(BeEquivalentTo(types.NamespacedName{ + Namespace: admission_test.V1ValidPod().Request.Namespace, + Name: admission_test.V1ValidPod().Request.Name, + })) Expect(sut.Request().Namespace()).To(BeEquivalentTo(expected.Namespace)) Expect(sut.Response().ResponseType()).To(Equal(facade.AdmissionError)) }) diff --git a/pkg/webhook/facade/v1beta1_admission_review.go b/pkg/webhook/facade/v1beta1_admission_review.go index af8f873..ae610e3 100644 --- a/pkg/webhook/facade/v1beta1_admission_review.go +++ b/pkg/webhook/facade/v1beta1_admission_review.go @@ -4,6 +4,8 @@ package facade import ( "encoding/json" + "k8s.io/apimachinery/pkg/types" + "github.com/pkg/errors" "k8s.io/api/admission/v1beta1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -58,6 +60,10 @@ type v1beta1AdmissionReviewRequest struct { target *v1beta1.AdmissionRequest } +func (v *v1beta1AdmissionReviewRequest) ResourceID() types.NamespacedName { + return types.NamespacedName{Namespace: v.target.Namespace, Name: v.target.Name} +} + func (v *v1beta1AdmissionReviewRequest) Namespace() string { return v.target.Namespace } @@ -74,7 +80,7 @@ func (v *v1beta1AdmissionReviewRequest) OldObject() *runtime.RawExtension { return &v.target.OldObject } -func (v *v1beta1AdmissionReviewRequest) Resource() metav1.GroupVersionResource { +func (v *v1beta1AdmissionReviewRequest) ResourceKind() metav1.GroupVersionResource { return v.target.Resource } diff --git a/pkg/webhook/facade/v1beta1_admission_review_test.go b/pkg/webhook/facade/v1beta1_admission_review_test.go index fdf622b..03e08d1 100644 --- a/pkg/webhook/facade/v1beta1_admission_review_test.go +++ b/pkg/webhook/facade/v1beta1_admission_review_test.go @@ -9,6 +9,7 @@ import ( . "github.com/onsi/gomega" "k8s.io/api/admission/v1beta1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + "k8s.io/apimachinery/pkg/types" ) var _ = Describe("v1beta1AdmissionReview test", func() { @@ -35,7 +36,11 @@ var _ = Describe("v1beta1AdmissionReview test", func() { Expect(sut.Request().Kind()).To(BeEquivalentTo(expected.Kind)) Expect(sut.Request().Object()).To(BeEquivalentTo(&expected.Object)) Expect(sut.Request().OldObject()).To(BeEquivalentTo(&expected.OldObject)) - Expect(sut.Request().Resource()).To(BeEquivalentTo(expected.Resource)) + Expect(sut.Request().ResourceKind()).To(BeEquivalentTo(expected.Resource)) + Expect(sut.Request().ResourceID()).To(BeEquivalentTo(types.NamespacedName{ + Namespace: admission_test.V1ValidPod().Request.Namespace, + Name: admission_test.V1ValidPod().Request.Name, + })) Expect(sut.Request().Namespace()).To(BeEquivalentTo(expected.Namespace)) Expect(sut.Response().ResponseType()).To(Equal(facade.AdmissionError)) }) diff --git a/pkg/webhook/handler/api.go b/pkg/webhook/handler/api.go index 1934b02..1692f61 100644 --- a/pkg/webhook/handler/api.go +++ b/pkg/webhook/handler/api.go @@ -25,7 +25,7 @@ const ( type AdmissionReview interface { // HandleReview handles the facade.AdmissionReview using the logr.Logger HandleReview(logger logr.Logger, review facade.AdmissionReview) error - // Type returns the Type to identify the web hook + // HandlerType returns the Type to identify the web hook HandlerType() Type } diff --git a/pkg/webhook/handler/mutator.go b/pkg/webhook/handler/mutator.go index 4836f9a..ca8b36f 100644 --- a/pkg/webhook/handler/mutator.go +++ b/pkg/webhook/handler/mutator.go @@ -25,8 +25,8 @@ func (m *mutatorImpl) HandlerType() Type { func (m *mutatorImpl) HandleReview(logger logr.Logger, review facade.AdmissionReview) error { request := review.Request() - verboseLogger := logger.V(1) - verboseLogger.Info("mutation hook start", "resource", request.Resource()) + verboseLogger := logger.V(1).WithValues("kind", request.ResourceKind(), "id", request.ResourceID()) + verboseLogger.Info("mutation hook start") if err := m.unmarshaller.HandleReview(logger, review); err != nil { return errors.Wrap(err, "unable to handle request object") } @@ -34,7 +34,7 @@ func (m *mutatorImpl) HandleReview(logger logr.Logger, review facade.AdmissionRe object, oldObject := request.Object().Object, request.OldObject().Object if object == nil && oldObject == nil { - logger.Info("mutation hook skipped, object type not registered", "resource", request.Resource()) + logger.Info("mutation hook skipped, object type not registered") return nil } @@ -47,11 +47,11 @@ func (m *mutatorImpl) HandleReview(logger logr.Logger, review facade.AdmissionRe review.Response().Allow() if len(patchBytes) > 0 { - logger.Info("admission review was patched", "resource", request.Resource(), "patch", string(patchBytes)) + logger.Info("admission review was patched", "patch", string(patchBytes)) review.Response().PatchJSON(patchBytes) } - verboseLogger.Info("mutation hook complete", "resource", request.Resource()) + verboseLogger.Info("mutation hook complete") return nil } diff --git a/pkg/webhook/handler/validator.go b/pkg/webhook/handler/validator.go index 51950b0..8c4c5c6 100644 --- a/pkg/webhook/handler/validator.go +++ b/pkg/webhook/handler/validator.go @@ -26,8 +26,8 @@ func (v *validatorImpl) HandlerType() Type { func (v *validatorImpl) HandleReview(logger logr.Logger, review facade.AdmissionReview) error { request := review.Request() - verboseLogger := logger.V(1) - verboseLogger.Info("validation hook start", "resource", request.Resource()) + verboseLogger := logger.V(1).WithValues("kind", request.ResourceKind(), "id", request.ResourceID()) + verboseLogger.Info("validation hook start") if err := v.unmarshaller.HandleReview(logger, review); err != nil { return errors.Wrap(err, "unable to handle request object") } @@ -35,7 +35,7 @@ func (v *validatorImpl) HandleReview(logger logr.Logger, review facade.Admission object, oldObject := request.Object().Object, request.OldObject().Object if object == nil { - logger.Info("validation hook skipped, object type not registered", "resource", request.Resource()) + logger.Info("validation hook skipped, object type not registered") return nil } @@ -46,15 +46,15 @@ func (v *validatorImpl) HandleReview(logger logr.Logger, review facade.Admission } // Handle valid status if len(failures) == 0 { - verboseLogger.Info("validation hook allowed the request", "resource", request.Resource()) + verboseLogger.Info("validation hook allowed the request") review.Response().Allow() return nil } // Convert the fail into a status status := v.convertFailuresToStatus(object, failures) - logger.Info("validation hook denied the request", "resource", request.Resource()) + logger.Info("validation hook denied the request") review.Response().Deny(status) - verboseLogger.Info("validation hook complete", "resource", request.Resource()) + verboseLogger.Info("validation hook complete") return nil } diff --git a/pkg/webhook/server.go b/pkg/webhook/server.go index e0cce90..3b77b36 100644 --- a/pkg/webhook/server.go +++ b/pkg/webhook/server.go @@ -53,8 +53,11 @@ func (s *Server) AddMutator(mutators ...mutation.Mutator) error { func (s *Server) HandleAdmissionReview(path string, admRevHandler handler.AdmissionReview, summary metering.Summary) { // Add a handler function s.HandleExt(path, func(writer httpext.ResponseWriter, request *httpext.Request) { + logger := request.Logger().V(1).WithValues("path", path, "handler", admRevHandler.HandlerType()) + logger.Info("reading admission review") review := s.readAdmissionReview(writer, request) if review == nil { + logger.Info("no review provided") return } @@ -62,20 +65,25 @@ func (s *Server) HandleAdmissionReview(path string, admRevHandler handler.Admiss finishMetering := s.startMetering(summary, review, writer) defer finishMetering() + logger.Info("handling review") // Delegate the review to the admRevHandler if err := admRevHandler.HandleReview(request.Logger(), review); err != nil { writer.HandleInternalError(errors.Wrap(err, "review handler failed")) return } + logger.Info("removing request part of review and sending response") + // Clear out the request review.ClearRequest() - // Send the response bytes, err := review.Marshal() if err != nil { + logger.Error(err, "response could not be marshalled") writer.HandleInternalError(errors.Wrap(err, "response review cannot be marshaled")) + return } + logger.Info("sending response", "size", len(bytes)) writer.SendJSONBytes(http.StatusOK, bytes) }) }