[BUG] Stall detection cannot see a session idling inside a tool call: pane-log re-arm keeps the grace alive through `sleep`

Bắt đầu với generic.py, xung quanh _log_activity_key, vòng lặp stall-deadline gần dòng 811 và _sample_weighted_usage gần dòng 1154; sau đó kiểm tra policy.py để xem các thiết lập stall và các giao diện TUI/journal. So sánh mức tăng của bản ghi trực tiếp với hoạt động của pane-log và xác định cách ghi lại cũng như hiển thị thời gian nhàn rỗi mà không coi mọi lệnh gọi công cụ kéo dài là stall; hoàn tất khi khoảng thời gian nhàn rỗi hiển thị trong run record, journal và TUI.

Description

_log_activity_key re-arms dev_stall_grace_s from the tee'd pane log's (mtime_ns, size). A coding CLI repaints its spinner every second while it is blocked inside a tool call, so the pane log grows the whole time. The grace therefore cannot expire while a session sits in sleep, and a session that keeps its turn alive by polling — sleep 590; cat <background-task-output> — is indistinguishable from one streaming a diff.

Nothing in the run record separates the two. nudges stays 0, the heartbeat stays fresh, session-start is the last journal event, and the TUI shows a working session. The only bound is session_timeout_min.

This is the shape #157 named but did not file: "because the session never ends a turn, it never emits a result-less Stop, so dev_stall_grace_s / dev_stall_nudges never engage." #157 asked for prompt teardown once timeout_s fires. This asks for the gap before that: for the hours in between, the orchestrator has no signal at all.

Why sessions do this now. #109 / PR #122 ship CLAUDE_CODE_DISABLE_BACKGROUND_TASKS=1 to stop a session yielding its turn to a background subagent. That removed the sanctioned path but not the incentive: there is still no background-completion re-invocation, so yielding costs a 600 s grace plus a nudge that is itself a submitted turn (dev_stall_nudges_cap, #149). Waiting in-band with sleep is cheaper for the session — and it is the one shape no detector sees. The guard did not remove the wait; it moved the wait somewhere invisible.

Steps to reproduce

1. Claude adapter, stock profile (so CLAUDE_CODE_DISABLE_BACKGROUND_TASKS=1 is set), dev_stall_grace_s = 600.
2. Run a story whose dev session spawns a subagent and then polls for its result rather than doing the work inline — e.g. sleep 590; cat <task-output-file>, repeated. 590 s is the longest sleep that fits one Bash call, whose timeout caps at 600000 ms.
3. Watch bmad-loop tui and the journal.

Expected behavior

Time a session spends idle inside a tool call is visible. At minimum the run record should let an operator answer "how much of this session's wall clock was spent doing nothing", and the TUI should not present such a session identically to a working one.

Actual behavior

The session reads as healthy for as long as it likes. stall_nudges_sent stays 0 because the grace deadline is pushed forward by every spinner repaint. No journal event marks the idle stretch. session_timeout_min is the only backstop, and it fires on total elapsed time, not on idleness.

Operator-side measurement over two runs on 0.11.0 (Claude adapter, macOS): one review session spent 44.2 of 64.2 minutes in sleep, another 17.0 of 31.8, and one dev session 90 of 107 minutes — 84%. Three single-subagent spawns accounted for 80% of that dev session's sleep; fan-outs amortise one wait across several agents and cost little. Four of seven sessions in the same runs never slept at all, including one that drove 22 subagents through 87 minutes, so this is session improvisation the loop currently permits rather than a deterministic path. Those runs are on a different machine from the checkout these line references were read on, so the numbers are quoted as operator measurements rather than attached artifacts. The run directories still exist and I can pull the journals or a diagnose dump if that would help. The code-level argument above stands on its own either way.

Suggested direction

The adapter already holds what it needs. transcript_path arrives on the first hook event and _sample_weighted_usage already polls that live file mid-turn for token spend. A session inside sleep appends no transcript entries and its weighted usage does not move, while the pane log keeps growing — so the two signals disagree exactly when the session is idle.

Worth separating, because they differ in risk:

1. Observability (low risk). Track time since the last transcript append alongside the pane-log key. Surface it in the TUI and journal an event when it crosses a threshold. This alone turns an invisible 90 minutes into a visible one and costs nothing in false stalls.
2. Bounding (needs design). Do not simply stall on absent transcript growth — a legitimately long single tool call looks the same (#157's 59-minute docker run is the counter-example). If a bound is wanted it needs its own knob and a way to tell a blocked tool call from a deliberate poll.

The upstream shape behind all of it — no background-completion re-invocation — is noted for context, not proposed here. As long as it is absent, sessions have a standing incentive to wait in-band, and item 1 at least makes the cost measurable.

Filing this separately from #109 because that issue's resolution is shipped and works for what it targeted; this is the pressure that moved elsewhere afterwards.

Which area is this for?

Orchestrator / control loop

bmad-loop Version

0.11.0

Which coding CLI are you using?

Claude (claude)

Operating System

macOS

Relevant log output

generic.py:971  _log_activity_key -> (st.st_mtime_ns, st.st_size) of logs_dir/<task_id>.log
generic.py:811  key = self._log_activity_key(...); if key != last_activity: stall_deadline = now + grace
generic.py:1154 _sample_weighted_usage(transcript_path, spec)   # live transcript already polled mid-turn
policy.py:104   dev_stall_grace_s = 600
policy.py:122   dev_stall_nudges_cap = 6

Confirm

• I've searched for existing issues (#109, #149, #157, #158, #470 are related; none covers in-tool idle detection)
• I'm using the latest version