diff --git a/pkg/metrics/admissionreviewlatency/admissionReviewLatency.go b/pkg/metrics/admissionreviewlatency/admissionReviewLatency.go new file mode 100644 index 0000000000..7f60fff131 --- /dev/null +++ b/pkg/metrics/admissionreviewlatency/admissionReviewLatency.go @@ -0,0 +1,68 @@ +package admissionreviewlatency + +import ( + "fmt" + kyverno "github.com/kyverno/kyverno/pkg/api/kyverno/v1" + "github.com/kyverno/kyverno/pkg/engine/response" + "github.com/kyverno/kyverno/pkg/metrics" + prom "github.com/prometheus/client_golang/prometheus" +) + +func (pm PromMetrics) registerAdmissionReviewLatencyMetric( + clusterPoliciesCount, namespacedPoliciesCount int, + validateRulesCount, mutateRulesCount, generateRulesCount int, + resourceName, resourceKind, resourceNamespace string, + resourceRequestOperation metrics.ResourceRequestOperation, + admissionRequestLatency float64, +) error { + pm.AdmissionReviewLatency.With(prom.Labels{ + "cluster_policies_count": fmt.Sprintf("%d", clusterPoliciesCount), + "namespaced_policies_count": fmt.Sprintf("%d", namespacedPoliciesCount), + "validate_rules_count": fmt.Sprintf("%d", validateRulesCount), + "mutate_rules_count": fmt.Sprintf("%d", mutateRulesCount), + "generate_rules_count": fmt.Sprintf("%d", generateRulesCount), + "resource_name": resourceName, + "resource_kind": resourceKind, + "resource_namespace": resourceNamespace, + "resource_request_operation": string(resourceRequestOperation), + }).Set(admissionRequestLatency) + return nil +} + +func (pm PromMetrics) ProcessEngineResponses(engineResponses []*response.EngineResponse, triggeredPolicies []kyverno.ClusterPolicy, admissionReviewLatencyDuration int64, resourceRequestOperation metrics.ResourceRequestOperation) error { + if len(engineResponses) == 0 { + return nil + } + resourceName, resourceNamespace, resourceKind := engineResponses[0].PolicyResponse.Resource.Name, engineResponses[0].PolicyResponse.Resource.Namespace, engineResponses[0].PolicyResponse.Resource.Kind + clusterPoliciesCount, namespacedPoliciesCount, totalValidateRulesCount, totalMutateRulesCount, totalGenerateRulesCount := 0, 0, 0, 0, 0 + for i, e := range engineResponses { + validateRulesCount, mutateRulesCount, generateRulesCount := 0, 0, 0 + for _, rule := range e.PolicyResponse.Rules { + switch rule.Type { + case "Validation": + validateRulesCount++ + case "Mutation": + mutateRulesCount++ + case "Generation": + generateRulesCount++ + } + } + // no rules triggered + if validateRulesCount+mutateRulesCount+generateRulesCount == 0 { + continue + } + if triggeredPolicies[i].Namespace == "" { + clusterPoliciesCount++ + } else { + namespacedPoliciesCount++ + } + totalValidateRulesCount += validateRulesCount + totalMutateRulesCount += mutateRulesCount + totalGenerateRulesCount += generateRulesCount + } + if totalValidateRulesCount+totalMutateRulesCount+totalGenerateRulesCount == 0 { + return nil + } + admissionReviewLatencyDurationInMs := float64(admissionReviewLatencyDuration) / float64(1000*1000) + return pm.registerAdmissionReviewLatencyMetric(clusterPoliciesCount, namespacedPoliciesCount, totalValidateRulesCount, totalMutateRulesCount, totalGenerateRulesCount, resourceName, resourceKind, resourceNamespace, resourceRequestOperation, admissionReviewLatencyDurationInMs) +} diff --git a/pkg/metrics/admissionreviewlatency/parsers.go b/pkg/metrics/admissionreviewlatency/parsers.go new file mode 100644 index 0000000000..14855e578a --- /dev/null +++ b/pkg/metrics/admissionreviewlatency/parsers.go @@ -0,0 +1,25 @@ +package admissionreviewlatency + +import ( + "fmt" + "github.com/kyverno/kyverno/pkg/metrics" +) + +func ParsePromMetrics(pm metrics.PromMetrics) PromMetrics { + return PromMetrics(pm) +} + +func ParseResourceRequestOperation(requestOperationStr string) (metrics.ResourceRequestOperation, error) { + switch requestOperationStr { + case "CREATE": + return metrics.ResourceCreated, nil + case "UPDATE": + return metrics.ResourceUpdated, nil + case "DELETE": + return metrics.ResourceDeleted, nil + case "CONNECT": + return metrics.ResourceConnected, nil + default: + return "", fmt.Errorf("Unknown request operation made by resource: %s. Allowed requests: 'CREATE', 'UPDATE', 'DELETE', 'CONNECT'", requestOperationStr) + } +} diff --git a/pkg/metrics/admissionreviewlatency/types.go b/pkg/metrics/admissionreviewlatency/types.go new file mode 100644 index 0000000000..a635a88b40 --- /dev/null +++ b/pkg/metrics/admissionreviewlatency/types.go @@ -0,0 +1,7 @@ +package admissionreviewlatency + +import ( + "github.com/kyverno/kyverno/pkg/metrics" +) + +type PromMetrics metrics.PromMetrics diff --git a/pkg/metrics/metrics.go b/pkg/metrics/metrics.go index 6875a84839..943c484300 100644 --- a/pkg/metrics/metrics.go +++ b/pkg/metrics/metrics.go @@ -79,7 +79,7 @@ func NewPromConfig() *PromConfig { } admissionReviewLatencyMetric := prom.NewGaugeVec( prom.GaugeOpts{ - Name: "kyverno_admission_review_latency", + Name: "kyverno_admission_review_latency_milliseconds", Help: "can be used to track the latencies associated with the entire individual admission review. For example, if an incoming request trigger, say, five policies, this metric will track the e2e latency associated with the execution of all those policies.", }, admissionReviewLatency, diff --git a/pkg/webhooks/generation.go b/pkg/webhooks/generation.go index 10182cf779..1add14d1d4 100644 --- a/pkg/webhooks/generation.go +++ b/pkg/webhooks/generation.go @@ -36,7 +36,7 @@ import ( ) //HandleGenerate handles admission-requests for policies with generate rules -func (ws *WebhookServer) HandleGenerate(request *v1beta1.AdmissionRequest, policies []*kyverno.ClusterPolicy, ctx *context.Context, userRequestInfo kyverno.RequestInfo, dynamicConfig config.Interface, admissionRequestTimestamp int64) { +func (ws *WebhookServer) HandleGenerate(request *v1beta1.AdmissionRequest, policies []*kyverno.ClusterPolicy, ctx *context.Context, userRequestInfo kyverno.RequestInfo, dynamicConfig config.Interface, admissionRequestTimestamp int64, latencySender *chan int64) { logger := ws.log.WithValues("action", "generation", "uid", request.UID, "kind", request.Kind, "namespace", request.Namespace, "name", request.Name, "operation", request.Operation, "gvk", request.Kind.String()) logger.V(4).Info("incoming request") var engineResponses []*response.EngineResponse @@ -104,6 +104,10 @@ func (ws *WebhookServer) HandleGenerate(request *v1beta1.AdmissionRequest, polic if request.Operation == v1beta1.Update { ws.handleUpdate(request, policies) } + + // sending the admission request latency to other goroutine (reporting the metrics) over the channel + admissionReviewLatencyDuration := int64(time.Since(time.Unix(admissionRequestTimestamp, 0))) + *latencySender <- admissionReviewLatencyDuration } func (ws *WebhookServer) registerPolicyRuleResultsMetricGeneration(logger logr.Logger, resourceRequestOperation string, policy kyverno.ClusterPolicy, engineResponse response.EngineResponse, admissionRequestTimestamp int64) { diff --git a/pkg/webhooks/mutation.go b/pkg/webhooks/mutation.go index fed392f542..c665300cac 100644 --- a/pkg/webhooks/mutation.go +++ b/pkg/webhooks/mutation.go @@ -22,17 +22,17 @@ import ( ) // HandleMutation handles mutating webhook admission request -// return value: generated patches +// return value: generated patches, triggered policies, engine responses correspdonding to the triggered policies func (ws *WebhookServer) HandleMutation( request *v1beta1.AdmissionRequest, resource unstructured.Unstructured, policies []*kyverno.ClusterPolicy, ctx *context.Context, userRequestInfo kyverno.RequestInfo, - admissionRequestTimestamp int64) []byte { + admissionRequestTimestamp int64) ([]byte, []kyverno.ClusterPolicy, []*response.EngineResponse) { if len(policies) == 0 { - return nil + return nil, nil, nil } resourceName := request.Kind.Kind + "/" + request.Name @@ -100,6 +100,7 @@ func (ws *WebhookServer) HandleMutation( // registering the kyverno_policy_rule_execution_latency_milliseconds metric concurrently go ws.registerPolicyRuleExecutionLatencyMetricMutate(logger, string(request.Operation), *policy, *engineResponse, admissionRequestTimestamp) + triggeredPolicies = append(triggeredPolicies, *policy) } // generate annotations @@ -131,7 +132,7 @@ func (ws *WebhookServer) HandleMutation( }() // patches holds all the successful patches, if no patch is created, it returns nil - return engineutils.JoinPatches(patches) + return engineutils.JoinPatches(patches), triggeredPolicies, engineResponses } func (ws *WebhookServer) registerPolicyRuleResultsMetricMutation(logger logr.Logger, resourceRequestOperation string, policy kyverno.ClusterPolicy, engineResponse response.EngineResponse, admissionRequestTimestamp int64) { diff --git a/pkg/webhooks/server.go b/pkg/webhooks/server.go index 08ef64dd68..00dc806572 100644 --- a/pkg/webhooks/server.go +++ b/pkg/webhooks/server.go @@ -19,9 +19,11 @@ import ( "github.com/kyverno/kyverno/pkg/config" client "github.com/kyverno/kyverno/pkg/dclient" enginectx "github.com/kyverno/kyverno/pkg/engine/context" + "github.com/kyverno/kyverno/pkg/engine/response" "github.com/kyverno/kyverno/pkg/event" "github.com/kyverno/kyverno/pkg/generate" "github.com/kyverno/kyverno/pkg/metrics" + admissionReviewLatency "github.com/kyverno/kyverno/pkg/metrics/admissionreviewlatency" "github.com/kyverno/kyverno/pkg/openapi" "github.com/kyverno/kyverno/pkg/policycache" "github.com/kyverno/kyverno/pkg/policyreport" @@ -362,18 +364,30 @@ func (ws *WebhookServer) ResourceMutation(request *v1beta1.AdmissionRequest) *v1 patchedResource := request.Object.Raw // MUTATION - patches = ws.HandleMutation(request, resource, mutatePolicies, ctx, userRequestInfo, admissionRequestTimestamp) + var triggeredMutatePolicies []v1.ClusterPolicy + var mutateEngineResponses []*response.EngineResponse + + patches, triggeredMutatePolicies, mutateEngineResponses = ws.HandleMutation(request, resource, mutatePolicies, ctx, userRequestInfo, admissionRequestTimestamp) logger.V(6).Info("", "generated patches", string(patches)) // patch the resource with patches before handling validation rules patchedResource = processResourceWithPatches(patches, request.Object.Raw, logger) logger.V(6).Info("", "patchedResource", string(patchedResource)) + admissionReviewLatencyDuration := int64(time.Since(time.Unix(admissionRequestTimestamp, 0))) + // registering the kyverno_admission_review_latency_milliseconds metric concurrently + go registerAdmissionReviewLatencyMetricMutate(logger, *ws.promConfig.Metrics, string(request.Operation), mutateEngineResponses, triggeredMutatePolicies, admissionReviewLatencyDuration) // GENERATE newRequest := request.DeepCopy() newRequest.Object.Raw = patchedResource - go ws.HandleGenerate(newRequest, generatePolicies, ctx, userRequestInfo, ws.configHandler, admissionRequestTimestamp) + // this channel will be used to transmit the admissionReviewLatency from ws.HandleGenerate(..,) goroutine to registeGeneraterPolicyAdmissionReviewLatencyMetric(...) goroutine + admissionReviewCompletionLatencyChannel := make(chan int64, 1) + + go ws.HandleGenerate(newRequest, generatePolicies, ctx, userRequestInfo, ws.configHandler, admissionRequestTimestamp, &admissionReviewCompletionLatencyChannel) + + // registering the kyverno_admission_review_latency_milliseconds metric concurrently + go registerAdmissionReviewLatencyMetricGenerate(logger, *ws.promConfig.Metrics, string(request.Operation), mutateEngineResponses, triggeredMutatePolicies, &admissionReviewCompletionLatencyChannel) patchType := v1beta1.PatchTypeJSONPatch return &v1beta1.AdmissionResponse{ Allowed: true, @@ -385,6 +399,29 @@ func (ws *WebhookServer) ResourceMutation(request *v1beta1.AdmissionRequest) *v1 } } +func registerAdmissionReviewLatencyMetricMutate(logger logr.Logger, promMetrics metrics.PromMetrics, requestOperation string, engineResponses []*response.EngineResponse, triggeredPolicies []v1.ClusterPolicy, admissionReviewLatencyDuration int64) { + resourceRequestOperationPromAlias, err := admissionReviewLatency.ParseResourceRequestOperation(requestOperation) + if err != nil { + logger.Error(err, "error occurred while registering kyverno_admission_review_latency_milliseconds metrics") + } + if err := admissionReviewLatency.ParsePromMetrics(promMetrics).ProcessEngineResponses(engineResponses, triggeredPolicies, admissionReviewLatencyDuration, resourceRequestOperationPromAlias); err != nil { + logger.Error(err, "error occurred while registering kyverno_admission_review_latency_milliseconds metrics") + } +} + +func registerAdmissionReviewLatencyMetricGenerate(logger logr.Logger, promMetrics metrics.PromMetrics, requestOperation string, engineResponses []*response.EngineResponse, triggeredPolicies []v1.ClusterPolicy, latencyReceiver *chan int64) { + defer close(*latencyReceiver) + resourceRequestOperationPromAlias, err := admissionReviewLatency.ParseResourceRequestOperation(requestOperation) + if err != nil { + logger.Error(err, "error occurred while registering kyverno_admission_review_latency_milliseconds metrics") + } + // this goroutine will keep on waiting here till it doesn't receive the admission review latency int64 from the other goroutine i.e. ws.HandleGenerate + admissionReviewLatencyDuration := <-(*latencyReceiver) + if err := admissionReviewLatency.ParsePromMetrics(promMetrics).ProcessEngineResponses(engineResponses, triggeredPolicies, admissionReviewLatencyDuration, resourceRequestOperationPromAlias); err != nil { + logger.Error(err, "error occurred while registering kyverno_admission_review_latency_milliseconds metrics") + } +} + func (ws *WebhookServer) resourceValidation(request *v1beta1.AdmissionRequest) *v1beta1.AdmissionResponse { logger := ws.log.WithName("Validate").WithValues("uid", request.UID, "kind", request.Kind.Kind, "namespace", request.Namespace, "name", request.Name, "operation", request.Operation) if request.Operation == v1beta1.Delete { diff --git a/pkg/webhooks/validation.go b/pkg/webhooks/validation.go index b082f72d8c..1c3e68b808 100644 --- a/pkg/webhooks/validation.go +++ b/pkg/webhooks/validation.go @@ -5,16 +5,19 @@ import ( "sort" "time" - client "github.com/kyverno/kyverno/pkg/dclient" - "github.com/go-logr/logr" kyverno "github.com/kyverno/kyverno/pkg/api/kyverno/v1" v1 "github.com/kyverno/kyverno/pkg/api/kyverno/v1" "github.com/kyverno/kyverno/pkg/config" + client "github.com/kyverno/kyverno/pkg/dclient" "github.com/kyverno/kyverno/pkg/engine" "github.com/kyverno/kyverno/pkg/engine/context" "github.com/kyverno/kyverno/pkg/engine/response" "github.com/kyverno/kyverno/pkg/event" + "github.com/kyverno/kyverno/pkg/metrics" + admissionReviewLatency "github.com/kyverno/kyverno/pkg/metrics/admissionreviewlatency" + policyRuleExecutionLatency "github.com/kyverno/kyverno/pkg/metrics/policyruleexecutionlatency" + policyRuleResults "github.com/kyverno/kyverno/pkg/metrics/policyruleresults" "github.com/kyverno/kyverno/pkg/policyreport" "github.com/kyverno/kyverno/pkg/policystatus" "github.com/kyverno/kyverno/pkg/resourcecache" @@ -22,10 +25,6 @@ import ( v1beta1 "k8s.io/api/admission/v1beta1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" - - "github.com/kyverno/kyverno/pkg/metrics" - policyRuleExecutionLatency "github.com/kyverno/kyverno/pkg/metrics/policyruleexecutionlatency" - policyRuleResults "github.com/kyverno/kyverno/pkg/metrics/policyruleresults" ) // HandleValidation handles validating webhook admission request @@ -94,6 +93,7 @@ func HandleValidation( } var engineResponses []*response.EngineResponse + var triggeredPolicies []kyverno.ClusterPolicy for _, policy := range policies { logger.V(3).Info("evaluating policy", "policy", policy.Name) policyContext.Policy = *policy @@ -111,6 +111,7 @@ func HandleValidation( go registerPolicyRuleExecutionLatencyMetricValidate(promConfig, logger, string(request.Operation), policyContext.Policy, *engineResponse, admissionRequestTimestamp) engineResponses = append(engineResponses, engineResponse) + triggeredPolicies = append(triggeredPolicies, *policy) statusListener.Update(validateStats{ resp: engineResponse, namespace: policy.Namespace, @@ -144,6 +145,9 @@ func HandleValidation( eventGen.Add(events...) if blocked { logger.V(4).Info("resource blocked") + //registering the kyverno_admission_review_latency_milliseconds metric concurrently + admissionReviewLatencyDuration := int64(time.Since(time.Unix(admissionRequestTimestamp, 0))) + go registerAdmissionReviewLatencyMetricValidate(promConfig, logger, string(request.Operation), engineResponses, triggeredPolicies, admissionReviewLatencyDuration) return false, getEnforceFailureErrorMsg(engineResponses) } @@ -155,6 +159,10 @@ func HandleValidation( prInfos := policyreport.GeneratePRsFromEngineResponse(engineResponses, logger) prGenerator.Add(prInfos...) + //registering the kyverno_admission_review_latency_milliseconds metric concurrently + admissionReviewLatencyDuration := int64(time.Since(time.Unix(admissionRequestTimestamp, 0))) + go registerAdmissionReviewLatencyMetricValidate(promConfig, logger, string(request.Operation), engineResponses, triggeredPolicies, admissionReviewLatencyDuration) + return true, "" } @@ -178,6 +186,16 @@ func registerPolicyRuleExecutionLatencyMetricValidate(promConfig *metrics.PromCo } } +func registerAdmissionReviewLatencyMetricValidate(promConfig *metrics.PromConfig, logger logr.Logger, requestOperation string, engineResponses []*response.EngineResponse, triggeredPolicies []kyverno.ClusterPolicy, admissionReviewLatencyDuration int64) { + resourceRequestOperationPromAlias, err := admissionReviewLatency.ParseResourceRequestOperation(requestOperation) + if err != nil { + logger.Error(err, "error occurred while registering kyverno_admission_review_latency_milliseconds metrics") + } + if err := admissionReviewLatency.ParsePromMetrics(*promConfig.Metrics).ProcessEngineResponses(engineResponses, triggeredPolicies, admissionReviewLatencyDuration, resourceRequestOperationPromAlias); err != nil { + logger.Error(err, "error occurred while registering kyverno_admission_review_latency_milliseconds metrics") + } +} + func buildDeletionPrInfo(oldR unstructured.Unstructured) policyreport.Info { return policyreport.Info{ Namespace: oldR.GetNamespace(),