Cert-manager: Too much logs

[divo1]

Describe the bug:
I have lot this kind logs:
I0215 01:22:59.136211 1 sync.go:303] cert-manager/controller/certificates "msg"="updated Secret resource metadata as it was out of date" "related_resource_kind"="CertificateRequest" "related_resource_name"="xxx" "related_resource_namespace"="xxx" "resource_kind"="Certificate" "resource_name"="storage-test-pl" "resource_namespace"="xxx"

Expected behaviour:
I won't see it in log

Steps to reproduce the bug:
Install v0.13.0 with command:
helm install --name cert-manager --namespace cert-manager --version v0.13.0 jetstack/cert-manager --set global.logLevel=2

Anything else we need to know?:
I had same problem with v0.12.0 version, after that I upgrade it to v0.13.0, but still it happend. Now I was deleted cert-manager by helm and install it again with logLevel, but still the same. I was trying to set logLevel to different value. I saw that logLevel was changed in yaml on kubernetes but even then there are too much logs.

/kind bug

[munnerz]

I think this issue is the same as the one solved by #2543. We'll be releasing v0.13.1 later today which includes this patch, so if you could report back on v0.13.1 that'd be great :)

[divo1]

@munnerz Big thanks for reply! Unfortunately v0.13.1 won't work :( I have this kind of errors:

I0218 23:00:24.137593 1 controller.go:129] cert-manager/controller/certificates "msg"="syncing item" "key"="xxx/xxx"
I0218 23:00:24.145370 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="978h38m41.854693579s" "related_resource_kind"="Secret" "related_resource_name"="xxx" "related_resource_namespace"="xxx" "resource_kind"="Certificate" "resource_name"="xxx" "resource_namespace"="xxx"
I0218 23:00:24.145520 1 sync.go:310] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="xxx-2807894422" "related_resource_namespace"="xxx" "resource_kind"="Certificate" "resource_name"="xxx" "resource_namespace"="xxx"
I0218 23:00:24.146492 1 controller.go:135] cert-manager/controller/certificates "msg"="finished processing work item" "key"="xxx/xxx"

helm list
NAME            REVISION        UPDATED                         STATUS          CHART                   APP VERSION    NAMESPACE
cert-manager    2               Tue Feb 18 23:58:12 2020        DEPLOYED        cert-manager-v0.13.1    v0.13.1        cert-manager

[divo1]

/reopen This still send lot of logs... Many, many informations as I write above.

[munnerz]

Those messages do not seem like errors to me, that is the 'happy case' for the controller, where it's detected that a certificate is up to date and nothing more needs to happen.

Can you share a full log file? Perhaps putting it into a GitHub gist would be best 😄

If you're also seeing a lot of repeated logs similar to what you've shared above, it may be worthwhile turning up the log 'level' using the --v=4 flag on the 'controller' component before sharing those logs, as they'll then contain a lot more debugging info for us to work with 😄

