🌱 Add logging to certpoolwatcher and client #1684

tmshort · 2025-01-31T16:31:57Z

Logging now indicates what certificate (by file and X.509 name) is being watched

Update:

Remove firstExpiration as it's no longer calculated
Default logging to V(4), using a constant
Add cert logging for catalogd pull failure

Log when an unknown server cert is encountered:

E0203 20:46:01.629763       1 client.go:124] "unverified cert" err="Get \"https://catalogd-service.olmv1-system.svc/catalogs/operatorhubio/api/v1/all\": tls: failed to verify certificate: x509: certificate signed by unknown authority" logger="catalog-client" n=1 subject="" issuer="CN=olmv1-ca" DNSNames=["localhost","catalogd-service.olmv1-system.svc","catalogd-service.olmv1-system.svc.cluster.local"] serial="197916310015755767059581167694871409392"

Loading and Watching certificates:

I0203 20:29:03.579864       1 certlog.go:81] "loading certificate file" logger="cert-pool" directory="/var/certs" file="olm-ca.crt" subject="CN=olmv1-ca"
I0203 20:29:03.580046       1 certlog.go:81] "watching certificate directory" logger="cert-pool" directory="/var/certs" file="olm-ca.crt" subject="CN=olmv1-ca"
I0203 20:29:03.580236       1 certlog.go:81] "watching certificate file" logger="cert-pool" file="/etc/ssl/certs/ca-certificates.crt" subject="CN=ACCVRAIZ1,OU=PKIACCV,O=ACCV,C=ES"
I0203 20:29:03.580264       1 certlog.go:81] "watching certificate file" logger="cert-pool" file="/etc/ssl/certs/ca-certificates.crt" subject="OU=AC RAIZ FNMT-RCM,O=FNMT-RCM,C=ES"

netlify · 2025-01-31T16:32:13Z

✅ Deploy Preview for olmv1 ready!

Name	Link
🔨 Latest commit	`5a10b3d`
🔍 Latest deploy log	https://app.netlify.com/sites/olmv1/deploys/67a678cb4445e20008ffadcb
😎 Deploy Preview	https://deploy-preview-1684--olmv1.netlify.app
📱 Preview on mobile	Toggle QR Code... Use your smartphone camera to open QR code link.

To edit notification comments on pull requests, go to your Netlify site configuration.

codecov · 2025-01-31T16:45:32Z

Codecov Report

Attention: Patch coverage is 44.96644% with 82 lines in your changes missing coverage. Please review.

Project coverage is 67.55%. Comparing base (d72e551) to head (5a10b3d).

Files with missing lines	Patch %	Lines
internal/httputil/certlog.go	41.50%	54 Missing and 8 partials ⚠️
catalogd/internal/source/containers_image.go	46.15%	6 Missing and 1 partial ⚠️
internal/rukpak/source/containers_image.go	46.15%	6 Missing and 1 partial ⚠️
catalogd/cmd/catalogd/main.go	0.00%	3 Missing ⚠️
cmd/operator-controller/main.go	0.00%	2 Missing and 1 partial ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #1684      +/-   ##
==========================================
- Coverage   68.24%   67.55%   -0.70%     
==========================================
  Files          58       59       +1     
  Lines        4988     5128     +140     
==========================================
+ Hits         3404     3464      +60     
- Misses       1342     1411      +69     
- Partials      242      253      +11

Flag	Coverage Δ
e2e	`52.47% <45.11%> (-0.45%)`	⬇️
unit	`54.85% <35.57%> (-0.60%)`	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

perdasilva

lgtm ^^

perdasilva · 2025-01-31T18:01:09Z

you may need to rebase to pick up the upgrade-e2e mitigations =S

joelanford · 2025-01-31T23:34:35Z

Would you mind adding some example output to the description of the PR?

internal/httputil/certpoolwatcher.go

tmshort · 2025-02-03T20:42:58Z

Example logging at start:

