amadan
edge: pin the two multi-upstream fallback contracts, throttle the reload complaint
Review found both non-happy-path branches of Reload's addr arm untested:
- unparseable health column -> the route must lose its PROBING, never its
service. Test: Health "{not json" + a live backend answers 200 and holds
no prober entry.
- addrs set with no health config -> serves addrs[0] unprobed. This shape
was served by NOTHING before the switch changed (the old arm gated on the
legacy Addr column, which it leaves empty), so the behavior is new by
construction: the test pins that upstream one serves every request, that
the sibling upstream is never used, and that a dead first upstream keeps
the legacy bare 502 rather than borrowing the probed path's 503.
Also from review: the balance assertion is exact 10/10 rather than "both were
used" (which would sit through a 19/1 split); the WebSocket test asserts the
route is probed, so it cannot pass while silently exercising tcpProxy; and
prober.go's claim that Reload's `hib` gate is the no-hibernate door for addr
routes is corrected — it reads Kind/Hibernate/viaTunnel and says nothing about
addrs, so the actual door is provision.ValidateShape's addr+hibernate refusal.
The unparseable-health line is a STANDING condition, printing on every reload
for as long as the bad row exists, so it now goes through logThrottled —
logPurgeIssue's first-then-every-300th counter, generalized out of
purge_header.go now that it has a second caller.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
4 files changed,
+180
−33
internal/edge/edge.go+44 −11internal/edge/edge_test.go+121 −5internal/edge/prober.go+14 −5internal/edge/purge_header.go+1 −12
diff --git a/internal/edge/edge.go b/internal/edge/edge.go| index 97a411db4..c7b0768c1 100644 |
| --- a/internal/edge/edge.go |
| +++ b/internal/edge/edge.go |
| @@ -130,12 +130,14 @@ type Edge struct { |
| // invoking the hibernation activator or the backend — the mitigation |
| // this whole feature exists for. nil disables caching entirely. |
| cache *Cache |
| - // purgeLogN counts Carlos-Purge complaints per (class, host) so |
| - // logPurgeIssue can rate-limit them; those lines are driven by app |
| - // responses on the request hot path and would otherwise be one journal |
| - // line per request. Lazily created under purgeLogMu. |
| - purgeLogMu sync.Mutex |
| - purgeLogN map[string]int |
| + // logN counts occurrences per throttle key so logThrottled can rate-limit |
| + // a repeating complaint. Two callers today: Carlos-Purge complaints, which |
| + // are driven by app responses on the request hot path and would otherwise |
| + // be one journal line per request, and Reload's unparseable-health line, |
| + // which repeats on every reload for as long as the bad row exists. Lazily |
| + // created under logMu. |
| + logMu sync.Mutex |
| + logN map[string]int |
| // reloadHook, when set (OnReload), runs after every successful route |
| // swap — the wildcard manager recomputes its parent set from it. Atomic |
| // because registration happens in RunWithActivator after Watch may |
| @@ -398,11 +400,14 @@ func (e *Edge) Reload() error { |
| var h provision.Health |
| if err := json.Unmarshal([]byte(t.Health), &h); err != nil { |
| // Never a dead route: a health column we cannot parse costs |
| - // the route its probing, not its service. Logged every |
| - // reload on purpose — it is a config error someone has to |
| - // fix, and the route silently losing HA is worse than the |
| - // log line. |
| - log.Printf("edge: route %s: unparseable health config (%v) — serving %s unprobed", t.Host, err, addrs[0]) |
| + // the route its probing, not its service. Logged rather |
| + // than swallowed — it is a config error someone has to fix, |
| + // and a route silently losing its HA is worse than a log |
| + // line — but throttled, because a bad row is a STANDING |
| + // condition that would otherwise print on every reload for |
| + // as long as it exists. |
| + e.logThrottled("health-parse "+t.Host, fmt.Sprintf( |
| + "route %s: unparseable health config (%v) — serving %s unprobed", t.Host, err, addrs[0])) |
| p = tcpProxy(addrs[0]) |
| break |
| } |
| @@ -551,6 +556,34 @@ func (e *Edge) OnReload(fn func()) { |
| e.reloadHook.Store(&fn) |
| } |
| +// logThrottled logs msg the first time key occurs and every 300th time after |
| +// that — the same first-then-every-300th shape as the registry watcher below, |
| +// generalized out of logPurgeIssue (purge_header.go) when Reload gained a |
| +// second line with the same problem. |
| +// |
| +// The problem both share: the condition is a STANDING one, not an event. A |
| +// malformed Carlos-Purge header repeats on every response the app writes; an |
| +// unparseable health column repeats on every reload for as long as the row |
| +// exists. Either would fill a journal with the same sentence. The first |
| +// occurrence is always logged, so nothing is silently swallowed, and the |
| +// running count travels with each line so the rate stays visible. |
| +// |
| +// Keys must be built from values the box itself controls (a route's own host, |
| +// a complaint class) — never from remote input, or the map becomes a memory |
| +// growth vector. |
| +func (e *Edge) logThrottled(key, msg string) { |
| + e.logMu.Lock() |
| + if e.logN == nil { |
| + e.logN = make(map[string]int) |
| + } |
| + e.logN[key]++ |
| + n := e.logN[key] |
| + e.logMu.Unlock() |
| + if n == 1 || n%300 == 0 { |
| + log.Printf("edge: %s (occurrence #%d)", msg, n) |
| + } |
| +} |
| + |
| func (e *Edge) current() map[string]upstream { |
| if p := e.upstreams.Load(); p != nil { |
| return *p |
diff --git a/internal/edge/edge_test.go b/internal/edge/edge_test.go| index 4ada76d02..76ae05b87 100644 |
| --- a/internal/edge/edge_test.go |
| +++ b/internal/edge/edge_test.go |
| @@ -1627,13 +1627,15 @@ func TestMultiUpstreamBalancesAcrossLiveBackends(t *testing.T) { |
| t.Fatalf("request %d: body = %q, want one of the two upstreams", i, body) |
| } |
| } |
| - if hitsA.Load() == 0 || hitsB.Load() == 0 { |
| - t.Fatalf("upstream hits = A:%d B:%d, want BOTH non-zero (round-robin over the live set)", |
| + // Exactly even, not merely "both were used". The cursor is per route and |
| + // starts at zero, keep-alives are off so every request dials, and both |
| + // upstreams stay live throughout — so 10/10 is the only correct answer |
| + // here, and a loose "> 0" assertion would sit quietly through a 19/1 split |
| + // that means the rotation has broken. |
| + if hitsA.Load() != 10 || hitsB.Load() != 10 { |
| + t.Fatalf("upstream hits = A:%d B:%d, want 10/10 (strict round-robin over the live set)", |
| hitsA.Load(), hitsB.Load()) |
| } |
| - if total := hitsA.Load() + hitsB.Load(); total != 20 { |
| - t.Fatalf("upstreams served %d requests, want exactly 20 (no request served twice or dropped)", total) |
| - } |
| } |
| func TestDialFailureRetriesOtherUpstreamNoUserError(t *testing.T) { |
| @@ -1889,6 +1891,15 @@ func TestMultiUpstreamServesWebSocketUpgrade(t *testing.T) { |
| srv := httptest.NewServer(e) |
| defer srv.Close() |
| + // Pin that this route really took the multiProxy arm: only a probed route |
| + // has a prober, so without this the test would still pass if the switch |
| + // had quietly built a plain tcpProxy — and it is tcpProxy's transport, |
| + // not multiProxy's keep-alive-free one, that the upgrade path is being |
| + // checked against. |
| + if live := e.probers.Live("ws.example.com"); len(live) != 1 { |
| + t.Fatalf("live set = %v, want one probed upstream — this test must exercise multiProxy, not tcpProxy", live) |
| + } |
| + |
| c, err := net.Dial("tcp", strings.TrimPrefix(srv.URL, "http://")) |
| if err != nil { |
| t.Fatalf("dial edge: %v", err) |
| @@ -1919,3 +1930,108 @@ func TestMultiUpstreamServesWebSocketUpgrade(t *testing.T) { |
| t.Fatalf("post-upgrade echo = %q, want %q — bytes must flow both ways after the switch", line, "ws:ping\n") |
| } |
| } |
| + |
| +// TestUnparseableHealthServesUnprobed pins the parse-failure contract: a |
| +// health column the edge cannot read costs the route its PROBING, never its |
| +// SERVICE. The alternative — skipping the route, or building a proxy over an |
| +// empty live set — turns one bad character in a config column into a dead |
| +// host, which is the one outcome this branch exists to prevent. |
| +func TestUnparseableHealthServesUnprobed(t *testing.T) { |
| + addr, hits := countingBackend(t, "served anyway") |
| + |
| + reg := openReg(t) |
| + if err := reg.Upsert(registry.Route{ |
| + Host: "broken.example.com", Kind: "service", Status: "ready", |
| + Addrs: addr, Health: "{not json", |
| + }); err != nil { |
| + t.Fatalf("upsert: %v", err) |
| + } |
| + |
| + e, err := New(reg, nil) |
| + if err != nil { |
| + t.Fatalf("New: %v", err) |
| + } |
| + defer e.probers.Stop() |
| + srv := httptest.NewServer(e) |
| + defer srv.Close() |
| + |
| + code, body := getHost(t, srv.URL, "broken.example.com") |
| + if code != http.StatusOK || body != "served anyway" { |
| + t.Fatalf("= %d %q, want 200 %q — an unreadable health config must not take the host off the air", |
| + code, body, "served anyway") |
| + } |
| + if got := hits.Load(); got != 1 { |
| + t.Fatalf("backend served %d requests, want 1", got) |
| + } |
| + if st := e.probers.State(); len(st) != 0 { |
| + t.Fatalf("prober state = %v, want empty — a health config that did not parse cannot become a probing job", st) |
| + } |
| +} |
| + |
| +// TestMultiAddrWithoutHealthServesFirstUnprobed covers the row shape nothing |
| +// mints but the switch must still answer for: several addrs, no health |
| +// config. Before multi-upstream routing such a row was served by NOTHING (the |
| +// old arm gated on the legacy Addr column, which this shape leaves empty), so |
| +// the behavior asserted here is new by construction and needs pinning: |
| +// upstream ONE is served, unprobed, with the legacy 502 semantics. Balancing |
| +// is deliberately not offered — without a probe there is no live set, and |
| +// rotating onto upstreams nothing is checking would be worse than using one. |
| +func TestMultiAddrWithoutHealthServesFirstUnprobed(t *testing.T) { |
| + first, firstHits := countingBackend(t, "first") |
| + second, secondHits := countingBackend(t, "second") |
| + dead := deadAddr(t) |
| + |
| + reg := openReg(t) |
| + if err := reg.Upsert(registry.Route{ |
| + Host: "unprobed.example.com", Kind: "service", Status: "ready", |
| + Addrs: first + "," + second, |
| + }); err != nil { |
| + t.Fatalf("upsert: %v", err) |
| + } |
| + // A second route of the same shape whose first upstream is dead, so the |
| + // failure semantics can be asserted alongside the success ones. |
| + if err := reg.Upsert(registry.Route{ |
| + Host: "unprobed-dead.example.com", Kind: "service", Status: "ready", |
| + Addrs: dead + "," + second, |
| + }); err != nil { |
| + t.Fatalf("upsert: %v", err) |
| + } |
| + |
| + e, err := New(reg, nil) |
| + if err != nil { |
| + t.Fatalf("New: %v", err) |
| + } |
| + defer e.probers.Stop() |
| + srv := httptest.NewServer(e) |
| + defer srv.Close() |
| + |
| + for i := 0; i < 6; i++ { |
| + code, body := getHost(t, srv.URL, "unprobed.example.com") |
| + if code != http.StatusOK || body != "first" { |
| + t.Fatalf("request %d = %d %q, want 200 %q (addrs[0], unprobed)", i, code, body, "first") |
| + } |
| + } |
| + if got := firstHits.Load(); got != 6 { |
| + t.Fatalf("first upstream served %d requests, want all 6", got) |
| + } |
| + if got := secondHits.Load(); got != 0 { |
| + t.Fatalf("second upstream served %d requests, want 0 — an unprobed route must not balance onto upstreams nothing is checking", got) |
| + } |
| + |
| + // Dead first upstream: the LEGACY failure shape, not the probed one. No |
| + // live set exists to fail away from, so there is nothing to promise a |
| + // client about coming back. |
| + resp := getHostHeader(t, srv.URL, "unprobed-dead.example.com") |
| + if resp.StatusCode != http.StatusBadGateway { |
| + t.Fatalf("dead first upstream = %d, want 502 (the unprobed path keeps the stdlib behavior)", resp.StatusCode) |
| + } |
| + if got := resp.Header.Get("Retry-After"); got != "" { |
| + t.Fatalf("Retry-After = %q, want absent — 503 semantics are bought by probing, not by the addr count", got) |
| + } |
| + if got := secondHits.Load(); got != 0 { |
| + t.Fatalf("second upstream served %d requests, want 0 — the unprobed path must not retry onto a sibling upstream", got) |
| + } |
| + if st := e.probers.State(); len(st) != 0 { |
| + t.Fatalf("prober state = %v, want empty — neither route carries a health config", st) |
| + } |
| +} |
diff --git a/internal/edge/prober.go b/internal/edge/prober.go| index 6add169eb..9467c0d58 100644 |
| --- a/internal/edge/prober.go |
| +++ b/internal/edge/prober.go |
| @@ -14,11 +14,20 @@ package edge |
| // fail_after × interval while probes catch up. Probing only ever REMOVES |
| // confidence; it never withholds it. |
| // |
| -// 2. **Probes dial upstreams directly**, never the edge's own public host. |
| -// Combined with the no-hibernate invariant for addr routes (Reload's `hib` |
| -// gate), a probe can therefore never wake a hibernating tenant — the wake |
| -// hazard that would otherwise make active probing incompatible with |
| -// hibernation simply does not exist here. |
| +// 2. **Probes dial upstreams directly**, never the edge's own public host, so |
| +// a probe cannot enter the activator and cannot wake a hibernating tenant |
| +// — the wake hazard that would otherwise make active probing incompatible |
| +// with hibernation. |
| +// |
| +// The second half of that guarantee is a MINT-SIDE door, not Reload's: |
| +// provision.ValidateShape refuses `addrs` together with `hibernate: true` |
| +// outright (internal/provision/provision.go, "addr with hibernate"), so a |
| +// probed route is never activator-managed in the first place. Reload's |
| +// `hib` gate is NOT that door — it reads `Kind == "instance" && Hibernate |
| +// && !viaTunnel` and says nothing about addrs — so a hand-written registry |
| +// row could still pair the two, and would then hibernate a process whose |
| +// upstream the probe keeps marking down. Fixing that means widening the |
| +// gate, not trusting this comment. |
| import ( |
| "context" |
diff --git a/internal/edge/purge_header.go b/internal/edge/purge_header.go| index c9afa81a6..bdb75c250 100644 |
| --- a/internal/edge/purge_header.go |
| +++ b/internal/edge/purge_header.go |
| @@ -2,7 +2,6 @@ package edge |
| import ( |
| "fmt" |
| - "log" |
| "net/http" |
| "net/http/httputil" |
| "net/url" |
| @@ -525,17 +524,7 @@ func (e *Edge) applyPurgeTargets(host, joined string) { |
| // table, never from the header, so the map is bounded by the number of routes |
| // on the box and cannot be grown by a remote party. |
| func (e *Edge) logPurgeIssue(kind, host, msg string) { |
| - e.purgeLogMu.Lock() |
| - if e.purgeLogN == nil { |
| - e.purgeLogN = make(map[string]int) |
| - } |
| - key := kind + " " + host |
| - e.purgeLogN[key]++ |
| - n := e.purgeLogN[key] |
| - e.purgeLogMu.Unlock() |
| - if n == 1 || n%300 == 0 { |
| - log.Printf("edge: %s (occurrence #%d)", msg, n) |
| - } |
| + e.logThrottled("purge "+kind+" "+host, msg) |
| } |
| // purgeTargetKey turns one declared target into the cache-key components it |