Reduce duplicated logging of errors in WFE (#3071)

In 7d04ea9 we introduced the notion of a requestEvent, which had an AddError method that could be called to log an error. In that change we also added an AddError call before every wfe.sendError, to ensure errors got logged. In dc58017, we made it so that sendError would automatically add its errors to the request event, so we wouldn't need to write AddError everywhere. However, we never cleaned up the existing AddError calls, and since then have tended to "follow local style" and add a redundant AddError before many of our sendError calls.

This change attempts to undo some of that, by removing all AddError calls that appear to be redundant with the sendError call immediately following. It also adds a section on error handling to CONTRIBUTING.md.

CONTRIBUTING.md

@@ -39,6 +39,41 @@ request into the body of the commit message.
 
 If the Travis tests are failing on your branch, you should look at the logs to figure out why. Sometimes they fail spuriously, in which case you can post a comment requesting that a project owner kick the build.
 
+# Error handling
+
+All errors must be addressed in some way: That may be simply by returning an
+error up the stack, or by handling it in some intelligent way where it is
+generated, or by explicitly ignoring it and assigning to `_`. We use the `errcheck`
+tool in our integration tests to make sure all errors are addressed. Note that
+ignoring errors, even in tests, should be rare, since they may generate
+hard-to-debug problems.
+
+We define two special types of error. `BoulderError`, defined in
+errors/errors.go, is used specifically when an typed error needs to be passed
+across an RPC boundary. For instance, if the SA returns "not found", callers
+need to be able to distinguish that from a network error. Not every error that
+may pass across an RPC boundary needs to be a BoulderError, only those errors
+that need to be handled by type elsewhere. Handling by type may be as simple as
+turning a BoulderError into a specific type of ProblemDetail.
+
+The other special type of error is `ProblemDetails`. We try to treat these as a
+presentation-layer detail, and use them only in parts of the system that are
+responsible for rendering errors to end-users, i.e. wfe and wfe2. Note
+one exception: The VA RPC layer defines its own `ProblemDetails` type, which is
+returned to the RA and stored as part of a challenge (to eventually be rendered
+to the user).
+
+Within WFE and WFE2, ProblemDetails are sent to the client by calling
+`sendError()`, which also logs the error. For internal errors like timeout,
+or any error type that we haven't specifically turned into a ProblemDetail, we
+return a ServerInternal error. This avoids unnecessarily exposing internals.
+It's possible to add additional errors to a logEvent using `.AddError()`, but
+this should only be done when there is is internal-only information to log
+that isn't redundant with the ProblemDetails sent to the user. Note that the
+final argument to `sendError()`, `ierr`, will automatically get added to the
+logEvent for ServerInternal errors, so when sending a ServerInternal error it's
+not necessary to separately call `.AddError`.
+
 # Deployability
 
 We want to ensure that a new Boulder revision can be deployed to the currently running Boulder production instance without requiring config changes first. We also want to ensure that during a deploy, services can be restarted in any order. That means two things:

wfe/wfe.go

@@ -480,21 +480,18 @@ func (wfe *WebFrontEndImpl) verifyPOST(ctx context.Context, logEvent *requestEve
 
 	if _, ok := request.Header["Content-Length"]; !ok {
 		wfe.stats.Inc("HTTP.ClientErrors.LengthRequiredError", 1)
-		logEvent.AddError("missing Content-Length header on POST")
 		return nil, nil, reg, probs.ContentLengthRequired()
 	}
 
 	// Read body
 	if request.Body == nil {
 		wfe.stats.Inc("Errors.NoPOSTBody", 1)
-		logEvent.AddError("no body on POST")
 		return nil, nil, reg, probs.Malformed("No body on POST")
 	}
 
 	bodyBytes, err := ioutil.ReadAll(request.Body)
 	if err != nil {
 		wfe.stats.Inc("Errors.UnableToReadRequestBody", 1)
-		logEvent.AddError("unable to read request body")
 		return nil, nil, reg, probs.ServerInternal("unable to read request body")
 	}
 
@@ -508,7 +505,6 @@ func (wfe *WebFrontEndImpl) verifyPOST(ctx context.Context, logEvent *requestEve
 	// the signature itself.
 	submittedKey, parsedJws, err := wfe.extractJWSKey(body)
 	if err != nil {
-		logEvent.AddError(err.Error())
 		return nil, nil, reg, probs.Malformed(err.Error())
 	}
 
@@ -523,7 +519,6 @@ func (wfe *WebFrontEndImpl) verifyPOST(ctx context.Context, logEvent *requestEve
 		// to check its quality before doing the verify.
 		if err = wfe.keyPolicy.GoodKey(submittedKey.Key); err != nil {
 			wfe.stats.Inc("Errors.JWKRejectedByGoodKey", 1)
-			logEvent.AddError("JWK in request was rejected by GoodKey: %s", err)
 			return nil, nil, reg, probs.Malformed(err.Error())
 		}
 		key = submittedKey
@@ -570,12 +565,10 @@ func (wfe *WebFrontEndImpl) verifyPOST(ctx context.Context, logEvent *requestEve
 	logEvent.RequestNonce = nonce
 	if len(nonce) == 0 {
 		wfe.stats.Inc("Errors.JWSMissingNonce", 1)
-		logEvent.AddError("JWS is missing an anti-replay nonce")
 		return nil, nil, reg, probs.BadNonce("JWS has no anti-replay nonce")
 	} else if !wfe.nonceService.Valid(nonce) {
 		wfe.stats.Inc("Errors.JWSInvalidNonce", 1)
-		logEvent.AddError("JWS has an invalid anti-replay nonce: %s", nonce)
+		return nil, nil, reg, probs.BadNonce(fmt.Sprintf("JWS has invalid anti-replay nonce %s", nonce))
-		return nil, nil, reg, probs.BadNonce(fmt.Sprintf("JWS has invalid anti-replay nonce %v", nonce))
 	}
 
 	// Check that the "resource" field is present and has the correct value
@@ -585,16 +578,13 @@ func (wfe *WebFrontEndImpl) verifyPOST(ctx context.Context, logEvent *requestEve
 	err = json.Unmarshal([]byte(payload), &parsedRequest)
 	if err != nil {
 		wfe.stats.Inc("Errors.UnparseableJWSPayload", 1)
-		logEvent.AddError("unable to JSON parse resource from JWS payload: %s", err)
 		return nil, nil, reg, probs.Malformed("Request payload did not parse as JSON")
 	}
 	if parsedRequest.Resource == "" {
 		wfe.stats.Inc("Errors.NoResourceInJWSPayload", 1)
-		logEvent.AddError("JWS request payload does not specify a resource")
 		return nil, nil, reg, probs.Malformed("Request payload does not specify a resource")
 	} else if resource != core.AcmeResource(parsedRequest.Resource) {
 		wfe.stats.Inc("Errors.MismatchedResourceInJWSPayload", 1)
-		logEvent.AddError("JWS request payload does not match resource")
 		return nil, nil, reg, probs.Malformed("JWS resource payload does not match the HTTP resource: %s != %s", parsedRequest.Resource, resource)
 	}
 
@@ -687,7 +677,6 @@ func (wfe *WebFrontEndImpl) NewRegistration(ctx context.Context, logEvent *reque
 
 	reg, err := wfe.RA.NewRegistration(ctx, init)
 	if err != nil {
-		logEvent.AddError("unable to create new registration: %s", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Error creating new registration"), err)
 		return
 	}
@@ -709,7 +698,6 @@ func (wfe *WebFrontEndImpl) NewRegistration(ctx context.Context, logEvent *reque
 	if err != nil {
 		// ServerInternal because we just created this registration, and it
 		// should be OK.
-		logEvent.AddError("unable to marshal registration: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Error marshaling registration"), err)
 		return
 	}
@@ -734,7 +722,6 @@ func (wfe *WebFrontEndImpl) NewAuthorization(ctx context.Context, logEvent *requ
 
 	var init core.Authorization
 	if err := json.Unmarshal(body, &init); err != nil {
-		logEvent.AddError("unable to JSON unmarshal Authorization: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Error unmarshaling JSON"), err)
 		return
 	}
@@ -743,7 +730,6 @@ func (wfe *WebFrontEndImpl) NewAuthorization(ctx context.Context, logEvent *requ
 	// Create new authz and return
 	authz, err := wfe.RA.NewAuthorization(ctx, init, currReg.ID)
 	if err != nil {
-		logEvent.AddError("unable to create new authz: %s", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Error creating new authz"), err)
 		return
 	}
@@ -799,14 +785,12 @@ func (wfe *WebFrontEndImpl) RevokeCertificate(ctx context.Context, logEvent *req
 	}
 	var revokeRequest RevokeRequest
 	if err := json.Unmarshal(body, &revokeRequest); err != nil {
-		logEvent.AddError(fmt.Sprintf("Couldn't unmarshal in revoke request %s", string(body)))
 		wfe.sendError(response, logEvent, probs.Malformed("Unable to JSON parse revoke request"), err)
 		return
 	}
 	providedCert, err := x509.ParseCertificate(revokeRequest.CertificateDER)
 	if err != nil {
-		logEvent.AddError("unable to parse revoke certificate DER: %s", err)
+		wfe.sendError(response, logEvent, probs.Malformed("Unable to parse revoke certificate DER"), err)
-		wfe.sendError(response, logEvent, probs.Malformed("Unable to parse certificate DER"), err)
 		return
 	}
 
@@ -839,7 +823,6 @@ func (wfe *WebFrontEndImpl) RevokeCertificate(ctx context.Context, logEvent *req
 	logEvent.Extra["CertificateStatus"] = certStatus.Status
 
 	if certStatus.Status == core.OCSPStatusRevoked {
-		logEvent.AddError("Certificate already revoked: %#v", serial)
 		wfe.sendError(response, logEvent, probs.Conflict("Certificate already revoked"), nil)
 		return
 	}
@@ -847,7 +830,6 @@ func (wfe *WebFrontEndImpl) RevokeCertificate(ctx context.Context, logEvent *req
 	if !(core.KeyDigestEquals(requestKey, parsedCertificate.PublicKey) || registration.ID == cert.RegistrationID) {
 		valid, err := wfe.regHoldsAuthorizations(ctx, registration.ID, parsedCertificate.DNSNames)
 		if err != nil {
-			logEvent.AddError("regHoldsAuthorizations failed: %s", err)
 			wfe.sendError(response, logEvent, probs.ServerInternal("Failed to retrieve authorizations for names in certificate"), err)
 			return
 		}
@@ -864,7 +846,6 @@ func (wfe *WebFrontEndImpl) RevokeCertificate(ctx context.Context, logEvent *req
 	reason := revocation.Reason(0)
 	if revokeRequest.Reason != nil && wfe.AcceptRevocationReason {
 		if _, present := revocation.UserAllowedReasons[*revokeRequest.Reason]; !present {
-			logEvent.AddError("unsupported revocation reason code provided")
 			wfe.sendError(response, logEvent, probs.Malformed("unsupported revocation reason code provided"), nil)
 			return
 		}
@@ -873,7 +854,6 @@ func (wfe *WebFrontEndImpl) RevokeCertificate(ctx context.Context, logEvent *req
 
 	err = wfe.RA.RevokeCertificateWithReg(ctx, *parsedCertificate, reason, registration.ID)
 	if err != nil {
-		logEvent.AddError("failed to revoke certificate: %s", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Failed to revoke certificate"), err)
 	} else {
 		wfe.log.Debug(fmt.Sprintf("Revoked %v", serial))
@@ -915,7 +895,6 @@ func (wfe *WebFrontEndImpl) NewCertificate(ctx context.Context, logEvent *reques
 	var rawCSR core.RawCertificateRequest
 	err := json.Unmarshal(body, &rawCSR)
 	if err != nil {
-		logEvent.AddError("unable to JSON unmarshal CertificateRequest: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Error unmarshaling certificate request"), err)
 		return
 	}
@@ -940,7 +919,6 @@ func (wfe *WebFrontEndImpl) NewCertificate(ctx context.Context, logEvent *reques
 	certificateRequest := core.CertificateRequest{Bytes: rawCSR.CSR}
 	certificateRequest.CSR, err = x509.ParseCertificateRequest(rawCSR.CSR)
 	if err != nil {
-		logEvent.AddError("unable to parse certificate request: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Error parsing certificate request: %s", err), err)
 		return
 	}
@@ -952,7 +930,6 @@ func (wfe *WebFrontEndImpl) NewCertificate(ctx context.Context, logEvent *reques
 	// a bad key from the client is just a malformed request and doesn't need to
 	// be audited.
 	if err := wfe.keyPolicy.GoodKey(certificateRequest.CSR.PublicKey); err != nil {
-		logEvent.AddError("CSR public key failed GoodKey: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Invalid key in certificate request :: %s", err), err)
 		return
 	}
@@ -971,7 +948,6 @@ func (wfe *WebFrontEndImpl) NewCertificate(ctx context.Context, logEvent *reques
 	// RA for secondary validation.
 	cert, err := wfe.RA.NewCertificate(ctx, certificateRequest, reg.ID)
 	if err != nil {
-		logEvent.AddError("unable to create new cert: %s", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Error creating new cert"), err)
 		return
 	}
@@ -982,7 +958,6 @@ func (wfe *WebFrontEndImpl) NewCertificate(ctx context.Context, logEvent *reques
 	// enumerate and mirror our certificates.
 	parsedCertificate, err := x509.ParseCertificate([]byte(cert.DER))
 	if err != nil {
-		logEvent.AddError("unable to parse certificate: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Unable to parse certificate"), err)
 		return
 	}
@@ -993,7 +968,6 @@ func (wfe *WebFrontEndImpl) NewCertificate(ctx context.Context, logEvent *reques
 	response.Header().Add("Location", certURL)
 	if features.Enabled(features.UseAIAIssuerURL) {
 		if err = wfe.addIssuingCertificateURLs(response, parsedCertificate.IssuingCertificateURL); err != nil {
-			logEvent.AddError("unable to parse IssuingCertificateURL: %s", err)
 			wfe.sendError(response, logEvent, probs.ServerInternal("unable to parse IssuingCertificateURL"), err)
 			return
 		}
@@ -1049,7 +1023,6 @@ func (wfe *WebFrontEndImpl) Challenge(
 
 	// After expiring, challenges are inaccessible
 	if authz.Expires == nil || authz.Expires.Before(wfe.clk.Now()) {
-		logEvent.AddError("Authorization %v expired in the past (%v)", authz.ID, *authz.Expires)
 		wfe.sendError(response, logEvent, probs.NotFound("Expired authorization"), nil)
 		return
 	}
@@ -1124,7 +1097,6 @@ func (wfe *WebFrontEndImpl) getChallenge(
 	if err != nil {
 		// InternalServerError because this is a failure to decode data passed in
 		// by the caller, which got it from the DB.
-		logEvent.AddError("unable to marshal challenge: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to marshal challenge"), err)
 		return
 	}
@@ -1166,7 +1138,6 @@ func (wfe *WebFrontEndImpl) postChallenge(
 
 	var challengeUpdate core.Challenge
 	if err := json.Unmarshal(body, &challengeUpdate); err != nil {
-		logEvent.AddError("error JSON unmarshaling challenge response: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Error unmarshaling challenge response"), err)
 		return
 	}
@@ -1174,7 +1145,6 @@ func (wfe *WebFrontEndImpl) postChallenge(
 	// Ask the RA to update this authorization
 	updatedAuthorization, err := wfe.RA.UpdateAuthorization(ctx, authz, challengeIndex, challengeUpdate)
 	if err != nil {
-		logEvent.AddError("unable to update challenge: %s", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Unable to update challenge"), err)
 		return
 	}
@@ -1190,7 +1160,6 @@ func (wfe *WebFrontEndImpl) postChallenge(
 	err = wfe.writeJsonResponse(response, logEvent, http.StatusAccepted, challenge)
 	if err != nil {
 		// ServerInternal because we made the challenges, they should be OK
-		logEvent.AddError("failed to marshal challenge: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to marshal challenge"), err)
 		return
 	}
@@ -1212,16 +1181,13 @@ func (wfe *WebFrontEndImpl) Registration(ctx context.Context, logEvent *requestE
 	idStr := request.URL.Path
 	id, err := strconv.ParseInt(idStr, 10, 64)
 	if err != nil {
-		logEvent.AddError("registration ID must be an integer, was %#v", idStr)
 		wfe.sendError(response, logEvent, probs.Malformed("Registration ID must be an integer"), err)
 		return
 	} else if id <= 0 {
 		msg := fmt.Sprintf("Registration ID must be a positive non-zero integer, was %d", id)
-		logEvent.AddError(msg)
 		wfe.sendError(response, logEvent, probs.Malformed(msg), nil)
 		return
 	} else if id != currReg.ID {
-		logEvent.AddError("Request signing key did not match registration key: %d != %d", id, currReg.ID)
 		wfe.sendError(response, logEvent, probs.Unauthorized("Request signing key did not match registration key"), nil)
 		return
 	}
@@ -1229,7 +1195,6 @@ func (wfe *WebFrontEndImpl) Registration(ctx context.Context, logEvent *requestE
 	var update core.Registration
 	err = json.Unmarshal(body, &update)
 	if err != nil {
-		logEvent.AddError("unable to JSON parse registration: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Error unmarshaling registration"), err)
 		return
 	}
@@ -1262,7 +1227,6 @@ func (wfe *WebFrontEndImpl) Registration(ctx context.Context, logEvent *requestE
 	if len(update.Agreement) > 0 && update.Agreement != currReg.Agreement &&
 		update.Agreement != wfe.SubscriberAgreementURL {
 		msg := fmt.Sprintf("Provided agreement URL [%s] does not match current agreement URL [%s]", update.Agreement, wfe.SubscriberAgreementURL)
-		logEvent.AddError(msg)
 		wfe.sendError(response, logEvent, probs.Malformed(msg), nil)
 		return
 	}
@@ -1276,7 +1240,6 @@ func (wfe *WebFrontEndImpl) Registration(ctx context.Context, logEvent *requestE
 
 	updatedReg, err := wfe.RA.UpdateRegistration(ctx, currReg, update)
 	if err != nil {
-		logEvent.AddError("unable to update registration: %s", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Unable to update registration"), err)
 		return
 	}
@@ -1289,7 +1252,6 @@ func (wfe *WebFrontEndImpl) Registration(ctx context.Context, logEvent *requestE
 	err = wfe.writeJsonResponse(response, logEvent, http.StatusAccepted, updatedReg)
 	if err != nil {
 		// ServerInternal because we just generated the reg, it should be OK
-		logEvent.AddError("unable to marshal updated registration: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to marshal registration"), err)
 		return
 	}
@@ -1303,7 +1265,6 @@ func (wfe *WebFrontEndImpl) deactivateAuthorization(ctx context.Context, authz *
 		return false
 	}
 	if reg.ID != authz.RegistrationID {
-		logEvent.AddError("registration ID doesn't match ID for authorization")
 		wfe.sendError(response, logEvent, probs.Unauthorized("Registration ID doesn't match ID for authorization"), nil)
 		return false
 	}
@@ -1316,13 +1277,11 @@ func (wfe *WebFrontEndImpl) deactivateAuthorization(ctx context.Context, authz *
 		return false
 	}
 	if req.Status != core.StatusDeactivated {
-		logEvent.AddError("invalid status value")
 		wfe.sendError(response, logEvent, probs.Malformed("Invalid status value"), err)
 		return false
 	}
 	err = wfe.RA.DeactivateAuthorization(ctx, *authz)
 	if err != nil {
-		logEvent.AddError("unable to deactivate authorization", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Error deactivating authorization"), err)
 		return false
 	}
@@ -1353,8 +1312,6 @@ func (wfe *WebFrontEndImpl) Authorization(ctx context.Context, logEvent *request
 
 	// After expiring, authorizations are inaccessible
 	if authz.Expires == nil || authz.Expires.Before(wfe.clk.Now()) {
-		msg := fmt.Sprintf("Authorization %v expired in the past (%v)", authz.ID, *authz.Expires)
-		logEvent.AddError(msg)
 		wfe.sendError(response, logEvent, probs.NotFound("Expired authorization"), nil)
 		return
 	}
@@ -1375,7 +1332,6 @@ func (wfe *WebFrontEndImpl) Authorization(ctx context.Context, logEvent *request
 	err = wfe.writeJsonResponse(response, logEvent, http.StatusOK, authz)
 	if err != nil {
 		// InternalServerError because this is a failure to decode from our DB.
-		logEvent.AddError("Failed to JSON marshal authz: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to JSON marshal authz"), err)
 		return
 	}
@@ -1391,7 +1347,6 @@ func (wfe *WebFrontEndImpl) Certificate(ctx context.Context, logEvent *requestEv
 	// Certificate paths consist of the CertBase path, plus exactly sixteen hex
 	// digits.
 	if !core.ValidSerial(serial) {
-		logEvent.AddError("certificate serial provided was not valid: %s", serial)
 		wfe.sendError(response, logEvent, probs.NotFound("Certificate not found"), nil)
 		return
 	}
@@ -1414,12 +1369,10 @@ func (wfe *WebFrontEndImpl) Certificate(ctx context.Context, logEvent *requestEv
 	if features.Enabled(features.UseAIAIssuerURL) {
 		parsedCertificate, err := x509.ParseCertificate([]byte(cert.DER))
 		if err != nil {
-			logEvent.AddError("unable to parse certificate: %s", err)
 			wfe.sendError(response, logEvent, probs.ServerInternal("Unable to parse certificate"), err)
 			return
 		}
 		if err = wfe.addIssuingCertificateURLs(response, parsedCertificate.IssuingCertificateURL); err != nil {
-			logEvent.AddError("unable to parse IssuingCertificateURL: %s", err)
 			wfe.sendError(response, logEvent, probs.ServerInternal("unable to parse IssuingCertificateURL"), err)
 			return
 		}
@@ -1458,7 +1411,6 @@ func (wfe *WebFrontEndImpl) BuildID(ctx context.Context, logEvent *requestEvent,
 	response.WriteHeader(http.StatusOK)
 	detailsString := fmt.Sprintf("Boulder=(%s %s)", core.GetBuildID(), core.GetBuildTime())
 	if _, err := fmt.Fprintln(response, detailsString); err != nil {
-		logEvent.AddError("unable to print build information: %s", err)
 		wfe.log.Warning(fmt.Sprintf("Could not write response: %s", err))
 	}
 }
@@ -1530,13 +1482,11 @@ func (wfe *WebFrontEndImpl) KeyRollover(ctx context.Context, logEvent *requestEv
 	// Parse as JWS
 	newKey, parsedJWS, err := wfe.extractJWSKey(string(body))
 	if err != nil {
-		logEvent.AddError(err.Error())
 		wfe.sendError(response, logEvent, probs.Malformed(err.Error()), err)
 		return
 	}
 	payload, err := parsedJWS.Verify(newKey)
 	if err != nil {
-		logEvent.AddError("verification of the inner JWS with the inner JWK failed: %v", err)
 		wfe.sendError(response, logEvent, probs.Malformed("JWS verification error"), err)
 		return
 	}
@@ -1546,25 +1496,21 @@ func (wfe *WebFrontEndImpl) KeyRollover(ctx context.Context, logEvent *requestEv
 	}
 	err = json.Unmarshal(payload, &rolloverRequest)
 	if err != nil {
-		logEvent.AddError("unable to JSON parse resource from JWS payload: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Request payload did not parse as JSON"), nil)
 		return
 	}
 
 	if wfe.relativeEndpoint(request, fmt.Sprintf("%s%d", regPath, reg.ID)) != rolloverRequest.Account {
-		logEvent.AddError("incorrect account URL provided")
 		wfe.sendError(response, logEvent, probs.Malformed("Incorrect account URL provided in payload"), nil)
 		return
 	}
 
 	keysEqual, err := core.PublicKeysEqual(rolloverRequest.NewKey.Key, newKey.Key)
 	if err != nil {
-		logEvent.AddError("unable to marshal new key: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Unable to marshal new JWK"), nil)
 		return
 	}
 	if !keysEqual {
-		logEvent.AddError("new key in inner payload doesn't match key used to sign inner JWS")
 		wfe.sendError(response, logEvent, probs.Malformed("New JWK in inner payload doesn't match key used to sign inner JWS"), nil)
 		return
 	}
@@ -1572,14 +1518,12 @@ func (wfe *WebFrontEndImpl) KeyRollover(ctx context.Context, logEvent *requestEv
 	// Update registration key
 	updatedReg, err := wfe.RA.UpdateRegistration(ctx, reg, core.Registration{Key: newKey})
 	if err != nil {
-		logEvent.AddError("unable to update registration: %s", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Unable to update registration"), err)
 		return
 	}
 
 	jsonReply, err := marshalIndent(updatedReg)
 	if err != nil {
-		logEvent.AddError("unable to marshal updated registration: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to marshal registration"), err)
 		return
 	}
@@ -1591,7 +1535,6 @@ func (wfe *WebFrontEndImpl) KeyRollover(ctx context.Context, logEvent *requestEv
 func (wfe *WebFrontEndImpl) deactivateRegistration(ctx context.Context, reg core.Registration, response http.ResponseWriter, request *http.Request, logEvent *requestEvent) {
 	err := wfe.RA.DeactivateRegistration(ctx, reg)
 	if err != nil {
-		logEvent.AddError("unable to deactivate registration", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Error deactivating registration"), err)
 		return
 	}
@@ -1600,7 +1543,6 @@ func (wfe *WebFrontEndImpl) deactivateRegistration(ctx context.Context, reg core
 	err = wfe.writeJsonResponse(response, logEvent, http.StatusOK, reg)
 	if err != nil {
 		// ServerInternal because registration is from DB and should be fine
-		logEvent.AddError("unable to marshal updated registration: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to marshal registration"), err)
 		return
 	}

wfe2/wfe.go

@@ -501,7 +501,6 @@ func (wfe *WebFrontEndImpl) NewAccount(
 
 	acct, err := wfe.RA.NewRegistration(ctx, init)
 	if err != nil {
-		logEvent.AddError("unable to create new account: %s", err)
 		wfe.sendError(response, logEvent,
 			problemDetailsForError(err, "Error creating new account"), err)
 		return
@@ -521,7 +520,6 @@ func (wfe *WebFrontEndImpl) NewAccount(
 	if err != nil {
 		// ServerInternal because we just created this account, and it
 		// should be OK.
-		logEvent.AddError("unable to marshal account: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Error marshaling account"), err)
 		return
 	}
@@ -803,7 +801,6 @@ func (wfe *WebFrontEndImpl) Challenge(
 
 	// After expiring, challenges are inaccessible
 	if authz.Expires == nil || authz.Expires.Before(wfe.clk.Now()) {
-		logEvent.AddError("Authorization %v expired in the past (%v)", authz.ID, *authz.Expires)
 		wfe.sendError(response, logEvent, probs.NotFound("Expired authorization"), nil)
 		return
 	}
@@ -878,7 +875,6 @@ func (wfe *WebFrontEndImpl) getChallenge(
 	if err != nil {
 		// InternalServerError because this is a failure to decode data passed in
 		// by the caller, which got it from the DB.
-		logEvent.AddError("unable to marshal challenge: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to marshal challenge"), err)
 		return
 	}
@@ -910,7 +906,6 @@ func (wfe *WebFrontEndImpl) postChallenge(
 	// Check that the account ID matching the key used matches
 	// the account ID on the authz object
 	if currAcct.ID != authz.RegistrationID {
-		logEvent.AddError("User account id: %d != Authorization account id: %v", currAcct.ID, authz.RegistrationID)
 		wfe.sendError(response,
 			logEvent,
 			probs.Unauthorized("User account ID doesn't match account ID in authorization"),
@@ -921,7 +916,6 @@ func (wfe *WebFrontEndImpl) postChallenge(
 
 	var challengeUpdate core.Challenge
 	if err := json.Unmarshal(body, &challengeUpdate); err != nil {
-		logEvent.AddError("error JSON unmarshaling challenge response: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Error unmarshaling challenge response"), err)
 		return
 	}
@@ -929,7 +923,6 @@ func (wfe *WebFrontEndImpl) postChallenge(
 	// Ask the RA to update this authorization
 	updatedAuthorization, err := wfe.RA.UpdateAuthorization(ctx, authz, challengeIndex, challengeUpdate)
 	if err != nil {
-		logEvent.AddError("unable to update challenge: %s", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Unable to update challenge"), err)
 		return
 	}
@@ -945,7 +938,6 @@ func (wfe *WebFrontEndImpl) postChallenge(
 	err = wfe.writeJsonResponse(response, logEvent, http.StatusAccepted, challenge)
 	if err != nil {
 		// ServerInternal because we made the challenges, they should be OK
-		logEvent.AddError("failed to marshal challenge: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to marshal challenge"), err)
 		return
 	}
@@ -970,16 +962,13 @@ func (wfe *WebFrontEndImpl) Account(
 	idStr := request.URL.Path
 	id, err := strconv.ParseInt(idStr, 10, 64)
 	if err != nil {
-		logEvent.AddError("account ID must be an integer, was %#v", idStr)
 		wfe.sendError(response, logEvent, probs.Malformed("Account ID must be an integer"), err)
 		return
 	} else if id <= 0 {
 		msg := fmt.Sprintf("Account ID must be a positive non-zero integer, was %d", id)
-		logEvent.AddError(msg)
 		wfe.sendError(response, logEvent, probs.Malformed(msg), nil)
 		return
 	} else if id != currAcct.ID {
-		logEvent.AddError("Request signing key did not match account key: %d != %d", id, currAcct.ID)
 		wfe.sendError(response, logEvent,
 			probs.Unauthorized("Request signing key did not match account key"), nil)
 		return
@@ -988,7 +977,6 @@ func (wfe *WebFrontEndImpl) Account(
 	var update core.Registration
 	err = json.Unmarshal(body, &update)
 	if err != nil {
-		logEvent.AddError("unable to JSON parse account: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Error unmarshaling account"), err)
 		return
 	}
@@ -1022,7 +1010,6 @@ func (wfe *WebFrontEndImpl) Account(
 		update.Agreement != wfe.SubscriberAgreementURL {
 		msg := fmt.Sprintf("Provided agreement URL [%s] does not match current agreement URL [%s]",
 			update.Agreement, wfe.SubscriberAgreementURL)
-		logEvent.AddError(msg)
 		wfe.sendError(response, logEvent, probs.Malformed(msg), nil)
 		return
 	}
@@ -1036,7 +1023,6 @@ func (wfe *WebFrontEndImpl) Account(
 
 	updatedAcct, err := wfe.RA.UpdateRegistration(ctx, *currAcct, update)
 	if err != nil {
-		logEvent.AddError("unable to update account: %s", err)
 		wfe.sendError(response, logEvent,
 			problemDetailsForError(err, "Unable to update account"), err)
 		return
@@ -1049,7 +1035,6 @@ func (wfe *WebFrontEndImpl) Account(
 	err = wfe.writeJsonResponse(response, logEvent, http.StatusAccepted, updatedAcct)
 	if err != nil {
 		// ServerInternal because we just generated the account, it should be OK
-		logEvent.AddError("unable to marshal updated account: %s", err)
 		wfe.sendError(response, logEvent,
 			probs.ServerInternal("Failed to marshal account"), err)
 		return
@@ -1069,7 +1054,6 @@ func (wfe *WebFrontEndImpl) deactivateAuthorization(
 		return false
 	}
 	if acct.ID != authz.RegistrationID {
-		logEvent.AddError("account ID doesn't match ID for authorization")
 		wfe.sendError(response, logEvent,
 			probs.Unauthorized("Account ID doesn't match ID for authorization"), nil)
 		return false
@@ -1083,13 +1067,11 @@ func (wfe *WebFrontEndImpl) deactivateAuthorization(
 		return false
 	}
 	if req.Status != core.StatusDeactivated {
-		logEvent.AddError("invalid status value")
 		wfe.sendError(response, logEvent, probs.Malformed("Invalid status value"), err)
 		return false
 	}
 	err = wfe.RA.DeactivateAuthorization(ctx, *authz)
 	if err != nil {
-		logEvent.AddError("unable to deactivate authorization", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Error deactivating authorization"), err)
 		return false
 	}
@@ -1107,7 +1089,6 @@ func (wfe *WebFrontEndImpl) Authorization(ctx context.Context, logEvent *request
 	id := request.URL.Path
 	authz, err := wfe.SA.GetAuthorization(ctx, id)
 	if err != nil {
-		logEvent.AddError("No such authorization at id %s", id)
 		// TODO(#1199): handle db errors
 		wfe.sendError(response, logEvent, probs.NotFound("Unable to find authorization"), err)
 		return
@@ -1120,8 +1101,6 @@ func (wfe *WebFrontEndImpl) Authorization(ctx context.Context, logEvent *request
 
 	// After expiring, authorizations are inaccessible
 	if authz.Expires == nil || authz.Expires.Before(wfe.clk.Now()) {
-		msg := fmt.Sprintf("Authorization %v expired in the past (%v)", authz.ID, *authz.Expires)
-		logEvent.AddError(msg)
 		wfe.sendError(response, logEvent, probs.NotFound("Expired authorization"), nil)
 		return
 	}
@@ -1140,7 +1119,6 @@ func (wfe *WebFrontEndImpl) Authorization(ctx context.Context, logEvent *request
 	err = wfe.writeJsonResponse(response, logEvent, http.StatusOK, authz)
 	if err != nil {
 		// InternalServerError because this is a failure to decode from our DB.
-		logEvent.AddError("Failed to JSON marshal authz: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to JSON marshal authz"), err)
 		return
 	}
@@ -1178,7 +1156,6 @@ func (wfe *WebFrontEndImpl) Certificate(ctx context.Context, logEvent *requestEv
 	response.Header().Set("Content-Type", "application/pkix-cert")
 	parsedCertificate, err := x509.ParseCertificate([]byte(cert.DER))
 	if err != nil {
-		logEvent.AddError("unable to parse certificate: %s", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Unable to parse certificate"), err)
 		return
 	}
@@ -1219,7 +1196,6 @@ func (wfe *WebFrontEndImpl) BuildID(ctx context.Context, logEvent *requestEvent,
 	response.WriteHeader(http.StatusOK)
 	detailsString := fmt.Sprintf("Boulder=(%s %s)", core.GetBuildID(), core.GetBuildTime())
 	if _, err := fmt.Fprintln(response, detailsString); err != nil {
-		logEvent.AddError("unable to print build information: %s", err)
 		wfe.log.Warning(fmt.Sprintf("Could not write response: %s", err))
 	}
 }
@@ -1357,7 +1333,6 @@ func (wfe *WebFrontEndImpl) KeyRollover(
 
 	err = wfe.writeJsonResponse(response, logEvent, http.StatusOK, updatedAcct)
 	if err != nil {
-		logEvent.AddError("failed to marshal updated account: %q", err)
 		wfe.sendError(response, logEvent, probs.ServerInternal("Failed to marshal updated account"), err)
 	}
 }
@@ -1370,7 +1345,6 @@ func (wfe *WebFrontEndImpl) deactivateAccount(
 	logEvent *requestEvent) {
 	err := wfe.RA.DeactivateRegistration(ctx, acct)
 	if err != nil {
-		logEvent.AddError("unable to deactivate account", err)
 		wfe.sendError(response, logEvent,
 			problemDetailsForError(err, "Error deactivating account"), err)
 		return
@@ -1380,7 +1354,6 @@ func (wfe *WebFrontEndImpl) deactivateAccount(
 	err = wfe.writeJsonResponse(response, logEvent, http.StatusOK, acct)
 	if err != nil {
 		// ServerInternal because account is from DB and should be fine
-		logEvent.AddError("unable to marshal updated account: %s", err)
 		wfe.sendError(response, logEvent,
 			probs.ServerInternal("Failed to marshal account"), err)
 		return
@@ -1430,7 +1403,6 @@ func (wfe *WebFrontEndImpl) NewOrder(
 	// in the request
 	err := json.Unmarshal(body, &rawCSR)
 	if err != nil {
-		logEvent.AddError("unable to JSON unmarshal order request: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Error unmarshaling order request"), err)
 		return
 	}
@@ -1442,7 +1414,6 @@ func (wfe *WebFrontEndImpl) NewOrder(
 	// and encoding/asn1 will refuse to parse it. If this is the case exit early
 	// with a more useful error message.
 	if len(rawCSR.CSR) >= 10 && rawCSR.CSR[8] == 2 && rawCSR.CSR[9] == 0 {
-		logEvent.AddError("Pre-1.0.2 OpenSSL malformed CSR")
 		wfe.sendError(
 			response,
 			logEvent,
@@ -1455,7 +1426,6 @@ func (wfe *WebFrontEndImpl) NewOrder(
 	// Check for a malformed CSR early to avoid unnecessary RPCs
 	_, err = x509.ParseCertificateRequest(rawCSR.CSR)
 	if err != nil {
-		logEvent.AddError("unable to parse CSR: %s", err)
 		wfe.sendError(response, logEvent, probs.Malformed("Error parsing certificate request: %s", err), err)
 		return
 	}
@@ -1465,7 +1435,6 @@ func (wfe *WebFrontEndImpl) NewOrder(
 		Csr:            rawCSR.CSR,
 	})
 	if err != nil {
-		logEvent.AddError("unable to create order: %s", err)
 		wfe.sendError(response, logEvent, problemDetailsForError(err, "Error creating new order"), err)
 		return
 	}