Health Checks

A platform asks a running service two different questions. Liveness asks whether the process should be restarted, and the only honest answer is whether it still serves at all. Readiness asks whether it should be sent traffic right now, which depends on its database, its cache and on whether it is starting up or shutting down. Muzak answers both once AppOptions.Health is enabled.

app := muzak.New(muzak.AppOptions{
    Title: "Awesome API",

    Health: muzak.HealthOptions{
        Enabled: true,
        Checks: []muzak.HealthCheck{
            {Name: "database", Check: db.PingContext},
            {Name: "cache", Check: func(ctx context.Context) error {
                return redisClient.Ping(ctx).Err()
            }},
        },
    },

    // Keep serving for five seconds after readiness drops, so the load
    // balancer has time to notice before the socket closes.
    DrainDelay: 5 * time.Second,
})

The zero value of HealthOptions serves nothing and costs nothing: no route, no middleware, no goroutine. Setting a field such as Checks without Enabled is a build error rather than configuration that silently does nothing.

The two endpoints

Both take GET and HEAD and answer anything else with 405 and Allow: GET, HEAD, rendered by the application's error renderer like any other 405. Both are sent with Cache-Control: no-store, so no cache between the platform and the process can answer a probe with a stale result.

Liveness never runs a check. A database that is down is a reason to stop sending traffic, not a reason to restart every replica at once, which is what a liveness probe that pinged the database would do.

The paths move with LivenessPath and ReadinessPath:

Health: muzak.HealthOptions{
    Enabled:       true,
    LivenessPath:  "/_/alive",
    ReadinessPath: "/_/ready",
},

A path is matched exactly, so /readyz/ is not the readiness endpoint. It has to be absolute, in its clean form, and made of letters, digits and -._~/, which a probe never has to encode. The two paths must differ. A path a route, a mount or the documentation already answers is a build error, because the health endpoint is answered first and would take that path from it without a word. A frontend or a handler mounted at / is the exception: it answers only what nothing else does, as it does for every route. Its root is its own, though, so a health path of / beside one is a build error too.

Answered ahead of the application

The health endpoints are answered right after the request identifier, tracing and the request observer, the security headers and panic recovery, and before everything else:

• No middleware installed with App.Use. An authenticating middleware that refuses a probe takes every replica out of rotation.
• No guard, provider or rate limit, including those given to New. A probe carries no credentials, and a platform probing every few seconds is the one client that must never be told to slow down.
• No CORS policy, host allowlist or redirect to HTTPS. No browser has any business reading a probe, and a probe is sent to the pod's own address over plain HTTP, which AllowedHosts and RedirectHTTPS would refuse or redirect.
• Not in the OpenAPI document. The endpoints are for the platform, not for API clients.

Tracing and the request observer are outside them, so with Tracing or Observer configured every probe is observed, with an empty route, and a sampled one gets a server span named after its method alone. A readiness 503 counts as a server error there, as any 5xx does. A Sampler sees the request, so it can decline to record the probes' traces.

Since nothing authenticates a probe, the endpoints say very little. The body is {"status":"ok"} or {"status":"unavailable"} and nothing else; the error a check returned is written to the log, never to the response. A service whose readiness endpoint is reachable only from inside the platform can ask for the name of each check with ReportChecks:

Health: muzak.HealthOptions{
    Enabled:      true,
    ReportChecks: true,
    Checks:       checks,
},

{"status":"unavailable","checks":{"database":"fail","cache":"ok"}}

It is off by default because the names of a service's dependencies, and which of them is down right now, are worth something to an attacker probing an unauthenticated endpoint. Since the host allowlist does not apply to the health paths, a web page that points its own name at the service's address (DNS rebinding) can read the body from a browser on the same network as well. Turn ReportChecks on only where the port is reachable from the platform alone.

Readiness checks

type HealthCheck struct {
    // Name identifies the check in logs and, with ReportChecks, in the body.
    Name string
    // Check returns nil when the dependency is usable.
    Check func(ctx context.Context) error
    // Timeout bounds one run, defaulting to one second.
    Timeout time.Duration
}

A Check with the signature func(context.Context) error fits most clients as they are: (*sql.DB).PingContext is one. A name is required, unique, at most 64 characters, and made of letters, digits, -, . and _, so it never needs escaping in a log line or a body.

The checks run concurrently, each under its own timeout, so readiness takes as long as the slowest check rather than the sum. Keep Timeout below the probe's own timeout (Kubernetes defaults timeoutSeconds to 1), so a slow dependency is reported as a 503 rather than as a probe that never got an answer.

