perf(health): kill the 5s cold-start tax — no initial_delay default + fast-start probing

CHANGELOG.md

@@ -9,6 +9,25 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ### Added
 
+- **`initial_delay` no longer defaults to 5 seconds.** An unset delay now
+  means "probe immediately" - the old silent default made every container's
+  readiness gate sleep 5s before the FIRST health probe, which was the
+  single largest component of cold start (php-fpm listens ~50ms after
+  start; nginx then waited out the delay on the dependency chain). An
+  explicitly configured `initial_delay` is honored unchanged, and
+  fast-start probing (below) keeps failure semantics on the steady-state
+  schedule.
+- **Fast-start health probing.** Until a process's first successful health
+  check, the monitor probes every 250ms instead of waiting the steady-state
+  period - php-fpm listens ~50ms after start, and losing the race against
+  the immediate first probe used to cost a full period (5s in the shipped
+  images) of container cold start. Failure semantics are unchanged: at most
+  one failure is counted per period (the extra discovery probes are silent),
+  so a never-up process is declared unhealthy on exactly the old schedule.
+  Restarted instances get the same fast discovery. Measured on the
+  php-baseimages benchmark: the dependency gate between php-fpm and nginx
+  dropped from ~5.0s to sub-second.
+
 - **`fpm_tune.cpu_ceiling` and `fpm_tune.cpu_headroom`.** The embedded
   autotuner sizes pools to the memory budget; on CPU-bound workloads that
   oversubscribes the CPU and costs throughput (measured: a 2-CPU container

internal/config/types.go

@@ -566,9 +566,13 @@ func (c *Config) setProcessHealthCheckDefaults(proc *Process) {
 		return
 	}
 	hc := proc.HealthCheck
-	if hc.InitialDelay == 0 {
-		hc.InitialDelay = 5
-	}
+	// initial_delay deliberately has NO default: an unset delay means probing
+	// starts immediately, and fast-start probing (see process.HealthMonitor)
+	// discovers readiness within FastStartInterval while still counting
+	// failures at steady-state cadence. The old default of 5 silently added
+	// five seconds to every container's cold start - the readiness gate slept
+	// through the dependency chain even though php-fpm listens within ~50ms.
+	// An explicitly configured initial_delay is honored unchanged.
 	if hc.Period == 0 {
 		hc.Period = 10
 	}

internal/config/types_test.go

@@ -171,8 +171,11 @@ func TestSetDefaults(t *testing.T) {
 			},
 			validate: func(t *testing.T, c *Config) {
 				hc := c.Processes["test"].HealthCheck
-				if hc.InitialDelay != 5 {
-					t.Errorf("InitialDelay = %v, want 5", hc.InitialDelay)
+				// initial_delay has no default anymore: unset means probe immediately
+				// (fast-start probing discovers readiness; the old default of 5 added
+				// five silent seconds to every container cold start).
+				if hc.InitialDelay != 0 {
+					t.Errorf("InitialDelay = %v, want 0 (no default)", hc.InitialDelay)
 				}
 				if hc.Period != 10 {
 					t.Errorf("Period = %v, want 10", hc.Period)

internal/process/healthcheck.go

@@ -178,8 +178,25 @@ type HealthMonitor struct {
 	consecutiveSuccess int
 	currentlyHealthy   bool
 	graceUntil         time.Time // checks are skipped until this time (warmup after (re)start)
+
+	// Fast-start probing: until the first successful check after (re)start,
+	// probe at FastStartInterval instead of the steady-state period. Success
+	// is discovered within one FastStartInterval; failures keep their exact
+	// steady-state timing - at most one failure is counted (and emitted) per
+	// period, the extra discovery probes that fail are silent. Readiness gets
+	// fast without changing how quickly a never-up process goes unhealthy.
+	// fastUntil bounds the window as a safety valve.
+	everSucceeded   bool
+	fastUntil       time.Time
+	lastCountedFail time.Time
 }
 
+// FastStartInterval is the probe cadence before the first success. First
+// readiness is a discovery problem, not a failure-detection problem: php-fpm
+// listens ~50ms after start, and waiting a full period to notice was the
+// single largest component of container cold start.
+const FastStartInterval = 100 * time.Millisecond
+
 // NewHealthMonitor creates a new health monitor
 func NewHealthMonitor(processName string, cfg *config.HealthCheck, log *slog.Logger) (*HealthMonitor, error) {
 	checker, err := NewHealthChecker(cfg)
@@ -216,10 +233,12 @@ func (hm *HealthMonitor) Start(ctx context.Context) <-chan HealthStatus {
 		// Guard the send on ctx: if the consumer has already exited (its own ctx
 		// cancelled) with a status buffered, an unguarded send on the
 		// capacity-1 channel blocks this goroutine — and its ticker — forever.
-		select {
-		case statusCh <- status:
-		case <-ctx.Done():
-			return
+		if !status.suppress {
+			select {
+			case statusCh <- status:
+			case <-ctx.Done():
+				return
+			}
 		}
 
 		// A non-positive period panics time.NewTicker, and this runs in a
@@ -233,24 +252,28 @@ func (hm *HealthMonitor) Start(ctx context.Context) <-chan HealthStatus {
 			hm.logger.Warn("Health check period is not positive; using the default",
 				"configured", hm.config.Period, "using", period)
 		}
-		ticker := time.NewTicker(period)
-		defer ticker.Stop()
+		hm.armFastStart(period)
+
+		timer := time.NewTimer(hm.nextInterval(period))
+		defer timer.Stop()
 
 		for {
 			select {
-			case <-ticker.C:
+			case <-timer.C:
 				// Skip checks during a warmup grace window (initial start or a
 				// re-arm after a health-triggered restart), so a slow-booting
 				// replacement isn't killed before it can come up.
-				if hm.inGrace() {
-					continue
-				}
-				status := hm.performCheck(ctx)
-				select {
-				case statusCh <- status:
-				case <-ctx.Done():
-					return
+				if !hm.inGrace() {
+					status := hm.performCheck(ctx)
+					if !status.suppress {
+						select {
+						case statusCh <- status:
+						case <-ctx.Done():
+							return
+						}
+					}
 				}
+				timer.Reset(hm.nextInterval(period))
 			case <-ctx.Done():
 				return
 			}
@@ -275,6 +298,19 @@ func (hm *HealthMonitor) Rearm() {
 	if hm.config != nil && hm.config.InitialDelay > 0 {
 		hm.graceUntil = time.Now().Add(time.Duration(hm.config.InitialDelay) * time.Second)
 	}
+	// The replacement instance gets the same fast readiness discovery the
+	// first instance got.
+	period := DefaultHealthCheckPeriod
+	if hm.config != nil && hm.config.Period > 0 {
+		period = time.Duration(hm.config.Period) * time.Second
+	}
+	threshold := 1
+	if hm.config != nil && hm.config.FailureThreshold > 0 {
+		threshold = hm.config.FailureThreshold
+	}
+	hm.everSucceeded = false
+	hm.lastCountedFail = time.Time{}
+	hm.fastUntil = time.Now().Add(time.Duration(threshold) * period)
 }
 
 // inGrace reports whether the monitor is inside a warmup grace window, during
@@ -285,6 +321,32 @@ func (hm *HealthMonitor) inGrace() bool {
 	return !hm.graceUntil.IsZero() && time.Now().Before(hm.graceUntil)
 }
 
+// armFastStart opens the fast-probing window for a fresh start: probes run at
+// FastStartInterval until the first success, bounded by failure_threshold x
+// period (when steady-state semantics would have settled the question anyway).
+func (hm *HealthMonitor) armFastStart(period time.Duration) {
+	hm.mu.Lock()
+	defer hm.mu.Unlock()
+	threshold := 1
+	if hm.config != nil && hm.config.FailureThreshold > 0 {
+		threshold = hm.config.FailureThreshold
+	}
+	hm.everSucceeded = false
+	hm.lastCountedFail = time.Time{}
+	hm.fastUntil = time.Now().Add(time.Duration(threshold) * period)
+}
+
+// nextInterval picks the probe cadence: FastStartInterval inside the
+// fast-start window (pre-first-success), the steady-state period otherwise.
+func (hm *HealthMonitor) nextInterval(period time.Duration) time.Duration {
+	hm.mu.Lock()
+	defer hm.mu.Unlock()
+	if !hm.everSucceeded && time.Now().Before(hm.fastUntil) && period > FastStartInterval {
+		return FastStartInterval
+	}
+	return period
+}
+
 func (hm *HealthMonitor) performCheck(ctx context.Context) HealthStatus {
 	checkCtx, cancel := context.WithTimeout(ctx, time.Duration(hm.config.Timeout)*time.Second)
 	defer cancel()
@@ -304,6 +366,21 @@ func (hm *HealthMonitor) performCheck(ctx context.Context) HealthStatus {
 	}
 
 	if err != nil {
+		// Inside the fast-start window, failures are throttled to steady-state
+		// timing: at most one is counted (and emitted) per period, so the
+		// extra discovery probes change nothing about failure semantics.
+		if !hm.everSucceeded && time.Now().Before(hm.fastUntil) {
+			period := DefaultHealthCheckPeriod
+			if hm.config != nil && hm.config.Period > 0 {
+				period = time.Duration(hm.config.Period) * time.Second
+			}
+			if !hm.lastCountedFail.IsZero() && time.Since(hm.lastCountedFail) < period {
+				hm.logger.Debug("Health check not yet passing (fast-start window)",
+					"error", err)
+				return HealthStatus{Healthy: true, LastCheckSucceeded: false, suppress: true}
+			}
+			hm.lastCountedFail = time.Now()
+		}
 		// Health check failed
 		hm.consecutiveFails++
 		hm.consecutiveSuccess = 0 // Reset success counter on failure
@@ -334,6 +411,7 @@ func (hm *HealthMonitor) performCheck(ctx context.Context) HealthStatus {
 	}
 
 	// Health check succeeded
+	hm.everSucceeded = true
 	hm.consecutiveSuccess++
 	hm.consecutiveFails = 0 // Reset failure counter on success
 
@@ -366,6 +444,10 @@ func (hm *HealthMonitor) performCheck(ctx context.Context) HealthStatus {
 
 // HealthStatus represents the result of a health check
 type HealthStatus struct {
+	// suppress marks a fast-start probe whose failure was throttled (not
+	// counted); the monitor loop drops it instead of emitting.
+	suppress bool
+
 	Healthy            bool  // Whether process should be considered healthy (for liveness/restart decisions)
 	LastCheckSucceeded bool  // Whether the most recent health check actually succeeded (for readiness)
 	Error              error // Error from the health check, if any

internal/process/healthcheck_faststart_test.go

@@ -0,0 +1,69 @@
+package process
+
+import (
+	"context"
+	"log/slog"
+	"net"
+	"os"
+	"testing"
+	"time"
+
+	"github.com/cboxdk/init/internal/config"
+)
+
+// A service that starts listening shortly after the monitor starts must be
+// discovered within the fast-start cadence, not after a full period. This was
+// the single largest component of container cold start: php-fpm listened 50ms
+// after the immediate first probe, and readiness waited the full 5s period.
+func TestHealthMonitor_FastStartDiscovery(t *testing.T) {
+	logger := slog.New(slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{Level: slog.LevelWarn}))
+
+	// Reserve a port, close it, and re-listen 600ms later - after the
+	// monitor's immediate first probe has already failed.
+	l, err := net.Listen("tcp", "127.0.0.1:0")
+	if err != nil {
+		t.Fatal(err)
+	}
+	addr := l.Addr().String()
+	_ = l.Close()
+
+	cfg := &config.HealthCheck{
+		Type:             "tcp",
+		Address:          addr,
+		Period:           5,
+		Timeout:          1,
+		FailureThreshold: 3,
+	}
+	monitor, err := NewHealthMonitor("fast-start", cfg, logger)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	go func() {
+		time.Sleep(600 * time.Millisecond)
+		l2, err := net.Listen("tcp", addr)
+		if err != nil {
+			return
+		}
+		defer l2.Close()
+		time.Sleep(5 * time.Second)
+	}()
+
+	ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
+	defer cancel()
+
+	start := time.Now()
+	statusCh := monitor.Start(ctx)
+	for status := range statusCh {
+		if status.LastCheckSucceeded {
+			elapsed := time.Since(start)
+			// Old behavior: first success at ~period (5s). Fast-start must
+			// find it within ~600ms + a couple of probe intervals.
+			if elapsed > 2*time.Second {
+				t.Fatalf("first success took %v; fast-start should discover readiness well before the 5s period", elapsed)
+			}
+			return
+		}
+	}
+	t.Fatal("monitor channel closed without a successful check")
+}