From 104c208d0fb69ad8edb180b2b306516f9d01d021 Mon Sep 17 00:00:00 2001 From: HirazawaUi <695097494plus@gmail.com> Date: Tue, 11 Apr 2023 22:35:14 +0800 Subject: [PATCH] add Authentication tracking request/error counts and latency metrics --- .../pkg/endpoints/filters/authentication.go | 6 +- .../pkg/endpoints/filters/authorization.go | 18 ++- .../pkg/endpoints/filters/metrics.go | 47 +++++++- .../pkg/endpoints/filters/metrics_test.go | 111 ++++++++++++++++++ 4 files changed, 176 insertions(+), 6 deletions(-) diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication.go index d6741bf3a3a..277bdcdfe5f 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication.go +++ b/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 diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authorization.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authorization.go index f7648d41ced..e102a1e3281 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authorization.go +++ b/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. -func WithAuthorization(handler http.Handler, a authorizer.Authorizer, s runtime.NegotiatedSerializer) http.Handler { +type recordAuthorizationMetricsFunc func(ctx context.Context, authorized authorizer.Decision, err error, authStart time.Time, authFinish time.Time) + +// 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, diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/metrics.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/metrics.go index 47e1be847c7..a4dae3d84ed 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/metrics.go +++ b/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 { diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/metrics_test.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/metrics_test.go index e20eee417bd..25ecb2d9176 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/metrics_test.go +++ b/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) + } + }) + } +}