From ce567c481bcfd9735962bf4de460da9bfb165187 Mon Sep 17 00:00:00 2001 From: Ryan Richard Date: Fri, 8 Sep 2023 09:22:10 -0700 Subject: [PATCH] Improve pod logs related to Supervisor TLS certificate problems --- .../supervisorconfig/tls_cert_observer.go | 36 +++++++++++++++---- internal/httputil/requestutil/requestutil.go | 14 ++++++++ internal/oidc/provider/manager/manager.go | 12 ++++--- internal/supervisor/server/bootstrap.go | 13 +++++++ internal/supervisor/server/server.go | 31 +++++++++------- 5 files changed, 82 insertions(+), 24 deletions(-) create mode 100644 internal/httputil/requestutil/requestutil.go diff --git a/internal/controller/supervisorconfig/tls_cert_observer.go b/internal/controller/supervisorconfig/tls_cert_observer.go index 7574a1bb..407b58ed 100644 --- a/internal/controller/supervisorconfig/tls_cert_observer.go +++ b/internal/controller/supervisorconfig/tls_cert_observer.go @@ -1,4 +1,4 @@ -// Copyright 2020-2021 the Pinniped contributors. All Rights Reserved. +// Copyright 2020-2023 the Pinniped contributors. All Rights Reserved. // SPDX-License-Identifier: Apache-2.0 package supervisorconfig @@ -10,6 +10,7 @@ import ( "strings" v1 "k8s.io/api/core/v1" + k8serrors "k8s.io/apimachinery/pkg/api/errors" "k8s.io/apimachinery/pkg/labels" corev1informers "k8s.io/client-go/informers/core/v1" @@ -73,19 +74,33 @@ func (c *tlsCertObserverController) Sync(ctx controllerlib.Context) error { issuerHostToTLSCertMap := map[string]*tls.Certificate{} for _, provider := range allProviders { - secretName := "" - if provider.Spec.TLS != nil { - secretName = provider.Spec.TLS.SecretName - } issuerURL, err := url.Parse(provider.Spec.Issuer) if err != nil { plog.Debug("tlsCertObserverController Sync found an invalid issuer URL", "namespace", ns, "issuer", provider.Spec.Issuer) continue } - certFromSecret, err := c.certFromSecret(ns, secretName) - if err != nil { + + secretName := "" + if provider.Spec.TLS != nil { + secretName = provider.Spec.TLS.SecretName + } + if secretName == "" { + // No secret name provided, so no need to try to load any Secret. continue } + + certFromSecret, err := c.certFromSecret(ns, secretName) + if err != nil { + // The user configured a TLS secret on the FederationDomain but it could not be loaded, + // so log a message which is visible at the default log level. Any error here indicates a problem, + // including "not found" errors. + plog.Error("error loading TLS certificate from Secret for FederationDomain.spec.tls.secretName", err, + "FederationDomain.metadata.name", provider.Name, + "FederationDomain.spec.tls.secretName", provider.Spec.TLS.SecretName, + ) + continue + } + // Lowercase the host part of the URL because hostnames should be treated as case-insensitive. issuerHostToTLSCertMap[lowercaseHostWithoutPort(issuerURL)] = certFromSecret } @@ -96,6 +111,13 @@ func (c *tlsCertObserverController) Sync(ctx controllerlib.Context) error { defaultCert, err := c.certFromSecret(ns, c.defaultTLSCertificateSecretName) if err != nil { c.issuerTLSCertSetter.SetDefaultTLSCert(nil) + // It's okay if the default TLS cert Secret is not found (it is not required). + if !k8serrors.IsNotFound(err) { + // For any other error, log a message which is visible at the default log level. + plog.Error("error loading TLS certificate from Secret for Supervisor default TLS cert", err, + "defaultCertSecretName", c.defaultTLSCertificateSecretName, + ) + } } else { c.issuerTLSCertSetter.SetDefaultTLSCert(defaultCert) } diff --git a/internal/httputil/requestutil/requestutil.go b/internal/httputil/requestutil/requestutil.go new file mode 100644 index 00000000..3bfe4898 --- /dev/null +++ b/internal/httputil/requestutil/requestutil.go @@ -0,0 +1,14 @@ +// Copyright 2023 the Pinniped contributors. All Rights Reserved. +// SPDX-License-Identifier: Apache-2.0 + +package requestutil + +import "net/http" + +func SNIServerName(req *http.Request) string { + name := "" + if req.TLS != nil { + name = req.TLS.ServerName + } + return name +} diff --git a/internal/oidc/provider/manager/manager.go b/internal/oidc/provider/manager/manager.go index 47d25981..0cd3e3e3 100644 --- a/internal/oidc/provider/manager/manager.go +++ b/internal/oidc/provider/manager/manager.go @@ -1,4 +1,4 @@ -// Copyright 2020-2022 the Pinniped contributors. All Rights Reserved. +// Copyright 2020-2023 the Pinniped contributors. All Rights Reserved. // SPDX-License-Identifier: Apache-2.0 package manager @@ -11,6 +11,7 @@ import ( corev1client "k8s.io/client-go/kubernetes/typed/core/v1" "go.pinniped.dev/generated/latest/client/supervisor/clientset/versioned/typed/config/v1alpha1" + "go.pinniped.dev/internal/httputil/requestutil" "go.pinniped.dev/internal/oidc" "go.pinniped.dev/internal/oidc/auth" "go.pinniped.dev/internal/oidc/callback" @@ -167,12 +168,15 @@ func (m *Manager) SetProviders(federationDomains ...*provider.FederationDomainIs func (m *Manager) ServeHTTP(resp http.ResponseWriter, req *http.Request) { requestHandler := m.findHandler(req) - plog.Debug( - "oidc provider manager examining request", + // Using Info level so the user can safely configure a production Supervisor to show this message if they choose. + plog.Info("received incoming request", + "proto", req.Proto, "method", req.Method, "host", req.Host, + "requestSNIServerName", requestutil.SNIServerName(req), "path", req.URL.Path, - "foundMatchingIssuer", requestHandler != nil, + "remoteAddr", req.RemoteAddr, + "foundFederationDomainRequestHandler", requestHandler != nil, ) if requestHandler == nil { diff --git a/internal/supervisor/server/bootstrap.go b/internal/supervisor/server/bootstrap.go index 9ffdf2b3..1b8e63f5 100644 --- a/internal/supervisor/server/bootstrap.go +++ b/internal/supervisor/server/bootstrap.go @@ -15,6 +15,8 @@ import ( "k8s.io/apimachinery/pkg/util/sets" "go.pinniped.dev/internal/certauthority" + "go.pinniped.dev/internal/httputil/requestutil" + "go.pinniped.dev/internal/plog" ) // contextKey type is unexported to prevent collisions. @@ -41,6 +43,17 @@ func withBootstrapPaths(handler http.Handler, paths ...string) http.Handler { isBootstrap, _ := req.Context().Value(bootstrapKey).(*atomic.Bool) if isBootstrap != nil && isBootstrap.Load() && !bootstrapPaths.Has(req.URL.Path) { + // When a user-provided cert was not found for a request path which requires it, + // then emit a log statement visible at the default log level. + plog.Warning("error finding user-provided TLS cert to use for for incoming request", + "proto", req.Proto, + "method", req.Method, + "host", req.Host, + "requestSNIServerName", requestutil.SNIServerName(req), + "path", req.URL.Path, + "remoteAddr", req.RemoteAddr, + ) + http.Error(w, "pinniped supervisor has invalid TLS serving certificate configuration", http.StatusInternalServerError) return } diff --git a/internal/supervisor/server/server.go b/internal/supervisor/server/server.go index 6f9b152a..bfbb36bf 100644 --- a/internal/supervisor/server/server.go +++ b/internal/supervisor/server/server.go @@ -521,30 +521,35 @@ func runSupervisor(ctx context.Context, podInfo *downward.PodInfo, cfg *supervis c := ptls.Default(nil) c.GetCertificate = func(info *tls.ClientHelloInfo) (*tls.Certificate, error) { cert := dynamicTLSCertProvider.GetTLSCert(strings.ToLower(info.ServerName)) + foundServerNameCert := cert != nil defaultCert := dynamicTLSCertProvider.GetDefaultTLSCert() - if plog.Enabled(plog.LevelTrace) { // minor CPU optimization as this is generally just noise - host, port, _ := net.SplitHostPort(info.Conn.LocalAddr().String()) // error is safe to ignore here - - plog.Trace("GetCertificate called", - "info.ServerName", info.ServerName, - "foundSNICert", cert != nil, - "foundDefaultCert", defaultCert != nil, - "host", host, - "port", port, - ) - } - - if cert == nil { + if !foundServerNameCert { cert = defaultCert } + // If we still don't have a cert for the request at this point, then using the bootstrapping cert, + // but in that case also set the request to fail unless it is a health check request. + usingBootstrapCert := false if cert == nil { + usingBootstrapCert = true setIsBootstrapConn(info.Context()) // make this connection only work for bootstrap requests cert = bootstrapCert } + // Emit logs visible at a higher level of logging than the default. Using Info level so the user + // can safely configure a production Supervisor to show this message if they choose. + plog.Info("choosing TLS cert for incoming request", + "requestSNIServerName", info.ServerName, + "foundCertForSNIServerNameFromFederationDomain", foundServerNameCert, + "foundDefaultCertFromSecret", defaultCert != nil, + "defaultCertSecretName", cfg.NamesConfig.DefaultTLSCertificateSecret, + "servingBootstrapHealthzCert", usingBootstrapCert, + "requestLocalAddr", info.Conn.LocalAddr().String(), + "requestRemoteAddr", info.Conn.RemoteAddr().String(), + ) + return cert, nil }