Skip to content

Commit

Permalink
Add logging to certpoolwatcher and client
Browse files Browse the repository at this point in the history
Logging now indicates what certificate (by file and X.509 name) is being watched

When an unverified certificate error is returned to the client, log the cert

Signed-off-by: Todd Short <[email protected]>
  • Loading branch information
tmshort committed Feb 7, 2025
1 parent 9b08aea commit 3405fad
Show file tree
Hide file tree
Showing 9 changed files with 226 additions and 8 deletions.
4 changes: 4 additions & 0 deletions catalogd/cmd/catalogd/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,7 @@ import (

"github.com/containers/image/v5/types"
"github.com/go-logr/logr"
"github.com/sirupsen/logrus"
"github.com/spf13/pflag"
corev1 "k8s.io/api/core/v1"
"k8s.io/apimachinery/pkg/fields"
Expand Down Expand Up @@ -120,6 +121,9 @@ func main() {
flag.StringVar(&globalPullSecret, "global-pull-secret", "", "The <namespace>/<name> of the global pull secret that is going to be used to pull bundle images.")

klog.InitFlags(flag.CommandLine)
if klog.V(4).Enabled() {
logrus.SetLevel(logrus.DebugLevel)
}

// Combine both flagsets and parse them
pflag.CommandLine.AddGoFlagSet(flag.CommandLine)
Expand Down
24 changes: 24 additions & 0 deletions catalogd/internal/controllers/core/clustercatalog_controller.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ import (
"sync"
"time"

"github.com/go-logr/logr"
"k8s.io/apimachinery/pkg/api/equality"
"k8s.io/apimachinery/pkg/api/meta"
metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
Expand All @@ -40,6 +41,7 @@ import (
catalogdv1 "github.com/operator-framework/operator-controller/catalogd/api/v1"
"github.com/operator-framework/operator-controller/catalogd/internal/source"
"github.com/operator-framework/operator-controller/catalogd/internal/storage"
"github.com/operator-framework/operator-controller/internal/httputil"
)

const (
Expand Down Expand Up @@ -149,6 +151,18 @@ func (r *ClusterCatalogReconciler) SetupWithManager(mgr ctrl.Manager) error {
Complete(r)
}

// Get the DockerCertPath from the reconciler
func (r *ClusterCatalogReconciler) getDockerCertPath(l logr.Logger) (string, error) {
if cir, ok := r.Unpacker.(*source.ContainersImageRegistry); ok {
src, srcErr := cir.SourceContextFunc(l)
if srcErr == nil {
return src.DockerCertPath, nil
}
return "", srcErr
}
return "", fmt.Errorf("unable to determine DockerCertPath")
}

// Note: This function always returns ctrl.Result{}. The linter
// fusses about this as we could instead just return error. This was
// discussed in https://github.com/operator-framework/rukpak/pull/635#discussion_r1229859464
Expand Down Expand Up @@ -229,6 +243,16 @@ func (r *ClusterCatalogReconciler) reconcile(ctx context.Context, catalog *catal

unpackResult, err := r.Unpacker.Unpack(ctx, catalog)
if err != nil {
// Log any CertificateVerificationErrors, and log Docker Certificates if necessary
l := ctrl.Log.WithName("catalogd-unpacker")
if httputil.LogCertificateVerificationError(err, l) {
path, pathErr := r.getDockerCertPath(l)
if pathErr != nil {
l.Error(pathErr, "unable to get docker cert path")
} else {
httputil.LogDockerCertificates(path, l)
}
}
unpackErr := fmt.Errorf("source catalog content: %w", err)
updateStatusProgressing(&catalog.Status, catalog.GetGeneration(), unpackErr)
return ctrl.Result{}, unpackErr
Expand Down
4 changes: 4 additions & 0 deletions cmd/operator-controller/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,7 @@ import (

"github.com/containers/image/v5/types"
"github.com/go-logr/logr"
"github.com/sirupsen/logrus"
"github.com/spf13/pflag"
corev1 "k8s.io/api/core/v1"
apiextensionsv1client "k8s.io/apiextensions-apiserver/pkg/client/clientset/clientset/typed/apiextensions/v1"
Expand Down Expand Up @@ -121,6 +122,9 @@ func main() {
flag.StringVar(&globalPullSecret, "global-pull-secret", "", "The <namespace>/<name> of the global pull secret that is going to be used to pull bundle images.")

klog.InitFlags(flag.CommandLine)
if klog.V(4).Enabled() {
logrus.SetLevel(logrus.DebugLevel)
}

pflag.CommandLine.AddGoFlagSet(flag.CommandLine)
features.OperatorControllerFeatureGate.AddFlag(pflag.CommandLine)
Expand Down
2 changes: 1 addition & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ require (
github.com/operator-framework/helm-operator-plugins v0.8.0
github.com/operator-framework/operator-registry v1.50.0
github.com/prometheus/client_golang v1.20.5
github.com/sirupsen/logrus v1.9.3
github.com/spf13/pflag v1.0.6
github.com/stretchr/testify v1.10.0
golang.org/x/exp v0.0.0-20241009180824-f66d83c29e7c
Expand Down Expand Up @@ -194,7 +195,6 @@ require (
github.com/sigstore/fulcio v1.6.4 // indirect
github.com/sigstore/rekor v1.3.6 // indirect
github.com/sigstore/sigstore v1.8.9 // indirect
github.com/sirupsen/logrus v1.9.3 // indirect
github.com/spf13/cast v1.7.0 // indirect
github.com/spf13/cobra v1.8.1 // indirect
github.com/stefanberger/go-pkcs11uri v0.0.0-20230803200340-78284954bff6 // indirect
Expand Down
3 changes: 3 additions & 0 deletions internal/catalogmetadata/client/client.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,10 +11,12 @@ import (

"k8s.io/apimachinery/pkg/api/meta"
metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
ctrl "sigs.k8s.io/controller-runtime"

"github.com/operator-framework/operator-registry/alpha/declcfg"

catalogd "github.com/operator-framework/operator-controller/catalogd/api/v1"
"github.com/operator-framework/operator-controller/internal/httputil"
)

const (
Expand Down Expand Up @@ -133,6 +135,7 @@ func (c *Client) doRequest(ctx context.Context, catalog *catalogd.ClusterCatalog

resp, err := client.Do(req)
if err != nil {
_ = httputil.LogCertificateVerificationError(err, ctrl.Log.WithName("catalog-client"))
return nil, fmt.Errorf("error performing request: %v", err)
}

Expand Down
23 changes: 23 additions & 0 deletions internal/controllers/clusterextension_controller.go
Original file line number Diff line number Diff line change
Expand Up @@ -53,6 +53,7 @@ import (
"github.com/operator-framework/operator-controller/internal/bundleutil"
"github.com/operator-framework/operator-controller/internal/conditionsets"
"github.com/operator-framework/operator-controller/internal/contentmanager"
"github.com/operator-framework/operator-controller/internal/httputil"
"github.com/operator-framework/operator-controller/internal/labels"
"github.com/operator-framework/operator-controller/internal/resolve"
rukpaksource "github.com/operator-framework/operator-controller/internal/rukpak/source"
Expand Down Expand Up @@ -171,6 +172,18 @@ func checkForUnexpectedFieldChange(a, b ocv1.ClusterExtension) bool {
return !equality.Semantic.DeepEqual(a, b)
}

// Get the DockerCertPath from the reconciler
func (r *ClusterExtensionReconciler) getDockerCertPath(l logr.Logger) (string, error) {
if cir, ok := r.Unpacker.(*rukpaksource.ContainersImageRegistry); ok {
src, srcErr := cir.SourceContextFunc(l)
if srcErr == nil {
return src.DockerCertPath, nil
}
return "", srcErr
}
return "", fmt.Errorf("unable to determine DockerCertPath")
}

// Helper function to do the actual reconcile
//
// Today we always return ctrl.Result{} and an error.
Expand Down Expand Up @@ -259,6 +272,16 @@ func (r *ClusterExtensionReconciler) reconcile(ctx context.Context, ext *ocv1.Cl
// and will be removing the .status.resolution field from the ClusterExtension status API
setStatusProgressing(ext, wrapErrorWithResolutionInfo(resolvedBundleMetadata, err))
setInstalledStatusFromBundle(ext, installedBundle)
// Log any CertificateVerificationErrors, and log Docker Certificates if necessary
l := ctrl.Log.WithName("operator-controller-unpacker")
if httputil.LogCertificateVerificationError(err, l) {
path, pathErr := r.getDockerCertPath(l)
if pathErr != nil {
l.Error(pathErr, "unable to get docker cert path")
} else {
httputil.LogDockerCertificates(path, l)
}
}
return ctrl.Result{}, err
}

Expand Down
157 changes: 157 additions & 0 deletions internal/httputil/certlog.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,157 @@
package httputil

import (
"crypto/tls"
"crypto/x509"
"encoding/pem"
"errors"
"fmt"
"os"
"path/filepath"

"github.com/go-logr/logr"
)

const (
defaultLogLevel = 4
)

// Log the certificates that would be used for docker pull operations
// Assumes a /etc/docker/certs.d like path, where the directory contains
// <hostname>:<port> directories in which a CA certificate (generally
// named "ca.crt") is located.
func LogDockerCertificates(path string, log logr.Logger) {
var paths []string
if path == "" {
paths = []string{"/etc/docker/certs.d", "/etc/containers/certs.d"}
} else {
paths = []string{path}
}
for _, path := range paths {
fi, err := os.Stat(path)
if err != nil {
log.Error(err, "statting directory", "directory", path)
continue
}
if !fi.IsDir() {
log.V(defaultLogLevel).V(1).Info("not a directory", "directory", path)
continue
}
dirEntries, err := os.ReadDir(path)
if err != nil {
log.Error(err, "reading directory", "directory", path)
continue
}
for _, e := range dirEntries {
hostPath := filepath.Join(path, e.Name())
fi, err := os.Stat(hostPath)
if err != nil {
log.Error(err, "dumping certs", "path", hostPath)
continue
}
if !fi.IsDir() {
log.V(defaultLogLevel).V(1).Info("ignoring non-directory", "path", hostPath)
continue
}
logPath(hostPath, "dump docker certs", log)
}
}
}

// This function unwraps the given error to find an CertificateVerificationError.
// It then logs the list of certificates found in the unwrapped error
// Returns:
// * true if a CertificateVerificationError is found
// * false if no CertificateVerificationError is found
func LogCertificateVerificationError(err error, log logr.Logger) bool {
for err != nil {
var cvErr *tls.CertificateVerificationError
if errors.As(err, &cvErr) {
n := 1
for _, cert := range cvErr.UnverifiedCertificates {
log.Error(err, "unverified cert", "n", n, "subject", cert.Subject, "issuer", cert.Issuer, "DNSNames", cert.DNSNames, "serial", cert.SerialNumber)
n = n + 1
}
return true
}
err = errors.Unwrap(err)
}
return false
}

func logPath(path, action string, log logr.Logger) {
fi, err := os.Stat(path)
if err != nil {
log.Error(err, "error in os.Stat()", "path", path)
return
}
if !fi.IsDir() {
logFile(path, "", fmt.Sprintf("%s file", action), log)
return
}
action = fmt.Sprintf("%s directory", action)
dirEntries, err := os.ReadDir(path)
if err != nil {
log.Error(err, "error in os.ReadDir()", "path", path)
return
}
for _, e := range dirEntries {
file := filepath.Join(path, e.Name())
fi, err := os.Stat(file)
if err != nil {
log.Error(err, "error in os.Stat()", "file", file)
continue
}
if fi.IsDir() {
log.V(defaultLogLevel).V(1).Info("ignoring subdirectory", "directory", file)
continue
}
logFile(e.Name(), path, action, log)
}
}

func logFile(filename, path, action string, log logr.Logger) {
filepath := filepath.Join(path, filename)
_, err := os.Stat(filepath)
if err != nil {
log.Error(err, "statting file", "file", filepath)
return
}
data, err := os.ReadFile(filepath)
if err != nil {
log.Error(err, "error in os.ReadFile()", "file", filepath)
return
}
logPem(data, filename, path, action, log)
}

func logPem(data []byte, filename, path, action string, log logr.Logger) {
for len(data) > 0 {
var block *pem.Block
block, data = pem.Decode(data)
if block == nil {
log.Info("error: no block returned from pem.Decode()", "file", filename)
return
}
crt, err := x509.ParseCertificate(block.Bytes)
if err != nil {
log.Error(err, "error in x509.ParseCertificate()", "file", filename)
return
}

args := []any{}
if path != "" {
args = append(args, "directory", path)
}
// Find an appopriate certificate identifier
args = append(args, "file", filename)
if s := crt.Subject.String(); s != "" {
args = append(args, "subject", s)
} else if crt.DNSNames != nil {
args = append(args, "DNSNames", crt.DNSNames)
} else if s := crt.SerialNumber.String(); s != "" {
args = append(args, "serial", s)
}
log.V(defaultLogLevel).Info(action, args...)
}
}
9 changes: 7 additions & 2 deletions internal/httputil/certpoolwatcher.go
Original file line number Diff line number Diff line change
Expand Up @@ -50,8 +50,12 @@ func NewCertPoolWatcher(caDir string, log logr.Logger) (*CertPoolWatcher, error)
// If the SSL_CERT_DIR or SSL_CERT_FILE environment variables are
// specified, this means that we have some control over the system root
// location, thus they may change, thus we should watch those locations.
watchPaths := strings.Split(os.Getenv("SSL_CERT_DIR"), ":")
watchPaths = append(watchPaths, caDir, os.Getenv("SSL_CERT_FILE"))
sslCertDir := os.Getenv("SSL_CERT_DIR")
sslCertFile := os.Getenv("SSL_CERT_FILE")
log.V(defaultLogLevel).Info("SSL environment", "SSL_CERT_DIR", sslCertDir, "SSL_CERT_FILE", sslCertFile)

watchPaths := strings.Split(sslCertDir, ":")
watchPaths = append(watchPaths, caDir, sslCertFile)
watchPaths = slices.DeleteFunc(watchPaths, func(p string) bool {
if p == "" {
return true
Expand All @@ -66,6 +70,7 @@ func NewCertPoolWatcher(caDir string, log logr.Logger) (*CertPoolWatcher, error)
if err := watcher.Add(p); err != nil {
return nil, err
}
logPath(p, "watching certificate", log)
}

cpw := &CertPoolWatcher{
Expand Down
8 changes: 3 additions & 5 deletions internal/httputil/certutil.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,6 @@ import (
"fmt"
"os"
"path/filepath"
"time"

"github.com/go-logr/logr"
)
Expand All @@ -24,7 +23,6 @@ func NewCertPool(caDir string, log logr.Logger) (*x509.CertPool, error) {
return nil, err
}
count := 0
firstExpiration := time.Time{}

for _, e := range dirEntries {
file := filepath.Join(caDir, e.Name())
Expand All @@ -34,10 +32,10 @@ func NewCertPool(caDir string, log logr.Logger) (*x509.CertPool, error) {
return nil, err
}
if fi.IsDir() {
log.Info("skip directory", "name", e.Name())
log.V(defaultLogLevel).V(1).Info("skip directory", "name", e.Name())
continue
}
log.Info("load certificate", "name", e.Name())
log.V(defaultLogLevel).V(1).Info("load certificate", "name", e.Name())
data, err := os.ReadFile(file)
if err != nil {
return nil, fmt.Errorf("error reading cert file %q: %w", file, err)
Expand All @@ -46,13 +44,13 @@ func NewCertPool(caDir string, log logr.Logger) (*x509.CertPool, error) {
if caCertPool.AppendCertsFromPEM(data) {
count++
}
logPem(data, e.Name(), caDir, "loading certificate file", log)
}

// Found no certs!
if count == 0 {
return nil, fmt.Errorf("no certificates found in %q", caDir)
}

log.Info("first expiration", "time", firstExpiration.Format(time.RFC3339))
return caCertPool, nil
}

0 comments on commit 3405fad

Please sign in to comment.