(ps, you need to put / commands onto their own line when commenting else they won't work!)

/reopen

[jetstack-bot]

@munnerz: Reopened this issue.

In response to this:

Those messages do not seem like errors to me, that is the 'happy case' for the controller, where it's detected that a certificate is up to date and nothing more needs to happen.

Can you share a full log file? Perhaps putting it into a GitHub gist would be best 😄

If you're also seeing a lot of repeated logs similar to what you've shared above, it may be worthwhile turning up the log 'level' using the --v=4 flag on the 'controller' component before sharing those logs, as they'll then contain a lot more debugging info for us to work with 😄

(ps, you need to put / commands onto their own line when commenting else they won't work!)

/reopen

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

[marvel-vella]

I am having this issue as well on v0.14.1.

I understand cert-manager is reporting the 'happy state' - but why does it have to do this thousands of times per hour?

In my case I am seeing this line "controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/xxxxxxxx-cert" 36,000 times per hour.

To me it looks like cert-manager is checking the certificates too frequently.

Can this be limited in some way? I think checking the certificate once an hour would be enough

[erSitzt]

Same here with v0.15.0

It looks like cert-manager is rescheduling the renewal only to try again instantly and flooding my logs

I0513 11:21:22.793057       1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-tls-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-tls" "resource_namespace"="dmz"
I0513 11:21:22.794152       1 controller.go:147] cert-manager/controller/certificates "msg"="finished processing work item" "key"="dmz/idp-mydomain-de-tls"
I0513 11:21:22.979341       1 sync.go:304] cert-manager/controller/certificates "msg"="updated Secret resource metadata as it was out of date" "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-test5-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:22.988426       1 controller.go:141] cert-manager/controller/certificates "msg"="syncing item" "key"="dmz/idp-mydomain-de-tls"
I0513 11:21:23.001435       1 util.go:178] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1219h43m51.998895012s" "related_resource_kind"="Secret" "related_resource_name"="idp-mydomain-de-tls" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:23.002359       1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-test5-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:23.004549       1 controller.go:147] cert-manager/controller/certificates "msg"="finished processing work item" "key"="dmz/idp-mydomain-de-test5"
I0513 11:21:23.005343       1 controller.go:141] cert-manager/controller/certificates "msg"="syncing item" "key"="dmz/idp-mydomain-de-test5"
I0513 11:21:23.011673       1 util.go:178] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1219h43m51.988403947s" "related_resource_kind"="Secret" "related_resource_name"="idp-mydomain-de-tls" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:23.011741       1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-test5-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:23.012636       1 controller.go:147] cert-manager/controller/certificates "msg"="finished processing work item" "key"="dmz/idp-mydomain-de-test5"
I0513 11:21:23.175336       1 controller.go:141] cert-manager/controller/certificates "msg"="syncing item" "key"="dmz/idp-mydomain-de-test5"
I0513 11:21:23.182860       1 sync.go:304] cert-manager/controller/certificates "msg"="updated Secret resource metadata as it was out of date" "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-tls-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-tls" "resource_namespace"="dmz"
I0513 11:21:23.186944       1 util.go:178] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1219h43m51.813175306s" "related_resource_kind"="Secret" "related_resource_name"="idp-mydomain-de-tls" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-tls" "resource_namespace"="dmz"
I0513 11:21:23.198010       1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-tls-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-tls" "resource_namespace"="dmz"
I0513 11:21:23.199281       1 controller.go:147] cert-manager/controller/certificates "msg"="finished processing work item" "key"="dmz/idp-mydomain-de-tls"
I0513 11:21:23.199364       1 controller.go:141] cert-manager/controller/certificates "msg"="syncing item" "key"="dmz/idp-mydomain-de-tls"
I0513 11:21:23.201373       1 util.go:178] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1219h43m51.798696462s" "related_resource_kind"="Secret" "related_resource_name"="idp-mydomain-de-tls" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-tls" "resource_namespace"="dmz"
I0513 11:21:23.201430       1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-tls-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-tls" "resource_namespace"="dmz"
I0513 11:21:23.202898       1 controller.go:147] cert-manager/controller/certificates "msg"="finished processing work item" "key"="dmz/idp-mydomain-de-tls"
I0513 11:21:23.377331       1 controller.go:141] cert-manager/controller/certificates "msg"="syncing item" "key"="dmz/idp-mydomain-de-tls"
I0513 11:21:23.388144       1 sync.go:304] cert-manager/controller/certificates "msg"="updated Secret resource metadata as it was out of date" "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-test5-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:23.388622       1 util.go:178] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1219h43m51.611440545s" "related_resource_kind"="Secret" "related_resource_name"="idp-mydomain-de-tls" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:23.388685       1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-test5-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:23.389745       1 controller.go:147] cert-manager/controller/certificates "msg"="finished processing work item" "key"="dmz/idp-mydomain-de-test5"
I0513 11:21:23.389792       1 controller.go:141] cert-manager/controller/certificates "msg"="syncing item" "key"="dmz/idp-mydomain-de-test5"
I0513 11:21:23.391079       1 util.go:178] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1219h43m51.608983964s" "related_resource_kind"="Secret" "related_resource_name"="idp-mydomain-de-tls" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:23.391132       1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-test5-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-test5" "resource_namespace"="dmz"
I0513 11:21:23.392126       1 controller.go:147] cert-manager/controller/certificates "msg"="finished processing work item" "key"="dmz/idp-mydomain-de-test5"
I0513 11:21:23.575434       1 sync.go:304] cert-manager/controller/certificates "msg"="updated Secret resource metadata as it was out of date" "related_resource_kind"="CertificateRequest" "related_resource_name"="idp-mydomain-de-tls-1565143486" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-tls" "resource_namespace"="dmz"
I0513 11:21:23.575936       1 util.go:178] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1219h43m51.424130953s" "related_resource_kind"="Secret" "related_resource_name"="idp-mydomain-de-tls" "related_resource_namespace"="dmz" "resource_kind"="Certificate" "resource_name"="idp-mydomain-de-tls" "resource_namespace"="dmz"

[acehead]

Can confirm this happens for me as well (v0.14.3). Tried both with --v=0 and with -v=0 parameters, no effect. In addition it seems that all current log messages are logged with severity level 0 which means that there is no possibility to switch them off.

As other guys mentioned, the number of logs produced takes a lot of space, leaving no option other than exclude all the cert-manager logs before they are send to central location like Elasticsearch.

