Profile the nonce service (#2135)

Adds `NonceService` metrics output.

nonce/nonce.go

@@ -8,6 +8,9 @@ import (
 	"errors"
 	"math/big"
 	"sync"
+	"time"
+
+	"github.com/letsencrypt/boulder/metrics"
 )
 
 // MaxUsed defines the maximum number of Nonces we're willing to hold in
@@ -25,10 +28,11 @@ type NonceService struct {
 	used     map[int64]bool
 	gcm      cipher.AEAD
 	maxUsed  int
+	stats    metrics.Scope
 }
 
 // NewNonceService constructs a NonceService with defaults
-func NewNonceService() (*NonceService, error) {
+func NewNonceService(parent metrics.Scope) (*NonceService, error) {
 	key := make([]byte, 16)
 	if _, err := rand.Read(key); err != nil {
 		return nil, err
@@ -49,6 +53,7 @@ func NewNonceService() (*NonceService, error) {
 		used:     make(map[int64]bool, MaxUsed),
 		gcm:      gcm,
 		maxUsed:  MaxUsed,
+		stats:    parent.NewScope("NonceService"),
 	}, nil
 }
 
@@ -107,18 +112,21 @@ func (ns *NonceService) Nonce() (string, error) {
 	ns.latest++
 	latest := ns.latest
 	ns.mu.Unlock()
+	defer ns.stats.Inc("Generated", 1)
 	return ns.encrypt(latest)
 }
 
 // minUsed returns the lowest key in the used map. Requires that a lock be held
 // by caller.
 func (ns *NonceService) minUsed() int64 {
+	s := time.Now()
 	min := ns.latest
 	for t := range ns.used {
 		if t < min {
 			min = t
 		}
 	}
+	ns.stats.TimingDuration("LinearScan.Latency", time.Since(s))
 	return min
 }
 
@@ -127,28 +135,34 @@ func (ns *NonceService) minUsed() int64 {
 func (ns *NonceService) Valid(nonce string) bool {
 	c, err := ns.decrypt(nonce)
 	if err != nil {
+		ns.stats.Inc("Invalid.Decrypt", 1)
 		return false
 	}
 
 	ns.mu.Lock()
 	defer ns.mu.Unlock()
 	if c > ns.latest {
+		ns.stats.Inc("Invalid.TooHigh", 1)
 		return false
 	}
 
 	if c <= ns.earliest {
+		ns.stats.Inc("Invalid.TooLow", 1)
 		return false
 	}
 
 	if ns.used[c] {
+		ns.stats.Inc("Invalid.AlreadyUsed", 1)
 		return false
 	}
 
 	ns.used[c] = true
 	if len(ns.used) > ns.maxUsed {
+		ns.stats.Inc("LinearScan.Full", 1)
 		ns.earliest = ns.minUsed()
 		delete(ns.used, ns.earliest)
 	}
 
+	ns.stats.Inc("Valid", 1)
 	return true
 }

nonce/nonce_test.go

@@ -4,11 +4,12 @@ import (
 	"fmt"
 	"testing"
 
+	"github.com/letsencrypt/boulder/metrics"
 	"github.com/letsencrypt/boulder/test"
 )
 
 func TestValidNonce(t *testing.T) {
-	ns, err := NewNonceService()
+	ns, err := NewNonceService(metrics.NewNoopScope())
 	test.AssertNotError(t, err, "Could not create nonce service")
 	n, err := ns.Nonce()
 	test.AssertNotError(t, err, "Could not create nonce")
@@ -16,7 +17,7 @@ func TestValidNonce(t *testing.T) {
 }
 
 func TestAlreadyUsed(t *testing.T) {
-	ns, err := NewNonceService()
+	ns, err := NewNonceService(metrics.NewNoopScope())
 	test.AssertNotError(t, err, "Could not create nonce service")
 	n, err := ns.Nonce()
 	test.AssertNotError(t, err, "Could not create nonce")
@@ -25,7 +26,7 @@ func TestAlreadyUsed(t *testing.T) {
 }
 
 func TestRejectMalformed(t *testing.T) {
-	ns, err := NewNonceService()
+	ns, err := NewNonceService(metrics.NewNoopScope())
 	test.AssertNotError(t, err, "Could not create nonce service")
 	n, err := ns.Nonce()
 	test.AssertNotError(t, err, "Could not create nonce")
@@ -33,15 +34,15 @@ func TestRejectMalformed(t *testing.T) {
 }
 
 func TestRejectShort(t *testing.T) {
-	ns, err := NewNonceService()
+	ns, err := NewNonceService(metrics.NewNoopScope())
 	test.AssertNotError(t, err, "Could not create nonce service")
 	test.Assert(t, !ns.Valid("aGkK"), "Accepted an invalid nonce")
 }
 
 func TestRejectUnknown(t *testing.T) {
-	ns1, err := NewNonceService()
+	ns1, err := NewNonceService(metrics.NewNoopScope())
 	test.AssertNotError(t, err, "Could not create nonce service")
-	ns2, err := NewNonceService()
+	ns2, err := NewNonceService(metrics.NewNoopScope())
 	test.AssertNotError(t, err, "Could not create nonce service")
 
 	n, err := ns1.Nonce()
@@ -50,7 +51,7 @@ func TestRejectUnknown(t *testing.T) {
 }
 
 func TestRejectTooLate(t *testing.T) {
-	ns, err := NewNonceService()
+	ns, err := NewNonceService(metrics.NewNoopScope())
 	test.AssertNotError(t, err, "Could not create nonce service")
 
 	ns.latest = 2
@@ -61,7 +62,7 @@ func TestRejectTooLate(t *testing.T) {
 }
 
 func TestRejectTooEarly(t *testing.T) {
-	ns, err := NewNonceService()
+	ns, err := NewNonceService(metrics.NewNoopScope())
 	test.AssertNotError(t, err, "Could not create nonce service")
 	ns.maxUsed = 2
 

wfe/wfe.go

@@ -23,6 +23,7 @@ import (
 	"github.com/letsencrypt/boulder/core"
 	"github.com/letsencrypt/boulder/goodkey"
 	blog "github.com/letsencrypt/boulder/log"
+	"github.com/letsencrypt/boulder/metrics"
 	"github.com/letsencrypt/boulder/nonce"
 	"github.com/letsencrypt/boulder/probs"
 	"github.com/letsencrypt/boulder/revocation"
@@ -95,7 +96,8 @@ func NewWebFrontEndImpl(
 	keyPolicy goodkey.KeyPolicy,
 	logger blog.Logger,
 ) (WebFrontEndImpl, error) {
-	nonceService, err := nonce.NewNonceService()
+	scope := metrics.NewStatsdScope(stats, "WFE")
+	nonceService, err := nonce.NewNonceService(scope)
 	if err != nil {
 		return WebFrontEndImpl{}, err
 	}