djpbessems/ContainerImage.Pinniped
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Reduce log spam

Browse Source 
Signed-off-by: Monis Khan <mok@vmware.com>
This commit is contained in:
Monis Khan 2020-11-10 10:22:16 -05:00
parent a5643e3738
commit 15a5332428
No known key found for this signature in database
GPG Key ID: 52C90ADA01B269B8
15 changed files with 81 additions and 74 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

45
cmd/local-user-authenticator/main.go
View File

@ -38,6 +38,7 @@ import (
"go.pinniped.dev/internal/controller/apicerts" "go.pinniped.dev/internal/controller/apicerts"
"go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/controllerlib"
"go.pinniped.dev/internal/dynamiccert" "go.pinniped.dev/internal/dynamiccert"
"go.pinniped.dev/internal/plog"
) )
const ( const (
@ -92,11 +93,11 @@ func (w *webhook) start(ctx context.Context, l net.Listener) error {
go func() { go func() {
select { select {
case err := <-errCh: case err := <-errCh:
klog.InfoS("server exited", "err", err) plog.Debug("server exited", "err", err)
case <-ctx.Done(): 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 { 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) secret, err := w.secretInformer.Lister().Secrets(namespace).Get(username)
notFound := k8serrors.IsNotFound(err) notFound := k8serrors.IsNotFound(err)
if err != nil && !notFound { if err != nil && !notFound {
klog.InfoS("could not get secret", "err", err) plog.Debug("could not get secret", "err", err)
rsp.WriteHeader(http.StatusInternalServerError) rsp.WriteHeader(http.StatusInternalServerError)
return return
} }
if notFound { if notFound {
klog.InfoS("user not found") plog.Debug("user not found")
respondWithUnauthenticated(rsp) respondWithUnauthenticated(rsp)
return return
} }
@ -130,7 +131,7 @@ func (w *webhook) ServeHTTP(rsp http.ResponseWriter, req *http.Request) {
[]byte(password), []byte(password),
) == nil ) == nil
if !passwordMatches { if !passwordMatches {
klog.InfoS("authentication failed: wrong password") plog.Debug("authentication failed: wrong password")
respondWithUnauthenticated(rsp) respondWithUnauthenticated(rsp)
return return
} }
@ -141,32 +142,32 @@ func (w *webhook) ServeHTTP(rsp http.ResponseWriter, req *http.Request) {
groupsCSVReader := csv.NewReader(groupsBuf) groupsCSVReader := csv.NewReader(groupsBuf)
groups, err = groupsCSVReader.Read() groups, err = groupsCSVReader.Read()
if err != nil { if err != nil {
klog.InfoS("could not read groups", "err", err) plog.Debug("could not read groups", "err", err)
rsp.WriteHeader(http.StatusInternalServerError) rsp.WriteHeader(http.StatusInternalServerError)
return return
} }
trimLeadingAndTrailingWhitespace(groups) trimLeadingAndTrailingWhitespace(groups)
} }
klog.InfoS("successful authentication") plog.Debug("successful authentication")
respondWithAuthenticated(rsp, secret.ObjectMeta.Name, string(secret.UID), groups) respondWithAuthenticated(rsp, secret.ObjectMeta.Name, string(secret.UID), groups)
} }
func getUsernameAndPasswordFromRequest(rsp http.ResponseWriter, req *http.Request) (string, string, error) { func getUsernameAndPasswordFromRequest(rsp http.ResponseWriter, req *http.Request) (string, string, error) {
if req.URL.Path != "/authenticate" { 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) rsp.WriteHeader(http.StatusNotFound)
return "", "", invalidRequest return "", "", invalidRequest
} }
if req.Method != http.MethodPost { 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) rsp.WriteHeader(http.StatusMethodNotAllowed)
return "", "", invalidRequest return "", "", invalidRequest
} }
if !headerContains(req, "Content-Type", "application/json") { 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) rsp.WriteHeader(http.StatusUnsupportedMediaType)
return "", "", invalidRequest return "", "", invalidRequest
} }
@ -174,39 +175,39 @@ func getUsernameAndPasswordFromRequest(rsp http.ResponseWriter, req *http.Reques
if !headerContains(req, "Accept", "application/json") && if !headerContains(req, "Accept", "application/json") &&
!headerContains(req, "Accept", "application/*") && !headerContains(req, "Accept", "application/*") &&
!headerContains(req, "Accept", "*/*") { !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) rsp.WriteHeader(http.StatusUnsupportedMediaType)
return "", "", invalidRequest return "", "", invalidRequest
} }
if req.Body == nil { if req.Body == nil {
klog.InfoS("invalid nil body") plog.Debug("invalid nil body")
rsp.WriteHeader(http.StatusBadRequest) rsp.WriteHeader(http.StatusBadRequest)
return "", "", invalidRequest return "", "", invalidRequest
} }
var body authenticationv1beta1.TokenReview var body authenticationv1beta1.TokenReview
if err := json.NewDecoder(req.Body).Decode(&body); err != nil { 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) rsp.WriteHeader(http.StatusBadRequest)
return "", "", invalidRequest return "", "", invalidRequest
} }
if body.APIVersion != authenticationv1beta1.SchemeGroupVersion.String() { 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) rsp.WriteHeader(http.StatusBadRequest)
return "", "", invalidRequest return "", "", invalidRequest
} }
if body.Kind != "TokenReview" { if body.Kind != "TokenReview" {
klog.InfoS("invalid TokenReview kind", "kind", body.Kind) plog.Debug("invalid TokenReview kind", "kind", body.Kind)
rsp.WriteHeader(http.StatusBadRequest) rsp.WriteHeader(http.StatusBadRequest)
return "", "", invalidRequest return "", "", invalidRequest
} }
tokenSegments := strings.SplitN(body.Spec.Token, ":", 2) tokenSegments := strings.SplitN(body.Spec.Token, ":", 2)
if len(tokenSegments) != 2 { if len(tokenSegments) != 2 {
klog.InfoS("bad token format in request") plog.Debug("bad token format in request")
rsp.WriteHeader(http.StatusBadRequest) rsp.WriteHeader(http.StatusBadRequest)
return "", "", invalidRequest return "", "", invalidRequest
} }
@ -247,7 +248,7 @@ func respondWithUnauthenticated(rsp http.ResponseWriter) {
}, },
} }
if err := json.NewEncoder(rsp).Encode(body); err != nil { 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) rsp.WriteHeader(http.StatusInternalServerError)
} }
} }
@ -273,7 +274,7 @@ func respondWithAuthenticated(
}, },
} }
if err := json.NewEncoder(rsp).Encode(body); err != nil { 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) rsp.WriteHeader(http.StatusInternalServerError)
} }
} }
@ -372,7 +373,7 @@ func run() error {
dynamicCertProvider := dynamiccert.New() dynamicCertProvider := dynamiccert.New()
startControllers(ctx, dynamicCertProvider, kubeClient, kubeInformers) startControllers(ctx, dynamicCertProvider, kubeClient, kubeInformers)
klog.InfoS("controllers are ready") plog.Debug("controllers are ready")
//nolint: gosec // Intentionally binding to all network interfaces. //nolint: gosec // Intentionally binding to all network interfaces.
l, err := net.Listen("tcp", ":8443") l, err := net.Listen("tcp", ":8443")
@ -385,10 +386,10 @@ func run() error {
if err != nil { if err != nil {
return fmt.Errorf("cannot start webhook: %w", err) 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() gotSignal := waitForSignal()
klog.InfoS("webhook exiting", "signal", gotSignal) plog.Debug("webhook exiting", "signal", gotSignal)
return nil return nil
} }

12
cmd/pinniped-supervisor/main.go
View File

@ -51,11 +51,11 @@ func start(ctx context.Context, l net.Listener, handler http.Handler) {
go func() { go func() {
select { select {
case err := <-errCh: case err := <-errCh:
klog.InfoS("server exited", "err", err) plog.Debug("server exited", "err", err)
case <-ctx.Done(): 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 { 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) { GetCertificate: func(info *tls.ClientHelloInfo) (*tls.Certificate, error) {
cert := dynamicTLSCertProvider.GetTLSCert(strings.ToLower(info.ServerName)) cert := dynamicTLSCertProvider.GetTLSCert(strings.ToLower(info.ServerName))
defaultCert := dynamicTLSCertProvider.GetDefaultTLSCert() defaultCert := dynamicTLSCertProvider.GetDefaultTLSCert()
klog.InfoS("GetCertificate called for port 8443", plog.Debug("GetCertificate called for port 8443",
"info.ServerName", info.ServerName, "info.ServerName", info.ServerName,
"foundSNICert", cert != nil, "foundSNICert", cert != nil,
"foundDefaultCert", defaultCert != nil, "foundDefaultCert", defaultCert != nil,
@ -229,13 +229,13 @@ func run(serverInstallationNamespace string, cfg *supervisor.Config) error {
defer func() { _ = httpsListener.Close() }() defer func() { _ = httpsListener.Close() }()
start(ctx, httpsListener, oidProvidersManager) start(ctx, httpsListener, oidProvidersManager)
klog.InfoS("supervisor is ready", plog.Debug("supervisor is ready",
"httpAddress", httpListener.Addr().String(), "httpAddress", httpListener.Addr().String(),
"httpsAddress", httpsListener.Addr().String(), "httpsAddress", httpsListener.Addr().String(),
) )
gotSignal := waitForSignal() gotSignal := waitForSignal()
klog.InfoS("supervisor exiting", "signal", gotSignal) plog.Debug("supervisor exiting", "signal", gotSignal)
return nil return nil
} }

4
internal/concierge/apiserver/apiserver.go
View File

@ -15,10 +15,10 @@ import (
"k8s.io/apiserver/pkg/registry/rest" "k8s.io/apiserver/pkg/registry/rest"
genericapiserver "k8s.io/apiserver/pkg/server" genericapiserver "k8s.io/apiserver/pkg/server"
"k8s.io/client-go/pkg/version" "k8s.io/client-go/pkg/version"
"k8s.io/klog/v2"
loginapi "go.pinniped.dev/generated/1.19/apis/concierge/login" loginapi "go.pinniped.dev/generated/1.19/apis/concierge/login"
loginv1alpha1 "go.pinniped.dev/generated/1.19/apis/concierge/login/v1alpha1" loginv1alpha1 "go.pinniped.dev/generated/1.19/apis/concierge/login/v1alpha1"
"go.pinniped.dev/internal/plog"
"go.pinniped.dev/internal/registry/credentialrequest" "go.pinniped.dev/internal/registry/credentialrequest"
) )
@ -111,7 +111,7 @@ func (c completedConfig) New() (*PinnipedServer, error) {
s.GenericAPIServer.AddPostStartHookOrDie("start-controllers", s.GenericAPIServer.AddPostStartHookOrDie("start-controllers",
func(postStartContext genericapiserver.PostStartHookContext) error { 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()) ctx, cancel := context.WithCancel(context.Background())
go func() { go func() {

7
internal/controller/issuerconfig/kube_config_info_publisher.go
View File

@ -16,6 +16,7 @@ import (
pinnipedclientset "go.pinniped.dev/generated/1.19/client/concierge/clientset/versioned" pinnipedclientset "go.pinniped.dev/generated/1.19/client/concierge/clientset/versioned"
pinnipedcontroller "go.pinniped.dev/internal/controller" pinnipedcontroller "go.pinniped.dev/internal/controller"
"go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/controllerlib"
"go.pinniped.dev/internal/plog"
) )
const ( const (
@ -75,7 +76,7 @@ func (c *kubeConigInfoPublisherController) Sync(ctx controllerlib.Context) error
return fmt.Errorf("failed to get %s configmap: %w", clusterInfoName, err) return fmt.Errorf("failed to get %s configmap: %w", clusterInfoName, err)
} }
if notFound { if notFound {
klog.InfoS( plog.Debug(
"could not find config map", "could not find config map",
"configmap", "configmap",
klog.KRef(ClusterInfoNamespace, clusterInfoName), klog.KRef(ClusterInfoNamespace, clusterInfoName),
@ -85,13 +86,13 @@ func (c *kubeConigInfoPublisherController) Sync(ctx controllerlib.Context) error
kubeConfig, kubeConfigPresent := configMap.Data[clusterInfoConfigMapKey] kubeConfig, kubeConfigPresent := configMap.Data[clusterInfoConfigMapKey]
if !kubeConfigPresent { if !kubeConfigPresent {
klog.InfoS("could not find kubeconfig configmap key") plog.Debug("could not find kubeconfig configmap key")
return nil return nil
} }
config, err := clientcmd.Load([]byte(kubeConfig)) config, err := clientcmd.Load([]byte(kubeConfig))
if err != nil { if err != nil {
klog.InfoS("could not load kubeconfig configmap key") plog.Debug("could not load kubeconfig configmap key")
return nil return nil
} }

3
internal/controller/kubecertagent/annotater.go
View File

@ -19,6 +19,7 @@ import (
pinnipedclientset "go.pinniped.dev/generated/1.19/client/concierge/clientset/versioned" pinnipedclientset "go.pinniped.dev/generated/1.19/client/concierge/clientset/versioned"
pinnipedcontroller "go.pinniped.dev/internal/controller" pinnipedcontroller "go.pinniped.dev/internal/controller"
"go.pinniped.dev/internal/controllerlib" "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 // 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[agentPodCertPathAnnotationKey] = certPath
updatedAgentPod.Annotations[agentPodKeyPathAnnotationKey] = keyPath updatedAgentPod.Annotations[agentPodKeyPathAnnotationKey] = keyPath
klog.InfoS( plog.Debug(
"updating agent pod annotations", "updating agent pod annotations",
"pod", "pod",
klog.KObj(updatedAgentPod), klog.KObj(updatedAgentPod),

3
internal/controller/kubecertagent/creater.go
View File

@ -18,6 +18,7 @@ import (
"go.pinniped.dev/internal/constable" "go.pinniped.dev/internal/constable"
pinnipedcontroller "go.pinniped.dev/internal/controller" pinnipedcontroller "go.pinniped.dev/internal/controller"
"go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/controllerlib"
"go.pinniped.dev/internal/plog"
) )
type createrController struct { type createrController struct {
@ -118,7 +119,7 @@ func (c *createrController) Sync(ctx controllerlib.Context) error {
if agentPod == nil { if agentPod == nil {
agentPod = c.agentPodConfig.newAgentPod(controllerManagerPod) agentPod = c.agentPodConfig.newAgentPod(controllerManagerPod)
klog.InfoS( plog.Debug(
"creating agent pod", "creating agent pod",
"pod", "pod",
klog.KObj(agentPod), klog.KObj(agentPod),

3
internal/controller/kubecertagent/deleter.go
View File

@ -13,6 +13,7 @@ import (
pinnipedcontroller "go.pinniped.dev/internal/controller" pinnipedcontroller "go.pinniped.dev/internal/controller"
"go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/controllerlib"
"go.pinniped.dev/internal/plog"
) )
type deleterController struct { type deleterController struct {
@ -71,7 +72,7 @@ func (c *deleterController) Sync(ctx controllerlib.Context) error {
} }
if controllerManagerPod == nil || if controllerManagerPod == nil ||
!isAgentPodUpToDate(agentPod, c.agentPodConfig.newAgentPod(controllerManagerPod)) { !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. err := c.k8sClient.
CoreV1(). CoreV1().
Pods(agentPod.Namespace). Pods(agentPod.Namespace).

6
internal/controller/kubecertagent/kubecertagent.go
View File

@ -23,11 +23,11 @@ import (
"k8s.io/apimachinery/pkg/labels" "k8s.io/apimachinery/pkg/labels"
"k8s.io/apimachinery/pkg/util/clock" "k8s.io/apimachinery/pkg/util/clock"
corev1informers "k8s.io/client-go/informers/core/v1" corev1informers "k8s.io/client-go/informers/core/v1"
"k8s.io/klog/v2"
configv1alpha1 "go.pinniped.dev/generated/1.19/apis/concierge/config/v1alpha1" configv1alpha1 "go.pinniped.dev/generated/1.19/apis/concierge/config/v1alpha1"
pinnipedclientset "go.pinniped.dev/generated/1.19/client/concierge/clientset/versioned" pinnipedclientset "go.pinniped.dev/generated/1.19/client/concierge/clientset/versioned"
"go.pinniped.dev/internal/controller/issuerconfig" "go.pinniped.dev/internal/controller/issuerconfig"
"go.pinniped.dev/internal/plog"
) )
const ( const (
@ -257,13 +257,13 @@ func findControllerManagerPodForSpecificAgentPod(
) (*corev1.Pod, error) { ) (*corev1.Pod, error) {
name, ok := agentPod.Annotations[controllerManagerNameAnnotationKey] name, ok := agentPod.Annotations[controllerManagerNameAnnotationKey]
if !ok { 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 return nil, nil
} }
uid, ok := agentPod.Annotations[controllerManagerUIDAnnotationKey] uid, ok := agentPod.Annotations[controllerManagerUIDAnnotationKey]
if !ok { 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 return nil, nil
} }

8
internal/controller/supervisorconfig/jwks_observer.go
View File

@ -10,11 +10,11 @@ import (
"gopkg.in/square/go-jose.v2" "gopkg.in/square/go-jose.v2"
"k8s.io/apimachinery/pkg/labels" "k8s.io/apimachinery/pkg/labels"
corev1informers "k8s.io/client-go/informers/core/v1" corev1informers "k8s.io/client-go/informers/core/v1"
"k8s.io/klog/v2"
"go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1" "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1"
pinnipedcontroller "go.pinniped.dev/internal/controller" pinnipedcontroller "go.pinniped.dev/internal/controller"
"go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/controllerlib"
"go.pinniped.dev/internal/plog"
) )
type jwksObserverController struct { type jwksObserverController struct {
@ -75,19 +75,19 @@ func (c *jwksObserverController) Sync(ctx controllerlib.Context) error {
secretRef := provider.Status.JWKSSecret secretRef := provider.Status.JWKSSecret
jwksSecret, err := c.secretInformer.Lister().Secrets(ns).Get(secretRef.Name) jwksSecret, err := c.secretInformer.Lister().Secrets(ns).Get(secretRef.Name)
if err != nil { 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 continue
} }
jwkFromSecret := jose.JSONWebKeySet{} jwkFromSecret := jose.JSONWebKeySet{}
err = json.Unmarshal(jwksSecret.Data[jwksKey], &jwkFromSecret) err = json.Unmarshal(jwksSecret.Data[jwksKey], &jwkFromSecret)
if err != nil { 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 continue
} }
issuerToJWKSMap[provider.Spec.Issuer] = &jwkFromSecret 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) c.issuerToJWKSSetter.SetIssuerToJWKSMap(issuerToJWKSMap)
return nil return nil

27
internal/controller/supervisorconfig/jwks_writer.go
View File

@ -27,6 +27,7 @@ import (
configinformers "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1" configinformers "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1"
pinnipedcontroller "go.pinniped.dev/internal/controller" pinnipedcontroller "go.pinniped.dev/internal/controller"
"go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/controllerlib"
"go.pinniped.dev/internal/plog"
) )
// These constants are the keys in an OPC's Secret's Data map. // 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 { if notFound {
// The corresponding secret to this OPC should have been garbage collected since it should have // The corresponding secret to this OPC should have been garbage collected since it should have
// had this OPC as its owner. // had this OPC as its owner.
klog.InfoS( plog.Debug(
"oidcprovider deleted", "oidcprovider deleted",
"oidcprovider", "oidcprovider",
klog.KRef(ctx.Key.Namespace, ctx.Key.Name), klog.KRef(ctx.Key.Namespace, ctx.Key.Name),
@ -146,7 +147,7 @@ func (c *jwksWriterController) Sync(ctx controllerlib.Context) error {
} }
if !secretNeedsUpdate { if !secretNeedsUpdate {
// Secret is up to date - we are good to go. // Secret is up to date - we are good to go.
klog.InfoS( plog.Debug(
"secret is up to date", "secret is up to date",
"oidcprovider", "oidcprovider",
klog.KRef(ctx.Key.Namespace, ctx.Key.Name), 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 { if err := c.createOrUpdateSecret(ctx.Context, secret); err != nil {
return fmt.Errorf("cannot create or update secret: %w", err) 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. // Ensure that the OPC points to the secret.
newOPC := opc.DeepCopy() newOPC := opc.DeepCopy()
@ -172,7 +173,7 @@ func (c *jwksWriterController) Sync(ctx controllerlib.Context) error {
if err := c.updateOPC(ctx.Context, newOPC); err != nil { if err := c.updateOPC(ctx.Context, newOPC); err != nil {
return fmt.Errorf("cannot update opc: %w", err) 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 return nil
} }
@ -323,45 +324,45 @@ func isOPCControllee(obj metav1.Object) bool {
func isValid(secret *corev1.Secret) bool { func isValid(secret *corev1.Secret) bool {
jwkData, ok := secret.Data[activeJWKKey] jwkData, ok := secret.Data[activeJWKKey]
if !ok { if !ok {
klog.InfoS("secret does not contain active jwk") plog.Debug("secret does not contain active jwk")
return false return false
} }
var activeJWK jose.JSONWebKey var activeJWK jose.JSONWebKey
if err := json.Unmarshal(jwkData, &activeJWK); err != nil { 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 return false
} }
if activeJWK.IsPublic() { if activeJWK.IsPublic() {
klog.InfoS("active jwk is public", "keyid", activeJWK.KeyID) plog.Debug("active jwk is public", "keyid", activeJWK.KeyID)
return false return false
} }
if !activeJWK.Valid() { 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 return false
} }
jwksData, ok := secret.Data[jwksKey] jwksData, ok := secret.Data[jwksKey]
if !ok { if !ok {
klog.InfoS("secret does not contain valid jwks") plog.Debug("secret does not contain valid jwks")
} }
var validJWKS jose.JSONWebKeySet var validJWKS jose.JSONWebKeySet
if err := json.Unmarshal(jwksData, &validJWKS); err != nil { 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 return false
} }
foundActiveJWK := false foundActiveJWK := false
for _, validJWK := range validJWKS.Keys { for _, validJWK := range validJWKS.Keys {
if !validJWK.IsPublic() { 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 return false
} }
if !validJWK.Valid() { 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 return false
} }
if validJWK.KeyID == activeJWK.KeyID { if validJWK.KeyID == activeJWK.KeyID {
@ -370,7 +371,7 @@ func isValid(secret *corev1.Secret) bool {
} }
if !foundActiveJWK { 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 return false
} }

6
internal/controller/supervisorconfig/oidcproviderconfig_watcher.go
View File

@ -9,8 +9,6 @@ import (
"net/url" "net/url"
"strings" "strings"
"go.pinniped.dev/internal/multierror"
metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
"k8s.io/apimachinery/pkg/labels" "k8s.io/apimachinery/pkg/labels"
"k8s.io/apimachinery/pkg/util/clock" "k8s.io/apimachinery/pkg/util/clock"
@ -22,7 +20,9 @@ import (
configinformers "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1" configinformers "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1"
pinnipedcontroller "go.pinniped.dev/internal/controller" pinnipedcontroller "go.pinniped.dev/internal/controller"
"go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/controllerlib"
"go.pinniped.dev/internal/multierror"
"go.pinniped.dev/internal/oidc/provider" "go.pinniped.dev/internal/oidc/provider"
"go.pinniped.dev/internal/plog"
) )
// ProvidersSetter can be notified of all known valid providers with its SetIssuer function. // ProvidersSetter can be notified of all known valid providers with its SetIssuer function.
@ -191,7 +191,7 @@ func (c *oidcProviderWatcherController) updateStatus(
return nil return nil
} }
klog.InfoS( plog.Debug(
"attempting status update", "attempting status update",
"openidproviderconfig", "openidproviderconfig",
klog.KRef(namespace, name), klog.KRef(namespace, name),

10
internal/controller/supervisorconfig/tls_cert_observer.go
View File

@ -11,11 +11,11 @@ import (
"k8s.io/apimachinery/pkg/labels" "k8s.io/apimachinery/pkg/labels"
corev1informers "k8s.io/client-go/informers/core/v1" corev1informers "k8s.io/client-go/informers/core/v1"
"k8s.io/klog/v2"
"go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1" "go.pinniped.dev/generated/1.19/client/supervisor/informers/externalversions/config/v1alpha1"
pinnipedcontroller "go.pinniped.dev/internal/controller" pinnipedcontroller "go.pinniped.dev/internal/controller"
"go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/controllerlib"
"go.pinniped.dev/internal/plog"
) )
type tlsCertObserverController struct { type tlsCertObserverController struct {
@ -78,7 +78,7 @@ func (c *tlsCertObserverController) Sync(ctx controllerlib.Context) error {
} }
issuerURL, err := url.Parse(provider.Spec.Issuer) issuerURL, err := url.Parse(provider.Spec.Issuer)
if err != nil { 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 continue
} }
certFromSecret, err := c.certFromSecret(ns, secretName) certFromSecret, err := c.certFromSecret(ns, secretName)
@ -89,7 +89,7 @@ func (c *tlsCertObserverController) Sync(ctx controllerlib.Context) error {
issuerHostToTLSCertMap[lowercaseHostWithoutPort(issuerURL)] = certFromSecret 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) c.issuerTLSCertSetter.SetIssuerHostToTLSCertMap(issuerHostToTLSCertMap)
defaultCert, err := c.certFromSecret(ns, c.defaultTLSCertificateSecretName) 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) { func (c *tlsCertObserverController) certFromSecret(ns string, secretName string) (*tls.Certificate, error) {
tlsSecret, err := c.secretInformer.Lister().Secrets(ns).Get(secretName) tlsSecret, err := c.secretInformer.Lister().Secrets(ns).Get(secretName)
if err != nil { 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 return nil, err
} }
certFromSecret, err := tls.X509KeyPair(tlsSecret.Data["tls.crt"], tlsSecret.Data["tls.key"]) certFromSecret, err := tls.X509KeyPair(tlsSecret.Data["tls.crt"], tlsSecret.Data["tls.key"])
if err != nil { 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 nil, err
} }
return &certFromSecret, nil return &certFromSecret, nil

10
internal/controllerlib/controller.go
View File

@ -16,6 +16,8 @@ import (
"k8s.io/client-go/tools/events" "k8s.io/client-go/tools/events"
"k8s.io/client-go/util/workqueue" "k8s.io/client-go/util/workqueue"
"k8s.io/klog/v2" "k8s.io/klog/v2"
"go.pinniped.dev/internal/plog"
) )
// Controller interface represents a runnable Kubernetes controller. // Controller interface represents a runnable Kubernetes controller.
@ -87,7 +89,7 @@ type controller struct {
func (c *controller) Run(ctx context.Context, workers int) { func (c *controller) Run(ctx context.Context, workers int) {
defer utilruntime.HandleCrash(crash) // prevent panics from killing the process 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() 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 // at this point the Run() can hang and callers have to implement the logic that will kill
// this controller (SIGKILL). // this controller (SIGKILL).
workerWg.Wait() 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++ { for i := 1; i <= workers; i++ {
idx := i idx := i
klog.InfoS("starting worker", "controller", c.Name(), "worker", idx) plog.Debug("starting worker", "controller", c.Name(), "worker", idx)
workerWg.Add(1) workerWg.Add(1)
go func() { go func() {
defer utilruntime.HandleCrash(crash) // prevent panics from killing the process defer utilruntime.HandleCrash(crash) // prevent panics from killing the process
defer func() { defer func() {
klog.InfoS("shutting down worker", "controller", c.Name(), "worker", idx) plog.Debug("shutting down worker", "controller", c.Name(), "worker", idx)
workerWg.Done() workerWg.Done()
}() }()
c.runWorker(workerContext) c.runWorker(workerContext)

4
internal/controllerlib/manager.go
View File

@ -7,7 +7,7 @@ import (
"context" "context"
"sync" "sync"
"k8s.io/klog/v2" "go.pinniped.dev/internal/plog"
) )
type Manager interface { type Manager interface {
@ -48,7 +48,7 @@ func (c *controllerManager) Start(ctx context.Context) {
idx := i idx := i
go func() { go func() {
r := c.controllers[idx] 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() defer wg.Done()
r.controller.Run(ctx, r.workers) r.controller.Run(ctx, r.workers)
}() }()

7
internal/oidc/provider/manager/manager.go
View File

@ -8,12 +8,11 @@ import (
"strings" "strings"
"sync" "sync"
"k8s.io/klog/v2"
"go.pinniped.dev/internal/oidc" "go.pinniped.dev/internal/oidc"
"go.pinniped.dev/internal/oidc/discovery" "go.pinniped.dev/internal/oidc/discovery"
"go.pinniped.dev/internal/oidc/jwks" "go.pinniped.dev/internal/oidc/jwks"
"go.pinniped.dev/internal/oidc/provider" "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. // 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 jwksURL := strings.ToLower(incomingProvider.IssuerHost()) + "/" + incomingProvider.IssuerPath() + oidc.JWKSEndpointPath
m.providerHandlers[jwksURL] = jwks.NewHandler(incomingProvider.Issuer(), m.dynamicJWKSProvider) 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) { func (m *Manager) ServeHTTP(resp http.ResponseWriter, req *http.Request) {
requestHandler := m.findHandler(req) requestHandler := m.findHandler(req)
klog.InfoS( plog.Debug(
"oidc provider manager examining request", "oidc provider manager examining request",
"method", req.Method, "method", req.Method,
"host", req.Host, "host", req.Host,