From 15a5332428ec8881b2419e9f1e9190bcdceaf18e Mon Sep 17 00:00:00 2001 From: Monis Khan Date: Tue, 10 Nov 2020 10:22:16 -0500 Subject: [PATCH] Reduce log spam Signed-off-by: Monis Khan --- cmd/local-user-authenticator/main.go | 45 ++++++++++--------- cmd/pinniped-supervisor/main.go | 12 ++--- internal/concierge/apiserver/apiserver.go | 4 +- .../kube_config_info_publisher.go | 7 +-- .../controller/kubecertagent/annotater.go | 3 +- internal/controller/kubecertagent/creater.go | 3 +- internal/controller/kubecertagent/deleter.go | 3 +- .../controller/kubecertagent/kubecertagent.go | 6 +-- .../supervisorconfig/jwks_observer.go | 8 ++-- .../supervisorconfig/jwks_writer.go | 27 +++++------ .../oidcproviderconfig_watcher.go | 6 +-- .../supervisorconfig/tls_cert_observer.go | 10 ++--- internal/controllerlib/controller.go | 10 +++-- internal/controllerlib/manager.go | 4 +- internal/oidc/provider/manager/manager.go | 7 ++- 15 files changed, 81 insertions(+), 74 deletions(-) diff --git a/cmd/local-user-authenticator/main.go b/cmd/local-user-authenticator/main.go index c88dbf3c..c4dd9db8 100644 --- a/cmd/local-user-authenticator/main.go +++ b/cmd/local-user-authenticator/main.go @@ -38,6 +38,7 @@ import ( "go.pinniped.dev/internal/controller/apicerts" "go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/dynamiccert" + "go.pinniped.dev/internal/plog" ) const ( @@ -92,11 +93,11 @@ func (w *webhook) start(ctx context.Context, l net.Listener) error { go func() { select { case err := <-errCh: - klog.InfoS("server exited", "err", err) + plog.Debug("server exited", "err", err) case <-ctx.Done(): - klog.InfoS("server context cancelled", "err", ctx.Err()) + plog.Debug("server context cancelled", "err", ctx.Err()) if err := server.Shutdown(context.Background()); err != nil { - klog.InfoS("server shutdown failed", "err", err) + plog.Debug("server shutdown failed", "err", err) } } }() @@ -114,13 +115,13 @@ func (w *webhook) ServeHTTP(rsp http.ResponseWriter, req *http.Request) { secret, err := w.secretInformer.Lister().Secrets(namespace).Get(username) notFound := k8serrors.IsNotFound(err) if err != nil && !notFound { - klog.InfoS("could not get secret", "err", err) + plog.Debug("could not get secret", "err", err) rsp.WriteHeader(http.StatusInternalServerError) return } if notFound { - klog.InfoS("user not found") + plog.Debug("user not found") respondWithUnauthenticated(rsp) return } @@ -130,7 +131,7 @@ func (w *webhook) ServeHTTP(rsp http.ResponseWriter, req *http.Request) { []byte(password), ) == nil if !passwordMatches { - klog.InfoS("authentication failed: wrong password") + plog.Debug("authentication failed: wrong password") respondWithUnauthenticated(rsp) return } @@ -141,32 +142,32 @@ func (w *webhook) ServeHTTP(rsp http.ResponseWriter, req *http.Request) { groupsCSVReader := csv.NewReader(groupsBuf) groups, err = groupsCSVReader.Read() if err != nil { - klog.InfoS("could not read groups", "err", err) + plog.Debug("could not read groups", "err", err) rsp.WriteHeader(http.StatusInternalServerError) return } trimLeadingAndTrailingWhitespace(groups) } - klog.InfoS("successful authentication") + plog.Debug("successful authentication") respondWithAuthenticated(rsp, secret.ObjectMeta.Name, string(secret.UID), groups) } func getUsernameAndPasswordFromRequest(rsp http.ResponseWriter, req *http.Request) (string, string, error) { if req.URL.Path != "/authenticate" { - klog.InfoS("received request path other than /authenticate", "path", req.URL.Path) + plog.Debug("received request path other than /authenticate", "path", req.URL.Path) rsp.WriteHeader(http.StatusNotFound) return "", "", invalidRequest } if req.Method != http.MethodPost { - klog.InfoS("received request method other than post", "method", req.Method) + plog.Debug("received request method other than post", "method", req.Method) rsp.WriteHeader(http.StatusMethodNotAllowed) return "", "", invalidRequest } if !headerContains(req, "Content-Type", "application/json") { - klog.InfoS("content type is not application/json", "Content-Type", req.Header.Values("Content-Type")) + plog.Debug("content type is not application/json", "Content-Type", req.Header.Values("Content-Type")) rsp.WriteHeader(http.StatusUnsupportedMediaType) return "", "", invalidRequest } @@ -174,39 +175,39 @@ func getUsernameAndPasswordFromRequest(rsp http.ResponseWriter, req *http.Reques if !headerContains(req, "Accept", "application/json") && !headerContains(req, "Accept", "application/*") && !headerContains(req, "Accept", "*/*") { - klog.InfoS("client does not accept application/json", "Accept", req.Header.Values("Accept")) + plog.Debug("client does not accept application/json", "Accept", req.Header.Values("Accept")) rsp.WriteHeader(http.StatusUnsupportedMediaType) return "", "", invalidRequest } if req.Body == nil { - klog.InfoS("invalid nil body") + plog.Debug("invalid nil body") rsp.WriteHeader(http.StatusBadRequest) return "", "", invalidRequest } var body authenticationv1beta1.TokenReview if err := json.NewDecoder(req.Body).Decode(&body); err != nil { - klog.InfoS("failed to decode body", "err", err) + plog.Debug("failed to decode body", "err", err) rsp.WriteHeader(http.StatusBadRequest) return "", "", invalidRequest } if body.APIVersion != authenticationv1beta1.SchemeGroupVersion.String() { - klog.InfoS("invalid TokenReview apiVersion", "apiVersion", body.APIVersion) + plog.Debug("invalid TokenReview apiVersion", "apiVersion", body.APIVersion) rsp.WriteHeader(http.StatusBadRequest) return "", "", invalidRequest } if body.Kind != "TokenReview" { - klog.InfoS("invalid TokenReview kind", "kind", body.Kind) + plog.Debug("invalid TokenReview kind", "kind", body.Kind) rsp.WriteHeader(http.StatusBadRequest) return "", "", invalidRequest } tokenSegments := strings.SplitN(body.Spec.Token, ":", 2) if len(tokenSegments) != 2 { - klog.InfoS("bad token format in request") + plog.Debug("bad token format in request") rsp.WriteHeader(http.StatusBadRequest) return "", "", invalidRequest } @@ -247,7 +248,7 @@ func respondWithUnauthenticated(rsp http.ResponseWriter) { }, } if err := json.NewEncoder(rsp).Encode(body); err != nil { - klog.InfoS("could not encode response", "err", err) + plog.Debug("could not encode response", "err", err) rsp.WriteHeader(http.StatusInternalServerError) } } @@ -273,7 +274,7 @@ func respondWithAuthenticated( }, } if err := json.NewEncoder(rsp).Encode(body); err != nil { - klog.InfoS("could not encode response", "err", err) + plog.Debug("could not encode response", "err", err) rsp.WriteHeader(http.StatusInternalServerError) } } @@ -372,7 +373,7 @@ func run() error { dynamicCertProvider := dynamiccert.New() startControllers(ctx, dynamicCertProvider, kubeClient, kubeInformers) - klog.InfoS("controllers are ready") + plog.Debug("controllers are ready") //nolint: gosec // Intentionally binding to all network interfaces. l, err := net.Listen("tcp", ":8443") @@ -385,10 +386,10 @@ func run() error { if err != nil { return fmt.Errorf("cannot start webhook: %w", err) } - klog.InfoS("webhook is ready", "address", l.Addr().String()) + plog.Debug("webhook is ready", "address", l.Addr().String()) gotSignal := waitForSignal() - klog.InfoS("webhook exiting", "signal", gotSignal) + plog.Debug("webhook exiting", "signal", gotSignal) return nil } diff --git a/cmd/pinniped-supervisor/main.go b/cmd/pinniped-supervisor/main.go index 1ed2ac18..9b82948b 100644 --- a/cmd/pinniped-supervisor/main.go +++ b/cmd/pinniped-supervisor/main.go @@ -51,11 +51,11 @@ func start(ctx context.Context, l net.Listener, handler http.Handler) { go func() { select { case err := <-errCh: - klog.InfoS("server exited", "err", err) + plog.Debug("server exited", "err", err) case <-ctx.Done(): - klog.InfoS("server context cancelled", "err", ctx.Err()) + plog.Debug("server context cancelled", "err", ctx.Err()) if err := server.Shutdown(context.Background()); err != nil { - klog.InfoS("server shutdown failed", "err", err) + plog.Debug("server shutdown failed", "err", err) } } }() @@ -212,7 +212,7 @@ func run(serverInstallationNamespace string, cfg *supervisor.Config) error { GetCertificate: func(info *tls.ClientHelloInfo) (*tls.Certificate, error) { cert := dynamicTLSCertProvider.GetTLSCert(strings.ToLower(info.ServerName)) defaultCert := dynamicTLSCertProvider.GetDefaultTLSCert() - klog.InfoS("GetCertificate called for port 8443", + plog.Debug("GetCertificate called for port 8443", "info.ServerName", info.ServerName, "foundSNICert", cert != nil, "foundDefaultCert", defaultCert != nil, @@ -229,13 +229,13 @@ func run(serverInstallationNamespace string, cfg *supervisor.Config) error { defer func() { _ = httpsListener.Close() }() start(ctx, httpsListener, oidProvidersManager) - klog.InfoS("supervisor is ready", + plog.Debug("supervisor is ready", "httpAddress", httpListener.Addr().String(), "httpsAddress", httpsListener.Addr().String(), ) gotSignal := waitForSignal() - klog.InfoS("supervisor exiting", "signal", gotSignal) + plog.Debug("supervisor exiting", "signal", gotSignal) return nil } diff --git a/internal/concierge/apiserver/apiserver.go b/internal/concierge/apiserver/apiserver.go index 0af3e963..133efe7d 100644 --- a/internal/concierge/apiserver/apiserver.go +++ b/internal/concierge/apiserver/apiserver.go @@ -15,10 +15,10 @@ import ( "k8s.io/apiserver/pkg/registry/rest" genericapiserver "k8s.io/apiserver/pkg/server" "k8s.io/client-go/pkg/version" - "k8s.io/klog/v2" loginapi "go.pinniped.dev/generated/1.19/apis/concierge/login" loginv1alpha1 "go.pinniped.dev/generated/1.19/apis/concierge/login/v1alpha1" + "go.pinniped.dev/internal/plog" "go.pinniped.dev/internal/registry/credentialrequest" ) @@ -111,7 +111,7 @@ func (c completedConfig) New() (*PinnipedServer, error) { s.GenericAPIServer.AddPostStartHookOrDie("start-controllers", func(postStartContext genericapiserver.PostStartHookContext) error { - klog.InfoS("start-controllers post start hook starting") + plog.Debug("start-controllers post start hook starting") ctx, cancel := context.WithCancel(context.Background()) go func() { diff --git a/internal/controller/issuerconfig/kube_config_info_publisher.go b/internal/controller/issuerconfig/kube_config_info_publisher.go index 90056432..cdfe408e 100644 --- a/internal/controller/issuerconfig/kube_config_info_publisher.go +++ b/internal/controller/issuerconfig/kube_config_info_publisher.go @@ -16,6 +16,7 @@ import ( pinnipedclientset "go.pinniped.dev/generated/1.19/client/concierge/clientset/versioned" pinnipedcontroller "go.pinniped.dev/internal/controller" "go.pinniped.dev/internal/controllerlib" + "go.pinniped.dev/internal/plog" ) const ( @@ -75,7 +76,7 @@ func (c *kubeConigInfoPublisherController) Sync(ctx controllerlib.Context) error return fmt.Errorf("failed to get %s configmap: %w", clusterInfoName, err) } if notFound { - klog.InfoS( + plog.Debug( "could not find config map", "configmap", klog.KRef(ClusterInfoNamespace, clusterInfoName), @@ -85,13 +86,13 @@ func (c *kubeConigInfoPublisherController) Sync(ctx controllerlib.Context) error kubeConfig, kubeConfigPresent := configMap.Data[clusterInfoConfigMapKey] if !kubeConfigPresent { - klog.InfoS("could not find kubeconfig configmap key") + plog.Debug("could not find kubeconfig configmap key") return nil } config, err := clientcmd.Load([]byte(kubeConfig)) if err != nil { - klog.InfoS("could not load kubeconfig configmap key") + plog.Debug("could not load kubeconfig configmap key") return nil } diff --git a/internal/controller/kubecertagent/annotater.go b/internal/controller/kubecertagent/annotater.go index eb951d63..d5700f4e 100644 --- a/internal/controller/kubecertagent/annotater.go +++ b/internal/controller/kubecertagent/annotater.go @@ -19,6 +19,7 @@ import ( pinnipedclientset "go.pinniped.dev/generated/1.19/client/concierge/clientset/versioned" pinnipedcontroller "go.pinniped.dev/internal/controller" "go.pinniped.dev/internal/controllerlib" + "go.pinniped.dev/internal/plog" ) // These constants are the default values for the kube-controller-manager flags. If the flags are @@ -177,7 +178,7 @@ func (c *annotaterController) reallyUpdateAgentPod( updatedAgentPod.Annotations[agentPodCertPathAnnotationKey] = certPath updatedAgentPod.Annotations[agentPodKeyPathAnnotationKey] = keyPath - klog.InfoS( + plog.Debug( "updating agent pod annotations", "pod", klog.KObj(updatedAgentPod), diff --git a/internal/controller/kubecertagent/creater.go b/internal/controller/kubecertagent/creater.go index c917a39e..e7844833 100644 --- a/internal/controller/kubecertagent/creater.go +++ b/internal/controller/kubecertagent/creater.go @@ -18,6 +18,7 @@ import ( "go.pinniped.dev/internal/constable" pinnipedcontroller "go.pinniped.dev/internal/controller" "go.pinniped.dev/internal/controllerlib" + "go.pinniped.dev/internal/plog" ) type createrController struct { @@ -118,7 +119,7 @@ func (c *createrController) Sync(ctx controllerlib.Context) error { if agentPod == nil { agentPod = c.agentPodConfig.newAgentPod(controllerManagerPod) - klog.InfoS( + plog.Debug( "creating agent pod", "pod", klog.KObj(agentPod), diff --git a/internal/controller/kubecertagent/deleter.go b/internal/controller/kubecertagent/deleter.go index 3953449f..dfb66aed 100644 --- a/internal/controller/kubecertagent/deleter.go +++ b/internal/controller/kubecertagent/deleter.go @@ -13,6 +13,7 @@ import ( pinnipedcontroller "go.pinniped.dev/internal/controller" "go.pinniped.dev/internal/controllerlib" + "go.pinniped.dev/internal/plog" ) type deleterController struct { @@ -71,7 +72,7 @@ func (c *deleterController) Sync(ctx controllerlib.Context) error { } if controllerManagerPod == nil || !isAgentPodUpToDate(agentPod, c.agentPodConfig.newAgentPod(controllerManagerPod)) { - klog.InfoS("deleting agent pod", "pod", klog.KObj(agentPod)) + plog.Debug("deleting agent pod", "pod", klog.KObj(agentPod)) err := c.k8sClient. CoreV1(). Pods(agentPod.Namespace). diff --git a/internal/controller/kubecertagent/kubecertagent.go b/internal/controller/kubecertagent/kubecertagent.go index 17a0dcf6..8442c941 100644 --- a/internal/controller/kubecertagent/kubecertagent.go +++ b/internal/controller/kubecertagent/kubecertagent.go @@ -23,11 +23,11 @@ import ( "k8s.io/apimachinery/pkg/labels" "k8s.io/apimachinery/pkg/util/clock" corev1informers "k8s.io/client-go/informers/core/v1" - "k8s.io/klog/v2" configv1alpha1 "go.pinniped.dev/generated/1.19/apis/concierge/config/v1alpha1" pinnipedclientset "go.pinniped.dev/generated/1.19/client/concierge/clientset/versioned" "go.pinniped.dev/internal/controller/issuerconfig" + "go.pinniped.dev/internal/plog" ) const ( @@ -257,13 +257,13 @@ func findControllerManagerPodForSpecificAgentPod( ) (*corev1.Pod, error) { name, ok := agentPod.Annotations[controllerManagerNameAnnotationKey] if !ok { - klog.InfoS("agent pod missing parent name annotation", "pod", agentPod.Name) + plog.Debug("agent pod missing parent name annotation", "pod", agentPod.Name) return nil, nil } uid, ok := agentPod.Annotations[controllerManagerUIDAnnotationKey] if !ok { - klog.InfoS("agent pod missing parent uid annotation", "pod", agentPod.Name) + plog.Debug("agent pod missing parent uid annotation", "pod", agentPod.Name) return nil, nil } diff --git a/internal/controller/supervisorconfig/jwks_observer.go b/internal/controller/supervisorconfig/jwks_observer.go index ba99fc7b..0d6df5b6 100644 --- a/internal/controller/supervisorconfig/jwks_observer.go +++ b/internal/controller/supervisorconfig/jwks_observer.go @@ -10,11 +10,11 @@ import ( "gopkg.in/square/go-jose.v2" "k8s.io/apimachinery/pkg/labels" corev1informers "k8s.io/client-go/informers/core/v1" - "k8s.io/klog/v2" "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1" pinnipedcontroller "go.pinniped.dev/internal/controller" "go.pinniped.dev/internal/controllerlib" + "go.pinniped.dev/internal/plog" ) type jwksObserverController struct { @@ -75,19 +75,19 @@ func (c *jwksObserverController) Sync(ctx controllerlib.Context) error { secretRef := provider.Status.JWKSSecret jwksSecret, err := c.secretInformer.Lister().Secrets(ns).Get(secretRef.Name) if err != nil { - klog.InfoS("jwksObserverController Sync could not find JWKS secret", "namespace", ns, "secretName", secretRef.Name) + plog.Debug("jwksObserverController Sync could not find JWKS secret", "namespace", ns, "secretName", secretRef.Name) continue } jwkFromSecret := jose.JSONWebKeySet{} err = json.Unmarshal(jwksSecret.Data[jwksKey], &jwkFromSecret) if err != nil { - klog.InfoS("jwksObserverController Sync found a JWKS secret with Data in an unexpected format", "namespace", ns, "secretName", secretRef.Name) + plog.Debug("jwksObserverController Sync found a JWKS secret with Data in an unexpected format", "namespace", ns, "secretName", secretRef.Name) continue } issuerToJWKSMap[provider.Spec.Issuer] = &jwkFromSecret } - klog.InfoS("jwksObserverController Sync updated the JWKS cache", "issuerCount", len(issuerToJWKSMap)) + plog.Debug("jwksObserverController Sync updated the JWKS cache", "issuerCount", len(issuerToJWKSMap)) c.issuerToJWKSSetter.SetIssuerToJWKSMap(issuerToJWKSMap) return nil diff --git a/internal/controller/supervisorconfig/jwks_writer.go b/internal/controller/supervisorconfig/jwks_writer.go index 16833a0a..4e6a51a1 100644 --- a/internal/controller/supervisorconfig/jwks_writer.go +++ b/internal/controller/supervisorconfig/jwks_writer.go @@ -27,6 +27,7 @@ import ( configinformers "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1" pinnipedcontroller "go.pinniped.dev/internal/controller" "go.pinniped.dev/internal/controllerlib" + "go.pinniped.dev/internal/plog" ) // These constants are the keys in an OPC's Secret's Data map. @@ -132,7 +133,7 @@ func (c *jwksWriterController) Sync(ctx controllerlib.Context) error { if notFound { // The corresponding secret to this OPC should have been garbage collected since it should have // had this OPC as its owner. - klog.InfoS( + plog.Debug( "oidcprovider deleted", "oidcprovider", klog.KRef(ctx.Key.Namespace, ctx.Key.Name), @@ -146,7 +147,7 @@ func (c *jwksWriterController) Sync(ctx controllerlib.Context) error { } if !secretNeedsUpdate { // Secret is up to date - we are good to go. - klog.InfoS( + plog.Debug( "secret is up to date", "oidcprovider", klog.KRef(ctx.Key.Namespace, ctx.Key.Name), @@ -164,7 +165,7 @@ func (c *jwksWriterController) Sync(ctx controllerlib.Context) error { if err := c.createOrUpdateSecret(ctx.Context, secret); err != nil { return fmt.Errorf("cannot create or update secret: %w", err) } - klog.InfoS("created/updated secret", "secret", klog.KObj(secret)) + plog.Debug("created/updated secret", "secret", klog.KObj(secret)) // Ensure that the OPC points to the secret. newOPC := opc.DeepCopy() @@ -172,7 +173,7 @@ func (c *jwksWriterController) Sync(ctx controllerlib.Context) error { if err := c.updateOPC(ctx.Context, newOPC); err != nil { return fmt.Errorf("cannot update opc: %w", err) } - klog.InfoS("updated oidcprovider", "oidcprovider", klog.KObj(newOPC)) + plog.Debug("updated oidcprovider", "oidcprovider", klog.KObj(newOPC)) return nil } @@ -323,45 +324,45 @@ func isOPCControllee(obj metav1.Object) bool { func isValid(secret *corev1.Secret) bool { jwkData, ok := secret.Data[activeJWKKey] if !ok { - klog.InfoS("secret does not contain active jwk") + plog.Debug("secret does not contain active jwk") return false } var activeJWK jose.JSONWebKey if err := json.Unmarshal(jwkData, &activeJWK); err != nil { - klog.InfoS("cannot unmarshal active jwk", "err", err) + plog.Debug("cannot unmarshal active jwk", "err", err) return false } if activeJWK.IsPublic() { - klog.InfoS("active jwk is public", "keyid", activeJWK.KeyID) + plog.Debug("active jwk is public", "keyid", activeJWK.KeyID) return false } if !activeJWK.Valid() { - klog.InfoS("active jwk is not valid", "keyid", activeJWK.KeyID) + plog.Debug("active jwk is not valid", "keyid", activeJWK.KeyID) return false } jwksData, ok := secret.Data[jwksKey] if !ok { - klog.InfoS("secret does not contain valid jwks") + plog.Debug("secret does not contain valid jwks") } var validJWKS jose.JSONWebKeySet if err := json.Unmarshal(jwksData, &validJWKS); err != nil { - klog.InfoS("cannot unmarshal valid jwks", "err", err) + plog.Debug("cannot unmarshal valid jwks", "err", err) return false } foundActiveJWK := false for _, validJWK := range validJWKS.Keys { if !validJWK.IsPublic() { - klog.InfoS("jwks key is not public", "keyid", validJWK.KeyID) + plog.Debug("jwks key is not public", "keyid", validJWK.KeyID) return false } if !validJWK.Valid() { - klog.InfoS("jwks key is not valid", "keyid", validJWK.KeyID) + plog.Debug("jwks key is not valid", "keyid", validJWK.KeyID) return false } if validJWK.KeyID == activeJWK.KeyID { @@ -370,7 +371,7 @@ func isValid(secret *corev1.Secret) bool { } if !foundActiveJWK { - klog.InfoS("did not find active jwk in valid jwks", "keyid", activeJWK.KeyID) + plog.Debug("did not find active jwk in valid jwks", "keyid", activeJWK.KeyID) return false } diff --git a/internal/controller/supervisorconfig/oidcproviderconfig_watcher.go b/internal/controller/supervisorconfig/oidcproviderconfig_watcher.go index 77e6b12b..a80ed0c3 100644 --- a/internal/controller/supervisorconfig/oidcproviderconfig_watcher.go +++ b/internal/controller/supervisorconfig/oidcproviderconfig_watcher.go @@ -9,8 +9,6 @@ import ( "net/url" "strings" - "go.pinniped.dev/internal/multierror" - metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/labels" "k8s.io/apimachinery/pkg/util/clock" @@ -22,7 +20,9 @@ import ( configinformers "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1" pinnipedcontroller "go.pinniped.dev/internal/controller" "go.pinniped.dev/internal/controllerlib" + "go.pinniped.dev/internal/multierror" "go.pinniped.dev/internal/oidc/provider" + "go.pinniped.dev/internal/plog" ) // ProvidersSetter can be notified of all known valid providers with its SetIssuer function. @@ -191,7 +191,7 @@ func (c *oidcProviderWatcherController) updateStatus( return nil } - klog.InfoS( + plog.Debug( "attempting status update", "openidproviderconfig", klog.KRef(namespace, name), diff --git a/internal/controller/supervisorconfig/tls_cert_observer.go b/internal/controller/supervisorconfig/tls_cert_observer.go index 9caeb747..d50ca780 100644 --- a/internal/controller/supervisorconfig/tls_cert_observer.go +++ b/internal/controller/supervisorconfig/tls_cert_observer.go @@ -11,11 +11,11 @@ import ( "k8s.io/apimachinery/pkg/labels" corev1informers "k8s.io/client-go/informers/core/v1" - "k8s.io/klog/v2" "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1" pinnipedcontroller "go.pinniped.dev/internal/controller" "go.pinniped.dev/internal/controllerlib" + "go.pinniped.dev/internal/plog" ) type tlsCertObserverController struct { @@ -78,7 +78,7 @@ func (c *tlsCertObserverController) Sync(ctx controllerlib.Context) error { } issuerURL, err := url.Parse(provider.Spec.Issuer) if err != nil { - klog.InfoS("tlsCertObserverController Sync found an invalid issuer URL", "namespace", ns, "issuer", provider.Spec.Issuer) + plog.Debug("tlsCertObserverController Sync found an invalid issuer URL", "namespace", ns, "issuer", provider.Spec.Issuer) continue } certFromSecret, err := c.certFromSecret(ns, secretName) @@ -89,7 +89,7 @@ func (c *tlsCertObserverController) Sync(ctx controllerlib.Context) error { issuerHostToTLSCertMap[lowercaseHostWithoutPort(issuerURL)] = certFromSecret } - klog.InfoS("tlsCertObserverController Sync updated the TLS cert cache", "issuerHostCount", len(issuerHostToTLSCertMap)) + plog.Debug("tlsCertObserverController Sync updated the TLS cert cache", "issuerHostCount", len(issuerHostToTLSCertMap)) c.issuerTLSCertSetter.SetIssuerHostToTLSCertMap(issuerHostToTLSCertMap) defaultCert, err := c.certFromSecret(ns, c.defaultTLSCertificateSecretName) @@ -105,12 +105,12 @@ func (c *tlsCertObserverController) Sync(ctx controllerlib.Context) error { func (c *tlsCertObserverController) certFromSecret(ns string, secretName string) (*tls.Certificate, error) { tlsSecret, err := c.secretInformer.Lister().Secrets(ns).Get(secretName) if err != nil { - klog.InfoS("tlsCertObserverController Sync could not find TLS cert secret", "namespace", ns, "secretName", secretName) + plog.Debug("tlsCertObserverController Sync could not find TLS cert secret", "namespace", ns, "secretName", secretName) return nil, err } certFromSecret, err := tls.X509KeyPair(tlsSecret.Data["tls.crt"], tlsSecret.Data["tls.key"]) if err != nil { - klog.InfoS("tlsCertObserverController Sync found a TLS secret with Data in an unexpected format", "namespace", ns, "secretName", secretName) + plog.Debug("tlsCertObserverController Sync found a TLS secret with Data in an unexpected format", "namespace", ns, "secretName", secretName) return nil, err } return &certFromSecret, nil diff --git a/internal/controllerlib/controller.go b/internal/controllerlib/controller.go index 39b61075..4d3940a7 100644 --- a/internal/controllerlib/controller.go +++ b/internal/controllerlib/controller.go @@ -16,6 +16,8 @@ import ( "k8s.io/client-go/tools/events" "k8s.io/client-go/util/workqueue" "k8s.io/klog/v2" + + "go.pinniped.dev/internal/plog" ) // Controller interface represents a runnable Kubernetes controller. @@ -87,7 +89,7 @@ type controller struct { func (c *controller) Run(ctx context.Context, workers int) { defer utilruntime.HandleCrash(crash) // prevent panics from killing the process - klog.InfoS("starting controller", "controller", c.Name(), "workers", workers) + plog.Debug("starting controller", "controller", c.Name(), "workers", workers) c.invokeAllRunOpts() @@ -108,17 +110,17 @@ func (c *controller) Run(ctx context.Context, workers int) { // at this point the Run() can hang and callers have to implement the logic that will kill // this controller (SIGKILL). workerWg.Wait() - klog.InfoS("all workers have been terminated, shutting down", "controller", c.Name(), "workers", workers) + plog.Debug("all workers have been terminated, shutting down", "controller", c.Name(), "workers", workers) }() for i := 1; i <= workers; i++ { idx := i - klog.InfoS("starting worker", "controller", c.Name(), "worker", idx) + plog.Debug("starting worker", "controller", c.Name(), "worker", idx) workerWg.Add(1) go func() { defer utilruntime.HandleCrash(crash) // prevent panics from killing the process defer func() { - klog.InfoS("shutting down worker", "controller", c.Name(), "worker", idx) + plog.Debug("shutting down worker", "controller", c.Name(), "worker", idx) workerWg.Done() }() c.runWorker(workerContext) diff --git a/internal/controllerlib/manager.go b/internal/controllerlib/manager.go index f78dad17..d0babbbe 100644 --- a/internal/controllerlib/manager.go +++ b/internal/controllerlib/manager.go @@ -7,7 +7,7 @@ import ( "context" "sync" - "k8s.io/klog/v2" + "go.pinniped.dev/internal/plog" ) type Manager interface { @@ -48,7 +48,7 @@ func (c *controllerManager) Start(ctx context.Context) { idx := i go func() { r := c.controllers[idx] - defer klog.InfoS("controller terminated", "controller", r.controller.Name()) + defer plog.Debug("controller terminated", "controller", r.controller.Name()) defer wg.Done() r.controller.Run(ctx, r.workers) }() diff --git a/internal/oidc/provider/manager/manager.go b/internal/oidc/provider/manager/manager.go index 46a5f071..52be1e6b 100644 --- a/internal/oidc/provider/manager/manager.go +++ b/internal/oidc/provider/manager/manager.go @@ -8,12 +8,11 @@ import ( "strings" "sync" - "k8s.io/klog/v2" - "go.pinniped.dev/internal/oidc" "go.pinniped.dev/internal/oidc/discovery" "go.pinniped.dev/internal/oidc/jwks" "go.pinniped.dev/internal/oidc/provider" + "go.pinniped.dev/internal/plog" ) // Manager can manage multiple active OIDC providers. It acts as a request router for them. @@ -60,7 +59,7 @@ func (m *Manager) SetProviders(oidcProviders ...*provider.OIDCProvider) { jwksURL := strings.ToLower(incomingProvider.IssuerHost()) + "/" + incomingProvider.IssuerPath() + oidc.JWKSEndpointPath m.providerHandlers[jwksURL] = jwks.NewHandler(incomingProvider.Issuer(), m.dynamicJWKSProvider) - klog.InfoS("oidc provider manager added or updated issuer", "issuer", incomingProvider.Issuer()) + plog.Debug("oidc provider manager added or updated issuer", "issuer", incomingProvider.Issuer()) } } @@ -68,7 +67,7 @@ func (m *Manager) SetProviders(oidcProviders ...*provider.OIDCProvider) { func (m *Manager) ServeHTTP(resp http.ResponseWriter, req *http.Request) { requestHandler := m.findHandler(req) - klog.InfoS( + plog.Debug( "oidc provider manager examining request", "method", req.Method, "host", req.Host,