From d78ab4b638e8de6798c968a789dcc00debb1f7d8 Mon Sep 17 00:00:00 2001 From: Gustavo Bertoi Date: Mon, 29 Jun 2026 09:40:30 -0300 Subject: [PATCH] =?UTF-8?q?feat(health):=20C3b=20=E2=80=94=20internal/heal?= =?UTF-8?q?th=20thin=20readiness=20poller=20(spec=2010)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit New read-only, lock-free package that gates the up saga on real readiness: - Compile(*config.Healthcheck) → Timing with spec-10 defaults (interval 5s, timeout 3s, retries 10, startPeriod 30s); the "60s for stateful images" rule stays in the engine templates (no hardcoded engine knowledge here). Budget() = startPeriod + interval*retries. - Poll(ctx, docker.Client, Target, Timing): polls .State.Health.Status until Healthy (or Started: container running), failing fast on unhealthy / a fatal container state (exited/dead/restarting) / timeout / ctx cancel. Transient inspect errors (container not created yet) are tolerated until the deadline. - On failure returns a *ProbeError carrying the --json Record AND the last 20 log lines (fetched on a detached context so a timed-out poll still has a diagnostic) + a one-line remediation (ARCHITECTURE §7.6). - Record is the machine-readable health contract (service/project/kind/status/ attempts/elapsedMs/lastError, lastError null on success). Thin v1 — single-target Poll consumed linearly by the caller (C5). The full workspace DAG (cycle paths, topo waves, profile pruning, generate-time "condition:healthy needs a healthcheck") is X2. Unit tests use a scripted client (healthy-after-starting, fail-fast unhealthy/ exited, started condition, timeout, transient-error recovery, ctx cancel, Compile defaults/overrides/bad-durations). A `//go:build integration` test polls real healthy + unhealthy containers and asserts the log diagnostic. Co-Authored-By: Claude Opus 4.8 (1M context) --- internal/health/health.go | 249 +++++++++++++++++++++ internal/health/health_integration_test.go | 79 +++++++ internal/health/health_test.go | 192 ++++++++++++++++ 3 files changed, 520 insertions(+) create mode 100644 internal/health/health.go create mode 100644 internal/health/health_integration_test.go create mode 100644 internal/health/health_test.go diff --git a/internal/health/health.go b/internal/health/health.go new file mode 100644 index 0000000..ca14504 --- /dev/null +++ b/internal/health/health.go @@ -0,0 +1,249 @@ +// Package health compiles a service's declarative healthcheck (spec 10) into +// timing parameters and polls the read-only Engine SDK (.State.Health.Status) +// until a target is ready or fails fast. It is strictly read-only and therefore +// lock-free (ARCHITECTURE §4, spec 10 §gotchas): the up saga takes the flock +// only for the start/provision steps a green poll unblocks. +// +// This is the thin v1 — a single-target Poll plus Compile, consumed linearly by +// the caller. The full workspace DAG (cycle paths, topo waves, profile-aware +// pruning, generate-time "condition:healthy needs a healthcheck") is X2. +package health + +import ( + "context" + "fmt" + "strings" + "time" + + "github.com/open-source-cloud/devstack/internal/config" + "github.com/open-source-cloud/devstack/internal/docker" +) + +// Defaults per spec 10 (Compose-equivalent). StartPeriod stays 30s here: the +// "60s for stateful images" guidance lives in the engine TEMPLATES, not in this +// package, which carries no hardcoded engine knowledge — it only compiles/polls. +const ( + DefaultInterval = 5 * time.Second + DefaultTimeout = 3 * time.Second + DefaultRetries = 10 + DefaultStartPeriod = 30 * time.Second + // DefaultLogTail is how many trailing log lines the fail-fast diagnostic inlines. + DefaultLogTail = 20 +) + +// Condition is the readiness bar for a target (spec 10): Healthy waits for a +// passing healthcheck; Started waits only for the container to be running (the +// only honest gate when no healthcheck is declared). +type Condition string + +const ( + Healthy Condition = "healthy" + Started Condition = "started" +) + +// Timing is the compiled, defaulted timing for a probe. +type Timing struct { + Interval time.Duration + Timeout time.Duration + Retries int + StartPeriod time.Duration +} + +// Budget is the overall wall-clock a poll may take before timing out: +// startPeriod + interval*retries (spec 10 §blocking-UX). The caller caps it +// further with --health-timeout via the context deadline. +func (t Timing) Budget() time.Duration { + return t.StartPeriod + t.Interval*time.Duration(max(t.Retries, 0)) +} + +// Compile applies spec-10 defaults to a (possibly nil or partial) healthcheck. +// Duration strings are already validated at config-load (the `duration` +// validator), so a parse error here falls back to the default rather than erroring. +func Compile(hc *config.Healthcheck) Timing { + t := Timing{ + Interval: DefaultInterval, + Timeout: DefaultTimeout, + Retries: DefaultRetries, + StartPeriod: DefaultStartPeriod, + } + if hc == nil { + return t + } + if d, ok := parseDur(hc.Interval); ok { + t.Interval = d + } + if d, ok := parseDur(hc.Timeout); ok { + t.Timeout = d + } + if d, ok := parseDur(hc.StartPeriod); ok { + t.StartPeriod = d + } + if hc.Retries > 0 { + t.Retries = hc.Retries + } + return t +} + +func parseDur(s string) (time.Duration, bool) { + if s == "" { + return 0, false + } + d, err := time.ParseDuration(s) + if err != nil || d <= 0 { + return 0, false + } + return d, true +} + +// Target names what to poll and labels the resulting record/diagnostic. +type Target struct { + ContainerID string + Service string // service name (for the record + diagnostic) + Project string // compose project (for the record) + Kind string // healthcheck kind, e.g. "pg_isready" (for the record) + Condition Condition // Healthy (default) | Started +} + +// Record is the machine-readable health result (spec 10 §--json). LastError is +// null on success. +type Record struct { + Service string `json:"service"` + Project string `json:"project"` + Kind string `json:"kind"` + Status string `json:"status"` // healthy | started | unhealthy | exited | timeout + Attempts int `json:"attempts"` + ElapsedMs int64 `json:"elapsedMs"` + LastError *string `json:"lastError"` +} + +// Result statuses. +const ( + statusHealthy = "healthy" + statusStarted = "started" + statusUnhealthy = "unhealthy" + statusExited = "exited" + statusTimeout = "timeout" +) + +// ProbeError is the fail-fast diagnostic returned when a target goes unhealthy, +// exits, or times out: it carries the final Record and the last N log lines, and +// renders a one-line remediation (ARCHITECTURE §7.6). +type ProbeError struct { + Record Record + Logs string +} + +func (e *ProbeError) Error() string { + var b strings.Builder + fmt.Fprintf(&b, "service %q (project %s) is %s after %d attempt(s)", + e.Record.Service, e.Record.Project, e.Record.Status, e.Record.Attempts) + if e.Record.Kind != "" { + fmt.Fprintf(&b, " [healthcheck: %s]", e.Record.Kind) + } + if e.Logs != "" { + fmt.Fprintf(&b, "\nlast %d log lines:\n%s", DefaultLogTail, e.Logs) + } + b.WriteString("\nhint: inspect the service's logs and healthcheck; a slow stateful image may need a larger startPeriod (spec 10)") + return b.String() +} + +// sleep is the cancelable inter-poll wait, indirected for tests. +var sleep = func(ctx context.Context, d time.Duration) error { + if d <= 0 { + return ctx.Err() + } + t := time.NewTimer(d) + defer t.Stop() + select { + case <-ctx.Done(): + return ctx.Err() + case <-t.C: + return nil + } +} + +// now is indirected for tests; in production it is time.Now. +var now = time.Now + +// Poll blocks until tgt reaches its Condition or fails fast (unhealthy / exited / +// timeout / context cancellation). On success it returns a Record with a nil +// error; on failure it returns the Record AND a *ProbeError carrying the last +// log lines. It never mutates state — safe to call outside the flock. +func Poll(ctx context.Context, cli docker.Client, tgt Target, tm Timing) (Record, error) { + if tgt.Condition == "" { + tgt.Condition = Healthy + } + start := now() + deadline := start.Add(tm.Budget()) + if dl, ok := ctx.Deadline(); ok && dl.Before(deadline) { + deadline = dl + } + rec := Record{Service: tgt.Service, Project: tgt.Project, Kind: tgt.Kind, Status: statusTimeout} + + for { + rec.Attempts++ + d, err := cli.ContainerInspect(ctx, tgt.ContainerID) + switch { + case err != nil: + // The container may not exist yet (compose still creating it); keep + // waiting until the deadline, recording the last transient error. + setLastErr(&rec, err) + case fatalState(d.State): + return fail(ctx, cli, tgt, rec, start, statusExited) + case tgt.Condition == Started: + if d.Running { + return finish(rec, start, statusStarted), nil + } + default: // Healthy + rec.LastError = nil + switch d.Health { + case docker.HealthHealthy: + return finish(rec, start, statusHealthy), nil + case docker.HealthUnhealthy: + return fail(ctx, cli, tgt, rec, start, statusUnhealthy) + } + } + + if !now().Before(deadline) { + return fail(ctx, cli, tgt, rec, start, statusTimeout) + } + if err := sleep(ctx, tm.Interval); err != nil { + return fail(ctx, cli, tgt, rec, start, statusTimeout) + } + } +} + +// fatalState reports container states from which readiness can never be reached +// (spec 10: a container that exits/restarts before reporting health fails fast). +func fatalState(state string) bool { + switch state { + case "exited", "dead", "restarting", "removing": + return true + default: + return false + } +} + +func setLastErr(rec *Record, err error) { + msg := err.Error() + rec.LastError = &msg +} + +func finish(rec Record, start time.Time, status string) Record { + rec.Status = status + rec.ElapsedMs = now().Sub(start).Milliseconds() + rec.LastError = nil + return rec +} + +// fail finalizes a failing record and attaches the container's last log lines. +// Logs are fetched on a detached context so a deadline-exceeded poll still +// produces a diagnostic. +func fail(ctx context.Context, cli docker.Client, tgt Target, rec Record, start time.Time, status string) (Record, error) { + rec.Status = status + rec.ElapsedMs = now().Sub(start).Milliseconds() + lctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), 5*time.Second) + defer cancel() + logs, _ := cli.ContainerLogs(lctx, tgt.ContainerID, DefaultLogTail) + return rec, &ProbeError{Record: rec, Logs: strings.TrimSpace(logs)} +} diff --git a/internal/health/health_integration_test.go b/internal/health/health_integration_test.go new file mode 100644 index 0000000..c3bc788 --- /dev/null +++ b/internal/health/health_integration_test.go @@ -0,0 +1,79 @@ +//go:build integration + +package health + +import ( + "context" + "errors" + "os" + "os/exec" + "strconv" + "strings" + "testing" + "time" + + "github.com/open-source-cloud/devstack/internal/docker" +) + +// TestPoll_RealDaemon polls real containers: one whose healthcheck passes (→ +// healthy) and one whose healthcheck fails (→ unhealthy ProbeError with logs). +// Tagged `integration`; run via `go test -tags=integration ./internal/health`. +func TestPoll_RealDaemon(t *testing.T) { + ctx := context.Background() + cli, err := docker.NewClient(ctx) + if err != nil { + t.Fatalf("NewClient: %v", err) + } + defer func() { _ = cli.Close() }() + if err := cli.Ping(ctx); err != nil { + t.Skipf("no reachable Docker daemon: %v", err) + } + if out, err := exec.CommandContext(ctx, "docker", "pull", "busybox").CombinedOutput(); err != nil { + t.Fatalf("docker pull busybox: %v\n%s", err, out) + } + pid := strconv.Itoa(os.Getpid()) + + run := func(name string, args ...string) string { + full := append([]string{"run", "-d", "--name", name}, args...) + out, err := exec.CommandContext(ctx, "docker", full...).Output() + if err != nil { + t.Fatalf("docker run %s: %v", name, err) + } + t.Cleanup(func() { _ = exec.Command("docker", "rm", "-f", name).Run() }) + return strings.TrimSpace(string(out)) + } + + tm := Timing{Interval: 500 * time.Millisecond, Timeout: time.Second, Retries: 30, StartPeriod: 0} + + t.Run("healthy", func(t *testing.T) { + id := run("devstack-it-h-ok-"+pid, + "--health-cmd", "true", "--health-interval", "1s", "--health-retries", "1", + "--health-start-period", "0s", + "busybox", "sh", "-c", "echo ready; sleep 120") + rec, err := Poll(ctx, cli, Target{ContainerID: id, Service: "ok", Kind: "exec"}, tm) + if err != nil { + t.Fatalf("Poll healthy: %v", err) + } + if rec.Status != statusHealthy { + t.Errorf("status = %q, want healthy", rec.Status) + } + }) + + t.Run("unhealthy", func(t *testing.T) { + id := run("devstack-it-h-bad-"+pid, + "--health-cmd", "false", "--health-interval", "1s", "--health-retries", "1", + "--health-start-period", "0s", + "busybox", "sh", "-c", "echo about-to-be-unhealthy; sleep 120") + rec, err := Poll(ctx, cli, Target{ContainerID: id, Service: "bad", Kind: "exec"}, tm) + var pe *ProbeError + if !errors.As(err, &pe) { + t.Fatalf("want ProbeError, got %v", err) + } + if rec.Status != statusUnhealthy { + t.Errorf("status = %q, want unhealthy", rec.Status) + } + if !strings.Contains(pe.Logs, "about-to-be-unhealthy") { + t.Errorf("diagnostic logs = %q, want the printed line", pe.Logs) + } + }) +} diff --git a/internal/health/health_test.go b/internal/health/health_test.go new file mode 100644 index 0000000..425c4db --- /dev/null +++ b/internal/health/health_test.go @@ -0,0 +1,192 @@ +package health + +import ( + "context" + "errors" + "testing" + "time" + + "github.com/open-source-cloud/devstack/internal/config" + "github.com/open-source-cloud/devstack/internal/docker" +) + +// seqClient returns a scripted sequence of ContainerInspect results (the last +// element repeats once exhausted) and a canned log body, so the poll loop is +// exercised with no daemon. inspectErrs[i] (if set) forces the i-th call to err. +type seqClient struct { + *docker.MockClient + states []docker.ContainerDetails + inspectErr []error + i int + logs string +} + +func (s *seqClient) ContainerInspect(_ context.Context, _ string) (docker.ContainerDetails, error) { + idx := s.i + if idx >= len(s.states) { + idx = len(s.states) - 1 + } + var err error + if s.i < len(s.inspectErr) { + err = s.inspectErr[s.i] + } + s.i++ + if err != nil { + return docker.ContainerDetails{}, err + } + if idx < 0 { + return docker.ContainerDetails{}, errors.New("no states") + } + return s.states[idx], nil +} + +func (s *seqClient) ContainerLogs(_ context.Context, _ string, _ int) (string, error) { + return s.logs, nil +} + +func det(state string, running bool, h docker.HealthStatus) docker.ContainerDetails { + return docker.ContainerDetails{State: state, Running: running, Health: h} +} + +// fastTiming polls effectively instantly so tests don't sleep for real. +func fastTiming(retries int) Timing { + return Timing{Interval: time.Millisecond, Timeout: time.Second, Retries: retries, StartPeriod: 0} +} + +func newClient(logs string, states ...docker.ContainerDetails) *seqClient { + return &seqClient{MockClient: &docker.MockClient{}, states: states, logs: logs} +} + +func TestPollHealthyAfterStarting(t *testing.T) { + cli := newClient("", det("running", true, docker.HealthStarting), + det("running", true, docker.HealthStarting), + det("running", true, docker.HealthHealthy)) + rec, err := Poll(context.Background(), cli, Target{Service: "pg", Project: "devstack-shared", Kind: "pg_isready"}, fastTiming(10)) + if err != nil { + t.Fatalf("Poll: %v", err) + } + if rec.Status != statusHealthy { + t.Errorf("status = %q, want healthy", rec.Status) + } + if rec.Attempts != 3 { + t.Errorf("attempts = %d, want 3", rec.Attempts) + } + if rec.LastError != nil { + t.Errorf("lastError = %v, want nil", *rec.LastError) + } +} + +func TestPollUnhealthyFailsFast(t *testing.T) { + cli := newClient("boom: connection refused\n", + det("running", true, docker.HealthStarting), + det("running", true, docker.HealthUnhealthy)) + rec, err := Poll(context.Background(), cli, Target{Service: "api"}, fastTiming(10)) + if rec.Status != statusUnhealthy { + t.Errorf("status = %q, want unhealthy", rec.Status) + } + var pe *ProbeError + if !errors.As(err, &pe) { + t.Fatalf("want *ProbeError, got %T: %v", err, err) + } + if pe.Logs == "" || pe.Record.Status != statusUnhealthy { + t.Errorf("ProbeError missing logs/status: %+v", pe) + } + // It must fail on the 2nd inspect, not poll to exhaustion. + if rec.Attempts != 2 { + t.Errorf("attempts = %d, want 2 (fail-fast)", rec.Attempts) + } +} + +func TestPollExitedFailsFast(t *testing.T) { + cli := newClient("crash\n", + det("running", true, docker.HealthStarting), + det("exited", false, "")) + _, err := Poll(context.Background(), cli, Target{Service: "api"}, fastTiming(10)) + var pe *ProbeError + if !errors.As(err, &pe) || pe.Record.Status != statusExited { + t.Fatalf("want exited ProbeError, got %v", err) + } +} + +func TestPollStartedCondition(t *testing.T) { + cli := newClient("", det("created", false, ""), det("running", true, "")) + rec, err := Poll(context.Background(), cli, Target{Service: "cache", Condition: Started}, fastTiming(10)) + if err != nil { + t.Fatalf("Poll: %v", err) + } + if rec.Status != statusStarted { + t.Errorf("status = %q, want started", rec.Status) + } +} + +func TestPollTimeout(t *testing.T) { + // Always "starting" → never healthy → must time out within the budget. + cli := newClient("still booting\n", det("running", true, docker.HealthStarting)) + rec, err := Poll(context.Background(), cli, Target{Service: "api"}, fastTiming(3)) + var pe *ProbeError + if !errors.As(err, &pe) || rec.Status != statusTimeout { + t.Fatalf("want timeout ProbeError, got status=%q err=%v", rec.Status, err) + } + if pe.Logs == "" { + t.Error("timeout diagnostic should still inline logs") + } +} + +func TestPollTransientInspectErrorRecovers(t *testing.T) { + cli := &seqClient{ + MockClient: &docker.MockClient{}, + states: []docker.ContainerDetails{det("running", true, docker.HealthHealthy)}, + inspectErr: []error{errors.New("no such container")}, + } + rec, err := Poll(context.Background(), cli, Target{Service: "api"}, fastTiming(10)) + if err != nil { + t.Fatalf("Poll should recover after a transient inspect error: %v", err) + } + if rec.Status != statusHealthy || rec.Attempts != 2 { + t.Errorf("rec = %+v, want healthy after 2 attempts", rec) + } + if rec.LastError != nil { + t.Errorf("lastError should clear on success, got %v", *rec.LastError) + } +} + +func TestPollContextCancel(t *testing.T) { + ctx, cancel := context.WithCancel(context.Background()) + cancel() + cli := newClient("", det("running", true, docker.HealthStarting)) + _, err := Poll(ctx, cli, Target{Service: "api"}, Timing{Interval: time.Hour, Retries: 100, StartPeriod: time.Hour}) + if err == nil { + t.Fatal("want an error on a cancelled context") + } +} + +func TestCompileDefaults(t *testing.T) { + got := Compile(nil) + want := Timing{Interval: DefaultInterval, Timeout: DefaultTimeout, Retries: DefaultRetries, StartPeriod: DefaultStartPeriod} + if got != want { + t.Errorf("Compile(nil) = %+v, want %+v", got, want) + } +} + +func TestCompileOverridesAndBudget(t *testing.T) { + hc := &config.Healthcheck{ + Kind: "http", Interval: "2s", Timeout: "1s", StartPeriod: "10s", Retries: 4, + } + got := Compile(hc) + if got.Interval != 2*time.Second || got.Timeout != time.Second || got.StartPeriod != 10*time.Second || got.Retries != 4 { + t.Fatalf("Compile = %+v", got) + } + // Budget = startPeriod + interval*retries = 10s + 2s*4 = 18s. + if got.Budget() != 18*time.Second { + t.Errorf("Budget = %v, want 18s", got.Budget()) + } +} + +func TestCompileIgnoresBadDurations(t *testing.T) { + // Bad/zero durations fall back to defaults (load-time validation is the guard). + hc := &config.Healthcheck{Kind: "tcp", Interval: "nope", Timeout: "", StartPeriod: "0s"} + got := Compile(hc) + if got.Interval != DefaultInterval || got.Timeout != DefaultTimeout || got.StartPeriod != DefaultStartPeriod { + t.Errorf("Compile with bad durations = %+v, want defaults", got) + } +}