Merge pull request #117211 from HirazawaUi/add-auth-metrics

add Authorization tracking request/error counts and latency metrics

staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication.go

@@ -34,17 +34,17 @@ import (
 	"k8s.io/klog/v2"
 )
 
-type recordMetrics func(context.Context, *authenticator.Response, bool, error, authenticator.Audiences, time.Time, time.Time)
+type authenticationRecordMetricsFunc func(context.Context, *authenticator.Response, bool, error, authenticator.Audiences, time.Time, time.Time)
 
 // WithAuthentication creates an http handler that tries to authenticate the given request as a user, and then
 // stores any such user found onto the provided context for the request. If authentication fails or returns an error
 // the failed handler is used. On success, "Authorization" header is removed from the request and handler
 // is invoked to serve the request.
 func WithAuthentication(handler http.Handler, auth authenticator.Request, failed http.Handler, apiAuds authenticator.Audiences, requestHeaderConfig *authenticatorfactory.RequestHeaderConfig) http.Handler {
-	return withAuthentication(handler, auth, failed, apiAuds, requestHeaderConfig, recordAuthMetrics)
+	return withAuthentication(handler, auth, failed, apiAuds, requestHeaderConfig, recordAuthenticationMetrics)
 }
 
-func withAuthentication(handler http.Handler, auth authenticator.Request, failed http.Handler, apiAuds authenticator.Audiences, requestHeaderConfig *authenticatorfactory.RequestHeaderConfig, metrics recordMetrics) http.Handler {
+func withAuthentication(handler http.Handler, auth authenticator.Request, failed http.Handler, apiAuds authenticator.Audiences, requestHeaderConfig *authenticatorfactory.RequestHeaderConfig, metrics authenticationRecordMetricsFunc) http.Handler {
 	if auth == nil {
 		klog.Warning("Authentication is disabled")
 		return handler

staging/src/k8s.io/apiserver/pkg/endpoints/filters/authorization.go

@@ -20,6 +20,7 @@ import (
 	"context"
 	"errors"
 	"net/http"
+	"time"
 
 	"k8s.io/klog/v2"
 
@@ -41,14 +42,21 @@ const (
 	reasonError    = "internal error"
 )
 
-// WithAuthorizationCheck passes all authorized requests on to handler, and returns a forbidden error otherwise.
+type recordAuthorizationMetricsFunc func(ctx context.Context, authorized authorizer.Decision, err error, authStart time.Time, authFinish time.Time)
-func WithAuthorization(handler http.Handler, a authorizer.Authorizer, s runtime.NegotiatedSerializer) http.Handler {
+
+// WithAuthorization passes all authorized requests on to handler, and returns a forbidden error otherwise.
+func WithAuthorization(hhandler http.Handler, auth authorizer.Authorizer, s runtime.NegotiatedSerializer) http.Handler {
+	return withAuthorization(hhandler, auth, s, recordAuthorizationMetrics)
+}
+
+func withAuthorization(handler http.Handler, a authorizer.Authorizer, s runtime.NegotiatedSerializer, metrics recordAuthorizationMetricsFunc) http.Handler {
 	if a == nil {
 		klog.Warning("Authorization is disabled")
 		return handler
 	}
 	return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
 		ctx := req.Context()
+		authorizationStart := time.Now()
 
 		attributes, err := GetAuthorizerAttributes(ctx)
 		if err != nil {
@@ -56,6 +64,12 @@ func WithAuthorization(handler http.Handler, a authorizer.Authorizer, s runtime.
 			return
 		}
 		authorized, reason, err := a.Authorize(ctx, attributes)
+
+		authorizationFinish := time.Now()
+		defer func() {
+			metrics(ctx, authorized, err, authorizationStart, authorizationFinish)
+		}()
+
 		// an authorizer like RBAC could encounter evaluation errors and still allow the request, so authorizer decision is checked before error here.
 		if authorized == authorizer.DecisionAllow {
 			audit.AddAuditAnnotations(ctx,

staging/src/k8s.io/apiserver/pkg/endpoints/filters/metrics.go

@@ -21,6 +21,8 @@ import (
 	"strings"
 	"time"
 
+	"k8s.io/apiserver/pkg/authorization/authorizer"
+
 	"k8s.io/apiserver/pkg/authentication/authenticator"
 	"k8s.io/component-base/metrics"
 	"k8s.io/component-base/metrics/legacyregistry"
@@ -38,6 +40,10 @@ const (
 	successLabel = "success"
 	failureLabel = "failure"
 	errorLabel   = "error"
+
+	allowedLabel   = "allowed"
+	deniedLabel    = "denied"
+	noOpinionLabel = "no-opinion"
 )
 
 var (
@@ -68,15 +74,54 @@ var (
 		},
 		[]string{"result"},
 	)
+
+	authorizationAttemptsCounter = metrics.NewCounterVec(
+		&metrics.CounterOpts{
+			Name:           "authorization_attempts_total",
+			Help:           "Counter of authorization attempts broken down by result. It can be either 'allowed', 'denied', 'no-opinion' or 'error'.",
+			StabilityLevel: metrics.ALPHA,
+		},
+		[]string{"result"},
+	)
+
+	authorizationLatency = metrics.NewHistogramVec(
+		&metrics.HistogramOpts{
+			Name:           "authorization_duration_seconds",
+			Help:           "Authorization duration in seconds broken out by result.",
+			Buckets:        metrics.ExponentialBuckets(0.001, 2, 15),
+			StabilityLevel: metrics.ALPHA,
+		},
+		[]string{"result"},
+	)
 )
 
 func init() {
 	legacyregistry.MustRegister(authenticatedUserCounter)
 	legacyregistry.MustRegister(authenticatedAttemptsCounter)
 	legacyregistry.MustRegister(authenticationLatency)
+	legacyregistry.MustRegister(authorizationAttemptsCounter)
+	legacyregistry.MustRegister(authorizationLatency)
 }
 
-func recordAuthMetrics(ctx context.Context, resp *authenticator.Response, ok bool, err error, apiAudiences authenticator.Audiences, authStart time.Time, authFinish time.Time) {
+func recordAuthorizationMetrics(ctx context.Context, authorized authorizer.Decision, err error, authStart time.Time, authFinish time.Time) {
+	var resultLabel string
+
+	switch {
+	case authorized == authorizer.DecisionAllow:
+		resultLabel = allowedLabel
+	case err != nil:
+		resultLabel = errorLabel
+	case authorized == authorizer.DecisionDeny:
+		resultLabel = deniedLabel
+	case authorized == authorizer.DecisionNoOpinion:
+		resultLabel = noOpinionLabel
+	}
+
+	authorizationAttemptsCounter.WithContext(ctx).WithLabelValues(resultLabel).Inc()
+	authorizationLatency.WithContext(ctx).WithLabelValues(resultLabel).Observe(authFinish.Sub(authStart).Seconds())
+}
+
+func recordAuthenticationMetrics(ctx context.Context, resp *authenticator.Response, ok bool, err error, apiAudiences authenticator.Audiences, authStart time.Time, authFinish time.Time) {
 	var resultLabel string
 
 	switch {

staging/src/k8s.io/apiserver/pkg/endpoints/filters/metrics_test.go

@@ -23,8 +23,12 @@ import (
 	"strings"
 	"testing"
 
+	"k8s.io/apimachinery/pkg/runtime"
+	"k8s.io/apimachinery/pkg/runtime/serializer"
+	auditinternal "k8s.io/apiserver/pkg/apis/audit"
 	"k8s.io/apiserver/pkg/authentication/authenticator"
 	"k8s.io/apiserver/pkg/authentication/user"
+	"k8s.io/apiserver/pkg/authorization/authorizer"
 	"k8s.io/component-base/metrics/legacyregistry"
 	"k8s.io/component-base/metrics/testutil"
 )
@@ -158,3 +162,110 @@ func TestMetrics(t *testing.T) {
 		})
 	}
 }
+
+func TestRecordAuthorizationMetricsMetrics(t *testing.T) {
+	// Excluding authorization_duration_seconds since it is difficult to predict its values.
+	metrics := []string{
+		"authorization_attempts_total",
+		"authorization_decision_annotations_total",
+	}
+
+	testCases := []struct {
+		desc       string
+		authorizer fakeAuthorizer
+		want       string
+	}{
+		{
+			desc: "auth ok",
+			authorizer: fakeAuthorizer{
+				authorizer.DecisionAllow,
+				"RBAC: allowed to patch pod",
+				nil,
+			},
+			want: `
+			# HELP authorization_attempts_total [ALPHA] Counter of authorization attempts broken down by result. It can be either 'allowed', 'denied', 'no-opinion' or 'error'.
+			# TYPE authorization_attempts_total counter
+			authorization_attempts_total{result="allowed"} 1
+				`,
+		},
+		{
+			desc: "decision forbid",
+			authorizer: fakeAuthorizer{
+				authorizer.DecisionDeny,
+				"RBAC: not allowed to patch pod",
+				nil,
+			},
+			want: `
+			# HELP authorization_attempts_total [ALPHA] Counter of authorization attempts broken down by result. It can be either 'allowed', 'denied', 'no-opinion' or 'error'.
+			# TYPE authorization_attempts_total counter
+			authorization_attempts_total{result="denied"} 1
+				`,
+		},
+		{
+			desc: "authorizer failed with error",
+			authorizer: fakeAuthorizer{
+				authorizer.DecisionNoOpinion,
+				"",
+				errors.New("can't parse user info"),
+			},
+			want: `
+			# HELP authorization_attempts_total [ALPHA] Counter of authorization attempts broken down by result. It can be either 'allowed', 'denied', 'no-opinion' or 'error'.
+			# TYPE authorization_attempts_total counter
+			authorization_attempts_total{result="error"} 1
+				`,
+		},
+		{
+			desc: "authorizer decided allow with error",
+			authorizer: fakeAuthorizer{
+				authorizer.DecisionAllow,
+				"",
+				errors.New("can't parse user info"),
+			},
+			want: `
+			# HELP authorization_attempts_total [ALPHA] Counter of authorization attempts broken down by result. It can be either 'allowed', 'denied', 'no-opinion' or 'error'.
+			# TYPE authorization_attempts_total counter
+			authorization_attempts_total{result="allowed"} 1
+				`,
+		},
+		{
+			desc: "authorizer failed with error",
+			authorizer: fakeAuthorizer{
+				authorizer.DecisionNoOpinion,
+				"",
+				nil,
+			},
+			want: `
+			# HELP authorization_attempts_total [ALPHA] Counter of authorization attempts broken down by result. It can be either 'allowed', 'denied', 'no-opinion' or 'error'.
+			# TYPE authorization_attempts_total counter
+			authorization_attempts_total{result="no-opinion"} 1
+				`,
+		},
+	}
+
+	// Since prometheus' gatherer is global, other tests may have updated metrics already, so
+	// we need to reset them prior running this test.
+	// This also implies that we can't run this test in parallel with other auth tests.
+	authorizationAttemptsCounter.Reset()
+
+	scheme := runtime.NewScheme()
+	negotiatedSerializer := serializer.NewCodecFactory(scheme).WithoutConversion()
+
+	for _, tt := range testCases {
+		t.Run(tt.desc, func(t *testing.T) {
+			defer authorizationAttemptsCounter.Reset()
+
+			audit := &auditinternal.Event{Level: auditinternal.LevelMetadata}
+			handler := WithAuthorization(&fakeHTTPHandler{}, tt.authorizer, negotiatedSerializer)
+			// TODO: fake audit injector
+
+			req, _ := http.NewRequest("GET", "/api/v1/namespaces/default/pods", nil)
+			req = withTestContext(req, nil, audit)
+			req.RemoteAddr = "127.0.0.1"
+			handler.ServeHTTP(httptest.NewRecorder(), req)
+
+			if err := testutil.GatherAndCompare(legacyregistry.DefaultGatherer, strings.NewReader(tt.want), metrics...); err != nil {
+				t.Fatal(err)
+			}
+		})
+	}
+}