Engine silently freezes mid-run: user messages are persisted but never answered; no error, no log line, no crash entry

[bevis-wong]

Body

### Environment

- codewhale 0.9.13 (Rust TUI), linux x86_64
- provider: zai, model: GLM-5.3-Flash
- posture: Ask / workspace-write

### Summary

During long, tool-heavy runs the engine stops producing model output mid-turn.
Everything the user types afterwards is persisted into the session journal but
never answered. The stall is completely silent: no ERROR/WARN in the TUI log,
no crash entry, the spinner just keeps absorbing input.

This happened twice in two independent sessions on consecutive days.

### Steps to reproduce (observed, not deterministic)

1. Run an interactive session with a long skill-driven task that issues many
   bash tool calls (session A), or a multi-turn task with tool approval
   round-trips (session B).
2. Mid-run, the model stops emitting output (session B stalled right after an
   assistant thinking block, before any text/tool output).
3. Send follow-up user messages. They are accepted and persisted.
4. No reply ever arrives; force-quit is the only way out.

### Observed evidence (timestamps UTC)

Session A `a69916b2…` (2026-09-14):

- TUI log `tui-2026-09-14-2784622.log` ends at `10:51:38` with
  `engine.turn completion settled status=Completed delivered=true`.
- The session demonstrably continued for hours after that line and stalled
  later. The entire stall window produced **zero** additional log lines —
  the freeze is invisible to the log.
- Journal tail contains three consecutive `user` entries with no assistant
  response after them (a Chinese follow-up question, `"hello?"`, and a
  `/feedback bug` draft request).
- On-disk session JSON is structurally intact: 95 journal entries, valid
  `leaf_id` pointing at an existing entry, undamaged parent chain.

Session B `53b16822…` (2026-09-15):

- Assistant emitted a thinking block, then stalled before any text or tool
  output. A later `"继续"` (continue) user message also got no response.
- On force-quit, the TUI logged **two** pending turns at the same moment:

2026-09-15T03:27:48.318072Z INFO engine.turn: engine turn completion settled status=Interrupted delivered=true
2026-09-15T03:27:48.548725Z INFO engine.turn: engine turn completion settled status=Interrupted delivered=true

Note `delivered=true` even though the user received no model output for
either turn — the flag does not mean the user saw anything.

- `~/.codewhale/crashes/` is empty in both cases.

### Expected

- A stalled provider stream should be subject to a read/response timeout and
surface a visible error in the UI.
- Queued user messages during a stalled turn should be rejected or reported,
not silently absorbed.
- `delivered=true` on an Interrupted turn should not be recorded when nothing
was ever rendered to the user.

### Impact

Long tasks can absorb follow-up messages indefinitely with zero feedback. The
user cannot distinguish "still working" from "dead" and must force-quit, which
then triggers the separate resume bug (filed separately).

### Hypothesis (unconfirmed)

No network-layer logs are available, so the transport-side root cause is
unknown. Suspected: a zai streaming hang with no read timeout in the harness.
Regardless of the transport cause, the missing stall detection and the silent
absorption of user messages are harness-side gaps.

---
Sanitized log excerpts: see `attachment-issue-1-logs.en.md`.

attachment-issue-1-logs.en.md

[github-actions]

Thanks @bevis-wong for the report.

This issue is staying open for maintainer triage. CodeWhale gets better because people bring us real edge cases from real machines, providers, regions, and workflows.

If you can add a reproduction, logs, version output, screenshots, or the provider/model involved, that makes it much easier for us to verify and harvest the fix. Maintainers may comment /lgtmi to mark recurring issue reporters as approved so this intake note is skipped next time.

[Hmbown]

Confirmed and taking this. The evidence maps to two distinct harness gaps, tracked separately:

• No stall detection on the provider stream — a hung response is indistinguishable from "still working", so nothing bounds the wait. That's a harness-side gap regardless of the transport cause.
• Silent absorption of queued user messages — input accepted and journaled while a turn can never answer it is a real defect; the journal write is not the problem, the missing surface is.

