Reduce nonce redemption flake by giving WFE time to mark SubConns READY (#8442)

In noncebalancer, add documentation and change names to make the roles
played by each type clearer. Unexport the pickerBuilder and picker
types, since they aren't directly referenced anywhere outside of the
package's init function.

In the WFE, move the nonceWellFormed error message upwards into
validNonce, alongside the other errors returned by that function. Change
that same error message to say "malformed" rather than "invalid", to
differentiate it from redemption failures and to match the corresponding
metric label. Replace the JWSInvalidNonce metric label with two
more-specific metric labels JWSNoBackendNonce and JWSExpiredNonce, for
better insight into whether nonce redemption failures are due to
backends shutting down or due to backends expiring old nonces.

Finally, in the python integration tests, increase how long we wait
between retries from 10ms to (up to) 600ms. This gives the WFE's
NonceRedeemer gRPC client enough time to move its SubConns from the
CONNECTING state to the READY state, and in practice seems to eliminate
flaky nonce redemption errors in CI.

Fixes #8385

Author: aarongable

grpc/noncebalancer/noncebalancer.go

@@ -31,49 +31,44 @@ const (
 // balancer.
 //
 // In any case, when the WFE receives this error it will return a badNonce error
-// to the ACME client.
+// to the ACME client. Note that the WFE uses exact pointer comparison to
+// detect that the status it receives is this exact status object, so don't
+// wrap this with fmt.Errorf when returning it.
 var ErrNoBackendsMatchPrefix = status.New(codes.Unavailable, "no backends match the nonce prefix")
 var errMissingPrefixCtxKey = errors.New("nonce.PrefixCtxKey value required in RPC context")
 var errMissingHMACKeyCtxKey = errors.New("nonce.HMACKeyCtxKey value required in RPC context")
 var errInvalidPrefixCtxKeyType = errors.New("nonce.PrefixCtxKey value in RPC context must be a string")
 var errInvalidHMACKeyCtxKeyType = errors.New("nonce.HMACKeyCtxKey value in RPC context must be a byte slice")
 
-// Balancer implements the base.PickerBuilder interface. It's used to create new
-// balancer.Picker instances. It should only be used by nonce-service clients.
-type Balancer struct{}
-
-// Compile-time assertion that *Balancer implements the base.PickerBuilder
-// interface.
-var _ base.PickerBuilder = (*Balancer)(nil)
+// pickerBuilder implements the base.PickerBuilder interface. It's used to
+// create new Picker instances. It should only be used by nonce-service clients.
+type pickerBuilder struct{}
 
 // Build implements the base.PickerBuilder interface. It is called by the gRPC
 // runtime when the balancer is first initialized and when the set of backend
 // (SubConn) addresses changes.
-func (b *Balancer) Build(buildInfo base.PickerBuildInfo) balancer.Picker {
+func (b *pickerBuilder) Build(buildInfo base.PickerBuildInfo) balancer.Picker {
 	if len(buildInfo.ReadySCs) == 0 {
 		// The Picker must be rebuilt if there are no backends available.
 		return base.NewErrPicker(balancer.ErrNoSubConnAvailable)
 	}
-	return &Picker{
+	return &picker{
 		backends: buildInfo.ReadySCs,
 	}
 }
 
-// Picker implements the balancer.Picker interface. It picks a backend (SubConn)
+// picker implements the balancer.Picker interface. It picks a backend (SubConn)
 // based on the nonce prefix contained in each request's Context.
-type Picker struct {
+type picker struct {
 	backends            map[balancer.SubConn]base.SubConnInfo
 	prefixToBackend     map[string]balancer.SubConn
 	prefixToBackendOnce sync.Once
 }
 
-// Compile-time assertion that *Picker implements the balancer.Picker interface.
-var _ balancer.Picker = (*Picker)(nil)
-
 // Pick implements the balancer.Picker interface. It is called by the gRPC
 // runtime for each RPC message. It is responsible for picking a backend
 // (SubConn) based on the context of each RPC message.
-func (p *Picker) Pick(info balancer.PickInfo) (balancer.PickResult, error) {
+func (p *picker) Pick(info balancer.PickInfo) (balancer.PickResult, error) {
 	if len(p.backends) == 0 {
 		// This should never happen, the Picker should only be built when there
 		// are backends available.
@@ -124,6 +119,6 @@ func (p *Picker) Pick(info balancer.PickInfo) (balancer.PickResult, error) {
 
 func init() {
 	balancer.Register(
-		base.NewBalancerBuilder(Name, &Balancer{}, base.Config{}),
+		base.NewBalancerBuilder(Name, &pickerBuilder{}, base.Config{}),
 	)
 }

grpc/noncebalancer/noncebalancer_test.go

@@ -95,7 +95,7 @@ func TestPickerNoSubConnsAvailable(t *testing.T) {
 	test.AssertNil(t, gotPick.SubConn, "subConn should be nil")
 }
 
-func setupTest(noSubConns bool) (*Balancer, balancer.Picker, []*subConn) {
+func setupTest(noSubConns bool) (*pickerBuilder, balancer.Picker, []*subConn) {
 	var subConns []*subConn
 	bi := base.PickerBuildInfo{
 		ReadySCs: make(map[balancer.SubConn]base.SubConnInfo),
@@ -110,7 +110,7 @@ func setupTest(noSubConns bool) (*Balancer, balancer.Picker, []*subConn) {
 		subConns = append(subConns, sc)
 	}
 
-	b := &Balancer{}
+	b := &pickerBuilder{}
 	p := b.Build(bi)
 	return b, p, subConns
 }

test/chisel2.py

@@ -142,16 +142,16 @@ def auth_and_issue(domains, chall_type="dns-01", email=None, cert_output=None, c
     else:
         raise Exception("invalid challenge type %s" % chall_type)
 
-    # Retry up to twice upon badNonce errors
-    for n in range(2):
+    # Make up to three attempts, retrying on badNonce errors
+    for n in range(3):
+        time.sleep(0.2 * n)  # No sleep before the first attempt, then backoff
         try:
             order = client.poll_and_finalize(order)
             if cert_output is not None:
                 with open(cert_output, "w") as f:
                     f.write(order.fullchain_pem)
         except messages.Error as e:
             if e.typ == "urn:ietf:params:acme:error:badNonce":
-                time.sleep(0.01)
                 continue
         else:
             break
@@ -242,15 +242,8 @@ def expect_problem(problem_type, func):
     if len(domains) == 0:
         print(__doc__)
         sys.exit(0)
-    # Retry up to twice upon badNonce errors
-    for n in range(2):
-        try:
-            auth_and_issue(domains)
-        except messages.Error as e:
-            if e.typ == "urn:ietf:params:acme:error:badNonce":
-                time.sleep(0.01)
-                continue
-            print(e)
-            sys.exit(1)
-        else:
-            break
+    try:
+        auth_and_issue(domains)
+    except messages.Error as e:
+        print(e)
+        sys.exit(1)

wfe2/verify.go

@@ -182,27 +182,26 @@ func (wfe *WebFrontEndImpl) validPOSTRequest(request *http.Request) error {
 	return nil
 }
 
-// nonceWellFormed checks a JWS' Nonce header to ensure it is well-formed,
-// otherwise a bad nonce error is returned. This avoids unnecessary RPCs to
-// the nonce redemption service.
-func nonceWellFormed(nonceHeader string, prefixLen int) error {
-	errBadNonce := berrors.BadNonceError("JWS has an invalid anti-replay nonce: %q", nonceHeader)
+// nonceWellFormed checks whether a JWS' Nonce header is well-formed, returning
+// false if it is not. This avoids unnecessary RPCs to the nonce redemption
+// service.
+func nonceWellFormed(nonceHeader string, prefixLen int) bool {
 	if len(nonceHeader) <= prefixLen {
 		// Nonce header was an unexpected length because there is either:
 		// 1) no nonce, or
 		// 2) no nonce material after the prefix.
-		return errBadNonce
+		return false
 	}
 	body, err := base64.RawURLEncoding.DecodeString(nonceHeader[prefixLen:])
 	if err != nil {
 		// Nonce was not valid base64url.
-		return errBadNonce
+		return false
 	}
 	if len(body) != nonce.NonceLen {
 		// Nonce was an unexpected length.
-		return errBadNonce
+		return false
 	}
-	return nil
+	return true
 }
 
 // validNonce checks a JWS' Nonce header to ensure it is one that the
@@ -215,10 +214,9 @@ func (wfe *WebFrontEndImpl) validNonce(ctx context.Context, header jose.Header)
 		return berrors.BadNonceError("JWS has no anti-replay nonce")
 	}
 
-	err := nonceWellFormed(header.Nonce, nonce.PrefixLen)
-	if err != nil {
+	if !nonceWellFormed(header.Nonce, nonce.PrefixLen) {
 		wfe.stats.joseErrorCount.With(prometheus.Labels{"type": "JWSMalformedNonce"}).Inc()
-		return err
+		return berrors.BadNonceError("JWS has a malformed anti-replay nonce: %q", header.Nonce)
 	}
 
 	// Populate the context with the nonce prefix and HMAC key. These are
@@ -230,22 +228,25 @@ func (wfe *WebFrontEndImpl) validNonce(ctx context.Context, header jose.Header)
 	resp, err := wfe.rnc.Redeem(ctx, &noncepb.NonceMessage{Nonce: header.Nonce})
 	if err != nil {
 		rpcStatus, ok := status.FromError(err)
-		if !ok || rpcStatus != nb.ErrNoBackendsMatchPrefix {
-			return fmt.Errorf("failed to redeem nonce: %w", err)
+		if ok && rpcStatus == nb.ErrNoBackendsMatchPrefix {
+			// Getting our sentinel ErrNoBackendsMatchPrefix status.Status means that
+			// the nonce backend which issued this nonce is presently unreachable or
+			// unrecognized by this WFE. As this is a transient failure, the client
+			// should retry their request with a fresh nonce.
+			wfe.stats.nonceNoMatchingBackendCount.Inc()
+			wfe.stats.joseErrorCount.With(prometheus.Labels{"type": "JWSNoBackendNonce"}).Inc()
+			return berrors.BadNonceError("JWS has an invalid anti-replay nonce: %q", header.Nonce)
 		}
 
-		// ErrNoBackendsMatchPrefix suggests that the nonce backend, which
-		// issued this nonce, is presently unreachable or unrecognized by
-		// this WFE. As this is a transient failure, the client should retry
-		// their request with a fresh nonce.
-		resp = &noncepb.ValidMessage{Valid: false}
-		wfe.stats.nonceNoMatchingBackendCount.Inc()
+		// We don't recognize this error, so just pass it upwards.
+		return fmt.Errorf("failed to redeem nonce: %w", err)
 	}
 
 	if !resp.Valid {
-		wfe.stats.joseErrorCount.With(prometheus.Labels{"type": "JWSInvalidNonce"}).Inc()
-		return berrors.BadNonceError("JWS has an invalid anti-replay nonce: %q", header.Nonce)
+		wfe.stats.joseErrorCount.With(prometheus.Labels{"type": "JWSExpiredNonce"}).Inc()
+		return berrors.BadNonceError("JWS has an expired anti-replay nonce: %q", header.Nonce)
 	}
+
 	return nil
 }
 

wfe2/verify_test.go

@@ -14,7 +14,9 @@ import (
 	"strings"
 	"testing"
 
+	"github.com/go-jose/go-jose/v4"
 	"github.com/prometheus/client_golang/prometheus"
+	"google.golang.org/grpc"
 
 	"github.com/letsencrypt/boulder/core"
 	corepb "github.com/letsencrypt/boulder/core/proto"
@@ -26,9 +28,6 @@ import (
 	sapb "github.com/letsencrypt/boulder/sa/proto"
 	"github.com/letsencrypt/boulder/test"
 	"github.com/letsencrypt/boulder/web"
-
-	"github.com/go-jose/go-jose/v4"
-	"google.golang.org/grpc"
 )
 
 // sigAlgForKey uses `signatureAlgorithmForKey` but fails immediately using the
@@ -204,8 +203,9 @@ func (rs requestSigner) missingNonce() *jose.JSONWebSignature {
 	return jws
 }
 
-// invalidNonce returns an otherwise well-signed request with an invalid nonce.
-func (rs requestSigner) invalidNonce() *jose.JSONWebSignature {
+// expiredNonce returns an otherwise well-signed request with a nonce that the
+// nonce service doesn't remember giving out (i.e. is expired).
+func (rs requestSigner) expiredNonce() *jose.JSONWebSignature {
 	privateKey := loadKey(rs.t, []byte(test1KeyPrivatePEM))
 	jwk := &jose.JSONWebKey{
 		Key:       privateKey,
@@ -710,23 +710,26 @@ func TestValidNonce(t *testing.T) {
 			Name:          "Malformed nonce in JWS",
 			JWS:           signer.malformedNonce(),
 			WantErrType:   berrors.BadNonce,
-			WantErrDetail: "JWS has an invalid anti-replay nonce: \"im-a-nonce\"",
+			WantErrDetail: "JWS has a malformed anti-replay nonce: \"im-a-nonce\"",
 			WantStatType:  "JWSMalformedNonce",
 		},
 		{
 			Name:          "Canned nonce shorter than prefixLength in JWS",
 			JWS:           signer.shortNonce(),
 			WantErrType:   berrors.BadNonce,
-			WantErrDetail: "JWS has an invalid anti-replay nonce: \"woww\"",
+			WantErrDetail: "JWS has a malformed anti-replay nonce: \"woww\"",
 			WantStatType:  "JWSMalformedNonce",
 		},
 		{
-			Name:          "Invalid nonce in JWS (test/config-next)",
-			JWS:           signer.invalidNonce(),
+			Name:          "Expired nonce in JWS",
+			JWS:           signer.expiredNonce(),
 			WantErrType:   berrors.BadNonce,
-			WantErrDetail: "JWS has an invalid anti-replay nonce: \"mlolmlol3ov77I5Ui-cdaY_k8IcjK58FvbG0y_BCRrx5rGQ8rjA\"",
-			WantStatType:  "JWSInvalidNonce",
+			WantErrDetail: "JWS has an expired anti-replay nonce: \"mlolmlol3ov77I5Ui-cdaY_k8IcjK58FvbG0y_BCRrx5rGQ8rjA\"",
+			WantStatType:  "JWSExpiredNonce",
 		},
+		// We don't have a test case for "invalid" (i.e. no backend matching the
+		// prefix) because the unit tests don't use the noncebalancer that does
+		// that routing.
 		{
 			Name: "Valid nonce in JWS",
 			JWS:  goodJWS,
@@ -1349,12 +1352,12 @@ func TestValidJWSForKey(t *testing.T) {
 			WantStatType:  "JWSAlgorithmCheckFailed",
 		},
 		{
-			Name:          "JWS with an invalid nonce (test/config-next)",
-			JWS:           bJSONWebSignature{signer.invalidNonce()},
+			Name:          "JWS with an expired nonce",
+			JWS:           bJSONWebSignature{signer.expiredNonce()},
 			JWK:           goodJWK,
 			WantErrType:   berrors.BadNonce,
-			WantErrDetail: "JWS has an invalid anti-replay nonce: \"mlolmlol3ov77I5Ui-cdaY_k8IcjK58FvbG0y_BCRrx5rGQ8rjA\"",
-			WantStatType:  "JWSInvalidNonce",
+			WantErrDetail: "JWS has an expired anti-replay nonce: \"mlolmlol3ov77I5Ui-cdaY_k8IcjK58FvbG0y_BCRrx5rGQ8rjA\"",
+			WantStatType:  "JWSExpiredNonce",
 		},
 		{
 			Name:          "JWS with broken signature",