Improve error reporting and use of status conditions

This commit is contained in:
James Munnelly 2018-04-09 21:03:07 +01:00
parent e8e6785e9a
commit d197817fa7
4 changed files with 73 additions and 95 deletions

View File

@ -43,23 +43,19 @@ const (
successCertificateRenewed = "CertificateRenewed"
successRenewalScheduled = "RenewalScheduled"
messageIssuerNotFound = "Issuer %s does not exist"
messageIssuerNotReady = "Issuer %s not ready"
messageIssuerErrorInit = "Error initializing issuer: "
messageErrorCheckCertificate = "Error checking existing TLS certificate, will re-issue: "
messageErrorGetCertificate = "Error getting TLS certificate: "
messageErrorPreparingCertificate = "Error preparing issuer for certificate: "
messageErrorIssuingCertificate = "Error issuing certificate: "
messageErrorRenewingCertificate = "Error renewing certificate: "
messageErrorSavingCertificate = "Error saving TLS certificate: "
messageIssuerNotFound = "Issuer %s does not exist"
messageIssuerNotReady = "Issuer %s not ready"
messageIssuerErrorInit = "Error initializing issuer: "
messageErrorGetCertificate = "Error getting TLS certificate: "
messageErrorIssuingCertificate = "Error issuing certificate: "
messageErrorRenewingCertificate = "Error renewing certificate: "
messageErrorSavingCertificate = "Error saving TLS certificate: "
messagePreparingCertificate = "Preparing certificate with issuer"
messageIssuingCertificate = "Issuing certificate..."
messageRenewingCertificate = "Renewing certificate..."
messageIssuingCertificate = "Issuing certificate..."
messageRenewingCertificate = "Renewing certificate..."
messageCertificateIssued = "Certificate issued successfully"
messageCertificateRenewed = "Certificate renewed successfully"
messageRenewalScheduled = "Certificate scheduled for renewal in %d hours"
)
func (c *Controller) Sync(ctx context.Context, crt *v1alpha1.Certificate) (err error) {
@ -102,11 +98,6 @@ func (c *Controller) Sync(ctx context.Context, crt *v1alpha1.Certificate) (err e
// grab existing certificate and validate private key
cert, err := kube.SecretTLSCert(c.secretLister, crt.Namespace, crt.Spec.SecretName)
if err != nil {
s := messageErrorCheckCertificate + err.Error()
glog.Info(s)
c.recorder.Event(crt, api.EventTypeNormal, errorCheckCertificate, s)
}
// if an error is returned, and that error is something other than
// IsNotFound or invalid data, then we should return the error.
@ -196,9 +187,7 @@ func (c *Controller) scheduleRenewal(crt *v1alpha1.Certificate) {
c.scheduledWorkQueue.Add(key, renewIn)
s := fmt.Sprintf(messageRenewalScheduled, renewIn/time.Hour)
glog.Info(s)
c.recorder.Event(crt, api.EventTypeNormal, successRenewalScheduled, s)
glog.Infof("Certificate %s/%s scheduled for renewal in %d hours", crt.Namespace, crt.Name, renewIn/time.Hour)
}
// issuerKind returns the kind of issuer for a certificate
@ -260,17 +249,13 @@ func (c *Controller) updateSecret(crt *v1alpha1.Certificate, namespace string, c
// and private key will be stored in the named secret
func (c *Controller) issue(ctx context.Context, issuer issuer.Interface, crt *v1alpha1.Certificate) error {
var err error
s := messagePreparingCertificate
glog.Info(s)
c.recorder.Event(crt, api.EventTypeNormal, reasonPreparingCertificate, s)
glog.Info("Preparing certificate %s/%s with issuer", crt.Namespace, crt.Name)
if err = issuer.Prepare(ctx, crt); err != nil {
s := messageErrorPreparingCertificate + err.Error()
glog.Info(s)
c.recorder.Event(crt, api.EventTypeWarning, errorPreparingCertificate, s)
glog.Info("Error preparing issuer for certificate %s/%s: %v", crt.Namespace, crt.Name, err)
return err
}
s = messageIssuingCertificate
s := messageIssuingCertificate
glog.Info(s)
c.recorder.Event(crt, api.EventTypeNormal, reasonIssuingCertificate, s)
@ -278,9 +263,7 @@ func (c *Controller) issue(ctx context.Context, issuer issuer.Interface, crt *v1
key, cert, err = issuer.Issue(ctx, crt)
if err != nil {
s := messageErrorIssuingCertificate + err.Error()
glog.Info(s)
c.recorder.Event(crt, api.EventTypeWarning, errorIssuingCertificate, s)
glog.Infof("Error issuing certificate for %s/%s: %v", crt.Namespace, crt.Name, err)
return err
}
@ -294,6 +277,7 @@ func (c *Controller) issue(ctx context.Context, issuer issuer.Interface, crt *v1
s = messageCertificateIssued
glog.Info(s)
c.recorder.Event(crt, api.EventTypeNormal, successCertificateIssued, s)
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionTrue, successCertificateIssued, s, true)
return nil
}
@ -303,18 +287,13 @@ func (c *Controller) issue(ctx context.Context, issuer issuer.Interface, crt *v1
// and private key will be stored in the named secret
func (c *Controller) renew(ctx context.Context, issuer issuer.Interface, crt *v1alpha1.Certificate) error {
var err error
s := messagePreparingCertificate
glog.Info(s)
c.recorder.Event(crt, api.EventTypeNormal, reasonPreparingCertificate, s)
glog.Info("Preparing certificate %s/%s with issuer", crt.Namespace, crt.Name)
if err = issuer.Prepare(ctx, crt); err != nil {
s := messageErrorPreparingCertificate + err.Error()
glog.Info(s)
c.recorder.Event(crt, api.EventTypeWarning, errorPreparingCertificate, s)
glog.Info("Error preparing issuer for certificate %s/%s: %v", crt.Namespace, crt.Name, err)
return err
}
s = messageRenewingCertificate
s := messageRenewingCertificate
glog.Info(s)
c.recorder.Event(crt, api.EventTypeNormal, reasonRenewingCertificate, s)
@ -322,9 +301,6 @@ func (c *Controller) renew(ctx context.Context, issuer issuer.Interface, crt *v1
key, cert, err = issuer.Renew(ctx, crt)
if err != nil {
s := messageErrorRenewingCertificate + err.Error()
glog.Info(s)
c.recorder.Event(crt, api.EventTypeWarning, errorRenewingCertificate, s)
return err
}
@ -338,6 +314,7 @@ func (c *Controller) renew(ctx context.Context, issuer issuer.Interface, crt *v1
s = messageCertificateRenewed
glog.Info(s)
c.recorder.Event(crt, api.EventTypeNormal, successCertificateRenewed, s)
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionTrue, successCertificateRenewed, s, true)
return nil
}

View File

@ -9,6 +9,7 @@ import (
"fmt"
"github.com/golang/glog"
corev1 "k8s.io/api/core/v1"
k8sErrors "k8s.io/apimachinery/pkg/api/errors"
"github.com/jetstack/cert-manager/pkg/apis/certmanager/v1alpha1"
@ -19,13 +20,9 @@ import (
)
const (
errorIssueCert = "ErrIssueCert"
errorIssueError = "IssueError"
successCertIssued = "CertIssueSuccess"
messageErrorIssueCert = "Error issuing TLS certificate: "
messageCertIssued = "Certificate issued successfully"
successCertIssued = "CertIssued"
)
func (a *Acme) obtainCertificate(ctx context.Context, crt *v1alpha1.Certificate) ([]byte, []byte, error) {
@ -34,15 +31,18 @@ func (a *Acme) obtainCertificate(ctx context.Context, crt *v1alpha1.Certificate)
cl, err := a.acmeClient()
if err != nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorIssueError, fmt.Sprintf("Failed to get ACME client: %v", err), false)
return nil, nil, fmt.Errorf("error creating ACME client: %s", err.Error())
}
orderURL := crt.Status.ACMEStatus().Order.URL
if orderURL == "" {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorInvalidConfig, "status.acme.order.url must be set", false)
return nil, nil, fmt.Errorf("certificate order url cannot be blank")
}
order, err := cl.GetOrder(ctx, orderURL)
if err != nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorIssueError, fmt.Sprintf("Failed to get order details: %v", err), false)
return nil, nil, fmt.Errorf("error getting order details: %v", err)
}
@ -51,10 +51,12 @@ func (a *Acme) obtainCertificate(ctx context.Context, crt *v1alpha1.Certificate)
if k8sErrors.IsNotFound(err) || errors.IsInvalidData(err) {
key, err = pki.GenerateRSAPrivateKey(2048)
if err != nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorIssueError, fmt.Sprintf("Failed to generate certificate private key: %v", err), false)
return nil, nil, fmt.Errorf("error generating private key: %s", err.Error())
}
}
if err != nil {
// don't log these errors to the api as they are likely transient
return nil, nil, fmt.Errorf("error getting certificate private key: %s", err.Error())
}
@ -62,6 +64,7 @@ func (a *Acme) obtainCertificate(ctx context.Context, crt *v1alpha1.Certificate)
template := pki.GenerateCSR(commonName, altNames...)
csr, err := x509.CreateCertificateRequest(rand.Reader, template, key)
if err != nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorIssueError, fmt.Sprintf("Failed to generate certificate request: %v", err), false)
return nil, nil, fmt.Errorf("error creating certificate request: %s", err)
}
@ -81,6 +84,8 @@ func (a *Acme) obtainCertificate(ctx context.Context, crt *v1alpha1.Certificate)
// condition here so back off can be applied?
}
}
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorIssueError, fmt.Sprintf("Failed to finalize order: %v", err), false)
a.recorder.Eventf(crt, corev1.EventTypeWarning, errorIssueError, "Failed to finalize order: %v", err)
return nil, nil, fmt.Errorf("error getting certificate from acme server: %s", err)
}
@ -90,7 +95,9 @@ func (a *Acme) obtainCertificate(ctx context.Context, crt *v1alpha1.Certificate)
pem.Encode(certBuffer, &pem.Block{Type: "CERTIFICATE", Bytes: cert})
}
glog.V(2).Infof("successfully got certificate: cn=%q altNames=%+v url=%q", commonName, altNames, orderURL)
a.recorder.Eventf(crt, corev1.EventTypeNormal, successCertIssued, "Obtained certificate from ACME server")
glog.Infof("successfully obtained certificate: cn=%q altNames=%+v url=%q", commonName, altNames, orderURL)
// encode the private key and return
return pki.EncodePKCS1PrivateKey(key), certBuffer.Bytes(), nil
}
@ -98,12 +105,7 @@ func (a *Acme) obtainCertificate(ctx context.Context, crt *v1alpha1.Certificate)
func (a *Acme) Issue(ctx context.Context, crt *v1alpha1.Certificate) ([]byte, []byte, error) {
key, cert, err := a.obtainCertificate(ctx, crt)
if err != nil {
s := messageErrorIssueCert + err.Error()
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorIssueCert, s, false)
return nil, nil, err
}
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionTrue, successCertIssued, messageCertIssued, false)
return key, cert, err
}

