Handle order status as a property of assoc. authz status. (#128)

This PR updates the way Pebble handles an Order's status field to closer match the way we handle it in Boulder. This means the order's status is considered to be a calculated field derived based on the order's error/beganProcessing/certificate fields and the status/expires/error of the order's associated authorizations. Along the way the new "Ready" status was implemented. This PR also addresses the problem of the order status not being updated when an authorization is failed. Now, an order has a problem details field that is set when an authorization associated with the order has a failed challenge validation.

Resolves #110 and #98

acme/common.go

@@ -7,7 +7,9 @@ const (
 	StatusPending     = "pending"
 	StatusInvalid     = "invalid"
 	StatusValid       = "valid"
+	StatusExpired     = "expired"
 	StatusProcessing  = "processing"
+	StatusReady       = "ready"
 	StatusDeactivated = "deactivated"
 
 	IdentifierDNS = "dns"
@@ -34,14 +36,15 @@ type Account struct {
 
 // An Order is created to request issuance for a CSR
 type Order struct {
-	Status         string       `json:"status"`
-	Expires        string       `json:"expires"`
-	Identifiers    []Identifier `json:"identifiers,omitempty"`
-	Finalize       string       `json:"finalize"`
-	NotBefore      string       `json:"notBefore,omitempty"`
-	NotAfter       string       `json:"notAfter,omitempty"`
-	Authorizations []string     `json:"authorizations"`
-	Certificate    string       `json:"certificate,omitempty"`
+	Status         string          `json:"status"`
+	Error          *ProblemDetails `json:"error,omitempty"`
+	Expires        string          `json:"expires"`
+	Identifiers    []Identifier    `json:"identifiers,omitempty"`
+	Finalize       string          `json:"finalize"`
+	NotBefore      string          `json:"notBefore,omitempty"`
+	NotAfter       string          `json:"notAfter,omitempty"`
+	Authorizations []string        `json:"authorizations"`
+	Certificate    string          `json:"certificate,omitempty"`
 }
 
 // An Authorization is created for each identifier in an order

ca/ca.go

@@ -221,19 +221,17 @@ func New(log *log.Logger, db *db.MemoryStore) *CAImpl {
 }
 
 func (ca *CAImpl) CompleteOrder(order *core.Order) {
-	// Lock the order for writing
-	order.Lock()
-	// If the order isn't pending, produce an error and immediately unlock
-	if order.Status != acme.StatusPending {
-		ca.log.Printf("Error: Asked to complete order %s is not status pending, was status %s",
-			order.ID, order.Status)
-		order.Unlock()
+	// Lock the order for reading
+	order.RLock()
+	// If the order isn't set as beganProcessing produce an error and immediately unlock
+	if !order.BeganProcessing {
+		ca.log.Printf("Error: Asked to complete order %s which had false beganProcessing.",
+			order.ID)
+		order.RUnlock()
 		return
 	}
-	// Otherwise update the order to be in a processing state
-	order.Status = acme.StatusProcessing
 	// Unlock the order again
-	order.Unlock()
+	order.RUnlock()
 
 	// Check the authorizations - this is done by the VA before calling
 	// CompleteOrder but we do it again for robustness sake.
@@ -255,10 +253,8 @@ func (ca *CAImpl) CompleteOrder(order *core.Order) {
 	}
 	ca.log.Printf("Issued certificate serial %s for order %s\n", cert.ID, order.ID)
 
-	// Lock and update the order to valid status and store a cert ID for the wfe
-	// to use to render the certificate URL for the order
+	// Lock and update the order to store the issued certificate
 	order.Lock()
-	order.Status = acme.StatusValid
 	order.CertificateObject = cert
 	order.Unlock()
 }

cmd/pebble/main.go

@@ -47,7 +47,7 @@ func main() {
 	cmd.FailOnError(err, "Reading JSON config file into config structure")
 
 	clk := clock.Default()
-	db := db.NewMemoryStore()
+	db := db.NewMemoryStore(clk)
 	ca := ca.New(logger, db)
 	va := va.New(logger, clk, c.Pebble.HTTPPort, c.Pebble.TLSPort)
 

core/types.go

@@ -10,6 +10,7 @@ import (
 	"sync"
 	"time"
 
+	"github.com/jmhodges/clock"
 	"github.com/letsencrypt/pebble/acme"
 	"gopkg.in/square/go-jose.v2"
 )
@@ -23,9 +24,90 @@ type Order struct {
 	ParsedCSR            *x509.CertificateRequest
 	ExpiresDate          time.Time
 	AuthorizationObjects []*Authorization
+	BeganProcessing      bool
 	CertificateObject    *Certificate
 }
 
+func (o *Order) GetStatus(clk clock.Clock) (string, error) {
+	// Lock the order for reading
+	o.RLock()
+	defer o.RUnlock()
+
+	// If the order has an error set, the status is invalid
+	if o.Error != nil {
+		return acme.StatusInvalid, nil
+	}
+
+	authzStatuses := make(map[string]int)
+
+	for _, authz := range o.AuthorizationObjects {
+		// Lock the authorization for reading
+		authz.RLock()
+		authzStatus := authz.Status
+		authzExpires := authz.ExpiresDate
+		authz.RUnlock()
+
+		authzStatuses[authzStatus]++
+
+		if authzExpires.Before(clk.Now()) {
+			authzStatuses[acme.StatusExpired]++
+		}
+	}
+
+	// An order is invalid if **any** of its authzs are invalid
+	if authzStatuses[acme.StatusInvalid] > 0 {
+		return acme.StatusInvalid, nil
+	}
+
+	// An order is expired if **any** of its authzs are expired
+	if authzStatuses[acme.StatusExpired] > 0 {
+		return acme.StatusInvalid, nil
+	}
+
+	// An order is deactivated if **any** of its authzs are deactivated
+	if authzStatuses[acme.StatusDeactivated] > 0 {
+		return acme.StatusDeactivated, nil
+	}
+
+	// An order is pending if **any** of its authzs are pending
+	if authzStatuses[acme.StatusPending] > 0 {
+		return acme.StatusPending, nil
+	}
+
+	fullyAuthorized := len(o.Names) == authzStatuses[acme.StatusValid]
+
+	// If the order isn't fully authorized we've encountered an internal error:
+	// Above we checked for any invalid or pending authzs and should have returned
+	// early. Somehow we made it this far but also don't have the correct number
+	// of valid authzs.
+	if !fullyAuthorized {
+		return "", fmt.Errorf(
+			"Order has the incorrect number of valid authorizations & no pending, " +
+				"deactivated or invalid authorizations")
+	}
+
+	// If the order is fully authorized and the certificate serial is set then the
+	// order is valid
+	if fullyAuthorized && o.CertificateObject != nil {
+		return acme.StatusValid, nil
+	}
+
+	// If the order is fully authorized, and we have began processing it, then the
+	// order is processing.
+	if fullyAuthorized && o.BeganProcessing {
+		return acme.StatusProcessing, nil
+	}
+
+	// If the order is fully authorized, and we haven't begun processing it, then
+	// the order is pending finalization and status ready.
+	if fullyAuthorized && !o.BeganProcessing {
+		return acme.StatusReady, nil
+	}
+
+	// If none of the above cases match something weird & unexpected has happened.
+	return "", fmt.Errorf("Order is in an unknown state")
+}
+
 type Account struct {
 	acme.Account
 	Key *jose.JSONWebKey `json:"key"`

db/memorystore.go

@@ -4,6 +4,7 @@ import (
 	"fmt"
 	"sync"
 
+	"github.com/jmhodges/clock"
 	"github.com/letsencrypt/pebble/core"
 )
 
@@ -13,6 +14,8 @@ import (
 type MemoryStore struct {
 	sync.RWMutex
 
+	clk clock.Clock
+
 	// Each Accounts's ID is the hex encoding of a SHA256 sum over its public
 	// key bytes.
 	accountsByID map[string]*core.Account
@@ -26,8 +29,9 @@ type MemoryStore struct {
 	certificatesByID map[string]*core.Certificate
 }
 
-func NewMemoryStore() *MemoryStore {
+func NewMemoryStore(clk clock.Clock) *MemoryStore {
 	return &MemoryStore{
+		clk:                clk,
 		accountsByID:       make(map[string]*core.Account),
 		ordersByID:         make(map[string]*core.Order),
 		authorizationsByID: make(map[string]*core.Authorization),
@@ -95,7 +99,18 @@ func (m *MemoryStore) AddOrder(order *core.Order) (int, error) {
 func (m *MemoryStore) GetOrderByID(id string) *core.Order {
 	m.RLock()
 	defer m.RUnlock()
-	return m.ordersByID[id]
+
+	if order, ok := m.ordersByID[id]; ok {
+		orderStatus, err := order.GetStatus(m.clk)
+		if err != nil {
+			panic(err)
+		}
+		order.Lock()
+		defer order.Unlock()
+		order.Status = orderStatus
+		return order
+	}
+	return nil
 }
 
 func (m *MemoryStore) AddAuthorization(authz *core.Authorization) (int, error) {

va/va.go

@@ -166,7 +166,15 @@ func (va VAImpl) setAuthzValid(authz *core.Authorization, chal *core.Challenge)
 	chal.Status = acme.StatusValid
 }
 
-// setAuthzInvalid updates an authorization an an associated challenge to be
+// setOrderError updates an order with an error from an authorization
+// validation.
+func (va VAImpl) setOrderError(order *core.Order, err *acme.ProblemDetails) {
+	order.Lock()
+	defer order.Unlock()
+	order.Error = err
+}
+
+// setAuthzInvalid updates an authorization and an associated challenge to be
 // status invalid. The challenge's error is set to the provided problem and both
 // the challenge and the authorization have their status updated to invalid.
 func (va VAImpl) setAuthzInvalid(
@@ -212,6 +220,8 @@ func (va VAImpl) process(task *vaTask) {
 	if err != nil {
 		va.setAuthzInvalid(authz, chal, err)
 		va.log.Printf("authz %s set INVALID by completed challenge %s", authz.ID, chal.ID)
+		va.setOrderError(authz.Order, err)
+		va.log.Printf("order %s set INVALID by invalid authz %s", authz.Order.ID, authz.ID)
 		return
 	}
 

wfe/wfe.go

@@ -1045,10 +1045,14 @@ func (wfe *WebFrontEndImpl) NewOrder(
 	wfe.log.Printf("Added order %q to the db\n", order.ID)
 	wfe.log.Printf("There are now %d orders in the db\n", count)
 
-	orderURL := wfe.relativeEndpoint(request, fmt.Sprintf("%s%s", orderPath, order.ID))
+	// Get the stored order back from the DB. The memorystore will set the order's
+	// status for us.
+	storedOrder := wfe.db.GetOrderByID(order.ID)
+
+	orderURL := wfe.relativeEndpoint(request, fmt.Sprintf("%s%s", orderPath, storedOrder.ID))
 	response.Header().Add("Location", orderURL)
 
-	orderResp := wfe.orderForDisplay(order, request)
+	orderResp := wfe.orderForDisplay(storedOrder, request)
 	err = wfe.writeJsonResponse(response, http.StatusCreated, orderResp)
 	if err != nil {
 		wfe.sendError(acme.InternalErrorProblem("Error marshalling order"), response)
@@ -1171,10 +1175,10 @@ func (wfe *WebFrontEndImpl) FinalizeOrder(
 		return
 	}
 
-	// The existing order must be in a pending status to finalize it
-	if orderStatus != acme.StatusPending {
+	// The existing order must be in a ready status to finalize it
+	if orderStatus != acme.StatusReady {
 		wfe.sendError(acme.MalformedProblem(fmt.Sprintf(
-			"Order's status (%q) was not pending", orderStatus)), response)
+			"Order's status (%q) was not %s", orderStatus, acme.StatusReady)), response)
 		return
 	}
 
@@ -1228,17 +1232,19 @@ func (wfe *WebFrontEndImpl) FinalizeOrder(
 		}
 	}
 
-	// Lock and update the order with the parsed CSR.
+	// Lock and update the order with the parsed CSR and the began processing
+	// state.
 	existingOrder.Lock()
 	existingOrder.ParsedCSR = parsedCSR
+	existingOrder.BeganProcessing = true
 	existingOrder.Unlock()
 
-	// Check whether the order is ready to issue, if it isn't, return a problem
-	prob = wfe.maybeIssue(existingOrder)
-	if prob != nil {
-		wfe.sendError(prob, response)
-		return
-	}
+	// Ask the CA to complete the order in a separate goroutine.
+	wfe.log.Printf("Order %s is fully authorized. Processing finalization", orderID)
+	go wfe.ca.CompleteOrder(existingOrder)
+
+	// Set the existingOrder to processing before displaying to the user
+	existingOrder.Status = acme.StatusProcessing
 
 	// Prepare the order for display as JSON
 	orderReq := wfe.orderForDisplay(existingOrder, request)
@@ -1251,38 +1257,6 @@ func (wfe *WebFrontEndImpl) FinalizeOrder(
 	}
 }
 
-func (wfe *WebFrontEndImpl) maybeIssue(order *core.Order) *acme.ProblemDetails {
-	// Lock the order for reading to check whether all authorizations are valid
-	order.RLock()
-	authzs := order.AuthorizationObjects
-	orderID := order.ID
-	order.RUnlock()
-	for _, authz := range authzs {
-		// Lock the authorization for reading to check its status
-		authz.RLock()
-		authzStatus := authz.Status
-		authzExpires := authz.ExpiresDate
-		ident := authz.Identifier
-		authz.RUnlock()
-		// If any of the authorizations are invalid the order isn't ready to issue
-		if authzStatus != acme.StatusValid {
-			return acme.UnauthorizedProblem(fmt.Sprintf(
-				"Authorization for %q is not status valid", ident.Value))
-		}
-		// If any of the authorizations are expired the order isn't ready to issue
-		if authzExpires.Before(wfe.clk.Now()) {
-			return acme.UnauthorizedProblem(fmt.Sprintf(
-				"Authorization for %q expired %q", ident.Value, authzExpires))
-		}
-	}
-	// All the authorizations are valid, ask the CA to complete the order in
-	// a separate goroutine. CompleteOrder will transition the order status to
-	// pending.
-	wfe.log.Printf("Order %s is fully authorized. Processing finalization", orderID)
-	go wfe.ca.CompleteOrder(order)
-	return nil
-}
-
 // prepAuthorizationForDisplay prepares the provided acme.Authorization for
 // display to an ACME client.
 func prepAuthorizationForDisplay(authz acme.Authorization) acme.Authorization {