feat(host_agent): NFS delay per mount, read from /proc/self/mountstats (#5996)

Each sample carries each NFS mount's requests since the last one: how many
a second, their round trip and execute time (READ and WRITE on their own),
and how many were sent again or hit a major timeout. mountstats is the
kernel's own count and never touches the share, so it reads while one is
stuck. Steward stores them per mount and the slowest on the host as
nfs_exe_max_ms, for an "NFS slow" rule and the host page's NFS chart beside
mounts_stalled; each mount's bar says what a request took.

Agent 1.22.0 (which also carries the backlog order from 41fc807).

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

tests/core/test_metric_catalog.py

@@ -25,17 +25,19 @@ def _const(node):
 
 
 def _loop_names(func: ast.AST, var: str) -> set[str]:
-    """Literal first elements of `for var, _ in [("a", x), ("b", y)]` loops."""
+    """Literal elements bound to `var` by `for var, _ in [("a", x), ("b", y)]`
+    loops, wherever `var` sits in the target (`for _, var in ...` too)."""
     names: set[str] = set()
     for node in ast.walk(func):
         if not (isinstance(node, ast.For) and isinstance(node.iter, (ast.List, ast.Tuple))):
             continue
-        target = node.target
-        first = target.elts[0] if isinstance(target, ast.Tuple) and target.elts else target
-        if isinstance(first, ast.Name) and first.id == var:
-            for elt in node.iter.elts:
-                if isinstance(elt, ast.Tuple) and elt.elts and _const(elt.elts[0]):
-                    names.add(elt.elts[0].value)
+        targets = node.target.elts if isinstance(node.target, ast.Tuple) else [node.target]
+        at = next((i for i, t in enumerate(targets) if isinstance(t, ast.Name) and t.id == var), None)
+        if at is None:
+            continue
+        for elt in node.iter.elts:
+            if isinstance(elt, ast.Tuple) and len(elt.elts) > at and _const(elt.elts[at]):
+                names.add(elt.elts[at].value)
     return names
 
 
@@ -112,17 +114,30 @@ def host_agent_rows(source: str) -> set[str]:
     for func in ast.walk(ast.parse(source)):
         if isinstance(func, ast.FunctionDef) and func.name == "_expand_sample_to_metrics":
             for call in ast.walk(func):
-                if (isinstance(call, ast.Call) and isinstance(call.func, ast.Name)
-                        and call.func.id == "row" and call.args and _const(call.args[0])):
+                if not (isinstance(call, ast.Call) and isinstance(call.func, ast.Name)
+                        and call.func.id == "row" and call.args):
+                    continue
+                if _const(call.args[0]):
                     names.add(call.args[0].value)
+                elif isinstance(call.args[0], ast.Name):
+                    names |= _loop_names(func, call.args[0].id)
     return names
 
 
 def test_every_metric_host_agent_ingest_writes_is_in_the_catalog():
     """temp_c_max was recorded for weeks and no rule could watch it (#5787)."""
     names = host_agent_rows((_REPO / "plugins/host_agent/routes.py").read_text())
-    assert {"cpu_pct", "temp_c_max", "mounts_stalled"} <= names and len(names) >= 20, names
+    assert {"cpu_pct", "temp_c_max", "mounts_stalled", "nfs_exe_ms"} <= names and len(names) >= 20, names
     from plugins.host_agent import NOT_ALERTABLE
     missing = sorted(names - catalog()["host_agent"] - NOT_ALERTABLE)
     assert not missing, f"host_agent records these but no rule can watch them: {missing}"
     assert NOT_ALERTABLE <= names, "NOT_ALERTABLE names something host_agent no longer records"
+
+
+def test_a_loop_name_is_read_wherever_it_sits_in_the_tuple():
+    code = '''
+def _expand_sample_to_metrics():
+    for key, metric in (("rtt_ms", "nfs_rtt_ms"), ("exe_ms", "nfs_exe_ms")):
+        row(metric, "h:/nfs", 1)
+'''
+    assert host_agent_rows(code) == {"nfs_rtt_ms", "nfs_exe_ms"}

tests/plugins/host_agent/test_agent_collectors.py

@@ -151,3 +151,52 @@ def test_a_mount_that_errors_is_left_out_not_the_whole_list():
             patch.object(a.os, "statvfs", side_effect=OSError):
         out = a.collect_storage(["/", "/nfs/gone"])
     assert out == [{"mount": "/", "total_bytes": 10, "used_bytes": 1}]
+
+
+# ─── NFS delay per mount (#5996) ─────────────────────────────────────────────
+
+MOUNTSTATS = (
+    "device proc mounted on /proc with fstype proc\n"
+    "device 192.168.0.7:/volume1/data mounted on /nfs/data with fstype nfs4 statvers=1.1\n"
+    "\topts:\trw,vers=4.1,hard,proto=tcp\n"
+    "\tper-op statistics\n"
+    "\t        NULL: 0 0 0 0 0 0 0 0 0\n"
+    "\t        READ: 10 10 0 1200 40960 5 30 40 0\n"
+    "\t       WRITE: 4 4 0 8192 512 2 20 24 0\n"
+    "\n"
+    "device 192.168.0.5:/volume1/My Media mounted on /nfs/my\\040media with fstype nfs statvers=1.1\n"
+    "\tper-op statistics\n"
+    "\t     GETATTR: 3 3 0 300 300 0 3 3 0\n"
+    "device /dev/sda1 mounted on / with fstype ext4\n"
+)
+
+
+def test_mountstats_reads_each_nfs_mount_s_ops_and_skips_the_rest():
+    got = a.read_mountstats(MOUNTSTATS)
+    assert set(got) == {"/nfs/data", "/nfs/my media"}
+    assert got["/nfs/data"]["READ"] == (10, 10, 0, 5, 30, 40)
+    assert got["/nfs/data"]["NULL"] == (0, 0, 0, 0, 0, 0)
+    assert got["/nfs/my media"] == {"GETATTR": (3, 3, 0, 0, 3, 3)}
+
+
+def test_mountstats_that_cannot_be_read_is_no_mounts(tmp_path):
+    with patch.object(a, "MOUNTSTATS_PATH", str(tmp_path / "missing")):
+        assert a.collect_nfs_raw() == {}
+
+
+def test_nfs_delay_is_what_the_requests_since_the_last_sample_took():
+    prev = {"/nfs/data": {"READ": (10, 10, 0, 5, 30, 40), "WRITE": (4, 4, 0, 2, 20, 24)},
+            "/nfs/idle": {"GETATTR": (3, 3, 0, 0, 3, 3)},
+            "/nfs/remounted": {"READ": (50, 50, 0, 0, 50, 50)}}
+    cur = {"/nfs/data": {"READ": (20, 21, 1, 7, 130, 240), "WRITE": (4, 4, 0, 2, 20, 24)},
+           "/nfs/idle": {"GETATTR": (3, 3, 0, 0, 3, 3)},
+           "/nfs/remounted": {"READ": (2, 2, 0, 0, 2, 2)},
+           "/nfs/new": {"READ": (5, 5, 0, 0, 5, 5)}}
+    got = {r["mount"]: r for r in a.nfs_delays(cur, prev, 10.0)}
+    # ten READs in 10 s, 100 ms of round trip and 200 ms of waiting between
+    # them, one sent twice and one that hit a major timeout; no WRITE finished
+    assert got["/nfs/data"] == {"mount": "/nfs/data", "ops_per_sec": 1.0, "retrans": 1, "timeouts": 1,
+                                "rtt_ms": 10.0, "exe_ms": 20.0, "read_ms": 20.0}
+    assert got["/nfs/idle"] == {"mount": "/nfs/idle", "ops_per_sec": 0.0, "retrans": 0, "timeouts": 0}
+    assert set(got) == {"/nfs/data", "/nfs/idle"}          # counters gone back, or no baseline yet
+    assert a.nfs_delays(cur, prev, 0) == []

tests/plugins/host_agent/test_expand_metrics.py

@@ -181,3 +181,25 @@ def test_the_host_page_lists_filesystems_fullest_first():
               "h:/data": {"disk_used_pct": 30.0}}
     *_, mounts = _split_host_metrics("h", latest)
     assert list(mounts) == ["/srv", "/var/lib/docker", "/", "/boot", "/data"]
