Skip to content

test(role): the publish observer cannot hang, and its sizing is measured (#296) - #304

Merged
localai-bot merged 2 commits into
mainfrom
row/ENG-OPERATOR-RECORD-COVERAGE-FIX
Aug 10, 2026
Merged

test(role): the publish observer cannot hang, and its sizing is measured (#296)#304
localai-bot merged 2 commits into
mainfrom
row/ENG-OPERATOR-RECORD-COVERAGE-FIX

Conversation

@localai-bot

Copy link
Copy Markdown
Collaborator

Merge pull request #304 from mudler/row/ENG-OPERATOR-RECORD-COVERAGE-FIX

test(role): the publish observer cannot hang, and its sizing is measured (#296)

Closes #296, the two coverage limitations #285 left recorded rather than fixed.

LIMITATION 1 — a comment the code falsified. RECORD_TTL_SECONDS still said a
stale record is "unlinked by the next claim", false for this worktree's own
record after keep_canonical (it is replaced). The spec's copy had been
corrected; the source copy one screen above the function had not. A tree-wide
grep confirms there is no third copy.

LIMITATION 2 — the publish-NAME pin was escapable. It monkeypatch-watched four
I/O primitives, so an os.rename + open() publish walked past it while a real
concurrent show returned rc 3. The fix ships BOTH halves, because they fail
differently: a widened watcher (deterministic, catches the primitives it names)
and an outside observer, 2000 publishes in a subprocess under an exists()
poller (one-sided -- a hit proves absence, a miss proves nothing -- so it can
never false-RED, and it is the only half that can catch a primitive nobody
enumerated).

That is not a theory. Across this review three distinct publish shapes were
found that the deterministic half cannot see, each by a different fresh
reviewer:

  • bytes first, then basename unlink, then os.rename(temp, name)
  • and, this round, a NEW CLASS: absence caused by an ANCESTOR rather than the
    leaf -- rename the records DIRECTORY aside and back, so no watched call ever
    receives the record's own path
    Both escape the watcher, the hardlink witness and the residue check, and both
    are caught by the observer alone, 10/10 in multi-core and single-core regimes.

TWO REVIEW ROUNDS, and the first round's findings were both real:

  1. The observer could HANG THE SUITE FOREVER. An unread stderr=PIPE plus an
    unbounded spin deadlocked once the child filled the 65536-byte pipe --
    measured on the CORRECT publish at 391 B/publish: rc=124, killed at 90 s,
    ~100% CPU. Reachable by anyone's change, since the child forks git rev-parse on every publish. Now: child output goes to FILES, the ready
    handshake is a bounded file poll, and both loops are bounded by a 60 s
    deadline. Both arms verified firing by an independent reviewer -- wedged
    mid-publish FAILED at 60.077 s, wedged before ready FAILED at 5.077 s with a
    shortened deadline -- with 0 orphan processes and 0 leaked files after ~60
    runs including three hard-failure paths.
  2. The sizing rationale was falsified by measurement. The comment claimed
    caching worktree_id removed the subprocess dilution; record_path() ->
    common_dir() still forked git rev-parse every publish, which was 89% of
    the observed window. Caching it lifted single-core detection 0/30 -> 7/30.

The residual was then CLOSED rather than restated: with the cheaper loop, raising
the count 200 -> 2000 makes detection 20/20 in BOTH regimes, which falsifies the
spec's "costs seconds per invocation" declination. Independently measured cost:
+0.36 s on a 5.58 s suite, slightly cheaper than the implementer's own ~0.5 s
estimate.

VERIFIED BY THE OPERATOR rather than taken on report: the commit touches exactly
two files and scripts/agent-role.py is byte-unchanged, so no product behaviour
moves; test_agent_role 60 tests in 5.312 s at load 142; 5 consecutive runs
green. The reviewer independently confirmed 119 tests across the three suites,
0/40 unmutated flake in both regimes, and agent-preflight.sh --quiet --no-require-role all gates green.

ONE LOW FINDING RECORDED, NOT REPAIRED. The deadline comment claims "over two
orders of magnitude of headroom" and the failure text prints "~182x the measured
window". Measured under 42x single-core oversubscription (40 CPU hogs, both
processes on one core), correct runs took 18.0-19.3 s -- a 3.1x margin, not 182x;
crossing 60 s would need roughly 130x oversubscription. No false failure was
produced in 45 correct runs across three regimes, and what it replaces was an
unbounded hang, so the change strictly dominates. Tracked as a follow-up rather
than blocking a fifth round on a diagnostic string.

A note on process: the first attempt at this review was terminated by an API
session limit at the full-gate step and returned nothing, so it was re-run from
scratch rather than resumed on assumptions.

Following-Agents-Protocol: true
AI-Assisted: true
Assisted-by: Claude-Code:claude-opus-5 [Claude Code]

mudler added 2 commits August 10, 2026 20:28
…le publish pin

Both were recorded as LOW by #295's final review rather than blocked. Neither
changes what `agent-role.py` does; the shipped publish is unchanged.

1. `RECORD_TTL_SECONDS`' comment still said a stale record is "unlinked by the
   next `claim`". `keep_canonical` made that false for THIS worktree's record --
   it is REPLACED, never unlinked, which is the whole point of the fix. The
   byte-identical sentence in the spec was corrected when that landed and the
   source copy, one screen above the function it describes, was missed. It now
   carries the same qualification, and a tree-wide search found no third copy.

2. `test_a_publish_never_leaves_the_record_NAME_absent` watched four I/O
   primitives, so a publish written `os.rename(target, aside)` then
   `open(target, "w")` escaped it. MEASURED: the pre-#296 suite is 59/59 GREEN
   under exactly that mutation, while a concurrent `show` in the window returns
   rc=3 role=UNDECLARED.

That is the third consecutive round in which one publish-coverage residual was
fixed and the next one opened, and the reason is structural: ANY
monkeypatch-watcher pin is escapable by one more primitive, so widening the list
chases a fixed point. The pin is now two tests that fail differently.

`_watch_publish` (deterministic, in-process) additionally watches
`os.rename`/`os.replace` and `Path.rename`/`Path.replace` as SOURCE -- the
shipped `os.replace(temp, target)` has the record as DESTINATION and never
removes the name -- plus `builtins.open`/`io.open`/`os.open` in write modes.

`test_a_concurrent_observer_never_sees_the_record_name_absent` (probabilistic,
out-of-process) republishes the record 200 times in a subprocess while the test
process does nothing but poll `exists()`. It enumerates no primitive, so it is
the only half that can catch one nobody listed. It is ONE-SIDED -- a hit proves
absence, a miss proves nothing -- so it cannot go red on correct code however
the two processes are scheduled; `os.replace` never lets the name stop
resolving. Contention costs detection probability, never a red run.

MEASURED 2026-08-10, 20-core box already at load average 263, ~1.5ms per publish
against ~1us per poll, 150k-300k polls per run:

  publish under test                    watcher   observer
  os.rename + open (documented escape)  RED       10/10 (and 10/10 at 60)
  unlink + write_text (prior escape)    RED       10/10
  byte-at-a-time in-place rewrite       green*    0/6
  shipped write temp + os.replace       green     40/40 green, 0 absent
  shipped, both processes on ONE core   green     20/20 green
  os.rename + open, on ONE core         RED       1/15

  * caught instead by test_a_publish_replaces_the_record_and_never_rewrites_it_
    in_place, whose hardlink witness is that mutation's subject.

The two single-core rows are why BOTH halves ship rather than either. The
observer needs real parallelism -- pinned to one core the publisher is rarely
preempted inside a window lasting microseconds -- and is blind by construction
to a publish that never makes the name absent. The watcher is unaffected by
scheduling but covers only what it names. Neither subsumes the other.

Sizing: 200 publishes is ~0.39s, chosen for margin over the 60 that already
detected 10/10. The only non-assertion guard is a floor of 200 polls, ~0.1% of
the measured count, whose sole job is to notice a poll loop that never ran.

The test's stated claim was weakened to match what it proves: it no longer
claims "at the instant ANY file content is written ... NOTHING may unlink it",
but bounds itself to the primitives `_watch_publish` names and points at the
observer for the rest.

Gates: test_agent_role 60 (was 59, +1), test_agent_onboard 39, test_agent_start
20, all green; `scripts/agent-preflight.sh --quiet` green before and after (with
--no-require-role: this session declared no role, so the role gate would report
its own state, not the tree's).

FOLLOWING_AGENTS_PROTOCOL

Following-Agents-Protocol: true
AI-Assisted: true
Assisted-by: Claude-Code:claude-opus-5 [Claude Code]
…s falsified

Two MEDIUM findings from the fresh review of 937edcf5 (issue #296). The design
it shipped -- a widened in-process watcher AND an out-of-process observer --
stays, and the review itself is the evidence for it: the reviewer found a FIFTH
publish shape (write the bytes while the name still resolves, `os.chdir` into
the records dir, `os.unlink` the BASENAME, `os.rename` the temp in) that trips
NO `_watch_publish` arm and satisfies the hardlink and residue pins, and that
the observer alone catches. It is now in the mutation matrix, 10/10 RED
multi-core and 10/10 pinned to one core.

1. THE OBSERVER COULD HANG FOREVER INSTEAD OF FAILING. An unread
   `stderr=subprocess.PIPE` plus an unbounded `while publisher.poll() is None`
   deadlocks once the child fills the pipe. Reproduced on the SHIPPED, CORRECT
   publish before the fix: 391 bytes of child stderr per publish never completed
   -- killed at `timeout 90`, rc=124, no output, spinning a core -- while 155
   bytes/publish (~31KB, under this box's 65536-byte pipe) passed in 0.410s.
   That cliff is reachable by anyone's change, not just a mutation: the child
   forks `git rev-parse` per publish. A test that cannot finish is worse in a
   suite everyone must pass than the gap it closes.

   Child stdout and stderr now go to FILES, which have no capacity to fill, and
   the diagnostics still reach the failure message. Same 391 bytes/publish now
   completes in 0.208s; 782KB and 40MB of child stderr pass in under a second.
   Both loops are additionally bounded by a 60s wall-clock deadline that kills
   the child and FAILS. Verified in both directions: a child wedged before its
   ready signal and a child wedged mid-publish each fail at 60.05s.

2. THE SIZING RATIONALE WAS FALSIFIED BY MEASUREMENT, AND THE RECORDED RESIDUAL
   WAS A HARNESS ARTIFACT. The child comment said caching `worktree_id` "stops
   the observed window being diluted by a subprocess that touches no record".
   It did not: `record_path` -> `records_dir` -> `common_dir` still forked
   `git rev-parse` on every publish. RE-DERIVED here, 20-core box at load 184:
   1.467 ms/publish as shipped, 0.163 ms with `common_dir` cached too, 1.041 ms
   for one bare `git rev-parse` -- so 89% of the window the observer was offered
   was the very subprocess the comment claimed had been removed.

   That makes the spec's declination wrong on the cost. Interleaved A/B, 30
   paired runs, `taskset -c 3`, load 198-201: `os.rename` + `open` went 0/30 ->
   7/30 RED and the basename shape 1/30 -> 9/30 with the one-line cache. Raising
   the publish count then closes the residual outright, because the loop is now
   cheap enough to run many more times in the same wall clock -- sweep against
   the basename shape, 20 runs per cell, multi-core / one core:
   200 -> 16/20 and 6/20; 800 -> 19/20 and 14/20; 2000 -> 20/20 and 20/20, with
   unmutated 0/3 at every count in both regimes. 2000 is the first count that is
   not probabilistic in EITHER regime and it costs ~0.5s on a ~5s suite, so
   `_OBSERVED_PUBLISHES` is 2000 and the spec's "Still declined here" paragraph
   is replaced by what was measured rather than restated.

Also addressed, both raised as open concerns rather than findings:

* `assertEqual(absent, 0)` would have passed VACUOUSLY if a future publish
  stopped touching the observed path -- the `exists()` guard, not the
  observation, was carrying that. The record's bytes are now captured before the
  run and required to CHANGE after it; the record carries the writer's pid and a
  fresh heartbeat, so this proves the name observed is the name republished.
* `TMPDIR` on NFS/overlay stays untested and is now RECORDED in the spec: both
  halves assume ordinary POSIX rename and stat semantics, and a filesystem that
  does not provide them surfaces as an ERROR, not a silent pass.

Finding 3 (LOW) is deliberately unchanged: `_watch_publish`'s `Path.rename`,
`Path.replace` and `Path.write_text` arms are redundant with the `os.*`/`io.open`
ones CPython delegates to, so one `Path.rename` records two removals. The
assertions are "this list is empty", so the duplicate is harmless, and the arm
keeps the pin honest if CPython ever stops delegating. The spec now says so.

`scripts/agent-role.py` is untouched: no product behaviour changes.

Mutation matrix at the shipped sizing, 10 runs per cell, load 185 multi-core and
262 pinned to `taskset -c 3` -- the three historical escapes still go RED, and
the shipped publish never does:

| publish | watcher | observer multi | observer 1-core | hardlink | residue |
|---|---|---|---|---|---|
| `os.rename` + `open` | 10/10 | 10/10 | 9/10 | - | - |
| `unlink` + `write_text` | 10/10 | 10/10 | 10/10 | - | - |
| byte-at-a-time in place | - | - | - | 10/10 | - |
| bytes, basename unlink, rename in | - | 10/10 | 10/10 | - | - |
| shipped temp + `os.replace` | 0/10 | 0/10 | 0/10 | 0/10 | 0/10 |

Unmutated flake rate over repeated runs at load average 397-415: observer 0/40
and watcher 0/40, multi-core and pinned to one core alike; slowest observer run
0.92s against the 60s deadline. Poll counts 148k-257k per run, against a floor
of 2000.

Gates: test_agent_role 60, test_agent_onboard 39, test_agent_start 20 = 119, all
green, no count change. `scripts/agent-preflight.sh --quiet` green before the
first edit and after the commit (with `--no-require-role`: this session declared
no role, so the role gate would report its own state, not the tree's). Rebased
onto origin/main 2430636; the #296 roadmap intake row survived.

FOLLOWING_AGENTS_PROTOCOL

Following-Agents-Protocol: true
AI-Assisted: true
Assisted-by: Claude-Code:claude-opus-5 [Claude Code]
@localai-bot
localai-bot merged commit 688eea1 into main Aug 10, 2026
10 of 13 checks passed
localai-bot pushed a commit that referenced this pull request Aug 11, 2026
main advanced by ten commits while the six external PRs were being reviewed and
merged (SILU-VECTORIZE, SERVE-METRICS-ASYNC #277, SAMPLE-LOGPROBS-RECORD-REPAIR
#259, PERF-27B-LMHEAD-DSR #298, PERF-35B-SHARED-DOWN-BF16, ENG-OPERATOR-RECORD-
COVERAGE-FIX #304, release #303). Resolved rather than re-based so nothing of
either side is lost.

  - .agents/roadmap_v1.md: issue rows are DISTINCT keys, so the two sides union
    -- main's #298 alongside this landing's #269/#305/#206.
  - .agents/NOW.md: main's 35B mid-band row is NEWER (two levers landed, not
    one) and was taken wholesale; only the Qwen3.5-4B row was reapplied on top,
    with main's row verified byte-present afterwards. The "next actions" hunk
    kept this side's item 3, which post-dates main's copy.
  - .agents/benchmark-record.md union-appended, main's entries first.
  - tests/vllm/v1/test_async_llm.cpp: both sides add a distinct `using`
    declaration (PublishAsyncRequestWaveIfAlive from #266, PrometheusStatLogger
    from #277) -- union, not a choice.
  - scripts/check-public-doc-tables.py: main had re-pinned the STATUS ratchet to
    243512 for #277 while this landing had reconciled #155 and #266 to 243455.
    Both rationale histories are kept and the value re-MEASURED on the merged
    page: 243368. Strictly down, the only direction it may move; the byte-tight
    test asserts equality, so this is measured, never predicted.

Doc-table checker and its 54 unit tests green; clean CPU build.

FOLLOWING_AGENTS_PROTOCOL

Following-Agents-Protocol: true
AI-Assisted: true
Assisted-by: Claude:claude-opus-5 [ClaudeCode]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Two known limitations recorded when #285 landed: a stale TTL comment and a publish-NAME pin that os.rename escapes

2 participants