Explorar o código

M11: mark as shipped CONDITIONALLY (NATS resource limit surfaced)

See parres commit 047f3cb for the full message. Summary: 2-min
re-verification 2026-06-16 14:48 EDT found NATS JetStream resource
limits exceeded; ingestd publish path is broken under sustained load;
10-min soak was green only because the receive-rate metric does not
assert on publish success. M11 not fully shippable until NATS limits
are raised or smoke is updated to assert on publish success.
Luis Rosales hai 1 mes
pai
achega
d8008bc4e4
Modificáronse 2 ficheiros con 48 adicións e 10 borrados
  1. 47 9
      M11_VERIFICATION.md
  2. 1 1
      SPEC.md

+ 47 - 9
M11_VERIFICATION.md

@@ -1,12 +1,14 @@
 # M11 Verification
 
 > Filled in after the 2026-06-16 parres run.
+> **Updated 2026-06-16 14:48 EDT — M11 dev-playground gate shipped CONDITIONALLY. Receive rate is green; publish path is broken. See "Post-ship finding" below.**
 
 ## Test environment
 
 - **Local**: `docker compose --profile loadgen-grpc` (not run for this gate)
 - **Remote**: `parres` (192.168.44.94, 4 cores, shared with 7 user sessions + ollama + prometheus + clickhouse + grafana always-on)
 - **Smoke run log**: `/root/smoke-logs/m11-6k-20260616-100031.log`
+- **Re-verification log**: `/root/smoke-logs/m11-2min-final-20260616-124829.log`
 
 ## Exit criteria
 
@@ -46,7 +48,9 @@ Horizontal-scaling story: M10-bench (`M10_BENCH_VERIFICATION.md`) already proves
 | 9m  | 9563 | nan  | 0 | 32 |
 | 10m | 9473 | nan  | 0 | 32 |
 
-**Summary:** 20/20 samples green, min rate 9376/s (156% of 6k target), max 9683/s, p99 ≤ 25ms throughout, DLQ = 0, 32 gRPC streams sustained. The cluster is configured at 8k/s per loadgen in `docker-compose.yml`; the per-instance ceiling on parres (4 cores) caps aggregate at ~9.5k/s, which is well above the dev-playground gate. The "nan" p99s are sparse histogram windows at 60s scrape (p99 query needs more samples to converge); the windows with data all read the same 24.8ms bucket.
+**Summary (RECEIVE RATE ONLY — see Post-ship finding for publish-path status):** 20/20 samples green, min rate 9376/s (156% of 6k target), max 9683/s, p99 ≤ 25ms throughout, DLQ = 0, 32 gRPC streams sustained. The cluster is configured at 8k/s per loadgen in `docker-compose.yml`; the per-instance ceiling on parres (4 cores) caps aggregate at ~9.5k/s, which is well above the dev-playground gate. The "nan" p99s are sparse histogram windows at 60s scrape (p99 query needs more samples to converge); the windows with data all read the same 24.8ms bucket.
+
+**CRITICAL CAVEAT (see Post-ship finding):** The rate metric used is `ba_ingestd_alerts_received_total{service="ingestd"}` — this counts alerts **received via gRPC**, not alerts **successfully published to NATS**. The 10-min soak is therefore a green signal on the transport receive path, not on end-to-end delivery.
 
 ## Backpressure test result
 
@@ -54,21 +58,55 @@ Horizontal-scaling story: M10-bench (`M10_BENCH_VERIFICATION.md`) already proves
 
 > ❌ **DEFERRED.** The 16-stream loadgen (instance `loadgen-grpc-bp`) did not honor `--duration=20s` and failed to exit within the smoke's 60s wait window. This is the same `--duration` regression from commit `48ecaba` ("fix: loadgen producer must respect --duration under backpressure") surfacing under the new cluster contention. The smoke process exited with code 1; the backpressure loadgen was cleaned up manually. Fix is in the loadgen, not the server; transport-level backpressure is otherwise exercised by the 256 in-flight cap and per-source rate limiter (`BA_INGESTD_RATE_LIMIT_PER_SOURCE=20000`), both of which held during the soak.
 
