Skip to content

✨ Pass webhook logger to handler via context #1972

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 3 commits into from
Jan 20, 2023
Merged

✨ Pass webhook logger to handler via context #1972

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
551eca3
✨ Pass webhook logger to handler via context
timebertt Aug 9, 2022
4dddfe9
Add namespace and name field
timebertt Nov 17, 2022
c80ac38
Allow configuring LogConstructor in webhook builder
timebertt Nov 17, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 6 additions & 1 deletion examples/builtins/mutatingwebhook.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,9 @@ import (
"net/http"

corev1 "k8s.io/api/core/v1"

"sigs.k8s.io/controller-runtime/pkg/client"
logf "sigs.k8s.io/controller-runtime/pkg/log"
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
)

Expand All @@ -36,8 +38,10 @@ type podAnnotator struct {

// podAnnotator adds an annotation to every incoming pods.
func (a *podAnnotator) Handle(ctx context.Context, req admission.Request) admission.Response {
pod := &corev1.Pod{}
// set up a convenient log object so we don't have to type request over and over again
log := logf.FromContext(ctx)

pod := &corev1.Pod{}
err := a.decoder.Decode(req, pod)
if err != nil {
return admission.Errored(http.StatusBadRequest, err)
Expand All @@ -52,6 +56,7 @@ func (a *podAnnotator) Handle(ctx context.Context, req admission.Request) admiss
if err != nil {
return admission.Errored(http.StatusInternalServerError, err)
}
log.Info("Annotating Pod")

return admission.PatchResponseFromRaw(req.Object.Raw, marshaledPod)
}
Expand Down
8 changes: 7 additions & 1 deletion examples/builtins/validatingwebhook.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,9 @@ import (
"net/http"

corev1 "k8s.io/api/core/v1"

"sigs.k8s.io/controller-runtime/pkg/client"
logf "sigs.k8s.io/controller-runtime/pkg/log"
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
)

Expand All @@ -36,13 +38,17 @@ type podValidator struct {

// podValidator admits a pod if a specific annotation exists.
func (v *podValidator) Handle(ctx context.Context, req admission.Request) admission.Response {
pod := &corev1.Pod{}
// set up a convenient log object so we don't have to type request over and over again
log := logf.FromContext(ctx)

pod := &corev1.Pod{}
err := v.decoder.Decode(req, pod)
if err != nil {
return admission.Errored(http.StatusBadRequest, err)
}

log.Info("Validating Pod")

key := "example-mutating-admission-webhook"
anno, found := pod.Annotations[key]
if !found {
Expand Down
48 changes: 41 additions & 7 deletions pkg/builder/webhook.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,9 +22,12 @@ import (
"net/url"
"strings"

"github.com/go-logr/logr"
"k8s.io/apimachinery/pkg/runtime"
"k8s.io/apimachinery/pkg/runtime/schema"
"k8s.io/client-go/rest"
"k8s.io/klog/v2"

"sigs.k8s.io/controller-runtime/pkg/client/apiutil"
"sigs.k8s.io/controller-runtime/pkg/manager"
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
Expand All @@ -33,13 +36,14 @@ import (

// WebhookBuilder builds a Webhook.
type WebhookBuilder struct {
apiType runtime.Object
withDefaulter admission.CustomDefaulter
withValidator admission.CustomValidator
gvk schema.GroupVersionKind
mgr manager.Manager
config *rest.Config
recoverPanic bool
apiType runtime.Object
withDefaulter admission.CustomDefaulter
withValidator admission.CustomValidator
gvk schema.GroupVersionKind
mgr manager.Manager
config *rest.Config
recoverPanic bool
logConstructor func(base logr.Logger, req *admission.Request) logr.Logger
}

// WebhookManagedBy allows inform its manager.Manager.
Expand Down Expand Up @@ -69,6 +73,12 @@ func (blder *WebhookBuilder) WithValidator(validator admission.CustomValidator)
return blder
}

// WithLogConstructor overrides the webhook's LogConstructor.
func (blder *WebhookBuilder) WithLogConstructor(logConstructor func(base logr.Logger, req *admission.Request) logr.Logger) *WebhookBuilder {
blder.logConstructor = logConstructor
return blder
}

// RecoverPanic indicates whether the panic caused by webhook should be recovered.
func (blder *WebhookBuilder) RecoverPanic() *WebhookBuilder {
blder.recoverPanic = true
Expand All @@ -80,6 +90,9 @@ func (blder *WebhookBuilder) Complete() error {
// Set the Config
blder.loadRestConfig()

// Configure the default LogConstructor
blder.setLogConstructor()

// Set the Webhook if needed
return blder.registerWebhooks()
}
Expand All @@ -90,6 +103,25 @@ func (blder *WebhookBuilder) loadRestConfig() {
}
}

func (blder *WebhookBuilder) setLogConstructor() {
if blder.logConstructor == nil {
blder.logConstructor = func(base logr.Logger, req *admission.Request) logr.Logger {
log := base.WithValues(
"webhookGroup", blder.gvk.Group,
"webhookKind", blder.gvk.Kind,
)
if req != nil {
return log.WithValues(
blder.gvk.Kind, klog.KRef(req.Namespace, req.Name),
"namespace", req.Namespace, "name", req.Name,
"resource", req.Resource, "user", req.UserInfo.Username,
)
}
return log
}
}
}

func (blder *WebhookBuilder) registerWebhooks() error {
typ, err := blder.getType()
if err != nil {
Expand All @@ -116,6 +148,7 @@ func (blder *WebhookBuilder) registerWebhooks() error {
func (blder *WebhookBuilder) registerDefaultingWebhook() {
mwh := blder.getDefaultingWebhook()
if mwh != nil {
mwh.LogConstructor = blder.logConstructor
path := generateMutatePath(blder.gvk)

// Checking if the path is already registered.
Expand Down Expand Up @@ -145,6 +178,7 @@ func (blder *WebhookBuilder) getDefaultingWebhook() *admission.Webhook {
func (blder *WebhookBuilder) registerValidatingWebhook() {
vwh := blder.getValidatingWebhook()
if vwh != nil {
vwh.LogConstructor = blder.logConstructor
path := generateValidatePath(blder.gvk)

// Checking if the path is already registered.
Expand Down
39 changes: 32 additions & 7 deletions pkg/builder/webhook_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,18 +20,23 @@ import (
"context"
"errors"
"fmt"
"io"
"net/http"
"net/http/httptest"
"os"
"strings"

"github.com/go-logr/logr"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
"github.com/onsi/gomega/gbytes"
metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
"k8s.io/apimachinery/pkg/runtime"
"k8s.io/apimachinery/pkg/runtime/schema"

"sigs.k8s.io/controller-runtime/pkg/controller"
logf "sigs.k8s.io/controller-runtime/pkg/log"
"sigs.k8s.io/controller-runtime/pkg/log/zap"
"sigs.k8s.io/controller-runtime/pkg/manager"
"sigs.k8s.io/controller-runtime/pkg/scheme"
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
Expand All @@ -49,11 +54,17 @@ var _ = Describe("webhook", func() {
})

func runTests(admissionReviewVersion string) {
var stop chan struct{}
var (
stop chan struct{}
logBuffer *gbytes.Buffer
testingLogger logr.Logger
)

BeforeEach(func() {
stop = make(chan struct{})
newController = controller.New
logBuffer = gbytes.NewBuffer()
testingLogger = zap.New(zap.JSONEncoder(), zap.WriteTo(io.MultiWriter(logBuffer, GinkgoWriter)))
})

AfterEach(func() {
Expand Down Expand Up @@ -214,6 +225,9 @@ func runTests(admissionReviewVersion string) {
err = WebhookManagedBy(m).
WithDefaulter(&TestCustomDefaulter{}).
For(&TestDefaulter{}).
WithLogConstructor(func(base logr.Logger, req *admission.Request) logr.Logger {
return admission.DefaultLogConstructor(testingLogger, req)
}).
Complete()
ExpectWithOffset(1, err).NotTo(HaveOccurred())
svr := m.GetWebhookServer()
Expand All @@ -225,16 +239,17 @@ func runTests(admissionReviewVersion string) {
"request":{
"uid":"07e52e8d-4513-11e9-a716-42010a800270",
"kind":{
"group":"",
"group":"foo.test.org",
"version":"v1",
"kind":"TestDefaulter"
},
"resource":{
"group":"",
"group":"foo.test.org",
"version":"v1",
"resource":"testdefaulter"
},
"namespace":"default",
"name":"foo",
"operation":"CREATE",
"object":{
"replica":1
Expand Down Expand Up @@ -263,6 +278,7 @@ func runTests(admissionReviewVersion string) {
ExpectWithOffset(1, w.Body).To(ContainSubstring(`"allowed":true`))
ExpectWithOffset(1, w.Body).To(ContainSubstring(`"patch":`))
ExpectWithOffset(1, w.Body).To(ContainSubstring(`"code":200`))
EventuallyWithOffset(1, logBuffer).Should(gbytes.Say(`"msg":"Defaulting object","object":{"name":"foo","namespace":"default"},"namespace":"default","name":"foo","resource":{"group":"foo.test.org","version":"v1","resource":"testdefaulter"},"user":"","requestID":"07e52e8d-4513-11e9-a716-42010a800270"`))

By("sending a request to a validating webhook path that doesn't exist")
path = generateValidatePath(testDefaulterGVK)
Expand Down Expand Up @@ -431,6 +447,9 @@ func runTests(admissionReviewVersion string) {
err = WebhookManagedBy(m).
WithValidator(&TestCustomValidator{}).
For(&TestValidator{}).
WithLogConstructor(func(base logr.Logger, req *admission.Request) logr.Logger {
return admission.DefaultLogConstructor(testingLogger, req)
}).
Complete()
ExpectWithOffset(1, err).NotTo(HaveOccurred())
svr := m.GetWebhookServer()
Expand All @@ -442,16 +461,17 @@ func runTests(admissionReviewVersion string) {
"request":{
"uid":"07e52e8d-4513-11e9-a716-42010a800270",
"kind":{
"group":"",
"group":"foo.test.org",
"version":"v1",
"kind":"TestValidator"
"kind":"TestDefaulter"
},
"resource":{
"group":"",
"group":"foo.test.org",
"version":"v1",
"resource":"testvalidator"
"resource":"testdefaulter"
},
"namespace":"default",
"name":"foo",
"operation":"UPDATE",
"object":{
"replica":1
Expand Down Expand Up @@ -491,6 +511,7 @@ func runTests(admissionReviewVersion string) {
By("sanity checking the response contains reasonable field")
ExpectWithOffset(1, w.Body).To(ContainSubstring(`"allowed":false`))
ExpectWithOffset(1, w.Body).To(ContainSubstring(`"code":403`))
EventuallyWithOffset(1, logBuffer).Should(gbytes.Say(`"msg":"Validating object","object":{"name":"foo","namespace":"default"},"namespace":"default","name":"foo","resource":{"group":"foo.test.org","version":"v1","resource":"testdefaulter"},"user":"","requestID":"07e52e8d-4513-11e9-a716-42010a800270"`))
})

It("should scaffold defaulting and validating webhooks if the type implements both Defaulter and Validator interfaces", func() {
Expand Down Expand Up @@ -845,6 +866,7 @@ func (dv *TestDefaultValidator) ValidateDelete() error {
type TestCustomDefaulter struct{}

func (*TestCustomDefaulter) Default(ctx context.Context, obj runtime.Object) error {
logf.FromContext(ctx).Info("Defaulting object")
req, err := admission.RequestFromContext(ctx)
if err != nil {
return fmt.Errorf("expected admission.Request in ctx: %w", err)
Expand All @@ -867,6 +889,7 @@ var _ admission.CustomDefaulter = &TestCustomDefaulter{}
type TestCustomValidator struct{}

func (*TestCustomValidator) ValidateCreate(ctx context.Context, obj runtime.Object) error {
logf.FromContext(ctx).Info("Validating object")
req, err := admission.RequestFromContext(ctx)
if err != nil {
return fmt.Errorf("expected admission.Request in ctx: %w", err)
Expand All @@ -883,6 +906,7 @@ func (*TestCustomValidator) ValidateCreate(ctx context.Context, obj runtime.Obje
}

func (*TestCustomValidator) ValidateUpdate(ctx context.Context, oldObj, newObj runtime.Object) error {
logf.FromContext(ctx).Info("Validating object")
req, err := admission.RequestFromContext(ctx)
if err != nil {
return fmt.Errorf("expected admission.Request in ctx: %w", err)
Expand All @@ -903,6 +927,7 @@ func (*TestCustomValidator) ValidateUpdate(ctx context.Context, oldObj, newObj r
}

func (*TestCustomValidator) ValidateDelete(ctx context.Context, obj runtime.Object) error {
logf.FromContext(ctx).Info("Validating object")
req, err := admission.RequestFromContext(ctx)
if err != nil {
return fmt.Errorf("expected admission.Request in ctx: %w", err)
Expand Down
3 changes: 3 additions & 0 deletions pkg/webhook/admission/defaulter_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,13 +10,16 @@ import (
admissionv1 "k8s.io/api/admission/v1"
"k8s.io/apimachinery/pkg/runtime"
"k8s.io/apimachinery/pkg/runtime/schema"

"sigs.k8s.io/controller-runtime/pkg/runtime/inject"
)

var _ = Describe("Defaulter Handler", func() {

It("should return ok if received delete verb in defaulter handler", func() {
obj := &TestDefaulter{}
handler := DefaultingWebhookFor(obj)
Expect(inject.LoggerInto(log, handler)).To(BeTrue())

resp := handler.Handle(context.TODO(), Request{
AdmissionRequest: admissionv1.AdmissionRequest{
Expand Down
16 changes: 8 additions & 8 deletions pkg/webhook/admission/http.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -52,15 +52,15 @@ func (wh *Webhook) ServeHTTP(w http.ResponseWriter, r *http.Request) {
var reviewResponse Response
if r.Body == nil {
err = errors.New("request body is empty")
wh.log.Error(err, "bad request")
wh.getLogger(nil).Error(err, "bad request")
reviewResponse = Errored(http.StatusBadRequest, err)
wh.writeResponse(w, reviewResponse)
return
}

defer r.Body.Close()
if body, err = io.ReadAll(r.Body); err != nil {
wh.log.Error(err, "unable to read the body from the incoming request")
wh.getLogger(nil).Error(err, "unable to read the body from the incoming request")
reviewResponse = Errored(http.StatusBadRequest, err)
wh.writeResponse(w, reviewResponse)
return
Expand All @@ -69,7 +69,7 @@ func (wh *Webhook) ServeHTTP(w http.ResponseWriter, r *http.Request) {
// verify the content type is accurate
if contentType := r.Header.Get("Content-Type"); contentType != "application/json" {
err = fmt.Errorf("contentType=%s, expected application/json", contentType)
wh.log.Error(err, "unable to process a request with an unknown content type", "content type", contentType)
wh.getLogger(nil).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
Expand All @@ -88,12 +88,12 @@ func (wh *Webhook) ServeHTTP(w http.ResponseWriter, r *http.Request) {
ar.SetGroupVersionKind(v1.SchemeGroupVersion.WithKind("AdmissionReview"))
_, actualAdmRevGVK, err := admissionCodecs.UniversalDeserializer().Decode(body, nil, &ar)
if err != nil {
wh.log.Error(err, "unable to decode the request")
wh.getLogger(nil).Error(err, "unable to decode the request")
reviewResponse = Errored(http.StatusBadRequest, err)
wh.writeResponse(w, reviewResponse)
return
}
wh.log.V(1).Info("received request", "UID", req.UID, "kind", req.Kind, "resource", req.Resource)
wh.getLogger(nil).V(1).Info("received request", "UID", req.UID, "kind", req.Kind, "resource", req.Resource)

reviewResponse = wh.Handle(ctx, req)
wh.writeResponseTyped(w, reviewResponse, actualAdmRevGVK)
Expand Down Expand Up @@ -124,19 +124,19 @@ func (wh *Webhook) writeResponseTyped(w io.Writer, response Response, admRevGVK
// writeAdmissionResponse writes ar to w.
func (wh *Webhook) writeAdmissionResponse(w io.Writer, ar v1.AdmissionReview) {
if err := json.NewEncoder(w).Encode(ar); err != nil {
wh.log.Error(err, "unable to encode and write the response")
wh.getLogger(nil).Error(err, "unable to encode and write the response")
// Since the `ar v1.AdmissionReview` is a clear and legal object,
// it should not have problem to be marshalled into bytes.
// The error here is probably caused by the abnormal HTTP connection,
// e.g., broken pipe, so we can only write the error response once,
// to avoid endless circular calling.
serverError := Errored(http.StatusInternalServerError, err)
if err = json.NewEncoder(w).Encode(v1.AdmissionReview{Response: &serverError.AdmissionResponse}); err != nil {
wh.log.Error(err, "still unable to encode and write the InternalServerError response")
wh.getLogger(nil).Error(err, "still unable to encode and write the InternalServerError response")
}
} else {
res := ar.Response
if log := wh.log; log.V(1).Enabled() {
if log := wh.getLogger(nil); log.V(1).Enabled() {
if res.Result != nil {
log = log.WithValues("code", res.Result.Code, "reason", res.Result.Reason)
}
Expand Down
Loading