tidaldb/docs/runbooks/on-call.md
jordan fe8d0c87e7 harden: restore CI verification, remove four wire-level fabrications, instrument the 401 path
Implements tmp/tidaldb-fleet-hardening (20 planned tasks + 2 found by measurement).

Ring 0 — restore verification. .woodpecker.yaml step pods ran at the namespace
default of 1500m/2Gi, which OOMKilled a prior pipeline and starved the release
gate past its budget. Both push-path steps now declare
backend_options.kubernetes.resources as two YAML anchors declared once on their
first consuming step. The values are CALIBRATED against measured free node
capacity, not against the LimitRange max: `requests: cpu 2` (this roadmap's
original figure) fits on NO node and would sit Pending forever, because
`ci-build-bounds` grants permission and the nodes supply capacity, and those are
not the same thing.

The `nightly` cron described in this file for 216 days was never created, so
tier-3 chaos, the fault classes, mTLS and the PITR test produced exactly zero
signal while reading like standing coverage. nightly-chaos and
nightly-security-ops now alias the anchors and have budgets matching the gate
(their 120/90 were TIGHTER on the same runner, so they would have failed
nightly for a budget reason, not a correctness one). nightly-soak is REMOVED,
not scheduled: it drives 1000 rps for 600s gating on p99 <= 250ms, and the best
node has 1700m free CPU, so it would fail on starvation rather than regression —
manufacturing a nightly false alarm. Its commands move verbatim to
docs/runbooks/nightly-soak.md.

Ring 1 — four fabrications removed from the wire.
- scatter_merge sorted and truncated without re-stamping rank, so /feed and
  /search returned 1,1,2 under full placement. Reuses merge_cross_shard's
  existing stamp; asserted on BOTH the multi-group merge path and the
  single-group [only] fast path that bypasses it.
- aggregate_region_row's None arm invented `applied_events: 0` plus a deficit
  derived from it. applied_events/lag_events are now Option<u64>, null on the
  wire. leader_last_seq was also unwrap_or(0), so a node that could not reach
  the LEADER computed 0 - applied = 0 for every region and reported a converged
  cluster it had never measured — a fabrication pointing the dangerous way.
- tidalctl inferred NO REPORT from `applied == 0 && lag > 0`. That heuristic was
  actively hiding the PVC-wipe shape: a measured zero with a real deficit
  rendered as "no report" instead of BEHIND. Now read off the wire; converged
  exits 0, partitioned still exits nonzero.