+**Update 2026-06-16 14:48 EDT:** The hang is **fixed** in commit `7f7928b` (parres) / `39907d1` (local). Verified in isolation: a 15s backpressure loadgen now exits cleanly in 17s with exit code 0 (sent 142,304 alerts, p99 RTT 10-25ms). However, when run via the smoke script, `docker compose run --rm` for the backpressure loadgen now returns non-zero (loadgen process itself exits 0; the cause is in the smoke's `subprocess.Popen` stderr capture or a docker compose edge case). New exit-code issue deferred for separate investigation.
+
 ## Parres run
 
 - **Log:** `/root/smoke-logs/m11-6k-20260616-100031.log`
-- **Repo at run:** `09f0d54` + smoke-threshold commit
-- **Result:** dev-playground gate GREEN. Backpressure step deferred (see above).
+- **Repo at run:** `09f0d54` + smoke-threshold commit + loadgen fix commits
+- **Result:** dev-playground gate **PARTIALLY GREEN** — receive rate 20/20 green; publish path broken (see Post-ship finding).
+
+## Post-ship finding (2026-06-16 14:48 EDT) — NATS JetStream resource limits exceeded
+
+After the 10-min soak was green, the user requested a 2-min @ 6k/s re-verification on a freshly-cleaned parres (all broad-announce containers recreated, ollama preserved). Result:
+
+| Time | Rate/s | p99 (ms) | DLQ | Status |
+|---|---|---|---|---|
+| 0m | 9558 | nan | 0 | ✅ |
+| 1m | 9748 | nan | 0 | ✅ |
+| 1m | 9716 | nan | 0 | ✅ |
+| 2m | **0**  | —    | — | ❌ rate collapse |
+
+**Root cause (NATS + ingestd logs):**
+
+NATS is logging `[ERR] JetStream resource limits exceeded for server` every 10 seconds throughout the smoke (first occurrence ~11s after `docker compose up`). Once the limit is hit, ingestd's `nats publish` calls fail with `context canceled` and alerts stop being processed. The gRPC receive rate collapses to 0 within ~30s of the limit being hit because the loadgens' per-stream contexts cancel and they stop sending.
+
+**Why the 10-min soak didn't catch this:**
+
+The smoke's rate metric (`ba_ingestd_alerts_received_total{service="ingestd"}`) counts alerts **received via gRPC**, not alerts **successfully published to NATS**. ingestd was acking alerts that NATS was rejecting. The 10-min soak was green on the receive rate; the system was actually broken end-to-end on the publish path the whole time.
+
+**Implication for M11:**
+
+The M11 dev-playground gate is shipped, but the gRPC → NATS → delivery pipeline is broken under sustained load. M11 cannot be declared fully shipped until **both**:
+
+1. NATS JetStream resource limits are raised (config investigation deferred), or the smoke is updated to assert on **publish success** rather than (or in addition to) receive rate, AND
+2. The full 5-step smoke (soak + backpressure + DLQ invariant + teardown) runs green end-to-end with the new assertion
 
 ## Known issues
 
-1. **Loadgen `--duration` regression** — the backpressure loadgen does not exit cleanly after `--duration=N` under cluster contention. Surfaced in commits `a61fc6d`, `48ecaba`, and the 2026-06-16 run. Server-side backpressure is unaffected; this is purely a loadgen shutdown bug.
-2. **p99 sparse windows** — `m11_lib.get_grpc_p99()` reads `ba_ingestd_grpc_ack_latency_seconds_bucket` over a 60s window. At ~9.5k/s with 32 streams, individual bucket counts are high enough for convergence, but the metric does not always have data at the exact 60s scrape instant. Window selection (90s or 120s) would densify coverage; not blocking for the M11 gate since all populated windows read the same value.
+1. **NATS JetStream resource limits exceeded** (post-ship finding, 2026-06-16 14:48 EDT) — under sustained load (~6k/s for >1.5 min), NATS hits an internal resource limit (memory? storage? max messages per stream?) and starts rejecting publishes. ingestd logs `"nats publish"` errors with `"context canceled"`. The smoke's receive-rate metric does not catch this; a publish-success assertion (`rate(ba_ingestd_nats_publish_ok_total[30s])` or similar) is required. NATS config investigation deferred.
+2. **Loadgen backpressure test exits non-zero** (2026-06-16 14:48 EDT) — the hang is fixed (`7f7928b` / `39907d1`), but `docker compose run --rm` for the backpressure loadgen now returns non-zero. The loadgen process itself exits 0; the cause is in the smoke's `subprocess.Popen` stderr capture or a docker compose edge case. Investigation deferred.
+3. **Loadgen `--duration` regression** (pre-ship) — the backpressure loadgen does not exit cleanly after `--duration=N` under cluster contention. **Resolved** in `7f7928b` / `39907d1` (main() now exits on worker completion, not just on SIGTERM).
+4. **p99 sparse windows** (pre-ship) — `m11_lib.get_grpc_p99()` reads `ba_ingestd_grpc_ack_latency_seconds_bucket` over a 60s window. At ~9.5k/s with 32 streams, individual bucket counts are high enough for convergence, but the metric does not always have data at the exact 60s scrape instant. Window selection (90s or 120s) would densify coverage; not blocking for the M11 gate since all populated windows read the same value.
 
 ## Sign-off
 
-- [x] **M11 dev-playground gate** PASS (1/1 parres run, 20/20 soak samples green, p99 ≤ 25ms, DLQ=0)
-- [ ] 3/3 local runs green (deferred — dev-playground gate already proven on parres; local can be re-run if desired)
+- [⚠️] **M11 dev-playground gate** SHIPPED CONDITIONALLY — receive rate green, publish path broken (NATS resource limit)
+- [x] Receive-rate assertion: 20/20 soak samples green at 9376-9683/s, p99 ≤ 25ms, DLQ=0
+- [ ] Publish-success assertion: **NOT YET** — needs smoke update + NATS limit fix
+- [ ] 3/3 local runs green (deferred — dev-playground gate already tested on parres)
 - [ ] M11 prod gate (10k/s, prod-shape cluster) — planned for M12
-- [x] Backpressure step noted as deferred, fix tracked in loadgen
-- [x] SPEC.md M11 row updated to **shipped 2026-06-16** (dev-playground gate)
+- [x] Backpressure step hang fixed (`7f7928b` / `39907d1`); new exit-code issue deferred
+- [⚠️] SPEC.md M11 row updated to **shipped conditionally 2026-06-16**
+
+**Bottom line:** M11 is not fully shippable. The receive path works. The publish path (gRPC → NATS → delivery) is broken under sustained load due to NATS resource limits. Re-verification needed after NATS config is tuned and the smoke is updated to assert on publish success.

+ 1 - 1
SPEC.md

@@ -895,4 +895,4 @@ ingestd_rejection_latency_seconds_bucket{transport,reason} histogram
 | M9 | Observability (Prom/Grafana) | 1 dashboard per tier + per-company drilldown; layers 6, 7 in |
 | M10 | Load test 5k/s on docker-compose | soak 10 min, p99 ≤ 5s, zero DLQ, run via `loadgen`; runaway-source test passes | **✅ shipped 2026-06-15** (live smoke test: 3 consecutive green runs on local; 1 run on remote `parres`; all 20 soak samples within 268–278/s, p99=0.248s, DLQ=0; runaway-source fault injection: p99 clean for healthy companies throughout 60s rogue load; see `M10_VERIFICATION.md` + `M10_SMOKE_LOG.md`) |
 | M10-bench | Broker + router ceiling bench | 50k/s via `loadgen` against broker+router (delivery stubbed); p99 router latency ≤ 50ms; no broker backpressure | **✅ shipped 2026-06-15** (1 green run on remote `parres`; 10 samples over 5 min, router p99=5.0ms throughout, NATS qd informational only; see `M10_BENCH_VERIFICATION.md`; HTTP loadgen RTT ceiling limits realistic rate to ~275/s, target adjusted accordingly) |
-| M11 | gRPC bidi-streaming ingest | internal Go service pushes ≥ 10k alerts/sec on one stream, p99 server-side `Ack` ≤ 50ms | **✅ shipped 2026-06-16** (M11 dev-playground gate: 1 green run on remote `parres` 192.168.44.94; 20/20 soak samples at 9376–9683/s sustained 10 min, p99=24.8ms, DLQ=0, 32 gRPC streams; backpressure step deferred — loadgen `--duration=20s` not honored under cluster contention; see `M11_VERIFICATION.md`; M11 prod gate at 10k/s requires a prod-shape cluster, planned for **M12**) |
+| M11 | gRPC bidi-streaming ingest | internal Go service pushes ≥ 10k alerts/sec on one stream, p99 server-side `Ack` ≤ 50ms | **⚠️ shipped conditionally 2026-06-16** (M11 dev-playground gate: 10-min soak 20/20 receive-rate samples green at 9376–9683/s, p99=24.8ms, DLQ=0, 32 gRPC streams — BUT the receive-rate metric does not assert on publish success; 2-min re-verification 2026-06-16 14:48 EDT found NATS JetStream resource limits exceeded causing rate collapse to 0/s at 2m; pipeline is broken end-to-end on the publish path. Backpressure step: hang fixed in `7f7928b`/`39907d1`, new exit-code issue deferred. M11 not fully shippable until NATS limits are raised or smoke asserts on publish success. M11 prod gate at 10k/s requires a prod-shape cluster, planned for **M12**.) |