Skip to content

fix(liveness): tolerate ±2s cross-process probe drift in pid liveness fingerprints - #117091

Open
emirsaffar-collab wants to merge 2 commits into
NousResearch:mainfrom
emirsaffar-collab:upstream-pr/liveness-drift-tolerance
Open

emirsaffar-collab wants to merge 2 commits into
NousResearch:mainfrom
emirsaffar-collab:upstream-pr/liveness-drift-tolerance

Conversation

@emirsaffar-collab

Copy link
Copy Markdown

Problem

Processes on one host read the same pid's start time with ~1s disagreement (observed +1.00 s exactly: 178978036115 recorded vs 03:12:40.15 kernel). Bit-exact start-time compares in liveness predicates then declared live owners dead/recycled:

  • cron/executions.py _owner_is_live reclaimed 9 running executions (reclaim-job falsely swept live jobs).
  • Sibling predicates had the same bit-exact class: gateway/status.py (_pid_marker_names_self, _scoped_lock_owner_state, _validated_scoped_lock_gateway_owner), gateway/delivery_ledger.py (_owner_alive), hermes_cli/kanban_db_dispatch.py (_pid_recycled) — drift made a live scoped-lock owner read "exited" (lock stolen while held) and a live worker read "recycled" (termination refused for the wrong pid).

Fix

  • New helper gateway.status.start_times_match(current, recorded, *, tolerance=200): ±2 native units (centiseconds: psutil create_time()*100 on macOS, /proc field 22 at USER_HZ=100 on Linux — same scale on both), False on junk, documented int() coercion.
  • All five liveness predicates route through it. Probe-None → live in liveness contexts (unprobeable ≠ dead).
  • Kill-permission gates (_start_times_agree force-kill, pid_is_hermes) deliberately stay bit-exact: a refused kill is fail-safe, a wrongly permitted one is not.
  • String fingerprints (kanban dispatch) keep the epoch part exact — cross-boot reuse still detected; only the start-time component widens.

Tests (18 new, all green; drift polarity empirically verified to fail on pre-fix sources)

  • tests/cron/test_owner_liveness_fingerprint.py — drifted live owner stays live; far/recycled still detected; probe-None stays live; boundary ±200 inclusive.
  • tests/gateway/test_liveness_fingerprint_tolerance.py — same polarities for all five sibling predicates + _validated_scoped_lock_gateway_owner corroboration compare.

Independent reviewer verdict: APPROVE (two-pass).

Owner liveness compared the start-time fingerprint bit-exact and treated an
unprobeable pid as dead. Observed 2026-09-19: one process read its own start
time +1.00s later than every other probe of the same pid; recover_interrupted_
executions then marked six live mid-flight executions unknown as 'owner
process died' (owners were alive and running: gateway 19577, desktop 93220).

- tolerate ±2s probe drift (native units ≈ 1/100s on macOS and Linux): PID
  reuse shifts start times by minutes-to-days, so reuse detection stays exact
- an unprobeable pid that exists is no longer proven dead (guard doctrine:
  inability to prove death must not rewrite state)
- tests cover both polarities: drifted-live owner is not reaped, genuinely
  dead owner is
Estate-wide follow-up to 3f84079 (cron _owner_is_live): the same
bit-exact start-time compares declared LIVE owners dead/recycled in
gateway/status.py, gateway/delivery_ledger.py and
hermes_cli/kanban_db_dispatch.py when cross-process probe drift
(+1.00s observed, kernel vs psutil) hit liveness verdicts.

- gateway/status.py: new start_times_match(current, recorded, *, tolerance=200)
  (centiseconds on both macOS psutil*100 and Linux /proc field 22 at
  USER_HZ=100). Widened ONLY at liveness call sites
  (_pid_marker_names_self, _validated_scoped_lock_gateway_owner,
  _scoped_lock_owner_state). int() coercion accepts numeric-string
  start_time records that bit-exact != rejected; junk still fails the
  match (documented).
- gateway/delivery_ledger.py: _owner_alive drift-tolerant via lazy
  start_times_match import (lazy keeps monkeypatched tests working);
  narrow except widened to Exception for import-failure consistency.
- hermes_cli/kanban_db_dispatch.py: _pid_recycled — string-branch epoch
  part stays EXACT (cross-boot), start-time part tolerant; integer-rows
  tolerant. Dead _start_times_agree import removed.
- kill-permission gates (_start_times_agree force-kill, pid_is_hermes
  taskkill) deliberately stay bit-exact: a refused kill is fail-safe.

