From f5a1045a4544f9a903df460521257cf4c637fe21 Mon Sep 17 00:00:00 2001 From: sneak Date: Mon, 19 Oct 2026 04:18:21 +0000 Subject: [PATCH] Health check answers 503 while report files cannot be written (closes #142) The health check answered 200 "status":"ok" whatever happened, so a container whose report files could not be written stayed healthy while every report was refused with 500. The report buffer now says whether its last write of a report file failed. While it has, the health check's status is "error" and the handler answers 503 with the same fields, which fails the image's HEALTHCHECK. At start no write has failed, and the first write that succeeds brings back 200. A test removes DATA_DIR to make a write fail and checks the 503, then the 200 once a write succeeds again. Model: opus-5-5 --- README.md | 26 ++++++--- TODO.md | 9 ++++ internal/handlers/healthcheck.go | 12 ++++- internal/handlers/healthcheck_test.go | 31 +++++++---- internal/healthcheck/healthcheck.go | 12 ++++- internal/reportbuf/reportbuf.go | 10 ++++ internal/reportbuf/reportbuf_test.go | 78 +++++++++++++++++++++++++++ 7 files changed, 157 insertions(+), 21 deletions(-) diff --git a/README.md b/README.md index 671154d..6f4add2 100644 --- a/README.md +++ b/README.md @@ -199,7 +199,9 @@ stops. Its routes: address may send a limited number a minute, and the report files are capped in size, the oldest deleted first - `GET /.well-known/healthcheck` — answers 200 with `"status":"ok"`, the - server's version and its uptime + server's version and its uptime; while reports cannot be stored, as the last + write of a report file failed, it answers 503 with `"status":"error"` and the + same fields (see [Report storage](#report-storage)) - `GET /metrics` — Prometheus metrics behind basic auth, only when `METRICS_USERNAME` and `METRICS_PASSWORD` are set; each client address may make a limited number of requests to it a minute @@ -274,10 +276,11 @@ The reports of a failed write stay in memory, and the next flush, within a minute, tries again to write them. The server writes one file at a time, so a file holds its reports in the order they arrived, those of a failed write included. From the failed write until a write succeeds, `POST /api/v1/reports` -refuses every report with 500 and keeps nothing of it. The page sends the -refused samples again in its next report, as long as it still holds them: at the -1-second interval one refused report already loses some of those in the history -(see [Reporting](#reporting)). Reports already answered 200 are lost only if the +refuses every report with 500 and keeps nothing of it, and the health check +answers 503 with `"status":"error"`. The page sends the refused samples again in +its next report, as long as it still holds them: at the 1-second interval one +refused report already loses some of those in the history (see +[Reporting](#reporting)). Reports already answered 200 are lost only if the server stops before a write succeeds; the final flush at stop tries them too, and if it fails, the process exits non-zero. @@ -551,9 +554,16 @@ What the [upaas](https://git.eeqj.de/sneak/upaas) app for netwatch needs: stops the container. Empty, the backend sends nothing to Sentry - **Health check:** the image's `HEALTHCHECK` requests `/.well-known/healthcheck` through nginx every 30 seconds, so it fails unless - both nginx and the backend answer. upaas reads the container's health 60 - seconds after a deploy and fails the deploy unless it is `healthy`. The - container also stops when either process exits. + both nginx and the backend answer. It also fails while reports cannot be + stored, as when the volume is full or `DATA_DIR` cannot be written: the health + check answers 503 from a failed write of a report file until a write succeeds, + and the backend tries the write again every minute. Three failed checks in a + row make the container `unhealthy`, and one that passes makes it `healthy` + again. upaas reads the container's health once, 60 seconds after a deploy, and + fails the deploy unless it is `healthy`. A container that turns `unhealthy` + after that is neither restarted nor reported by upaas, whose `unless-stopped` + restart policy ignores health; only `docker ps` and `docker inspect` show it. + The container also stops when either process exits. ## Browser Compatibility diff --git a/TODO.md b/TODO.md index d63ca15..a8c1513 100644 --- a/TODO.md +++ b/TODO.md @@ -21,6 +21,15 @@ Run `make frontend-viewport-test` in CI as its own step; it is not part of # Completed Steps +- 2026-10-19: while report files cannot be written, the health check answers 503 + with `"status":"error"` and the same fields, so the image's `HEALTHCHECK` + reports the container `unhealthy` + ([#142](https://git.eeqj.de/sneak/netwatch/issues/142)). It answered 200 + `"status":"ok"` whatever happened, so the platform saw a healthy container + while every report was refused with 500. It answers 200 at start, before any + write has failed, and again from the first write that succeeds. A unit test + removes `DATA_DIR` to make a write fail and checks the 503, then puts it back + and checks the 200 after the next write - 2026-10-19: report file writes no longer overlap ([#150](https://git.eeqj.de/sneak/netwatch/issues/150)), so the reports of failed writes are written in the order they arrived. Two writes that failed at diff --git a/internal/handlers/healthcheck.go b/internal/handlers/healthcheck.go index 41cd943..04e0f70 100644 --- a/internal/handlers/healthcheck.go +++ b/internal/handlers/healthcheck.go @@ -3,9 +3,17 @@ package handlers import "net/http" // HandleHealthCheck returns a handler for the health check -// endpoint. +// endpoint. It answers 200 while the status is "ok" and 503 otherwise, +// so that the image's HEALTHCHECK fails. func (s *Handlers) HandleHealthCheck() http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { - s.respondJSON(w, r, s.hc.Healthcheck(), http.StatusOK) + resp := s.hc.Healthcheck() + + code := http.StatusOK + if resp.Status != "ok" { + code = http.StatusServiceUnavailable + } + + s.respondJSON(w, r, resp, code) } } diff --git a/internal/handlers/healthcheck_test.go b/internal/handlers/healthcheck_test.go index 3348ab6..ae9192d 100644 --- a/internal/handlers/healthcheck_test.go +++ b/internal/handlers/healthcheck_test.go @@ -9,17 +9,19 @@ import ( "testing" "time" + "sneak.berlin/go/netwatch/internal/config" "sneak.berlin/go/netwatch/internal/globals" "sneak.berlin/go/netwatch/internal/handlers" "sneak.berlin/go/netwatch/internal/healthcheck" "sneak.berlin/go/netwatch/internal/logger" + "sneak.berlin/go/netwatch/internal/reportbuf" "go.uber.org/fx/fxtest" ) // newStartedHandlers builds Handlers with a real health check for the -// server named in g, and starts them, which records the time the -// uptime counts from. +// server named in g, and a report buffer in a temporary directory, and +// starts them, which records the time the uptime counts from. func newStartedHandlers(t *testing.T, g *globals.Globals) *handlers.Handlers { t.Helper() @@ -30,14 +32,23 @@ func newStartedHandlers(t *testing.T, g *globals.Globals) *handlers.Handlers { t.Fatalf("logger: %v", err) } + buf, err := reportbuf.New(lc, reportbuf.Params{ + Config: &config.Config{DataDir: t.TempDir(), DataDirMaxBytes: 1 << 20}, + Logger: log, + }) + if err != nil { + t.Fatalf("report buffer: %v", err) + } + hc, err := healthcheck.New(lc, - healthcheck.Params{Globals: g, Logger: log}) + healthcheck.Params{Buffer: buf, Globals: g, Logger: log}) if err != nil { t.Fatalf("health check: %v", err) } - h, err := handlers.New(lc, - handlers.Params{Globals: g, Healthcheck: hc, Logger: log}) + h, err := handlers.New(lc, handlers.Params{ + Buffer: buf, Globals: g, Healthcheck: hc, Logger: log, + }) if err != nil { t.Fatalf("handlers: %v", err) } @@ -48,10 +59,12 @@ func newStartedHandlers(t *testing.T, g *globals.Globals) *handlers.Handlers { return h } -// TestHandleHealthCheck checks the health check's answer: 200, a JSON -// content type, and a JSON object with exactly the fields of -// healthcheck.HealthcheckResponse, carrying this server's name and -// version and an uptime counted from its start. +// TestHandleHealthCheck checks the health check's answer at start, when +// no write of a report file has failed: 200, a JSON content type, and a +// JSON object with exactly the fields of healthcheck.HealthcheckResponse, +// carrying "status":"ok", this server's name and version and an uptime +// counted from its start. The answer while writes fail is checked in +// internal/reportbuf, whose tests can make a write fail. func TestHandleHealthCheck(t *testing.T) { t.Parallel() diff --git a/internal/healthcheck/healthcheck.go b/internal/healthcheck/healthcheck.go index f4b78e1..8d7bdc3 100644 --- a/internal/healthcheck/healthcheck.go +++ b/internal/healthcheck/healthcheck.go @@ -10,6 +10,7 @@ import ( "sneak.berlin/go/netwatch/internal/config" "sneak.berlin/go/netwatch/internal/globals" "sneak.berlin/go/netwatch/internal/logger" + "sneak.berlin/go/netwatch/internal/reportbuf" "go.uber.org/fx" ) @@ -18,6 +19,7 @@ import ( type Params struct { fx.In + Buffer *reportbuf.Buffer Config *config.Config Globals *globals.Globals Logger *logger.Logger @@ -68,12 +70,18 @@ func New( return s, nil } -// Healthcheck returns the current health status of the application. +// Healthcheck returns the current health status of the application: +// "ok", or "error" while report files cannot be written. func (s *Healthcheck) Healthcheck() *HealthcheckResponse { + status := "ok" + if s.params.Buffer.LastWriteFailed() { + status = "error" + } + return &HealthcheckResponse{ Appname: s.params.Globals.Appname, Now: time.Now().UTC().Format(time.RFC3339Nano), - Status: "ok", + Status: status, UptimeHuman: s.uptime().String(), UptimeSeconds: int64(s.uptime().Seconds()), Version: s.params.Globals.Version, diff --git a/internal/reportbuf/reportbuf.go b/internal/reportbuf/reportbuf.go index 3b54eef..f6eb88f 100644 --- a/internal/reportbuf/reportbuf.go +++ b/internal/reportbuf/reportbuf.go @@ -255,6 +255,16 @@ func (b *Buffer) Append(v any) error { return nil } +// LastWriteFailed reports whether the last write of a report file to +// finish failed: false at start until a write fails, and false again +// once a write succeeds. While it is true, Append refuses reports. +func (b *Buffer) LastWriteFailed() bool { + b.mu.Lock() + defer b.mu.Unlock() + + return b.writeErr != nil +} + // deleteOldestFiles deletes report files, oldest first, until n more // bytes fit under maxBytes. It deletes none when the reports waiting // to be written leave no room for n even with every file gone, since diff --git a/internal/reportbuf/reportbuf_test.go b/internal/reportbuf/reportbuf_test.go index 448a6d6..ffb6128 100644 --- a/internal/reportbuf/reportbuf_test.go +++ b/internal/reportbuf/reportbuf_test.go @@ -1074,6 +1074,51 @@ func TestReportsRefusedWhileWritesFail(t *testing.T) { } } +// TestHealthCheckFailsWhileWritesFail asks the health check handler +// for its answer around a failed write. It answers 200 with +// "status":"ok" at start, 503 with "status":"error" from the failed +// write until a write succeeds, and 200 with "status":"ok" again after. +func TestHealthCheckFailsWhileWritesFail(t *testing.T) { + dir := t.TempDir() + t.Setenv("DATA_DIR", dir) + + buf, h := startBufferWithHandlers(t) + + checkHealthCheck(t, h, "at start", http.StatusOK, "ok") + + // A flush writes a file only when a report is waiting. + err := buf.Append(map[string]string{"id": "kept"}) + if err != nil { + t.Fatalf("append: %v", err) + } + + // With the data directory gone, the write has nowhere to go. + err = os.Remove(dir) + if err != nil { + t.Fatalf("remove data dir: %v", err) + } + + err = buf.Flush() + if err == nil { + t.Fatal("flush succeeded with the data directory gone") + } + + checkHealthCheck(t, h, "after the failed write", + http.StatusServiceUnavailable, "error") + + err = os.Mkdir(dir, 0o750) + if err != nil { + t.Fatalf("make data dir: %v", err) + } + + err = buf.Flush() + if err != nil { + t.Fatalf("flush with the data directory back: %v", err) + } + + checkHealthCheck(t, h, "after a write succeeded", http.StatusOK, "ok") +} + // startBufferWithHandlers starts a Buffer and the Handlers that store // reports in it through fx, as main does, with the DATA_DIR the calling // test has set. @@ -1121,6 +1166,39 @@ func postReport(t *testing.T, h *handlers.Handlers, clientID string) int { return rec.Code } +// checkHealthCheck asks the health check handler for its answer, and +// fails the test, saying when it asked, unless the answer has status +// code wantCode and a "status" field of wantStatus. +func checkHealthCheck( + t *testing.T, + h *handlers.Handlers, + when string, + wantCode int, + wantStatus string, +) { + t.Helper() + + rec := httptest.NewRecorder() + req := httptest.NewRequestWithContext(t.Context(), + http.MethodGet, "/.well-known/healthcheck", http.NoBody) + h.HandleHealthCheck().ServeHTTP(rec, req) + + var body struct { + Status string `json:"status"` + } + + err := json.Unmarshal(rec.Body.Bytes(), &body) + if err != nil { + t.Fatalf("health check %s: body not JSON: %v (%q)", + when, err, rec.Body.String()) + } + + if rec.Code != wantCode || body.Status != wantStatus { + t.Fatalf("health check %s: %d with status %q, want %d with %q", + when, rec.Code, body.Status, wantCode, wantStatus) + } +} + // TestConcurrentAppendsStopAtCap appends from many goroutines at once // with room for exactly roomFor reports: exactly that many must be // taken, which holds only if Append checks and counts each report -- 2.54.0