From 09c9be2c2ee809bae4a85e486d04d69dcab778df Mon Sep 17 00:00:00 2001 From: Anish Ramasekar Date: Thu, 8 Feb 2024 18:08:07 +0000 Subject: [PATCH] Add `apiserver_authentication_jwt_authenticator_latency_seconds` metric Signed-off-by: Anish Ramasekar Kubernetes-commit: 0da5e8137b839860d55938ceb6d520caba3fc776 --- .../pkg/authenticator/token/oidc/metrics.go | 106 ++++++++++++++ .../authenticator/token/oidc/metrics_test.go | 129 ++++++++++++++++++ plugin/pkg/authenticator/token/oidc/oidc.go | 9 +- .../pkg/authenticator/token/oidc/oidc_test.go | 14 ++ 4 files changed, 254 insertions(+), 4 deletions(-) create mode 100644 plugin/pkg/authenticator/token/oidc/metrics.go create mode 100644 plugin/pkg/authenticator/token/oidc/metrics_test.go diff --git a/plugin/pkg/authenticator/token/oidc/metrics.go b/plugin/pkg/authenticator/token/oidc/metrics.go new file mode 100644 index 000000000..66c6254ec --- /dev/null +++ b/plugin/pkg/authenticator/token/oidc/metrics.go @@ -0,0 +1,106 @@ +/* +Copyright 2024 The Kubernetes Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package oidc + +import ( + "context" + "crypto/sha256" + "fmt" + "k8s.io/utils/clock" + "sync" + "time" + + "k8s.io/apiserver/pkg/authentication/authenticator" + "k8s.io/component-base/metrics" + "k8s.io/component-base/metrics/legacyregistry" +) + +const ( + namespace = "apiserver" + subsystem = "authentication" +) + +var ( + jwtAuthenticatorLatencyMetric = metrics.NewHistogramVec( + &metrics.HistogramOpts{ + Namespace: namespace, + Subsystem: subsystem, + Name: "jwt_authenticator_latency_seconds", + Help: "Latency of jwt authentication operations in seconds. This is the time spent authenticating a token for cache miss only (i.e. when the token is not found in the cache).", + StabilityLevel: metrics.ALPHA, + // default histogram buckets with a 1ms starting point + Buckets: []float64{.001, .005, .01, .025, .05, .1, .25, .5, 1, 2.5, 5, 10}, + }, + []string{"result", "jwt_issuer_hash"}, + ) +) + +var registerMetrics sync.Once + +func RegisterMetrics() { + registerMetrics.Do(func() { + legacyregistry.MustRegister(jwtAuthenticatorLatencyMetric) + }) +} + +func recordAuthenticationLatency(result, jwtIssuerHash string, duration time.Duration) { + jwtAuthenticatorLatencyMetric.WithLabelValues(result, jwtIssuerHash).Observe(duration.Seconds()) +} + +func getHash(data string) string { + if len(data) > 0 { + return fmt.Sprintf("sha256:%x", sha256.Sum256([]byte(data))) + } + return "" +} + +func newInstrumentedAuthenticator(jwtIssuer string, delegate authenticator.Token) authenticator.Token { + return newInstrumentedAuthenticatorWithClock(jwtIssuer, delegate, clock.RealClock{}) +} + +func newInstrumentedAuthenticatorWithClock(jwtIssuer string, delegate authenticator.Token, clock clock.PassiveClock) *instrumentedAuthenticator { + RegisterMetrics() + return &instrumentedAuthenticator{ + jwtIssuerHash: getHash(jwtIssuer), + delegate: delegate, + clock: clock, + } +} + +type instrumentedAuthenticator struct { + jwtIssuerHash string + delegate authenticator.Token + clock clock.PassiveClock +} + +func (a *instrumentedAuthenticator) AuthenticateToken(ctx context.Context, token string) (*authenticator.Response, bool, error) { + start := a.clock.Now() + response, ok, err := a.delegate.AuthenticateToken(ctx, token) + // this only happens when issuer doesn't match the authenticator + // we don't want to record metrics for this case + if !ok && err == nil { + return response, ok, err + } + + duration := a.clock.Since(start) + if err != nil { + recordAuthenticationLatency("failure", a.jwtIssuerHash, duration) + } else { + recordAuthenticationLatency("success", a.jwtIssuerHash, duration) + } + return response, ok, err +} diff --git a/plugin/pkg/authenticator/token/oidc/metrics_test.go b/plugin/pkg/authenticator/token/oidc/metrics_test.go new file mode 100644 index 000000000..998b18466 --- /dev/null +++ b/plugin/pkg/authenticator/token/oidc/metrics_test.go @@ -0,0 +1,129 @@ +/* +Copyright 2024 The Kubernetes Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package oidc + +import ( + "context" + "fmt" + "strings" + "testing" + "time" + + "k8s.io/apiserver/pkg/authentication/authenticator" + "k8s.io/component-base/metrics/legacyregistry" + "k8s.io/component-base/metrics/testutil" +) + +const ( + testIssuer = "testIssuer" +) + +func TestRecordAuthenticationLatency(t *testing.T) { + tests := []struct { + name string + authenticator authenticator.Token + generateMetrics func() + expectedValue string + }{ + { + name: "success", + authenticator: &dummyAuthenticator{response: &authenticator.Response{}, ok: true}, + expectedValue: ` + # HELP apiserver_authentication_jwt_authenticator_latency_seconds [ALPHA] Latency of jwt authentication operations in seconds. This is the time spent authenticating a token for cache miss only (i.e. when the token is not found in the cache). + # TYPE apiserver_authentication_jwt_authenticator_latency_seconds histogram + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="0.001"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="0.005"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="0.01"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="0.025"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="0.05"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="0.1"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="0.25"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="0.5"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="1"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="2.5"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="5"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="10"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success",le="+Inf"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_sum{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success"} 1e-09 + apiserver_authentication_jwt_authenticator_latency_seconds_count{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="success"} 1 + `, + }, + { + name: "error", + authenticator: &dummyAuthenticator{response: &authenticator.Response{}, ok: false, err: fmt.Errorf("error")}, + expectedValue: ` + # HELP apiserver_authentication_jwt_authenticator_latency_seconds [ALPHA] Latency of jwt authentication operations in seconds. This is the time spent authenticating a token for cache miss only (i.e. when the token is not found in the cache). + # TYPE apiserver_authentication_jwt_authenticator_latency_seconds histogram + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="0.001"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="0.005"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="0.01"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="0.025"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="0.05"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="0.1"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="0.25"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="0.5"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="1"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="2.5"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="5"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="10"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_bucket{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure",le="+Inf"} 1 + apiserver_authentication_jwt_authenticator_latency_seconds_sum{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure"} 1e-09 + apiserver_authentication_jwt_authenticator_latency_seconds_count{jwt_issuer_hash="sha256:29b34beedc55b972f2428f21bc588f9d38e5e8f7a7af825486e7bb4fd9caa2ad",result="failure"} 1 + `, + }, + { + name: "no metrics when issuer doesn't match", + authenticator: &dummyAuthenticator{response: &authenticator.Response{}, ok: false, err: nil}, + expectedValue: "", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + jwtAuthenticatorLatencyMetric.Reset() + RegisterMetrics() + + a := newInstrumentedAuthenticatorWithClock(testIssuer, tt.authenticator, dummyClock{}) + _, _, _ = a.AuthenticateToken(context.Background(), "token") + + if err := testutil.GatherAndCompare(legacyregistry.DefaultGatherer, strings.NewReader(tt.expectedValue), "apiserver_authentication_jwt_authenticator_latency_seconds"); err != nil { + t.Fatal(err) + } + }) + } +} + +type dummyAuthenticator struct { + response *authenticator.Response + ok bool + err error +} + +func (a *dummyAuthenticator) AuthenticateToken(ctx context.Context, token string) (*authenticator.Response, bool, error) { + return a.response, a.ok, a.err +} + +type dummyClock struct { +} + +func (d dummyClock) Now() time.Time { + return time.Now() +} + +func (d dummyClock) Since(t time.Time) time.Duration { + return time.Duration(1) +} diff --git a/plugin/pkg/authenticator/token/oidc/oidc.go b/plugin/pkg/authenticator/token/oidc/oidc.go index b0aa1f5c8..87ee459a0 100644 --- a/plugin/pkg/authenticator/token/oidc/oidc.go +++ b/plugin/pkg/authenticator/token/oidc/oidc.go @@ -221,7 +221,7 @@ var allowedSigningAlgs = map[string]bool{ oidc.PS512: true, } -func New(opts Options) (*Authenticator, error) { +func New(opts Options) (authenticator.Token, error) { celMapper, fieldErr := apiservervalidation.CompileAndValidateJWTAuthenticator(opts.JWTAuthenticator) if err := fieldErr.ToAggregate(); err != nil { return nil, err @@ -313,17 +313,18 @@ func New(opts Options) (*Authenticator, error) { requiredClaims: requiredClaims, } + issuerURL := opts.JWTAuthenticator.Issuer.URL if opts.KeySet != nil { // We already have a key set, synchronously initialize the verifier. authenticator.setVerifier(&idTokenVerifier{ - oidc.NewVerifier(opts.JWTAuthenticator.Issuer.URL, opts.KeySet, verifierConfig), + oidc.NewVerifier(issuerURL, opts.KeySet, verifierConfig), audiences, }) } else { // Asynchronously attempt to initialize the authenticator. This enables // self-hosted providers, providers that run on top of Kubernetes itself. go wait.PollImmediateUntil(10*time.Second, func() (done bool, err error) { - provider, err := oidc.NewProvider(ctx, opts.JWTAuthenticator.Issuer.URL) + provider, err := oidc.NewProvider(ctx, issuerURL) if err != nil { klog.Errorf("oidc authenticator: initializing plugin: %v", err) return false, nil @@ -335,7 +336,7 @@ func New(opts Options) (*Authenticator, error) { }, ctx.Done()) } - return authenticator, nil + return newInstrumentedAuthenticator(issuerURL, authenticator), nil } // untrustedIssuer extracts an untrusted "iss" claim from the given JWT token, diff --git a/plugin/pkg/authenticator/token/oidc/oidc_test.go b/plugin/pkg/authenticator/token/oidc/oidc_test.go index 92c848076..c8991fda9 100644 --- a/plugin/pkg/authenticator/token/oidc/oidc_test.go +++ b/plugin/pkg/authenticator/token/oidc/oidc_test.go @@ -42,6 +42,7 @@ import ( "k8s.io/apiserver/pkg/server/dynamiccertificates" utilfeature "k8s.io/apiserver/pkg/util/feature" featuregatetesting "k8s.io/component-base/featuregate/testing" + "k8s.io/component-base/metrics/testutil" "k8s.io/klog/v2" "k8s.io/utils/pointer" ) @@ -2986,8 +2987,21 @@ func TestToken(t *testing.T) { }, }, } + + var successTestCount, failureTestCount int for _, test := range tests { t.Run(test.name, test.run) + if test.wantSkip || test.wantInitErr != "" { + continue + } + // check metrics for success and failure + if test.wantErr == "" { + successTestCount++ + testutil.AssertHistogramTotalCount(t, "apiserver_authentication_jwt_authenticator_latency_seconds", map[string]string{"result": "success"}, successTestCount) + } else { + failureTestCount++ + testutil.AssertHistogramTotalCount(t, "apiserver_authentication_jwt_authenticator_latency_seconds", map[string]string{"result": "failure"}, failureTestCount) + } } }