I0203 20:29:03.579864       1 certlog.go:81] "loading certificate file" logger="cert-pool" directory="/var/certs" file="olm-ca.crt" subject="CN=olmv1-ca"
I0203 20:29:03.579910       1 certlog.go:81] "loading certificate file" logger="cert-pool" directory="/var/certs" file="tls.cert" DNSNames=["operator-controller-service.olmv1-system.svc","operator-controller-service.olmv1-system.svc.cluster.local"]
E0203 20:29:03.579947       1 certlog.go:64] "error in x509.ParseCertificate()" err="x509: malformed tbs certificate" logger="cert-pool" file="tls.key"
I0203 20:29:03.580012       1 certlog.go:37] "ignoring subdirectory" logger="cert-pool" directory="/var/certs/..2025_02_03_20_29_03.3099064557"
I0203 20:29:03.580020       1 certlog.go:37] "ignoring subdirectory" logger="cert-pool" directory="/var/certs/..data"
I0203 20:29:03.580046       1 certlog.go:81] "watching certificate directory" logger="cert-pool" directory="/var/certs" file="olm-ca.crt" subject="CN=olmv1-ca"
I0203 20:29:03.580084       1 certlog.go:81] "watching certificate directory" logger="cert-pool" directory="/var/certs" file="tls.cert" DNSNames=["operator-controller-service.olmv1-system.svc","operator-controller-service.olmv1-system.svc.cluster.local"]
E0203 20:29:03.580106       1 certlog.go:64] "error in x509.ParseCertificate()" err="x509: malformed tbs certificate" logger="cert-pool" file="tls.key"
I0203 20:29:03.580236       1 certlog.go:81] "watching certificate file" logger="cert-pool" file="/etc/ssl/certs/ca-certificates.crt" subject="CN=ACCVRAIZ1,OU=PKIACCV,O=ACCV,C=ES"
I0203 20:29:03.580264       1 certlog.go:81] "watching certificate file" logger="cert-pool" file="/etc/ssl/certs/ca-certificates.crt" subject="OU=AC RAIZ FNMT-RCM,O=FNMT-RCM,C=ES"
...

tmshort · 2025-02-03T20:46:58Z

Example logging of an unknown certificate:

E0203 20:46:01.629763       1 client.go:124] "Unverified Cert" err="Get \"https://catalogd-service.olmv1-system.svc/catalogs/operatorhubio/api/v1/all\": tls: failed to verify certificate: x509: certificate signed by unknown authority" logger="catalog-client" n=1 subject="" issuer="CN=olmv1-ca" DNSNames=["localhost","catalogd-service.olmv1-system.svc","catalogd-service.olmv1-system.svc.cluster.local"] serial="197916310015755767059581167694871409392"
I0203 20:46:01.629867       1 clustercatalog_controller.go:87] "reconcile ending" logger="cluster-catalog" controller="clustercatalog" controllerGroup="olm.operatorframework.io" controllerKind="ClusterCatalog" ClusterCatalog="operatorhubio" namespace="" name="operatorhubio" reconcileID="b5c3fd7f-0bc5-447e-a2cf-ab7bc08d86e5"
E0203 20:46:01.629929       1 controller.go:316] "Reconciler error" err="error populating cache for catalog \"operatorhubio\": error performing request: Get \"https://catalogd-service.olmv1-system.svc/catalogs/operatorhubio/api/v1/all\": tls: failed to verify certificate: x509: certificate signed by unknown authority" controller="clustercatalog" controllerGroup="olm.operatorframework.io" controllerKind="ClusterCatalog" ClusterCatalog="operatorhubio" namespace="" name="operatorhubio" reconcileID="b5c3fd7f-0bc5-447e-a2cf-ab7bc08d86e5"

internal/catalogmetadata/client/client.go

catalogd/internal/controllers/core/clustercatalog_controller.go

internal/httputil/certlog.go

internal/controllers/clusterextension_controller.go

internal/httputil/certlog.go

catalogd/internal/controllers/core/clustercatalog_controller.go

LalatenduMohanty · 2025-02-07T19:34:38Z

internal/httputil/certlog.go

@@ -0,0 +1,157 @@
+package httputil


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.

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

internal/httputil/certlog.go

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]>

joelanford · 2025-02-07T23:05:59Z

catalogd/internal/source/containers_image.go

