From 290676e4d185f25978025f439e9e8ed47d6407ed Mon Sep 17 00:00:00 2001 From: Ryan Richard Date: Mon, 29 Jul 2024 14:46:18 -0700 Subject: [PATCH] improve info/debug log messages for jwtcachefiller & webhookcachefiller Co-authored-by: Ashish Amarnath --- .../jwtcachefiller/jwtcachefiller.go | 22 +- .../jwtcachefiller/jwtcachefiller_test.go | 379 ++++++++++++++---- .../webhookcachefiller/webhookcachefiller.go | 25 +- .../webhookcachefiller_test.go | 364 +++++++++++++---- .../concierge_jwtauthenticator_status_test.go | 3 + ...cierge_webhookauthenticator_status_test.go | 17 +- 6 files changed, 645 insertions(+), 165 deletions(-) diff --git a/internal/controller/authenticator/jwtcachefiller/jwtcachefiller.go b/internal/controller/authenticator/jwtcachefiller/jwtcachefiller.go index 6bd3b885c..e1682d72c 100644 --- a/internal/controller/authenticator/jwtcachefiller/jwtcachefiller.go +++ b/internal/controller/authenticator/jwtcachefiller/jwtcachefiller.go @@ -239,7 +239,7 @@ func (c *jwtCacheFillerController) syncIndividualJWTAuthenticator(ctx context.Co tlsBundleOk && // if there was any error while validating the CA bundle, then run remaining validations and update status oldJWTAuthenticatorFromCache.caBundleHash.Equal(caBundle.Hash()) { c.log.WithValues("jwtAuthenticator", klog.KObj(jwtAuthenticator), "issuer", jwtAuthenticator.Spec.Issuer). - Info("actual jwt authenticator and desired jwt authenticator are the same") + Info("cached jwt authenticator and desired jwt authenticator are the same: already cached, so skipping validations") // Stop, no more work to be done. This authenticator is already validated and cached. return nil } @@ -283,6 +283,11 @@ func (c *jwtCacheFillerController) syncIndividualJWTAuthenticator(ctx context.Co // validated and cached. Do not allow an old, previously validated spec of the authenticator to continue // being used for authentication. c.cache.Delete(cacheKey) + c.log.WithValues( + "jwtAuthenticator", klog.KObj(jwtAuthenticator), + "issuer", jwtAuthenticator.Spec.Issuer, + "removedFromCache", oldJWTAuthenticatorFromCache != nil, + ).Info("invalid jwt authenticator") } updateErr := c.updateStatus(ctx, jwtAuthenticator, conditions) @@ -293,8 +298,11 @@ func (c *jwtCacheFillerController) syncIndividualJWTAuthenticator(ctx context.Co // and skip trying to update its status again, which would leave its old status permanently intact. if authenticatorValid && updateErr == nil { c.cache.Store(cacheKey, newJWTAuthenticatorForCache) - c.log.WithValues("jwtAuthenticator", klog.KObj(jwtAuthenticator), "issuer", jwtAuthenticator.Spec.Issuer). - Info("added new jwt authenticator") + c.log.WithValues( + "jwtAuthenticator", klog.KObj(jwtAuthenticator), + "issuer", jwtAuthenticator.Spec.Issuer, + "isOverwrite", oldJWTAuthenticatorFromCache != nil, + ).Info("added or updated jwt authenticator in cache") } // Sync loop errors: @@ -669,11 +677,14 @@ func (c *jwtCacheFillerController) updateStatus( }) } + // TODO: this should use c.log.WithValues("jwtAuthenticator", original.Name) + log := plog.New().WithName(controllerName).WithValues("jwtAuthenticator", original.Name) + _ = conditionsutil.MergeConditions( conditions, original.Generation, &updated.Status.Conditions, - plog.New().WithName(controllerName), + log, metav1.NewTime(c.clock.Now()), ) @@ -681,5 +692,8 @@ func (c *jwtCacheFillerController) updateStatus( return nil } _, err := c.client.AuthenticationV1alpha1().JWTAuthenticators().UpdateStatus(ctx, updated, metav1.UpdateOptions{}) + if err == nil { + log.Debug("jwtauthenticator status successfully updated") + } return err } diff --git a/internal/controller/authenticator/jwtcachefiller/jwtcachefiller_test.go b/internal/controller/authenticator/jwtcachefiller/jwtcachefiller_test.go index a8005650b..8c2e16b08 100644 --- a/internal/controller/authenticator/jwtcachefiller/jwtcachefiller_test.go +++ b/internal/controller/authenticator/jwtcachefiller/jwtcachefiller_test.go @@ -755,11 +755,12 @@ func TestController(t *testing.T) { }, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -812,21 +813,45 @@ func TestController(t *testing.T) { ), wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": badIssuerJWKSURIJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "another-invalid-jwt-authenticator", + }, + }, + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "existing-jwt-authenticator", }, }, { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": badIssuerJWKSURIJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "invalid-jwt-authenticator", + }, + }, + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "new-jwt-authenticator", }, @@ -926,11 +951,12 @@ func TestController(t *testing.T) { }, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -973,11 +999,12 @@ func TestController(t *testing.T) { }, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -1016,11 +1043,12 @@ func TestController(t *testing.T) { someSecretWithCA, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -1059,11 +1087,12 @@ func TestController(t *testing.T) { someConfigMapWithCA, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -1099,11 +1128,12 @@ func TestController(t *testing.T) { }, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -1140,11 +1170,12 @@ func TestController(t *testing.T) { }, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -1193,11 +1224,12 @@ func TestController(t *testing.T) { }, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": true, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -1302,11 +1334,12 @@ func TestController(t *testing.T) { someSecretWithCA, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": true, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -1358,7 +1391,7 @@ func TestController(t *testing.T) { "level": "info", "timestamp": "2099-08-08T13:57:36.123456Z", "logger": "jwtcachefiller-controller", - "message": "actual jwt authenticator and desired jwt authenticator are the same", + "message": "cached jwt authenticator and desired jwt authenticator are the same: already cached, so skipping validations", "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", @@ -1413,11 +1446,12 @@ func TestController(t *testing.T) { "actualType": "*mockcachevalue.MockValue", }, { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -1453,6 +1487,19 @@ func TestController(t *testing.T) { Spec: *missingTLSJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": missingTLSJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1495,6 +1542,19 @@ func TestController(t *testing.T) { Spec: *invalidTLSJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": invalidTLSJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1548,6 +1608,19 @@ func TestController(t *testing.T) { Spec: *invalidTLSJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": true, + "issuer": invalidTLSJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1600,6 +1673,19 @@ func TestController(t *testing.T) { Spec: *invalidIssuerJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": true, + "issuer": invalidIssuerJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1641,6 +1727,19 @@ func TestController(t *testing.T) { Spec: *invalidIssuerJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": invalidIssuerJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1680,6 +1779,19 @@ func TestController(t *testing.T) { Spec: *invalidIssuerSchemeJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": invalidIssuerSchemeJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1723,6 +1835,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": "https://www.example.com/foo/bar/#do-not-include-fragment", + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1770,6 +1895,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": "https://www.example.com/foo/bar/?query-params=not-allowed", + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1817,6 +1955,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": "https://www.example.com/foo/bar/.well-known/openid-configuration", + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1860,6 +2011,19 @@ func TestController(t *testing.T) { Spec: *validIssuerURLButDoesNotExistJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": validIssuerURLButDoesNotExistJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1905,6 +2069,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": goodIssuer + "/path/to/not/found", + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1955,6 +2132,19 @@ func TestController(t *testing.T) { Spec: *badIssuerJWKSURIJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": badIssuerJWKSURIJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1994,6 +2184,19 @@ func TestController(t *testing.T) { Spec: *badIssuerJWKSURISchemeJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": badIssuerJWKSURISchemeJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -2033,6 +2236,19 @@ func TestController(t *testing.T) { Spec: *badIssuerUsesOurHardcodedPrivateKeyJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": badIssuerUsesOurHardcodedPrivateKeyJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -2073,6 +2289,19 @@ func TestController(t *testing.T) { Spec: *jwksFetchShouldFailJWTAuthenticatorSpec, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "invalid jwt authenticator", + "removedFromCache": false, + "issuer": jwksFetchShouldFailJWTAuthenticatorSpec.Issuer, + "jwtAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(jwtAuthenticatorsGVR, "", &authenticationv1alpha1.JWTAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -2117,11 +2346,12 @@ func TestController(t *testing.T) { }, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -2154,11 +2384,12 @@ func TestController(t *testing.T) { }, }, wantLogs: []map[string]any{{ - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "jwtcachefiller-controller", - "message": "added new jwt authenticator", - "issuer": goodIssuer, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "jwtcachefiller-controller", + "message": "added or updated jwt authenticator in cache", + "isOverwrite": false, + "issuer": goodIssuer, "jwtAuthenticator": map[string]any{ "name": "test-name", }, @@ -2288,8 +2519,12 @@ func TestController(t *testing.T) { require.Equal(t, len(tt.wantNamesOfJWTAuthenticatorsInCache), len(cache.Keys()), fmt.Sprintf("expected cache entries is incorrect. wanted:%d, got: %d, keys: %v", len(tt.wantNamesOfJWTAuthenticatorsInCache), len(cache.Keys()), cache.Keys())) + wantLogsAsJSON, err := json.Marshal(tt.wantLogs) + require.NoError(t, err) + actualLogLines := testutil.SplitByNewline(log.String()) - require.Equal(t, len(tt.wantLogs), len(actualLogLines), "log line count should be correct") + require.Equalf(t, len(tt.wantLogs), len(actualLogLines), + "log line count should be correct\nactual: %s\nwant: %s", actualLogLines, wantLogsAsJSON) for actualLogLineNum, actualLogLine := range actualLogLines { wantLine := tt.wantLogs[actualLogLineNum] diff --git a/internal/controller/authenticator/webhookcachefiller/webhookcachefiller.go b/internal/controller/authenticator/webhookcachefiller/webhookcachefiller.go index b27293b1c..e131e75a6 100644 --- a/internal/controller/authenticator/webhookcachefiller/webhookcachefiller.go +++ b/internal/controller/authenticator/webhookcachefiller/webhookcachefiller.go @@ -174,14 +174,15 @@ func (c *webhookCacheFillerController) syncIndividualWebhookAuthenticator(ctx co // rather than trying to show the most up-to-date status possible. These validations are for administrator // convenience at the time of a configuration change, to catch typos and blatant misconfigurations, rather // than to constantly monitor for external issues. + var oldWebhookAuthenticatorFromCache *cachedWebhookAuthenticator if valueFromCache := c.cache.Get(cacheKey); valueFromCache != nil { - oldWebhookAuthenticatorFromCache := c.cacheValueAsWebhookAuthenticator(valueFromCache) + oldWebhookAuthenticatorFromCache = c.cacheValueAsWebhookAuthenticator(valueFromCache) if oldWebhookAuthenticatorFromCache != nil && reflect.DeepEqual(oldWebhookAuthenticatorFromCache.spec, &webhookAuthenticator.Spec) && tlsBundleOk && // if there was any error while validating the CA bundle, then run remaining validations and update status oldWebhookAuthenticatorFromCache.caBundleHash.Equal(caBundle.Hash()) { c.log.WithValues("webhookAuthenticator", klog.KObj(webhookAuthenticator), "endpoint", webhookAuthenticator.Spec.Endpoint). - Info("actual webhook authenticator and desired webhook authenticator are the same") + Info("cached webhook authenticator and desired webhook authenticator are the same: already cached, so skipping validations") // Stop, no more work to be done. This authenticator is already validated and cached. return nil } @@ -214,6 +215,11 @@ func (c *webhookCacheFillerController) syncIndividualWebhookAuthenticator(ctx co // validated and cached. Do not allow an old, previously validated spec of the authenticator to continue // being used for authentication. c.cache.Delete(cacheKey) + c.log.WithValues( + "webhookAuthenticator", klog.KObj(webhookAuthenticator), + "endpoint", webhookAuthenticator.Spec.Endpoint, + "removedFromCache", oldWebhookAuthenticatorFromCache != nil, + ).Info("invalid webhook authenticator") } updateErr := c.updateStatus(ctx, webhookAuthenticator, conditions) @@ -228,8 +234,11 @@ func (c *webhookCacheFillerController) syncIndividualWebhookAuthenticator(ctx co spec: webhookAuthenticator.Spec.DeepCopy(), // deep copy to avoid caching original object caBundleHash: caBundle.Hash(), }) - c.log.WithValues("webhookAuthenticator", klog.KObj(webhookAuthenticator), "endpoint", webhookAuthenticator.Spec.Endpoint). - Info("added new webhook authenticator") + c.log.WithValues( + "webhookAuthenticator", klog.KObj(webhookAuthenticator), + "endpoint", webhookAuthenticator.Spec.Endpoint, + "isOverwrite", oldWebhookAuthenticatorFromCache != nil, + ).Info("added or updated webhook authenticator in cache") } // Sync loop errors: @@ -456,11 +465,14 @@ func (c *webhookCacheFillerController) updateStatus( }) } + // TODO: this should use c.log.WithValues("webhookAuthenticator", original.Name) + log := plog.New().WithName(controllerName).WithValues("webhookAuthenticator", original.Name) + _ = conditionsutil.MergeConditions( conditions, original.Generation, &updated.Status.Conditions, - plog.New().WithName(controllerName), + log, metav1.NewTime(c.clock.Now()), ) @@ -468,5 +480,8 @@ func (c *webhookCacheFillerController) updateStatus( return nil } _, err := c.client.AuthenticationV1alpha1().WebhookAuthenticators().UpdateStatus(ctx, updated, metav1.UpdateOptions{}) + if err == nil { + log.Debug("webhookauthenticator status successfully updated") + } return err } diff --git a/internal/controller/authenticator/webhookcachefiller/webhookcachefiller_test.go b/internal/controller/authenticator/webhookcachefiller/webhookcachefiller_test.go index 5a5cbdd41..f399fa35c 100644 --- a/internal/controller/authenticator/webhookcachefiller/webhookcachefiller_test.go +++ b/internal/controller/authenticator/webhookcachefiller/webhookcachefiller_test.go @@ -453,11 +453,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -505,21 +506,45 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, + "webhookAuthenticator": map[string]any{ + "name": "another-invalid-webhook-authenticator", + }, + }, + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "existing-webhook-authenticator", }, }, { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, + "webhookAuthenticator": map[string]any{ + "name": "invalid-webhook-authenticator", + }, + }, + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "new-webhook-authenticator", }, @@ -604,11 +629,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -649,11 +675,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -704,11 +731,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": true, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -758,6 +786,19 @@ func TestController(t *testing.T) { Spec: badWebhookAuthenticatorSpecInvalidTLS, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": true, + "endpoint": badWebhookAuthenticatorSpecInvalidTLS.Endpoint, + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -817,7 +858,7 @@ func TestController(t *testing.T) { "level": "info", "timestamp": "2099-08-08T13:57:36.123456Z", "logger": "webhookcachefiller-controller", - "message": "actual webhook authenticator and desired webhook authenticator are the same", + "message": "cached webhook authenticator and desired webhook authenticator are the same: already cached, so skipping validations", "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", @@ -870,11 +911,12 @@ func TestController(t *testing.T) { "actualType": "*mockcachevalue.MockValue", }, { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -935,11 +977,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": true, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -1038,11 +1081,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -1087,11 +1131,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": hostLocalIPv6Server.URL, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": hostLocalIPv6Server.URL, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -1134,6 +1179,19 @@ func TestController(t *testing.T) { Spec: goodWebhookAuthenticatorSpecWithoutCA, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": goodWebhookAuthenticatorSpecWithoutCA.Endpoint, + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1173,6 +1231,19 @@ func TestController(t *testing.T) { Spec: badWebhookAuthenticatorSpecInvalidTLS, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": badWebhookAuthenticatorSpecInvalidTLS.Endpoint, + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1225,6 +1296,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": true, + "endpoint": badEndpointInvalidURL, + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1289,6 +1373,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": true, + "endpoint": badEndpointInvalidURL, + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1333,6 +1430,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": badEndpointInvalidURL, + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1376,6 +1486,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": badEndpointNoHTTPS, + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1422,6 +1545,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": "https://[0:0:0:0:0:0:0:1]:69999/some/fake/path", + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1466,6 +1602,19 @@ func TestController(t *testing.T) { }, }, wantSyncErr: testutil.WantExactErrorString("error for WebhookAuthenticator test-name: cannot dial server: tls: failed to verify certificate: x509: certificate signed by unknown authority"), + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": badWebhookAuthenticatorSpecGoodEndpointButUnknownCA.Endpoint, + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1508,11 +1657,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpointBut404, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpointBut404, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -1560,11 +1710,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": fmt.Sprintf("https://localhost:%s", localhostURL.Port()), + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": fmt.Sprintf("https://localhost:%s", localhostURL.Port()), "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -1593,6 +1744,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": "https://[0:0:0:0:0:0:0:1]:4242/some/fake/path", + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1641,6 +1805,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": "https://[0:0:0:0:0:0:0:1]/some/fake/path", + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1695,11 +1872,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": hostAs127001WebhookServer.URL, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": hostAs127001WebhookServer.URL, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -1727,6 +1905,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": localWithExampleDotComWeebhookAuthenticatorSpec.Endpoint, + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1770,6 +1961,19 @@ func TestController(t *testing.T) { }, }, }, + wantLogs: []map[string]any{ + { + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "invalid webhook authenticator", + "removedFromCache": false, + "endpoint": "https://0:0:0:0:0:0:0:1/some/fake/path", + "webhookAuthenticator": map[string]any{ + "name": "test-name", + }, + }, + }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1819,11 +2023,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -1858,11 +2063,12 @@ func TestController(t *testing.T) { }, wantLogs: []map[string]any{ { - "level": "info", - "timestamp": "2099-08-08T13:57:36.123456Z", - "logger": "webhookcachefiller-controller", - "message": "added new webhook authenticator", - "endpoint": goodWebhookDefaultServingCertEndpoint, + "level": "info", + "timestamp": "2099-08-08T13:57:36.123456Z", + "logger": "webhookcachefiller-controller", + "message": "added or updated webhook authenticator in cache", + "isOverwrite": false, + "endpoint": goodWebhookDefaultServingCertEndpoint, "webhookAuthenticator": map[string]any{ "name": "test-name", }, @@ -1979,8 +2185,12 @@ func TestController(t *testing.T) { require.Equal(t, tt.wantActions(), pinnipedAPIClient.Actions()) require.Equal(t, len(tt.wantNamesOfWebhookAuthenticatorsInCache), len(cache.Keys()), fmt.Sprintf("expected cache entries is incorrect. wanted:%d, got: %d, keys: %v", len(tt.wantNamesOfWebhookAuthenticatorsInCache), len(cache.Keys()), cache.Keys())) + wantLogsAsJSON, err := json.Marshal(tt.wantLogs) + require.NoError(t, err) + actualLogLines := testutil.SplitByNewline(log.String()) - require.Equal(t, len(tt.wantLogs), len(actualLogLines), "log line count should be correct") + require.Equalf(t, len(tt.wantLogs), len(actualLogLines), + "log line count should be correct\nactual: %s\nwant: %s", actualLogLines, wantLogsAsJSON) for actualLogLineNum, actualLogLine := range actualLogLines { wantLine := tt.wantLogs[actualLogLineNum] diff --git a/test/integration/concierge_jwtauthenticator_status_test.go b/test/integration/concierge_jwtauthenticator_status_test.go index f2721a45c..dfc14565d 100644 --- a/test/integration/concierge_jwtauthenticator_status_test.go +++ b/test/integration/concierge_jwtauthenticator_status_test.go @@ -101,6 +101,9 @@ func TestConciergeJWTAuthenticatorWithExternalCABundleStatusIsUpdatedWhenExterna }, }, authenticationv1alpha1.JWTAuthenticatorPhaseReady) + t.Logf("created jwtauthenticator %s with CA bundle source %s %s", + authenticator.Name, test.caBundleSourceSpecKind, caBundleResourceName) + test.updateCABundle(t, caBundleResourceName, "this is not a valid CA bundle value") testlib.WaitForJWTAuthenticatorStatusPhase(ctx, t, authenticator.Name, authenticationv1alpha1.JWTAuthenticatorPhaseError) diff --git a/test/integration/concierge_webhookauthenticator_status_test.go b/test/integration/concierge_webhookauthenticator_status_test.go index ac8fd5153..357e766e0 100644 --- a/test/integration/concierge_webhookauthenticator_status_test.go +++ b/test/integration/concierge_webhookauthenticator_status_test.go @@ -82,13 +82,13 @@ func TestConciergeWebhookAuthenticatorWithExternalCABundleStatusIsUpdatedWhenExt t.Run(fmt.Sprintf("%d", i), func(t *testing.T) { t.Parallel() - caBundlePEM, err := base64.StdEncoding.DecodeString(testlib.IntegrationEnv(t).TestWebhook.TLS.CertificateAuthorityData) + caBundlePEM, err := base64.StdEncoding.DecodeString(env.TestWebhook.TLS.CertificateAuthorityData) require.NoError(t, err) caBundleResourceName := test.createResourceForCABundle(t, string(caBundlePEM)) authenticator := testlib.CreateTestWebhookAuthenticator(ctx, t, &authenticationv1alpha1.WebhookAuthenticatorSpec{ - Endpoint: testlib.IntegrationEnv(t).TestWebhook.Endpoint, + Endpoint: env.TestWebhook.Endpoint, TLS: &authenticationv1alpha1.TLSSpec{ CertificateAuthorityDataSource: &authenticationv1alpha1.CABundleSource{ Kind: test.caBundleSourceSpecKind, @@ -98,6 +98,9 @@ func TestConciergeWebhookAuthenticatorWithExternalCABundleStatusIsUpdatedWhenExt }, }, authenticationv1alpha1.WebhookAuthenticatorPhaseReady) + t.Logf("created webhookauthenticator %s with CA bundle source %s %s", + authenticator.Name, test.caBundleSourceSpecKind, caBundleResourceName) + test.updateCABundle(t, caBundleResourceName, "this is not a valid CA bundle value") testlib.WaitForWebhookAuthenticatorStatusPhase(ctx, t, authenticator.Name, authenticationv1alpha1.WebhookAuthenticatorPhaseError) @@ -110,7 +113,7 @@ func TestConciergeWebhookAuthenticatorWithExternalCABundleStatusIsUpdatedWhenExt } func TestConciergeWebhookAuthenticatorStatus_Parallel(t *testing.T) { - testEnv := testlib.IntegrationEnv(t) + env := testlib.IntegrationEnv(t) ctx, cancel := context.WithTimeout(context.Background(), 10*time.Minute) t.Cleanup(cancel) @@ -126,7 +129,7 @@ func TestConciergeWebhookAuthenticatorStatus_Parallel(t *testing.T) { { name: "basic test to see if the WebhookAuthenticator wakes up or not", spec: func() *authenticationv1alpha1.WebhookAuthenticatorSpec { - return &testlib.IntegrationEnv(t).TestWebhook + return &env.TestWebhook }, initialPhase: authenticationv1alpha1.WebhookAuthenticatorPhaseReady, finalConditions: allSuccessfulWebhookAuthenticatorConditions(), @@ -135,7 +138,7 @@ func TestConciergeWebhookAuthenticatorStatus_Parallel(t *testing.T) { name: "valid spec with invalid CA in TLS config will result in a WebhookAuthenticator that is not ready", spec: func() *authenticationv1alpha1.WebhookAuthenticatorSpec { caBundleString := "invalid base64-encoded data" - webhookSpec := testEnv.TestWebhook.DeepCopy() + webhookSpec := env.TestWebhook.DeepCopy() webhookSpec.TLS = &authenticationv1alpha1.TLSSpec{ CertificateAuthorityData: caBundleString, } @@ -172,7 +175,7 @@ func TestConciergeWebhookAuthenticatorStatus_Parallel(t *testing.T) { { name: "valid spec with valid CA in TLS config but does not match issuer server will result in a WebhookAuthenticator that is not ready", spec: func() *authenticationv1alpha1.WebhookAuthenticatorSpec { - webhookSpec := testEnv.TestWebhook.DeepCopy() + webhookSpec := env.TestWebhook.DeepCopy() webhookSpec.TLS = &authenticationv1alpha1.TLSSpec{ CertificateAuthorityData: caBundleSomePivotalCA, } @@ -204,7 +207,7 @@ func TestConciergeWebhookAuthenticatorStatus_Parallel(t *testing.T) { { name: "invalid with unresponsive endpoint will result in a WebhookAuthenticator that is not ready", spec: func() *authenticationv1alpha1.WebhookAuthenticatorSpec { - webhookSpec := testEnv.TestWebhook.DeepCopy() + webhookSpec := env.TestWebhook.DeepCopy() webhookSpec.TLS = &authenticationv1alpha1.TLSSpec{ CertificateAuthorityData: caBundleSomePivotalCA, }