diff --git a/internal/controller/authenticator/webhookcachefiller/webhookcachefiller.go b/internal/controller/authenticator/webhookcachefiller/webhookcachefiller.go index 84dde901c..82b7f1674 100644 --- a/internal/controller/authenticator/webhookcachefiller/webhookcachefiller.go +++ b/internal/controller/authenticator/webhookcachefiller/webhookcachefiller.go @@ -165,6 +165,11 @@ func (c *webhookCacheFillerController) syncIndividualWebhookAuthenticator(ctx co conditions := make([]*metav1.Condition, 0) caBundle, conditions, tlsBundleOk := c.validateTLSBundle(webhookAuthenticator.Spec.TLS, conditions) + + webhookSpecificLogger := c.log.WithValues( + "webhookAuthenticator", webhookAuthenticator.Name, + "endpoint", webhookAuthenticator.Spec.Endpoint) + // Only revalidate and update the cache if the cached authenticator is different from the desired authenticator. // There is no need to repeat validations for a spec that was already successfully validated. We are making a // design decision to avoid repeating the validation which dials the server, even though the server's TLS @@ -175,13 +180,12 @@ func (c *webhookCacheFillerController) syncIndividualWebhookAuthenticator(ctx co // 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, webhookSpecificLogger) 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", webhookAuthenticator.Name, "endpoint", webhookAuthenticator.Spec.Endpoint). - Info("cached webhook authenticator and desired webhook authenticator are the same: already cached, so skipping validations") + webhookSpecificLogger.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 } @@ -191,7 +195,7 @@ func (c *webhookCacheFillerController) syncIndividualWebhookAuthenticator(ctx co endpointHostPort, conditions, endpointOk := c.validateEndpoint(webhookAuthenticator.Spec.Endpoint, conditions) okSoFar := tlsBundleOk && endpointOk - conditions, tlsNegotiateErr := c.validateConnection(caBundle.CertPool(), endpointHostPort, conditions, okSoFar) + conditions, tlsNegotiateErr := c.validateConnection(caBundle.CertPool(), endpointHostPort, conditions, okSoFar, webhookSpecificLogger) errs = append(errs, tlsNegotiateErr) okSoFar = okSoFar && tlsNegotiateErr == nil @@ -214,14 +218,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", webhookAuthenticator.Name, - "endpoint", webhookAuthenticator.Spec.Endpoint, - "removedFromCache", oldWebhookAuthenticatorFromCache != nil, - ).Info("invalid webhook authenticator") + webhookSpecificLogger.Info("invalid webhook authenticator", + "removedFromCache", oldWebhookAuthenticatorFromCache != nil) } - updateErr := c.updateStatus(ctx, webhookAuthenticator, conditions) + updateErr := c.updateStatus(ctx, webhookAuthenticator, conditions, webhookSpecificLogger) errs = append(errs, updateErr) // Only add this WebhookAuthenticator to the cache if the status update succeeds. @@ -233,11 +234,8 @@ func (c *webhookCacheFillerController) syncIndividualWebhookAuthenticator(ctx co spec: webhookAuthenticator.Spec.DeepCopy(), // deep copy to avoid caching original object caBundleHash: caBundle.Hash(), }) - c.log.WithValues( - "webhookAuthenticator", webhookAuthenticator.Name, - "endpoint", webhookAuthenticator.Spec.Endpoint, - "isOverwrite", oldWebhookAuthenticatorFromCache != nil, - ).Info("added or updated webhook authenticator in cache") + webhookSpecificLogger.Info("added or updated webhook authenticator in cache", + "isOverwrite", oldWebhookAuthenticatorFromCache != nil) } // Sync loop errors: @@ -248,14 +246,15 @@ func (c *webhookCacheFillerController) syncIndividualWebhookAuthenticator(ctx co return utilerrors.NewAggregate(errs) } -func (c *webhookCacheFillerController) cacheValueAsWebhookAuthenticator(value authncache.Value) *cachedWebhookAuthenticator { +func (c *webhookCacheFillerController) cacheValueAsWebhookAuthenticator(value authncache.Value, log plog.Logger) *cachedWebhookAuthenticator { webhookAuthenticator, ok := value.(*cachedWebhookAuthenticator) if !ok { actualType := "" if t := reflect.TypeOf(value); t != nil { actualType = t.String() } - c.log.WithValues("actualType", actualType).Info("wrong webhook authenticator type in cache") + log.Info("wrong webhook authenticator type in cache", + "actualType", actualType) return nil } return webhookAuthenticator @@ -352,7 +351,13 @@ func newWebhookAuthenticator( return webhookAuthenticator, conditions, nil } -func (c *webhookCacheFillerController) validateConnection(certPool *x509.CertPool, endpointHostPort *endpointaddr.HostPort, conditions []*metav1.Condition, prereqOk bool) ([]*metav1.Condition, error) { +func (c *webhookCacheFillerController) validateConnection( + certPool *x509.CertPool, + endpointHostPort *endpointaddr.HostPort, + conditions []*metav1.Condition, + prereqOk bool, + logger plog.Logger, +) ([]*metav1.Condition, error) { if !prereqOk { conditions = append(conditions, &metav1.Condition{ Type: typeWebhookConnectionValid, @@ -381,7 +386,7 @@ func (c *webhookCacheFillerController) validateConnection(certPool *x509.CertPoo err = conn.Close() if err != nil { // no unit test for this failure - c.log.Error("error closing dialer", err) + logger.Error("error closing dialer", err) } conditions = append(conditions, &metav1.Condition{ @@ -443,6 +448,7 @@ func (c *webhookCacheFillerController) updateStatus( ctx context.Context, original *authenticationv1alpha1.WebhookAuthenticator, conditions []*metav1.Condition, + logger plog.Logger, ) error { updated := original.DeepCopy() @@ -464,14 +470,11 @@ 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, - log, + logger, metav1.NewTime(c.clock.Now()), ) @@ -480,7 +483,7 @@ func (c *webhookCacheFillerController) updateStatus( } _, err := c.client.AuthenticationV1alpha1().WebhookAuthenticators().UpdateStatus(ctx, updated, metav1.UpdateOptions{}) if err == nil { - log.Debug("webhookauthenticator status successfully updated") + logger.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 afa295d90..06f2f63eb 100644 --- a/internal/controller/authenticator/webhookcachefiller/webhookcachefiller_test.go +++ b/internal/controller/authenticator/webhookcachefiller/webhookcachefiller_test.go @@ -491,8 +491,11 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"another-invalid-webhook-authenticator","endpoint":"%s","removedFromCache":false}`, goodWebhookDefaultServingCertEndpoint), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"another-invalid-webhook-authenticator","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"existing-webhook-authenticator","endpoint":"%s","isOverwrite":false}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"invalid-webhook-authenticator","endpoint":"%s","removedFromCache":false}`, goodWebhookDefaultServingCertEndpoint), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"invalid-webhook-authenticator","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"new-webhook-authenticator","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"new-webhook-authenticator","endpoint":"%s","isOverwrite":false}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { @@ -573,6 +576,7 @@ func TestController(t *testing.T) { someSecretWithCA, }, wantLogLines: []string{ + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":false}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { @@ -609,6 +613,7 @@ func TestController(t *testing.T) { someConfigMapWithCA, }, wantLogLines: []string{ + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":false}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { @@ -655,6 +660,7 @@ func TestController(t *testing.T) { someConfigMapWithCA, }, wantLogLines: []string{ + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":true}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { @@ -703,6 +709,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"%s","removedFromCache":true}`, badWebhookAuthenticatorSpecInvalidTLS.Endpoint), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -759,7 +766,8 @@ func TestController(t *testing.T) { }, }, wantLogLines: []string{ - fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"cached webhook authenticator and desired webhook authenticator are the same: already cached, so skipping validations","webhookAuthenticator":{"name":"test-name"},"endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), + fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"cached webhook authenticator and desired webhook authenticator are the same: already cached, so skipping validations","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), + fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":true}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { return []coretesting.Action{ @@ -799,7 +807,8 @@ func TestController(t *testing.T) { }, }, wantLogLines: []string{ - `{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).cacheValueAsWebhookAuthenticator","message":"wrong webhook authenticator type in cache","actualType":"*mockcachevalue.MockValue"}`, + fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).cacheValueAsWebhookAuthenticator","message":"wrong webhook authenticator type in cache","webhookAuthenticator":"test-name","endpoint":"%s","actualType":"*mockcachevalue.MockValue"}`, goodWebhookDefaultServingCertEndpoint), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":false}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { @@ -856,6 +865,7 @@ func TestController(t *testing.T) { }, }, wantLogLines: []string{ + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":true}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { @@ -916,7 +926,7 @@ func TestController(t *testing.T) { Spec: goodWebhookAuthenticatorSpecWithCA, }, }, - wantLogLines: []string{}, // wants no logs + wantLogLines: nil, // wants no logs wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -950,6 +960,7 @@ func TestController(t *testing.T) { }, }, wantLogLines: []string{ + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":false}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { @@ -990,6 +1001,7 @@ func TestController(t *testing.T) { }, }, wantLogLines: []string{ + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, hostLocalIPv6Server.URL), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":false}`, hostLocalIPv6Server.URL), }, wantActions: func() []coretesting.Action { @@ -1031,6 +1043,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"%s","removedFromCache":false}`, goodWebhookAuthenticatorSpecWithoutCA.Endpoint), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookAuthenticatorSpecWithoutCA.Endpoint), }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1073,6 +1086,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"%s","removedFromCache":false}`, badWebhookAuthenticatorSpecInvalidTLS.Endpoint), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, badWebhookAuthenticatorSpecInvalidTLS.Endpoint), }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1128,6 +1142,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"%s","removedFromCache":true}`, badEndpointInvalidURL), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, badEndpointInvalidURL), }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1242,6 +1257,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"%s","removedFromCache":false}`, badEndpointInvalidURL), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, badEndpointInvalidURL), }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1288,6 +1304,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"%s","removedFromCache":false}`, badEndpointNoHTTPS), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, badEndpointNoHTTPS), }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1337,6 +1354,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ `{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"https://[0:0:0:0:0:0:0:1]:69999/some/fake/path","removedFromCache":false}`, + `{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"https://[0:0:0:0:0:0:0:1]:69999/some/fake/path"}`, }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1384,6 +1402,7 @@ 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"), wantLogLines: []string{ fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"%s","removedFromCache":false}`, badWebhookAuthenticatorSpecGoodEndpointButUnknownCA.Endpoint), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, badWebhookAuthenticatorSpecGoodEndpointButUnknownCA.Endpoint), }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1426,6 +1445,7 @@ func TestController(t *testing.T) { }, }, wantLogLines: []string{ + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpointBut404), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":false}`, goodWebhookDefaultServingCertEndpointBut404), }, wantActions: func() []coretesting.Action { @@ -1496,6 +1516,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ `{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"https://[0:0:0:0:0:0:0:1]:4242/some/fake/path","removedFromCache":false}`, + `{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"https://[0:0:0:0:0:0:0:1]:4242/some/fake/path"}`, }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1547,6 +1568,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ `{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"https://[0:0:0:0:0:0:0:1]/some/fake/path","removedFromCache":false}`, + `{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"https://[0:0:0:0:0:0:0:1]/some/fake/path"}`, }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1627,6 +1649,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"%s","removedFromCache":false}`, localWithExampleDotComWeebhookAuthenticatorSpec.Endpoint), + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, localWithExampleDotComWeebhookAuthenticatorSpec.Endpoint), }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1673,6 +1696,7 @@ func TestController(t *testing.T) { }, wantLogLines: []string{ `{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"invalid webhook authenticator","webhookAuthenticator":"test-name","endpoint":"https://0:0:0:0:0:0:0:1/some/fake/path","removedFromCache":false}`, + `{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"https://0:0:0:0:0:0:0:1/some/fake/path"}`, }, wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ @@ -1752,6 +1776,7 @@ func TestController(t *testing.T) { }, }, wantLogLines: []string{ + fmt.Sprintf(`{"level":"debug","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).updateStatus","message":"webhookauthenticator status successfully updated","webhookAuthenticator":"test-name","endpoint":"%s"}`, goodWebhookDefaultServingCertEndpoint), fmt.Sprintf(`{"level":"info","timestamp":"2099-08-08T13:57:36.123456Z","logger":"webhookcachefiller-controller","caller":"webhookcachefiller/webhookcachefiller.go:$webhookcachefiller.(*webhookCacheFillerController).syncIndividualWebhookAuthenticator","message":"added or updated webhook authenticator in cache","webhookAuthenticator":"test-name","endpoint":"%s","isOverwrite":false}`, goodWebhookDefaultServingCertEndpoint), }, wantActions: func() []coretesting.Action { @@ -1793,7 +1818,7 @@ func TestController(t *testing.T) { Spec: goodWebhookAuthenticatorSpecWithCA, }, }, - wantLogLines: []string{}, // wants no logs + wantLogLines: nil, // wants no logs wantActions: func() []coretesting.Action { updateStatusAction := coretesting.NewUpdateAction(webhookAuthenticatorGVR, "", &authenticationv1alpha1.WebhookAuthenticator{ ObjectMeta: metav1.ObjectMeta{ @@ -1865,12 +1890,16 @@ 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())) - if len(tt.wantLogLines) == 0 { - require.Empty(t, log.String()) - } else { - actualLog, _ := strings.CutSuffix(log.String(), "\n") - require.Equal(t, tt.wantLogLines, strings.Split(actualLog, "\n")) + actualLog, _ := strings.CutSuffix(log.String(), "\n") + actualLogLines := strings.Split(actualLog, "\n") + var webhookLogLines []string + for _, line := range actualLogLines { + if strings.Contains(line, "webhookcachefiller/webhookcachefiller.go") { + webhookLogLines = append(webhookLogLines, line) + } } + + require.Equal(t, tt.wantLogLines, webhookLogLines) }) } }