[sambhav-gore]

I just connected DataDog and seeing 1000s of error per minute :-(
Now I will have to find how to exclude these before going there.

[meyskens]

@sambhav-gore do you see the just same ones as in https://github.com/jetstack/cert-manager/issues/2601#issuecomment-627920425 ?

[sambhav-gore]

@meyskens Yes.

I have a couple of domains there.

here is an excerpt:

2020-05-18T08:10:03.097Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:03.095617 1 controller.go:138] cert-manager/controller/certificates "msg"="syncing item" "key"="default/dada-card.com"
-- | -- | -- | --
2020-05-18T08:10:03.097Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:03.095223 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/dada-card.com"
2020-05-18T08:10:03.093Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:03.090499 1 sync.go:304] cert-manager/controller/certificates "msg"="updated Secret resource metadata as it was out of date" "related_resource_kind"="CertificateRequest" "related_resource_name"="dada-card.com-3434603086" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="dada-card.com" "resource_namespace"="default"
2020-05-18T08:10:02.892Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.891190 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/kali-vcards.com"
2020-05-18T08:10:02.891Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.890463 1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="kali-vcards.com-3284355086" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards.com" "resource_namespace"="default"
2020-05-18T08:10:02.891Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.890413 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1360h28m22.109633548s" "related_resource_kind"="Secret" "related_resource_name"="kali-vcards-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards.com" "resource_namespace"="default"
2020-05-18T08:10:02.891Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.889166 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/kali-vcards.com"
2020-05-18T08:10:02.891Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.886560 1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="kali-vcards.com-3284355086" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards.com" "resource_namespace"="default"
2020-05-18T08:10:02.891Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.886515 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1360h28m22.113528334s" "related_resource_kind"="Secret" "related_resource_name"="kali-vcards-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards.com" "resource_namespace"="default"
2020-05-18T08:10:02.891Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.886124 1 sync.go:304] cert-manager/controller/certificates "msg"="updated Secret resource metadata as it was out of date" "related_resource_kind"="CertificateRequest" "related_resource_name"="kali-vcards.com-3284355086" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards.com" "resource_namespace"="default"
2020-05-18T08:10:02.689Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.689422 1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="Secret" "related_resource_name"="dada-card-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="dada-card-com-tls" "resource_namespace"="default"
2020-05-18T08:10:02.689Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.689326 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1201h45m20.310733003s" "related_resource_kind"="Secret" "related_resource_name"="dada-card-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="dada-card-com-tls" "resource_namespace"="default"
2020-05-18T08:10:02.688Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.688306 1 controller.go:138] cert-manager/controller/certificates "msg"="syncing item" "key"="default/dada-card-com-tls"
2020-05-18T08:10:02.686Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.685618 1 controller.go:138] cert-manager/controller/certificates "msg"="syncing item" "key"="default/dada-card.com"
2020-05-18T08:10:02.492Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.491276 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1360h28m22.50878999s" "related_resource_kind"="Secret" "related_resource_name"="kali-vcards-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards-com-tls" "resource_namespace"="default"
2020-05-18T08:10:02.489Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.489414 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/kali-vcards-com-tls"
2020-05-18T08:10:02.291Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.290819 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/dada-card.com"
2020-05-18T08:10:02.288Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.288080 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/dada-card.com"
2020-05-18T08:10:02.287Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.286429 1 sync.go:304] cert-manager/controller/certificates "msg"="updated Secret resource metadata as it was out of date" "related_resource_kind"="CertificateRequest" "related_resource_name"="dada-card.com-3434603086" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="dada-card.com" "resource_namespace"="default"
2020-05-18T08:10:02.286Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.285185 1 controller.go:138] cert-manager/controller/certificates "msg"="syncing item" "key"="default/dada-card-com-tls"
2020-05-18T08:10:02.093Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.093010 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1360h28m22.907034597s" "related_resource_kind"="Secret" "related_resource_name"="kali-vcards-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards.com" "resource_namespace"="default"
2020-05-18T08:10:02.089Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.088732 1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="kali-vcards.com-3284355086" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards.com" "resource_namespace"="default"
2020-05-18T08:10:02.089Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:02.088693 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1360h28m22.911343093s" "related_resource_kind"="Secret" "related_resource_name"="kali-vcards-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards.com" "resource_namespace"="default"
2020-05-18T08:10:01.888Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.887640 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1201h45m21.112516516s" "related_resource_kind"="Secret" "related_resource_name"="dada-card-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="dada-card-com-tls" "resource_namespace"="default"
2020-05-18T08:10:01.691Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.690780 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1360h28m23.309271048s" "related_resource_kind"="Secret" "related_resource_name"="kali-vcards-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards-com-tls" "resource_namespace"="default"
2020-05-18T08:10:01.689Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.689673 1 controller.go:138] cert-manager/controller/certificates "msg"="syncing item" "key"="default/kali-vcards-com-tls"
2020-05-18T08:10:01.689Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.689483 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/kali-vcards-com-tls"
2020-05-18T08:10:01.689Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.688756 1 controller.go:138] cert-manager/controller/certificates "msg"="syncing item" "key"="default/kali-vcards.com"
2020-05-18T08:10:01.689Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.688343 1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="kali-vcards-com-tls-913567449" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards-com-tls" "resource_namespace"="default"
2020-05-18T08:10:01.491Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.490781 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/dada-card.com"
2020-05-18T08:10:01.304Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.286126 1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="kali-vcards.com-3284355086" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards.com" "resource_namespace"="default"
2020-05-18T08:10:01.105Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.088673 1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="Secret" "related_resource_name"="dada-card-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="dada-card-com-tls" "resource_namespace"="default"
2020-05-18T08:10:01.105Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.088029 1 controller.go:138] cert-manager/controller/certificates "msg"="syncing item" "key"="default/dada-card-com-tls"
2020-05-18T08:10:01.105Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:01.087511 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1201h45m21.912512687s" "related_resource_kind"="Secret" "related_resource_name"="dada-card-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="dada-card-com-tls" "resource_namespace"="default"
2020-05-18T08:10:00.913Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:00.896571 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/kali-vcards-com-tls"
2020-05-18T08:10:00.913Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:00.896158 1 util.go:177] cert-manager/controller/certificates "msg"="certificate scheduled for renewal" "duration_until_renewal"="1360h28m24.103864989s" "related_resource_kind"="Secret" "related_resource_name"="kali-vcards-com-tls" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards-com-tls" "resource_namespace"="default"
2020-05-18T08:10:00.913Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:00.895560 1 controller.go:138] cert-manager/controller/certificates "msg"="syncing item" "key"="default/kali-vcards-com-tls"
2020-05-18T08:10:00.913Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:00.894798 1 sync.go:304] cert-manager/controller/certificates "msg"="updated Secret resource metadata as it was out of date" "related_resource_kind"="CertificateRequest" "related_resource_name"="kali-vcards-com-tls-913567449" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="kali-vcards-com-tls" "resource_namespace"="default"
2020-05-18T08:10:00.720Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:00.710909 1 sync.go:311] cert-manager/controller/certificates "msg"="certificate does not require re-issuance. certificate renewal scheduled near expiry time." "related_resource_kind"="CertificateRequest" "related_resource_name"="dada-card.com-3434603086" "related_resource_namespace"="default" "resource_kind"="Certificate" "resource_name"="dada-card.com" "resource_namespace"="default"
2020-05-18T08:10:00.491Z | pool-pk55kk4qf-984d | cert-manager-controller | I0518 08:10:00.491500 1 controller.go:144] cert-manager/controller/certificates "msg"="finished processing work item" "key"="default/kali-vcards.com"