- /sharded/* answered 201/204 for single-copy writes with nothing anywhere
  saying so. Now requires `x-tidal-ack: local`, rejecting with 400 via the
  existing invalid_input path. Six call sites migrated, not the two this
  roadmap predicted — including docs/runbooks/cluster.md §16.3, which told
  operators to run a quorum-write probe via POST /sharded/items. That probe
  cannot verify quorum: the surface applies locally with no WAL append. It was
  used as the safety check between every step of a staged deploy earlier today.

Ring 2 — observability. JSON_LOGS was already implemented and the deployment
simply never asked for it; the StatefulSet now sets it, plus
TIDAL_SERVICE_NAME=tidaldb because enabling it silently renames the
VictoriaLogs `service` stream field and would have blinded every query keyed on
it. Adds tidaldb_usearch_replicated_vectors_total, incremented on BOTH the
origin (wal_blob_first -> Ok(Some)) and the follower apply path — counting only
the origin would mean each vector lands on exactly one node, replicas never
agree, and the alert built on it pages forever.

Found by measurement, not planned: the 401 path discarded every fact about
every rejection. Traefik has served 101,858 rejected requests to the public
ingress — 87.6% of all its traffic — with no record of who or why anywhere.
unauthorized_response now emits reason (missing_token vs invalid_token, the
distinction that separates a scanner from a rotation that missed a consumer)
and the forwarded client. The token is never logged.

Also: scripts/restore-fleet.sh --cluster started the soak monitor while
deliberately leaving its gate suspended, orphaning a watcher that has reported
"0/30 green nights" for 13 days. The pair now moves together. Doc-guard's
three-warning backlog is cleared with real backfill for M4/M6/M12.

Verified: fmt clean; clippy 5 crates 0 new warnings (74 vs 74 baseline,
counted in a detached worktree at HEAD); lib 2110 passed; cluster_sharding 5;
cluster_runbook 10; tidalctl 38; doc-guard 0 warnings. Playwright 32/34 with
the two remaining failures asserting the rank fix against the not-yet-rolled
image — they are the post-deploy proof.
2026-08-30 20:55:58 -06:00

319 lines
19 KiB
Markdown
Raw Permalink Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

# tidalDB On-Call & Incident Response
First page to open during a tidalDB incident. Routes a symptom → the golden signal
that confirms it → the runbook that fixes it. For the operational API see
[`cluster.md`](cluster.md); for k8s mechanics [`kubernetes.md`](kubernetes.md); for
backup/restore [`disaster-recovery.md`](disaster-recovery.md).
**Ownership:** the tidalDB maintainers (source: `git.threesix.ai/jordan/tidaldb`).
The live cluster runs in `orchard9-k3sf` (ns `tidaldb-cluster`); deployment history
is `orchard9-k3sf/deployments/history/tidaldb.md`; live state is
`orchard9-k3sf/cluster-state.yaml`.
---
> ## ✅ RESOLVED — the narrowed client-Service selector is NO LONGER in force
>
> **Between 2026-08-21 and 2026-08-21T20:10Z** the client Service `tidaldb`
> carried an extra `tidaldb.orchard9.ai/serving: "true"` selector label that held
> `tidaldb-0` out of the read path, because it served a shard-1 frontier
> cross-seeded from shard 2's snapshot (`incident_2026_08_20_reseed_livelock` in
> `orchard9-k3sf/cluster-state.yaml`). **That intervention was reverted and this
> section is history, not instruction.** It is kept because the footgun below is
> worth knowing if anyone ever re-narrows the selector.
>
> Verified 2026-08-31, three ways:
>
> ```bash
> kubectl -n tidaldb-cluster get svc tidaldb -o jsonpath='{.spec.selector}'
> # => {"app.kubernetes.io/component":"cluster-node","app.kubernetes.io/name":"tidaldb"}
> # the plain manifest selector; no serving label
> kubectl -n tidaldb-cluster get endpoints tidaldb \
> -o jsonpath='{range .subsets[*].addresses[*]}{.targetRef.name}{"\n"}{end}'
> # => tidaldb-0, tidaldb-1, tidaldb-2 — all three serving
> kubectl -n tidaldb-cluster get pods -l app.kubernetes.io/name=tidaldb \
> -o custom-columns=NAME:.metadata.name,SERVING:'.metadata.labels.tidaldb\.orchard9\.ai/serving'
> # => <none> on all three
> ```
>
> `cluster-state.yaml` records the same: *"RESOLVED 2026-08-21T20:10Z (verified,
> not inferred) … Client Service selector reverted to the manifest's original."*
>
> **If you ever re-apply that narrowing, the footgun is that the label goes on the
> PODS, not the StatefulSet template** (templating it triggers a rolling update,
> which with two healthy voters loses quorum). Pod labels do not survive pod
> recreation, so a recreated pod silently drops out of the client Service, and if
> every labelled pod is recreated the Service has ZERO endpoints and all reads
> fail. Symptom and repair:
>
> ```bash
> kubectl -n tidaldb-cluster get endpoints tidaldb # empty subsets?
> kubectl -n tidaldb-cluster label pod tidaldb-1 tidaldb-2 \
> tidaldb.orchard9.ai/serving=true --overwrite
> ```
>
> Do not re-narrow on a frontier number alone — a matching `lag_events: 0` is
> exactly what misled the original diagnosis. Require per-shard `applied_events`
> matching each shard's leader AND a real query agreeing with a healthy peer.
---
## 0. First 60 seconds — orient
```bash
export KUBECONFIG=~/.kube/orchard9-k3sf.yaml
kubectl get pods -n tidaldb-cluster -l app.kubernetes.io/name=tidaldb -o wide # 3/3 Ready? restarts?
# health + leader (HTTPS + mTLS plane), via port-forward:
kubectl port-forward -n tidaldb-cluster tidaldb-0 19500:9500 >/dev/null 2>&1 &
curl -fsSk https://127.0.0.1:19500/health # ok:true + agreed leader across pods
curl -fsSk https://127.0.0.1:19500/cluster/status # per-shard leaders, commit index, quarantine, reseed
```
Golden signals (Grafana "tidalDB Overview" → Cluster Replication row, or `/metrics`):
| Signal | Metric | Healthy |
|---|---|---|
| Per-peer circuit breaker | `tidaldb_cluster_peer_breaker_state` | 0 (closed). **1 (open) on a live peer = the write-burst/partition pattern.** |
| Commit progress / quorum lag | `relay_durable_seq` vs `relay_last_seq` | lag bounded, advancing under load |
| Reseed pending | `reseed_required` | 0 |
| Election churn | `leader_changes_total`, `election_term` | flat |
| Quorum timeouts | `quorum_timeouts_total` | flat (a rising rate = writes can't reach quorum) |
| Divergence | `divergence_quarantined` | 0 |
---
## 1. Severity
| SEV | Definition | Examples |
|---|---|---|
| **SEV1** | Writes unavailable or acked data at risk | quorum lost (≥2 voters down or both breakers stuck open), divergent prefix served, total cluster loss |
| **SEV2** | Degraded but serving | one voter down (still 2/3 quorum), read p99 > 10 ms sustained, a pod CrashLooping, write-burst 503s on an old image |
| **SEV3** | No user impact yet | single transient reseed, elevated election term, one breaker briefly open then clears, soak night failed |
---
## 2. Symptom → signal → runbook
| Symptom | Confirm with | Action |
|---|---|---|
| **Pod CrashLooping** ("reseed marker latched") | `kubectl logs`, `reseed_required` | Reseed-loop is resolved on the live image (rc5+); a genuine reseed snapshot-installs and converges lag=0. If looping on an OLD image → roll to the live digest. [`cluster.md` reseed] |
| **Writes 503 / quorum lost** | `/cluster/status` (voters down?), `quorum_timeouts_total` rising | One voter down is survivable (2/3). Both followers down → honest retryable 503 until one returns. Restart/replace the down voter; check node health. [`cluster.md` §9] |
| **Write-burst 503-storm, no self-heal; both breakers stuck at 1 while peers alive** | `tidaldb_cluster_peer_breaker_state == 1` on live (heartbeating) followers | Fixed in **rc7** (write-burst false-partition). If on an older image, **roll to ≥ rc7**. Confirm the gauge clears as load eases. [`cluster.md` §9.1] |
| **Stuck leader / dual-leader view** (leader sees peers partitioned, reads 408) | `/cluster/status` disagrees across pods | Restart the leader pod to force re-election; auto-election converges. [`cluster.md` §9] |
| **Divergence / node serving a stale prefix** | `divergence_quarantined > 0` | The node auto-quarantines (503 readiness) and reseeds without wiping — it never serves a divergent prefix. Let it reseed; verify it rejoins lag=0. [`cluster.md` §9.1] |
| **Read p99 > 10 ms, reads hang** | Grafana read-latency; check load spread | Read-SLA collapse was CPU oversubscription, fixed in rc12 (SEARCH_GATE + parallel scatter + cpu limit 3). Ensure reads are spread round-robin across all 3 pods; check the ~1000-rps read ceiling isn't exceeded. [`capacity-planning.md`] |
| **OOMKilled** | pod `lastState.terminated.reason=OOMKilled` | 1536-D full placement peaks ~1.9 GiB at 100k; **1M needs > 16 GiB nodes** (≈78 GB/pod). Do not raise the limit past node headroom — it's a node-size limit. [`capacity-planning.md`] |
| **One pod's PVC lost/corrupt** | pod won't open its data dir | Delete that pod's PVC + pod → it reseeds fresh from the live quorum (snapshot install), converges lag=0. Do NOT object-store-restore for a single-pod loss. [`ops/recovery.md`] |
| **Total cluster loss** | — | Rebuild fresh + `tidalctl restore` each shard before boot. [`disaster-recovery.md`] |
| **Soak night failed** | `kubectl get jobs -n tidaldb-cluster -l app.kubernetes.io/name=tidal-soak` | A FAIL resets the 30-night streak. Read the night's log for the SLO breach (p99 > 150 ms or error > 1%) or an under-load restart. [`cluster.md` §15] |
| **401 rate spike / "is someone attacking us?"** | `tidaldb_http_requests_total{status="401"}` for the RATE; the `rejected request` WARN for the REASON | Most 401s here are unauthenticated scanning of a public ingress and are working as designed. Do not page on volume — page on `reason=invalid_token`. Full triage: §2.1 below. |
### 2.1 Auth rejections (401) — triage
**Do not page on 401 volume.** As measured 2026-08-31T02:28Z, **87.5%** of all
traffic reaching the public ingress is a 401 (281,093 of 321,342 requests over
~14 days), and it has been that way continuously. Volume is the background rate
of an internet-facing endpoint being scanned. What is worth waking someone for is
a *change in kind*, and only the server-side WARN can tell you which kind.
#### Two counters, two different questions — never compare them
| Counter | What it measures | Use it for |
|---|---|---|
| `traefik_service_requests_total{service="tidaldb-cluster-tidaldb-9500@kubernetes",code="401"}` | Cumulative since **each Traefik pod** started (both started 2026-08-16T22:26Z) | **History.** Is this normal for this endpoint? |
| `tidaldb_http_requests_total{status="401"}` | Cumulative since **each tidalDB pod** started (current pods: 2026-08-30T20:0020:03Z) | **Live rate.** Is it changing right now? |
**The trap:** these two have different epochs and different denominators. A
change that appears to "cut 401s from 281,000 to 3,600" cut nothing — it
restarted the pods. Any claim that a restriction worked must compare a *rate*
before and after, from the same counter, across a pod lifetime that did not
reset in between.
**Two more traps in the history number itself.** There are **two** Traefik pods
and each keeps its own counters, so a single-pod scrape undercounts — reading
only `cxz7f` gives 101,901 where the fleet total is 281,093, a 64% undercount.
And the metric is `traefik_service_requests_total`, **not**
`traefik_router_requests_total`: router labels are disabled on this build and
that metric does not exist here.
```bash
export KUBECONFIG=~/.kube/orchard9-k3sf.yaml
# HISTORY — sum across BOTH traefik pods
for p in $(kubectl -n kube-system get pods -l app.kubernetes.io/name=traefik -o name); do
IP=$(kubectl -n kube-system get "$p" -o jsonpath='{.status.podIP}')
echo "== $p"
kubectl -n observability exec deploy/vmagent -- sh -c \
"wget -qO- --timeout=20 http://$IP:9100/metrics | grep '^traefik_service_requests_total' | grep tidaldb"
done
# LIVE RATE — sample the same counter twice and difference it
sample() {
for p in tidaldb-0 tidaldb-1 tidaldb-2; do
IP=$(kubectl -n tidaldb-cluster get pod "$p" -o jsonpath='{.status.podIP}')
N=$(kubectl -n observability exec deploy/vmagent -- sh -c \
"wget -qO- --timeout=20 http://$IP:9091/metrics | awk '/^tidaldb_http_requests_total.*status=\"401\"/{s+=\$2} END{print s+0}'")
echo -n "$p=$N "
done; echo
}
sample; sleep 90; sample
```
Reference reading, 2026-08-31T02:3102:32Z (94s): `3640→3657`, `3664→3675`,
`3144→3161`**+45 fleet-wide, 28.7/min, ~9.6/min per pod.** That is the
baseline. Triage a departure from it, not the number itself.
#### The reason field is the whole diagnosis
`unauthorized_response()` in `tidal-server/src/router.rs` is the single funnel for
every 401 on every surface, and it emits one WARN per rejection carrying `reason`
and `client` (the token itself is never logged, in either form). Correlate to the
request via `request_id` on the surrounding span.
| `reason` | `client` | What it means | Page? |
|---|---|---|---|
| `invalid_token` | one consistent value, steady rate | **A credential that STOPPED working.** A real client just lost access and is failing right now — almost always a key rotation that missed a consumer. | **YES.** Check the last rotation of `tidaldb-credentials` and find the consumer still holding the old key. |
| `invalid_token` | many/varied values, bursty | A scanner spraying guessed bearers. Read the caveat below before paging. | No — but confirm it is varied, not one client. |
| `missing_token` | an external address | Unauthenticated scanning of a public ingress. Expected, correctly rejected, nothing leaked. This is the 87.5% baseline. | **NO.** Never page on this. |
| `missing_token` | `-` (absent) | **Most likely one of our workloads deployed without its key** — an absent XFF should mean the request never traversed Traefik, i.e. an in-cluster caller. Confirm that reading with the calibration below before relying on it. Not urgent, but the workload is broken until fixed. | No — file it, find the workload, give it `TIDAL_API_KEY`. |
**Read `invalid_token` precisely.** The implementation
(`unauthorized_response()`, `tidal-server/src/router.rs`) sets it whenever an
`Authorization` header is **present and did not validate** — it does not, and
cannot, know whether the token was ever valid. So a scanner sending
`Authorization: Bearer admin` lands in the page-worthy bucket alongside a genuine
rotation miss. The discriminator is `client` and the shape of the rate: a
rotation miss is a *steady* rate from *one* client that starts at a rotation; a
scanner is bursty and varied. Check both before waking anyone.
**`client="-"` should be a signal, not a gap — confirm it in the same calibration
run.** The field is `x-forwarded-for` with a `-` default. Traefik sets XFF on
what it proxies, so an absent value should mean the request **did not come
through the ingress** — it reached the pod or the ClusterIP Service directly,
which on this cluster means an in-cluster caller. That is the cleanest
internal/external split available and, unlike the address itself, it does not
depend on SNAT fidelity. The three-request test below proves it in passing: if
those known-external requests come back with a non-`-` `client`, XFF-on-proxied
holds and `-` can be read as "in-cluster". This has not been observed yet — the
WARN is not deployed — so do not lean on it until it has.
A sudden move from a steady `missing_token` baseline to `invalid_token` is the
shape that matters. Volume alone is noise; `reason` is signal.
```bash
# now: plain text on stdout
kubectl -n tidaldb-cluster logs tidaldb-0 -c tidaldb --since=15m | grep 'rejected request'
# after the JSON_LOGS roll (deploy-verification.md §9.3), ask the store instead:
kubectl -n observability exec deploy/vmagent -- sh -c \
'wget -qO- --timeout=25 \
--post-data="query=_time:15m AND unit:tidaldb-cluster AND _msg:rejected AND _msg:request | stats by (reason, client) count() n" \
http://victoria-logs:9428/select/logsql/query'
```
> **Two things that will bite you here, both already paid for.**
>
> The message field in LogsQL is **`_msg`**, not `msg` — Vector's sink declares
> `_msg_field: msg`, so VictoriaLogs renames it on ingest. `msg:rejected` returns
> nothing forever and looks exactly like "no rejections". Verified 2026-08-31: the
> identical query shape with a phrase that *does* exist today
> (`_msg:compaction AND _msg:complete`) returns `{"n":"226"}`, while `msg:` in the
> same position returns empty.
>
> Word filters, not a quoted phrase. `--post-data="query=…"` is already inside a
> double-quoted shell string; a `"rejected request"` inside it terminates the
> quoting and `wget` fails with `bad address 'request | stats…'`. Two `_msg:`
> word filters ANDed need no quotes and cannot break.
> **Not yet runnable.** The WARN ships with the next image, so the two commands
> above are the only ones in §2.1 not yet executed against real data. The LogsQL
> one runs clean today and returns **nothing** — `stats by (...)` emits no rows
> when nothing matches, unlike `stats count() n` which returns `{"n":"0"}`. Its
> *form* is verified; only the content is pending. Everything else in §2.1 was
> run against the live cluster.
#### Before trusting `client`, calibrate it
`client` carries `x-forwarded-for`, because behind Traefik the socket peer is the
ingress, not the caller. Its *presence* is the part expected to be reliable (see
above); its **value**
is not yet verified on this cluster, and the "an external address" row above
depends on it. Two measured facts say to check rather than assume: the Traefik
LoadBalancer Service is `externalTrafficPolicy: Cluster` (so the external source
IP is SNATed before Traefik ever sees it), and Traefik access logging is off
(no `--accesslog` argument), so there is no second opinion to compare against.
Calibrate with a request whose origin you know — this exact procedure was run on
2026-08-31 and the counter deltas below are its real output:
```bash
# 3 unauthenticated GETs from outside the cluster
for i in 1 2 3; do
curl -s -o /dev/null -w "http=%{http_code} remote=%{remote_ip}\n" \
--max-time 15 "https://tidaldb.threesix.ai/search?query=probe"
done
# -> http=401 remote=208.122.204.173
# http=401 remote=208.122.204.174
# http=401 remote=208.122.204.173
# /search 401 counters moved 532/526/451 -> 533/527/453: +1 +1 +2 == the 3 requests
```
Then read the `client` value those three requests produced. If it is the address
you sent from, the table above works as written. If it is a node IP
(`208.122.204.172/173/174`) or an svclb pod IP (`10.42.0.13`, `10.42.1.182`,
`10.42.2.58`), then XFF is carrying the SNAT hop: external callers are no longer
distinguishable *from each other*, and a scanner will look like it came from your
own infrastructure. The `client="-"` split still holds in that case — an absent
XFF still means "never traversed Traefik" — but you lose the ability to
attribute an external caller. Fix it (Traefik trusted-IP config, or
`externalTrafficPolicy: Local`) before using the address itself to route
anything.
#### Corrected: the "all 401s land on tidaldb-0" claim
Earlier notes recorded 3,535 401s "all on `tidaldb-0`" and flagged it as an
unexplained asymmetry possibly caused by Traefik pinning an endpoint. **Measured
2026-08-31, that asymmetry does not exist** — the earlier figure was one pod's
counter read in isolation and generalized. All three pods take the load, at
within-noise-equal rates:
- Steady state: `tidaldb-0=3640 tidaldb-1=3664 tidaldb-2=3144`, all three climbing
(+17 / +11 / +17 over 94s).
- Controlled test: 3 external requests produced deltas of **+1 / +1 / +2** across
the three pods.
- The Service has all three as endpoints and no pod carries a restricting label
(see the RESOLVED banner at the top of this file).
There is nothing to investigate here. Do not spend an incident chasing it.
---
## 3. Alerting status (action required)
The alert rules in [`../ops/prometheus-alerts.yaml`](../ops/prometheus-alerts.yaml)
are **accurate but DESIGN-REFERENCE — they are not yet loaded by the live
Prometheus.** The rules already cover the must-watch signals
(`TidalDBClusterBreakerOpen` on `peer_breaker_state == 1`,
`TidalDBClusterCommitIndexStall`, `TidalDBClusterElectionChurn`,
`TidalDBClusterQuorumTimeouts`, `TidalDBClusterDivergenceQuarantine`,
`TidalDBClusterReseedPending`).
**Open infra step:** promote them into the observability stack as a `PrometheusRule`
(or vmalert rule file) so they actually page. Until then, on-call watches the
Grafana Cluster Replication row manually. This is the one item that is an
observability *deployment*, not a doc fix — track it in `orchard9-k3sf`.
---
## 4. Escalation
1. Page the on-call operator → run §0, classify per §1.
2. SEV1 (acked data at risk / writes down): stop further rollouts, capture
`/cluster/status` + breaker gauge + `kubectl logs` from all 3 pods, then engage
the tidalDB maintainers. Do **not** delete PVCs or force-promote under a
divergence/quorum-loss condition without confirming the data-safety path in
[`cluster.md`](cluster.md) — the system is designed to quarantine rather than
serve bad data; let it.
3. Record the incident + resolution in
`orchard9-k3sf/deployments/history/tidaldb.md` (newest first).