The delivered=true on Interrupted turns that rendered nothing is also worth its own look — the flag currently records delivery to the event channel, not visibility.

Investigation is starting against v0914-chunk2 (the active milestone branch). Will post findings here.

[Hmbown]

Diagnosis (read-only source inspection, v0914-chunk2)

The seam: persistence happens before engine admission — dispatch.rs:633-654 pushes the user message + is_loading optimistically, then a raw tokio::spawn (dispatch.rs:718, unsupervised, dropped JoinHandle) runs route-plan → reserve_owned().await → closure delivery. A message can be durable while no executable turn exists or completes.

Ranked root-cause hypotheses:

H1 — Unbounded post-turn settlement barrier withholds TurnComplete. handle_send_message awaits barrier.cancel_and_flush()/continue_and_flush() after run_turn returns but before emitting TurnComplete (engine.rs:5390-5396). ForegroundChildRegistry::settle_and_wait (subagent/mod.rs:2473-2517) loops settled.changed().await until children empty — no timeout, and it does not select on self.cancel_token, so Esc cannot break it. A child parked on an await that doesn't observe its token (tool handlers, manager.write().await, inbox waits) keeps the turn without a terminal event for up to the 30-min child wall clock. is_loading stays true → submits queue → persisted → never answered. Meanwhile the still-"Running" child suppresses every watchdog and its events keep refreshing turn_last_activity_at.

H2 — Dropped AgentComplete poisons has_running_agents, silencing all watchdogs. Lifecycle events use event_tx.try_send + let _ = on a cap-256 channel (subagent/mod.rs:7479, 16518, 2262). A dropped terminal event leaves a ghost Running entry; the pending_subagent_list_refresh repair is armed only by received events — self-masking. Every reconcile_turn_liveness branch is gated on !has_running_agents (session_state.rs:167,200,224,244) — one ghost disables all four watchdogs.

H3 — The unsupervised dispatch task dies/parks before delivering its closure. dispatch.rs:718 is raw tokio::spawn, not spawn_supervised; reserve_owned().await on cap-32 tx_op is unbounded (parks behind a wedged engine — composes with H1). If the closure never lands: dispatch_in_flight stays true, dispatch_started_at stays None, and no watchdog covers that state — branch 1 requires dispatch_started_at.is_some(), the rest need a runtime_turn_status that never gets set. Exact symptom match.

H4 — Dropped ApprovalRequired while !is_loading. ignore_stale_stream_event_while_idle (ui.rs:1143-1158) silently drops ApprovalRequired when !is_loading; await_tool_approval (approval.rs:165-218) has no timeout — the turn parks forever, next op sits behind it.

H5 — No response-headers timeout. create_message_stream selects on cancel (Esc works) but the client has connect_timeout only, no overall/headers timeout (client.rs:1866-1873). A server that accepts and never replies parks the turn; watchdogs would catch it unless H2 silences them.

Cleared: engine run-loop exit (impossible while Engine holds a tx_op), run_turn panic (catch_unwind → Failed TurnComplete), child task panic (supervised), MCP tool hang (timeouts exist), lost-wakeup queue drain.

