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

@@ -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"])
+	}
+}

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)

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.

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",