From 8623a9b9f9ccec039d0d83b2346d4345b8247e43 Mon Sep 17 00:00:00 2001 From: Solly Ross Date: Tue, 19 Feb 2019 18:34:19 -0800 Subject: [PATCH] Add per-webhook logging This gives each webhook a log, so that serving errors can be tied to a particuluar webhook. --- example/main.go | 4 ++-- pkg/runtime/inject/inject.go | 17 +++++++++++++++++ pkg/webhook/admission/http.go | 12 ++++++------ pkg/webhook/admission/http_test.go | 10 +++++++--- pkg/webhook/admission/webhook.go | 13 +++++++++++-- pkg/webhook/server.go | 10 +++++++++- 6 files changed, 52 insertions(+), 14 deletions(-) diff --git a/example/main.go b/example/main.go index 499de9daad..aa33c94831 100644 --- a/example/main.go +++ b/example/main.go @@ -88,8 +88,8 @@ func main() { } entryLog.Info("registering webhooks to the webhook server") - hookServer.Register("/mutate-pods", webhook.Admission{Handler: &podAnnotator{}}) - hookServer.Register("/validate-pods", webhook.Admission{Handler: &podValidator{}}) + hookServer.Register("/mutate-pods", &webhook.Admission{Handler: &podAnnotator{}}) + hookServer.Register("/validate-pods", &webhook.Admission{Handler: &podValidator{}}) entryLog.Info("starting manager") if err := mgr.Start(signals.SetupSignalHandler()); err != nil { diff --git a/pkg/runtime/inject/inject.go b/pkg/runtime/inject/inject.go index ec7f30c68d..c006fdb53d 100644 --- a/pkg/runtime/inject/inject.go +++ b/pkg/runtime/inject/inject.go @@ -17,9 +17,11 @@ limitations under the License. package inject import ( + "github.com/go-logr/logr" "k8s.io/apimachinery/pkg/api/meta" "k8s.io/apimachinery/pkg/runtime" "k8s.io/client-go/rest" + "sigs.k8s.io/controller-runtime/pkg/cache" "sigs.k8s.io/controller-runtime/pkg/client" ) @@ -129,3 +131,18 @@ func InjectorInto(f Func, i interface{}) (bool, error) { } return false, nil } + +// Logger is used to inject Loggers into components that need them +// and don't otherwise have opinions. +type Logger interface { + InjectLogger(l logr.Logger) error +} + +// LoggerInto will set the logger on the given object if it implements inject.Logger, +// returning true if a InjectLogger was called, and false otherwise. +func LoggerInto(l logr.Logger, i interface{}) (bool, error) { + if injectable, wantsLogger := i.(Logger); wantsLogger { + return true, injectable.InjectLogger(l) + } + return false, nil +} diff --git a/pkg/webhook/admission/http.go b/pkg/webhook/admission/http.go index 2943e445dd..fa60302adc 100644 --- a/pkg/webhook/admission/http.go +++ b/pkg/webhook/admission/http.go @@ -41,21 +41,21 @@ func init() { var _ http.Handler = &Webhook{} -func (wh Webhook) ServeHTTP(w http.ResponseWriter, r *http.Request) { +func (wh *Webhook) ServeHTTP(w http.ResponseWriter, r *http.Request) { var body []byte var err error var reviewResponse Response if r.Body != nil { if body, err = ioutil.ReadAll(r.Body); err != nil { - log.Error(err, "unable to read the body from the incoming request") + wh.log.Error(err, "unable to read the body from the incoming request") reviewResponse = Errored(http.StatusBadRequest, err) wh.writeResponse(w, reviewResponse) return } } else { err = errors.New("request body is empty") - log.Error(err, "bad request") + wh.log.Error(err, "bad request") reviewResponse = Errored(http.StatusBadRequest, err) wh.writeResponse(w, reviewResponse) return @@ -65,7 +65,7 @@ func (wh Webhook) ServeHTTP(w http.ResponseWriter, r *http.Request) { contentType := r.Header.Get("Content-Type") if contentType != "application/json" { err = fmt.Errorf("contentType=%s, expected application/json", contentType) - log.Error(err, "unable to process a request with an unknown content type", "content type", contentType) + wh.log.Error(err, "unable to process a request with an unknown content type", "content type", contentType) reviewResponse = Errored(http.StatusBadRequest, err) wh.writeResponse(w, reviewResponse) return @@ -77,7 +77,7 @@ func (wh Webhook) ServeHTTP(w http.ResponseWriter, r *http.Request) { Request: &req.AdmissionRequest, } if _, _, err := admissionCodecs.UniversalDeserializer().Decode(body, nil, &ar); err != nil { - log.Error(err, "unable to decode the request") + wh.log.Error(err, "unable to decode the request") reviewResponse = Errored(http.StatusBadRequest, err) wh.writeResponse(w, reviewResponse) return @@ -95,7 +95,7 @@ func (wh *Webhook) writeResponse(w io.Writer, response Response) { } err := encoder.Encode(responseAdmissionReview) if err != nil { - log.Error(err, "unable to encode the response") + wh.log.Error(err, "unable to encode the response") wh.writeResponse(w, Errored(http.StatusInternalServerError, err)) } } diff --git a/pkg/webhook/admission/http_test.go b/pkg/webhook/admission/http_test.go index 01e97756cf..975115695f 100644 --- a/pkg/webhook/admission/http_test.go +++ b/pkg/webhook/admission/http_test.go @@ -26,6 +26,8 @@ import ( . "github.com/onsi/ginkgo" . "github.com/onsi/gomega" + "sigs.k8s.io/controller-runtime/pkg/runtime/inject" + admissionv1beta1 "k8s.io/api/admission/v1beta1" ) @@ -33,14 +35,16 @@ var _ = Describe("Admission Webhooks", func() { Describe("HTTP Handler", func() { var respRecorder *httptest.ResponseRecorder + webhook := &Webhook{ + Handler: nil, + } BeforeEach(func() { respRecorder = &httptest.ResponseRecorder{ Body: bytes.NewBuffer(nil), } + _, err := inject.LoggerInto(log.WithName("test-webhook"), webhook) + Expect(err).NotTo(HaveOccurred()) }) - webhook := &Webhook{ - Handler: nil, - } It("should return bad-request when given an empty body", func() { req := &http.Request{Body: nil} diff --git a/pkg/webhook/admission/webhook.go b/pkg/webhook/admission/webhook.go index ff8a41fefc..2f6cd9a88f 100644 --- a/pkg/webhook/admission/webhook.go +++ b/pkg/webhook/admission/webhook.go @@ -22,6 +22,7 @@ import ( "net/http" "github.com/appscode/jsonpatch" + "github.com/go-logr/logr" admissionv1beta1 "k8s.io/api/admission/v1beta1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/runtime" @@ -110,8 +111,16 @@ type Webhook struct { // and potentially patches to apply to the handler. Handler Handler - // scheme is used to construct the Decoder + // decoder is constructed on receiving a scheme and passed down to then handler decoder *Decoder + + log logr.Logger +} + +// InjectLogger gets a handle to a logging instance, hopefully with more info about this particular webhook. +func (w *Webhook) InjectLogger(l logr.Logger) error { + w.log = l + return nil } // Handle processes AdmissionRequest. @@ -121,7 +130,7 @@ type Webhook struct { func (w *Webhook) Handle(ctx context.Context, req Request) Response { resp := w.Handler.Handle(ctx, req) if err := resp.Complete(req); err != nil { - log.Error(err, "unable to encode response") + w.log.Error(err, "unable to encode response") return Errored(http.StatusInternalServerError, errUnableToEncodeResponse) } diff --git a/pkg/webhook/server.go b/pkg/webhook/server.go index 52a6a29555..deb8a234d3 100644 --- a/pkg/webhook/server.go +++ b/pkg/webhook/server.go @@ -111,12 +111,20 @@ func instrumentedHook(path string, hookRaw http.Handler) http.Handler { func (s *Server) Start(stop <-chan struct{}) error { s.defaultingOnce.Do(s.setDefaults) + baseHookLog := log.WithName("webhooks") // inject fields here as opposed to in Register so that we're certain to have our setFields // function available. - for _, webhook := range s.webhooks { + for hookPath, webhook := range s.webhooks { if err := s.setFields(webhook); err != nil { return err } + + // NB(directxman12): we don't propagate this further by wrapping setFields because it's + // unclear if this is how we want to deal with log propagation. In this specific instance, + // we want to be able to pass a logger to webhooks because they don't know their own path. + if _, err := inject.LoggerInto(baseHookLog.WithValues("webhook", hookPath), webhook); err != nil { + return err + } } // TODO: watch the cert dir. Reload the cert if it changes