feat(monitoring): name the CAUSE of node I/O pressure, not just the stall

NodeIOPressureCritical has now fired twice on k3s-prod-1 for opposite causes and
said the same thing both times. On 2026-09-14 02:40-02:45Z it fired at PSI(full)
20.98% — twice the threshold, four times the 2026-09-07 level — while every local
device was idle (0.09-0.27 utilisation) and fast (1.4-4.8 ms per write), NFS
retransmissions were zero and no Longhorn volume was degraded. Establishing that
took eight ad-hoc PromQL queries after the event had already recovered.

Adds the group platform-health.node-io-cause: eight rules, one per cause class,
each naming its cause in its own summary.

  NodeDiskDeviceSaturated        device saturation   >0.85 busy, 10m
  NodeDiskWriteLatencyHigh       device latency      >20ms/write, 10m
  NodeDiskWriteLatencyCritical   device latency      >50ms/write, 5m
  NodeDiskReadLatencyHigh        device latency      >250ms/read, 15m
  NodeNFSRetransmissionRateHigh  NFS transport       >1% retransmitted, 10m
  NodeIOPressureNotLocalDisk     not local disk      PSI>10% with all of the above absent
  NodeEtcdRequestsSlow           etcd                >0.5% of etcd requests over 1s
  ContainerIOStallHigh           which workload      per-container PSI >15%

Every threshold is measured on prod over 24-48h, not guessed, and each rule
records its headroom. The PSI thresholds themselves are deliberately unchanged:
the 21% stall was real, it fired twice in 24h for two real events on the one node
that has a problem, and raising the bar would also have raised it above the 11.36%
at which prod-1 was already losing etcd on 2026-09-07.

Context reaches the operator at page time three ways: the summary states the cause
class; every rule carries a diagnostic_query annotation with the exact companion
PromQL; and node-pressure-dashboard.yaml gains a WHY row (seven panels) plotting
saturation, write/read service time, NFS retransmissions, our own NFS op rate,
the etcd slow-request fraction and per-container PSI side by side. runbooks/node-io.md
gains a 10-row triage table with the real healthy / 2026-09-14 / 2026-09-07 columns,
which turns those eight queries into a two-minute read.

etcd and NFS metric availability, verified on prod rather than assumed:
  * etcd SERVER disk metrics do NOT exist. etcd_disk_wal_fsync_duration_seconds and
    etcd_disk_backend_commit_duration_seconds are absent (kubeEtcd disabled for k3s);
    a query for etcd_disk_*/etcd_server_*/etcd_mvcc_* returns nothing at all.
    NodeEtcdRequestsSlow uses the apiserver's client-side view of its own local
    member instead, and says in its own description that it is a proxy.
  * node_nfs_* DOES exist — the nfs collector is on by default, host-wide via
    /proc/net/rpc/nfs, confirmed on all three nodes. It gives op counts and
    retransmissions and NO latency, so it can see a dropping export but not a slow
    one. The mountstats collector is enabled here to close that gap; NO rule
    references node_mountstats_* yet, because the series do not exist until the
    HelmRelease rolls out and the collector's visibility through the node-exporter
    mount namespace must be verified on prod first. The runbook records the check
    and says to revert if it comes back empty.

Proof, per the repo's two shipped alerting failure modes:
  * platform/monitoring/tests/node-io-cause.test.yaml — 7 fixtures, all from
    measured profiles: healthy (all 8 quiet), 2026-09-14 (NotLocalDisk fires and
    names sonarr), 2026-09-07 re-queried at offset 164h (write-latency and etcd
    fire, NotLocalDisk correctly silent), rebuild storm, NFS transport, read
    latency, and the `unless` semantics.
  * 10 mutations of the shipped rules, all killed. The mutation run found a real
    gap: the etcd threshold could be changed without failing any test, because it
    was only pinned by a promql_expr_test that restated the threshold in the test
    file. An alert_rule_test now pins it.
  * All 11 referenced metrics verified to return series on prod with
    `promtool query instant`, and all 8 expressions verified quiet on today's state.

Also extends the alert-metrics-have-scrape-targets owner table for container_*
(the kubelet ServiceMonitor's cAdvisor path, which this entry already claimed in
its title) and for etcd_request_duration_seconds_* by EXACT NAME, deliberately not
by an etcd_ prefix, so a future rule on the unscraped etcd_disk_* names still fails
the gate.

Co-Authored-By: Claude Opus 5 <[email protected]>
This commit is contained in:
jakman85andClaude Opus 5 committed 2026-09-13 22:35:19 -05:00
1 parent dafa9cd241
commit b9f3143f42
6 files changed
+1278 -7

No files matched your search

