feat: add tracing middleware (#5397)

* feat: add tracing middleware

Signed-off-by: Charles-Edouard Brétéché <charles.edouard@nirmata.com>

* add middleware

Signed-off-by: Charles-Edouard Brétéché <charles.edouard@nirmata.com>

* add tracing to middlewares

Signed-off-by: Charles-Edouard Brétéché <charles.edouard@nirmata.com>

* fix

Signed-off-by: Charles-Edouard Brétéché <charles.edouard@nirmata.com>

Signed-off-by: Charles-Edouard Brétéché <charles.edouard@nirmata.com>
Co-authored-by: shuting <shuting@nirmata.com>

cmd/cleanup-controller/server.go

@@ -44,8 +44,11 @@ func NewServer(
 	mux.HandlerFunc(
 		"POST",
 		ValidatingWebhookServicePath,
-		handlers.AdmissionHandler(policyHandlers.Validate).
-			WithAdmission(logger.Logger.WithName("validate")),
+		http.HandlerFunc(
+			handlers.AdmissionHandler(policyHandlers.Validate).
+				WithAdmission(logger.Logger.WithName("validate")).
+				WithTrace(),
+		),
 	)
 	return &server{
 		server: &http.Server{

pkg/tracing/tracing.go

@@ -89,3 +89,17 @@ func DoInSpan(ctx context.Context, tracerName string, operationName string, doFn
 func StartSpan(ctx context.Context, tracerName string, operationName string, attributes ...attribute.KeyValue) (context.Context, trace.Span) {
 	return otel.Tracer(tracerName).Start(ctx, operationName, trace.WithAttributes(attributes...))
 }
+
+// Span executes function doFn inside new span with `operationName` name and hooking as child to a span found within given context if any.
+func Span(ctx context.Context, tracerName string, operationName string, doFn func(context.Context, trace.Span), opts ...trace.SpanStartOption) {
+	newCtx, span := otel.Tracer(tracerName).Start(ctx, operationName, opts...)
+	defer span.End()
+	doFn(newCtx, span)
+}
+
+// Span executes function doFn inside new span with `operationName` name and hooking as child to a span found within given context if any.
+func Span1[T any](ctx context.Context, tracerName string, operationName string, doFn func(context.Context, trace.Span) T, opts ...trace.SpanStartOption) T {
+	newCtx, span := otel.Tracer(tracerName).Start(ctx, operationName, opts...)
+	defer span.End()
+	return doFn(newCtx, span)
+}

pkg/webhooks/handlers/admission.go

@@ -14,13 +14,16 @@ import (
 	admissionv1 "k8s.io/api/admission/v1"
 )
 
-type AdmissionHandler func(context.Context, logr.Logger, *admissionv1.AdmissionRequest, time.Time) *admissionv1.AdmissionResponse
+type (
+	AdmissionHandler func(context.Context, logr.Logger, *admissionv1.AdmissionRequest, time.Time) *admissionv1.AdmissionResponse
+	HttpHandler      func(http.ResponseWriter, *http.Request)
+)
 
-func (h AdmissionHandler) WithAdmission(logger logr.Logger) http.HandlerFunc {
+func (h AdmissionHandler) WithAdmission(logger logr.Logger) HttpHandler {
 	return withAdmission(logger, h)
 }
 
-func withAdmission(logger logr.Logger, inner AdmissionHandler) http.HandlerFunc {
+func withAdmission(logger logr.Logger, inner AdmissionHandler) HttpHandler {
 	return func(writer http.ResponseWriter, request *http.Request) {
 		startTime := time.Now()
 		if request.Body == nil {

pkg/webhooks/handlers/dump.go

@@ -7,7 +7,9 @@ import (
 
 	"github.com/go-logr/logr"
 	engineutils "github.com/kyverno/kyverno/pkg/engine/utils"
+	"github.com/kyverno/kyverno/pkg/tracing"
 	"github.com/kyverno/kyverno/pkg/utils"
+	"go.opentelemetry.io/otel/trace"
 	admissionv1 "k8s.io/api/admission/v1"
 	authenticationv1 "k8s.io/api/authentication/v1"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@@ -103,8 +105,15 @@ func (h AdmissionHandler) WithDump(enabled bool) AdmissionHandler {
 
 func withDump(inner AdmissionHandler) AdmissionHandler {
 	return func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
-		response := inner(ctx, logger, request, startTime)
-		dumpPayload(logger, request, response)
-		return response
+		return tracing.Span1(
+			ctx,
+			"admission_webhook_operations",
+			"dump",
+			func(ctx context.Context, span trace.Span) *admissionv1.AdmissionResponse {
+				response := inner(ctx, logger, request, startTime)
+				dumpPayload(logger, request, response)
+				return response
+			},
+		)
 	}
 }

pkg/webhooks/handlers/filter.go

@@ -6,6 +6,8 @@ import (
 
 	"github.com/go-logr/logr"
 	"github.com/kyverno/kyverno/pkg/config"
+	"github.com/kyverno/kyverno/pkg/tracing"
+	"go.opentelemetry.io/otel/trace"
 	admissionv1 "k8s.io/api/admission/v1"
 )
 
@@ -15,9 +17,16 @@ func (h AdmissionHandler) WithFilter(configuration config.Configuration) Admissi
 
 func withFilter(c config.Configuration, inner AdmissionHandler) AdmissionHandler {
 	return func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
-		if c.ToFilter(request.Kind.Kind, request.Namespace, request.Name) {
-			return nil
-		}
-		return inner(ctx, logger, request, startTime)
+		return tracing.Span1(
+			ctx,
+			"admission_webhook_operations",
+			"filter",
+			func(ctx context.Context, span trace.Span) *admissionv1.AdmissionResponse {
+				if c.ToFilter(request.Kind.Kind, request.Namespace, request.Name) {
+					return nil
+				}
+				return inner(ctx, logger, request, startTime)
+			},
+		)
 	}
 }

pkg/webhooks/handlers/metrics.go

@@ -8,6 +8,8 @@ import (
 	"github.com/kyverno/kyverno/pkg/metrics"
 	admissionRequests "github.com/kyverno/kyverno/pkg/metrics/admissionrequests"
 	admissionReviewDuration "github.com/kyverno/kyverno/pkg/metrics/admissionreviewduration"
+	"github.com/kyverno/kyverno/pkg/tracing"
+	"go.opentelemetry.io/otel/trace"
 	admissionv1 "k8s.io/api/admission/v1"
 )
 
@@ -17,8 +19,15 @@ func (h AdmissionHandler) WithMetrics(metricsConfig *metrics.MetricsConfig) Admi
 
 func withMetrics(metricsConfig *metrics.MetricsConfig, inner AdmissionHandler) AdmissionHandler {
 	return func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
-		defer admissionReviewDuration.Process(metricsConfig, request, int64(time.Since(startTime)))
-		admissionRequests.Process(metricsConfig, request)
-		return inner(ctx, logger, request, startTime)
+		return tracing.Span1(
+			ctx,
+			"admission_webhook_operations",
+			"metrics",
+			func(ctx context.Context, span trace.Span) *admissionv1.AdmissionResponse {
+				defer admissionReviewDuration.Process(metricsConfig, request, int64(time.Since(startTime)))
+				admissionRequests.Process(metricsConfig, request)
+				return inner(ctx, logger, request, startTime)
+			},
+		)
 	}
 }

pkg/webhooks/handlers/protect.go

@@ -9,8 +9,10 @@ import (
 	"github.com/go-logr/logr"
 	kyvernov1 "github.com/kyverno/kyverno/api/kyverno/v1"
 	"github.com/kyverno/kyverno/pkg/config"
+	"github.com/kyverno/kyverno/pkg/tracing"
 	"github.com/kyverno/kyverno/pkg/utils"
 	admissionutils "github.com/kyverno/kyverno/pkg/utils/admission"
+	"go.opentelemetry.io/otel/trace"
 	admissionv1 "k8s.io/api/admission/v1"
 	"k8s.io/apimachinery/pkg/apis/meta/v1/unstructured"
 )
@@ -24,20 +26,27 @@ func (h AdmissionHandler) WithProtection(enabled bool) AdmissionHandler {
 
 func withProtection(inner AdmissionHandler) AdmissionHandler {
 	return func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
-		newResource, oldResource, err := utils.ExtractResources(nil, request)
-		if err != nil {
-			logger.Error(err, "Failed to extract resources")
-			return admissionutils.Response(err)
-		}
-		for _, resource := range []unstructured.Unstructured{newResource, oldResource} {
-			resLabels := resource.GetLabels()
-			if resLabels[kyvernov1.LabelAppManagedBy] == kyvernov1.ValueKyvernoApp {
-				if request.UserInfo.Username != fmt.Sprintf("system:serviceaccount:%s:%s", config.KyvernoNamespace(), config.KyvernoServiceAccountName()) {
-					logger.Info("Access to the resource not authorized, this is a kyverno managed resource and should be altered only by kyverno")
-					return admissionutils.Response(errors.New("A kyverno managed resource can only be modified by kyverno"))
+		return tracing.Span1(
+			ctx,
+			"admission_webhook_operations",
+			"protect",
+			func(ctx context.Context, span trace.Span) *admissionv1.AdmissionResponse {
+				newResource, oldResource, err := utils.ExtractResources(nil, request)
+				if err != nil {
+					logger.Error(err, "Failed to extract resources")
+					return admissionutils.Response(err)
 				}
-			}
-		}
-		return inner(ctx, logger, request, startTime)
+				for _, resource := range []unstructured.Unstructured{newResource, oldResource} {
+					resLabels := resource.GetLabels()
+					if resLabels[kyvernov1.LabelAppManagedBy] == kyvernov1.ValueKyvernoApp {
+						if request.UserInfo.Username != fmt.Sprintf("system:serviceaccount:%s:%s", config.KyvernoNamespace(), config.KyvernoServiceAccountName()) {
+							logger.Info("Access to the resource not authorized, this is a kyverno managed resource and should be altered only by kyverno")
+							return admissionutils.Response(errors.New("A kyverno managed resource can only be modified by kyverno"))
+						}
+					}
+				}
+				return inner(ctx, logger, request, startTime)
+			},
+		)
 	}
 }

pkg/webhooks/handlers/trace.go

@@ -0,0 +1,34 @@
+package handlers
+
+import (
+	"context"
+	"net/http"
+
+	"github.com/kyverno/kyverno/pkg/tracing"
+	semconv "go.opentelemetry.io/otel/semconv/v1.4.0"
+	"go.opentelemetry.io/otel/trace"
+)
+
+func (h HttpHandler) WithTrace() HttpHandler {
+	return withTrace(h)
+}
+
+func withTrace(inner HttpHandler) HttpHandler {
+	return func(writer http.ResponseWriter, request *http.Request) {
+		tracing.Span(
+			request.Context(),
+			"admission_webhook_operations",
+			request.URL.Path,
+			func(ctx context.Context, span trace.Span) {
+				inner(writer, request.WithContext(ctx))
+			},
+			trace.WithAttributes(
+				semconv.HTTPRequestContentLengthKey.Int64(request.ContentLength),
+				semconv.HTTPHostKey.String(request.Host),
+				semconv.HTTPMethodKey.String(request.Method),
+				semconv.HTTPURLKey.String(request.RequestURI),
+			),
+			trace.WithSpanKind(trace.SpanKindServer),
+		)
+	}
+}

pkg/webhooks/handlers/verify.go

@@ -6,22 +6,31 @@ import (
 
 	"github.com/go-logr/logr"
 	"github.com/kyverno/kyverno/pkg/config"
+	"github.com/kyverno/kyverno/pkg/tracing"
 	admissionutils "github.com/kyverno/kyverno/pkg/utils/admission"
 	jsonutils "github.com/kyverno/kyverno/pkg/utils/json"
+	"go.opentelemetry.io/otel/trace"
 	admissionv1 "k8s.io/api/admission/v1"
 )
 
 func Verify() AdmissionHandler {
 	return func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
-		if request.Name != "kyverno-health" || request.Namespace != config.KyvernoNamespace() {
-			return admissionutils.ResponseSuccess()
-		}
-		patch := jsonutils.NewPatchOperation("/metadata/annotations/"+"kyverno.io~1last-request-time", "replace", time.Now().Format(time.RFC3339))
-		bytes, err := patch.ToPatchBytes()
-		if err != nil {
-			logger.Error(err, "failed to build patch bytes")
-			return admissionutils.Response(err)
-		}
-		return admissionutils.MutationResponse(bytes)
+		return tracing.Span1(
+			ctx,
+			"admission_webhook_operations",
+			"verify",
+			func(ctx context.Context, span trace.Span) *admissionv1.AdmissionResponse {
+				if request.Name != "kyverno-health" || request.Namespace != config.KyvernoNamespace() {
+					return admissionutils.ResponseSuccess()
+				}
+				patch := jsonutils.NewPatchOperation("/metadata/annotations/"+"kyverno.io~1last-request-time", "replace", time.Now().Format(time.RFC3339))
+				bytes, err := patch.ToPatchBytes()
+				if err != nil {
+					logger.Error(err, "failed to build patch bytes")
+					return admissionutils.Response(err)
+				}
+				return admissionutils.MutationResponse(bytes)
+			},
+		)
 	}
 }

pkg/webhooks/server.go

@@ -84,26 +84,35 @@ func NewServer(
 	mux.HandlerFunc(
 		"POST",
 		config.PolicyMutatingWebhookServicePath,
-		handlers.AdmissionHandler(policyHandlers.Mutate).
-			WithFilter(configuration).
-			WithDump(debugModeOpts.DumpPayload).
-			WithMetrics(metricsConfig).
-			WithAdmission(policyLogger.WithName("mutate")),
+		http.HandlerFunc(
+			handlers.AdmissionHandler(policyHandlers.Mutate).
+				WithFilter(configuration).
+				WithDump(debugModeOpts.DumpPayload).
+				WithMetrics(metricsConfig).
+				WithAdmission(policyLogger.WithName("mutate")).
+				WithTrace(),
+		),
 	)
 	mux.HandlerFunc(
 		"POST",
 		config.PolicyValidatingWebhookServicePath,
-		handlers.AdmissionHandler(policyHandlers.Validate).
-			WithFilter(configuration).
-			WithDump(debugModeOpts.DumpPayload).
-			WithMetrics(metricsConfig).
-			WithAdmission(policyLogger.WithName("validate")),
+		http.HandlerFunc(
+			handlers.AdmissionHandler(policyHandlers.Validate).
+				WithFilter(configuration).
+				WithDump(debugModeOpts.DumpPayload).
+				WithMetrics(metricsConfig).
+				WithAdmission(policyLogger.WithName("validate")).
+				WithTrace(),
+		),
 	)
 	mux.HandlerFunc(
 		"POST",
 		config.VerifyMutatingWebhookServicePath,
-		handlers.Verify().
-			WithAdmission(verifyLogger.WithName("mutate")),
+		http.HandlerFunc(
+			handlers.Verify().
+				WithAdmission(verifyLogger.WithName("mutate")).
+				WithTrace(),
+		),
 	)
 	mux.HandlerFunc("GET", config.LivenessServicePath, handlers.Probe(runtime.IsLive))
 	mux.HandlerFunc("GET", config.ReadinessServicePath, handlers.Probe(runtime.IsReady))
@@ -205,37 +214,46 @@ func registerWebhookHandlers(
 	mux.HandlerFunc(
 		"POST",
 		basePath,
-		handlers.AdmissionHandler(func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
-			return handlerFunc(ctx, logger, request, "all", startTime)
-		}).
-			WithFilter(configuration).
-			WithProtection(toggle.ProtectManagedResources.Enabled()).
-			WithDump(debugModeOpts.DumpPayload).
-			WithMetrics(metricsConfig).
-			WithAdmission(logger),
+		http.HandlerFunc(
+			handlers.AdmissionHandler(func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
+				return handlerFunc(ctx, logger, request, "all", startTime)
+			}).
+				WithFilter(configuration).
+				WithProtection(toggle.ProtectManagedResources.Enabled()).
+				WithDump(debugModeOpts.DumpPayload).
+				WithMetrics(metricsConfig).
+				WithAdmission(logger).
+				WithTrace(),
+		),
 	)
 	mux.HandlerFunc(
 		"POST",
 		basePath+"/fail",
-		handlers.AdmissionHandler(func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
-			return handlerFunc(ctx, logger, request, "fail", startTime)
-		}).
-			WithFilter(configuration).
-			WithProtection(toggle.ProtectManagedResources.Enabled()).
-			WithDump(debugModeOpts.DumpPayload).
-			WithMetrics(metricsConfig).
-			WithAdmission(logger),
+		http.HandlerFunc(
+			handlers.AdmissionHandler(func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
+				return handlerFunc(ctx, logger, request, "fail", startTime)
+			}).
+				WithFilter(configuration).
+				WithProtection(toggle.ProtectManagedResources.Enabled()).
+				WithDump(debugModeOpts.DumpPayload).
+				WithMetrics(metricsConfig).
+				WithAdmission(logger).
+				WithTrace(),
+		),
 	)
 	mux.HandlerFunc(
 		"POST",
 		basePath+"/ignore",
-		handlers.AdmissionHandler(func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
-			return handlerFunc(ctx, logger, request, "ignore", startTime)
-		}).
-			WithFilter(configuration).
-			WithProtection(toggle.ProtectManagedResources.Enabled()).
-			WithDump(debugModeOpts.DumpPayload).
-			WithMetrics(metricsConfig).
-			WithAdmission(logger),
+		http.HandlerFunc(
+			handlers.AdmissionHandler(func(ctx context.Context, logger logr.Logger, request *admissionv1.AdmissionRequest, startTime time.Time) *admissionv1.AdmissionResponse {
+				return handlerFunc(ctx, logger, request, "ignore", startTime)
+			}).
+				WithFilter(configuration).
+				WithProtection(toggle.ProtectManagedResources.Enabled()).
+				WithDump(debugModeOpts.DumpPayload).
+				WithMetrics(metricsConfig).
+				WithAdmission(logger).
+				WithTrace(),
+		),
 	)
 }