Skip to content

feat(observability): classify a run as working / stalled / crashed / done - #218

Open
OsherElhadad wants to merge 5 commits into
mainfrom
feat/issue-118-stall-detection
Open

feat(observability): classify a run as working / stalled / crashed / done#218
OsherElhadad wants to merge 5 commits into
mainfrom
feat/issue-118-stall-detection

Conversation

@OsherElhadad

Copy link
Copy Markdown
Collaborator

Closes #118

Built directly on #191 (issue #116), which landed the shared event tail specifically for this: follow_events(..., idle_timeout=None) left the stall threshold for me to define, and the typed {"kind": FOLLOW_END, "reason": ...} sentinel already distinguishes finished from went quiet from stopped. This PR turns that distinction into a named, surfaced state.

Before → After

Before. A hung run masqueraded as finished. The SSE stream closed after a fixed ~5 idle minutes (app.py:116) and the UI flipped to "idle" — which reads like completion, not a hang. And _status (runs.py:43-51) was coarse enough that a run which produced one candidate and then crashed showed live forever.

After. Every surface reports one of four states, from one classifier:

means
live last event is within what this run has already shown itself capable of
stalled silent longer than that, process still alive/unknown — probably wedged
crashed the process that owned the run is provably gone and it never finalized
done finalize sealed the test — terminal, nothing downgrades it
$ cap-evolve tail /tmp/e118b/.capevolve/run_killed --from-start
[02:54:58] ACCEPT  cand_0001  val=1.0000 (parent 0.0000)  — paired Δ̄=+1.0000 > 0
CRASHED — the process that owned this run is gone and it never finalized (last event 1s ago)
$ echo $?
5

Design decision 1: the threshold, and why it won't false-alarm

A fixed 5-minute idle timeout is wrong in both directions. A toy run is silent that long only if it is dead; one τ²-bench rollout with 50 tool calls can legitimately take 20 minutes. And the two errors are not symmetric: a false "hung" is worse than no signal at all, because the user's reaction to "hung" is to kill a run that was working — and that run cost money.

So the expectation is derived from the same run:

threshold = max(300s, 3 × the slowest inter-event gap this run has already produced)

Three deliberate choices:

  • max, not a mean or a quantile. A run alternating 1s evals with 20-minute optimizer calls has a mean of a couple of minutes — a mean-based bar would fire during every optimizer call. The slowest thing the run has already done is the only defensible estimate of the slowest thing it might do next.
  • The bar only rises. The run that sets the bar is the run judged by it. A workload that takes 20 minutes a step raises its own bar to an hour instead of tripping a global constant. It never vanishes, though — a genuinely wedged slow run still trips at 3× its own worst gap (tested).
  • 300s is the floor, not the rule. The old hard-coded SSE number is demoted: it stops a run whose first two events landed 40 ms apart from being declared hung 120 ms later.

Configurable: CAPEVOLVE_STALL_SECONDS=N pins a fixed number for a user who knows their workload better than the heuristic does; cap-evolve tail --no-stall-check opts out entirely.

One subtlety worth naming: tail without --from-start prints only new events, but the bar is derived from the whole log — otherwise attaching mid-run to a 20-min-per-step run would see no gaps at all, fall back to the 300s floor, and report a healthy run hung. That is test_tail_attaching_mid_run_uses_the_whole_log_not_just_what_it_streamed.

Design decision 2: liveness — is the process gone, or just quiet?

In an append-only log a dead run and a slow run look identical, so the log alone cannot answer it. There was no liveness signal, so this PR adds the cheapest possible one: cap-evolve run writes a small run.pid ({pid, host, started}) into the run dir — one write, once — and never deletes it. Once the process exits, its pid stops existing, and that absence is the signal. Deleting the marker on exit would erase the evidence.

Liveness is deliberately three-valued, and only a definite "this pid is gone" yields crashed:

  • pid missing from this host's process table → Falsecrashed
  • pid exists (incl. PermissionError: owned by another user) → True
  • None (unknown) — a pid recorded on another host (shared filesystem), an unparseable marker, or no marker at all (the per-phase /cap-evolve:baseline … skill chain has no single long-lived owner). Never reported crashed; can still be reported stalled.

No heartbeat event was added: it would mean touching the harness and every algorithm's hot loop, and run.pid + the events file's own mtime answers the same question for free. (ponytail: pid-only liveness could in principle hit a recycled pid — needs ~32k intervening spawns and the same host, and the failure direction is the safe one: a dead run looks quiet, not a live run looking dead. Upgrade path is a pid+start-time pair, noted in the code.)

Silence is measured from the events file's mtime, not from the last event's t: t is wall-clock recorded by the writer and can be skewed or malformed (log_event serialises with default=str), while mtime is the filesystem's own answer to "when did this run last make a noise".

Design decision 3: what the dashboard shows, and finished runs

  • Hub row and GET /api/runs/{id} both carry status plus a liveness object (silence_seconds, stall_threshold_seconds, slowest_gap_seconds, process_alive, and a one-sentence detail). Same key, same computation, same function — so the two payloads cannot disagree.
  • StatusBadge gains stalled (amber triangle) and crashed (red plug); color is never the sole signal (icon + label always), and the detail sentence is the accessible title, because a user deciding whether to kill a run needs the bar, not just the word.
  • The SSE route no longer drops the connection on a fixed idle period. It periodically emits a typed status frame naming which kind of quiet the run is in — which doubles as the keepalive, so an idle proxy has traffic to see — and closes only on a proven crash. Never as done: done means sealed. The old ambiguous idle frame is gone.
  • Degrades sanely for a finished run: done outranks both stall and crash, so a run finalized 30 days ago whose process is long gone reads a clean done, not crashed. Tested explicitly.

liveness is computed per request, outside reduce_run — deliberately. That reducer is cached on the run's on-disk stamp (#119 / PR #194), and "how long has this run been silent" is precisely the one fact that changes while nothing on disk changes; a cached answer would be permanently 0s. This is also how the change composes with #194: it adds no field to the cached reduction and touches neither _reduce nor the cache key.

A bug the real evidence caught: for a run whose log carried finalize but whose final.json/splits.json lagged, liveness said done while _status still said live — the two surfaces disagreeing about the same run dir, which is the exact failure this issue exists to remove. _status now accepts either the sealed artifacts or the finalize event; they are the same fact seen through the log vs the artifacts (second commit).

Verification

Real end-to-end, zero API cost (examples/toy_calc + mock optimizer)

(a) A run that completes → done. Real cap-evolve run --follow, then tail on the finished dir:

[02:54:37] splits frozen  train=4 val=2 test=2 (test sealed)
[02:54:37] baseline  val=0.0000 ±0.0000
[02:54:38] ACCEPT  cand_0001  val=1.0000 (parent 0.0000)  — paired Δ̄=+1.0000 > 0
[02:54:39] reject  cand_0002  val=1.0000 (parent 1.0000)  — paired Δ̄=+0.0000 <= 0
[02:54:40] reject  cand_0003  val=1.0000 (parent 1.0000)  — paired Δ̄=+0.0000 <= 0
[02:54:40] FINALIZE  test=1.0000 (baseline 0.0000, Δ+1.0000)  best=cand_0001
done — finalize sealed the test split
tail exit=0

run.pid written by the run: {"pid": 14610, "host": "Oshers-MacBook-Pro-2.local", "started": 1785369277.9289129}

(b) A run SIGKILLed mid-flight → crashed. The run process (and its tree) is kill -9ed after baseline + one accepted candidate; no finalize in the log:

--- events so far:        6 ---
--- killed pid 15109; run.pid on disk: {"pid": 15109, "host": "Oshers-MacBook-Pro-2.local", ...} ---
0        (grep -c finalize → no finalize event, as expected)
[02:54:58] splits frozen  train=4 val=2 test=2 (test sealed)
[02:54:58] baseline  val=0.0000 ±0.0000
[02:54:58] ACCEPT  cand_0001  val=1.0000 (parent 0.0000)  — paired Δ̄=+1.0000 > 0
CRASHED — the process that owned this run is gone and it never finalized (last event 1s ago)
tail exit=5

(c) A deliberately SLOW run → stays working. A live run with real 150-second steps, then 380s of genuine silence — past the old 300s rule — before finalizing. Sampled every 30s against both rules:

03:04:58 silence= 112.2s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:05:28 silence= 142.2s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:05:58 silence= 172.4s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:06:28 silence= 202.5s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:06:58 silence= 232.6s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:07:28 silence= 262.7s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:07:58 silence= 292.8s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:08:28 silence= 322.9s  OLD_5MIN_RULE=WOULD FIRE  NEW status=live  threshold=450s
03:08:58 silence= 353.0s  OLD_5MIN_RULE=WOULD FIRE  NEW status=live  threshold=450s
03:09:29 silence=   3.1s  OLD_5MIN_RULE=quiet ok    NEW status=done  threshold=1140s

This is the money row. The old fixed rule would have called this run hung — twice — and it went on to finish successfully. The live tail attached to it, verbatim:

03:00:59 | [02:55:35] splits frozen  train=4 val=2 test=2 (test sealed)
03:00:59 | [02:58:05] eval val/cand_0001  reward=1.0000 ±0.0000  150.0s
03:00:59 | [03:00:35] eval val/cand_0002  reward=1.0000 ±0.0000  150.0s
03:03:06 | [03:03:05] eval val/cand_0003  reward=1.0000 ±0.0000  150.0s
03:09:26 | [03:09:25] FINALIZE  test=1.0000 (baseline 0.0000, Δ+1.0000)  best=cand_0001
03:09:26 | done — finalize sealed the test split
tail finished at 03:09:26

Note the threshold tracking the run: 450s while its worst gap was 150s, 1140s once it had demonstrated a 380s gap. The bar rose because the run earned it.

The surfaces agree — same three run dirs, both surfaces

=== (a) COMPLETED run: GET /api/runs ===
  run_id=run_done  status='done'
    liveness.status='done'  silence=976.7  threshold=300.0  slowest_gap=0.81  process_alive=False
    detail=done — finalize sealed the test split
  GET /api/runs/run_done -> summary.status='done' (matches hub row: True)

=== (b) KILLED run: GET /api/runs ===
  run_id=run_killed  status='crashed'
    liveness.status='crashed'  silence=958.5  threshold=300.0  slowest_gap=0.76  process_alive=False
    detail=CRASHED — the process that owned this run is gone and it never finalized (last event 16.0m ago)
  GET /api/runs/run_killed -> summary.status='crashed' (matches hub row: True)

=== (c) SLOW-but-healthy run: GET /api/runs ===
  run_id=run_slow  status='done'
    liveness.status='done'  silence=91.4  threshold=1140.1  slowest_gap=380.0  process_alive=False
    detail=done — finalize sealed the test split
  GET /api/runs/run_slow -> summary.status='done' (matches hub row: True)

Terminal, on the same three dirs: done (exit 0) / CRASHED (exit 5) / done (exit 0). Dashboard done / crashed / done = terminal done / crashed / done.

Suites

$ PYTHONPATH=core python -m pytest core/tests -q
238 passed in 68.49s (0:01:08)

Baseline on this branch's base (main + #191) is 217 → +21, 0 failed.

$ cd dashboard/backend && PYTHONPATH=../../core:. python -m pytest tests -q
56 passed, 1 warning in 2.08s

(42 before → +14.)

