Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Unfortunate cert renew handling of 30d < TTL < 90d #3897

Closed
andreas-p opened this issue Apr 16, 2021 · 5 comments · Fixed by #4040
Closed

Unfortunate cert renew handling of 30d < TTL < 90d #3897

andreas-p opened this issue Apr 16, 2021 · 5 comments · Fixed by #4040
Labels
area/vault Indicates a PR directly modifies the Vault Issuer code kind/bug Categorizes issue or PR as related to a bug. priority/important-longterm Important over the long term, but may not be staffed and/or may need multiple releases to complete.
Milestone

Comments

@andreas-p
Copy link

Since I can't reopen the issue #3813, here's a new one:

Despite the code handling certificate TTLs <= 30d, I encountered the renew loop as mentioned in #3813 with cert-manager 1.20, when Vault issues certificates with TTL=30d.

Instead of the current code, renewBefore should be calculated as min(TTL/3, 30d) to get a sane renew period for TTLs between 30d and 90d.

@daniel-sullivan
Copy link

I'd like to throw my voice into this matter when using a slightly modified version of the example config here: https://cert-manager.io/docs/installation/kubernetes/

apiVersion: cert-manager.io/v1
kind: Certificate
metadata:
  name: selfsigned-cert-test
  namespace: cert-manager
spec:
  commonName: test.mgmt.company.internal
  dnsNames:
    - test.mgmt.charm.internal
  secretName: selfsigned-cert-tls
  issuerRef:
    name: vault-issuer
    kind: ClusterIssuer

The above caused the aforementioned renew loop.

Fixed using the following config:

apiVersion: cert-manager.io/v1
kind: Certificate
metadata:
  name: selfsigned-cert-test
  namespace: cert-manager
spec:
  commonName: test.mgmt.company.internal
  duration: 2160h
  renewBefore: 360h
  dnsNames:
    - test.mgmt.charm.internal
  secretName: selfsigned-cert-tls
  issuerRef:
    name: vault-issuer
    kind: ClusterIssuer

We are running 1.3.0 simply deployed using:

kubectl apply -f https://github.com/jetstack/cert-manager/releases/download/v1.3.0/cert-manager.yaml

@irbekrm
Copy link
Collaborator

irbekrm commented May 7, 2021

Thanks for opening the issue!

Same issue here on Slack, I was not able to reproduce this then, but seem to be able to reproduce it now with cert-manager v1.3.1.

