tidaldb/docs/ops/observability.md

# Observability: usage, errors, and live debugging

Four surfaces, in the order you reach for them during an incident.

| Question | Surface |
|---|---|
| How much traffic, and how much of it is failing? | Grafana → **tidalDB — usage, errors, and cluster health** |
| What exactly failed, for which request? | VictoriaLogs, `level:error`, correlate on `request_id` — **only after the `JSON_LOGS` roll; see §2** |
| Is the cluster converged right now? | `tidalctl cluster-status` / `tidalctl watch` |
| What does a query actually return? | `tidalctl search` / `tidalctl feed` |

---

## 1. Metrics

Every node serves Prometheus text on its `--metrics` address (`:9091` in the
shipped manifests). **Never expose that port externally — it is
unauthenticated.** In-cluster it is reachable only from the `observability`
namespace (`k8s/cluster/networkpolicy.yaml`).

Two families answer the usage/error questions:

```
tidaldb_http_requests_total{route,method,status}   counter
tidaldb_http_request_duration_us{route}            histogram
```

`route` is the matched route **template** (`/cluster/shards/{id}/transfer`), not
the concrete path, so cardinality is bounded by the router rather than by
traffic. Unmatched requests collapse into a single `<unmatched>` bucket — a 404
flood cannot mint series.

These are published by `tidal-server` onto the engine's existing listener (via
`MetricsState::set_extra_renderer`), so a node remains **one** scrape target.

Useful queries:

```promql
# request rate by route
sum by (route) (rate(tidaldb_http_requests_total[5m]))

# server-fault ratio
  sum(rate(tidaldb_http_requests_total{status=~"5.."}[5m]))
/ sum(rate(tidaldb_http_requests_total[5m]))

# who is being refused, and where
sum by (status, route) (rate(tidaldb_http_requests_total{status=~"401|403"}[5m]))

# client-observed p99, in ms
histogram_quantile(0.99,
  sum by (route, le) (rate(tidaldb_http_request_duration_us_bucket[5m]))) / 1000
```

Read `403` precisely: it means a valid **data** bearer was used against an
operator verb (`/cluster/*`). A sustained 403 rate is a client holding the wrong
key, or someone probing — not a server fault.

### Dashboard

`docs/ops/grafana-tidaldb.json` is the source of truth, mirrored into the fleet
as the `tidaldb-overview.json` key of the `grafana-database-dashboards`
ConfigMap — the same convention `docs/ops/prometheus-alerts.yaml` follows. Edit
here, then mirror. It lands in Grafana's **Databases** folder as
`tidaldb-overview`.

---

## 2. Logs

Set `JSON_LOGS=1` (or `TIDAL_LOG_FORMAT=json`) to emit one JSON object per line
in the collector's wire format:

```json
{"ts":"2026-08-23T15:57:57.090256Z","level":"info","service":"tidal-server",
 "env":"prod","msg":"committing 5","target":"tantivy::indexer","request_id":"418"}
```

Why it matters: the fleet's Vector collector parses each line as JSON and, on
success, replaces the event with that object; on failure it keeps the text and
stamps `level = "info"`. Without JSON, **every** tidalDB line was recorded as
info and `level:error` matched nothing — errors were collected but invisible.

- `level` is lowercase, matching the collector's enum
  (`critical|error|warn|info|debug`).
- `request_id` from the per-request span appears on every line emitted inside it,
  so one request's work is correlatable rather than grep-adjacent.
- `target` is the real module even for dependencies logging through the `log`
  crate (their bridge metadata is pruned rather than indexed forever).
- ANSI colour is off in **both** formats. It used to leak escape codes into
  stored logs.

Tunables: `TIDAL_SERVER_LOG` (env-filter, e.g.
`tidal_server=debug,tantivy=warn,info` to quiet a noisy dependency),
`TIDAL_SERVICE_NAME`, `TIDAL_ENV`.

`TIDAL_SERVICE_NAME` is not cosmetic here. `service` is one of the collector's
four `_stream_fields`, so its value is index identity. Plain-text lines carry no
`service` and Vector substitutes the container name, `tidaldb`; the JSON emitter
sets its own, defaulting to `tidal-server`. The cluster StatefulSet therefore
pins `TIDAL_SERVICE_NAME=tidaldb` so the stream does not rename itself the moment
the format changes. `TIDAL_ENV` is unset in the cluster, so `env` is absent from
its lines rather than guessed — do not filter on it.

### Querying the log store

Two things silently break a LogsQL query against tidalDB, and both fail as an
empty result — which reads exactly like a healthy cluster.

**1. The namespace field is `unit`, not `kubernetes.pod_namespace`.** Vector's
`normalize` transform does `del(.kubernetes)` and writes the namespace to `unit`
(and the node to `host`, the pod and container to `k8s_pod` / `k8s_container`).
A query keyed on the Kubernetes field matches nothing, forever. This document
shipped that broken selector; measured against the live store on
2026-08-31T02:24Z, same 15-minute window, same cluster:

```
_time:15m AND kubernetes.pod_namespace:tidaldb-cluster | stats count() n
  -> {"n":"0"}        # the selector is wrong, not the cluster

_time:15m AND unit:tidaldb-cluster | stats count() n
  -> {"n":"248"}      # same window, correct field
```

**So always run the unfiltered count first.** Zero total lines means a broken
selector. Only once that number is non-zero does a zero *error* count mean
anything.

**2. `level`, `request_id`, `target` and every other structured field exist only
once `JSON_LOGS` is on.** Until the pods restart with it, Vector cannot parse the
line, keeps the text as `msg`, and stamps `level = "info"` — so `level:error`
matches nothing no matter how healthy or unhealthy the cluster is, and every WARN
is filed as info. Pre-roll reading, same window:

