ocsp.go

Documentation: github.com/letsencrypt/boulder/ca

     1  package ca
     2  
     3  import (
     4  	"context"
     5  	"errors"
     6  	"fmt"
     7  	"strings"
     8  	"sync"
     9  	"time"
    10  
    11  	"github.com/jmhodges/clock"
    12  	"github.com/miekg/pkcs11"
    13  	"github.com/prometheus/client_golang/prometheus"
    14  	"golang.org/x/crypto/ocsp"
    15  
    16  	capb "github.com/letsencrypt/boulder/ca/proto"
    17  	"github.com/letsencrypt/boulder/core"
    18  	berrors "github.com/letsencrypt/boulder/errors"
    19  	"github.com/letsencrypt/boulder/issuance"
    20  	blog "github.com/letsencrypt/boulder/log"
    21  )
    22  
    23  // TODO(#5152): Simplify this when we've fully deprecated old-style IssuerIDs.
    24  type ocspIssuerMaps struct {
    25  	byID     map[issuance.IssuerID]*issuance.Issuer
    26  	byNameID map[issuance.IssuerNameID]*issuance.Issuer
    27  }
    28  
    29  // ocspImpl provides a backing implementation for the OCSP gRPC service.
    30  type ocspImpl struct {
    31  	capb.UnimplementedOCSPGeneratorServer
    32  	issuers        ocspIssuerMaps
    33  	ocspLifetime   time.Duration
    34  	ocspLogQueue   *ocspLogQueue
    35  	log            blog.Logger
    36  	signatureCount *prometheus.CounterVec
    37  	signErrorCount *prometheus.CounterVec
    38  	clk            clock.Clock
    39  }
    40  
    41  // makeOCSPIssuerMaps processes a list of issuers into a set of maps, mapping
    42  // nearly-unique identifiers of those issuers to the issuers themselves. Note
    43  // that, if two issuers have the same nearly-unique ID, the *latter* one in
    44  // the input list "wins".
    45  func makeOCSPIssuerMaps(issuers []*issuance.Issuer) ocspIssuerMaps {
    46  	issuersByID := make(map[issuance.IssuerID]*issuance.Issuer, len(issuers))
    47  	issuersByNameID := make(map[issuance.IssuerNameID]*issuance.Issuer, len(issuers))
    48  	for _, issuer := range issuers {
    49  		issuersByID[issuer.ID()] = issuer
    50  		issuersByNameID[issuer.Cert.NameID()] = issuer
    51  	}
    52  	return ocspIssuerMaps{issuersByID, issuersByNameID}
    53  }
    54  
    55  func NewOCSPImpl(
    56  	issuers []*issuance.Issuer,
    57  	ocspLifetime time.Duration,
    58  	ocspLogMaxLength int,
    59  	ocspLogPeriod time.Duration,
    60  	logger blog.Logger,
    61  	stats prometheus.Registerer,
    62  	signatureCount *prometheus.CounterVec,
    63  	signErrorCount *prometheus.CounterVec,
    64  	clk clock.Clock,
    65  ) (*ocspImpl, error) {
    66  	issuersByID := make(map[issuance.IssuerID]*issuance.Issuer, len(issuers))
    67  	for _, issuer := range issuers {
    68  		issuersByID[issuer.ID()] = issuer
    69  	}
    70  
    71  	var ocspLogQueue *ocspLogQueue
    72  	if ocspLogMaxLength > 0 {
    73  		ocspLogQueue = newOCSPLogQueue(ocspLogMaxLength, ocspLogPeriod, stats, logger)
    74  	}
    75  
    76  	issuerMaps := makeOCSPIssuerMaps(issuers)
    77  
    78  	oi := &ocspImpl{
    79  		issuers:        issuerMaps,
    80  		ocspLifetime:   ocspLifetime,
    81  		ocspLogQueue:   ocspLogQueue,
    82  		log:            logger,
    83  		signatureCount: signatureCount,
    84  		signErrorCount: signErrorCount,
    85  		clk:            clk,
    86  	}
    87  	return oi, nil
    88  }
    89  
    90  // LogOCSPLoop collects OCSP generation log events into bundles, and logs
    91  // them periodically.
    92  func (oi *ocspImpl) LogOCSPLoop() {
    93  	if oi.ocspLogQueue != nil {
    94  		oi.ocspLogQueue.loop()
    95  	}
    96  }
    97  
    98  // Stop asks this ocspImpl to shut down. It must be called after the
    99  // corresponding RPC service is shut down and there are no longer any inflight
   100  // RPCs. It will attempt to drain any logging queues (which may block), and will
   101  // return only when done.
   102  func (oi *ocspImpl) Stop() {
   103  	if oi.ocspLogQueue != nil {
   104  		oi.ocspLogQueue.stop()
   105  	}
   106  }
   107  
   108  // GenerateOCSP produces a new OCSP response and returns it
   109  func (oi *ocspImpl) GenerateOCSP(ctx context.Context, req *capb.GenerateOCSPRequest) (*capb.OCSPResponse, error) {
   110  	// req.Status, req.Reason, and req.RevokedAt are often 0, for non-revoked certs.
   111  	if core.IsAnyNilOrZero(req, req.Serial, req.IssuerID) {
   112  		return nil, berrors.InternalServerError("Incomplete generate OCSP request")
   113  	}
   114  
   115  	serialInt, err := core.StringToSerial(req.Serial)
   116  	if err != nil {
   117  		return nil, err
   118  	}
   119  	serial := serialInt
   120  
   121  	issuer, ok := oi.issuers.byNameID[issuance.IssuerNameID(req.IssuerID)]
   122  	if !ok {
   123  		// TODO(#5152): Remove this fallback to old-style IssuerIDs.
   124  		issuer, ok = oi.issuers.byID[issuance.IssuerID(req.IssuerID)]
   125  		if !ok {
   126  			return nil, fmt.Errorf("This CA doesn't have an issuer cert with ID %d", req.IssuerID)
   127  		}
   128  	}
   129  
   130  	now := oi.clk.Now().Truncate(time.Hour)
   131  	tbsResponse := ocsp.Response{
   132  		Status:       ocspStatusToCode[req.Status],
   133  		SerialNumber: serial,
   134  		ThisUpdate:   now,
   135  		NextUpdate:   now.Add(oi.ocspLifetime - time.Second),
   136  	}
   137  	if tbsResponse.Status == ocsp.Revoked {
   138  		tbsResponse.RevokedAt = time.Unix(0, req.RevokedAtNS)
   139  		tbsResponse.RevocationReason = int(req.Reason)
   140  	}
   141  
   142  	if oi.ocspLogQueue != nil {
   143  		oi.ocspLogQueue.enqueue(serial.Bytes(), now, tbsResponse.Status, tbsResponse.RevocationReason)
   144  	}
   145  
   146  	ocspResponse, err := ocsp.CreateResponse(issuer.Cert.Certificate, issuer.Cert.Certificate, tbsResponse, issuer.Signer)
   147  	if err == nil {
   148  		oi.signatureCount.With(prometheus.Labels{"purpose": "ocsp", "issuer": issuer.Name()}).Inc()
   149  	} else {
   150  		var pkcs11Error *pkcs11.Error
   151  		if errors.As(err, &pkcs11Error) {
   152  			oi.signErrorCount.WithLabelValues("HSM").Inc()
   153  		}
   154  	}
   155  	return &capb.OCSPResponse{Response: ocspResponse}, err
   156  }
   157  
   158  // ocspLogQueue accumulates OCSP logging events and writes several of them
   159  // in a single log line. This reduces the number of log lines and bytes,
   160  // which would otherwise be quite high. As of Jan 2021 we do approximately
   161  // 550 rps of OCSP generation events. We can turn that into about 5.5 rps
   162  // of log lines if we accumulate 100 entries per line, which amounts to about
   163  // 3900 bytes per log line.
   164  // Summary of log line usage:
   165  // serial in hex: 36 bytes, separator characters: 2 bytes, status: 1 byte
   166  // If maxLogLen is less than the length of a single log item, generate
   167  // one log line for every item.
   168  type ocspLogQueue struct {
   169  	// Maximum length, in bytes, of a single log line.
   170  	maxLogLen int
   171  	// Maximum amount of time between OCSP logging events.
   172  	period time.Duration
   173  	queue  chan ocspLog
   174  	// This allows the stop() function to block until we've drained the queue.
   175  	wg     sync.WaitGroup
   176  	depth  prometheus.Gauge
   177  	logger blog.Logger
   178  	clk    clock.Clock
   179  }
   180  
   181  type ocspLog struct {
   182  	serial []byte
   183  	time   time.Time
   184  	status int
   185  	reason int
   186  }
   187  
   188  func newOCSPLogQueue(
   189  	maxLogLen int,
   190  	period time.Duration,
   191  	stats prometheus.Registerer,
   192  	logger blog.Logger,
   193  ) *ocspLogQueue {
   194  	depth := prometheus.NewGauge(
   195  		prometheus.GaugeOpts{
   196  			Name: "ocsp_log_queue_depth",
   197  			Help: "Number of OCSP generation log entries waiting to be written",
   198  		})
   199  	stats.MustRegister(depth)
   200  	olq := ocspLogQueue{
   201  		maxLogLen: maxLogLen,
   202  		period:    period,
   203  		queue:     make(chan ocspLog),
   204  		wg:        sync.WaitGroup{},
   205  		depth:     depth,
   206  		logger:    logger,
   207  		clk:       clock.New(),
   208  	}
   209  	olq.wg.Add(1)
   210  	return &olq
   211  }
   212  
   213  func (olq *ocspLogQueue) enqueue(serial []byte, time time.Time, status, reason int) {
   214  	olq.queue <- ocspLog{
   215  		serial: append([]byte{}, serial...),
   216  		time:   time,
   217  		status: status,
   218  		reason: reason,
   219  	}
   220  }
   221  
   222  // To ensure we don't go over the max log line length, use a safety margin
   223  // equal to the expected length of an entry.
   224  const ocspSingleLogEntryLen = 39
   225  
   226  // loop consumes events from the queue channel, batches them up, and
   227  // logs them in batches of maxLogLen / 39, or every `period`,
   228  // whichever comes first.
   229  func (olq *ocspLogQueue) loop() {
   230  	defer olq.wg.Done()
   231  	done := false
   232  	for !done {
   233  		var builder strings.Builder
   234  		deadline := olq.clk.After(olq.period)
   235  	inner:
   236  		for {
   237  			olq.depth.Set(float64(len(olq.queue)))
   238  			select {
   239  			case ol, ok := <-olq.queue:
   240  				if !ok {
   241  					// Channel was closed, finish.
   242  					done = true
   243  					break inner
   244  				}
   245  				reasonStr := "_"
   246  				if ol.status == ocsp.Revoked {
   247  					reasonStr = fmt.Sprintf("%d", ol.reason)
   248  				}
   249  				fmt.Fprintf(&builder, "%x:%s,", ol.serial, reasonStr)
   250  			case <-deadline:
   251  				break inner
   252  			}
   253  			if builder.Len()+ocspSingleLogEntryLen >= olq.maxLogLen {
   254  				break
   255  			}
   256  		}
   257  		if builder.Len() > 0 {
   258  			olq.logger.AuditInfof("OCSP signed: %s", builder.String())
   259  		}
   260  	}
   261  }
   262  
   263  // stop the loop, and wait for it to finish. This must be called only after
   264  // it's guaranteed that nothing will call enqueue again (for instance, after
   265  // the OCSPGenerator and CertificateAuthority services are shut down with
   266  // no RPCs in flight). Otherwise, enqueue will panic.
   267  // If this is called without previously starting a goroutine running `.loop()`,
   268  // it will block forever.
   269  func (olq *ocspLogQueue) stop() {
   270  	close(olq.queue)
   271  	olq.wg.Wait()
   272  }
   273  
   274  // OCSPGenerator is an interface which exposes both the auto-generated gRPC
   275  // methods and our special-purpose log queue start and stop methods, so that
   276  // they can be called from main without exporting the ocspImpl type.
   277  type OCSPGenerator interface {
   278  	capb.OCSPGeneratorServer
   279  	LogOCSPLoop()
   280  	Stop()
   281  }
   282
View as plain text