[verified] reviewer deleg_8fab47aa verdict: APPROVE, 4 LOW findings
all addressed (int-coercion docs, dead import removed, 3 test gaps
filled, lazy-import except widened). Tests: fingerprint-tolerance
10/10; neighbors green: delivery_ledger 39, dispatch_lock 2, reaper 4,
reclaim 2, worker_pid_fingerprint 4, cron 1479 (pre-suite). Full-suite
failures (8) verified PRE-EXISTING on stashed clean tree (incl.
test_completion_delivery F+hang — reproduced identically without this
diff).
@alt-glitch alt-glitch added type/bug Something isn't working P2 Medium — degraded but workaround exists comp/cron Cron scheduler and job management comp/gateway Gateway runner, session dispatch, delivery comp/cli CLI entry point, hermes_cli/, setup wizard sweeper:risk-message-delivery Sweeper risk: may drop, duplicate, misroute, or suppress messages labels Sep 20, 2026
@Enough1122

Copy link
Copy Markdown

AI code review — automated review for reference; please use your judgment.

This PR replaces bit-exact pid start-time compares with a ±200-native-unit tolerance across the cron, gateway, and kanban liveness paths, keeping the kill-permission gates exact. The direction matches the 2026-09-19 RCA (cross-process probe drift reaped live owners) and the fail-safe polarity (unprobeable means alive) is preserved. One robustness regression and one doc nit below; nothing blocking.

  1. Unguarded int() on a DB-sourced value can abort the whole recovery sweep — cron/executions.py:147 (non-blocking). return abs(current - int(started_at)) <= 200 raises ValueError when process_started_at holds non-numeric text. SQLite columns are loose-typed, and the sole caller (recover_interrupted_executions, cron/executions.py:287) loops rows inside one transaction with no per-row guard, so one corrupt row aborts the entire sweep via rollback. The old current == started_at comparison never raised. Suggested fix: coerce defensively, e.g. wrap in try/except and return True (fail-safe alive, consistent with this module's doctrine), or validate with start_times_match-style handling that fails closed to alive.

  2. Junk live-probe polarity flipped in delivery_ledger — gateway/delivery_ledger.py:257 (non-blocking). The old int(current_start) == int(started_at) raised on a non-numeric live probe and fell into except → return True (alive); the new start_times_match(current_start, int(started_at)) returns False for junk current_start, declaring the owner dead. _start_time() returning junk is unlikely in practice, but if you want strict polarity preservation, treat a non-numeric live probe as alive.

Minor:

  • start_times_match docstring says "same start within ±2 native units" (gateway/status.py:286) while the default tolerance is 200 native units (≈2 s). Reword to "within ±200 native units (≈2 s)" to avoid misreading.

@youyoutu405-source

Copy link
Copy Markdown

+1 with an independent live occurrence of the exact-compare class, this time through the kanban crash sweep (_pid_recycled string path), observed 2026-09-23 on macOS (Apple silicon, psutil centisecond basis; same comparison verified present on origin/main @ 5f47c35d37, kanban_db_dispatch.py L406):

  • Worker PID 36506 spawned 10:24:43 (live re-derivation of its start fingerprint: 179013028315, fraction .15; epoch half empty on macOS). The spawn-time recorded fingerprint was |179013028515 — a constant +2.00 s (exactly 200 cs, identical fractional part), with no sleep/wake in the window, so this is a probe-basis disagreement rather than accumulated sleep drift.
  • Same dispatcher tick loop, 17 s apart: 12:59:10 claim_extended (reason: pid_alive) and 12:59:27 crash-sweep crashed (pid 36506 not alive). The two predicates read different datasources: the stale-claim path read the tasks.worker_started_at column (empty on this row → legacy-lenient, existence-only) while the crash sweep compared the run's spawned fingerprint with != (drifted → "recycled").
  • Net effect: two gave_up breaker bookings (12:59:27, 15:36:29) against a worker that was alive the whole time (10:24→15:37, task log advancing seconds before each sweep; it later exited on its own iteration budget). The card hit the failure limit and stayed blocked with zero actual worker deaths; recovery required a manual unblock.

The observed delta (+200 cs) lands exactly on this PR's inclusive ±200 boundary, so routing _pid_recycled's start-time half through the shared tolerant comparator (keeping the epoch half exact) would have kept both runs alive here. We carry an equivalent local patch with a drift-boundary regression test (±200 keeps the claim / ±201 is a stranger / neither path ever signals a drifted fingerprint) in tests/hermes_cli/test_kanban_worker_pid_fingerprint.py — happy to rebase it onto this PR's helper if useful.

@Enough1122 Enough1122 left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Verdict: COMMENT — 你的 +1 证据已收到且行号准确,但 PR 现状需要 rebase + 砍重复

@youyoutu405-source 你引用的 hermes_cli/kanban_db_dispatch.py 字符串路径行号与实文完全一致,这条独立复现(macOS Apple silicon,psutil centraction 精度、2026-09-23 走 kanban crash sweep 的 _pid_recycled)对我很有用 —— 而且你确认了同一比较在 origin/main 上存在,说明不是 PR 引入的。

但当前状态有两件事要先处理:

  1. PR 现为 CONFLICTING / DIRTY,需先 rebase。
  2. main 已合入重叠修复 #117584(36ede56a6,09-20):start_time_fingerprints_match(gateway/status.py:440)现已被 cron _owner_is_live 和 delivery_ledger._owner_alive 使用,本 PR 的 cron / ledger 部分已冗余。

仍有价值的缺口是这三处(都还是裸 ==):gateway/status.py:1617、:1731,以及 hermes_cli/kanban_db_dispatch.py:406 的字符串路径 —— 后者正是你这次踩到的那条。我 09-20 的 review 之后没有新 commit。

建议:rebase 后砍掉与 #117584 重复的部分,只保留这三处缺口再推进;另外你观察到的 +200cs 恰好落在含边界上(±2s 窗口刚好盖住),这个 case 也请一并加进测试。

@youyoutu405-source

Copy link
Copy Markdown

Follow-up to my earlier field report (+200 cs start-time drift on macOS, kanban crash-sweep path). We ran a full verification campaign against this PR head (7f75b15d06, base 9573f44ca5, 2 commits — 9d64ad9924 + 7f75b15d06, 6 files, +309/−9), with every finding independently re-executed in a second pass. Summary:

1. Regression surface — 0 PR-introduced failures. The 18 new tests pass. Two-sided runs of tests/cron, tests/gateway, and the liveness/kanban slices of tests/hermes_cli on head vs base give 71 failures = 69 pre-existing + 2 flaky, matched per-test on both sides (5×/tree three-way comparison; the 2 flip tests touch no symbol in this diff).

2. Boundary polarities. ±200 inclusive → owner kept (alive); ±201 → dead/stranger; live-probe None → alive (unprobeable ≠ dead); epoch mismatch (cross-boot pid reuse) → dead. Each recorded as its own outcome (PASS/FAIL/PASS/FAIL), not masked as "all true".

3. Enough1122's point 1 — confirmed, and worse than one corrupt row. The bare int(started_at) at cron/executions.py:147 raises ValueError on a non-numeric process_started_at, escaping from the :300 call site; since recover_interrupted_executions runs the rows inside a single _transaction(), the entire sweep rolls back — in our repro the junk row's batch stayed all-running while a control batch flipped to unknown normally. The suggested fix matches the review: coerce defensively and fail safe to alive (this module's doctrine), e.g. wrap the conversion in try/except (TypeError, ValueError): return True, or route it through start_times_match-style handling that fails closed to alive.

4. Enough1122's point 2 — confirmed, plus a downstream hazard. Polarity flip reproduced: the pre-diff tail except (TypeError, ValueError): return True (alive) becomes start_times_match(junk, …) → False (dead), and the outer except Exception: return True is now unreachable because start_times_match swallows (TypeError, ValueError) internally. Additional observed consequence: with the owner misjudged dead, sweep_recoverable re-claims pending delivery rows from a live owner — a duplicate-delivery path (right on the sweeper:risk-message-delivery axis). Suggested fix: treat a non-numeric live probe as alive, restoring the fail-safe/tri-state polarity.

5. _pid_recycled string fingerprint. Confirmed the PR routes only the start-time half through start_times_match (kanban_db_dispatch.py:399-427) with the epoch half kept exact. Three-state boundary verified, including our real incident shape (+200 cs, identical fraction): owner kept; ±201 cs → recycled; epoch change → recycled; legacy integer rows share the boundary. We have a regression test ready to contribute (tests/hermes_cli/test_worker_pid_recycled_boundary.py, 10/10: ±200 keeps the claim, ±201 is a stranger, epoch reuse still detected) — the same offer as in my previous comment.

6. Kill-permission gates untouched. start_times_match appears only in the liveness predicates; _start_times_agree (force-kill) and pid_is_hermes / _subprocess_compat.py:421,430 remain bit-exact (diff-grep + direct read). Tolerance stays out of the kill path — as designed.

7. Live sweep check on a real host. On an isolated probe board (production board left zero-residue, verified): crash-sweep/claim on PR code keeps a live worker carrying a +200 cs drifted fingerprint (no crashed/recycled, zero kill signals) and still reclaims a genuinely dead pid.

Minor: start_times_match's docstring says "±2 native units" while the default tolerance is 200 native units (≈2 s) — worth rewording.

Overall: the fix direction is validated end-to-end — drift is tolerated exactly where it must be and comparisons stay bit-exact where they must be — and the inclusive ±200 boundary happens to cover our live +200 cs incident exactly. We'd suggest landing points 3 and 4 (both "fail safe to alive") with this PR or as an immediate follow-up: point 4's dead-owner verdict can reach sweep_recoverable and double-deliver. Verification commands and outputs are archived on our side (reports + repro scripts); happy to share specifics on request.

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

comp/cli CLI entry point, hermes_cli/, setup wizard comp/cron Cron scheduler and job management comp/gateway Gateway runner, session dispatch, delivery P2 Medium — degraded but workaround exists sweeper:risk-message-delivery Sweeper risk: may drop, duplicate, misroute, or suppress messages type/bug Something isn't working

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants