Replace all log.Err calls with log.AuditErr (letsencrypt#1891)

* remove calls to log.Err()
* go fmt
* remove more occurrences
* change AuditErr argument to string and replace occurrences

akamai/cache-client.go

@@ -228,7 +228,7 @@ func (cpc *CachePurgeClient) Purge(urls []string) error {
 		err := cpc.purge(urls)
 		if err != nil {
 			if _, ok := err.(errFatal); ok {
-				cpc.log.AuditErr(err)
+				cpc.log.AuditErr(err.Error())
 				cpc.stats.Inc("CCU.FatalFailures", 1, 1.0)
 				return err
 			}

ca/ca.go

@@ -340,7 +340,7 @@ func (ca *CertificateAuthorityImpl) GenerateOCSP(ctx context.Context, xferObj co
 	cert, err := x509.ParseCertificate(xferObj.CertDER)
 	if err != nil {
 		// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
-		ca.log.AuditErr(err)
+		ca.log.AuditErr(err.Error())
 		return nil, err
 	}
 
@@ -378,7 +378,7 @@ func (ca *CertificateAuthorityImpl) IssueCertificate(ctx context.Context, csr x5
 
 	if err := csrlib.VerifyCSR(&csr, ca.maxNames, &ca.keyPolicy, ca.PA, ca.forceCNFromSAN, regID); err != nil {
 		// AUDIT[ Certificate Requests ] 11917fa4-10ef-4e0d-9105-bacbe7836a3c
-		ca.log.AuditErr(err)
+		ca.log.AuditErr(err.Error())
 		return emptyCert, core.MalformedRequestError(err.Error())
 	}
 
@@ -393,7 +393,7 @@ func (ca *CertificateAuthorityImpl) IssueCertificate(ctx context.Context, csr x5
 	if issuer.cert.NotAfter.Before(notAfter) {
 		err = core.InternalServerError("Cannot issue a certificate that expires after the issuer certificate.")
 		// AUDIT[ Certificate Requests ] 11917fa4-10ef-4e0d-9105-bacbe7836a3c
-		ca.log.AuditErr(err)
+		ca.log.AuditErr(err.Error())
 		return emptyCert, err
 	}
 
@@ -411,7 +411,7 @@ func (ca *CertificateAuthorityImpl) IssueCertificate(ctx context.Context, csr x5
 	if err != nil {
 		err = core.InternalServerError(err.Error())
 		// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
-		ca.log.AuditErr(fmt.Errorf("Serial randomness failed, err=[%v]", err))
+		ca.log.AuditErr(fmt.Sprintf("Serial randomness failed, err=[%v]", err))
 		return emptyCert, err
 	}
 	serialBigInt := big.NewInt(0)
@@ -427,7 +427,7 @@ func (ca *CertificateAuthorityImpl) IssueCertificate(ctx context.Context, csr x5
 	default:
 		err = core.InternalServerError(fmt.Sprintf("unsupported key type %T", csr.PublicKey))
 		// AUDIT[ Certificate Requests ] 11917fa4-10ef-4e0d-9105-bacbe7836a3c
-		ca.log.AuditErr(err)
+		ca.log.AuditErr(err.Error())
 		return emptyCert, err
 	}
 
@@ -454,7 +454,7 @@ func (ca *CertificateAuthorityImpl) IssueCertificate(ctx context.Context, csr x5
 	if err != nil {
 		err = core.InternalServerError(err.Error())
 		// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
-		ca.log.AuditErr(fmt.Errorf("Signing failed: serial=[%s] err=[%v]", serialHex, err))
+		ca.log.AuditErr(fmt.Sprintf("Signing failed: serial=[%s] err=[%v]", serialHex, err))
 		return emptyCert, err
 	}
 
@@ -465,15 +465,15 @@ func (ca *CertificateAuthorityImpl) IssueCertificate(ctx context.Context, csr x5
 	if len(certPEM) == 0 {
 		err = core.InternalServerError("No certificate returned by server")
 		// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
-		ca.log.AuditErr(fmt.Errorf("PEM empty from Signer: serial=[%s] err=[%v]", serialHex, err))
+		ca.log.AuditErr(fmt.Sprintf("PEM empty from Signer: serial=[%s] err=[%v]", serialHex, err))
 		return emptyCert, err
 	}
 
 	block, _ := pem.Decode(certPEM)
 	if block == nil || block.Type != "CERTIFICATE" {
 		err = core.InternalServerError("Invalid certificate value returned")
 		// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
-		ca.log.AuditErr(fmt.Errorf("PEM decode error, aborting: serial=[%s] pem=[%s] err=[%v]",
+		ca.log.AuditErr(fmt.Sprintf("PEM decode error, aborting: serial=[%s] pem=[%s] err=[%v]",
 			serialHex, certPEM, err))
 		return emptyCert, err
 	}
@@ -487,7 +487,7 @@ func (ca *CertificateAuthorityImpl) IssueCertificate(ctx context.Context, csr x5
 	if err != nil {
 		err = core.InternalServerError(err.Error())
 		// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
-		ca.log.AuditErr(fmt.Errorf("Uncaught error, aborting: serial=[%s] pem=[%s] err=[%v]",
+		ca.log.AuditErr(fmt.Sprintf("Uncaught error, aborting: serial=[%s] pem=[%s] err=[%v]",
 			serialHex, certPEM, err))
 		return emptyCert, err
 	}
@@ -497,7 +497,7 @@ func (ca *CertificateAuthorityImpl) IssueCertificate(ctx context.Context, csr x5
 	if err != nil {
 		err = core.InternalServerError(err.Error())
 		// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
-		ca.log.AuditErr(fmt.Errorf(
+		ca.log.AuditErr(fmt.Sprintf(
 			"Failed RPC to store at SA, orphaning certificate: serial=[%s] b64der=[%s] err=[%v], regID=[%d]",
 			serialHex,
 			base64.StdEncoding.EncodeToString(certDER),

cdr/resolver.go

@@ -206,7 +206,7 @@ func (cdr *CAADistributedResolver) LookupCAA(ctx context.Context, domain string)
 			cdr.stats.TimingDuration(fmt.Sprintf("CDR.GPDNS.Latency.%s", ia), time.Since(started))
 			if err != nil {
 				cdr.stats.Inc(fmt.Sprintf("CDR.GPDNS.Failures.%s", ia), 1)
-				cdr.logger.Err(fmt.Sprintf("queryCAA failed [via %s]: %s", ia, err))
+				cdr.logger.AuditErr(fmt.Sprintf("queryCAA failed [via %s]: %s", ia, err))
 			}
 			results <- queryResult{records, err}
 		}(interfaceClient, addr)
@@ -222,7 +222,7 @@ func (cdr *CAADistributedResolver) LookupCAA(ctx context.Context, domain string)
 			failed++
 			if failed > cdr.maxFailures {
 				cdr.stats.Inc("CDR.QuorumFailed", 1)
-				cdr.logger.Err(fmt.Sprintf("%d out of %d CAA queries failed", len(cdr.Clients), failed))
+				cdr.logger.AuditErr(fmt.Sprintf("%d out of %d CAA queries failed", len(cdr.Clients), failed))
 				return nil, r.err
 			}
 		}

cmd/boulder-publisher/main.go

@@ -28,7 +28,7 @@ func main() {
 		}
 
 		if c.Common.CT.IntermediateBundleFilename == "" {
-			logger.Err("No CT submission bundle provided")
+			logger.AuditErr("No CT submission bundle provided")
 			os.Exit(1)
 		}
 		pemBundle, err := core.LoadCertBundle(c.Common.CT.IntermediateBundleFilename)

cmd/expiration-mailer/main.go

@@ -114,14 +114,14 @@ func (m *mailer) updateCertStatus(serial string) error {
 	tx, err := m.dbMap.Begin()
 	if err != nil {
 		err = sa.Rollback(tx, err)
-		m.log.Err(fmt.Sprintf("Error opening transaction for certificate %s: %s", serial, err))
+		m.log.AuditErr(fmt.Sprintf("Error opening transaction for certificate %s: %s", serial, err))
 		return err
 	}
 
 	csObj, err := tx.Get(&core.CertificateStatus{}, serial)
 	if err != nil {
 		err = sa.Rollback(tx, err)
-		m.log.Err(fmt.Sprintf("Error fetching status for certificate %s: %s", serial, err))
+		m.log.AuditErr(fmt.Sprintf("Error fetching status for certificate %s: %s", serial, err))
 		return err
 	}
 	certStatus := csObj.(*core.CertificateStatus)
@@ -130,14 +130,14 @@ func (m *mailer) updateCertStatus(serial string) error {
 	_, err = tx.Update(certStatus)
 	if err != nil {
 		err = sa.Rollback(tx, err)
-		m.log.Err(fmt.Sprintf("Error updating status for certificate %s: %s", serial, err))
+		m.log.AuditErr(fmt.Sprintf("Error updating status for certificate %s: %s", serial, err))
 		return err
 	}
 
 	err = tx.Commit()
 	if err != nil {
 		err = sa.Rollback(tx, err)
-		m.log.Err(fmt.Sprintf("Error committing transaction for certificate %s: %s", serial, err))
+		m.log.AuditErr(fmt.Sprintf("Error committing transaction for certificate %s: %s", serial, err))
 		return err
 	}
 
@@ -173,7 +173,7 @@ func (m *mailer) processCerts(allCerts []core.Certificate) {
 	for regID, certs := range regIDToCerts {
 		reg, err := m.rs.GetRegistration(ctx, regID)
 		if err != nil {
-			m.log.Err(fmt.Sprintf("Error fetching registration %d: %s", regID, err))
+			m.log.AuditErr(fmt.Sprintf("Error fetching registration %d: %s", regID, err))
 			m.stats.Inc("Mailer.Expiration.Errors.GetRegistration", 1, 1.0)
 			continue
 		}
@@ -183,14 +183,14 @@ func (m *mailer) processCerts(allCerts []core.Certificate) {
 			parsedCert, err := x509.ParseCertificate(cert.DER)
 			if err != nil {
 				// TODO(#1420): tell registration about this error
-				m.log.Err(fmt.Sprintf("Error parsing certificate %s: %s", cert.Serial, err))
+				m.log.AuditErr(fmt.Sprintf("Error parsing certificate %s: %s", cert.Serial, err))
 				m.stats.Inc("Mailer.Expiration.Errors.ParseCertificate", 1, 1.0)
 				continue
 			}
 
 			renewed, err := m.certIsRenewed(cert.Serial)
 			if err != nil {
-				m.log.Err(fmt.Sprintf("expiration-mailer: error fetching renewal state: %v", err))
+				m.log.AuditErr(fmt.Sprintf("expiration-mailer: error fetching renewal state: %v", err))
 				// assume not renewed
 			} else if renewed {
 				m.stats.Inc("Mailer.Expiration.Renewed", 1, 1.0)
@@ -207,14 +207,14 @@ func (m *mailer) processCerts(allCerts []core.Certificate) {
 
 		err = m.sendNags(reg.Contact, parsedCerts)
 		if err != nil {
-			m.log.Err(fmt.Sprintf("Error sending nag emails: %s", err))
+			m.log.AuditErr(fmt.Sprintf("Error sending nag emails: %s", err))
 			continue
 		}
 		for _, cert := range parsedCerts {
 			serial := core.SerialToString(cert.SerialNumber)
 			err = m.updateCertStatus(serial)
 			if err != nil {
-				m.log.Err(fmt.Sprintf("Error updating certificate status for %s: %s", serial, err))
+				m.log.AuditErr(fmt.Sprintf("Error updating certificate status for %s: %s", serial, err))
 				m.stats.Inc("Mailer.Expiration.Errors.UpdateCertificateStatus", 1, 1.0)
 				continue
 			}
@@ -255,7 +255,7 @@ func (m *mailer) findExpiringCertificates() error {
 			},
 		)
 		if err != nil {
-			m.log.Err(fmt.Sprintf("expiration-mailer: Error loading certificates: %s", err))
+			m.log.AuditErr(fmt.Sprintf("expiration-mailer: Error loading certificates: %s", err))
 			return err // fatal
 		}
 
@@ -340,7 +340,7 @@ func main() {
 		if s := c.Mailer.NagCheckInterval; s != "" {
 			nagCheckInterval, err = time.ParseDuration(s)
 			if err != nil {
-				logger.Err(fmt.Sprintf("Failed to parse NagCheckInterval string %q: %s", s, err))
+				logger.AuditErr(fmt.Sprintf("Failed to parse NagCheckInterval string %q: %s", s, err))
 				return
 			}
 		}
@@ -349,7 +349,7 @@ func main() {
 		for _, nagDuration := range c.Mailer.NagTimes {
 			dur, err := time.ParseDuration(nagDuration)
 			if err != nil {
-				logger.Err(fmt.Sprintf("Failed to parse nag duration string [%s]: %s", nagDuration, err))
+				logger.AuditErr(fmt.Sprintf("Failed to parse nag duration string [%s]: %s", nagDuration, err))
 				return
 			}
 			nags = append(nags, dur+nagCheckInterval)

cmd/ocsp-responder/main.go

@@ -88,7 +88,7 @@ func (src *DBSource) Response(req *ocsp.Request) ([]byte, bool) {
 		map[string]interface{}{"serial": serialString},
 	)
 	if err != nil && err != sql.ErrNoRows {
-		src.log.Err(fmt.Sprintf("Failed to retrieve response from certificateStatus table: %s", err))
+		src.log.AuditErr(fmt.Sprintf("Failed to retrieve response from certificateStatus table: %s", err))
 	}
 	if err != nil {
 		return nil, false

cmd/ocsp-updater/main.go

@@ -174,13 +174,13 @@ func newUpdater(
 func (updater *OCSPUpdater) sendPurge(der []byte) {
 	cert, err := x509.ParseCertificate(der)
 	if err != nil {
-		updater.log.AuditErr(fmt.Errorf("Failed to parse certificate for cache purge: %s", err))
+		updater.log.AuditErr(fmt.Sprintf("Failed to parse certificate for cache purge: %s", err))
 		return
 	}
 
 	req, err := ocsp.CreateRequest(cert, updater.issuer, nil)
 	if err != nil {
-		updater.log.AuditErr(fmt.Errorf("Failed to create OCSP request for cache purge: %s", err))
+		updater.log.AuditErr(fmt.Sprintf("Failed to create OCSP request for cache purge: %s", err))
 		return
 	}
 
@@ -197,7 +197,7 @@ func (updater *OCSPUpdater) sendPurge(der []byte) {
 
 	err = updater.ccu.Purge(urls)
 	if err != nil {
-		updater.log.AuditErr(fmt.Errorf("Failed to purge OCSP response from CDN: %s", err))
+		updater.log.AuditErr(fmt.Sprintf("Failed to purge OCSP response from CDN: %s", err))
 	}
 }
 
@@ -341,7 +341,7 @@ func (updater *OCSPUpdater) newCertificateTick(ctx context.Context, batchSize in
 	statuses, err := updater.getCertificatesWithMissingResponses(batchSize)
 	if err != nil {
 		updater.stats.Inc("OCSP.Errors.FindMissingResponses", 1, 1.0)
-		updater.log.AuditErr(fmt.Errorf("Failed to find certificates with missing OCSP responses: %s", err))
+		updater.log.AuditErr(fmt.Sprintf("Failed to find certificates with missing OCSP responses: %s", err))
 		return err
 	}
 
@@ -368,21 +368,21 @@ func (updater *OCSPUpdater) revokedCertificatesTick(ctx context.Context, batchSi
 	statuses, err := updater.findRevokedCertificatesToUpdate(batchSize)
 	if err != nil {
 		updater.stats.Inc("OCSP.Errors.FindRevokedCertificates", 1, 1.0)
-		updater.log.AuditErr(fmt.Errorf("Failed to find revoked certificates: %s", err))
+		updater.log.AuditErr(fmt.Sprintf("Failed to find revoked certificates: %s", err))
 		return err
 	}
 
 	for _, status := range statuses {
 		meta, err := updater.generateRevokedResponse(ctx, status)
 		if err != nil {
-			updater.log.AuditErr(fmt.Errorf("Failed to generate revoked OCSP response: %s", err))
+			updater.log.AuditErr(fmt.Sprintf("Failed to generate revoked OCSP response: %s", err))
 			updater.stats.Inc("OCSP.Errors.RevokedResponseGeneration", 1, 1.0)
 			return err
 		}
 		err = updater.storeResponse(meta)
 		if err != nil {
 			updater.stats.Inc("OCSP.Errors.StoreRevokedResponse", 1, 1.0)
-			updater.log.AuditErr(fmt.Errorf("Failed to store OCSP response: %s", err))
+			updater.log.AuditErr(fmt.Sprintf("Failed to store OCSP response: %s", err))
 			continue
 		}
 	}
@@ -393,14 +393,14 @@ func (updater *OCSPUpdater) generateOCSPResponses(ctx context.Context, statuses
 	for _, status := range statuses {
 		meta, err := updater.generateResponse(ctx, status)
 		if err != nil {
-			updater.log.AuditErr(fmt.Errorf("Failed to generate OCSP response: %s", err))
+			updater.log.AuditErr(fmt.Sprintf("Failed to generate OCSP response: %s", err))
 			updater.stats.Inc("OCSP.Errors.ResponseGeneration", 1, 1.0)
 			return err
 		}
 		updater.stats.Inc("OCSP.GeneratedResponses", 1, 1.0)
 		err = updater.storeResponse(meta)
 		if err != nil {
-			updater.log.AuditErr(fmt.Errorf("Failed to store OCSP response: %s", err))
+			updater.log.AuditErr(fmt.Sprintf("Failed to store OCSP response: %s", err))
 			updater.stats.Inc("OCSP.Errors.StoreResponse", 1, 1.0)
 			continue
 		}
@@ -416,7 +416,7 @@ func (updater *OCSPUpdater) oldOCSPResponsesTick(ctx context.Context, batchSize
 	statuses, err := updater.findStaleOCSPResponses(now.Add(-updater.ocspMinTimeToExpiry), batchSize)
 	if err != nil {
 		updater.stats.Inc("OCSP.Errors.FindStaleResponses", 1, 1.0)
-		updater.log.AuditErr(fmt.Errorf("Failed to find stale OCSP responses: %s", err))
+		updater.log.AuditErr(fmt.Sprintf("Failed to find stale OCSP responses: %s", err))
 		return err
 	}
 
@@ -471,22 +471,22 @@ func (updater *OCSPUpdater) missingReceiptsTick(ctx context.Context, batchSize i
 	since := now.Add(-updater.oldestIssuedSCT)
 	serials, err := updater.getSerialsIssuedSince(since, batchSize)
 	if err != nil {
-		updater.log.AuditErr(fmt.Errorf("Failed to get certificate serials: %s", err))
+		updater.log.AuditErr(fmt.Sprintf("Failed to get certificate serials: %s", err))
 		return err
 	}
 
 	for _, serial := range serials {
 		count, err := updater.getNumberOfReceipts(serial)
 		if err != nil {
-			updater.log.AuditErr(fmt.Errorf("Failed to get number of SCT receipts for certificate: %s", err))
+			updater.log.AuditErr(fmt.Sprintf("Failed to get number of SCT receipts for certificate: %s", err))
 			continue
 		}
 		if count >= updater.numLogs {
 			continue
 		}
 		cert, err := updater.sac.GetCertificate(ctx, serial)
 		if err != nil {
-			updater.log.AuditErr(fmt.Errorf("Failed to get certificate: %s", err))
+			updater.log.AuditErr(fmt.Sprintf("Failed to get certificate: %s", err))
 			continue
 		}
 		_ = updater.pubc.SubmitToCT(ctx, cert.DER)
@@ -607,7 +607,7 @@ func main() {
 			go func(loop *looper) {
 				err = loop.loop()
 				if err != nil {
-					auditlogger.AuditErr(err)
+					auditlogger.AuditErr(err.Error())
 				}
 			}(l)
 		}

cmd/orphan-finder/main.go

@@ -62,12 +62,12 @@ func parseLogLine(sa certificateStorage, logger blog.Logger, line string) (found
 	}
 	derStr := b64derOrphan.FindStringSubmatch(line)
 	if len(derStr) <= 1 {
-		logger.Err(fmt.Sprintf("Didn't match regex for b64der: %s", line))
+		logger.AuditErr(fmt.Sprintf("Didn't match regex for b64der: %s", line))
 		return true, false
 	}
 	der, err := base64.StdEncoding.DecodeString(derStr[1])
 	if err != nil {
-		logger.Err(fmt.Sprintf("Couldn't decode b64: %s, [%s]", err, line))
+		logger.AuditErr(fmt.Sprintf("Couldn't decode b64: %s, [%s]", err, line))
 		return true, false
 	}
 	err = checkDER(sa, der)
@@ -82,17 +82,17 @@ func parseLogLine(sa certificateStorage, logger blog.Logger, line string) (found
 	// extract the regID
 	regStr := regOrphan.FindStringSubmatch(line)
 	if len(regStr) <= 1 {
-		logger.Err(fmt.Sprintf("regID variable is empty, [%s]", line))
+		logger.AuditErr(fmt.Sprintf("regID variable is empty, [%s]", line))
 		return true, false
 	}
 	regID, err := strconv.Atoi(regStr[1])
 	if err != nil {
-		logger.Err(fmt.Sprintf("Couldn't parse regID: %s, [%s]", err, line))
+		logger.AuditErr(fmt.Sprintf("Couldn't parse regID: %s, [%s]", err, line))
 		return true, false
 	}
 	_, err = sa.AddCertificate(ctx, der, int64(regID))
 	if err != nil {
-		logger.Err(fmt.Sprintf("Failed to store certificate: %s, [%s]", err, line))
+		logger.AuditErr(fmt.Sprintf("Failed to store certificate: %s, [%s]", err, line))
 		return true, false
 	}
 	return true, true