Skip to content

🌱 Add logging to certpoolwatcher and client #1684

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Feb 11, 2025
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
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
13 changes: 13 additions & 0 deletions catalogd/internal/source/containers_image.go
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@ import (
"sigs.k8s.io/controller-runtime/pkg/reconcile"

catalogdv1 "github.com/operator-framework/operator-controller/catalogd/api/v1"
"github.com/operator-framework/operator-controller/internal/httputil"
fsutil "github.com/operator-framework/operator-controller/internal/util/fs"
imageutil "github.com/operator-framework/operator-controller/internal/util/image"
)
Expand Down Expand Up @@ -54,6 +55,18 @@ func (i *ContainersImageRegistry) Unpack(ctx context.Context, catalog *catalogdv
if err != nil {
return nil, err
}

res, err := i.unpack(ctx, catalog, srcCtx, l)
if err != nil {
// Log any CertificateVerificationErrors, and log Docker Certificates if necessary
if httputil.LogCertificateVerificationError(err, l) {
httputil.LogDockerCertificates(srcCtx.DockerCertPath, l)
}
}
return res, err
}

func (i *ContainersImageRegistry) unpack(ctx context.Context, catalog *catalogdv1.ClusterCatalog, srcCtx *types.SystemContext, l logr.Logger) (*Result, error) {
//////////////////////////////////////////////////////
//
// Resolve a canonical reference for the image.
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 @@ -195,7 +196,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"))
Copy link
Member

@LalatenduMohanty LalatenduMohanty Feb 10, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why are we ignoring the return here?

// 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 {

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Because we don't need to log certs in /etc/docker here, because this is used for catalogd connections, not pulling images, The other places this is called, the return is used to determine if we want to look at /etc/docker

Copy link
Member

@LalatenduMohanty LalatenduMohanty Feb 10, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see, so we just called the function to log error in to the logfile.

return nil, fmt.Errorf("error performing request: %v", 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
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

it kind if weird that the certlog is in httputil pkg. Should we keep outside of httputil? Same comment for internal/httputil/certutil.go.

It is nit pick and not blocker for this PR.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was thinking of moving the cert utility stuff into it's own package, but that can be done later.


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) {
// These are the default paths that containers/images looks at for host:port certs
// See containers/images: docker/docker_client.go
paths := []string{"/etc/docker/certs.d", "/etc/containers/certs.d"}
if path != "" {
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+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+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+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+1).Info("skip directory", "name", e.Name())
continue
}
log.Info("load certificate", "name", e.Name())
log.V(defaultLogLevel+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
}
12 changes: 12 additions & 0 deletions internal/rukpak/source/containers_image.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ import (
"sigs.k8s.io/controller-runtime/pkg/log"
"sigs.k8s.io/controller-runtime/pkg/reconcile"

"github.com/operator-framework/operator-controller/internal/httputil"
fsutil "github.com/operator-framework/operator-controller/internal/util/fs"
imageutil "github.com/operator-framework/operator-controller/internal/util/image"
)
Expand Down Expand Up @@ -50,6 +51,17 @@ func (i *ContainersImageRegistry) Unpack(ctx context.Context, bundle *BundleSour
return nil, err
}

res, err := i.unpack(ctx, bundle, srcCtx, l)
if err != nil {
// Log any CertificateVerificationErrors, and log Docker Certificates if necessary
if httputil.LogCertificateVerificationError(err, l) {
httputil.LogDockerCertificates(srcCtx.DockerCertPath, l)
}
}
return res, err
}

func (i *ContainersImageRegistry) unpack(ctx context.Context, bundle *BundleSource, srcCtx *types.SystemContext, l logr.Logger) (*Result, error) {
//////////////////////////////////////////////////////
//
// Resolve a canonical reference for the image.
Expand Down
Loading