Migrate off global logger in impersonatorconfig.

Signed-off-by: Matt Moyer <moyerm@vmware.com>
This commit is contained in:
Matt Moyer 2021-05-26 12:42:50 -05:00
parent e5a61f3b95
commit b13c494f93
No known key found for this signature in database
GPG Key ID: EAE88AD172C5AE2D
3 changed files with 68 additions and 54 deletions

View File

@ -15,6 +15,7 @@ import (
"strings" "strings"
"time" "time"
"github.com/go-logr/logr"
v1 "k8s.io/api/core/v1" v1 "k8s.io/api/core/v1"
k8serrors "k8s.io/apimachinery/pkg/api/errors" k8serrors "k8s.io/apimachinery/pkg/api/errors"
metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@ -27,6 +28,7 @@ import (
"k8s.io/apimachinery/pkg/util/validation" "k8s.io/apimachinery/pkg/util/validation"
corev1informers "k8s.io/client-go/informers/core/v1" corev1informers "k8s.io/client-go/informers/core/v1"
"k8s.io/client-go/kubernetes" "k8s.io/client-go/kubernetes"
"k8s.io/klog/v2"
"go.pinniped.dev/generated/latest/apis/concierge/config/v1alpha1" "go.pinniped.dev/generated/latest/apis/concierge/config/v1alpha1"
pinnipedclientset "go.pinniped.dev/generated/latest/client/concierge/clientset/versioned" pinnipedclientset "go.pinniped.dev/generated/latest/client/concierge/clientset/versioned"
@ -41,7 +43,6 @@ import (
"go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/controllerlib"
"go.pinniped.dev/internal/dynamiccert" "go.pinniped.dev/internal/dynamiccert"
"go.pinniped.dev/internal/endpointaddr" "go.pinniped.dev/internal/endpointaddr"
"go.pinniped.dev/internal/plog"
) )
const ( const (
@ -79,6 +80,8 @@ type impersonatorConfigController struct {
serverStopCh chan struct{} serverStopCh chan struct{}
errorCh chan error errorCh chan error
tlsServingCertDynamicCertProvider dynamiccert.Private tlsServingCertDynamicCertProvider dynamiccert.Private
infoLog logr.Logger
debugLog logr.Logger
} }
func NewImpersonatorConfigController( func NewImpersonatorConfigController(
@ -100,8 +103,10 @@ func NewImpersonatorConfigController(
impersonatorFunc impersonator.FactoryFunc, impersonatorFunc impersonator.FactoryFunc,
impersonationSignerSecretName string, impersonationSignerSecretName string,
impersonationSigningCertProvider dynamiccert.Provider, impersonationSigningCertProvider dynamiccert.Provider,
log logr.Logger,
) controllerlib.Controller { ) controllerlib.Controller {
secretNames := sets.NewString(tlsSecretName, caSecretName, impersonationSignerSecretName) secretNames := sets.NewString(tlsSecretName, caSecretName, impersonationSignerSecretName)
log = log.WithName("impersonator-config-controller")
return controllerlib.New( return controllerlib.New(
controllerlib.Config{ controllerlib.Config{
Name: "impersonator-config-controller", Name: "impersonator-config-controller",
@ -123,6 +128,8 @@ func NewImpersonatorConfigController(
impersonationSigningCertProvider: impersonationSigningCertProvider, impersonationSigningCertProvider: impersonationSigningCertProvider,
impersonatorFunc: impersonatorFunc, impersonatorFunc: impersonatorFunc,
tlsServingCertDynamicCertProvider: dynamiccert.NewServingCert("impersonation-proxy-serving-cert"), tlsServingCertDynamicCertProvider: dynamiccert.NewServingCert("impersonation-proxy-serving-cert"),
infoLog: log,
debugLog: log.V(10),
}, },
}, },
withInformer(credentialIssuerInformer, withInformer(credentialIssuerInformer,
@ -151,7 +158,7 @@ func NewImpersonatorConfigController(
} }
func (c *impersonatorConfigController) Sync(syncCtx controllerlib.Context) error { func (c *impersonatorConfigController) Sync(syncCtx controllerlib.Context) error {
plog.Debug("Starting impersonatorConfigController Sync") c.debugLog.Info("starting impersonatorConfigController Sync")
// Load the CredentialIssuer that we'll update with status. // Load the CredentialIssuer that we'll update with status.
credIssuer, err := c.credIssuerInformer.Lister().Get(c.credentialIssuerResourceName) credIssuer, err := c.credIssuerInformer.Lister().Get(c.credentialIssuerResourceName)
@ -180,7 +187,7 @@ func (c *impersonatorConfigController) Sync(syncCtx controllerlib.Context) error
)}) )})
if err == nil { if err == nil {
plog.Debug("Successfully finished impersonatorConfigController Sync") c.debugLog.Info("successfully finished impersonatorConfigController Sync")
} }
return err return err
} }
@ -219,7 +226,7 @@ func (c *impersonatorConfigController) doSync(syncCtx controllerlib.Context, cre
return nil, err return nil, err
} }
c.hasControlPlaneNodes = &hasControlPlaneNodes c.hasControlPlaneNodes = &hasControlPlaneNodes
plog.Debug("Queried for control plane nodes", "foundControlPlaneNodes", hasControlPlaneNodes) c.debugLog.Info("queried for control plane nodes", "foundControlPlaneNodes", hasControlPlaneNodes)
} }
if c.shouldHaveImpersonator(impersonationSpec) { if c.shouldHaveImpersonator(impersonationSpec) {
@ -295,9 +302,7 @@ func (c *impersonatorConfigController) loadImpersonationProxyConfiguration(credI
if err := validateCredentialIssuerSpec(spec); err != nil { if err := validateCredentialIssuerSpec(spec); err != nil {
return nil, fmt.Errorf("could not load CredentialIssuer spec.impersonationProxy: %w", err) return nil, fmt.Errorf("could not load CredentialIssuer spec.impersonationProxy: %w", err)
} }
plog.Info("Read impersonation proxy config", c.infoLog.Info("read impersonation proxy config", "credentialIssuer", c.credentialIssuerResourceName)
"credentialIssuer", c.credentialIssuerResourceName,
)
return spec, nil return spec, nil
} }
@ -392,7 +397,7 @@ func (c *impersonatorConfigController) ensureImpersonatorIsStarted(syncCtx contr
} }
} }
plog.Info("Starting impersonation proxy", "port", impersonationProxyPort) c.infoLog.Info("starting impersonation proxy", "port", impersonationProxyPort)
startImpersonatorFunc, err := c.impersonatorFunc( startImpersonatorFunc, err := c.impersonatorFunc(
impersonationProxyPort, impersonationProxyPort,
c.tlsServingCertDynamicCertProvider, c.tlsServingCertDynamicCertProvider,
@ -427,7 +432,7 @@ func (c *impersonatorConfigController) ensureImpersonatorIsStopped(shouldCloseEr
return nil return nil
} }
plog.Info("Stopping impersonation proxy", "port", impersonationProxyPort) c.infoLog.Info("stopping impersonation proxy", "port", impersonationProxyPort)
close(c.serverStopCh) close(c.serverStopCh)
stopErr := <-c.errorCh stopErr := <-c.errorCh
@ -475,9 +480,9 @@ func (c *impersonatorConfigController) ensureLoadBalancerIsStopped(ctx context.C
return nil return nil
} }
plog.Info("Deleting load balancer for impersonation proxy", c.infoLog.Info("deleting load balancer for impersonation proxy",
"service", c.generatedLoadBalancerServiceName, "service", klog.KRef(c.namespace, c.generatedLoadBalancerServiceName),
"namespace", c.namespace) )
return c.k8sClient.CoreV1().Services(c.namespace).Delete(ctx, c.generatedLoadBalancerServiceName, metav1.DeleteOptions{}) return c.k8sClient.CoreV1().Services(c.namespace).Delete(ctx, c.generatedLoadBalancerServiceName, metav1.DeleteOptions{})
} }
@ -514,9 +519,9 @@ func (c *impersonatorConfigController) ensureClusterIPServiceIsStopped(ctx conte
return nil return nil
} }
plog.Info("Deleting cluster ip for impersonation proxy", c.infoLog.Info("deleting cluster ip for impersonation proxy",
"service", c.generatedClusterIPServiceName, "service", klog.KRef(c.namespace, c.generatedClusterIPServiceName),
"namespace", c.namespace) )
return c.k8sClient.CoreV1().Services(c.namespace).Delete(ctx, c.generatedClusterIPServiceName, metav1.DeleteOptions{}) return c.k8sClient.CoreV1().Services(c.namespace).Delete(ctx, c.generatedClusterIPServiceName, metav1.DeleteOptions{})
} }
@ -531,10 +536,10 @@ func (c *impersonatorConfigController) createOrUpdateService(ctx context.Context
return err return err
} }
if needsUpdate { if needsUpdate {
plog.Info("updating service for impersonation proxy", c.infoLog.Info("updating service for impersonation proxy",
"service type", service.Spec.Type, "serviceType", service.Spec.Type,
"service", service.Name, "service", klog.KObj(service),
"namespace", c.namespace) )
// update only the annotation and loadBalancerIP fields on the service // update only the annotation and loadBalancerIP fields on the service
var newService = &v1.Service{} var newService = &v1.Service{}
existingService.DeepCopyInto(newService) existingService.DeepCopyInto(newService)
@ -545,10 +550,10 @@ func (c *impersonatorConfigController) createOrUpdateService(ctx context.Context
} }
return nil return nil
} }
plog.Info("creating service for impersonation proxy", c.infoLog.Info("creating service for impersonation proxy",
"service type", service.Spec.Type, "serviceType", service.Spec.Type,
"service", service.Name, "service", klog.KObj(service),
"namespace", c.namespace) )
_, err = c.k8sClient.CoreV1().Services(c.namespace).Create(ctx, service, metav1.CreateOptions{}) _, err = c.k8sClient.CoreV1().Services(c.namespace).Create(ctx, service, metav1.CreateOptions{})
return err return err
} }
@ -579,10 +584,10 @@ func (c *impersonatorConfigController) deleteTLSSecretWhenCertificateDoesNotMatc
certPEM := secret.Data[v1.TLSCertKey] certPEM := secret.Data[v1.TLSCertKey]
block, _ := pem.Decode(certPEM) block, _ := pem.Decode(certPEM)
if block == nil { if block == nil {
plog.Warning("Found missing or not PEM-encoded data in TLS Secret", c.infoLog.Info("found missing or not PEM-encoded data in TLS Secret",
"invalidCertPEM", string(certPEM), "invalidCertPEM", string(certPEM),
"secret", c.tlsSecretName, "secret", klog.KObj(secret),
"namespace", c.namespace) )
deleteErr := c.ensureTLSSecretIsRemoved(ctx) deleteErr := c.ensureTLSSecretIsRemoved(ctx)
if deleteErr != nil { if deleteErr != nil {
return false, fmt.Errorf("found missing or not PEM-encoded data in TLS Secret, but got error while deleting it: %w", deleteErr) return false, fmt.Errorf("found missing or not PEM-encoded data in TLS Secret, but got error while deleting it: %w", deleteErr)
@ -592,10 +597,10 @@ func (c *impersonatorConfigController) deleteTLSSecretWhenCertificateDoesNotMatc
actualCertFromSecret, err := x509.ParseCertificate(block.Bytes) actualCertFromSecret, err := x509.ParseCertificate(block.Bytes)
if err != nil { if err != nil {
plog.Error("Found invalid PEM data in TLS Secret", err, c.infoLog.Error(err, "found missing or not PEM-encoded data in TLS Secret",
"invalidCertPEM", string(certPEM), "invalidCertPEM", string(certPEM),
"secret", c.tlsSecretName, "secret", klog.KObj(secret),
"namespace", c.namespace) )
if err = c.ensureTLSSecretIsRemoved(ctx); err != nil { if err = c.ensureTLSSecretIsRemoved(ctx); err != nil {
return false, fmt.Errorf("PEM data represented an invalid cert, but got error while deleting it: %w", err) return false, fmt.Errorf("PEM data represented an invalid cert, but got error while deleting it: %w", err)
} }
@ -605,9 +610,10 @@ func (c *impersonatorConfigController) deleteTLSSecretWhenCertificateDoesNotMatc
keyPEM := secret.Data[v1.TLSPrivateKeyKey] keyPEM := secret.Data[v1.TLSPrivateKeyKey]
_, err = tls.X509KeyPair(certPEM, keyPEM) _, err = tls.X509KeyPair(certPEM, keyPEM)
if err != nil { if err != nil {
plog.Error("Found invalid private key PEM data in TLS Secret", err, c.infoLog.Error(err, "found invalid private key PEM data in TLS Secret",
"secret", c.tlsSecretName, "invalidCertPEM", string(certPEM),
"namespace", c.namespace) "secret", klog.KObj(secret),
)
if err = c.ensureTLSSecretIsRemoved(ctx); err != nil { if err = c.ensureTLSSecretIsRemoved(ctx); err != nil {
return false, fmt.Errorf("cert had an invalid private key, but got error while deleting it: %w", err) return false, fmt.Errorf("cert had an invalid private key, but got error while deleting it: %w", err)
} }
@ -635,13 +641,13 @@ func (c *impersonatorConfigController) deleteTLSSecretWhenCertificateDoesNotMatc
actualIPs := actualCertFromSecret.IPAddresses actualIPs := actualCertFromSecret.IPAddresses
actualHostnames := actualCertFromSecret.DNSNames actualHostnames := actualCertFromSecret.DNSNames
plog.Info("Checking TLS certificate names", c.infoLog.Info("checking TLS certificate names",
"desiredIPs", nameInfo.selectedIPs, "desiredIPs", nameInfo.selectedIPs,
"desiredHostname", nameInfo.selectedHostname, "desiredHostname", nameInfo.selectedHostname,
"actualIPs", actualIPs, "actualIPs", actualIPs,
"actualHostnames", actualHostnames, "actualHostnames", actualHostnames,
"secret", c.tlsSecretName, "secret", klog.KObj(secret),
"namespace", c.namespace) )
if certHostnameAndIPMatchDesiredState(nameInfo.selectedIPs, actualIPs, nameInfo.selectedHostname, actualHostnames) { if certHostnameAndIPMatchDesiredState(nameInfo.selectedIPs, actualIPs, nameInfo.selectedHostname, actualHostnames) {
// The cert already matches the desired state, so there is no need to delete/recreate it. // The cert already matches the desired state, so there is no need to delete/recreate it.
@ -740,9 +746,9 @@ func (c *impersonatorConfigController) createCASecret(ctx context.Context) (*cer
Type: v1.SecretTypeOpaque, Type: v1.SecretTypeOpaque,
} }
plog.Info("Creating CA certificates for impersonation proxy", c.infoLog.Info("creating CA certificates for impersonation proxy",
"secret", c.caSecretName, "secret", klog.KObj(&secret),
"namespace", c.namespace) )
if _, err = c.k8sClient.CoreV1().Secrets(c.namespace).Create(ctx, &secret, metav1.CreateOptions{}); err != nil { if _, err = c.k8sClient.CoreV1().Secrets(c.namespace).Create(ctx, &secret, metav1.CreateOptions{}); err != nil {
return nil, err return nil, err
} }
@ -781,9 +787,9 @@ func (c *impersonatorConfigController) findTLSCertificateNameFromLoadBalancer()
} }
ingresses := lb.Status.LoadBalancer.Ingress ingresses := lb.Status.LoadBalancer.Ingress
if len(ingresses) == 0 || (ingresses[0].Hostname == "" && ingresses[0].IP == "") { if len(ingresses) == 0 || (ingresses[0].Hostname == "" && ingresses[0].IP == "") {
plog.Info("load balancer for impersonation proxy does not have an ingress yet, so skipping tls cert generation while we wait", c.infoLog.Info("load balancer for impersonation proxy does not have an ingress yet, so skipping tls cert generation while we wait",
"service", c.generatedLoadBalancerServiceName, "service", klog.KObj(lb),
"namespace", c.namespace) )
return &certNameInfo{ready: false}, nil return &certNameInfo{ready: false}, nil
} }
for _, ingress := range ingresses { for _, ingress := range ingresses {
@ -859,11 +865,11 @@ func (c *impersonatorConfigController) createNewTLSSecret(ctx context.Context, c
Type: v1.SecretTypeTLS, Type: v1.SecretTypeTLS,
} }
plog.Info("Creating TLS certificates for impersonation proxy", c.infoLog.Info("creating TLS certificates for impersonation proxy",
"ips", ips, "ips", ips,
"hostnames", hostnames, "hostnames", hostnames,
"secret", c.tlsSecretName, "secret", klog.KObj(newTLSSecret),
"namespace", c.namespace) )
return c.k8sClient.CoreV1().Secrets(c.namespace).Create(ctx, newTLSSecret, metav1.CreateOptions{}) return c.k8sClient.CoreV1().Secrets(c.namespace).Create(ctx, newTLSSecret, metav1.CreateOptions{})
} }
@ -876,10 +882,10 @@ func (c *impersonatorConfigController) loadTLSCertFromSecret(tlsSecret *v1.Secre
return fmt.Errorf("could not parse TLS cert PEM data from Secret: %w", err) return fmt.Errorf("could not parse TLS cert PEM data from Secret: %w", err)
} }
plog.Info("Loading TLS certificates for impersonation proxy", c.infoLog.Info("loading TLS certificates for impersonation proxy",
"certPEM", string(certPEM), "certPEM", string(certPEM),
"secret", c.tlsSecretName, "secret", klog.KObj(tlsSecret),
"namespace", c.namespace) )
return nil return nil
} }
@ -892,9 +898,9 @@ func (c *impersonatorConfigController) ensureTLSSecretIsRemoved(ctx context.Cont
if !tlsSecretExists { if !tlsSecretExists {
return nil return nil
} }
plog.Info("Deleting TLS certificates for impersonation proxy", c.infoLog.Info("deleting TLS certificates for impersonation proxy",
"secret", c.tlsSecretName, "secret", klog.KRef(c.namespace, c.tlsSecretName),
"namespace", c.namespace) )
err = c.k8sClient.CoreV1().Secrets(c.namespace).Delete(ctx, c.tlsSecretName, metav1.DeleteOptions{}) err = c.k8sClient.CoreV1().Secrets(c.namespace).Delete(ctx, c.tlsSecretName, metav1.DeleteOptions{})
notFound := k8serrors.IsNotFound(err) notFound := k8serrors.IsNotFound(err)
if notFound { if notFound {
@ -930,16 +936,16 @@ func (c *impersonatorConfigController) loadSignerCA(status v1alpha1.StrategyStat
return fmt.Errorf("could not load the impersonator's credential signing secret: %w", err) return fmt.Errorf("could not load the impersonator's credential signing secret: %w", err)
} }
plog.Info("Loading credential signing certificate for impersonation proxy", c.infoLog.Info("loading credential signing certificate for impersonation proxy",
"certPEM", string(certPEM), "certPEM", string(certPEM),
"fromSecret", c.impersonationSignerSecretName, "secret", klog.KObj(signingCertSecret),
"namespace", c.namespace) )
return nil return nil
} }
func (c *impersonatorConfigController) clearSignerCA() { func (c *impersonatorConfigController) clearSignerCA() {
plog.Info("Clearing credential signing certificate for impersonation proxy") c.infoLog.Info("clearing credential signing certificate for impersonation proxy")
c.impersonationSigningCertProvider.UnsetCertKeyContent() c.impersonationSigningCertProvider.UnsetCertKeyContent()
} }

View File

@ -42,6 +42,7 @@ import (
"go.pinniped.dev/internal/dynamiccert" "go.pinniped.dev/internal/dynamiccert"
"go.pinniped.dev/internal/kubeclient" "go.pinniped.dev/internal/kubeclient"
"go.pinniped.dev/internal/testutil" "go.pinniped.dev/internal/testutil"
"go.pinniped.dev/internal/testutil/testlogger"
) )
func TestImpersonatorConfigControllerOptions(t *testing.T) { func TestImpersonatorConfigControllerOptions(t *testing.T) {
@ -60,6 +61,7 @@ func TestImpersonatorConfigControllerOptions(t *testing.T) {
var credIssuerInformerFilter controllerlib.Filter var credIssuerInformerFilter controllerlib.Filter
var servicesInformerFilter controllerlib.Filter var servicesInformerFilter controllerlib.Filter
var secretsInformerFilter controllerlib.Filter var secretsInformerFilter controllerlib.Filter
var testLog *testlogger.Logger
it.Before(func() { it.Before(func() {
r = require.New(t) r = require.New(t)
@ -70,6 +72,7 @@ func TestImpersonatorConfigControllerOptions(t *testing.T) {
credIssuerInformer := pinnipedInformerFactory.Config().V1alpha1().CredentialIssuers() credIssuerInformer := pinnipedInformerFactory.Config().V1alpha1().CredentialIssuers()
servicesInformer := sharedInformerFactory.Core().V1().Services() servicesInformer := sharedInformerFactory.Core().V1().Services()
secretsInformer := sharedInformerFactory.Core().V1().Secrets() secretsInformer := sharedInformerFactory.Core().V1().Secrets()
testLog = testlogger.New(t)
_ = NewImpersonatorConfigController( _ = NewImpersonatorConfigController(
installedInNamespace, installedInNamespace,
@ -90,6 +93,7 @@ func TestImpersonatorConfigControllerOptions(t *testing.T) {
nil, nil,
caSignerName, caSignerName,
nil, nil,
testLog,
) )
credIssuerInformerFilter = observableWithInformerOption.GetFilterForInformer(credIssuerInformer) credIssuerInformerFilter = observableWithInformerOption.GetFilterForInformer(credIssuerInformer)
servicesInformerFilter = observableWithInformerOption.GetFilterForInformer(servicesInformer) servicesInformerFilter = observableWithInformerOption.GetFilterForInformer(servicesInformer)
@ -288,6 +292,7 @@ func TestImpersonatorConfigControllerSync(t *testing.T) {
var testHTTPServerInterruptCh chan struct{} var testHTTPServerInterruptCh chan struct{}
var queue *testQueue var queue *testQueue
var validClientCert *tls.Certificate var validClientCert *tls.Certificate
var testLog *testlogger.Logger
var impersonatorFunc = func( var impersonatorFunc = func(
port int, port int,
@ -536,6 +541,7 @@ func TestImpersonatorConfigControllerSync(t *testing.T) {
impersonatorFunc, impersonatorFunc,
caSignerName, caSignerName,
signingCertProvider, signingCertProvider,
testLog,
) )
// Set this at the last second to support calling subject.Name(). // Set this at the last second to support calling subject.Name().
@ -1038,6 +1044,7 @@ func TestImpersonatorConfigControllerSync(t *testing.T) {
signingCASecret = newSigningKeySecret(caSignerName, signingCACertPEM, signingCAKeyPEM) signingCASecret = newSigningKeySecret(caSignerName, signingCACertPEM, signingCAKeyPEM)
validClientCert, err = ca.IssueClientCert("username", nil, time.Hour) validClientCert, err = ca.IssueClientCert("username", nil, time.Hour)
r.NoError(err) r.NoError(err)
testLog = testlogger.New(t)
}) })
it.After(func() { it.After(func() {

View File

@ -269,6 +269,7 @@ func PrepareControllers(c *Config) (func(ctx context.Context), error) {
impersonator.New, impersonator.New,
c.NamesConfig.ImpersonationSignerSecret, c.NamesConfig.ImpersonationSignerSecret,
c.ImpersonationSigningCertProvider, c.ImpersonationSigningCertProvider,
klogr.New(),
), ),
singletonWorker, singletonWorker,
). ).