$ python -m compileall -q core skills && echo CLEAN
CLEAN

Frontend (CI never runs vitest — #207 — so run locally):

$ npm ci && npm test
 Test Files  14 passed (14)
      Tests  53 passed (53)
$ npx tsc -b --noEmit   # rc=0
$ npm run build         # ✓ built in 610ms

dashboard/frontend/dist/ is not committed, per epic #127's policy (#188 rebuilds it once after the frontend PRs land).

The tests that matter

Test Asserts
test_a_slow_but_healthy_run_is_never_called_hung the critical negative case — 20-min steps, 25 min quiet, silence > 300s yet live; and it does fire at 4× its own gap
test_a_slow_but_healthy_run_is_not_reported_stalled same, through the hub API
test_tail_does_not_stall_out_a_slow_but_healthy_run same, through the CLI
test_tail_attaching_mid_run_uses_the_whole_log_not_just_what_it_streamed attaching without --from-start must not fall back to the floor
test_a_toy_run_still_gets_the_five_minute_floor the other direction: 40 ms gaps must not derive a 120 ms bar
test_threshold_uses_the_slowest_gap_not_the_mean why max, not a mean
test_a_finalized_run_is_done_even_when_ancient_and_processless a finished run degrades to done
test_a_pid_from_another_host_is_unknown_not_dead / test_no_pid_file_means_unknown_never_crashed crashed requires proof
test_stream_sends_a_status_frame_naming_the_stall the ambiguous idle close is gone; a stall is never a done frame
test_a_finalize_event_alone_is_enough_to_report_done the two surfaces cannot disagree about a sealed run
test_dashboard_classifies_through_the_shared_helper_not_its_own_rule the dashboard owns no threshold of its own

Expected merge order

  1. feat(observability): live terminal progress via --follow and cap-evolve tail #191 (issue Classic cap-evolve run is silent for its entire duration — add --follow / cap-evolve tail #116) — this branch is built on it; eventstream.py must land first. (This branch = origin/main + feat(observability): live terminal progress via --follow and cap-evolve tail #191 + these two commits, so a merge after feat(observability): live terminal progress via --follow and cap-evolve tail #191 is a clean fast-forward-shaped diff.)
  2. This PR (Distinguish a stalled/hung run from idle/done (SSE 5-min idle + coarse status heuristic) #118).
  3. perf(dashboard): memoize reduce_run on events mtime+size, drop dead SSE snapshot, paginate runs/rollouts #194 (issue Dashboard re-reduces the full event log on every request/SSE tick — cache by mtime; drop dead SSE snapshot #119) — orthogonal by construction (liveness deliberately stays out of the cached reduce_run; no shared line in runs.py beyond the list_runs signature, and no overlap in app.py past the snapshot frame). Either order works; after perf(dashboard): memoize reduce_run on events mtime+size, drop dead SSE snapshot, paginate runs/rollouts #194 the SSE snapshot frame carries only {run_id}, which this PR does not depend on.
  4. Demo-first onboarding: shareable, scrubbable run-replay artifact ("watch it before you configure") #122 (replay) / Terminal/TUI robustness: no-TTY/CI degradation ladder + crash/forensic log #144 (no-TTY ladder) — also on eventstream; no conflict with the new classify/liveness_facts surface.
  5. Committed dashboard dist/ with hashed filenames makes every concurrent frontend PR conflict, and can silently ship a stale bundle #188 — rebuild dist/ once, after the frontend PRs.

House rules

Zero new runtime deps in core (eventstream.py additions use json, os, socket, time, pathlib only). New tests in core/tests/ (+ the dashboard's own tests/). harness.py untouched: the run already logged everything needed, which is why the diff is small.

Osher Elhadad added 4 commits July 30, 2026 00:34
…ve tail

A classic `cap-evolve run` was completely silent for its whole duration: every
phase ran under subprocess.run(capture_output=True), so a multi-hour hill-climb
showed a blank terminal until it returned one JSON blob — and a hung run was
indistinguishable from a working one. The only live view was the web dashboard,
which leaves CI/ssh/headless/air-gapped users with nothing.

- New core module `cap_evolve.eventstream` (stdlib only, zero new deps): the ONE
  place that reads a run's events.jsonl. read_new_events() (byte-offset
  incremental read, partial trailing line left unconsumed), follow_events()
  (blocking generator that waits for the file, stops on finalize/idle/signal),
  and format_event()/render_line() (one human-readable line per event, ANSI
  applied only by render_line).
- `cap-evolve run --follow`: prints stage transitions, baseline, per-candidate
  accept/reject with candidate id + val + reason, budget warnings, optimizer
  errors, finalize, plus a cumulative cost/token meter. Progress goes to STDERR
  so stdout stays the machine-readable final JSON scripts parse. Runs on a
  daemon thread started before baseline creates the run dir, so the first
  events are never missed; it can never raise into the run.
- `cap-evolve tail [run_dir]`: attaches to an existing or ongoing run (default:
  newest run_* under --base). Waits for the run dir to appear, so you can attach
  before the run creates it. --from-start replays history.
- The dashboard's SSE route now imports read_new_events from the shared core
  helper instead of owning its own copy, so terminal and web read the same typed
  event stream and can never disagree. #118 (stall detection), #122 (replay),
  #138 and #144 build on this module.
- Degrades cleanly with no TTY: plain text when piped, in CI, or under NO_COLOR.

Closes #116
…ion, honest cost, stderr safety

Review fixes for #191 (hub PR for #118/#122/#138/#144).

- A malformed event no longer kills the follower thread. format_event is total
  (non-dict / bad `t` degrade to None or `--:--:--`), and cli.py reports on stderr
  instead of swallowing, so a dead follower is never mistaken for a silent run —
  the exact bug #116 exists to fix.
- read_new_events returns only JSON objects, so no consumer (CLI or dashboard SSE)
  receives a bare 42/null/[1,2]; unreadable records surface as a log_corruption
  event instead of vanishing.
- All rendered text is sanitised: C0/C1 controls and ESC sequences are stripped and
  newlines collapse, so an optimizer's stderr cannot set the window title, clear the
  screen, or forge a fake FINALIZE line.
- The cost meter no longer double-counts: runner spend from `evaluate`, optimizer
  spend from `step`-likes, intake from `intake` — matching Spent.total_usd. Exposed
  as public accrue_totals so #138 does not fork the arithmetic.
- --follow disables itself when stderr is unusable (`2>&-`) rather than letting
  progress corrupt the stdout JSON contract.
- Hub API: follow_events yields a typed _follow_end sentinel naming its exit reason
  (stop_kind/idle/should_stop) for #118, should_stop now receives the last event, the
  300s idle_timeout module default is gone, a shrunk file re-reads from 0 for #122,
  and format_event(skip_kinds=()) exposes bookkeeping kinds for #138.
- tail exits 2 on an impossible run dir and 3 on an idle timeout with no events;
  --resume --follow no longer replays the whole prior log; use_color requires its
  stream; negative --idle-timeout is rejected.
…done

Closes #118

A hung run used to masquerade as finished. The dashboard's SSE stream closed after a
fixed ~5 idle minutes and the UI flipped to "idle" — which reads like completion — and
the hub's `_status` left a run that produced one candidate and then crashed as `live`
forever. Both surfaces are now driven by ONE classifier in
`cap_evolve.eventstream` (built on #116's shared event tail), consumed by
`cap-evolve tail`, `run --follow`, the hub row, the DeepDive header and the SSE route,
so the terminal and the web UI cannot disagree about the same run dir.

The threshold is derived from the run, not a constant. A fixed 5 minutes is wrong in
both directions: a toy run is silent that long only if it is dead, while one τ²-bench
rollout can legitimately take 20 minutes, and a false "hung" is the worst outcome
available because the user's reaction is to kill a working run. The bar is
`max(300s, 3 × the slowest inter-event gap this run has already shown)` — max, not a
mean, because a run alternating 1s evals with 20-minute optimizer calls has a small
mean and a mean-based bar would fire during every optimizer call. So the run that sets
the bar is the run judged by it, and it only ever rises. `CAPEVOLVE_STALL_SECONDS`
pins a fixed number for a workload the user knows better than the heuristic does.

Liveness needs proof, so `cap-evolve run` writes a small `run.pid`
(`{pid, host, started}`) into the run dir and never deletes it: after the process exits
the pid stops existing, and that absence is what separates "dead" from "alive but
quiet". A pid from another host, or no pid file at all (the per-phase skill chain has no
single owner), reads as *unknown* and is never reported crashed. `done` outranks
everything, so a finished run degrades to a clean `done` however long ago it ran.

- `cap-evolve tail` exits 4 on a stall and 5 on a crash and prints the verdict with its
  numbers on stderr, instead of a silence that reads like success. `--no-stall-check`
  opts out; `--idle-timeout` now bounds only the wait for the FIRST event.
- `run --follow` warns once when the run goes quieter than its own pace and re-arms when
  progress resumes — it warns rather than stopping, because whether a wedged phase is
  worth killing is the user's call.
- The SSE route no longer drops the connection on a fixed idle period: it periodically
  emits a typed `status` frame naming which kind of quiet the run is in (doubling as the
  keepalive) and closes only on a proven crash — never as `done`, which means sealed.
- `liveness` is computed per request, deliberately outside `reduce_run`: that reducer is
  cached on the run's on-disk stamp (#119), and "how long has this run been silent" is
  the one fact that changes while nothing on disk does.

37 new tests (21 core + 13 dashboard backend + 13 frontend), including the negative case
that matters most: a 20-minute-per-step run quiet for 25 minutes stays `live` on every
surface, where the old fixed rule called it hung.
Caught by the real end-to-end evidence: for a run whose log carried `finalize` but whose
final.json/splits.json lagged, `liveness.status` said `done` while `_status` still said
`live` — the two surfaces disagreeing about the same run dir, which is the exact failure
this issue exists to remove. `test_sealed`/`test_reward` and the `finalize` event are the
same fact seen through artifacts vs the log; accept either.
Copilot AI review requested due to automatic review settings July 30, 2026 00:15

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Copilot was unable to review this pull request because the user who requested the review has reached their quota limit.


import json
import os
import sys
for usd_key, tok_key in pairs:
try:
totals["usd"] = totals.get("usd", 0.0) + float(ev.get(usd_key) or 0.0)
except (TypeError, ValueError):
pass
try:
totals["tokens"] = totals.get("tokens", 0) + int(ev.get(tok_key) or 0)
except (TypeError, ValueError):
fixed = float(override)
if fixed > 0:
return fixed
except ValueError:
"""A run whose log says `finalize` but whose final.json/splits.json lag must still
read `done` — otherwise the hub says `live` while `cap-evolve tail` says `done`."""
from capevolve_dashboard import runs
rd = make_run("run_a", events=BASE_EVENTS + [{"t": time.time(), "kind": "finalize",
@OsherElhadad

Copy link
Copy Markdown
Collaborator Author

🔬 Evidence

Every command below was run in a clean worktree at /tmp/wt-118 = origin/main (6fca097) + #191 (009235b, the shared event-tail this builds on) + this PR's two commits. Interpreter: a venv with cap-evolve's own deps only (+fastapi/httpx, a dashboard dev extra — core gained no deps).

1. Baseline before this PR (main + #191)

$ git stash && PYTHONPATH=core python -m pytest core/tests -q
........................................................................ [ 99%]
.                                                                        [100%]
217 passed in 70.34s (0:01:10)

2. Full core suite with this PR

$ PYTHONPATH=core python -m pytest core/tests -q
........................................................................ [ 30%]
........................................................................ [ 60%]
........................................................................ [ 90%]
......................                                                   [100%]
238 passed in 68.49s (0:01:08)

217 → 238 (+21), 0 failed.

3. The new core module, test by test

$ PYTHONPATH=core python -m pytest core/tests/test_stall_detection.py -v
core/tests/test_stall_detection.py::test_working_run_is_live PASSED      [  4%]
core/tests/test_stall_detection.py::test_a_quiet_fast_run_whose_process_lives_is_stalled PASSED [  9%]
core/tests/test_stall_detection.py::test_a_run_whose_process_is_gone_is_crashed_not_live PASSED [ 14%]
core/tests/test_stall_detection.py::test_a_finalized_run_is_done_even_when_ancient_and_processless PASSED [ 19%]
core/tests/test_stall_detection.py::test_a_slow_but_healthy_run_is_never_called_hung PASSED [ 23%]
core/tests/test_stall_detection.py::test_a_toy_run_still_gets_the_five_minute_floor PASSED [ 28%]
core/tests/test_stall_detection.py::test_threshold_uses_the_slowest_gap_not_the_mean PASSED [ 33%]
core/tests/test_stall_detection.py::test_no_pid_file_means_unknown_never_crashed PASSED [ 38%]
core/tests/test_stall_detection.py::test_a_pid_from_another_host_is_unknown_not_dead PASSED [ 42%]
core/tests/test_stall_detection.py::test_malformed_pid_file_and_malformed_timestamps_do_not_raise PASSED [ 47%]
core/tests/test_stall_detection.py::test_missing_events_file_is_live_not_stalled PASSED [ 52%]
core/tests/test_stall_detection.py::test_env_override_wins_over_the_derived_threshold PASSED [ 57%]
core/tests/test_stall_detection.py::test_tail_exits_4_and_says_stalled PASSED [ 61%]
core/tests/test_stall_detection.py::test_tail_exits_5_and_says_crashed PASSED [ 66%]
core/tests/test_stall_detection.py::test_tail_exits_0_and_says_done_for_a_finalized_run PASSED [ 71%]
core/tests/test_stall_detection.py::test_tail_no_stall_check_keeps_following PASSED [ 76%]
core/tests/test_stall_detection.py::test_tail_does_not_stall_out_a_slow_but_healthy_run PASSED [ 80%]
core/tests/test_stall_detection.py::test_tail_attaching_mid_run_uses_the_whole_log_not_just_what_it_streamed PASSED [ 85%]
core/tests/test_stall_detection.py::test_tail_still_returns_3_when_nothing_ever_arrives PASSED [ 90%]
core/tests/test_stall_detection.py::test_run_writes_a_pid_marker_so_liveness_is_knowable PASSED [ 95%]
core/tests/test_stall_detection.py::test_dashboard_classifies_through_the_shared_helper_not_its_own_rule PASSED [100%]
============================== 21 passed in 2.80s ==============================

4. The new dashboard-backend module, test by test

$ cd dashboard/backend && PYTHONPATH=../../core:. python -m pytest tests/test_stall_status.py -v
tests/test_stall_status.py::test_a_silent_unfinalized_run_is_stalled_not_live PASSED [  7%]
tests/test_stall_status.py::test_a_run_whose_process_died_is_crashed_not_live_forever PASSED [ 14%]
tests/test_stall_status.py::test_a_finalized_run_still_reports_done PASSED [ 21%]
tests/test_stall_status.py::test_a_finalize_event_alone_is_enough_to_report_done PASSED [ 28%]
tests/test_stall_status.py::test_failed_and_done_outrank_the_liveness_verdict PASSED [ 35%]
tests/test_stall_status.py::test_a_dead_run_with_no_candidates_is_crashed_not_live PASSED [ 42%]
tests/test_stall_status.py::test_a_working_run_is_live PASSED            [ 50%]
tests/test_stall_status.py::test_a_slow_but_healthy_run_is_not_reported_stalled PASSED [ 57%]
tests/test_stall_status.py::test_load_run_carries_the_same_verdict_as_the_hub_row PASSED [ 64%]
tests/test_stall_status.py::test_liveness_never_raises_on_a_broken_run_dir PASSED [ 71%]
tests/test_stall_status.py::test_stream_sends_a_status_frame_naming_the_stall PASSED [ 78%]
tests/test_stall_status.py::test_stream_closes_on_crashed_but_never_calls_it_done PASSED [ 85%]
tests/test_stall_status.py::test_stream_status_frame_says_live_for_a_working_run PASSED [ 92%]
tests/test_stall_status.py::test_stream_still_ends_with_done_when_the_run_finalizes PASSED [100%]
============================== 14 passed in 0.78s ==============================

5. Full dashboard-backend suite (42 before → 56)

$ cd dashboard/backend && PYTHONPATH=../../core:. python -m pytest tests -q
56 passed, 1 warning in 2.08s

6. compileall

$ python -m compileall -q core skills && echo CLEAN
CLEAN

7. Frontend — npm ci / vitest / tsc / build

CI never runs vitest (#207), so all four were run locally.

$ npm ci     # (audit notices only, no install errors)

$ npm test
> vitest run
 RUN  v4.1.9 /private/tmp/wt-118/dashboard/frontend
 Test Files  14 passed (14)
      Tests  53 passed (53)
   Duration  9.13s

$ npx vitest run src/test/StatusBadge.test.tsx src/test/useRunStream.test.ts --reporter=verbose
 ✓ useRunStream.test.ts > streamReducer: stall/crash status frames (#118) > promotes a stalled verdict and keeps its reason 0ms
 ✓ useRunStream.test.ts > streamReducer: stall/crash status frames (#118) > promotes a crashed verdict 0ms
 ✓ useRunStream.test.ts > streamReducer: stall/crash status frames (#118) > a live verdict does NOT downgrade a finished run 0ms
 ✓ useRunStream.test.ts > streamReducer: stall/crash status frames (#118) > a stalled verdict does NOT downgrade a finished run either 0ms
 ✓ useRunStream.test.ts > streamReducer: stall/crash status frames (#118) > a slow-but-healthy run stays live and clears a stale reason 0ms
 ✓ StatusBadge.test.tsx > StatusBadge (#118) > renders the two new states with a distinct label, not as a finish 19ms
 ✓ StatusBadge.test.tsx > StatusBadge (#118) > renders crashed distinctly from failed 2ms
 ✓ StatusBadge.test.tsx > StatusBadge (#118) > a finished run still reads done 1ms
 Test Files  2 passed (2)
      Tests  13 passed (13)

$ npx tsc -b --noEmit; echo "tsc rc=$?"
tsc rc=0

$ npm run build
dist/assets/index-BXOPTHXk.js   831.11 kB │ gzip: 250.18 kB
✓ built in 610ms

dist/ was then reverted and cleaned — not committed, per epic #127 / #188:

$ git checkout -- dashboard/frontend/dist && git clean -fd dashboard/frontend/dist
$ git status --short dashboard/frontend/dist
(empty)

8. Real end-to-end (a): a run that COMPLETES → done

Setup mirrors examples/toy_calc/run.sh (toy_calc adapter + templates/project/capevolve.yaml, optimizer_skill: mock) — zero API cost:

REPO=/tmp/wt-118
export CAPEVOLVE_CORE="$REPO/core" PYTHONPATH="$REPO/core" CAPEVOLVE_SKILLS_DIR="$REPO/skills"
export CAPEVOLVE_TOY_DATA="$REPO/examples/toy_calc" CAPEVOLVE_MOCK_SCRIPT="$REPO/examples/toy_calc/mock_script.json"
D=/tmp/e118a; mkdir -p "$D/.capevolve/project/adapters"
cp "$REPO/examples/toy_calc/adapter.py" "$D/.capevolve/project/adapters/"
cp -R "$REPO/examples/toy_calc/capability" "$D/seed_capability"
cp "$REPO/templates/project/capevolve.yaml" "$D/.capevolve/project/capevolve.yaml"
python -m cap_evolve.cli run --spec "$D/.capevolve/project/capevolve.yaml" \
  --project "$D/.capevolve/project" --run-ts done --follow --dashboard off > /tmp/e118a.json
[02:54:37] splits frozen  train=4 val=2 test=2 (test sealed)
[02:54:37] eval val/seed  reward=0.0000 ±0.0000  0.0s
[02:54:37] baseline  val=0.0000 ±0.0000
[02:54:38] eval val/cand_0001  reward=1.0000 ±0.0000  0.0s
[02:54:38] gate warning (paired): combined/paired SE is 0 (likely n_trials=1 or identical trials)
[02:54:38] ACCEPT  cand_0001  val=1.0000 (parent 0.0000)  — paired Δ̄=+1.0000 > 0 (SE=0 → STRICT fallback, warned; n=2)
[02:54:39] eval val/cand_0002  reward=1.0000 ±0.0000  0.0s
[02:54:39] reject  cand_0002  val=1.0000 (parent 1.0000)  — paired Δ̄=+0.0000 <= 0 (SE=0 → STRICT fallback, warned; n=2)
[02:54:40] eval val/cand_0003  reward=1.0000 ±0.0000  0.0s
[02:54:40] reject  cand_0003  val=1.0000 (parent 1.0000)  — paired Δ̄=+0.0000 <= 0 (SE=0 → STRICT fallback, warned; n=2)
[02:54:40] eval test/FINAL  reward=1.0000 ±0.0000  0.0s
[02:54:40] eval test/FINAL_seed  reward=0.0000 ±0.0000  0.0s
[02:54:40] FINALIZE  test=1.0000 (baseline 0.0000, Δ+1.0000)  best=cand_0001
--- exit=0 ; run.pid written: ---
{"pid": 14610, "host": "Oshers-MacBook-Pro-2.local", "started": 1785369277.9289129}

cap-evolve tail --from-start on that finished dir:

[02:54:40] FINALIZE  test=1.0000 (baseline 0.0000, Δ+1.0000)  best=cand_0001
done — finalize sealed the test split
tail exit=0

9. Real end-to-end (b): a run KILLED mid-flight → crashed

The run is started in the background; once its events.jsonl has content, the whole process tree is kill -9ed:

python -m cap_evolve.cli run --spec ... --run-ts killed --dashboard off > /tmp/e118b.json 2>/tmp/e118b.err &
RUNPID=$!
for i in $(seq 1 300); do [ -s "$D/.capevolve/run_killed/events.jsonl" ] && break; sleep 0.1; done
sleep 1.2
pkill -9 -P $RUNPID; kill -9 $RUNPID; wait $RUNPID 2>/dev/null
--- events so far:        6 ---
--- killed pid 15109; run.pid on disk: {"pid": 15109, "host": "Oshers-MacBook-Pro-2.local", "started": 1785369298.151084} ---
$ grep -c finalize .../run_killed/events.jsonl
0        # no finalize event, as expected

--- cap-evolve tail on the killed run ---
[02:54:58] splits frozen  train=4 val=2 test=2 (test sealed)
[02:54:58] eval val/seed  reward=0.0000 ±0.0000  0.0s
[02:54:58] baseline  val=0.0000 ±0.0000
[02:54:58] eval val/cand_0001  reward=1.0000 ±0.0000  0.0s
[02:54:58] ACCEPT  cand_0001  val=1.0000 (parent 0.0000)  — paired Δ̄=+1.0000 > 0 (SE=0 → STRICT fallback, warned; n=2)
CRASHED — the process that owned this run is gone and it never finalized (last event 1s ago)
tail exit=5

10. Real end-to-end (c): a deliberately SLOW run stays working

A live process that owns the run dir, writes run.pid, and appends genuine events with 150-second gaps (the shape of a τ²-bench rollout), then goes quiet for 380s — past the old 300s rule — before finalizing:

log(kind="splits", train=4, val=2, test=2)
for i in (1, 2, 3):
    time.sleep(150)                       # a genuinely slow optimizer+eval step
    log(kind="evaluate", split="val", tag=f"cand_000{i}", reward=1.0, seconds=150.0)
time.sleep(380)                           # quiet, but only 380s: inside 3 × 150s
log(kind="finalize", test_reward=1.0, ...)

Sampled every 30s, old rule vs new:

03:04:58 silence= 112.2s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:05:28 silence= 142.2s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:05:58 silence= 172.4s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:06:28 silence= 202.5s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:06:58 silence= 232.6s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:07:28 silence= 262.7s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:07:58 silence= 292.8s  OLD_5MIN_RULE=quiet ok    NEW status=live  threshold=450s
03:08:28 silence= 322.9s  OLD_5MIN_RULE=WOULD FIRE  NEW status=live  threshold=450s
03:08:58 silence= 353.0s  OLD_5MIN_RULE=WOULD FIRE  NEW status=live  threshold=450s
03:09:29 silence=   3.1s  OLD_5MIN_RULE=quiet ok    NEW status=done  threshold=1140s
=== finalized; final verdict ===
{'status': 'done', 'detail': 'done — finalize sealed the test split',
 'silence_seconds': 3.15, 'stall_threshold_seconds': 1140.1,
 'slowest_gap_seconds': 380.03, 'process_alive': False}

The old fixed rule would have declared this working run hung — twice — and it went on to finish successfully. The live tail attached to it, timestamped per line:

tail started at 03:00:59
03:00:59 | [02:55:35] splits frozen  train=4 val=2 test=2 (test sealed)
03:00:59 | [02:58:05] eval val/cand_0001  reward=1.0000 ±0.0000  150.0s
03:00:59 | [03:00:35] eval val/cand_0002  reward=1.0000 ±0.0000  150.0s
03:03:06 | [03:03:05] eval val/cand_0003  reward=1.0000 ±0.0000  150.0s
03:09:26 | [03:09:25] FINALIZE  test=1.0000 (baseline 0.0000, Δ+1.0000)  best=cand_0001
03:09:26 | done — finalize sealed the test split
tail finished at 03:09:26

Note the derived bar tracking the run: 450s (= 3 × its 150s worst gap) while running, 1140s (= 3 × 380s) once it had demonstrated the longer quiet. The bar rose because the run earned it.

11. The dashboard agrees, on the same three run dirs

$ python /tmp/dash118.py     # TestClient over create_app() for each base dir

=== (a) COMPLETED run: GET /api/runs ===
  run_id=run_done  status='done'
    liveness.status='done'  silence=976.6884212493896  threshold=300.0  slowest_gap=0.8091549873352051  process_alive=False
    detail=done — finalize sealed the test split
  GET /api/runs/run_done -> summary.status='done' (matches hub row: True)

=== (b) KILLED run: GET /api/runs ===
  run_id=run_killed  status='crashed'
    liveness.status='crashed'  silence=958.4792633056641  threshold=300.0  slowest_gap=0.7611470222473145  process_alive=False
    detail=CRASHED — the process that owned this run is gone and it never finalized (last event 16.0m ago)
  GET /api/runs/run_killed -> summary.status='crashed' (matches hub row: True)

=== (c) SLOW-but-healthy run: GET /api/runs ===
  run_id=run_slow  status='done'
    liveness.status='done'  silence=91.42201113700867  threshold=1140.095993757248  slowest_gap=380.03199791908264  process_alive=False
    detail=done — finalize sealed the test split
  GET /api/runs/run_slow -> summary.status='done' (matches hub row: True)

Terminal, on the same three dirs:

$ for d in run_done run_killed run_slow; do cap-evolve tail $d --from-start; echo "exit=$?"; done
done — finalize sealed the test split                    exit=0
CRASHED — the process that owned this run is gone …      exit=5
done — finalize sealed the test split                    exit=0

Dashboard done / crashed / done ≡ terminal done / crashed / done. Hub row ≡ DeepDive payload (matches hub row: True on all three).

12. The bug this evidence caught

Run (c) initially came back liveness.status='done' but status='live' — the reducer's test_sealed/final.json had not caught up with the log's finalize. Two surfaces disagreeing about one run dir is exactly the failure #118 exists to remove, so _status now accepts either signal (commit 2, test_a_finalize_event_alone_is_enough_to_report_done). The transcript above is after the fix; before it, the (c) row read status='live' with liveness.status='done'.

@skillberry-bot

Copy link
Copy Markdown
Contributor

Automatic Labeling Failed

An error occurred while trying to automatically label this pull request. Please check the workflow logs for details and add labels manually.

@OsherElhadad

Copy link
Copy Markdown
Collaborator Author

🔍 Review — PR #218

CHANGES REQUESTED

The design is right — deriving the bar from the run's own pace beats a constant, and the
three-valued pid logic is careful about None. But the bar is derived from gaps between
events that already happened
, and a run's slowest step is nearly always the one it is
currently inside. That inverts the feature on the exact case #118 exists for: I got a
STALLED verdict and exit 4 on a run whose owning process I could see alive in ps,
purely because its first optimizer call had not returned yet. Details, reproductions, and
the surface-disagreement I found on the merged tree below.

Base established: #191 (009235b) already gave follow_events(idle_timeout=…, should_stop=…),
FOLLOW_END with reason, sanitize, use_color. This PR adds liveness_facts /
classify / describe_status / stall_threshold, run.pid, exit codes 4/5,
--no-stall-check, and the SSE status frame.


Blocking

1. eventstream.py:476-494 — the derived bar cannot see the gap it is currently in, so a
healthy run's FIRST slow step is reported STALLED.

stall_threshold maxes over completed gaps. A real cap-evolve run opens with a burst of
sub-second events (splits, evaluate val/seed, baseline — all within the same second in
your own e2e (a) transcript), then makes its first genuinely slow optimizer+eval call. At
that moment slowest_gap ≈ 0.2s, so threshold = 300s (the floor), and any first step
longer than 5 minutes trips. A τ²-bench first step is 20 minutes.

Reproduced against a run dir whose run.pid names a process I could see alive:

$ ps -p 16164 -o pid=,comm=
16164 /bin/sleep
$ python -m cap_evolve.cli tail /tmp/p118/base/run_slowfirst --from-start
[03:09:56] splits frozen  train=4 val=2 test=2 (test sealed)
[03:09:56] eval val/seed  reward=0.0000 ±?  ?s
[03:09:56] baseline  val=0.0000 ±?
STALLED — no events for 15.0m, over this run's own threshold 5.0m (floor). The process is still alive — it may be wedged rather than dead.
tail exit=4

Swept against elapsed time in the first step (all with the owner alive, all healthy):

  in-progress first step,   240s elapsed -> live     thr=300s
  in-progress first step,   300s elapsed -> stalled  thr=300s   <-- false
  in-progress first step,   900s elapsed -> stalled  thr=300s   <-- false
  in-progress first step,  1800s elapsed -> stalled  thr=300s   <-- false

Consequence: exactly the false positive the PR description says is the worst outcome, on the
first step of every expensive run, plus a STALLED badge on the hub and a stderr warning in
run --follow. The user's reaction is to kill a working run.

Fix: fold the open gap into the estimate — gaps + [now - last_event_t] is not available
(that's the thing being measured), so instead take max(completed_gaps + [silence_at_last_check]),
i.e. let the bar rise with the current silence rather than only on gap completion. The one-line
version: in liveness_facts, treat silence as a candidate gap when computing the threshold
for the next check and persist the high-water mark (or simply require two consecutive
over-bar observations spaced ≥ the floor apart before returning stalled). Cheapest correct
option: raise the floor to something no legitimate first step exceeds and let the derived bar
handle the rest — but that just moves the constant. The high-water-mark version is the real fix.

2. eventstream.py:463-472 + cli.py:534-537run.pid is never deleted and started is
written but never read, so a stale marker in a reused run dir reports crashed on a run that
is actively writing.

_owner_alive reads only pid and host. started (line 537) is dead data. A run dir whose
run.pid holds a dead pid from a previous attempt reads crashed no matter how live the
current writer is:

ACTIVELY WRITING run (silence 0.0s) with a stale dead run.pid -> crashed
  CRASHED — the process that owned this run is gone and it never finalized (last event 0s ago)

This is reachable: the per-phase skill chain (/cap-evolve:baseline …) writes no marker at
all, so any dir that was once driven by cap-evolve run and is later advanced by the skill
chain, or by a re-run that fails before cli.py:534 executes, keeps the old dead pid. Note
cli.py:534 runs after the baseline subprocess, so a cap-evolve run that dies inside
baseline leaves the previous marker in place.

Consequence: crashed badge + exit 5 + the SSE stream closing on a run that is working.

Fix: classify should treat alive is False as crashed only when silence > threshold too —
a run that spoke seconds ago is by definition not dead, whatever a marker says. One-line guard at
eventstream.py:553:

if facts.get("alive") is False and (facts.get("silence") or 0) > (facts.get("threshold") or STALL_FLOOR_SECONDS):

And separately: compare the recorded started against the process's actual start time
(psutil-free: ps -o lstart= -p PID) so a reused pid is caught — that is the ponytail comment's
stated upgrade path, and case 2 above shows it is already needed, not hypothetical.

3. runs.py:83 — a zero-candidate crashed/stalled run reads failed on the hub and
crashed/stalled in the DeepDive. Two panels, two words, same run.

_status returns failed for counts.total == 0 before consulting the liveness verdict,
but RunDeepDive.tsx:84-111 prefers the fresher SSE status frame whenever it is not live:

zero-candidate run, liveness=crashed  HUB=failed   DEEPDIVE=crashed  AGREE=False
zero-candidate run, liveness=stalled  HUB=failed   DEEPDIVE=stalled  AGREE=False

A run whose seed eval blows up (adapter raises → no candidates) and whose process then dies hits
this. Consequence: exactly the "done in one panel, live in another" defect class the issue is
about, in failed/crashed clothing. Fix: put the liveness verdict ahead of the zero-candidate
branch for crashed (a dead run with no candidates is crashed, and that's more actionable
than failed), or have RunDeepDive defer to data.summary.status when it is failed.

4. cli.py:233-243 — with --idle-timeout 0 (documented as "wait forever"), tail on a
provably dead run hangs forever instead of reporting crashed.

should_stop returns early at line 235 whenever last is None, and last stays None for the
whole session when tail attaches without --from-start (nothing new ever arrives on a dead
run). So the stall/crash check is never reached:

$ python -m cap_evolve.cli tail <killed run> --idle-timeout 0
HANGS FOREVER on a dead run (no crashed verdict) -- exit-3/5 never reached

Same shape with a finite timeout, where it degrades to the old ambiguous answer instead of the
new one:

CRASHED run, tail (no --from-start): rc=3   "timed out after 4s with no events"
CRASHED run, tail --from-start:      rc=5   "CRASHED — the process that owned this run is gone"

Consequence: the crash verdict — the headline feature — is only available when the caller
happens to pass --from-start, and --idle-timeout 0 is an unbounded hang. Fix: run the
liveness probe even when last is None; alive is False is proof regardless of whether this
process has seen an event. The last is None guard only needs to suppress the stalled
branch, not the crashed one.


Non-blocking

5. app.py:114 — the SSE stream never terminates for a finished run. offset starts at
EOF, so the finalize event that produces the done frame is already behind the cursor and
never replayed. Driving the generator directly:

run_done     STILL OPEN after 3.0s  frames=['snapshot','status','status',...] n=11  'done' in frames=False
run_crash    CLOSED after 0.0s      frames=['snapshot','status'] n=2            'done' in frames=False

Every browser tab left open on a completed run holds a connection emitting 720 status
frames/hour indefinitely. Note this is fixed for free by merging #204 after (#204 sets
offset = 0); on the merged tree the same probe gives run_done CLOSED after 0.0s … 'done' in frames=True. Worth a line in the merge-order note rather than a code change here.

6. runs.py:44-62 + app.py:129-132liveness() re-reads the entire events.jsonl every
status_every (default 5s) per open connection.
On a 50k-event / 4.6 MB log that is 108 ms of
parse work, 720×/hour/connection:

log lines= 50000  size=4.6 MB
liveness_facts on it: 0.108s (x720/hour/connection)

liveness_facts already accepts an events= kwarg to avoid the re-read (docstring line 501) but
neither caller uses it. Fix: pass the reduced run's already-parsed events, or read only the tail.

7. eventstream.py:527 — mtime is the right pragmatic signal but it makes the whole feature
silently wrong under clock skew, and the skew shows up in the unsafe direction.
With the
writer's t values in the future (skewed container clock) the derived gaps stay sane but
silence is computed from local now minus mtime, so:

R. events t in the FUTURE (clock skew), mtime 1h ago -> stalled (thr=1800s silence=3600s)

That happens to be correct here, but the two quantities come from different clocks (t from
the writer, mtime from the FS, now from the reader) and only agree by luck. Worth a comment
naming the assumption; the mtime choice itself is defensible and I would not change it.

8. eventstream.py:416-421 — the monotonic bar makes the feature weakest where it matters
most.
A run that showed one 20-minute gap needs 60 minutes of silence to trip; a run that
hangs right after its slowest step is invisible for an hour:

D. HUNG after a 20min gap: silent 45min, alive -> live  (thr=3600s)

Verdict: acceptable as a first cut, given the false-positive asymmetry — 60 minutes late is
better than killing a working run. But combined with finding #1 the current tuning is backwards:
it fires early on healthy first steps and late on genuine hangs. Fixing #1 with a high-water
mark also tightens this, because the bar then tracks demonstrated silence rather than only
completed gaps.

9. Test coverage — the false-positive direction is untested in exactly the shape that
breaks.
All three "slow but healthy" tests (test_stall_detection.py:105, :240, :258)
pre-seed the log with completed 20-minute gaps, so the bar is already 3600s before the assertion
runs. None covers the first-slow-step case (finding #1), the stale-marker case (#2), the
--idle-timeout 0 case (#4), or a --resume reopening. test_run_writes_a_pid_marker_so_liveness_is_knowable
(:288) asserts on the source text of cli.py rather than behaviour — it would pass if the
marker were written to the wrong directory.

10. --no-stall-check and the pin both work, and the pin is not overridable. Verified:

--no-stall-check on the false-positive dir      -> STILL FOLLOWING (correct)
CAPEVOLVE_STALL_SECONDS=99999 on a real 45m hang -> live (pin wins, correct)
CAPEVOLVE_STALL_SECONDS=60 on a 20m-gap run      -> stalled (pin wins, correct)

stall_threshold returns the override before touching gaps (eventstream.py:477-484), and
ignores <= 0 / unparseable values by falling through to derivation — good. Note the pin does
not suppress crashed: with the pin set to 99999 my stale-marker dir still exited 5. That's
arguably correct (crash is proof-based, not time-based) but undocumented.


Nits

11. docs/GETTING_STARTED.md:80-93 — exit code table lists 0 / 4 / 5 / 3 / 2 out of order
and describes exit 0 as "done / working".
A script branching on "did it finish" cannot use
0, since 0 now also means "still working, I gave up watching". Worth saying so explicitly.

12. cli.py:239next_check[0] = time.monotonic() + 2.0 and cli.py:141's + 30.0 are two
different hardcoded probe intervals for the same question.
Fine, but a named constant beside
STALL_FLOOR_SECONDS would make them findable.

13. #217 constraint holds. run stdout is still exactly one JSON object; the marker write
and all verdict text go to stderr:

$ python -c "import json; d=json.load(open('/tmp/e218a.json')); print('OK keys:', sorted(d)[:8])"
OK keys: ['baseline_val', 'best_id', 'dashboard', 'iterations', 'run_dir', 'test_baseline_reward', 'test_delta', 'test_pass_k']

False-positive probes

Owner process genuinely alive (/bin/sleep, verified in ps) unless noted.

# Run shape Verdict Correct?
A fast opening burst, then first 20-min optimizer call in flight stalled thr=300s false alarm (blocking #1)
B exactly one event, 10 min ago, owner alive stalled thr=300s false alarm (blocking #1)
C demonstrated 20-min gaps, quiet 25 min live thr=3600s
D hung after its slowest gap: silent 45 min live thr=3600s ⚠️ false negative (non-blocking #8)
E gepa cache burst (49 sub-second events) after a 20-min gap, quiet 400s live thr=3600s max holds
F pid gone, no finalize crashed
G pid gone, finalized done done outranks
H pid from another host, silent 1 h stalled (alive=None) ✅ never crashed
I no run.pid (skill chain), silent 1 h stalled (alive=None) ✅ never crashed
J pid: 0 live (alive=None)
K pid: -1 live (alive=None)
L unparseable run.pid ({not json) live (alive=None)
M stale marker, pid reassigned to a live process stalled ⚠️ dead run never reads crashed — safe direction, but see #2
N malformed t values ("soon", null), silent 1 h stalled (no gaps → floor) ✅ no raise
O no events.jsonl at all live (silence=None)
P CAPEVOLVE_STALL_SECONDS=60 vs a 20-min-gap run, silent 25 min stalled thr=60s ✅ pin wins
Q CAPEVOLVE_STALL_SECONDS=99999 on the real 45-min hang live ✅ pin wins
R writer t in the future (clock skew), mtime 1 h old stalled ⚠️ right answer, wrong reason (#7)
S --resume reopening a dir whose old log had only fast gaps, new step slow 700s stalled thr=300s false alarm — the bar does NOT carry over usefully (blocking #1)
T live writer (silence=0s) + stale dead run.pid crashed worst case (blocking #2)

Two ❌ classes, both false-positive: the first-slow-step / resume family (#1) and the stale
marker (#2). Everything the PR body claims about max-not-mean, alive is None, malformed
input, and done outranking reproduced exactly.

Live --resume behaviour is otherwise fine — the marker is rewritten by the new process and
the verdict recovers within one poll:

  t+1  verdict=crashed False  pid_in_marker=48044   (old dead pid)
  t+2  verdict=live    True   pid_in_marker=54995   (rewritten)
  t+8  verdict=done    True

That one-poll crashed flash is what #2 makes permanent when the rewrite never happens.


PID liveness audit

  • Reuse: not defended against. started is written (cli.py:537) and never read
    (_owner_alive, eventstream.py:463-472 reads only pid/host). Probe M: a dead run whose
    pid was reassigned reads stalled forever, never crashed. Failure direction is the safe one
    (as the ponytail: comment claims) — but the converse, probe T, is unsafe and reachable, so
    the stated upgrade path is now required, not optional.
  • Containers / namespaces: a live pid invisible to the reader raises ProcessLookupError
    Falsecrashed. The host check only catches a different hostname; a container sharing
    the host's UTS namespace but not its PID namespace passes the host check and gets a false
    crashed. Not exercised by any test.
  • Zombies: os.kill(pid, 0) succeeds on a zombie → alive=Truestalled, not crashed.
    Correct-and-safe, untested.
  • Stale marker + reused dir: blocking fix: add core/README.md and fix readme path in pyproject.toml #2. Never deleted, never validated against started,
    and cli.py:534 writes it only after the baseline subprocess succeeds.
  • --resume: marker is rewritten by the new owner and recovers within one poll (transcript
    above). Fine.
  • Correctly None, never crashed: other host ✅, unparseable ✅, missing ✅, pid 0 ✅,
    pid −1 ✅. That part of the three-valued design is solid.

Do the surfaces actually agree?

Three real run dirs, produced by cap-evolve run over toy_calc (optimizer_skill: mock,
zero API cost), then read by both surfaces.

This PR alone:

Run dir terminal tail --from-start hub _status DeepDive summary.status agree
run_done (completed) done / exit 0 done done
run_kill2 (SIGKILL mid-loop) CRASHED / exit 5 crashed crashed
run_slowfirst (slow-but-live) STALLED / exit 4 stalled stalled ✅ consistent, both wrong (#1)

So the surfaces agree with each other — including on the false positive, which is the point:
one classifier means one consistent wrong answer, which is better than two, but still wrong.

Merged tree with #204 (conflict in app.py:114-125 resolved by taking #204's offset = 0
plus this PR's last_status; 242 core + 57 backend + 60 frontend all pass, tsc rc=0). Hub row
vs the DeepDive badge with RunDeepDive.tsx:84-111 applied:

run_done     HUB=done     SSE=done     DEEPDIVE_BADGE=done     agree=YES
run_kill2    HUB=crashed  SSE=crashed  DEEPDIVE_BADGE=crashed  agree=YES
zero-candidate + crashed  HUB=failed   SSE=crashed  DEEPDIVE=crashed  agree=NO   <-- blocking #3
zero-candidate + stalled  HUB=failed   SSE=stalled  DEEPDIVE=stalled  agree=NO   <-- blocking #3

The finalize-event-vs-lagging-artifacts bug you fixed in commit 2 does hold on the happy
paths. Blocking #3 is a second instance of the same class that the fix did not cover, because it
lives in the other precedence decision (counts.total == 0 before liveness) rather than in the
done one.

Two status models, #218 vs #204: consistent, not contradictory. StreamStatus is a strict
superset ('connecting' | 'live' | 'done' | 'idle' | 'error' | 'stalled' | 'crashed') and
#204's EventTicker empty-state switch (EventTicker.tsx:35-41) falls through to
'No events yet — this run has just started.' for stalled/crashed. That message is wrong for
a crashed run but not a lie about completion, so: non-blocking follow-up on #204, not a merge
blocker.

Old cached dist/ bundle: degrades gracefully — it does not break. The committed bundle
(5ca5745, stale per #188) registers snapshot/event/done/idle/error and no status
listener:

$ grep -o "addEventListener(.[a-z]*." dist/assets/*.js | sort -u
addEventListener(`done`   addEventListener(`event`   addEventListener(`idle`
addEventListener(`open`   addEventListener(`snapshot`  ...
$ grep -c 'addEventListener(`status`' dist/assets/*.js
0

Unknown named SSE frames are silently dropped by EventSource, so an old bundle sees no
stalled/crashed and — because the backend no longer sends idle — simply shows live
forever with no ticker updates. Same behaviour as today for a hung run, i.e. #118 unfixed for
stale-bundle users, but nothing throws. #188 remains the fix.


Merge-order note

  1. feat(observability): live terminal progress via --follow and cap-evolve tail #191 first (this PR's base; already merged into it).
  2. perf(dashboard): memoize reduce_run on events mtime+size, drop dead SSE snapshot, paginate runs/rollouts #194 next — merges clean into feat(observability): classify a run as working / stalled / crashed / done #218, 251 passed core + 66 passed backend with no
    intervention. liveness() genuinely sits outside the cached reduce_run (runs.py:42-62
    calls eventstream directly, never dashboard.reduce_run), and the docstring's reasoning is
    right: silence is the one fact that changes while nothing on disk changes, so a cached answer
    would read 0s forever. A cached reduction cannot serve a stale status — verified, the
    author's claim holds.
  3. feat(observability): classify a run as working / stalled / crashed / done #218 after fixes 1–4.
  4. fix(dashboard): render the live event ticker in the SPA; populate the algorithm label #204 last. It conflicts with feat(observability): classify a run as working / stalled / crashed / done #218 in app.py:114-125 (offset = 0/idle vs
    offset = EOF/last_status); resolution is mechanical (keep fix(dashboard): render the live event ticker in the SPA; populate the algorithm label #204's offset = 0, keep feat(observability): classify a run as working / stalled / crashed / done #218's
    last_status) and also fixes non-blocking Cost visibility & budget completeness: surface max_usd/max_metric_calls, track optimizer spend, add pre-run estimates #5 — the merged stream terminates with done on
    a finished run, whereas feat(observability): classify a run as working / stalled / crashed / done #218 alone leaks it open. useRunStream.ts, types.ts,
    RunDeepDive.tsx, StatusBadge.tsx all auto-merged. If fix(dashboard): render the live event ticker in the SPA; populate the algorithm label #204 lands first, feat(observability): classify a run as working / stalled / crashed / done #218 must rebase and
    keep offset = 0.

Verification I re-ran

$ cd /tmp/rv-218 && PYTHONPATH=core python -m pytest core/tests -q
238 passed in 69.83s (0:01:09)

$ cd dashboard/backend && PYTHONPATH=../../core:. python -m pytest tests -q
56 passed, 1 warning in 2.51s

$ python -m compileall -q core skills && echo COMPILEALL_CLEAN
COMPILEALL_CLEAN

$ cd dashboard/frontend && npx tsc -b --noEmit; echo "tsc rc=$?"
tsc rc=0
$ npm test
 Test Files  14 passed (14)
      Tests  53 passed (53)

238 / 56 / 53 / tsc rc=0every count in the PR body reproduced, including the flaky
test_dashboard_launch.py::test_maybe_launch_spawns_when_available (#200) passing this time.

Merged with #194:

$ cd /tmp/rv-218-c && git merge origin/perf/issue-119-reduce-cache   # clean
$ PYTHONPATH=core python -m pytest core/tests -q
251 passed in 73.09s (0:01:13)
$ cd dashboard/backend && PYTHONPATH=../../core:. python -m pytest tests -q
66 passed, 1 warning in 2.18s

Merged with #204 (one conflict, resolved):

$ cd /tmp/rv-218-m && git merge origin/feat/issue-117-event-ticker
CONFLICT (content): Merge conflict in dashboard/backend/capevolve_dashboard/app.py
$ PYTHONPATH=core python -m pytest core/tests -q
242 passed in 73.33s (0:01:13)
$ cd dashboard/backend && PYTHONPATH=../../core:. python -m pytest tests -q
57 passed, 1 warning in 2.65s
$ cd dashboard/frontend && npx tsc -b --noEmit; echo "tsc rc=$?"; npm test
tsc rc=0
 Test Files  15 passed (15)
      Tests  60 passed (60)

Real e2e (a) completed run:

$ python -m cap_evolve.cli run --run-ts done --dashboard off > /tmp/e218a.json
exit=0
run.pid: {"pid": 43982, "host": "Oshers-MacBook-Pro-2.local", "started": 1785371317.6739142}
$ cap-evolve tail .capevolve/run_done --from-start
[03:28:40] FINALIZE  test=1.0000 (baseline 0.0000, Δ+1.0000)  best=cand_0001
done — finalize sealed the test split
tail exit=0

Real e2e (b) SIGKILLed run:

--- killed. events=6 finalize=0
run.pid: {"pid": 48044, "host": "Oshers-MacBook-Pro-2.local", "started": 1785371334.555365}
$ cap-evolve tail .capevolve/run_kill2 --from-start
CRASHED — the process that owned this run is gone and it never finalized (last event 0s ago)
exit=5

Real e2e (c) slow-but-live run — did not reproduce as claimed; see blocking #1. Your
transcript pre-seeds three completed 150s gaps before the 380s quiet, which is what raises the
bar to 450s/1140s. A run in its first slow step has no such gaps and falls to the floor.

tail --from-start subtlety (your claim 3) — verified correct. Attaching mid-run without
--from-start to a run with demonstrated 20-min gaps, quiet 25 min:

rc=STILL FOLLOWING (correct: derived bar from whole log, no false stall)

and the same dir with only fast gaps falls to the floor and trips, which is blocking #1 again,
not a flaw in the whole-log derivation.

Security (#15/#209): clean. describe_status (eventstream.py:568-588) interpolates only
classify()'s five literal words and numbers formatted through _mins(); no event-controlled
string reaches it, so nothing to inject. render_line still routes through sanitize
(eventstream.py:371). On the HTML side StatusBadge renders detail as a React title
attribute (auto-escaped) and status only as a MAP key with an ?? MAP.failed fallback for an
unknown value. No dangerouslySetInnerHTML on this path.

A false `stalled`/`crashed` gets a working, money-spending run killed, so both
directions the review found are fixed at the root rather than at the callers.

1. The derived bar maxes over COMPLETED gaps, so a healthy run in its FIRST slow
   step had only its sub-second opening burst to learn from, fell to the 300s
   floor, and reported `stalled` with its owner alive in `ps`. Guaranteed for any
   run whose first optimizer call exceeds five minutes, i.e. τ²-bench-shaped.

   Folding the open gap into the bar cannot work — the bar is what that silence
   is compared against, so slack >= 1 makes `stalled` unreachable forever and
   slack < 1 collapses onto the floor (pinned by a test). The uninformed case
   gets a conservative prior instead: STALL_FLOOR_SECONDS 300s -> 3600s, the same
   slack applied to the slowest plausible unobserved step. `crashed` needs proof,
   not silence, so the case that most needs a fast answer is unaffected.

2. `started` was written and never read, so a stale dead `run.pid` in a reused
   dir condemned a live writer: `crashed` at silence=0.0s. Now `classify`
   requires corroborating silence before ever saying `crashed`, and `_pid_alive`
   compares the marker's `started` against the process's real start time
   (`ps -o lstart=`, no new dependency) so a reused pid is caught too.

3. The hub's zero-candidate `failed` branch moved BELOW the liveness verdict: a
   dead run with no candidates read `failed` on the hub and `crashed` in the
   DeepDive. One run, one word.

4. `tail` ran no liveness probe while `last is None`, so `--idle-timeout 0` hung
   forever on a provably dead run and a finite timeout gave the old exit 3 rather
   than 5. `crashed` is proof-based and no longer gated on having seen an event;
   `stalled` still is, since a run may not have started talking yet.

Also: liveness_facts now folds only NEW bytes into the previous scan, so the SSE
route's 5s probe costs 0.016ms instead of re-parsing the whole log (119ms on a
5.7MB/50k-event log, 720x/hour/connection); named the two probe intervals;
documented that exit 0 means "finished OR still working" and that the
CAPEVOLVE_STALL_SECONDS pin does not suppress `crashed`; noted the mtime/`t`
clock-skew assumption.

Tests 238 -> 247: the first-slow-step, stale-marker, pid-reuse, zombie,
legacy-marker, --idle-timeout 0, and no-`--from-start` crash paths, plus a
hub/DeepDive agreement test on the zero-candidate dead-process shape. The
marker test now checks the marker's LOCATION through _owner_alive instead of
only grepping cli.py.
Copilot AI review requested due to automatic review settings July 30, 2026 01:47

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Copilot was unable to review this pull request because the user who requested the review has reached their quota limit.

@OsherElhadad

Copy link
Copy Markdown
Collaborator Author

🔧 Review fixes

All 4 blocking findings fixed, all 9 non-blocking addressed or declined with a reason.
Pushed as 83b99d7. Every number below is literal output re-run after the change.

One correction up front, because it changed the shape of fix #1: the suggested fix for
blocking #1 cannot work.
Folding the open gap into the max that derives the bar is
circular — the bar is what that same silence is compared against:

$ python -c '...'   # any factor applied to the CURRENT silence
f=3.0: NEVER fires (10h)
f=1.0: NEVER fires (10h)
f=0.5: fires at silence=360s bar=300s  <- degenerates to the bare floor
f=0.1: fires at silence=360s bar=300s  <- degenerates to the bare floor

With slack ≥ 1 the bar outruns the silence forever and stalled becomes unreachable; with
slack < 1 the bar collapses onto the floor and the fold does nothing. So I took the third
option you listed — a conservative prior — and pinned the reasoning in a test
(test_folding_the_open_gap_into_the_bar_would_never_fire) so nobody re-tries it.


False-positive probes

Rebuilt from scratch with no pre-seeded completed gaps — that pre-seeding is exactly
what hid blocking #1 in my original evidence. Owner is a real /bin/sleep, verified in
ps before and after the sweep.

live owner pid=46985   dead pid=46986
$ ps -p 46985 -o pid=,comm=
46985 /bin/sleep
# Run shape Verdict threshold silence Correct?
A1 fast opening burst, then FIRST slow step in flight — 6m live 60m 6.0m
A2 fast opening burst, then FIRST slow step in flight — 15m live 60m 15.0m
A3 fast opening burst, then FIRST slow step in flight — 30m live 60m 30.0m
A4 fast opening burst, then FIRST slow step in flight — 50m live 60m 50.0m
B exactly one event, 10m ago, owner alive live 60m 10.0m
S --resume: old log fast gaps only, new step slow 700s live 60m 11.7m
T live writer (silence 0s) + stale DEAD run.pid live 60m 0.0m
C demonstrated 20-min gaps, quiet 25m live 60m 25.0m
W fast run genuinely wedged past the floor (70m) stalled 60m 70.0m
E gepa cache burst (49 sub-second events) after a 20-min gap, quiet 400s live 60m 6.7m
F pid gone, no finalize, quiet 10m crashed 60m 10.0m
G pid gone, finalized done 60m 10.0m
H pid from another host, silent 2h stalled 60m 120.0m
I no run.pid (skill chain), silent 2h stalled 60m 120.0m
M stale marker, pid REUSED by a later process crashed 60m 10.0m
M2 genuine owner, started matches live 60m 10.0m
N malformed t values, silent 2h stalled 60m 120.0m
O no events.jsonl at all live ?
ps re-check of the owner AFTER all probes (must still be alive):
46985 S    /bin/sleep

18/18 correct, 0 wrong

The same sweep against the pre-fix code, so the regression is documented rather than
asserted:

| A1 | first slow step — 6m           | `stalled` | 5m | 6.0m   | ❌ expected live |
| A2 | first slow step — 15m          | `stalled` | 5m | 15.0m  | ❌ expected live |
| A3 | first slow step — 30m          | `stalled` | 5m | 30.0m  | ❌ expected live |
| A4 | first slow step — 50m          | `stalled` | 5m | 50.0m  | ❌ expected live |
| B  | one event, 10m ago             | `stalled` | 5m | 10.0m  | ❌ expected live |
| S  | --resume, new step slow 700s   | `stalled` | 5m | 11.7m  | ❌ expected live |
| T  | live writer + stale dead marker| `crashed` | 5m | 0.0m   | ❌ expected live |
| M  | pid reused by a later process  | `stalled` | 5m | 10.0m  | ❌ expected crashed |
| M2 | genuine owner, started matches | `stalled` | 5m | 10.0m  | ❌ expected live |

9/18 correct, 9 wrong        (= BEFORE the fix)

9/18 → 18/18. Both ❌ classes you identified are closed, and probe M (the safe-direction
one) is now correct too because started is finally read.

tail on the healthy first-slow-step run, with ps on either side:

$ ps -p 58346 -o pid=,state=,comm=
58346 SN   /bin/sleep
### A2 healthy, 15m into FIRST slow step, --from-start (bounded to 12s):
[04:21:45] eval val/cand_0000  reward=1.0000 ±?  1.0s
[04:21:46] eval val/cand_0001  reward=1.0000 ±?  1.0s
[04:21:46] eval val/cand_0002  reward=1.0000 ±?  1.0s
STILL FOLLOWING after 12s (correct: no false stall)
$ ps -p 58346 -o pid=,state=,comm=
58346 SN   /bin/sleep

Previously this exact dir gave STALLED … tail exit=4.


1. Blocking — first slow step reported STALLED

STALL_FLOOR_SECONDS 300s → 3600s, with the reasoning in the constant's docstring. It
is STALL_SLACK × the ~20-minute τ²-bench step: the same slack the derived bar applies to a
demonstrated gap, applied to the slowest step we consider plausible for a workload we have
not observed. One completed gap over 20 minutes and the derived bar takes over above it.

Why a prior and not the open gap: proven impossible above. Why not "require positive evidence
of death (pid gone) before ever saying stalled": that would make stalled unreachable for
every skill-chain run (no marker → alive is None) and for every wedged-but-alive run — which
is the entire "alive but not talking" state the issue asks for.

The cost is named honestly in a ponytail: comment: a genuinely wedged fast run is now
reported at 60m instead of 5m. That is the cheap direction (your own asymmetry: "a false
stalled may get a working run killed; a late stalled merely delays a diagnosis"), and
critically crashed is not delayed by the floor at all — it needs proof, not silence — so
the shape that most needs a fast answer still gets one. CAPEVOLVE_STALL_SECONDS pins it
lower for a workload known to be fast.

E2E (c) redone without pre-seeding — the opening burst only, then quiet:

opening burst written; slowest COMPLETED gap = 0.00s
    wall   silence  OLD 300s floor   NEW        threshold
      0s      0.0s  quiet ok         live       3600s
      0s    300.2s  WOULD FIRE       live       3600s
      0s    600.2s  WOULD FIRE       live       3600s
      1s    900.2s  WOULD FIRE       live       3600s
      1s   1200.2s  WOULD FIRE       live       3600s
      1s   1500.2s  WOULD FIRE       live       3600s
      1s   1800.2s  WOULD FIRE       live       3600s
      2s   2100.2s  WOULD FIRE       live       3600s
      2s   2400.2s  WOULD FIRE       live       3600s
      2s   2700.2s  WOULD FIRE       live       3600s
      2s   3000.2s  WOULD FIRE       live       3600s
      3s   3300.2s  WOULD FIRE       live       3600s
      3s   3600.2s  WOULD FIRE       stalled    3600s

=== the first slow step finally returned, then finalized ===
{'silence': 0.0, 'threshold': 3600.0, 'slowest_gap': 3.0, 'events': 5,
 'finalized': True, 'alive': True}
done — finalize sealed the test split

Zero completed gaps and it holds live for the full hour, where the old rule fires at five
minutes — and it still trips eventually, so the bar rises rather than vanishing.

2. Blocking — stale marker condemned a live run

Two changes, because the finding has two halves:

  • classify now requires corroborating silence before crashed
    (CRASH_MIN_SILENCE_SECONDS = 60.0). A log that moved seconds ago proves some process is
    writing it, which outranks any marker claiming the owner is dead. This is what closes probe
    T, and it also covers the container sharing the host's UTS but not PID namespace, where the
    host check passes and a live pid is simply invisible.
  • _pid_alive now reads started — the field that was dead data — and compares it against
    the process's real start time via ps -o lstart= (available on macOS and Linux, no new
    dependency; /proc is Linux-only and psutil is a dep for one field). The marker is
    written after the owner exists, so the owner's real start can only be earlier; a process
    at that pid which began measurably later is somebody else. _PID_START_SLACK = 60.0
    absorbs ps second-granularity. Unknowable start time falls back to pid-only.

The 60s is small on purpose: a really dead process stops writing instantly, so its silence
clears the bar within a minute and crashed still arrives promptly. Verified on the real
SIGKILLed run — this is the one visible cost of the fix, stated plainly:

immediately after the kill: live  silence=20.6s alive=False
after 2m of silence: crashed CRASHED — the process that owned this run is gone and
                             it never finalized (last event 2.0m ago)
$ cap-evolve tail .capevolve/run_killed --from-start
CRASHED — the process that owned this run is gone and it never finalized (last event 2.0m ago)
tail exit=5

Verified against every case you asked for: reused dir + stale marker + live writer (probe T
✅), --resume (probe S ✅), a zombie (test_a_zombie_owner_is_stalled_not_crashedkill(0)
succeeds so it reads alive → stalled, never crashed), a pid from another container/host
(probe H ✅ alive=None), and a legacy marker with no started
(test_a_marker_without_started_still_works).

3. Blocking — hub failed vs DeepDive crashed

The zero-candidate branch moved below the liveness verdict in runs.py:_status.
crashed/stalled win: consistent, and more actionable — they name a gone or wedged process
where failed says only "produced nothing". A zero-candidate run with no liveness verdict on
offer is still failed.

Asserted end-to-end on a real run dir, replicating RunDeepDive.tsx's precedence
(test_the_hub_row_and_the_deepdive_badge_agree_on_a_zero_candidate_dead_run):

run dir        HUB       DEEPDIVE  SSE frame BADGE     agree
run_done       done      done      done      done      YES
run_killed     crashed   crashed   crashed   crashed   YES
zero-candidate + crashed → HUB=crashed DEEPDIVE=crashed BADGE=crashed  YES
zero-candidate + stalled → HUB=stalled DEEPDIVE=stalled BADGE=stalled  YES

4. Blocking — tail hung, and inconsistent exit codes

should_stop now runs the probe regardless of last, and the last is None guard suppresses
only the stalled branch. crashed is proof-based, so it holds whether or not this process
happened to see a line; stalled is a guess from silence, and a run may simply not have
started talking yet.

--- dead run, --from-start ---
CRASHED — the process that owned this run is gone and it never finalized (last event 10.0m ago)
exit=5
--- dead run, NO --from-start, --idle-timeout 30  (was exit 3) ---
CRASHED — the process that owned this run is gone and it never finalized (last event 10.0m ago)
exit=5
--- dead run, --idle-timeout 0 = wait forever  (was an infinite HANG) ---
CRASHED — the process that owned this run is gone and it never finalized (last event 10.0m ago)
exit=5
--- wedged fast run past the floor ---
STALLED — no events for 70.0m, over this run's own threshold 60.0m (floor). The process is
still alive — it may be wedged rather than dead.
exit=4
--- finalized run ---
done — finalize sealed the test split
exit=0
--- stale dead marker + LIVE writer (was crashed/exit 5) ---
timed out after 4s with no events from …/run_livewriter/events.jsonl
exit=3

Each exit-code path has a test, including the inverse
(test_tail_idle_timeout_zero_still_waits_forever_when_nothing_is_proven_dead: no marker →
alive is None → no proof → still waits, so the "wait forever" contract survives).

5. Non-blocking — SSE never closes on a finished run

Confirmed, not assumed. Driving the generator directly on this PR alone vs the merged
tree with #204:

# #218 alone
run_done     STILL OPEN after 4.0s    n=9   frames=['snapshot','status','status','status']...  'done' in frames=False
run_killed   CLOSED                   n=2   frames=['snapshot','status']                       'done' in frames=False

# merged with #204 (offset = 0)
run_done     CLOSED                   n=17  frames=['snapshot','event','event','event']...     'done' in frames=True
run_killed   CLOSED                   n=8   frames=['snapshot','event','event','event']...     'done' in frames=False

Your read is right: #204's offset = 0 replays the log, hits finalize, emits done, and
returns. No code change here; it is in the merge-order note below.

6. Non-blocking — full-log re-parse every 5s per connection

Fixed, and the fix is not the tail-window one: reading only the tail would lose old slow
gaps and lower the bar, which is the unsafe direction. Instead liveness_facts keeps the byte
offset and folds only new bytes into the previous scan, so each probe costs O(new bytes).
Silence is never cached — it is the one fact that changes while nothing on disk changes, which
is why liveness sits outside #194's cache in the first place. A shrunk/replaced file falls back
to a full re-read.

log lines=50000  size=5.7 MB

BEFORE:
first call (cold, full parse): 121.5 ms
repeat calls, file unchanged:  120.534 ms  (median 119.727 ms)
after ONE new event:           121.1 ms

AFTER:
first call (cold, full parse): 118.9 ms
repeat calls, file unchanged:    0.018 ms  (median 0.016 ms)
after ONE new event (incremental): 3.9 ms

per connection per hour @5s: 720 probes
  before: 85.6 s of parse work
  after:   0.013 s  (6441x less)

The events= kwarg is kept and still honoured for callers that already hold the parsed log.

7. Non-blocking — clock skew

Comment added naming the assumption, as you suggested; the mtime choice itself is unchanged.
liveness_facts' docstring now states that gaps come from the writer's t, silence from the
filesystem's mtime against the reader's now, so a skewed machine gets a correct-by-luck
answer — and why mtime is still right (it is the only signal a malformed event cannot forge,
and both surfaces read it identically).

8. Non-blocking — monotonic bar / late on real hangs

Partially improved and partially made worse, honestly: the bar is unchanged, so a run that
hangs right after its slowest 20-minute gap is still invisible for ~60 min (probe D), and a
fast run that wedges now waits 60 min instead of 5. What did improve is your "backwards"
observation: the feature no longer fires early on healthy first steps, so the tuning is now
consistently late-and-safe rather than early-on-healthy and late-on-hung. Given the asymmetry
you named, I am declining to tighten it further in this PR — crashed (the proof-based half)
is unaffected and instant, and CAPEVOLVE_STALL_SECONDS is the escape hatch for a workload
whose pace the user knows.

9. Non-blocking — test coverage

238 → 247. New: the first-slow-step case at four elapsed times plus the single-event shape
(#1), the impossibility proof for the suggested fix, live-writer-with-stale-marker and
pid-reuse-via-started (#2), zombie owner, legacy marker without started,
--idle-timeout 0 on a dead run and its inverse, dead run without --from-start (#4), and
hub/DeepDive agreement on the zero-candidate dead shape (#3). The three pre-seeded
"slow but healthy" tests are kept — they cover the derived bar, which is still correct — but
they are no longer the only false-positive coverage.

test_run_writes_a_pid_marker_so_liveness_is_knowable now pins the marker's location: it
asserts the exact (workdir / run_dir / "run.pid") expression and reads a marker back through
the real _owner_alive, checking it is found in the run dir and None one level up. It would
now fail if the marker moved. The source-text half is unavoidable (driving the real run
needs a skill tree, which test_e2e_slice owns) but it is no longer the whole test.

10. Non-blocking — --no-stall-check / pin not overridable

No change; your verification stands. The undocumented part is now documented: GETTING_STARTED
states that the pin does not suppress crashed, because a crash verdict is proof-based
rather than time-based.

11. Nit — exit-code table

Reordered 0 / 2 / 3 / 4 / 5, and 0 now reads "done or working" with an explicit
paragraph: "Do not branch on 0 to mean 'it finished'", plus what to check instead
(finalize in the log, final.json, or tail's last stderr line). The cli.py module
docstring says the same. The floor in the docs is updated to 60 min with the reasoning.

12. Nit — two hardcoded probe intervals

Named: _STALL_PROBE_SECONDS = 2.0 and _FOLLOW_STALL_PROBE_SECONDS = 30.0, together at the
top of cli.py with a comment on why they differ (interactive tail answers fast; run --follow owns the run and only needs to warn).

13. Nit — #217 constraint

Unchanged and still holds; no code on the stdout path was touched.


Verification

$ PYTHONPATH=core python -m pytest core/tests -q
247 passed in 82.61s (0:01:22)

$ cd dashboard/backend && PYTHONPATH=../../core:. python -m pytest tests -q
57 passed, 1 warning in 2.18s

$ python -m compileall -q core skills && echo COMPILEALL_CLEAN
COMPILEALL_CLEAN

$ cd dashboard/frontend && npx tsc -b --noEmit; echo "tsc rc=$?"
tsc rc=0
$ npm test
 Test Files  14 passed (14)
      Tests  53 passed (53)

247 core (+9) / 57 backend (+1) / 53 frontend / tsc rc=0 / compileall clean.
The #200 flake (test_maybe_launch_spawns_when_available) passed on every run here.

Real e2e, all three scenarios, no pre-seeded gaps:

=== e2e (a): a run that COMPLETES -> done ===
run exit=0
run.pid: {"pid": 61793, "host": "Oshers-MacBook-Pro-2.local", "started": 1785375512.32724}
[04:38:35] FINALIZE  test=1.0000 (baseline 0.0000, Δ+1.0000)  best=cand_0001
done — finalize sealed the test split
tail exit=0

=== e2e (b): a run KILLED mid-flight -> crashed ===
events=6  finalize=0
run.pid: {"pid": 62131, "host": "Oshers-MacBook-Pro-2.local", "started": 1785375515.452906}
CRASHED — the process that owned this run is gone and it never finalized (last event 2.0m ago)
tail exit=5

=== e2e (c): slow-but-healthy, FIRST slow step, nothing pre-seeded ===
(transcript under finding #1 — live for the full hour, then done)

Terminal ≡ dashboard on the same three dirs:

run dir        HUB       DEEPDIVE  SSE frame BADGE     agree
run_done       done      done      done      done      YES
run_killed     crashed   crashed   crashed   crashed   YES

$ for d in run_done run_killed run_slow; do cap-evolve tail $d --from-start; done
run_done     exit=0  done — finalize sealed the test split
run_killed   exit=5  CRASHED — the process that owned this run is gone and it nev…
run_slow     exit=0  done — finalize sealed the test split

(run_slow is a synthetic dir with events.jsonl + run.pid only, so the reducer skips it
on the hub — it has no splits.json. The terminal reads it fine, which is the point of the
shared classifier.)

Merged tree, #194 then #204, my fixes applied on top, app.py conflict resolved
three-way (keep #204's offset = 0, #194's payload-free snapshot, #218's last_status):

$ PYTHONPATH=core python -m pytest core/tests -q
264 passed in 77.64s (0:01:17)
$ cd dashboard/backend && PYTHONPATH=../../core:. python -m pytest tests -q
68 passed, 1 warning in 2.69s
$ cd dashboard/frontend && npx tsc -b --noEmit; echo "tsc rc=$?"; npm test
tsc rc=0
 Test Files  15 passed (15)
      Tests  60 passed (60)

264 core + 68 backend + 60 frontend (was 242/57/60 before these fixes — the delta is my
+9 core and +1 backend, plus #194's own tests).

Merge order

  1. feat(observability): live terminal progress via --follow and cap-evolve tail #191 — this PR's base, already merged in.
  2. perf(dashboard): memoize reduce_run on events mtime+size, drop dead SSE snapshot, paginate runs/rollouts #194 — merges clean; liveness() genuinely sits outside the cached reduce_run, so a
    cached reduction cannot serve a stale status. My Feat/cap evolve dashboard #6 fix is complementary: it caches the
    event-derived facts on the file stamp while silence stays uncached.
  3. feat(observability): classify a run as working / stalled / crashed / done #218 — after these fixes.
  4. fix(dashboard): render the live event ticker in the SPA; populate the algorithm label #204 last — one mechanical app.py conflict; its offset = 0 also fixes non-blocking
    Cost visibility & budget completeness: surface max_usd/max_metric_calls, track optimizer spend, add pre-run estimates #5, confirmed above by driving the generator on both trees.

Files touched

  • core/cap_evolve/eventstream.py — floor 300→3600s, CRASH_MIN_SILENCE_SECONDS,
    _proc_start_time/_PID_START_SLACK, _pid_alive(started=…), classify ordering,
    incremental liveness_facts + _scan + _FACTS_CACHE, clock-skew note
  • core/cap_evolve/cli.pyshould_stop probes regardless of last, named probe
    constants, exit-code docstring
  • core/tests/test_stall_detection.py — 21 → 30 tests
  • dashboard/backend/capevolve_dashboard/runs.py — liveness verdict before the
    zero-candidate branch
  • dashboard/backend/tests/test_stall_status.py — updated ordering test, new agreement test
  • docs/GETTING_STARTED.md — exit-code table, 60-min floor, pin-vs-crash note

OsherElhadad pushed a commit that referenced this pull request Jul 30, 2026
…ll-clock rate (#138 review)

Three evidence-header honesty defects from the #234 review, all fixed at the layer that
owns the fact rather than at the renderer.

1. `✓ Implement & check` claimed the hard gate passed on no evidence.
   The `check` phase lit off `target_profile` — logged by the ALGORITHM runner, AFTER
   baseline, only when a target model is configured — so any `--target-model` run rendered
   a green tick over the gate that guards all spend. `seed_dir_created` was no better: it
   fires inside `harness.baseline`, and only when the seed dir is missing.
   `cap-evolve run` now logs `check_gate` (ok, problems) from the gate itself, and that is
   the only kind the phase accepts. Silence about the hard gate reads `unknown` — never
   `done`, never `skipped`, because unlike `intake` there is no legitimate path that skips
   it. Proven on a real `--target-model` run: with `check_gate` -> done; with it stripped,
   `target_profile` alone -> unknown (that same log rendered `done` before).

2. The events-only burn understated GEPA 3.9x — $0.28 against a true $1.09.
   Fixed at the EVENT SOURCE, not the dashboard, because #191's `--follow` meter and every
   future consumer read the same events. `minibatch` now carries `cost_usd`/`tokens`
   (GEPA's rollouts never pass through `evaluate`, the only other runner-spend event), and
   `gepa_local_gate` carries `opt_cost_usd`/`opt_tokens` — the local gate, not
   `gepa_val_gate`, because the optimizer is paid every iteration while the val gate only
   fires on the ones that pass, so keying off it would still lose every locally-rejected
   iteration's spend. `accrue_totals`' elif-chain became one `_SPEND_SOURCES` table where
   each kind appears exactly once, which is what keeps a dollar counted once.
   On the real logs, re-priced per each algorithm's own `update_spent` calls:
   GEPA $0.36 -> $1.56 == Spent (was 0.23x); hill-climb and skillopt unchanged at MATCH.

3. The live rate divided by the event span, not wall clock.
   `last_t - first_t` freezes the instant the log goes quiet, so a run 58 minutes into one
   slow step reported 30x the honest $/min — the same class as the `$18.69/min` already
   fixed, surviving in the live branch. The denominator is now `now - first_t`, and the
   rate is suppressed once the log has been silent past `_RATE_STALE_SECONDS`: a quiet log
   supports no recent-burn claim at all. Verified: the 30x case -> None; a live run with a
   current log still gets a rate, off wall clock (the span would have claimed 1.5x more).
   Swept every rate/percentage/average denominator — all eight edge cases yield None or a
   guarded value, including a backwards clock and out-of-order timestamps.

Merged-header contradiction (#218 + #221 + this). A phase must not read as *currently
active* when liveness says the run is dead or wedged: that is where the run STOPPED, not
what is running. `derive_pipeline` takes `liveness` and renders the latest phase
`interrupted` for crashed/stalled, and `EvidenceHeader` takes the same value the
StatusBadge beside it renders, so the two cannot disagree. `aria-current="step"` goes with
it — it claims "this is where you are". Verified on the merged tree with #218's own
`classify`: no contradictory pair in any of its four states. #221's plateau is left out on
purpose: "live and plateaued" is coherent, "live and crashed" is not.

Non-blocking + nits:
* An errored phase can no longer render as `skipped` or `done`. `skipped` says
  "legitimately not run" and `done` says "completed"; a phase whose only evidence is
  failure is neither, so it reads `errored`. A `check_gate` attesting its own FAILURE is
  likewise not evidence of a pass.
* Dropped the three dead `_PHASE_KINDS` entries (`algorithm`, `diagnose`, and the
  misattributed `target_profile`); a test now asserts every remaining kind is really
  emitted in core/ and that no kind is claimed by two phases.
* `metric_direction` deleted, not rewired: it was a hardcoded constant whose
  `lower_is_better` branch nothing could reach, with a frontend test asserting a value the
  backend cannot produce. Net deletion across four files; the renderers state the constant.
* Declined: a shared 1s tick for `useSecondsSince` (cosmetic, one interval per header).
  #194's reduce cache is not in this tree, so its `state.json` coupling is contingent on
  that merge — documented at the call site, and the rate can only ever decay to `None` as
  a run goes quiet, never grow into a fabricated figure.

Two claims corrected from the previous commit message: the naive-sum overstatement is
1.26x, not "~2x" (the 2x figure is #191's different arithmetic), and the three-way
$0.8100 equality holds for hill-climb only — it is exactly the generalisation to GEPA that
finding 2 was.

Tests: +9 core (burn == Spent for EVERY algorithm, the emitter contract, optimizer spend
on locally-rejected GEPA iterations, check-phase evidence, the stale-rate 30x case, dead
run -> interrupted, errored != skipped, backwards clock, kind-table drift), +4 frontend.
235 core (1 pre-existing #200 port-7878 flake, fails identically on b35e390), 42 backend,
65 frontend, tsc clean, compileall clean. dist/ untouched (#188).
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.

Distinguish a stalled/hung run from idle/done (SSE 5-min idle + coarse status heuristic)

3 participants