To reproduce follow steps here except for:

  1. Deploy a newer version of cert-manager and use v1 not v1alpha2 api when creating cert-manager resources
  2. Set max_ttl to 720h (30d) when creating the Vault role that `cert-manager will use
vault write pki/roles/example-dot-com \
    allowed_domains=example.com \
    allow_subdomains=true \
    max_ttl=720h

After creating the Certificate cert-manager entered a continuous renewal loop, see status of the Certificate:

status:
  conditions:
  - lastTransitionTime: "2021-05-07T09:05:36Z"
    message: Certificate is up to date and has not expired
    observedGeneration: 1
    reason: Ready
    status: "True"
    type: Ready
  - lastTransitionTime: "2021-05-07T09:06:50Z"
    message: Renewing certificate as renewal was scheduled at 2021-05-07 09:06:50
      +0000 UTC
    observedGeneration: 1
    reason: Renewing
    status: "True"
    type: Issuing
  nextPrivateKeySecretName: example-com-l2g4c
  notAfter: "2021-06-06T09:06:50Z"
  notBefore: "2021-05-07T09:06:20Z"
  renewalTime: "2021-05-07T09:06:50Z"
  revision: 185

@irbekrm irbekrm added kind/bug Categorizes issue or PR as related to a bug. area/vault Indicates a PR directly modifies the Vault Issuer code priority/important-longterm Important over the long term, but may not be staffed and/or may need multiple releases to complete. labels May 7, 2021
@irbekrm
Copy link
Collaborator

irbekrm commented May 8, 2021

/milestone v1.4

@jetstack-bot jetstack-bot added this to the v1.4 milestone May 8, 2021
@irbekrm
Copy link
Collaborator

irbekrm commented May 8, 2021

Instead of the current code, renewBefore should be calculated as min(TTL/3, 30d)

Agreed.
It could also make sense to refactor RenewBeforeExpiryDuration to return renewal time instead (see this TODO)- it is currently somewhat non-intuitive what it does which is probably why we missed this edge case.

@maelvls
Copy link
Member

maelvls commented Jun 14, 2021

I was able to check that the "hot-looping" is gone! Thank you @irbekrm for your thorough instructions for reproducing the bug. For later reference I recorded all the steps in this gist.

Before: 1.3.1 hot-loop ❌
E0614 08:25:42.341280       1 controller.go:158] cert-manager/controller/certificates-issuing "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
E0614 08:25:42.391172       1 controller.go:158] cert-manager/controller/certificates-readiness "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:42.440345       1 trigger_controller.go:189] cert-manager/controller/certificates-trigger "msg"="Certificate must be re-issued" "key"="default/example-com" "message"="Renewing certificate as renewal was scheduled at 2021-06-14 08:25:42 +0000 UTC" "reason"="Renewing"
I0614 08:25:42.440364       1 conditions.go:182] Setting lastTransitionTime for Certificate "example-com" condition "Issuing" to 2021-06-14 08:25:42.440361669 +0000 UTC m=+86.389069751
E0614 08:25:42.541436       1 controller.go:158] cert-manager/controller/certificates-key-manager "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:42.587701       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-p7452" condition "Approved" to 2021-06-14 08:25:42.587694028 +0000 UTC m=+86.536402120
I0614 08:25:42.595409       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-p7452" condition "Ready" to 2021-06-14 08:25:42.595403257 +0000 UTC m=+86.544111349
E0614 08:25:42.688826       1 controller.go:158] cert-manager/controller/certificaterequests-issuer-vault "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificaterequests.cert-manager.io \"example-com-p7452\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com-p7452"
I0614 08:25:42.694587       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-p7452" condition "Ready" to 2021-06-14 08:25:42.694582692 +0000 UTC m=+86.643290784
I0614 08:25:42.789970       1 trigger_controller.go:189] cert-manager/controller/certificates-trigger "msg"="Certificate must be re-issued" "key"="default/example-com" "message"="Renewing certificate as renewal was scheduled at 2021-06-14 08:25:42 +0000 UTC" "reason"="Renewing"
I0614 08:25:42.789990       1 conditions.go:182] Setting lastTransitionTime for Certificate "example-com" condition "Issuing" to 2021-06-14 08:25:42.789986584 +0000 UTC m=+86.738694676
E0614 08:25:42.889852       1 controller.go:158] cert-manager/controller/certificates-issuing "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
E0614 08:25:42.942085       1 controller.go:158] cert-manager/controller/certificates-key-manager "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:42.989094       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-tplcx" condition "Approved" to 2021-06-14 08:25:42.989087615 +0000 UTC m=+86.937795717
I0614 08:25:43.045876       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-tplcx" condition "Ready" to 2021-06-14 08:25:43.045869854 +0000 UTC m=+86.994577956
E0614 08:25:43.191825       1 controller.go:158] cert-manager/controller/certificates-issuing "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
E0614 08:25:43.242712       1 controller.go:158] cert-manager/controller/certificates-readiness "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:43.290881       1 trigger_controller.go:189] cert-manager/controller/certificates-trigger "msg"="Certificate must be re-issued" "key"="default/example-com" "message"="Renewing certificate as renewal was scheduled at 2021-06-14 08:25:43 +0000 UTC" "reason"="Renewing"
I0614 08:25:43.290897       1 conditions.go:182] Setting lastTransitionTime for Certificate "example-com" condition "Issuing" to 2021-06-14 08:25:43.29089462 +0000 UTC m=+87.239602712
E0614 08:25:43.390885       1 controller.go:158] cert-manager/controller/certificates-key-manager "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:43.437953       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-lxm6s" condition "Approved" to 2021-06-14 08:25:43.437948137 +0000 UTC m=+87.386656219
I0614 08:25:43.496797       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-lxm6s" condition "Ready" to 2021-06-14 08:25:43.496789742 +0000 UTC m=+87.445497824
I0614 08:25:43.590908       1 trigger_controller.go:189] cert-manager/controller/certificates-trigger "msg"="Certificate must be re-issued" "key"="default/example-com" "message"="Renewing certificate as renewal was scheduled at 2021-06-14 08:25:43 +0000 UTC" "reason"="Renewing"
I0614 08:25:43.590927       1 conditions.go:182] Setting lastTransitionTime for Certificate "example-com" condition "Issuing" to 2021-06-14 08:25:43.590925279 +0000 UTC m=+87.539633361
E0614 08:25:43.691141       1 controller.go:158] cert-manager/controller/certificates-key-manager "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
E0614 08:25:43.741897       1 controller.go:158] cert-manager/controller/certificates-issuing "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:43.789422       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-z6vfr" condition "Approved" to 2021-06-14 08:25:43.789414562 +0000 UTC m=+87.738122654
E0614 08:25:43.890094       1 controller.go:158] cert-manager/controller/certificaterequests-approver "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificaterequests.cert-manager.io \"example-com-z6vfr\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com-z6vfr"
I0614 08:25:43.890124       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-z6vfr" condition "Approved" to 2021-06-14 08:25:43.89012009 +0000 UTC m=+87.838828182
I0614 08:25:43.948515       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-z6vfr" condition "Ready" to 2021-06-14 08:25:43.94850995 +0000 UTC m=+87.897218032
I0614 08:25:44.041232       1 trigger_controller.go:189] cert-manager/controller/certificates-trigger "msg"="Certificate must be re-issued" "key"="default/example-com" "message"="Renewing certificate as renewal was scheduled at 2021-06-14 08:25:43 +0000 UTC" "reason"="Renewing"
I0614 08:25:44.041255       1 conditions.go:182] Setting lastTransitionTime for Certificate "example-com" condition "Issuing" to 2021-06-14 08:25:44.041250988 +0000 UTC m=+87.989959080
E0614 08:25:44.140873       1 controller.go:158] cert-manager/controller/certificates-issuing "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
E0614 08:25:44.190471       1 controller.go:158] cert-manager/controller/certificates-key-manager "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:44.239244       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-stjwx" condition "Approved" to 2021-06-14 08:25:44.239236218 +0000 UTC m=+88.187944330
I0614 08:25:44.293585       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-stjwx" condition "Ready" to 2021-06-14 08:25:44.293580385 +0000 UTC m=+88.242288467
E0614 08:25:44.440544       1 controller.go:158] cert-manager/controller/certificates-issuing "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
E0614 08:25:44.492954       1 controller.go:158] cert-manager/controller/certificates-readiness "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:44.540297       1 trigger_controller.go:189] cert-manager/controller/certificates-trigger "msg"="Certificate must be re-issued" "key"="default/example-com" "message"="Renewing certificate as renewal was scheduled at 2021-06-14 08:25:44 +0000 UTC" "reason"="Renewing"
I0614 08:25:44.540315       1 conditions.go:182] Setting lastTransitionTime for Certificate "example-com" condition "Issuing" to 2021-06-14 08:25:44.540312506 +0000 UTC m=+88.489020598
E0614 08:25:44.640953       1 controller.go:158] cert-manager/controller/certificates-key-manager "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:44.687793       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-ndjc2" condition "Approved" to 2021-06-14 08:25:44.687784197 +0000 UTC m=+88.636492309
E0614 08:25:44.787147       1 controller.go:158] cert-manager/controller/certificaterequests-approver "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificaterequests.cert-manager.io \"example-com-ndjc2\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com-ndjc2"
I0614 08:25:44.787175       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-ndjc2" condition "Approved" to 2021-06-14 08:25:44.787171962 +0000 UTC m=+88.735880054
I0614 08:25:44.845047       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-ndjc2" condition "Ready" to 2021-06-14 08:25:44.845041182 +0000 UTC m=+88.793749264
I0614 08:25:44.939781       1 trigger_controller.go:189] cert-manager/controller/certificates-trigger "msg"="Certificate must be re-issued" "key"="default/example-com" "message"="Renewing certificate as renewal was scheduled at 2021-06-14 08:25:44 +0000 UTC" "reason"="Renewing"
I0614 08:25:44.939797       1 conditions.go:182] Setting lastTransitionTime for Certificate "example-com" condition "Issuing" to 2021-06-14 08:25:44.939795375 +0000 UTC m=+88.888503457
E0614 08:25:45.040939       1 controller.go:158] cert-manager/controller/certificates-issuing "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
E0614 08:25:45.091132       1 controller.go:158] cert-manager/controller/certificates-key-manager "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:45.138539       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-6zkqg" condition "Approved" to 2021-06-14 08:25:45.138529396 +0000 UTC m=+89.087237498
I0614 08:25:45.195824       1 conditions.go:242] Setting lastTransitionTime for CertificateRequest "example-com-6zkqg" condition "Ready" to 2021-06-14 08:25:45.195817356 +0000 UTC m=+89.144525448
E0614 08:25:45.339247       1 controller.go:158] cert-manager/controller/certificates-issuing "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
E0614 08:25:45.391186       1 controller.go:158] cert-manager/controller/certificates-readiness "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
I0614 08:25:45.440188       1 trigger_controller.go:189] cert-manager/controller/certificates-trigger "msg"="Certificate must be re-issued" "key"="default/example-com" "message"="Renewing certificate as renewal was scheduled at 2021-06-14 08:25:45 +0000 UTC" "reason"="Renewing"
I0614 08:25:45.440208       1 conditions.go:182] Setting lastTransitionTime for Certificate "example-com" condition "Issuing" to 2021-06-14 08:25:45.4402043 +0000 UTC m=+89.388912392
E0614 08:25:45.541499       1 controller.go:158] cert-manager/controller/certificates-key-manager "msg"="re-queuing item due to error processing" "error"="Operation cannot be fulfilled on certificates.cert-manager.io \"example-com\": the object has been modified; please apply your changes to the latest version and try again" "key"="default/example-com"
After: 1.4.0-beta.1 no hot-loop ✅
E0614 08:57:47.670206       1 trigger_controller.go:145] cert-manager/controller/certificates-trigger "msg"="certificate not found for key" "error"="certificate.cert-manager.io \"example-com\" not found" "key"="default/example-com"
E0614 08:57:47.670215       1 readiness_controller.go:142] cert-manager/controller/certificates-readiness "msg"="certificate not found for key" "error"="certificate.cert-manager.io \"example-com\" not found" "key"="default/example-com"
E0614 08:57:47.670223       1 issuing_controller.go:152] cert-manager/controller/certificates-issuing "msg"="certificate not found for key" "error"="certificate.cert-manager.io \"example-com\" not found" "key"="default/example-com"
E0614 08:57:47.670223       1 keymanager_controller.go:139] cert-manager/controller/certificates-key-manager "msg"="certificate not found for key" "error"="certificate.cert-manager.io \"example-com\" not found" "key"="default/example-com"
E0614 08:57:47.670242       1 revisionmanager_controller.go:106] cert-manager/controller/certificates-revision-manager "msg"="certificate not found for key" "error"="certificate.cert-manager.io \"example-com\" not found" "key"="default/example-com"
E0614 08:57:47.670252       1 requestmanager_controller.go:129] cert-manager/controller/certificates-request-manager "msg"="certificate not found for key" "error"="certificate.cert-manager.io \"example-com\" not found" "key"="default/example-com"
E0614 08:57:54.106654       1 controller.go:133] cert-manager/controller/issuers "msg"="issuer in work queue no longer exists" "error"="issuer.cert-manager.io \"vault-issuer\" not found"
I0614 08:58:14.984856       1 conditions.go:95] Setting lastTransitionTime for Issuer "vault-issuer" condition "Ready" to 2021-06-14 08:58:14.984849264 +0000 UTC m=+1527.528824317
I0614 08:58:15.153809       1 conditions.go:182] Setting lastTransitionTime for Certificate "example-com" condition "Ready" to 2021-06-14 08:58:15.15380204 +0000 UTC m=+1527.697777113

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/vault Indicates a PR directly modifies the Vault Issuer code kind/bug Categorizes issue or PR as related to a bug. priority/important-longterm Important over the long term, but may not be staffed and/or may need multiple releases to complete.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants