Add health probe that detects skew between system clock and monotonic go process clock

[inteon]

Pull Request Motivation

This PR adds a new LivenessProbe that makes sure the clock skew is not more than 5 minutes.
If we detect that the monotonic duration since the start of the controller differs more than 5 minutes from the system clock duration since the start of the project, we return HTTP error code 500 and force a restart.

This check will fix the following issues:

• if the controller was started at time A & a timer for time B is created, hibernating for duration h will cause the timer to trigger at time B + h
• if the controller was started at time A & a timer for time B is created, changing the system clock (eg. fixing a wrong delta using ntp) will still result in the timer triggering at the original time

See golang/go#35012 for the background on this issue in upstream Go.

fixes #6341

Kind

/kind feature

Release Note

Added a clock skew detector liveness probe that will force a restart in case we detect a skew between the internal monotonic clock and the system clock of more than 5 minutes.
Also, the controller's liveness probe is now enabled by default.

[SgtCoDFish]

Feel like I've written a lot here, but I like the approach generally. I think there are a few subtle bits here which might need a little tweaking though - what do you think?

[SgtCoDFish]

Wonderfully written!

[SgtCoDFish]

/lgtm
/approve
/hold

I think this looks great, the comments you've added are fantastic. I'm adding a hold for someone else to review this, since someone else might have useful input on the fact this is a livenessProbe.

I don't have a problem with it being a livenessProbe, but I might have missed a reason why it shouldn't be implemented in this way. Still, I think this would be fine to merge - we can always revert before 1.14 if someone realises this is a problem!

[jetstack-bot]

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: SgtCoDFish

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

• OWNERS [SgtCoDFish]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

[maelvls]

I couldn't find the GitHub issue for this PR, so I'll share my thought here.

We return 500 and force a restart.

Why do we bother restarting the whole process with a liveness probe when we could simply re-queue all the certificates and be done? It seems like the liveness probe is overkill.

Also, is 500 ms arbitrary or does it related to something we observed?

[wallrj]

I do not agree with this approach but I'm not blocking it.

1. I think liveness probes should be reserved for recovering from problems which cause cert-manager to stop reconciling in a production environment.

2. I do not think there is sufficient justification here for enabling liveness probes by default. Are we sure that the existing liveness probe is and healthz endpoints are production ready? The plan had always been to get user feedback before enabling them by default. https://cert-manager.io/docs/installation/best-practice/#controller

3. As far as I remember, this problem affects a user who is testing cert-manager on a laptop and using a certificates with a lifetime where the calculated renewBefore time happens to be shorter than the time that the laptop was suspended. I think the risks of introducing this new (untested) code outweigh the benefit of fixing that specific problem.

4. I still want to know how other operators that use Go time.After address this issue and indeed Kubernetes its self? How does the Kind Kubernetes API server refresh a ServiceAccount token on time, after it resumes from suspend.

[inteon]

@maelvls and @wallrj: The reason for using a LivenessProbe to solve this problem is that this is by far the simplest solution to implement that fixes this problem. Also, this approach will provide feedback (in terms of the restart counter) that something went wrong with cert-manager. The Liveness probe indicates that something is wrong with the cert-manager process and that a restart will fix the problem. A skewed clock should be something that does not happen frequently, that is why I think that restarting the process is good enough.

@wallrj
1 & 3: As described in the PR description, this is not just a problem on laptops, it also happens on "paused" VMs and maybe on starving CPUs. Also, I think we should make sure that cert-manager works on laptops too, so developers don't get the impression that cert-manager fails to renew certs.

2: We already have a liveness probe for the webhook, so enabling a webhook for the controller is not a big deal I think.

3: The code has been manually tested (by multiple parties), but is very hard to test automatically (would require changing the system clock or altering the go runtime). The implementation is very simple, so there shouldn't be much room for errors.

4: I think apps that have long-running time.After delays are affected more by this bug (because you might get delays that trigger N days too late, where N = min(hibernate time, time.After time) ). Also, it would be great if we were not the first point of failure.

[maelvls]

enabling the liveness probe for the controller is not a big deal