```
_time:15m AND unit:tidaldb-cluster | stats by (level) count() n
  -> {"level":"info","n":"248"}     # ONE bucket: nothing is being classified

_time:15m AND unit:tidaldb-cluster AND level:error | stats count() n
  -> {"n":"0"}                      # meaningless pre-roll, not reassuring

_time:1h AND unit:tidaldb-cluster AND request_id:* | stats count() n
  -> {"n":"0"}                      # the field does not exist yet
```

(The counts move — `_time:15m` is a sliding window, and two runs a minute apart
returned 247 and 248. The load-bearing observation is the *number of buckets*,
not the number of lines: one bucket means the classifier never ran.)

The store itself is fine — `level:error` already works for services that emit
JSON: `_time:15m AND level:error | stats by (service) count() n` returns
`{"service":"relay","n":"189"}`, `{"service":"external-secrets","n":"2"}`.
tidalDB was simply not speaking the format. Deploy status is tracked in
`docs/runbooks/deploy-verification.md` §9.3.

**Post-roll, these are the queries.** Each pairs with its own discriminator so a
zero is readable:

```
# is anything arriving at all?  (run this first, every time)
_time:15m AND unit:tidaldb-cluster | stats count() n

# how is it being classified?  more than one bucket == JSON_LOGS is live
_time:15m AND unit:tidaldb-cluster | stats by (level) count() n

# errors, last 15 minutes
_time:15m AND unit:tidaldb-cluster AND level:error

# one request end to end
_time:1h AND unit:tidaldb-cluster AND request_id:418

# one pod
_time:15m AND unit:tidaldb-cluster AND k8s_pod:tidaldb-0 AND level:error

# search the message text — the field is _msg, NOT msg (see below)
_time:15m AND unit:tidaldb-cluster AND _msg:rejected AND _msg:request
```

Run them with:

```bash
kubectl -n observability exec deploy/vmagent -- sh -c \
  'wget -qO- --timeout=25 --post-data="query=<QUERY>" \
   http://victoria-logs:9428/select/logsql/query'
```

**The message field is `_msg`, not `msg`.** Vector's sink declares
`_msg_field: msg`, so VictoriaLogs renames it on ingest. `msg:rejected` parses
fine and matches nothing, forever — the same silent-zero failure as the namespace
field above. Verified 2026-08-31: `_msg:compaction` returns `{"n":"229"}` while
`msg:compaction` in the same position returns empty.

**Keep double quotes out of the query.** The runner above already wraps the query
in a double-quoted `--post-data="query=…"`, so a quoted phrase like
`_msg:"rejected request"` terminates the shell quoting and `wget` dies with
`bad address 'request | stats…'`. Bare tokens (`request_id:418`) and ANDed word
filters (`_msg:rejected AND _msg:request`) need no quotes and cannot break.

---

## 3. Live debugging with `tidalctl`

Every other `tidalctl` command reads a data directory **at rest** — some require
a stopped node. These take `--url` and talk to a **running** server.

```bash
export TIDAL_API_KEY=...          # or pass --key

# Is it converged? Exits 2 when not, so it gates a deploy.
tidalctl cluster-status --url http://127.0.0.1:9500

# Watch convergence (Ctrl-C to stop, or bound it with --count)
tidalctl watch --url http://127.0.0.1:9500 --interval 5 --count 12

# What does a query actually return?
tidalctl search --url http://127.0.0.1:9500 --query "cold brew" --limit 5
tidalctl feed   --url http://127.0.0.1:9500 --profile trending --user-id 42
```

**TLS.** A cluster node's client port is served with the *internal* cluster CA,
issued for in-cluster DNS names, so a port-forward fails both CA and hostname
verification. Pin the CA with `--ca ca.pem`, or use `--insecure` for a local
forward:

```bash
kubectl -n tidaldb-cluster port-forward svc/tidaldb 9500:9500 &
tidalctl cluster-status --url https://127.0.0.1:9500 --insecure
```

Exit codes follow the crate contract: `0` ok, `1` usage error, `2` degraded —
unreachable, non-2xx, or not converged. A `403` response prints the hint to use
the admin key.

---

## 4. Known caveat: the aggregated `/cluster/status` under-reports peers

The aggregated view can report a peer it holds no frontier report for as
`applied_events: 0`, and derive `lag_events` against that zero — so a fully
converged peer appears to be the leader's entire history behind, sometimes with
`reachable: false` / `partitioned: true` alongside.

Observed 2026-08-23: two healthy nodes shown as `UNREACHABLE PARTITIONED` at
13.3M lag, while every node's own `/cluster/status/local` reported `lag=0`,
`reseed_required=false`, and identical per-group frontiers. Pod-to-pod
connectivity was open and no error was logged.

`tidalctl cluster-status` detects that signature (`applied == 0` with non-zero
lag) and prints **`NO REPORT (aggregated view; query the node directly)`**
rather than repeating it as replication lag. A genuine lag report — non-zero
applied with non-zero lag — still reports `BEHIND`.

**When you see `NO REPORT`, confirm against the nodes themselves** before
treating it as an incident:

```bash
for i in 0 1 2; do
  kubectl -n tidaldb-cluster port-forward tidaldb-$i 1970$i:9500 >/dev/null 2>&1 &
  sleep 8
  curl -sk -H "Authorization: Bearer $TIDAL_API_KEY" \
    "https://127.0.0.1:1970$i/cluster/status/local" | jq '{region, reseed_required, shards}'
  kill %1
done
```

The underlying reporting gap in the aggregated surface is open work; it is a
reporting defect, not a replication one.