Add more context to error logs

Include This/NextUpdate, CRL number, CRL URL, and S3 object name and version
info.

checker/checker.go

@@ -115,18 +115,57 @@ type Checker struct {
 	issuers  map[string]*x509.Certificate
 }
 
+// crlSummary is a subset of fields from *x509.RevocationList
+// useful for logging, plus the number of entries and some metadata.
+type crlSummary struct {
+	Number     *big.Int
+	NumEntries int
+	ThisUpdate time.Time
+	NextUpdate time.Time
+	URL        string
+	StorageKey storage.Key
+}
+
+func summary(crl *x509.RevocationList, key storage.Key) crlSummary {
+	// If getIDP fails, we will just log ""
+	idp, _ := getIDP(crl)
+	return crlSummary{
+		ThisUpdate: crl.ThisUpdate,
+		NextUpdate: crl.NextUpdate,
+		Number:     crl.Number,
+		NumEntries: len(crl.RevokedCertificateEntries),
+		URL:        idp,
+		StorageKey: key,
+	}
+}
+
+type crlsSummary struct {
+	Old, New crlSummary
+}
+
+func logSummary(old *x509.RevocationList, oldStorageKey storage.Key, new *x509.RevocationList, newStorageKey storage.Key) crlsSummary {
+	return crlsSummary{
+		Old: summary(old, oldStorageKey),
+		New: summary(new, newStorageKey),
+	}
+}
+
 // Check fetches a CRL and its previous version.  It runs lints on the CRL, checks for early removal, and removes any
 // certificates we're waiting for out of the database.
