Skip to content

Commit ca6e86e

Browse files
committed
feat(probe): a connscale gap now records WHICH path degraded it, and the smoke test asserts only what it can
The FD probe returned the same all-None sample from THREE different paths and the record could not say which one fired. That is why `main`'s tip red was mis-attributed by four sessions today: the failing assertion was `tests/test_connscale_smoke.py:128`, `assert r.fd_count_peak is not None`, and the record's repr carried `sent=36 acked=24` -- so the attribution followed the NUMBERS in the dump to the item about sent/acked, rather than the ASSERTION, which was about the probe. The artifact did not carry the information needed to attribute it. WHAT CHANGED. `ProbeDegraded` names each cause distinctly -- the subtree walk timing out, erroring fast, returning zero rows, or returning a snapshot with no root; and the per-PID read timing out, erroring or parsing nothing. `ProcSample.degraded` carries it, `_gap(cause)` replaces the single shared `_EMPTY_PROC`, and `_resolve_errored` becomes a property over the recorded cause so a boolean can no longer be set without saying why. `is_budget_exhausted()` is the discriminator, stated once: a path that SPENT its budget measures the runner; one that failed without spending it is a broken probe. Those get opposite readings and they were previously indistinguishable. THE SMOKE ASSERTION IS NARROWED, NOT RELAXED, AND THE DIFFERENCE IS THE WHOLE POINT. It used to demand `fd_count_peak is not None` of EVERY record, with no tolerance for a probe that honestly could not measure -- so a degraded probe red a REQUIRED context as though the ENGINE were at fault. It now asserts `> 0` only where a value is present AND still requires that AT LEAST ONE record measured something. A run where the probe never measured at all still fails. Buying a green by deleting the requirement was the available wrong answer here and it is not what this does. Twelve cases in a new tests/test_connscale_probe_degradation.py pin each cause to its path, including the two that must record NO cause on success, and one asserting a resolution that fails without naming a cause is still given one -- so the enum cannot be bypassed by a future path that forgets to classify. Does NOT fix the underlying walk timeout, and does not claim to. It makes the next occurrence attributable, which is what four sessions lacked today. VERIFIED: tests/test_connscale_probe_degradation.py + tests/test_connscale_smoke.py -> 32 passed; tests/test_sandbox.py unaffected; ruff 0.15.22 clean on all five files; no cp1252-unsafe character introduced (census identical against HEAD). harness/ is not in CI's mypy scope (`mypy messagefoundry messagefoundry_webconsole --exclude 'messagefoundry/tray/'`), and the 3-file mypy invocation reports the same single package-discovery error at HEAD as with this change, so it is pre-existing and not introduced here. ITS ADVERSARIAL REVIEW HAD NOT REPORTED WHEN THIS WAS COMMITTED. Committed anyway to protect the work across a usage-window boundary, on the explicit understanding that a review finding is fixed FORWARD -- which is exactly what happened to the sibling #1290 commit earlier on this branch, where the review found a blocking defect and e2ce84ad corrected it before anything left this tree. Nothing here is pushed.
1 parent 1df0c07 commit ca6e86e

5 files changed

Lines changed: 898 additions & 49 deletions

File tree

harness/load/connscale/probe.py