[sambhav-gore]

@meyskens Further, it looks like this is happening only with the wildcard certificates. I will confirm a little bit later after investigating more.

[Yacine-A]

Any updates on this front?

Moreover where can we find the mappings between the 0-6 levels and human readable strings, like debug,info, warn,error. I can't find such info in the repo.

[yalctay93]

Any updates on this front?

Moreover where can we find the mappings between the 0-6 levels and human readable strings, like debug,info, warn,error. I can't find such info in the repo.

apparently it does not matter, cert-manager currently also logs error messages with severity level "1" - we are using the 0.14.0 version

example: I0618 04:49:34.449099 1 sync.go:107] Error checking existing TLS certificate: secret "gitlab3-gitlab-tls" not found

[julien-piccaluga]

Those messages do not seem like errors to me, that is the 'happy case' for the controller, where it's detected that a certificate is up to date and nothing more needs to happen.

Can you share a full log file? Perhaps putting it into a GitHub gist would be best

If you're also seeing a lot of repeated logs similar to what you've shared above, it may be worthwhile turning up the log 'level' using the --v=4 flag on the 'controller' component before sharing those logs, as they'll then contain a lot more debugging info for us to work with

(ps, you need to put / commands onto their own line when commenting else they won't work!)

/reopen

IMHO The log level for that kind of log should be debug and not info.

[cippaciong]

I used to be affected by this bug using version 0.11 but yesterday I did a major upgrade to version 0.16.1 and the problem seems to be fixed there.

[meyskens]

Logs have been refactored in v1.0 to be better leveled. Closing this issue.

/close

[jetstack-bot]

@meyskens: Closing this issue.

In response to this:

Logs have been refactored in v1.0 to be better leveled. Closing this issue.

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.