From 826fa942e6391e75bc697a04d2ae28f719f01df6 Mon Sep 17 00:00:00 2001 From: MrAlders0n <55921894+MrAlders0n@users.noreply.github.com> Date: Sat, 24 Oct 2026 15:29:11 -0400 Subject: [PATCH] Count every timeout 503 in beacon_api_unavailable_total (#281) * Count every timeout 503 in beacon_api_unavailable_total * Check each model's timeout count; clarify respondReaderError --- internal/api/handlers/reader_errors_test.go | 51 ++++++++++++++++++++ internal/api/handlers/responses.go | 18 +++++-- internal/api/handlers/unavailable_metrics.go | 1 + internal/metrics/metrics.go | 2 +- 4 files changed, 66 insertions(+), 6 deletions(-) diff --git a/internal/api/handlers/reader_errors_test.go b/internal/api/handlers/reader_errors_test.go index e5db054..76c60cf 100644 --- a/internal/api/handlers/reader_errors_test.go +++ b/internal/api/handlers/reader_errors_test.go @@ -13,8 +13,10 @@ import ( "testing" "github.com/MeshCore-Beacon/beacon-server/internal/api" + "github.com/MeshCore-Beacon/beacon-server/internal/metrics" "github.com/go-chi/chi/v5" "github.com/jackc/pgx/v5/pgconn" + "github.com/prometheus/client_golang/prometheus/testutil" ) // readerRoutes mounts every reader-backed router the way the API does. @@ -118,3 +120,52 @@ func TestReaderErrorsAnswerTimeoutAs503(t *testing.T) { } } } + +// timeouts reads beacon_api_unavailable_total{reason="timeout"} for every model a page reads. +func timeouts() map[string]float64 { + out := map[string]float64{} + for _, m := range []string{"none", "cmi", "packet_sites", "observation_payload_types"} { + out[m] = testutil.ToFloat64(metrics.APIUnavailable.WithLabelValues("timeout", m)) + } + return out +} + +// Every timeout 503 is counted once in beacon_api_unavailable_total: under its read model on a page that reads one, +// under none on every other page; a 500 is not counted. +func TestReaderTimeoutsAreCounted(t *testing.T) { + readModelPages := map[string]float64{"cmi": 2, "packet_sites": 1, "observation_payload_types": 1} // see readerErrorPaths + for _, c := range []struct { + err error + timeout bool + }{ + {&pgconn.PgError{Code: "57014"}, true}, + {errors.New("boom"), false}, + } { + handler := readerRoutes(errReader{err: fmt.Errorf("wrapped: %w", c.err)}) + before := timeouts() + for _, path := range readerErrorPaths { + handler.ServeHTTP(httptest.NewRecorder(), httptest.NewRequest("GET", path, nil)) + } + after := timeouts() + want := map[string]float64{"none": 0, "cmi": 0, "packet_sites": 0, "observation_payload_types": 0} + if c.timeout { + want["none"] = float64(len(readerErrorPaths)) + for m, n := range readModelPages { + want[m] = n + want["none"] -= n + } + } + for m, n := range want { + if got := after[m] - before[m]; got != n { + t.Errorf("%v: model %s counted %v timeouts, want %v", c.err, m, got, n) + } + } + } + // A handler's own time limit (the heavy stats and route searches) counts as a timeout on a page with no model. + before := timeouts() + rec := httptest.NewRecorder() + respondTimeout(rec, "comparison timed out; try a shorter time period") + if after := timeouts(); rec.Code != http.StatusServiceUnavailable || after["none"]-before["none"] != 1 { + t.Errorf("respondTimeout: status %d, counted under none %v", rec.Code, after["none"]-before["none"]) + } +} diff --git a/internal/api/handlers/responses.go b/internal/api/handlers/responses.go index 4e34121..48ed4c3 100644 --- a/internal/api/handlers/responses.go +++ b/internal/api/handlers/responses.go @@ -15,6 +15,7 @@ import ( "github.com/MeshCore-Beacon/beacon-server/internal/api" "github.com/MeshCore-Beacon/beacon-server/internal/guards" + "github.com/MeshCore-Beacon/beacon-server/internal/metrics" "github.com/jackc/pgx/v5/pgconn" ) @@ -27,22 +28,29 @@ func respondUnavailable(w http.ResponseWriter, err error) bool { Code: "service_unavailable", Message: "This page is not available yet. Retry later."}) return true case isQueryTimeout(err): - respondTimeout(w, "This page took too long to load. Retry later, or ask for a shorter time range.") + writeTimeout(w, "This page took too long to load. Retry later, or ask for a shorter time range.") return true } return false } -// respondTimeout answers a read that ran out of time with 503 deadline_exceeded and Retry-After. +// respondTimeout answers a read that ran out of time on a page that reads no read model with 503 deadline_exceeded +// and Retry-After, and counts it. func respondTimeout(w http.ResponseWriter, message string) { + writeTimeout(w, message) + metrics.APIUnavailable.WithLabelValues("timeout", modelNone).Inc() +} + +func writeTimeout(w http.ResponseWriter, message string) { guards.WriteRefusal(w, &guards.Refusal{Guard: "timeout", Status: http.StatusServiceUnavailable, RetryAfter: 10, Code: "deadline_exceeded", Message: message}) } -// respondReaderError answers a failed read: a retryable error is the 503 respondUnavailable writes, anything else a -// 500 with message that logs err. +// respondReaderError answers a failed read: a retryable error is the 503 respondUnavailable writes, counted with +// model none, anything else a 500 with message that logs err. A read-model page calls it only after +// respondUnavailableFor found the error not retryable, so it writes the 500 and counts nothing. func respondReaderError(w http.ResponseWriter, err error, message string) { - if respondUnavailable(w, err) { + if respondUnavailableFor(w, err, modelNone) { return } slog.Error(fmt.Sprintf("api: error %d: %s", http.StatusInternalServerError, message), "component", "api", "error", err) diff --git a/internal/api/handlers/unavailable_metrics.go b/internal/api/handlers/unavailable_metrics.go index 95e3f01..6086b7f 100644 --- a/internal/api/handlers/unavailable_metrics.go +++ b/internal/api/handlers/unavailable_metrics.go @@ -14,6 +14,7 @@ const ( modelPacketSites = "packet_sites" modelCmi = "cmi" modelPayloadTypes = "observation_payload_types" + modelNone = "none" // a page that reads no read model ) // respondUnavailableFor is respondUnavailable for a page that reads model; it counts each 503 it writes. diff --git a/internal/metrics/metrics.go b/internal/metrics/metrics.go index 097911b..edade06 100644 --- a/internal/metrics/metrics.go +++ b/internal/metrics/metrics.go @@ -121,7 +121,7 @@ var ( // that bypassed the model. APIUnavailable = prometheus.NewCounterVec(prometheus.CounterOpts{ Name: "beacon_api_unavailable_total", - Help: "503s a page answered because its data was not ready (reason not_ready) or its statement timed out (reason timeout), by the model the page reads.", + Help: "503s a page answered because its data was not ready (reason not_ready) or its statement ran out of time (reason timeout), by the read model the page reads (none for a page that reads none).", }, []string{"reason", "model"}) ReadModelRepaired = prometheus.NewCounterVec(prometheus.CounterOpts{ Name: "beacon_readmodel_repaired_rows_total",