Fix shape: (a) bound settle_and_wait — race a timeout + engine cancel_token, emit TurnComplete(Failed) naming the stuck child; (b) guarantee TurnComplete on every handle_send_message path; (c) lifecycle events must not try_send+drop on a bounded channel; (d) monitor_turn needs a receive timeout/heartbeat (the #5497 hole); (e) supervise the dispatch task and cover dispatch_in_flight-stuck-without-dispatch_started_at; (f) a Running agent older than a bound should read as suspect, not exonerating.

H1 is the best single fix — withholding the terminal event is strictly worse than a leaked child.

[Hmbown]

New candidate root cause, arrived at by ruling out the obvious ones. Every step below is read from the code on v0914-chunk2; what is inference is marked as such.

What it is not

The natural theory is that a sub-agent child parks forever, so the turn never completes. That does not survive reading:

tokio::time::timeout_at(deadline, run_subagent(...)) at tools/subagent/mod.rs:11650 wraps the child future directly — it is not timeout_at(.., spawn(..)) returning a JoinHandle. That distinction decides the question. A Timeout whose inner future is parked on a pending .await still fires: the timer waker makes Timeout::poll return Ready(Err(Elapsed)) without polling the inner future again, then drops it. Drop-cancellation needs no cooperation from the child — no cancel-token check, no resolving await.

So a child blocked on backpressure is bounded by its wall clock, and the settlement barrier that waits on those children is bounded too. "Hours" cannot come from in-child parking, and the fix for that in 7c74ecf0f (bounding the turn-end foreground-child join) correctly closed that half.

Where it actually is

The reported last log line is the tell:

engine.turn completion settled status=Completed delivered=true

The barrier emptied. Whatever holds the turn is therefore post-settlement — after the children are gone — and that is where the one genuinely unbounded wait lives.

TurnMailboxBarrier::flush (core/engine.rs:7751-7754):

async fn flush(self) {
    self.mailbox.seal();
    let _ = self.flush_tx.send(());
    let _ = self.drain_handle.await;   // no deadline
}

drain_handle is the subagent-mailbox-drainer task (engine.rs:4478). Its loop has exactly three exits — the flush branch running to completion, recv() returning None, or a forward returning false:

'drain: loop {
    tokio::select! {
        biased;
        _ = &mut flush_rx => { for envelope in receiver.drain_available() {
                if !forward_subagent_mailbox_message(..).await { break 'drain; } }
              break; }
        envelope = receiver.recv() => { ...
              if !forward_subagent_mailbox_message(..).await { break; } }
    }
}

and forward_subagent_mailbox_message ends in (engine.rs, same module):

tx.send(event).await.is_ok()

on tx_event, which is mpsc::channel(256) (engine.rs:1459). There is a try_send best-effort path for some message classes, but the terminal path is a blocking send().await.

The deadlock

tokio::select! stops racing its branches once a branch is chosen and its body is running. So if the drainer is inside forward_subagent_mailbox_message(..).await in the recv() branch, and the UI has stopped draining rx_event so the 256-slot channel is full, then:

1. the forward blocks on send().await with no deadline;
2. flush_rx is signalled but never observed, because select! is not polling it;
3. the drainer never exits;
4. flush()'s drain_handle.await never returns;
5. the turn never completes.

Nothing in that chain has a wall clock. The flush branch is not an escape either — it awaits the same blocking forward in a loop.

This fits every reported symptom: settlement is the last thing logged; the silence is total and lasts hours rather than 30 minutes; later user messages are journalled by the UI but never answered because no turn can start; and running_agent_count never decrements, which is the one gate that silences all four UI watchdogs indefinitely.

What is inference

That the UI stopped draining rx_event in these two sessions is not established — it is the precondition the mechanism needs, and it is unproven. Long tool-heavy runs with sub-agent mailbox traffic are the plausible way to fill 256 slots, which matches both reports, but that is reasoning from shape rather than evidence.

@bevis-wong, one cheap thing would discriminate it if you can still reproduce: at the moment of the freeze, a SIGQUIT or tokio-console task dump showing whether a task named subagent-mailbox-drainer is pending inside a send. That single fact confirms or kills this outright.

Suggested fix shape

Not "raise the channel capacity" — that moves the cliff. The three pieces:

1. flush() must bound drain_handle.await and abort the drainer on expiry, the same way 7c74ecf0f bounded the child join.
2. The drainer must not be able to miss a flush signal it has already been sent: either check flush_rx inside the forward loop, or make the forward itself cancellable by the flush/cancel token.
3. forward_subagent_mailbox_message's blocking send().await needs a deadline or a drop policy, so a non-draining consumer degrades (shed, or log and drop) instead of parking the engine forever.

(1) alone stops the hang. (2) and (3) stop it recurring by another door.

Worth noting for #6212: this is the same class as the bounded-queue work — a bounded channel whose producer blocks forever is a liveness bug, not a memory fix.

[Hmbown]

Correcting my comment above. I put the drainer-deadlock theory through an adversarial pass and most of it does not survive. Posting the refutation rather than leaving a plausible-but-wrong root cause standing, because it would send whoever picks this up in the wrong direction.

What breaks

The select! argument is wrong. I claimed the drainer "never observes flush_rx" once it is inside a branch body. select! is race-then-body, so it is true the other branch is not polled during the handler's await — but flush_rx is a sticky signal (flush_tx.send(()) with no await). Missing it while busy does not lose it; with biased and flush first, the next loop iteration observes it immediately.

Worse for my argument: both branches call the same forward(..).await. Even when the flush branch wins, it blocks on the identical tx.send().await. So the recv-vs-flush distinction I built the mechanism on is a red herring — select! contributes serialization delay and nothing else.

Bounds I overlooked. send() fails fast if rx is dropped (returns false → break). One recv() unblocks one send() — the consumer needs to drain one message, not 256. The first 256 sends never block at all. Some message classes take the try_send path and never block, and I never established that the stuck envelope was a blocking-class one. seal() plus recv() → None → break bounds the loop, so at most a single forward can stick, not the loop.

I quoted counter-evidence as support. delivered=true on the settlement line means delivery was working moments before the alleged stick. That is evidence against the channel being full at that instant, not for it.

"Nothing in that chain has a wall clock" was overreach. Three snippets cannot establish that. An outer turn or flush timeout is not ruled out.

The link that actually fails

My mechanism explains one hung task, not the reported symptom. send().await and drain_handle.await are async waits that yield the thread — journal writes, heartbeats and the 30-minute child timeout_at all keep running. But the report is total silence for hours, and a parked child must be drop-cancelled at its deadline.

Two deadlines passing with no timeout log falsifies single-task deadlock as the whole story. And the fact that later user messages still reach the journal proves some paths were alive while logging and answering were dead. That points at an executor stall, a logging/event-pipeline stall, or a blocking synchronous primitive on a runtime thread — not one task parked on an mpsc.

And it would need a coincidence stack

Pressure is highest during a tool-heavy turn, so a slow consumer would stall before settlement, not after delivered=true. A normal flush is often a no-op: mailbox already empty, drain_available() returns zero, flush branch breaks without any send. To hang post-settlement you would need seal-time backlog > 0 and blocking-class and rx_event exactly full in the window after delivered=true and consumer drain rate going to literally zero at settlement and staying there for hours.

That last one is not a primitive: a consumer alive enough to hold rx open but dead enough to never recv() for hours is itself an independent hang — which would be the actual root cause, with the drainer as a victim rather than a culprit.

What still stands

Two defensive points survive on their own merits, independent of whether they caused this:

• flush() awaiting drain_handle with no deadline is an unbounded wait in a shutdown path, and should be bounded with an abort on expiry the way 7c74ecf0f bounded the child join.
• forward_subagent_mailbox_message's blocking send().await on a bounded channel is a liveness hazard: a non-draining consumer should cause shedding or a logged drop, not an indefinite park.

Both are worth doing. Neither is established as the cause here.

The falsifier

One observation decides it: rx_event's queue depth and consumer liveness during the freeze, or simply whether any 30-minute child timeout fired. If the channel was not full, or a timer fired and merely failed to log, the drainer theory is dead and the real question becomes why the logging stopped while the journal kept accepting writes.

@bevis-wong — that reframes what would help most. Rather than the mailbox, the useful evidence is whether anything at all was still logging: a SIGQUIT dump at the moment of the freeze would show every task's state at once and settle this in one shot.