What a flood of probes costs

The combined result is reused for CacheInterval. Probes that arrive while the checks are running wait for that run instead of starting their own, so three thousand probes at once run each check exactly once. A negative CacheInterval runs the checks for every probe that does not find a run already in progress: concurrent probes still share a run, but the rate is no longer bounded.

A check that ignores its context and never returns is the case that matters. The probe is answered at the check's timeout with a 503, and the check is not started again while its goroutine is still running: every later probe reports it as failing at once, so a hung dependency costs one goroutine, not one per probe. A check that panics is recovered and counts as a failure, and a check that answers after its timeout counts as failed even if it returned nil.

What is logged

A check that starts failing is logged at warn level with its error, once. While it keeps failing it is logged at debug level only, and when it passes again that is logged at info level, so the log grows with changes of state rather than with the rate of probes.

14:32:41.902 WARN  [Server]        muzak: a readiness check failed; readiness reports unavailable  check=database  error="dial tcp 10.0.0.5:5432: connect: connection refused"
14:33:02.117 INFO  [Server]        muzak: a readiness check passes again  check=database

The error is the check's own text, cut to a bounded length, and may name a host or a user. Nothing is redacted out of it, since the log is where an operator needs to read it, but it never reaches a response.

Probes are recorded in the access log at debug level whatever their status, since a platform probing every few seconds would otherwise outnumber real traffic and a 503 during start-up is expected rather than an error. Change the level with AccessLogLevel, or leave a path out entirely with AccessLogOptions.SkipPaths.

Start-up and shutdown

Readiness follows the lifecycle. It answers 503 until StartLifecycle has succeeded, which the run methods and the test client do before the socket opens, and again once a shutdown begins.

Readiness drops before anything else happens. The first thing Shutdown does is report unavailable, before any listener closes or any connection is touched, so a load balancer probing it stops sending traffic while requests in flight still finish. Liveness keeps answering 200 throughout: a process draining its requests is alive, and restarting it would cut the drain short.

DrainDelay keeps serving while the load balancer catches up. A load balancer learns about a shutdown on its next probe, and Kubernetes removes a terminating pod from its Service while it sends SIGTERM, not before. Requests sent in that gap would find the socket closed. With DrainDelay set, the shutdown waits that long with readiness down and the listeners still accepting, before it closes them:

14:32:41.902 INFO  [Server]        Shutting down, waiting for in-flight requests...
14:32:41.902 INFO  [Server]        Readiness now reports unavailable; waiting 5s before closing the listeners
14:32:46.903 INFO  [Server]        Stopping 2 lifecycle components
14:32:46.910 INFO  [Server]        Stopped

The delay counts against ShutdownTimeout rather than being added to it, because the platform's grace period counts it too. A DrainDelay that is not shorter than ShutdownTimeout would leave no time to drain, and is a build error; so is a negative one. The default of zero closes the listeners at once. The delay applies whether or not health is enabled, since a platform that removes endpoints on its own clock needs it either way, and it replaces the sleep a preStop hook would otherwise hold.

An application run again after a shutdown reports 503 until its components have started once more, and does not reuse a readiness result from the previous run.

The whole sequence, in order:

1. Readiness reports unavailable.
2. The server keeps serving through DrainDelay.
3. The listeners close and requests in flight are drained, while WebSockets are told the server is going away and event streams are ended.
4. The background tasks those requests registered are waited for.
5. The lifecycle components are stopped.

The test client shuts an application down the same way when a test ends, so a DrainDelay in the configuration a test builds delays the end of that test by as much. Leave it out of the configuration tests use.

Kubernetes

livenessProbe:
  httpGet: {path: /livez, port: 8080}
  periodSeconds: 10
readinessProbe:
  httpGet: {path: /readyz, port: 8080}
  periodSeconds: 5
  timeoutSeconds: 2
terminationGracePeriodSeconds: 30

ShutdownTimeout: 25 * time.Second, // below terminationGracePeriodSeconds
DrainDelay:      5 * time.Second,  // at least one readiness period

Serving it yourself

An application served through App.ServeHTTP in a server you built answers the health endpoints the same way, but nothing starts its lifecycle for it, so readiness answers 503 until you call StartLifecycle, and again after StopLifecycle. DrainDelay belongs to Shutdown, which such a server does not use.

Where to go next

Server Configuration covers ShutdownTimeout and the rest of the shutdown, Lifecycle the components readiness waits for, and Background Tasks the work a shutdown drains after its requests.