-func (c *Checker) Check(ctx context.Context, bucket, object string, startingVersion *string) error {
+func (c *Checker) Check(ctx context.Context, bucket, object string, startingVersion string) error {
 	// Read the current CRL shard
-	crlDER, version, err := c.storage.Fetch(ctx, bucket, object, startingVersion)
+	crlDER, version, err := c.storage.Fetch(ctx, storage.Key{
+		Bucket:  bucket,
+		Object:  object,
+		Version: startingVersion,
+	})
 	if err != nil {
 		return err
 	}
 
 	crl, err := x509.ParseRevocationList(crlDER)
 	if err != nil {
-		return fmt.Errorf("error parsing current crl: %v", err)
+		return fmt.Errorf("parsing current crl: %v", err)
 	}
 	log.Printf("loaded CRL number %d (len %d) from %s version %s", crl.Number, len(crl.RevokedCertificateEntries), object, version)
 
@@ -146,26 +185,36 @@ func (c *Checker) Check(ctx context.Context, bucket, object string, startingVers
 		return err
 	}
 
+	curKey := storage.Key{
+		Bucket:  bucket,
+		Object:  object,
+		Version: version,
+	}
 	// And the previous:
-	prevVersion, err := c.storage.Previous(ctx, bucket, object, version)
+	prevVersion, err := c.storage.Previous(ctx, curKey)
 	if err != nil {
 		return err
 	}
 
-	prevDER, _, err := c.storage.Fetch(ctx, bucket, object, &prevVersion)
+	prevKey := curKey
+	prevKey.Version = prevVersion
+
+	prevDER, _, err := c.storage.Fetch(ctx, prevKey)
 	if err != nil {
 		return err
 	}
 
 	prev, err := x509.ParseRevocationList(prevDER)
 	if err != nil {
-		return fmt.Errorf("error parsing previous crl: %v", err)
+		return fmt.Errorf("parsing previous crl: %v", err)
 	}
 	log.Printf("loaded previous CRL number %d (len %d) from version %s", prev.Number, len(prev.RevokedCertificateEntries), prevVersion)
 
+	context := logSummary(prev, prevKey, crl, curKey)
+
 	earlyRemoved, err := earlyremoval.Check(ctx, c.fetcher, c.maxFetch, prev, crl)
 	if err != nil {
-		return fmt.Errorf("failed to check for early removal: %v", err)
+		return fmt.Errorf("checking for early removal: %v. context: %+v", err, context)
 	}
 
 	if len(earlyRemoved) != 0 {
@@ -175,7 +224,7 @@ func (c *Checker) Check(ctx context.Context, bucket, object string, startingVers
 		}
 
 		// Certificates removed early!  This is very bad.
-		return fmt.Errorf("early removal of %d certificates detected! First %d: %v", len(earlyRemoved), len(sample), sample)
+		return fmt.Errorf("early removal of %d certificates detected! First %d: %v. context: %+v", len(earlyRemoved), len(sample), sample, context)
 	}
 
 	return c.lookForSeenCerts(ctx, crl)
@@ -186,7 +235,7 @@ func (c *Checker) Check(ctx context.Context, bucket, object string, startingVers
 func (c *Checker) lookForSeenCerts(ctx context.Context, crl *x509.RevocationList) error {
 	unseenCerts, err := c.db.GetAllCerts(ctx)
 	if err != nil {
-		return fmt.Errorf("failed to read from db: %v", err)
+		return fmt.Errorf("getting all certs from DB: %v", err)
 	}
 	var seenSerials [][]byte
 	var errs []error
@@ -208,7 +257,7 @@ func (c *Checker) lookForSeenCerts(ctx context.Context, crl *x509.RevocationList
 
 	err = c.db.DeleteSerials(ctx, seenSerials)
 	if err != nil {
-		errs = append(errs, fmt.Errorf("failed to delete from db: %v", err))
+		errs = append(errs, fmt.Errorf("deleting %d serials from DB: %v", len(seenSerials), err))
 	}
 	return errors.Join(errs...)
 }

checker/checker_test.go

@@ -95,7 +95,7 @@ func TestCheck(t *testing.T) {
 	require.NoError(t, checker.db.AddCert(ctx, &x509.Certificate{SerialNumber: shouldNotBeSeen}, testdata.Now))
 	mismatchCRLDistributionPoint := big.NewInt(4213)
 
-	require.NoError(t, checker.Check(ctx, bucket, shouldBeGood, nil))
+	require.NoError(t, checker.Check(ctx, bucket, shouldBeGood, ""))
 
 	// We should have seen the monitored cert but not the 12345 serial
 	unseenCerts, err := checker.db.GetAllCerts(ctx)
@@ -106,7 +106,7 @@ func TestCheck(t *testing.T) {
 	require.Empty(t, unseenCerts)
 
 	// The "early-removal" object should error on a certificate removed early
-	require.ErrorContains(t, checker.Check(ctx, bucket, earlyRemoval, nil), "early removal of 1 certificates detected!")
+	require.ErrorContains(t, checker.Check(ctx, bucket, earlyRemoval, ""), "early removal of 1 certificates detected!")
 
 	require.NoError(t, checker.db.AddCert(ctx, &x509.Certificate{
 		SerialNumber: mismatchCRLDistributionPoint,
@@ -115,7 +115,7 @@ func TestCheck(t *testing.T) {
 		},
 	}, testdata.Now))
 	// The "certificates-have-crldp" object should error because the certificate CRL is a mismatch
-	require.ErrorContains(t, checker.Check(ctx, bucket, certificatesHaveCRLDP, nil), "has non-matching CRLDistributionPoint")
+	require.ErrorContains(t, checker.Check(ctx, bucket, certificatesHaveCRLDP, ""), "has non-matching CRLDistributionPoint")
 }
 
 func Test_nameID(t *testing.T) {

cmd/checker/checker.go

@@ -17,7 +17,7 @@ const (
 func main() {
 	bucket := S3CRLBucket.MustRead("S3 CRL bucket name")
 	object := S3CRLObject.MustRead("S3 Object path to CRL file")
-	version, hasVersion := S3CRLVersion.LookupEnv()
+	version, _ := S3CRLVersion.LookupEnv()
 
 	ctx := context.Background()
 
@@ -26,13 +26,7 @@ func main() {
 		log.Fatalf("error creating checker: %v", err)
 	}
 
-	// The version is optional, so we pass it as a possibly-nil string pointer.
-	var optionalVersion *string
-	if hasVersion {
-		optionalVersion = &version
-	}
-
-	err = c.Check(ctx, bucket, object, optionalVersion)
+	err = c.Check(ctx, bucket, object, version)
 	if err != nil {
 		log.Printf("error checking CRL %s: %v", object, err)
 	}

lambda/checker/checker.go

@@ -16,7 +16,7 @@ func HandleRequest(c *checker.Checker) func(ctx context.Context, event events.S3
 		var err error
 		for _, record := range event.Records {
 			record := record
-			err = errors.Join(err, c.Check(ctx, record.S3.Bucket.Name, record.S3.Object.Key, &record.S3.Object.VersionID))
+			err = errors.Join(err, c.Check(ctx, record.S3.Bucket.Name, record.S3.Object.Key, record.S3.Object.VersionID))
 		}
 		return err
 	}

storage/mock/mock.go

@@ -46,6 +46,7 @@ func (s *s3mock) GetObject(ctx context.Context, input *s3.GetObjectInput, opts .
 	versionID := input.VersionId
 	if input.VersionId == nil {
 		versionID = aws.String(object[0].VersionID)
+		fmt.Printf("returning versionID %q", *versionID)
 	}
 
 	for _, version := range object {

storage/storage.go

@@ -20,6 +20,11 @@ type Storage struct {
 	S3Client s3client
 }
 
+// The parameters used to fetch a unique item from storage.
+type Key struct {
+	Bucket, Object, Version string
+}
+
 func New(ctx context.Context) *Storage {
 	cfg, err := config.LoadDefaultConfig(ctx)
 	if err != nil {
@@ -32,31 +37,35 @@ func New(ctx context.Context) *Storage {
 
 // Fetch gets a CRL from storage at a particular version
 // The bucket and object names are required.
-// If version is nil, the current version is returned.
+// If version is "", the current version is returned.
 // Returns the retrieved DER CRL bytes and what VersionID it was.
-func (s *Storage) Fetch(ctx context.Context, bucket, object string, version *string) ([]byte, string, error) {
+func (s *Storage) Fetch(ctx context.Context, key Key) ([]byte, string, error) {
+	var version *string
+	if key.Version != "" {
+		version = &key.Version
+	}
 	resp, err := s.S3Client.GetObject(ctx, &s3.GetObjectInput{
-		Bucket:    &bucket,
-		Key:       &object,
+		Bucket:    &key.Bucket,
+		Key:       &key.Object,
 		VersionId: version,
 	})
 	if err != nil {
-		return nil, "", fmt.Errorf("error retrieving CRL %s %s version %v: %w", bucket, object, version, err)
+		return nil, "", fmt.Errorf("retrieving CRL %s %s version %v: %w", key.Bucket, key.Object, version, err)
 	}
 
 	body, err := io.ReadAll(resp.Body)
 	if err != nil {
-		return nil, "", fmt.Errorf("error reading CRL %s %s version %v: %w", bucket, object, version, err)
+		return nil, "", fmt.Errorf("reading CRL %s %s version %v: %w", key.Bucket, key.Object, version, err)
 	}
 
 	return body, *resp.VersionId, err
 }
 
 // Previous returns the previous version of a CRL shard, which can then be fetched.
-func (s *Storage) Previous(ctx context.Context, bucket, object, version string) (string, error) {
+func (s *Storage) Previous(ctx context.Context, key Key) (string, error) {
 	resp, err := s.S3Client.ListObjectVersions(ctx, &s3.ListObjectVersionsInput{
-		Bucket: &bucket,
-		Prefix: &object,
+		Bucket: &key.Bucket,
+		Prefix: &key.Object,
 	})
 	if err != nil {
 		return "", err
@@ -70,14 +79,14 @@ func (s *Storage) Previous(ctx context.Context, bucket, object, version string)
 			break
 		}
 
-		if v.VersionId != nil && *v.VersionId == version {
+		if v.VersionId != nil && *v.VersionId == key.Version {
 			// This is the version of interest; select the next one
 			found = true
 		}
 	}
 
 	if (!found || prevVersion == nil) && resp.IsTruncated != nil && *resp.IsTruncated {
-		return "", fmt.Errorf("too many versions and pagination not implemented! %s %s %s", bucket, object, version)
+		return "", fmt.Errorf("too many versions and pagination not implemented! %+v", key)
 	}
 
 	if !found {

storage/storage_test.go

@@ -4,14 +4,14 @@ import (
 	"context"
 	"testing"
 
-	"github.com/aws/aws-sdk-go-v2/aws"
 	"github.com/stretchr/testify/require"
 
+	"github.com/letsencrypt/crl-monitor/storage"
 	"github.com/letsencrypt/crl-monitor/storage/mock"
 )
 
 func TestStorage(t *testing.T) {
-	storage := mock.New(t, "somebucket", map[string][]mock.MockObject{
+	mockStorage := mock.New(t, "somebucket", map[string][]mock.MockObject{
 		"123/0.crl": {
 			{VersionID: "111", Data: []byte{0xaa, 0xbb}},
 			{VersionID: "222", Data: []byte{0xcc, 0xdd}},
@@ -26,37 +26,41 @@ func TestStorage(t *testing.T) {
 	for _, tt := range []struct {
 		name        string
 		object      string
-		version     *string
+		version     string
 		expectedVer string
 		expectedCRL []byte
 	}{
 		{
 			name:        "nil version 1",
 			object:      "123/0.crl",
-			version:     nil,
+			version:     "0",
 			expectedVer: "111",
 			expectedCRL: []byte{0xaa, 0xbb},
 		}, {
 			name:   "nil version 2",
-			object: "456/2.crl", version: nil,
+			object: "456/2.crl", version: "",
 			expectedVer: "singleton",
 			expectedCRL: []byte{0x45, 0x02},
 		}, {
 			name:        "first version",
 			object:      "123/0.crl",
-			version:     aws.String("111"),
+			version:     "111",
 			expectedVer: "111",
 			expectedCRL: []byte{0xaa, 0xbb},
 		}, {
 			name:        "singleton version",
 			object:      "456/2.crl",
-			version:     aws.String("singleton"),
+			version:     "singleton",
 			expectedVer: "singleton",
 			expectedCRL: []byte{0x45, 0x02},
 		},
 	} {
 		t.Run(tt.name, func(t *testing.T) {
-			crl, version, err := storage.Fetch(context.Background(), "somebucket", tt.object, tt.version)
+			crl, version, err := mockStorage.Fetch(context.Background(), storage.Key{
+				Bucket:  "somebucket",
+				Object:  tt.object,
+				Version: tt.version,
+			})
 			require.NoError(t, err)
 			require.Equal(t, tt.expectedVer, version)
 			require.Equal(t, tt.expectedCRL, crl)
@@ -87,7 +91,11 @@ func TestStorage(t *testing.T) {
 		},
 	} {
 		t.Run(tt.name, func(t *testing.T) {
-			version, err := storage.Previous(context.Background(), "somebucket", tt.object, tt.version)
+			version, err := mockStorage.Previous(context.Background(), storage.Key{
+				Bucket:  "somebucket",
+				Object:  tt.object,
+				Version: tt.version,
+			})
 			require.NoError(t, err)
 			require.Equal(t, tt.expectedVer, version)
 		})
@@ -113,7 +121,11 @@ func TestStorage(t *testing.T) {
 		},
 	} {
 		t.Run(tt.name, func(t *testing.T) {
-			version, err := storage.Previous(context.Background(), "somebucket", tt.object, tt.version)
+			version, err := mockStorage.Previous(context.Background(), storage.Key{
+				Bucket:  "somebucket",
+				Object:  tt.object,
+				Version: tt.version,
+			})
 			require.Error(t, err)
 			require.Equal(t, "", version)
 		})