This implements more sleeps when clients are expected to poll

Specifically this adds two additional delay points:
- Between completing validation but before updating the order state
- After signing the certificate and before marking it as ready

The first is controlled by the existing PEBBLE_VA_* environment
variables, and the second is controlled by equivalent PEBBLE_CA_*
environment variables.

It also corrects a minor typo in the README.md (default is 5s,
not 15s), and removes shadowing of the internal `len` function.

Author: squizzling

README.md

@@ -130,16 +130,17 @@ services:
     - 15000:15000  # Management port
   environment:
     - PEBBLE_VA_NOSLEEP=1
+    - PEBBLE_CA_NOSLEEP=1
   volumes:
     - ./my-pebble-config.json:/test/my-pebble-config.json
 ```
 
 With a Docker command:
 
 ```bash
-docker run -e "PEBBLE_VA_NOSLEEP=1" letsencrypt/pebble
+docker run -e "PEBBLE_VA_NOSLEEP=1" -e "PEBBLE_CA_NOSLEEP=1" letsencrypt/pebble
 # or
-docker run -e "PEBBLE_VA_NOSLEEP=1" --mount src=$(pwd)/my-pebble-config.json,target=/test/my-pebble-config.json,type=bind letsencrypt/pebble pebble -config /test/my-pebble-config.json
+docker run -e "PEBBLE_VA_NOSLEEP=1" -e "PEBBLE_CA_NOSLEEP=1" --mount src=$(pwd)/my-pebble-config.json,target=/test/my-pebble-config.json,type=bind letsencrypt/pebble pebble -config /test/my-pebble-config.json
 ```
 
 **Note**: The Pebble dockerfile uses [multi-stage builds](https://docs.docker.com/develop/develop-images/multistage-build/) and requires Docker CE 17.05.0-ce or newer.
@@ -197,19 +198,33 @@ for more information.
 
 ### Testing at full speed
 
-By default Pebble will sleep a random number of seconds (from 0 to 15) between
-individual challenge validation attempts. This ensures clients don't make
-assumptions about when the challenge is solved from the CA side by observing
-a single request for a challenge response. Instead clients must poll the
-challenge to observe the state since the CA may send many validation requests.
+By default Pebble will sleep a random number of seconds (from 0 to 5) during
+specific stages of the workflow. This ensures clients don't make assumptions
+about the state of the system based on observing external behavior. Instead,
+clients must poll at the appropriate time.
 
-To test issuance "at full speed" with no artificial sleeps set the environment
-variable `PEBBLE_VA_NOSLEEP` to `1`. E.g.
+These sleeps occur at the following 3 points:
 
-`PEBBLE_VA_NOSLEEP=1 pebble -config ./test/config/pebble-config.json`
+1. Before attempting to perform a validation
+2. Between validating and updating the order state
+3. After creating the certificate and marking it as ready
 
-The maximal number of seconds to sleep can be configured by defining
-`PEBBLE_VA_SLEEPTIME`. It must be set to a positive integer.
+To test "at full speed"  with no artificial sleeps, set the following environment
+variables:
+
+- `PEBBLE_VA_NOSLEEP` set to `1` to disable #1 and #2
+- `PEBBLE_CA_NOSLEEP` set to `1` to disable #3
+
+The maximum duration can also be controlled via the following environment variables,
+both of which are specified in seconds:
+
+- `PEBBLE_VA_SLEEPTIME` for #1 and #2
+- `PEBBLE_CA_SLEEPTIME` for #3
+
+For example, to disable sleeping in validation, and cap the certificate issuance
+time to 5 seconds, use:
+
+`PEBBLE_VA_NOSLEEP=1 PEBBLE_CA_SLEEPTIME=5 pebble -config ./test/config/pebble-config.json`
 
 ### Skipping Validation
 

ca/ca.go

@@ -2,7 +2,7 @@ package ca
 
 import (
 	"crypto"
-	"crypto/rand"
+	crand "crypto/rand"
 	"crypto/rsa"
 	"crypto/sha1"
 	"crypto/x509"
@@ -13,7 +13,10 @@ import (
 	"log"
 	"math"
 	"math/big"
+	mrand "math/rand"
 	"net"
+	"os"
+	"strconv"
 	"strings"
 	"time"
 
@@ -25,12 +28,33 @@ import (
 const (
 	rootCAPrefix         = "Pebble Root CA "
 	intermediateCAPrefix = "Pebble Intermediate CA "
+
+	// noSleepEnvVar defines the environment variable name used to signal that the
+	// CA should *not* sleep before transitioning an order from processing to ready.
+	// Set this to 1 when you invoke Pebble if you wish completion to be done at full
+	// speed, e.g.:
+	//   PEBBLE_CA_NOSLEEP=1 pebble
+	noSleepEnvVar = "PEBBLE_CA_NOSLEEP"
+
+	// sleepTimeEnvVar defines the environment variable name used to set the time
+	// the CA should sleep between transitioning an order from processing to ready
+	// (if not disabled). Set this e.g. to 5 when you invoke Pebble if you wish the
+	// delays to be between 0 and 10 seconds (instead of between 0 and 5 seconds):
+	//   PEBBLE_CA_SLEEPTIME=5 pebble
+	sleepTimeEnvVar = "PEBBLE_CA_SLEEPTIME"
+
+	// defaultSleepTime defines the default sleep time (in seconds) between
+	// transitioning an order from processing to ready.
+	// variables PEBBLE_CA_NOSLEEP resp. PEBBLE_CA_SLEEPTIME (see above).
+	defaultSleepTime = 5
 )
 
 type CAImpl struct {
 	log              *log.Logger
 	db               *db.MemoryStore
 	ocspResponderURL string
+	sleep            bool
+	sleepTime        int
 
 	chains []*chain
 }
@@ -57,7 +81,7 @@ type issuer struct {
 }
 
 func makeSerial() *big.Int {
-	serial, err := rand.Int(rand.Reader, big.NewInt(math.MaxInt64))
+	serial, err := crand.Int(crand.Reader, big.NewInt(math.MaxInt64))
 	if err != nil {
 		panic(fmt.Sprintf("unable to create random serial number: %s", err.Error()))
 	}
@@ -92,7 +116,7 @@ func makeSubjectKeyID(key crypto.PublicKey) ([]byte, error) {
 
 // makeKey creates a new 2048 bit RSA private key and a Subject Key Identifier
 func makeKey() (*rsa.PrivateKey, []byte, error) {
-	key, err := rsa.GenerateKey(rand.Reader, 2048)
+	key, err := rsa.GenerateKey(crand.Reader, 2048)
 	if err != nil {
 		return nil, nil, err
 	}
@@ -133,7 +157,7 @@ func (ca *CAImpl) makeRootCert(
 		parent = template
 	}
 
-	der, err := x509.CreateCertificate(rand.Reader, template, parent, subjectKey.Public(), signerKey)
+	der, err := x509.CreateCertificate(crand.Reader, template, parent, subjectKey.Public(), signerKey)
 	if err != nil {
 		return nil, err
 	}
@@ -307,7 +331,7 @@ func (ca *CAImpl) newCertificate(domains []string, ips []net.IP, key crypto.Publ
 		template.OCSPServer = []string{ca.ocspResponderURL}
 	}
 
-	der, err := x509.CreateCertificate(rand.Reader, template, issuer.cert.Cert, key, issuer.key)
+	der, err := x509.CreateCertificate(crand.Reader, template, issuer.cert.Cert, key, issuer.key)
 	if err != nil {
 		return nil, err
 	}
@@ -342,8 +366,26 @@ func (ca *CAImpl) newCertificate(domains []string, ips []net.IP, key crypto.Publ
 
 func New(log *log.Logger, db *db.MemoryStore, ocspResponderURL string, alternateRoots int, chainLength int) *CAImpl {
 	ca := &CAImpl{
-		log: log,
-		db:  db,
+		log:       log,
+		db:        db,
+		sleep:     true,
+		sleepTime: defaultSleepTime,
+	}
+
+	// Read the PEBBLE_CA_NOSLEEP environment variable string
+	noSleep := os.Getenv(noSleepEnvVar)
+	// If it is set to something true-like, then the CA shouldn't sleep
+	switch strings.ToLower(noSleep) {
+	case "1", "true":
+		ca.sleep = false
+		ca.log.Printf("Disabling random CA sleeps")
+	}
+
+	sleepTime := os.Getenv(sleepTimeEnvVar)
+	sleepTimeInt, err := strconv.Atoi(sleepTime)
+	if err == nil && ca.sleep && sleepTimeInt >= 1 {
+		ca.sleepTime = sleepTimeInt
+		ca.log.Printf("Setting maximum random CA sleep time to %d seconds", ca.sleepTime)
 	}
 
 	if ocspResponderURL != "" {
@@ -398,6 +440,12 @@ func (ca *CAImpl) CompleteOrder(order *core.Order) {
 	}
 	ca.log.Printf("Issued certificate serial %s for order %s\n", cert.ID, order.ID)
 
+	if ca.sleep {
+		sleepLen := time.Duration(mrand.Intn(ca.sleepTime))
+		ca.log.Printf("Sleeping for %s seconds before marking complete", time.Second*sleepLen)
+		time.Sleep(time.Second * sleepLen)
+	}
+
 	// Lock and update the order to store the issued certificate
 	order.Lock()
 	order.CertificateObject = cert

va/va.go

@@ -24,6 +24,7 @@ import (
 	"github.com/miekg/dns"
 
 	"github.com/letsencrypt/challtestsrv"
+
 	"github.com/letsencrypt/pebble/acme"
 	"github.com/letsencrypt/pebble/core"
 )
@@ -132,8 +133,8 @@ func New(
 	// Read the PEBBLE_VA_NOSLEEP environment variable string
 	noSleep := os.Getenv(noSleepEnvVar)
 	// If it is set to something true-like, then the VA shouldn't sleep
-	switch noSleep {
-	case "1", "true", "True", "TRUE":
+	switch strings.ToLower(noSleep) {
+	case "1", "true":
 		va.sleep = false
 		va.log.Printf("Disabling random VA sleeps")
 	}
@@ -251,6 +252,13 @@ func (va VAImpl) process(task *vaTask) {
 	}
 
 	err := va.firstError(results)
+
+	if va.sleep {
+		sleepLen := time.Duration(rand.Intn(va.sleepTime))
+		va.log.Printf("Sleeping for %s seconds before marking valid", time.Second*sleepLen)
+		time.Sleep(time.Second * sleepLen)
+	}
+
 	// If one of the results was an error, the challenge fails
 	if err != nil {
 		va.setAuthzInvalid(authz, chal, err)
@@ -268,9 +276,9 @@ func (va VAImpl) process(task *vaTask) {
 func (va VAImpl) performValidation(task *vaTask, results chan<- *core.ValidationRecord) {
 	if va.sleep {
 		// Sleep for a random amount of time between 0 and va.sleepTime seconds
-		len := time.Duration(rand.Intn(va.sleepTime))
-		va.log.Printf("Sleeping for %s seconds before validating", time.Second*len)
-		time.Sleep(time.Second * len)
+		sleepLen := time.Duration(rand.Intn(va.sleepTime))
+		va.log.Printf("Sleeping for %s seconds before attempting validation", time.Second*sleepLen)
+		time.Sleep(time.Second * sleepLen)
 	}
 
 	// If `alwaysValid` is true then return a validation record immediately