View File

@ -6,6 +6,8 @@ import (
"reflect"
"time"
corev1 "k8s.io/api/core/v1"
"github.com/golang/glog"
"github.com/jetstack/cert-manager/pkg/apis/certmanager/v1alpha1"
"github.com/jetstack/cert-manager/pkg/issuer/acme/client"
@ -14,21 +16,17 @@ import (
)
const (
successObtainedAuthorization = "ObtainAuthorization"
reasonPresentChallenge = "PresentChallenge"
reasonSelfCheck = "SelfCheck"
errorGetACMEAccount = "ErrGetACMEAccount"
errorCheckAuthorization = "ErrCheckAuthorization"
errorObtainAuthorization = "ErrObtainAuthorization"
errorInvalidConfig = "ErrInvalidConfig"
reasonCreateOrder = "CreateOrder"
reasonDomainVerified = "DomainVerified"
reasonSelfCheck = "SelfCheck"
messageObtainedAuthorization = "Obtained authorization for domain %s"
messagePresentChallenge = "Presenting %s challenge for domain %s"
messageSelfCheck = "Performing self-check for domain %s"
messageErrorGetACMEAccount = "Error getting ACME account: "
messageErrorCheckAuthorization = "Error checking ACME domain validation: "
messageErrorObtainAuthorization = "Error obtaining ACME domain authorization: "
messageErrorMissingConfig = "certificate.spec.acme must be specified"
errorInvalidConfig = "InvalidConfig"
errorCleanupError = "CleanupError"
errorPresentError = "PresentError"
errorBackoff = "Backoff"
messagePresentChallenge = "Presenting %s challenge for domain %s"
messageSelfCheck = "Performing self-check for domain %s"
// the amount of time to wait before attempting to create a new order after
// an order has failed.s
@ -42,14 +40,15 @@ const (
// challenge requests if neccessary.
func (a *Acme) Prepare(ctx context.Context, crt *v1alpha1.Certificate) error {
if crt.Spec.ACME == nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorInvalidConfig, messageErrorMissingConfig, false)
return fmt.Errorf(messageErrorMissingConfig)
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorInvalidConfig, "spec.acme must be specified", false)
return fmt.Errorf("spec.acme not specified on certificate %s/%s", crt.Namespace, crt.Name)
}
glog.V(4).Infof("Getting ACME client")
// obtain an ACME client
cl, err := a.acmeClient()
if err != nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorPresentError, fmt.Sprintf("Failed to get ACME client: %v", err), false)
return err
}
@ -58,6 +57,7 @@ func (a *Acme) Prepare(ctx context.Context, crt *v1alpha1.Certificate) error {
// acme server.
nextPresentIn, order, err := a.shouldAttemptValidation(ctx, cl, crt)
if err != nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorPresentError, fmt.Sprintf("Failed to determine order status: %v", err), false)
return err
}
@ -66,6 +66,7 @@ func (a *Acme) Prepare(ctx context.Context, crt *v1alpha1.Certificate) error {
if order == nil {
err := a.cleanupLastOrder(ctx, crt)
if err != nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorPresentError, fmt.Sprintf("Failed to clean up previous order: %v", err), false)
return err
}
}
@ -74,6 +75,7 @@ func (a *Acme) Prepare(ctx context.Context, crt *v1alpha1.Certificate) error {
// will be requeued.
if nextPresentIn > 0 {
nextPresentTimeStr := time.Now().Add(nextPresentIn).Format(time.RFC822Z)
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorBackoff, fmt.Sprintf("Backing off %s until attempting re-validation", nextPresentIn), false)
return fmt.Errorf("not attempting acme validation until %s", nextPresentTimeStr)
}
@ -82,8 +84,10 @@ func (a *Acme) Prepare(ctx context.Context, crt *v1alpha1.Certificate) error {
if order == nil {
order, err = a.createOrder(ctx, cl, crt)
if err != nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorPresentError, fmt.Sprintf("Failed to create new order: %v", err), false)
return err
}
a.recorder.Eventf(crt, corev1.EventTypeNormal, reasonCreateOrder, "Created new ACME order, attempting validation...")
}
// attempt to present/validate the order
@ -93,8 +97,7 @@ func (a *Acme) Prepare(ctx context.Context, crt *v1alpha1.Certificate) error {
func (a *Acme) presentOrder(ctx context.Context, cl client.Interface, crt *v1alpha1.Certificate, order *acme.Order) error {
allAuthorizations, err := getRemainingAuthorizations(ctx, cl, order.Authorizations...)
if err != nil {
// TODO: update status condition?
// TODO: log an event?
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorPresentError, fmt.Sprintf("Failed to determine authorizations to obtain: %v", err), false)
return err
}
@ -104,15 +107,13 @@ func (a *Acme) presentOrder(ctx context.Context, cl client.Interface, crt *v1alp
chs, err := a.selectChallengesForAuthorizations(ctx, cl, crt, allAuthorizations...)
errCleanup := a.cleanupIrrelevantChallenges(ctx, crt, chs)
if errCleanup != nil {
// TODO: update status condition?
// TODO: log an event?
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorCleanupError, fmt.Sprintf("Failed to clean up old challenges: %v", err), false)
// perhaps we should just throw a warning here instead of erroring.
// for now, return an error to pick up bugs in this codepath
return err
}
if err != nil {
// TODO: update status condition?
// TODO: log an event?
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorInvalidConfig, err.Error(), false)
return err
}
@ -129,6 +130,9 @@ func (a *Acme) presentOrder(ctx context.Context, cl client.Interface, crt *v1alp
// passing, to save the number of 'accept' operations sent to the acme server.
err = utilerrors.NewAggregate(errs)
if err != nil {
// we set forceTime to true so the user can see the self check is being
// performed regularly
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorPresentError, err.Error(), true)
return err
}
@ -137,16 +141,17 @@ func (a *Acme) presentOrder(ctx context.Context, cl client.Interface, crt *v1alp
// compute the new challenge list after cleaning up successful challenges
var newChallengeList []v1alpha1.ACMEOrderChallenge
for _, ch := range chs {
acceptChalErr := a.acceptChallenge(ctx, cl, ch)
acceptChalErr := a.acceptChallenge(ctx, cl, crt, ch)
errs = append(errs, acceptChalErr)
// only clean up if this stage suceeded.
// If it fails, an error will be returned anyway and our standard
// failed-validation cleanup logic will be invoked.
if acceptChalErr == nil {
err := a.cleanupChallenge(ctx, crt, ch)
errs = append(errs, err)
if err != nil {
newChallengeList = append(newChallengeList, ch)
return err
continue
}
} else {
newChallengeList = append(newChallengeList, ch)
@ -154,7 +159,13 @@ func (a *Acme) presentOrder(ctx context.Context, cl client.Interface, crt *v1alp
}
crt.Status.ACMEStatus().Order.Challenges = newChallengeList
return utilerrors.NewAggregate(errs)
err = utilerrors.NewAggregate(errs)
if err != nil {
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorPresentError, err.Error(), false)
return err
}
return nil
}
// presentChallenge will process a challenge by talking to the acme server and
@ -183,7 +194,7 @@ func (a *Acme) presentChallenge(ctx context.Context, cl client.Interface, crt *v
return fmt.Errorf("challenge for domain %q failed: %s", ch.Domain, acmeErrReason)
case acme.StatusPending, acme.StatusProcessing:
default:
return fmt.Errorf("unknown acme challenge status %q", acmeCh.Status)
return fmt.Errorf("unknown acme challenge status %q for domain %q", acmeCh.Status, ch.Domain)
}
solver, err := a.solverFor(ch.Type)
@ -201,7 +212,7 @@ func (a *Acme) presentChallenge(ctx context.Context, cl client.Interface, crt *v
return err
}
if !ok {
return fmt.Errorf("Self check (%s) failed for domain %q", ch.Type, ch.Domain)
return fmt.Errorf("%s self check failed for domain %q", ch.Type, ch.Domain)
}
return nil
@ -427,7 +438,7 @@ func (a *Acme) shouldAttemptValidation(ctx context.Context, cl client.Interface,
return 0, nil, fmt.Errorf("unrecognised existing acme order status: %q", order.Status)
}
func (a *Acme) acceptChallenge(ctx context.Context, cl client.Interface, ch v1alpha1.ACMEOrderChallenge) error {
func (a *Acme) acceptChallenge(ctx context.Context, cl client.Interface, crt *v1alpha1.Certificate, ch v1alpha1.ACMEOrderChallenge) error {
glog.Infof("Accepting challenge for domain %q", ch.Domain)
// We manually construct an ACME challenge here from our own internal type
// to save additional round trips to the ACME server.
@ -451,6 +462,7 @@ func (a *Acme) acceptChallenge(ctx context.Context, cl client.Interface, ch v1al
}
glog.Infof("Successfully authorized domain %q", authorization.Identifier.Value)
a.recorder.Eventf(crt, corev1.EventTypeNormal, reasonDomainVerified, "Domain %q verified with %q validation", ch.Domain, ch.Type)
return nil
}

View File

@ -6,23 +6,10 @@ import (
"github.com/jetstack/cert-manager/pkg/apis/certmanager/v1alpha1"
)
const (
errorRenewCert = "ErrRenewCert"
messageErrorRenewCert = "Error renewing TLS certificate: "
successCertRenewed = "CertRenewSuccess"
messageCertRenewed = "Certificate renewed successfully"
)
func (a *Acme) Renew(ctx context.Context, crt *v1alpha1.Certificate) ([]byte, []byte, error) {
key, cert, err := a.obtainCertificate(ctx, crt)
if err != nil {
s := messageErrorIssueCert + err.Error()
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionFalse, errorRenewCert, s, false)
return nil, nil, err
}
crt.UpdateStatusCondition(v1alpha1.CertificateConditionReady, v1alpha1.ConditionTrue, successCertRenewed, messageCertRenewed, false)
return key, cert, err
}