diff --git a/cmd/kube-controller-manager/app/bootstrap.go b/cmd/kube-controller-manager/app/bootstrap.go index 02b2ed0229f..81881566f1e 100644 --- a/cmd/kube-controller-manager/app/bootstrap.go +++ b/cmd/kube-controller-manager/app/bootstrap.go @@ -20,11 +20,14 @@ import ( "context" "fmt" + "k8s.io/klog/v2" + "k8s.io/controller-manager/controller" "k8s.io/kubernetes/pkg/controller/bootstrap" ) func startBootstrapSignerController(ctx context.Context, controllerContext ControllerContext) (controller.Interface, bool, error) { + ctx = klog.NewContext(ctx, klog.LoggerWithName(klog.FromContext(ctx), "bootstrap-signer-controller")) bsc, err := bootstrap.NewSigner( controllerContext.ClientBuilder.ClientOrDie("bootstrap-signer"), controllerContext.InformerFactory.Core().V1().Secrets(), @@ -39,6 +42,7 @@ func startBootstrapSignerController(ctx context.Context, controllerContext Contr } func startTokenCleanerController(ctx context.Context, controllerContext ControllerContext) (controller.Interface, bool, error) { + ctx = klog.NewContext(ctx, klog.LoggerWithName(klog.FromContext(ctx), "token-cleaner-controller")) tcc, err := bootstrap.NewTokenCleaner( controllerContext.ClientBuilder.ClientOrDie("token-cleaner"), controllerContext.InformerFactory.Core().V1().Secrets(), diff --git a/pkg/controller/bootstrap/bootstrapsigner.go b/pkg/controller/bootstrap/bootstrapsigner.go index 6ac34e44755..95be04bd768 100644 --- a/pkg/controller/bootstrap/bootstrapsigner.go +++ b/pkg/controller/bootstrap/bootstrapsigner.go @@ -158,10 +158,11 @@ func (e *Signer) Run(ctx context.Context) { return } - klog.V(5).Infof("Starting workers") + logger := klog.FromContext(ctx) + logger.V(5).Info("Starting workers") go wait.UntilWithContext(ctx, e.serviceConfigMapQueue, 0) <-ctx.Done() - klog.V(1).Infof("Shutting down") + logger.V(1).Info("Shutting down") } func (e *Signer) pokeConfigMapSync() { @@ -191,10 +192,12 @@ func (e *Signer) signConfigMap(ctx context.Context) { newCM := origCM.DeepCopy() + logger := klog.FromContext(ctx) + // First capture the config we are signing content, ok := newCM.Data[bootstrapapi.KubeConfigKey] if !ok { - klog.V(3).Infof("No %s key in %s/%s ConfigMap", bootstrapapi.KubeConfigKey, origCM.Namespace, origCM.Name) + logger.V(3).Info("No key in ConfigMap", "key", bootstrapapi.KubeConfigKey, "configMap", klog.KObj(origCM)) return } @@ -209,7 +212,7 @@ func (e *Signer) signConfigMap(ctx context.Context) { } // Now recompute signatures and store them on the new map - tokens := e.getTokens() + tokens := e.getTokens(ctx) for tokenID, tokenValue := range tokens { sig, err := jws.ComputeDetachedSignature(content, tokenID, tokenValue) if err != nil { @@ -240,7 +243,7 @@ func (e *Signer) signConfigMap(ctx context.Context) { func (e *Signer) updateConfigMap(ctx context.Context, cm *v1.ConfigMap) { _, err := e.client.CoreV1().ConfigMaps(cm.Namespace).Update(ctx, cm, metav1.UpdateOptions{}) if err != nil && !apierrors.IsConflict(err) && !apierrors.IsNotFound(err) { - klog.V(3).Infof("Error updating ConfigMap: %v", err) + klog.FromContext(ctx).V(3).Info("Error updating ConfigMap", "err", err) } } @@ -278,11 +281,11 @@ func (e *Signer) listSecrets() []*v1.Secret { // getTokens returns a map of tokenID->tokenSecret. It ensures the token is // valid for signing. -func (e *Signer) getTokens() map[string]string { +func (e *Signer) getTokens(ctx context.Context) map[string]string { ret := map[string]string{} secretObjs := e.listSecrets() for _, secret := range secretObjs { - tokenID, tokenSecret, ok := validateSecretForSigning(secret) + tokenID, tokenSecret, ok := validateSecretForSigning(ctx, secret) if !ok { continue } @@ -291,7 +294,7 @@ func (e *Signer) getTokens() map[string]string { if _, ok := ret[tokenID]; ok { // This should never happen as we ensure a consistent secret name. // But leave this in here just in case. - klog.V(1).Infof("Duplicate bootstrap tokens found for id %s, ignoring on in %s/%s", tokenID, secret.Namespace, secret.Name) + klog.FromContext(ctx).V(1).Info("Duplicate bootstrap tokens found for id, ignoring on the duplicate secret", "tokenID", tokenID, "ignoredSecret", klog.KObj(secret)) continue } diff --git a/pkg/controller/bootstrap/tokencleaner.go b/pkg/controller/bootstrap/tokencleaner.go index b356ff76a3e..5a08296557f 100644 --- a/pkg/controller/bootstrap/tokencleaner.go +++ b/pkg/controller/bootstrap/tokencleaner.go @@ -108,8 +108,9 @@ func (tc *TokenCleaner) Run(ctx context.Context) { defer utilruntime.HandleCrash() defer tc.queue.ShutDown() - klog.Infof("Starting token cleaner controller") - defer klog.Infof("Shutting down token cleaner controller") + logger := klog.FromContext(ctx) + logger.Info("Starting token cleaner controller") + defer logger.Info("Shutting down token cleaner controller") if !cache.WaitForNamedCacheSync("token_cleaner", ctx.Done(), tc.secretSynced) { return @@ -154,9 +155,10 @@ func (tc *TokenCleaner) processNextWorkItem(ctx context.Context) bool { } func (tc *TokenCleaner) syncFunc(ctx context.Context, key string) error { + logger := klog.FromContext(ctx) startTime := time.Now() defer func() { - klog.V(4).Infof("Finished syncing secret %q (%v)", key, time.Since(startTime)) + logger.V(4).Info("Finished syncing secret", "secret", key, "elapsedTime", time.Since(startTime)) }() namespace, name, err := cache.SplitMetaNamespaceKey(key) @@ -166,7 +168,7 @@ func (tc *TokenCleaner) syncFunc(ctx context.Context, key string) error { ret, err := tc.secretLister.Secrets(namespace).Get(name) if apierrors.IsNotFound(err) { - klog.V(3).Infof("secret has been deleted: %v", key) + logger.V(3).Info("Secret has been deleted", "secret", key) return nil } @@ -181,10 +183,11 @@ func (tc *TokenCleaner) syncFunc(ctx context.Context, key string) error { } func (tc *TokenCleaner) evalSecret(ctx context.Context, o interface{}) { + logger := klog.FromContext(ctx) secret := o.(*v1.Secret) ttl, alreadyExpired := bootstrapsecretutil.GetExpiration(secret, time.Now()) if alreadyExpired { - klog.V(3).Infof("Deleting expired secret %s/%s", secret.Namespace, secret.Name) + logger.V(3).Info("Deleting expired secret", "secret", klog.KObj(secret)) var options metav1.DeleteOptions if len(secret.UID) > 0 { options.Preconditions = &metav1.Preconditions{UID: &secret.UID} @@ -193,7 +196,7 @@ func (tc *TokenCleaner) evalSecret(ctx context.Context, o interface{}) { // NotFound isn't a real error (it's already been deleted) // Conflict isn't a real error (the UID precondition failed) if err != nil && !apierrors.IsConflict(err) && !apierrors.IsNotFound(err) { - klog.V(3).Infof("Error deleting Secret: %v", err) + logger.V(3).Info("Error deleting secret", "err", err) } } else if ttl > 0 { key, err := controller.KeyFunc(o) diff --git a/pkg/controller/bootstrap/util.go b/pkg/controller/bootstrap/util.go index 6f5ad9ff882..7d58f609fad 100644 --- a/pkg/controller/bootstrap/util.go +++ b/pkg/controller/bootstrap/util.go @@ -17,6 +17,7 @@ limitations under the License. package bootstrap import ( + "context" "time" "k8s.io/klog/v2" @@ -26,27 +27,28 @@ import ( bootstrapsecretutil "k8s.io/cluster-bootstrap/util/secrets" ) -func validateSecretForSigning(secret *v1.Secret) (tokenID, tokenSecret string, ok bool) { +func validateSecretForSigning(ctx context.Context, secret *v1.Secret) (tokenID, tokenSecret string, ok bool) { + logger := klog.FromContext(ctx) nameTokenID, ok := bootstrapsecretutil.ParseName(secret.Name) if !ok { - klog.V(3).Infof("Invalid secret name: %s. Must be of form %s.", secret.Name, bootstrapapi.BootstrapTokenSecretPrefix) + logger.V(3).Info("Invalid secret name, must be of the form "+bootstrapapi.BootstrapTokenSecretPrefix+"", "secretName", secret.Name) return "", "", false } tokenID = bootstrapsecretutil.GetData(secret, bootstrapapi.BootstrapTokenIDKey) if len(tokenID) == 0 { - klog.V(3).Infof("No %s key in %s/%s Secret", bootstrapapi.BootstrapTokenIDKey, secret.Namespace, secret.Name) + logger.V(3).Info("No key in Secret", "key", bootstrapapi.BootstrapTokenIDKey, "secret", klog.KObj(secret)) return "", "", false } if nameTokenID != tokenID { - klog.V(3).Infof("Token ID (%s) doesn't match secret name: %s", tokenID, nameTokenID) + logger.V(3).Info("Token ID doesn't match secret name", "tokenID", tokenID, "secretName", secret.Name) return "", "", false } tokenSecret = bootstrapsecretutil.GetData(secret, bootstrapapi.BootstrapTokenSecretKey) if len(tokenSecret) == 0 { - klog.V(3).Infof("No %s key in %s/%s Secret", bootstrapapi.BootstrapTokenSecretKey, secret.Namespace, secret.Name) + logger.V(3).Info("No key in secret", "key", bootstrapapi.BootstrapTokenSecretKey, "secret", klog.KObj(secret)) return "", "", false } diff --git a/pkg/controller/bootstrap/util_test.go b/pkg/controller/bootstrap/util_test.go index ca17c99785f..0aa228a0730 100644 --- a/pkg/controller/bootstrap/util_test.go +++ b/pkg/controller/bootstrap/util_test.go @@ -23,6 +23,7 @@ import ( "k8s.io/api/core/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" bootstrapapi "k8s.io/cluster-bootstrap/token/api" + "k8s.io/klog/v2/ktesting" ) const ( @@ -79,38 +80,42 @@ func TestValidateSecretForSigning(t *testing.T) { } for _, tc := range cases { - secret := &v1.Secret{ - ObjectMeta: metav1.ObjectMeta{ - Namespace: metav1.NamespaceSystem, - Name: bootstrapapi.BootstrapTokenSecretPrefix + givenTokenID, - ResourceVersion: "1", - }, - Type: bootstrapapi.SecretTypeBootstrapToken, - Data: map[string][]byte{ - bootstrapapi.BootstrapTokenIDKey: []byte(tc.tokenID), - bootstrapapi.BootstrapTokenSecretKey: []byte(tc.tokenSecret), - bootstrapapi.BootstrapTokenUsageSigningKey: []byte(tc.okToSign), - bootstrapapi.BootstrapTokenExpirationKey: []byte(tc.expiration), - }, - } + t.Run(tc.description, func(t *testing.T) { + _, ctx := ktesting.NewTestContext(t) + secret := &v1.Secret{ + ObjectMeta: metav1.ObjectMeta{ + Namespace: metav1.NamespaceSystem, + Name: bootstrapapi.BootstrapTokenSecretPrefix + givenTokenID, + ResourceVersion: "1", + }, + Type: bootstrapapi.SecretTypeBootstrapToken, + Data: map[string][]byte{ + bootstrapapi.BootstrapTokenIDKey: []byte(tc.tokenID), + bootstrapapi.BootstrapTokenSecretKey: []byte(tc.tokenSecret), + bootstrapapi.BootstrapTokenUsageSigningKey: []byte(tc.okToSign), + bootstrapapi.BootstrapTokenExpirationKey: []byte(tc.expiration), + }, + } - tokenID, tokenSecret, ok := validateSecretForSigning(secret) - if ok != tc.valid { - t.Errorf("%s: Unexpected validation failure. Expected %v, got %v", tc.description, tc.valid, ok) - } - if ok { - if tokenID != tc.tokenID { - t.Errorf("%s: Unexpected Token ID. Expected %q, got %q", tc.description, givenTokenID, tokenID) + tokenID, tokenSecret, ok := validateSecretForSigning(ctx, secret) + if ok != tc.valid { + t.Errorf("Unexpected validation failure. Expected %v, got %v", tc.valid, ok) } - if tokenSecret != tc.tokenSecret { - t.Errorf("%s: Unexpected Token Secret. Expected %q, got %q", tc.description, givenTokenSecret, tokenSecret) + if ok { + if tokenID != tc.tokenID { + t.Errorf("Unexpected Token ID. Expected %q, got %q", givenTokenID, tokenID) + } + if tokenSecret != tc.tokenSecret { + t.Errorf("Unexpected Token Secret. Expected %q, got %q", givenTokenSecret, tokenSecret) + } } - } + }) } } func TestValidateSecret(t *testing.T) { + _, ctx := ktesting.NewTestContext(t) secret := &v1.Secret{ ObjectMeta: metav1.ObjectMeta{ Namespace: metav1.NamespaceSystem, @@ -125,7 +130,7 @@ func TestValidateSecret(t *testing.T) { }, } - tokenID, tokenSecret, ok := validateSecretForSigning(secret) + tokenID, tokenSecret, ok := validateSecretForSigning(ctx, secret) if !ok { t.Errorf("Unexpected validation failure.") } @@ -138,6 +143,7 @@ func TestValidateSecret(t *testing.T) { } func TestBadSecretName(t *testing.T) { + _, ctx := ktesting.NewTestContext(t) secret := &v1.Secret{ ObjectMeta: metav1.ObjectMeta{ Namespace: metav1.NamespaceSystem, @@ -152,13 +158,14 @@ func TestBadSecretName(t *testing.T) { }, } - _, _, ok := validateSecretForSigning(secret) + _, _, ok := validateSecretForSigning(ctx, secret) if ok { t.Errorf("Token validation should fail with bad name") } } func TestMismatchSecretName(t *testing.T) { + _, ctx := ktesting.NewTestContext(t) secret := &v1.Secret{ ObjectMeta: metav1.ObjectMeta{ Namespace: metav1.NamespaceSystem, @@ -173,7 +180,7 @@ func TestMismatchSecretName(t *testing.T) { }, } - _, _, ok := validateSecretForSigning(secret) + _, _, ok := validateSecretForSigning(ctx, secret) if ok { t.Errorf("Token validation should fail with mismatched name") }