+138 -4
View File
@@ -1,9 +1,100 @@
# node-io — Disk I/O pressure / starvation on a node
**Alerts:** `NodeIOPressureHigh` (warning, 10m) and `NodeIOPressureCritical` (critical, 5m)
**Detection alerts:** `NodeIOPressureHigh` (warning, 10m) and `NodeIOPressureCritical` (critical, 5m)
**File:** `platform/monitoring/alerts.yaml`, group `platform-health.nodes`
**Expression:** `rate(node_pressure_io_stalled_seconds_total[5m]) > 0.05` (warning) / `> 0.10` (critical)
**Cause-attribution alerts** (added 2026-09-14, group `platform-health.node-io-cause` in the same
file — these say WHY, and each names its cause in its own `summary`):
`NodeDiskDeviceSaturated`, `NodeDiskWriteLatencyHigh`, `NodeDiskWriteLatencyCritical`,
`NodeDiskReadLatencyHigh`, `NodeNFSRetransmissionRateHigh`, `NodeIOPressureNotLocalDisk`,
`NodeEtcdRequestsSlow`, `ContainerIOStallHigh`.
**Dashboard:** `node-pressure`, the *WHY* row — `https://grafana.<BASE_DOMAIN>/d/node-pressure`
## START HERE — 2-minute triage: which column are you in?
**This section exists because the page used to carry no context at all.** On 2026-09-14
`NodeIOPressureCritical` fired on `k3s-prod-1` with I/O PSI at **20.98%** — twice the threshold and
four times the 2026-09-07 level — and establishing that it was *not* a failing drive took **eight
ad-hoc PromQL queries**, by which time the event had recovered unattended. The queries are below, in
order, with the numbers they returned on a healthy cluster, during that event, and during the
2026-09-07 outage. Read down one column and you have the cause class in about two minutes.
Since 2026-09-14 the alerts in `platform-health.node-io-cause` compute this table for you and put
the verdict in the page's own `summary` (`CAUSE device saturation` / `CAUSE device latency` /
`CAUSE NFS transport` / `CAUSE not local disk` / `CAUSE etcd` / `WHO is stalled`), every rule
carries a `diagnostic_query` annotation with the exact PromQL below, and the Grafana dashboard
`node-pressure` has a **WHY** row that plots all six side by side —
`https://grafana.<BASE_DOMAIN>/d/node-pressure`. Use this table when you want to check the alert's
reasoning, or when the answer is "none of the above".
| # | Question / query | HEALTHY (measured 2026-09-14, 24-48h) | 2026-09-14 02:40Z — NFS/unexplained | 2026-09-07 06:05Z — FAILING DRIVE |
|---|---|---|---|---|
| 1 | **Is the node actually stalled?** `max by (instance) (rate(node_pressure_io_stalled_seconds_total[5m]))` | 0.006-0.014; 0 min above 5% on prod-2 | **0.2098** on prod-1; prod-2/3 under 0.015 | **0.7397** on prod-1; prod-2 0.103, prod-3 0.189 |
| 2 | **Is any device saturated?** `topk(5, rate(node_disk_io_time_seconds_total[5m]))` | 48h max 0.610 / 0.217 / 0.295 | **0.27** (sdi 0.21, sda 0.09) — NOT saturated | 0.745 sda, 0.788 sdb prod-1; 0.858 prod-2 sdb |
| 3 | **Is any device slow per write?** `rate(node_disk_write_time_seconds_total[5m]) / rate(node_disk_writes_completed_total[5m]) and rate(node_disk_writes_completed_total[5m]) > 10` | 48h max **3.1 ms** cluster-wide | **1.6 ms** — healthy | **1,039 ms** on prod-1 sda. Nodes 2/3: 4.3 ms, 1.1 ms |
| 4 | **Is any device slow per read?** same with `read_time` / `reads_completed` | 156 ms on prod-1 sdg (a media HDD, normal); SSDs 1.6-6.3 ms | 156 ms — unchanged | n/a (writes were the story) |
| 5 | **Is NFS retransmitting?** `sum by (instance) (rate(node_nfs_rpc_retransmissions_total[5m])) / sum by (instance) (rate(node_nfs_rpcs_total[5m]))` | **exactly 0** on all three nodes over 48h | **0** — the transport was fine | 0 |
| 6 | **Is it OUR NFS traffic?** `sum by (instance, method) (rate(node_nfs_requests_total{method=~"Read|Write"}[5m]))` | prod-1 0-95 reads/s; prod-2/3 ~0 | **114 reads/s on prod-1**, 0 elsewhere | 10 RPC/s — not the story |
| 7 | **Is the etcd path stalling?** `1 - (sum by (instance) (rate(etcd_request_duration_seconds_bucket{job="apiserver",le="1.0"}[5m])) / sum by (instance) (rate(etcd_request_duration_seconds_bucket{job="apiserver",le="+Inf"}[5m])))` | **0** on all three members over 48h | **0** — etcd was never at risk | **0.0054 / 0.0205 / 0.0165** (0.5-2% of requests over 1s) |
| 8 | **WHO is stalled?** `topk(10, rate(container_pressure_io_stalled_seconds_total{container!="",namespace!=""}[5m]))` | under 0.02 everywhere | **sonarr 0.268**, qbittorrent 0.070, rest under 0.013 | Longhorn instance-manager and the rebuild set |
| 9 | **Are volumes degraded?** `kubectl --context k3s-prod -n longhorn-system get volumes.longhorn.io -o custom-columns=NAME:.metadata.name,ROBUST:.status.robustness \| grep -v healthy` | none | **0 of 24** | all 18 rebuilding |
| 10 | **Did the node leave?** `min_over_time(kube_node_status_condition{condition="Ready",status="true"}[2h])` | 1 | **1** — never NotReady | **0** — "Kubelet stopped posting node status" |
### Reading the columns
* **Column 2 is "not local disk".** Stalled hard, every device idle and fast, NFS transport clean,
our own NFS read rate high, etcd untouched, and the stalled workload is an NFS media consumer.
That is an **NFS-side** stall: I/O PSI counts an NFS wait as an I/O stall, which is exactly why
rows 2-4 look innocent. `NodeIOPressureNotLocalDisk` now fires for this profile and says so.
**Do not replace a disk. Do not throttle Longhorn. Do not raise the PSI thresholds.**
* **Column 3 is hardware.** Row 3 is the giveaway and it is the row the stack did not have in
September: 1,039 ms per write is three orders of magnitude off healthy. `NodeDiskWriteLatencyHigh`
and `NodeDiskWriteLatencyCritical` now fire on it and name the device; `NodeEtcdRequestsSlow`
fires on row 7 and tells you how much time is left. Row 2 being merely "busy" and not pinned is
characteristic: **a dying drive services few slow operations, so utilisation alone never catches
it.**
* **Both columns had a real 10%+ PSI stall.** The thresholds are not the problem and were left
alone (see "Why the PSI thresholds did not change" below).
### What this table still cannot tell you
Row 5 clears the NFS **transport** — dropped or timed-out RPCs — and nothing more. It cannot
distinguish *"the export is answering slowly"* from *"we are asking it for a great deal"*, because
**per-mount NFS round-trip time is not collected on this cluster.** node-exporter's `nfs` collector
(on by default, host-wide via `/proc/net/rpc/nfs`) gives operation COUNTS and retransmissions only;
per-mount, per-operation latency needs the **`mountstats`** collector, which is enabled in
`platform/monitoring/kube-prometheus-stack.yaml` as of 2026-09-14 but **produces nothing until that
HelmRelease has rolled out**. Until then:
* There is no alert on `node_mountstats_*` — deliberately. A rule against a metric nobody scrapes is
the inert-alert failure this repo has already shipped twice, and the L0 gate
(`alert-metrics-have-scrape-targets`) refuses it.
* After the rollout, **verify the series actually arrived** before trusting anything:
`count({__name__=~"node_mountstats_.*"})` and
`count(node_mountstats_nfs_operations_requests_total) by (export)`. node-exporter reads its own
mount namespace, so the kubelet-created NFS mounts are only visible through the `root` hostPath's
`mountPropagation: HostToContainer` and will carry a `/host/root/var/lib/kubelet/...` mount point.
If the count is zero, **revert the collector** rather than leaving it on.
* The open question the numbers cannot settle from inside the cluster: the Proxmox-hosted copy of
this media stack **still has operational control of the same files on 192.168.2.102**. A second
consumer of that export would make the pressure look random from in here and would correlate with
nothing we scrape. The in-cluster signal that points at it is row 1 high with rows 2-5 clean; row 6
then says whether the traffic is ours. Instrumenting the Proxmox host is out of scope from this
repo.
### Why the PSI thresholds did not change
The obvious way to stop this page recurring is to raise 0.05/0.10. Measured 24h distribution on
2026-09-14: prod-1 spent **14 minutes above 5%, 11 above 10%, 3 above 20%**; prod-2 spent **0**
minutes above 5%; prod-3 spent 5. Two distinct prod-1 events in 24h — the 02:40Z one above, and one
20-24h earlier coinciding with Velero's first full volume backup. So the alert is not noisy: it fired
twice in a day, both times for something real, on the one node that has a problem. Raising the
critical threshold to, say, 25% would have silenced tonight entirely and would still not have
explained it; it would also have raised the bar above the 11.36% at which prod-1 was already losing
etcd on 2026-09-07. What was missing was never a higher threshold — it was a cause. That is what the
`platform-health.node-io-cause` rules add.
## What this means here
PSI **full** for I/O: the fraction of wall-clock time in which *every* runnable task on the node was
@@ -35,9 +126,21 @@ shared-data-partition`, not a dedicated device, and §2's exit condition in
2026-09-07 needed a manual `systemctl restart k3s`, and I/O pressure only fell when the 18 rebuilds
finished.
**There is no etcd fsync metric to check.** `etcd_disk_wal_fsync_duration_seconds` is not collected —
`kubeEtcd` is deliberately disabled in `platform/monitoring/kube-prometheus-stack.yaml` for k3s. PSI
is the only signal that exists. Do not go looking for the etcd dashboard; it is not there.
**There is no etcd *server* fsync metric to check, but there IS a per-node proxy.**
`etcd_disk_wal_fsync_duration_seconds` and `etcd_disk_backend_commit_duration_seconds` are not
collected — `kubeEtcd` is deliberately disabled in
`platform/monitoring/kube-prometheus-stack.yaml` for k3s' embedded etcd, and a query for
`{__name__=~"etcd_disk_.*|etcd_server_.*|etcd_mvcc_.*"}` on prod returns nothing at all (re-verified
2026-09-14). Do not go looking for the etcd dashboard; it is not there.
What IS scraped, and what this runbook told you to ignore until 2026-09-14, is
`etcd_request_duration_seconds` on `job="apiserver"` — the apiserver's **client-side** view of its
requests to etcd. On k3s each apiserver talks to the etcd inside its own process, so `instance`
attributes a stall to a node, and the fraction of requests slower than one second is the closest
available stand-in for "etcd cannot commit". Measured 0 on all three members over 48h; 0.5-2% at the
2026-09-07 outage window. `NodeEtcdRequestsSlow` alerts on it at 0.5%. It is a proxy, not the real
thing: it also rises for leader elections, CPU starvation and network problems, so pair it with the
device-latency rules to decide whether the cause is the disk.
## Running the commands in this runbook
@@ -106,6 +209,10 @@ ssh k3s-prod-1 'sudo smartctl -a /dev/sda | grep -Ei "Reallocated|Pending|Uncorr
## Likely causes, most likely first
This list was written from the 2026-09-07 outage and is ordered by what had been seen by then. The
2026-09-14 event was **cause 6**, which is now tied with cause 1 for frequency: two prod-1 events in
24 hours, one of each. If the page says `CAUSE not local disk`, skip straight to 6.
### 1. A Longhorn replica rebuild storm (most common by far)
Every node reboot degrades all ~18 volumes and triggers a full rebuild. That is the normal cost of
Longhorn on these disks, and it is why reboots are rolled **one node at a time, waiting for
@@ -169,6 +276,33 @@ too); `IOSchedulingPriority` is a no-op under `mq-deadline`; `io.latency` is una
decoration (blk-iocost compiled-but-disabled, BFQ not loaded). And no cgroup or scheduler control
arbitrates the **jbd2 journal** that etcd's `fdatasync` actually waits on.
### 6. NFS: the export at 192.168.2.102 — the 2026-09-14 profile
**I/O PSI counts an NFS stall as an I/O stall.** This is the single fact that makes this cluster's
I/O pressure hard to read, and it is why causes 1-5 can all be cleanly excluded while the node is
still stalled at 20%. Five in-tree NFS PVs on `192.168.2.102` carry the media library and the legacy
Nextcloud dataset, and every one of the arr/media pods mounts one.
The signature, all of it measured on 2026-09-14 at 02:40Z (see the triage table above): PSI 20.98% on
prod-1, no device above 0.27 utilisation, 1.6 ms per write, zero NFS retransmissions, 114 NFS
reads/s, and `sonarr` at 0.268 container PSI while everything else on the node sat under 0.013.
`NodeIOPressureNotLocalDisk` fires on exactly this shape and `ContainerIOStallHigh` names the pod.
What to do:
- **Nothing to the disks.** Do not replace hardware, do not throttle Longhorn, do not raise the PSI
thresholds. All three would be acting on the wrong subsystem.
- Ask whether the traffic is ours: row 6 of the triage table. High means our workload is driving the
export and the pressure is self-inflicted (an import or library scan). Near zero, with PSI still
high, means a consumer **outside this cluster**.
- The standing hypothesis for the outside consumer is that the **Proxmox-hosted copy of this media
stack still has operational control of the same files**. It cannot be instrumented from this repo.
From in here, the most the platform can say is "the stall is on NFS and our own op rate does not
account for it" — which is what the alert's `description` asks you to check.
- The operator has explicitly **declined** moving the NFS workloads and declined touching the media
files, so pod anti-affinity and file reorganisation are not on the table. Scope here is
observability.
- The measurement gap that would settle it is per-mount RPC round-trip time (`mountstats`), which is
switched on but unverified — see "What this table still cannot tell you" above.
## When to escalate or stop
- **Stop and get the operator** if `NodeIOPressureCritical` is firing *and* the journal shows