rocsp: when Redis lookup fails, live sign (#6478)

Fixes #6455

.golangci.yml

@@ -30,6 +30,7 @@ linters-settings:
           - (github.com/letsencrypt/boulder/log.Logger).Debugf
           - (github.com/letsencrypt/boulder/log.Logger).AuditInfof
           - (github.com/letsencrypt/boulder/log.Logger).AuditErrf
+          - (github.com/letsencrypt/boulder/ocsp/responder).SampledError
   staticcheck:
     # SA1019: Using a deprecated function, variable, constant or field
     # SA6003: Converting a string to a slice of runes before ranging over it

ocsp/responder/redis/redis_source.go

@@ -106,10 +106,11 @@ func (src *redisSource) Response(ctx context.Context, req *ocsp.Request) (*respo
 	if err != nil {
 		if errors.Is(err, rocsp.ErrRedisNotFound) {
 			src.counter.WithLabelValues("not_found").Inc()
-			return src.signAndSave(ctx, req, causeNotFound)
+		} else {
+			src.counter.WithLabelValues("lookup_error").Inc()
+			responder.SampledError(src.log, 1000, "looking for cached response: %s", err)
 		}
-		src.counter.WithLabelValues("lookup_error").Inc()
-		return nil, err
+		return src.signAndSave(ctx, req, causeNotFound)
 	}
 
 	resp, err := ocsp.ParseResponse(respBytes, nil)

ocsp/responder/redis/redis_source_test.go

@@ -15,6 +15,7 @@ import (
 	ocsp_test "github.com/letsencrypt/boulder/ocsp/test"
 	"github.com/letsencrypt/boulder/rocsp"
 	"github.com/letsencrypt/boulder/test"
+	"github.com/prometheus/client_golang/prometheus"
 	"golang.org/x/crypto/ocsp"
 )
 
@@ -91,18 +92,32 @@ func (er errorRedis) GetResponse(ctx context.Context, serial string) ([]byte, er
 }
 
 func (er errorRedis) StoreResponse(ctx context.Context, resp *ocsp.Response) error {
-	panic("shouldn't happen")
+	return nil
 }
 
+// When the initial Redis lookup returns an error, we should
+// proceed with live signing.
 func TestQueryError(t *testing.T) {
-	src, err := NewRedisSource(nil, panicSource{}, time.Second, clock.NewFake(), metrics.NoopRegisterer, log.NewMock())
+	serial := big.NewInt(314159)
+	thisUpdate := time.Now().Truncate(time.Second).UTC()
+	resp, _, err := ocsp_test.FakeResponse(ocsp.Response{
+		SerialNumber: serial,
+		Status:       ocsp.Good,
+		ThisUpdate:   thisUpdate,
+	})
+	test.AssertNotError(t, err, "making fake response")
+	source := echoSource{resp: resp}
+
+	src, err := NewRedisSource(nil, source, time.Second, clock.NewFake(), metrics.NoopRegisterer, log.NewMock())
 	test.AssertNotError(t, err, "making source")
 	src.client = errorRedis{}
 
-	_, err = src.Response(context.Background(), &ocsp.Request{
-		SerialNumber: big.NewInt(314159),
+	receivedResp, err := src.Response(context.Background(), &ocsp.Request{
+		SerialNumber: serial,
 	})
-	test.AssertError(t, err, "expected error when Redis errored")
+	test.AssertNotError(t, err, "expected no error when Redis errored")
+	test.AssertDeepEquals(t, resp.Raw, receivedResp.Raw)
+	test.AssertMetricWithLabelsEquals(t, src.counter, prometheus.Labels{"result": "lookup_error"}, 1)
 }
 
 type garbleRedis struct{}
@@ -129,14 +144,8 @@ func TestParseError(t *testing.T) {
 	}
 }
 
-type errorSigner struct{}
-
-func (es errorSigner) Response(ctx context.Context, req *ocsp.Request) (*responder.Response, error) {
-	return nil, errors.New("cannot sign; lost my pen")
-}
-
 func TestSignError(t *testing.T) {
-	src, err := NewRedisSource(nil, errorSigner{}, time.Second, clock.NewFake(), metrics.NoopRegisterer, log.NewMock())
+	src, err := NewRedisSource(nil, errorSource{}, time.Second, clock.NewFake(), metrics.NoopRegisterer, log.NewMock())
 	test.AssertNotError(t, err, "making source")
 	src.client = &notFoundRedis{nil}
 
@@ -230,7 +239,7 @@ func TestCertificateNotFound(t *testing.T) {
 
 func TestNoServeStale(t *testing.T) {
 	clk := clock.NewFake()
-	src, err := NewRedisSource(nil, errorSigner{}, time.Second, clk, metrics.NoopRegisterer, log.NewMock())
+	src, err := NewRedisSource(nil, errorSource{}, time.Second, clk, metrics.NoopRegisterer, log.NewMock())
 	test.AssertNotError(t, err, "making source")
 	staleRedis := &staleRedis{
 		serialStored: nil,

ocsp/responder/responder.go

@@ -153,12 +153,16 @@ var hashToString = map[crypto.Hash]string{
 	crypto.SHA512: "SHA512",
 }
 
-func (rs Responder) sampledError(format string, a ...interface{}) {
-	if rs.sampleRate > 0 && rand.Intn(rs.sampleRate) == 0 {
-		rs.log.Errf(format, a...)
+func SampledError(log blog.Logger, sampleRate int, format string, a ...interface{}) {
+	if sampleRate > 0 && rand.Intn(sampleRate) == 0 {
+		log.Errf(format, a...)
 	}
 }
 
+func (rs Responder) sampledError(format string, a ...interface{}) {
+	SampledError(rs.log, rs.sampleRate, format, a...)
+}
+
 // A Responder can process both GET and POST requests. The mapping from an OCSP
 // request to an OCSP response is done by the Source; the Responder simply
 // decodes the request, and passes back whatever response is provided by the