+
+
+def test_nfs_delay_is_recorded_per_mount_and_the_slowest_on_the_host():
+    """#5996: what each NFS mount's requests took, and the host's slowest for a rule."""
+    sample = {"ts": "2026-10-17T12:00:00+00:00",
+              "nfs": [{"mount": "/nfs/data", "ops_per_sec": 4.0, "retrans": 2, "timeouts": 0,
+                       "rtt_ms": 3.5, "exe_ms": 1250.0, "write_ms": 1400.0},
+                      {"mount": "/nfs/media", "ops_per_sec": 1.0, "retrans": 0, "timeouts": 0,
+                       "rtt_ms": 1.0, "exe_ms": 2.0, "read_ms": 2.0}]}
+    idx = _index(_expand_sample_to_metrics(sample, "d3", datetime.now(timezone.utc)))
+    assert idx[("nfs_exe_ms", "d3:/nfs/data")] == 1250.0
+    assert idx[("nfs_write_ms", "d3:/nfs/data")] == 1400.0 and ("nfs_read_ms", "d3:/nfs/data") not in idx
+    assert idx[("nfs_retrans", "d3:/nfs/data")] == 2 and idx[("nfs_ops_per_sec", "d3:/nfs/media")] == 1.0
+    assert idx[("nfs_exe_max_ms", "d3")] == 1250.0
+
+
+def test_a_host_whose_nfs_mounts_finished_nothing_has_no_nfs_delay():
+    sample = {"ts": "2026-10-17T12:00:00+00:00",
+              "nfs": [{"mount": "/nfs/data", "ops_per_sec": 0.0, "retrans": 0, "timeouts": 0}]}
+    idx = _index(_expand_sample_to_metrics(sample, "d3", datetime.now(timezone.utc)))
+    assert idx[("nfs_ops_per_sec", "d3:/nfs/data")] == 0.0
+    assert ("nfs_exe_max_ms", "d3") not in idx and ("nfs_exe_ms", "d3:/nfs/data") not in idx