Lines changed: 135 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -22,7 +22,8 @@
2222
statm`` (resident pages). Where the launching interpreter spawns no shim the subtree is just the one
2323
process — byte-identical to single-process sampling. Every field is ``None`` when nothing in the
2424
subtree could be read (a dead tree / a missing tool), so the runner records a gap rather than
25-
crashing.
25+
crashing — and that gap CARRIES ITS CAUSE (:class:`ProbeDegraded`), because a gap that cannot say
26+
which of the probe's seven degrade paths produced it is not attributable to anything.
2627
2728
The walk is **provenance-checked** (BACKLOG #1210): a candidate that PREDATES the root is not a
2829
descendant of it, so it is rejected along with its subtree. Windows never rewrites
@@ -42,6 +43,7 @@
4243
import sys
4344
import time
4445
from dataclasses import dataclass
46+
from enum import StrEnum
4547
from pathlib import Path
4648

4749
from messagefoundry.apiclient import ApiError, EngineClient
@@ -75,6 +77,58 @@
7577
type ProcRow = tuple[int, int, float | None]
7678

7779

80+
class ProbeDegraded(StrEnum):
81+
"""WHY a :class:`ProcSample` carries no reading — the path that degraded this tick.
82+
83+
A gap that does not name its cause is UNATTRIBUTABLE, and this probe has seven distinct ways to
84+
produce one. They were previously indistinguishable: every path returned the same all-``None``
85+
sample, so a record could say only THAT the probe did not read, never WHICH mechanism stopped it —
86+
and a CI red was mis-attributed to unrelated work three times over precisely because the artifact
87+
did not carry the information needed to attribute it.
88+
89+
The one distinction a CONSUMER has to draw is BUDGET-EXHAUSTED vs not (:attr:`is_budget_exhausted`),
90+
because the two earn OPPOSITE verdicts: a shell-out that spent its whole ``_PROBE_TIMEOUT_S``
91+
measures the RUNNER (a starved host could not answer in time), while every other member means the
92+
probe RAN and produced nothing usable, which is a defect in the probe. That line is stated here
93+
ONCE. ``tests/test_connscale_cpu_probe.py`` draws the same line at the walk level from the seconds a
94+
failed walk actually spent (``_BUDGET_CONSUMED_FRACTION``), and the two must stay one vocabulary:
95+
"budget exhausted" is could-not-measure, anything faster is measured-and-broken."""
96+
97+
# --- the subtree walk: one process-table snapshot, per `FdSampler._resolve_pids` ---
98+
# The walk spent its whole timeout. This measures the runner, not the engine.
99+
WALK_TIMEOUT = "walk_timeout"
100+
# The walk's shell-out raised something OTHER than a timeout (OSError / a non-timeout
101+
# SubprocessError), so it failed without using its budget.
102+
WALK_ERROR = "walk_error"
103+
# The walk COMPLETED and yielded zero usable rows. A live host always has many processes, so this
104+
# is a silent enumeration failure (truncated output / a walk that never really ran), never a
105+
# genuine empty result -- see `_enumerate_windows`.
106+
WALK_EMPTY = "walk_empty"
107+
# The snapshot carried no row for the ROOT pid, so no candidate could be validated against the
108+
# root's creation instant. Fail closed (`_validated_descendants`) rather than walk unchecked.
109+
WALK_NO_ROOT = "walk_no_root"
110+
111+
# --- the per-PID read: `FdSampler._sample_windows` / `._sample_posix` ---
112+
# The per-PID read spent its whole timeout. Measures the runner, as WALK_TIMEOUT does.
113+
READ_TIMEOUT = "read_timeout"
114+
# The per-PID read raised something other than a timeout, without using its budget.
115+
READ_ERROR = "read_error"
116+
# The per-PID read RAN and returned zero usable rows across the whole subtree. Not a timeout at
117+
# all -- the enumeration happened and produced nothing.
118+
READ_EMPTY = "read_empty"
119+
120+
@property
121+
def is_budget_exhausted(self) -> bool:
122+
"""True when this cause is a shell-out that SPENT its whole ``_PROBE_TIMEOUT_S``.
123+
124+
The discriminator a consumer needs, and the only one: budget-exhausted says the host was too
125+
slow to answer, so the probe reports COULD NOT MEASURE and the subject under test is not
126+
implicated. Every other member says the probe ran and produced nothing usable, which IS a
127+
finding. Kept as a property on the vocabulary itself so no consumer re-derives the split from a
128+
member list of its own that could then drift member-by-member."""
129+
return self in (ProbeDegraded.WALK_TIMEOUT, ProbeDegraded.READ_TIMEOUT)
130+
131+
78132
@dataclass(frozen=True)
79133
class ProcSample:
80134
"""One OS-side reading of the engine process (all ``None`` when unreadable — a poll tick gap).
@@ -88,15 +142,28 @@ class ProcSample:
88142
to derive utilisation, and that difference is only a clean CPU delta when the summed-over PID set
89143
is unchanged — A3's periodic subtree re-resolution can add a joining ``serve --shard`` worker or
90144
drop a departing one mid-window, so the runner uses this set to sum only same-set intervals and
91-
degrade the rest to a gap (BACKLOG #220)."""
145+
degrade the rest to a gap (BACKLOG #220).
146+
* ``degraded`` — WHY this tick measured nothing, when it measured nothing. Set **iff** the tick is a
147+
FULL gap (every field above ``None``); a tick that read anything at all carries ``None`` here. A
148+
partial POSIX read (handles present, CPU absent) is NOT a degradation — the gauges that read still
149+
read, and the ones that did not are visible as their own ``None``."""
92150

93151
handles: int | None
94152
cpu_seconds: float | None
95153
working_set_bytes: int | None
96154
cpu_pids: frozenset[int] | None = None
155+
degraded: ProbeDegraded | None = None
97156

98157

99-
_EMPTY_PROC = ProcSample(handles=None, cpu_seconds=None, working_set_bytes=None, cpu_pids=None)
158+
def _gap(cause: ProbeDegraded) -> ProcSample:
159+
"""A full-gap sample that NAMES the path that produced it.
160+
161+
Every degrade site goes through here, so a gap cannot be constructed without stating its cause —
162+
which is the whole point: an unattributed gap is what let one starved-runner timeout and one
163+
genuinely broken enumeration render as the same artifact."""
164+
return ProcSample(
165+
handles=None, cpu_seconds=None, working_set_bytes=None, cpu_pids=None, degraded=cause
166+
)
100167

101168

102169
class FdSampler:
@@ -107,17 +174,21 @@ class FdSampler:
107174
resolved periodically and cached in between; each :meth:`sample_proc` sums a cheap per-PID read
108175
across it. :meth:`sample` keeps the legacy handle-count-only shape (``int | None``). Every field is
109176
``None`` when nothing in the subtree could be read (a dead tree / a missing tool) so a poll tick
110-
records a gap, never raises."""
177+
records a gap, never raises — and that gap names the path that produced it
178+
(:attr:`ProcSample.degraded`)."""
111179

112180
def __init__(self, pid: int, *, resolve_every: int = _RESOLVE_EVERY_TICKS) -> None:
113181
self._pid = pid
114182
self._pids: list[int] | None = None # [root, *descendants], re-resolved every N ticks
115-
# True while the last subtree resolution ERRORED (Windows enumeration failed/timed out, or the
116-
# root's own creation instant was absent so nothing could be validated against it) — as opposed
117-
# to a genuine no-descendants result. An errored resolution is NOT cached (so a later tick
118-
# retries) and its samples are reported probe-degraded (all None) rather than measuring a root
119-
# that may be only the launcher shim.
120-
self._resolve_errored = False
183+
# WHY the last subtree resolution failed, or None when it succeeded (Windows enumeration
184+
# timed out / errored / came back empty, or the root's own creation instant was absent so
185+
# nothing could be validated against it) — as opposed to a genuine no-descendants result. An
186+
# errored resolution is NOT cached (so a later tick retries) and its samples are reported
187+
# probe-degraded rather than measuring a root that may be only the launcher shim.
188+
#
189+
# This holds the CAUSE, not a bool, because the bool was the defect: four different resolution
190+
# failures set it identically and the tick they degraded could not say which had fired.
191+
self._resolve_degraded: ProbeDegraded | None = None
121192
# A3: the subtree is NOT stable for a SHARDED engine — ADR 0037's supervisor spawns one
122193
# `serve --shard` subprocess per shard, and a subtree cached before they appear measures an idle
123194
# supervisor forever (a flat CPU counter that used to render as a plausible 0.00). Re-resolve
@@ -129,6 +200,12 @@ def __init__(self, pid: int, *, resolve_every: int = _RESOLVE_EVERY_TICKS) -> No
129200
def pid(self) -> int:
130201
return self._pid
131202

203+
@property
204+
def _resolve_errored(self) -> bool:
205+
"""Did the last subtree resolution fail? DERIVED from :attr:`_resolve_degraded` so the fact is
206+
stored once — a separate bool beside the cause is two statements of one fact, and they drift."""
207+
return self._resolve_degraded is not None
208+
132209
def sample(self) -> int | None:
133210
"""The current handle/fd count across the engine subtree, or ``None`` if it can't be read
134211
(legacy shape). Delegates to :meth:`sample_proc` so it stays one cheap read per PID."""
@@ -139,12 +216,13 @@ def sample_proc(self) -> ProcSample:
139216
each field ``None`` when nothing could be read. Runs the OS probe synchronously — the runner
140217
calls it in ``run_in_executor`` (off the event loop), like the rest of the sampling."""
141218
pids = self._resolve_pids()
142-
if self._resolve_errored:
143-
# Subtree resolution ERRORED (a failed/timed-out Windows enumeration, or no row for the
144-
# root). Reading the root PID alone would report a launcher shim's footprint as the
219+
if self._resolve_degraded is not None:
220+
# Subtree resolution FAILED (a timed-out / errored / empty Windows enumeration, or no row
221+
# for the root). Reading the root PID alone would report a launcher shim's footprint as the
145222
# engine's — worse than a gap, because it's a plausible-looking WRONG number that could flip
146-
# a footprint delta. Record a probe-degraded gap (all None) and let a later tick retry.
147-
return _EMPTY_PROC
223+
# a footprint delta. Record a probe-degraded gap CARRYING WHICH of those fired, and let a
224+
# later tick retry.
225+
return _gap(self._resolve_degraded)
148226
if _WINDOWS:
149227
return self._sample_windows(pids)
150228
return self._sample_posix(pids)
@@ -173,15 +251,21 @@ def _resolve_pids(self) -> list[int]:
173251
# Serving a previously-VALIDATED subtree. If the last re-resolve errored, that error
174252
# applied to that tick only — the cached subtree is still the best known truth, and
175253
# degrading every tick until the next re-walk would turn one transient enumeration
176-
# failure into a run-long blackout. Clear the flag so this tick reports a real reading.
177-
self._resolve_errored = False
254+
# failure into a run-long blackout. Clear the cause so this tick reports a real reading.
255+
self._resolve_degraded = None
178256
return self._pids
179257
self._ticks_since_resolve = 0
258+
# Cleared BEFORE the walk: the walk itself records why it failed, and a stale cause from the
259+
# previous walk would otherwise be attributed to this one.
260+
self._resolve_degraded = None
180261
descendants = self._descendants_windows() if _WINDOWS else self._descendants_posix()
181262
if descendants is None:
182-
self._resolve_errored = True
263+
if self._resolve_degraded is None:
264+
# Defensive: `_descendants_windows` names every failure it returns None for. A stand-in
265+
# that returns None without naming one still gets a cause rather than an unattributed
266+
# gap — an unnamed cause is the exact condition this field exists to remove.
267+
self._resolve_degraded = ProbeDegraded.WALK_ERROR
183268
return [self._pid] # transient (this tick only), not cached — retry next tick
184-
self._resolve_errored = False
185269
ordered = [self._pid]
186270
for pid in descendants:
187271
if pid not in ordered:
@@ -218,8 +302,14 @@ def _enumerate_windows(self) -> list[ProcRow] | None:
218302
text=True,
219303
timeout=_PROBE_TIMEOUT_S,
220304
)
305+
# TimeoutExpired is caught FIRST because it is a SubprocessError subclass, and it is the one
306+
# failure here that measures the RUNNER rather than the probe (see ProbeDegraded).
307+
except subprocess.TimeoutExpired:
308+
self._resolve_degraded = ProbeDegraded.WALK_TIMEOUT
309+
return None # spent its whole budget — NOT "no descendants"
221310
except (OSError, subprocess.SubprocessError):
222-
return None # errored/timed out — NOT "no descendants"
311+
self._resolve_degraded = ProbeDegraded.WALK_ERROR
312+
return None # errored without using its budget — NOT "no descendants"
223313
# Parse whatever rows came back regardless of the exit code (a partial result is still usable).
224314
rows: list[ProcRow] = []
225315
for line in out.stdout.splitlines():
@@ -236,6 +326,7 @@ def _enumerate_windows(self) -> list[ProcRow] | None:
236326
# (a silent failure / truncated output). Signal errored so the caller retries + degrades rather
237327
# than caching root-only and reporting the launcher shim's footprint as the engine's.
238328
if not rows:
329+
self._resolve_degraded = ProbeDegraded.WALK_EMPTY
239330
return None
240331
return rows
241332

@@ -267,8 +358,14 @@ def _enumerate_posix(self) -> list[ProcRow]:
267358
def _descendants_windows(self) -> list[int] | None:
268359
rows = self._enumerate_windows()
269360
if rows is None:
270-
return None
271-
return _validated_descendants(rows, self._pid)
361+
return None # `_enumerate_windows` recorded WHICH enumeration failure this was
362+
walked = _validated_descendants(rows, self._pid)
363+
if walked is None:
364+
# The enumeration itself SUCCEEDED; what failed is validation — the snapshot carried no row
365+
# for the root, so nothing could be checked against its creation instant. A distinct
366+
# mechanism from any enumeration failure, and it must not be reported as one.
367+
self._resolve_degraded = ProbeDegraded.WALK_NO_ROOT
368+
return walked
272369

273370
def _descendants_posix(self) -> list[int]:
274371
walked = _validated_descendants(self._enumerate_posix(), self._pid)
@@ -294,8 +391,12 @@ def _sample_windows(self, pids: list[int]) -> ProcSample:
294391
text=True,
295392
timeout=_PROBE_TIMEOUT_S,
296393
)
394+
# TimeoutExpired first (it subclasses SubprocessError): a read that spent its whole budget
395+
# measures the runner, an immediate error is the probe failing. Opposite verdicts downstream.
396+
except subprocess.TimeoutExpired:
397+
return _gap(ProbeDegraded.READ_TIMEOUT)
297398
except (OSError, subprocess.SubprocessError):
298-
return _EMPTY_PROC
399+
return _gap(ProbeDegraded.READ_ERROR)
299400
# NB: ignore the exit code. `Get-Process -Id a,b` where one PID has since exited emits a
300401
# non-terminating error (exit 1) EVEN under -ErrorAction SilentlyContinue, yet still writes the
301402
# live processes' rows to stdout. Trust the parsed rows; only zero rows ⇒ a genuine gap.
@@ -322,7 +423,9 @@ def _sample_windows(self, pids: list[int]) -> ProcSample:
322423
cpu_pids.add(pid)
323424
rows += 1
324425
if rows == 0:
325-
return _EMPTY_PROC
426+
# The read RAN and parsed nothing. NOT a timeout — no budget was exhausted, the command
427+
# completed and produced no usable row for any PID in the subtree.
428+
return _gap(ProbeDegraded.READ_EMPTY)
326429
return ProcSample(
327430
handles=handles,
328431
cpu_seconds=cpu_ticks / _WIN_CPU_TICKS_PER_S,
@@ -350,6 +453,14 @@ def _sample_posix(self, pids: list[int]) -> ProcSample:
350453
if r is not None:
351454
rss_sum += r
352455
r_seen += 1
456+
if not (h_seen or c_seen or r_seen):
457+
# Nothing in the whole subtree was readable — the reads RAN and produced no usable row, so
458+
# this is READ_EMPTY for the same reason the Windows zero-rows branch is. The POSIX side
459+
# does not split out a timeout: /proc reads are file reads with no budget to exhaust, and
460+
# the one budgeted call (the lsof fallback) is per-PID, so a subtree-wide gap here is not
461+
# attributable to any single PID's timeout. Claiming a timeout we did not observe would be
462+
# exactly the fabricated cause this vocabulary exists to prevent.
463+
return _gap(ProbeDegraded.READ_EMPTY)
353464
return ProcSample(
354465
handles=handles_sum if h_seen else None,
355466
cpu_seconds=cpu_sum if c_seen else None,

harness/load/connscale/report.py

Lines changed: 32 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -149,6 +149,19 @@ class ConnScaleRecord:
149149
# non-batching record deserializes unchanged. The batch comparison pairs B0 vs B1 by this tag (it
150150
# reuses the fusion comparator's verdict path keyed on this field instead of ``fuse_thread_hops``).
151151
batch_handoff_statements: bool = False
152+
# --- wall #4 probe provenance: why `fd_count_peak` is None, when it is None ---
153+
# `fd_count_peak = None` used to be the whole story, and it is the same value whether the host was
154+
# too starved to enumerate, the process tree was gone, or the enumerator ran and returned zero
155+
# rows. Those warrant different verdicts, so the OS probe's own account of the window travels with
156+
# the gauge. `fd_probe_ticks` is the SCOPE for `fd_probe_degraded_ticks` (a degraded count without
157+
# its denominator is not readable), and `fd_probe_degraded` holds the DISTINCT causes as strings
158+
# (`harness.load.connscale.probe.ProbeDegraded` values) — strings, so this module keeps its
159+
# independence from the probe. All three default so an older artifact deserializes unchanged;
160+
# an empty `fd_probe_degraded` alongside `fd_probe_ticks == 0` means the probe did not run at all,
161+
# which is itself distinct from having run and failed.
162+
fd_probe_ticks: int = 0
163+
fd_probe_degraded_ticks: int = 0
164+
fd_probe_degraded: tuple[str, ...] = ()
152165

153166
def to_json_dict(self) -> dict[str, object]:
154167
return {
@@ -212,7 +225,16 @@ def to_json_dict(self) -> dict[str, object]:
212225
else round(self.empty_claims_per_msg, 3)
213226
),
214227
},
215-
"wall4_fd": {"count_peak": self.fd_count_peak},
228+
"wall4_fd": {
229+
"count_peak": self.fd_count_peak,
230+
# The gap's account of itself. Present even on a clean window (0 degraded of N ticks),
231+
# because "the probe measured every tick" is a fact worth reading in an artifact too.
232+
"probe": {
233+
"ticks": self.fd_probe_ticks,
234+
"degraded_ticks": self.fd_probe_degraded_ticks,
235+
"degraded": list(self.fd_probe_degraded),
236+
},
237+
},
216238
"wall5_reload": {"seconds": self.reload_seconds},
217239
"wall6_ack_ms": {
218240
"p50": round(self.ack_p50_ms, 3),
@@ -370,6 +392,15 @@ def render_console(self) -> str:
370392
f"{_na(r.fd_count_peak):>7}{_na(_round_or_none(r.cpu_seconds_total, 1)):>8}"
371393
f"{_na(r.reload_seconds):>8}{r.ack_p99_ms:>9.1f}"
372394
)
395+
# The `fd` column renders `n/a` on a gap, and nobody can act on `n/a`. Name the mechanism beside
396+
# it, with the scope of the count, so the console says which of the probe's degrade paths fired.
397+
for r in self.records:
398+
if r.fd_probe_degraded_ticks:
399+
causes = ", ".join(r.fd_probe_degraded) or "cause not recorded"
400+
lines.append(
401+
f"fd probe: {r.sweep_mode}@N={r.count} -- {r.fd_probe_degraded_ticks} of "
402+
f"{r.fd_probe_ticks} tick(s) measured nothing [{causes}]"
403+
)
373404
lines.append("")
374405
lines.append("SLOs:")
375406
if not self.slos:

0 commit comments

Comments
 (0)