From 164e035915e22666cacd978fdc15e313be42d725 Mon Sep 17 00:00:00 2001
From: Aaron Gable <aaron@letsencrypt.org>
Date: Fri, 15 Dec 2023 09:58:34 -0800
Subject: [PATCH] Reduce logging from inflight validation collisions (#7209)

If a client attempts to validate a challenge twice in rapid succession,
we'll kick off two background validation routines. One of these will
complete first, updating the database with success or failure. The other
will fail when it attempts to update the database and finds that there
are no longer any authorizations with that ID in the "pending" state.
Reduce the level at which we log such events, since we don't
particularly care about them.

Fixes https://github.com/letsencrypt/boulder/issues/3995
---
 ra/ra.go | 14 ++++++++------
 sa/sa.go |  2 +-
 2 files changed, 9 insertions(+), 7 deletions(-)

diff --git a/ra/ra.go b/ra/ra.go
index b9aa6ed0d..5e43d9c3b 100644
--- a/ra/ra.go
+++ b/ra/ra.go
@@ -1747,10 +1747,7 @@ func (ra *RegistrationAuthorityImpl) recordValidation(ctx context.Context, authI
 		ValidationRecords: vr.Records,
 		ValidationError:   vr.Problems,
 	})
-	if err != nil {
-		return err
-	}
-	return nil
+	return err
 }
 
 // PerformValidation initiates validation for a specific challenge associated
@@ -1889,8 +1886,13 @@ func (ra *RegistrationAuthorityImpl) PerformValidation(
 
 		err = ra.recordValidation(vaCtx, authz.ID, authz.Expires, challenge)
 		if err != nil {
-			ra.log.AuditErrf("Could not record updated validation: regID=[%d] authzID=[%s] err=[%s]",
-				authz.RegistrationID, authz.ID, err)
+			if errors.Is(err, berrors.AlreadyRevoked) {
+				ra.log.Infof("Didn't record already-finalized validation: regID=[%d] authzID=[%s] err=[%s]",
+					authz.RegistrationID, authz.ID, err)
+			} else {
+				ra.log.AuditErrf("Failed to record validation: regID=[%d] authzID=[%s] err=[%s]",
+					authz.RegistrationID, authz.ID, err)
+			}
 		}
 	}(authz)
 	return bgrpc.AuthzToPB(authz)
diff --git a/sa/sa.go b/sa/sa.go
index 989e48564..982f5a3ed 100644
--- a/sa/sa.go
+++ b/sa/sa.go
@@ -784,7 +784,7 @@ func (ssa *SQLStorageAuthority) FinalizeAuthorization2(ctx context.Context, req
 		return nil, err
 	}
 	if rows == 0 {
-		return nil, berrors.NotFoundError("authorization with id %d not found", req.Id)
+		return nil, berrors.NotFoundError("no pending authorization with id %d", req.Id)
 	} else if rows > 1 {
 		return nil, berrors.InternalServerError("multiple rows updated for authorization id %d", req.Id)
 	}