It seems like our liveness probe documentation thinks otherwise; it explains that the leader election liveness probe shouldn't be needed "in theory" but that you may want to use it "in practice":

The liveness probe should only be needed if there is a bug in this orderly shutdown process, or if there is a bug in one of the other threads which causes the process to deadlock and not shutdown. You may want to enable the liveness probe anyway, for defense against unforeseen bugs and deadlocks, but you will need to monitor the processes closely and, tweak the various liveness probe time settings and thresholds, if necessary.

If we are about to use livenessProbe: true for everyone, let's rephrase this paragraph to explain why the leader election liveness probe exists:

"Although we tried our best to have each goroutine gracefully stop after the leader election fails, the many possible code paths make it hard to be certain that cert-manager will exit. If cert-manager doesn't exit and silently becomes a zombie, there is a high chance that will cause an outage since the recommended number of replicas is 1 and Kubernetes won't do anything to restart cert-manager."

(I found #5889 where cainjector ended up in a zombie state while trying to stop gracefully; that could have been prevented by a liveness check)

Now that some time has passed since we released the leader election liveness probe in 1.12, are we now feeling more confident about switching this on for everyone? I have searched for "liveness probe" in Slack and on GitHub and I did not find anyone complaining, although I wouldn't be able to know if anyone has actually used it.

[inteon]

Ok, I think that in combination with updating the website documentation, this PR can be merged?

[inteon]

I also updated the max skew to 5 minutes (instead of 1 minute) to reduce the risk of unwanted restarts on weird systems: 5049cd4.

[SgtCoDFish]

/lgtm

[inteon]

/unhold

[wallrj]

I just experienced this feature for the first time, on a Kind cluster on my laptop which went to sleep overnight.

It seems to work well. Thanks @inteon.

[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:37.593525781Z I0214 09:08:37.593176       1 healthz.go:261] clockHealth check failed: livez
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:37.593616907Z [-]clockHealth failed: the system clock is out of sync with the internal monotonic clock by 13h6m36.228644807s, which is more than the allowed 5m0s
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:47.593866157Z I0214 09:08:47.593575       1 healthz.go:261] clockHealth check failed: livez
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:47.593899671Z [-]clockHealth failed: the system clock is out of sync with the internal monotonic clock by 13h6m36.228644816s, which is more than the allowed 5m0s
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:57.592977738Z I0214 09:08:57.592675       1 healthz.go:261] clockHealth check failed: livez
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:57.593085064Z [-]clockHealth failed: the system clock is out of sync with the internal monotonic clock by 13h6m36.228644809s, which is more than the allowed 5m0s

[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:58.189880206Z W0214 09:08:58.189257       1 client_config.go:618] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:58.203968628Z I0214 09:08:58.203730       1 options.go:248] "enabling all experimental certificatesigningrequest controllers" logger="cert-manager"
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:58.203993138Z I0214 09:08:58.203770       1 options.go:253] "enabling the sig-network Gateway API certificate-shim and HTTP-01 solver" logger="cert-manager"
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:58.203998248Z I0214 09:08:58.203833       1 controller.go:89] "enabled controllers: [certificaterequests-approver certificaterequests-issuer-acme certificaterequests-issuer-ca certificaterequests-issuer-selfsigned certificaterequests-issuer-vault certificaterequests-issuer-venafi certificates-issuing certificates-key-manager certificates-metrics certificates-readiness certificates-request-manager certificates-revision-manager certificates-trigger certificatesigningrequests-issuer-acme certificatesigningrequests-issuer-ca certificatesigningrequests-issuer-selfsigned certificatesigningrequests-issuer-vault certificatesigningrequests-issuer-venafi challenges clusterissuers gateway-shim ingress-shim issuers orders]" logger="cert-manager.controller"
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:58.209794381Z I0214 09:08:58.209439       1 leaderelection.go:250] attempting to acquire leader lease kube-system/cert-manager-controller...
[pod/cert-manager-5957b48cf5-t9gtf/cert-manager-controller] 2024-02-14T09:08:58.216509192Z I0214 09:08:58.216126       1 leaderelection.go:260] successfully acquired lease kube-system/cert-manager-controller