tests/plugins/host_agent/test_host_health.py

@@ -95,3 +95,22 @@ async def test_sensors_not_counted_are_listed_once_per_reason(app):
     page = " ".join(page.split())
     assert (f"Not counted, likely nothing wired to them: temp3 62°C ({falls}); "
             f"SYSTIN 115°C, AUXTIN0 110°C ({held}).") in page
+
+
+async def test_an_nfs_mount_says_what_a_request_took_and_a_local_one_says_nothing(app):
+    """#5996: the delay under each NFS mount's bar, graded at 100 and 1000 ms."""
+    async with app.test_request_context("/plugins/host_agent/h1/metrics"):
+        page = await render_plugin_template(
+            app, "host_agent", "_host_metrics.html", host=SimpleNamespace(address="10.0.0.2"), stale=False,
+            reg=SimpleNamespace(distro=None, kernel=None, arch=None, agent_version=None,
+                                last_seen_at=datetime.now(timezone.utc)),
+            hostlvl={}, cores=[], nets={}, disks_io={}, temps={},
+            mounts={"/nfs/data": {"disk_used_pct": 40.0, "nfs_ops_per_sec": 4.0, "nfs_exe_ms": 250.0,
+                                  "nfs_retrans": 3.0},
+                    "/nfs/media": {"disk_used_pct": 30.0, "nfs_ops_per_sec": 0.0},
+                    "/": {"disk_used_pct": 20.0}})
+    page = re.sub(r">\s+<", "><", " ".join(page.split()))
+    assert '<span class="tone-warn">250.0 ms a request</span> · 4/s · <span class="tone-warn">3 sent again</span>' in page
+    assert "NFS idle" in page and page.count("NFS ") == 2
+    assert "timed out" not in page
+    assert not hex_colours(page), hex_colours(page)