@@ -37,6 +39,23 @@ type ContainersImageRegistry struct {
 }

 func (i *ContainersImageRegistry) Unpack(ctx context.Context, catalog *catalogdv1.ClusterCatalog) (*Result, error) {
+	res, err := i.unpack(ctx, catalog)


Lines 59-75 (the first lines of unpack should be moved into Unpack to:

Get a common logger to use (we should get it from the context, not from the root ctrl.Log)

Only have to call i.SourceContextFunc(l) once

Then we could just pass the logger and the SystemContext to unpack().

joelanford · 2025-02-07T23:07:41Z

internal/httputil/certutil.go

+			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())


Just checking that you are intending to use V(defaultLogLevel).V(1) here (which is the same as V(defaultLogLevel+1))? If so, maybe use the latter construction?

tmshort requested a review from a team as a code owner January 31, 2025 16:31

perdasilva previously approved these changes Jan 31, 2025

View reviewed changes

tmshort force-pushed the cert-watcher-logging branch from 906bb34 to d20ad5f Compare January 31, 2025 21:42

joelanford reviewed Jan 31, 2025

View reviewed changes

internal/httputil/certpoolwatcher.go Outdated Show resolved Hide resolved

joelanford reviewed Jan 31, 2025

View reviewed changes

internal/httputil/certpoolwatcher.go Outdated Show resolved Hide resolved

tmshort dismissed perdasilva’s stale review via 9eebd85 February 3, 2025 20:41

tmshort force-pushed the cert-watcher-logging branch from d20ad5f to 9eebd85 Compare February 3, 2025 20:41

tmshort closed this Feb 3, 2025

tmshort reopened this Feb 3, 2025

tmshort force-pushed the cert-watcher-logging branch 2 times, most recently from 0d53099 to cf71d8f Compare February 3, 2025 20:55

tmshort changed the title ~~🌱 Add logging to certpoolwatcher~~ 🌱 Add logging to certpoolwatcher and client Feb 3, 2025

joelanford reviewed Feb 4, 2025

View reviewed changes

internal/catalogmetadata/client/client.go Outdated Show resolved Hide resolved

joelanford reviewed Feb 4, 2025

View reviewed changes

internal/catalogmetadata/client/client.go Outdated Show resolved Hide resolved

tmshort force-pushed the cert-watcher-logging branch 3 times, most recently from c80561b to 01f38e7 Compare February 5, 2025 16:11

joelanford reviewed Feb 5, 2025

View reviewed changes

catalogd/internal/controllers/core/clustercatalog_controller.go Outdated Show resolved Hide resolved

tmshort force-pushed the cert-watcher-logging branch 3 times, most recently from de4fe9d to b778a9f Compare February 6, 2025 21:54

camilamacedo86 reviewed Feb 6, 2025

View reviewed changes

internal/httputil/certlog.go Outdated Show resolved Hide resolved

camilamacedo86 reviewed Feb 6, 2025

View reviewed changes

internal/controllers/clusterextension_controller.go Outdated Show resolved Hide resolved

camilamacedo86 reviewed Feb 7, 2025

View reviewed changes

internal/httputil/certlog.go Outdated Show resolved Hide resolved

tmshort force-pushed the cert-watcher-logging branch 5 times, most recently from 228010b to 3405fad Compare February 7, 2025 18:46

joelanford reviewed Feb 7, 2025

View reviewed changes

catalogd/internal/controllers/core/clustercatalog_controller.go Outdated Show resolved Hide resolved

LalatenduMohanty reviewed Feb 7, 2025

View reviewed changes

LalatenduMohanty requested changes Feb 7, 2025

View reviewed changes

internal/httputil/certlog.go Outdated Show resolved Hide resolved

tmshort force-pushed the cert-watcher-logging branch 2 times, most recently from a48c266 to 7da2528 Compare February 7, 2025 21:01

openshift-merge-robot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Feb 7, 2025

Add logging to certpoolwatcher and client

5a10b3d

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]>

tmshort force-pushed the cert-watcher-logging branch from 7da2528 to 5a10b3d Compare February 7, 2025 21:19

openshift-merge-robot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Feb 7, 2025

joelanford reviewed Feb 7, 2025

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

🌱 Add logging to certpoolwatcher and client #1684

🌱 Add logging to certpoolwatcher and client #1684

tmshort commented Jan 31, 2025 •

edited

Loading

netlify bot commented Jan 31, 2025 •

edited

Loading

codecov bot commented Jan 31, 2025 •

edited

Loading

perdasilva left a comment

perdasilva commented Jan 31, 2025

joelanford commented Jan 31, 2025

tmshort commented Feb 3, 2025

tmshort commented Feb 3, 2025

LalatenduMohanty Feb 7, 2025

tmshort Feb 7, 2025

joelanford Feb 7, 2025

joelanford Feb 7, 2025

🌱 Add logging to certpoolwatcher and client #1684

Are you sure you want to change the base?

🌱 Add logging to certpoolwatcher and client #1684

Conversation

tmshort commented Jan 31, 2025 • edited Loading

netlify bot commented Jan 31, 2025 • edited Loading

✅ Deploy Preview for olmv1 ready!

codecov bot commented Jan 31, 2025 • edited Loading

Codecov Report

perdasilva left a comment

Choose a reason for hiding this comment

perdasilva commented Jan 31, 2025

joelanford commented Jan 31, 2025

tmshort commented Feb 3, 2025

tmshort commented Feb 3, 2025

LalatenduMohanty Feb 7, 2025

Choose a reason for hiding this comment

tmshort Feb 7, 2025

Choose a reason for hiding this comment

joelanford Feb 7, 2025

Choose a reason for hiding this comment

joelanford Feb 7, 2025

Choose a reason for hiding this comment

tmshort commented Jan 31, 2025 •

edited

Loading

netlify bot commented Jan 31, 2025 •

edited

Loading

codecov bot commented Jan 31, 2025 •

edited

Loading