Cleanup webhook logging

Author: sbueringer

pkg/builder/webhook.go

@@ -115,6 +115,7 @@ func (blder *WebhookBuilder) setLogConstructor() {
 					blder.gvk.Kind, klog.KRef(req.Namespace, req.Name),
 					"namespace", req.Namespace, "name", req.Name,
 					"resource", req.Resource, "user", req.UserInfo.Username,
+					"requestID", req.UID,
 				)
 			}
 			return log

pkg/webhook/admission/http.go

@@ -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.getLogger(nil).Error(err, "unable to process a request with an unknown content type", "content type", contentType)
+		wh.getLogger(nil).Error(err, fmt.Sprintf("unable to process a request with unknown content type: %q", contentType))
 		reviewResponse = Errored(http.StatusBadRequest, err)
 		wh.writeResponse(w, reviewResponse)
 		return
@@ -93,7 +93,7 @@ func (wh *Webhook) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		wh.writeResponse(w, reviewResponse)
 		return
 	}
-	wh.getLogger(nil).V(1).Info("received request", "UID", req.UID, "kind", req.Kind, "resource", req.Resource)
+	wh.getLogger(&req).V(1).Info("received request")
 
 	reviewResponse = wh.Handle(ctx, req)
 	wh.writeResponseTyped(w, reviewResponse, actualAdmRevGVK)
@@ -140,7 +140,7 @@ func (wh *Webhook) writeAdmissionResponse(w io.Writer, ar v1.AdmissionReview) {
 			if res.Result != nil {
 				log = log.WithValues("code", res.Result.Code, "reason", res.Result.Reason, "message", res.Result.Message)
 			}
-			log.V(1).Info("wrote response", "UID", res.UID, "allowed", res.Allowed)
+			log.V(1).Info("wrote response", "requestID", res.UID, "allowed", res.Allowed)
 		}
 	}
 }

pkg/webhook/admission/webhook.go

@@ -30,6 +30,7 @@ import (
 	"k8s.io/apimachinery/pkg/util/json"
 	utilruntime "k8s.io/apimachinery/pkg/util/runtime"
 	"k8s.io/klog/v2"
+
 	logf "sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/webhook/internal/metrics"
 )
@@ -163,7 +164,6 @@ func (wh *Webhook) Handle(ctx context.Context, req Request) (response Response)
 	}
 
 	reqLog := wh.getLogger(&req)
-	reqLog = reqLog.WithValues("requestID", req.UID)
 	ctx = logf.IntoContext(ctx, reqLog)
 
 	resp := wh.Handler.Handle(ctx, req)
@@ -196,6 +196,7 @@ func DefaultLogConstructor(base logr.Logger, req *Request) logr.Logger {
 		return base.WithValues("object", klog.KRef(req.Namespace, req.Name),
 			"namespace", req.Namespace, "name", req.Name,
 			"resource", req.Resource, "user", req.UserInfo.Username,
+			"requestID", req.UID,
 		)
 	}
 	return base

pkg/webhook/admission/webhook_test.go

@@ -182,7 +182,7 @@ var _ = Describe("Admission Webhooks", func() {
 				}
 			}),
 			LogConstructor: func(base logr.Logger, req *Request) logr.Logger {
-				return base.WithValues("operation", req.Operation)
+				return base.WithValues("operation", req.Operation, "requestID", req.UID)
 			},
 			log: testLogger,
 		}

pkg/webhook/authentication/http.go

@@ -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.getLogger(nil).Error(err, "unable to process a request with an unknown content type", "content type", contentType)
+		wh.getLogger(nil).Error(err, fmt.Sprintf("unable to process a request with unknown content type: %q", contentType))
 		reviewResponse = Errored(err)
 		wh.writeResponse(w, reviewResponse)
 		return
@@ -94,7 +94,7 @@ func (wh *Webhook) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		wh.writeResponse(w, reviewResponse)
 		return
 	}
-	wh.getLogger(&req).V(1).Info("received request", "UID", req.UID, "kind", req.Kind)
+	wh.getLogger(&req).V(1).Info("received request")
 
 	if req.Spec.Token == "" {
 		err = errors.New("token is empty")
@@ -136,7 +136,7 @@ func (wh *Webhook) writeTokenResponse(w io.Writer, ar authenticationv1.TokenRevi
 	}
 	res := ar
 	if wh.getLogger(nil).V(1).Enabled() {
-		wh.getLogger(nil).V(1).Info("wrote response", "UID", res.UID, "authenticated", res.Status.Authenticated)
+		wh.getLogger(nil).V(1).Info("wrote response", "requestID", res.UID, "authenticated", res.Status.Authenticated)
 	}
 }
 

pkg/webhook/authentication/webhook.go

@@ -119,6 +119,7 @@ func logConstructor(base logr.Logger, req *Request) logr.Logger {
 		return base.WithValues("object", klog.KRef(req.Namespace, req.Name),
 			"namespace", req.Namespace, "name", req.Name,
 			"user", req.Status.User.Username,
+			"requestID", req.UID,
 		)
 	}
 	return base