Description
While attempting to live-verify the bg: N enrich, M telem TUI status-bar segment (coverage-status.md row "BackgroundSupervisor Phase 2", deferred from ci-1386 for a retry with a forced backlog), the segment never rendered across two full live-testing sessions — despite confirming, via code reading and log evidence, that background enrichment tasks (memory.graph extraction) genuinely run in-flight for 20-30 seconds after every turn.
Root cause: Agent::reap_background_tasks_and_update_metrics (crates/zeph-core/src/agent/mod.rs:1278) is documented as "Called at the top of each turn, before any user message processing" — this is the only call site that refreshes MetricsSnapshot.bg_enrichment_inflight/bg_telemetry_inflight (crates/zeph-core/src/agent/mod.rs:1289-1290) from BackgroundSupervisor::metrics_snapshot(). Since enrichment tasks (graph/persona/trajectory extraction, spawned from persist_message after a turn's response) run after a turn completes, and the metrics are only refreshed before the next turn starts, the bg: N enrich, M telem segment can only ever show a non-zero value in the narrow case where a new turn's reap happens to run while the previous turn's background task is still in flight. If the user does not send another message during that ~20-30s window (the common case — most users pause to read the response), the segment permanently displays 0/absent for that backlog, even though real background work is actively running.
This contradicts the TUI Rule in CLAUDE.md ("Any background or implicit operation in the TUI ... must be accompanied by a visible system status indicator ... The user must always know what is happening behind the scenes") — the current turn-gated refresh means the indicator is frequently absent exactly when it would be most informative (while the user is idle, waiting, and the background task is the only ongoing activity).
Reproduction Steps
- Config: scratch copy of
.local/config/testing.toml with [agent.supervisor] enrichment_limit = 1, telemetry_limit = 1, local Ollama provider (gemma4:26b) for chat + memory.graph.extract_provider (cloud accounts exhausted, standard workaround).
cargo run --features full -- --config <scratch-config> --tui- Send a conversational message (e.g. "Tell me a short 3-sentence story about X.") and wait for the response.
- Observe the debug log (
.local/testing/debug/zeph-acp.<date>.log in this build — tracing writes to a dated file appender in TUI mode, not to the redirected stderr) for zeph_memory::semantic::graph: graph extraction timed out, which fires ~20-30s after the response (matching extraction_timeout_secs) — confirming a real, ~20-30s-long background task is in flight during that window.
- Poll the TUI status bar every 1s throughout that entire window (verified across two independent turns with dense 1s-interval polling spanning the full 20-30s extraction window each time) — the
bg: N enrich, M telem segment never appears.
- Attempting the workaround of sending a second message immediately when the first response completes (to force a new turn's
reap() to run while the first turn's enrichment is still in flight) also did not reliably produce the segment — the new turn's own reap() appears to run essentially immediately after the message is submitted, likely winning the race against persist_message's enrichment-task spawn from the previous turn (which itself only happens after the response is fully persisted).
Expected Behavior
Per the TUI Rule, any in-flight background task should be visibly indicated to the user for as long as it is actually running — not only during the brief, hard-to-hit window where a new turn's start happens to coincide with a still-running previous-turn background task.
Actual Behavior
bg_enrichment_inflight/bg_telemetry_inflight are only ever refreshed once per turn, at turn start (reap_background_tasks_and_update_metrics, crates/zeph-core/src/agent/mod.rs:1278), so the segment is effectively invisible during the common "respond then wait" idle period, which is exactly when background enrichment work is happening.
Environment
- Version: 0.22.0 (unreleased), commit
1fe1d0e2
- Config:
.local/config/scratch-1387-bgsup.toml (scratch copy of .local/config/testing.toml), [agent.supervisor] enrichment_limit = 1, telemetry_limit = 1
- Features:
full, --tui
- Provider: local Ollama
gemma4:26b (cloud exhausted)
Logs / Evidence
2026-07-14T10:53:52.762716Z WARN zeph_core::agent: context preparation timed out; proceeding with degraded context timeout_secs=30
2026-07-14T10:54:12.192551Z WARN zeph_memory::semantic::graph: graph extraction timed out
(~20s gap between response and the enrichment task's own timeout — confirming it was genuinely in flight that whole time) — during this exact window (12:53:40-12:55:40 local time, dense 1s-interval tmux capture-pane polling), the status bar's last segment never once read bg:.
Also noted in passing (secondary observation, not filed separately): the bg_task{class="enrichment", task="graph_extraction"} tracing span from BackgroundSupervisor::spawn (crates/zeph-core/src/agent/agent_supervisor.rs) does not appear to wrap the "graph extraction timed out" log line even though SemanticMemory::spawn_graph_extraction's inner tokio::spawn is EXEMPT-annotated as "awaited inside BackgroundSupervisor task" (crates/zeph-memory/src/semantic/graph.rs:910) — the inner tokio::spawn'd task appears to run outside the outer span's instrumented context (a .instrument() on an outer future does not propagate into a separately-spawned nested task). This is a tracing/observability gap, not the root cause of the missing status-bar segment (the atomic class_inflight counter is updated synchronously by the outer, correctly-instrumented BackgroundSupervisor::spawn() closure regardless of the inner task's span attribution), but worth a look if a follow-up touches this code.
Related
.local/testing/coverage-status.md row "BackgroundSupervisor Phase 2 (supervisor metrics)" — this issue supersedes the "timing/observation miss" theory from ci-1386 with a structural root cause.
Description
While attempting to live-verify the
bg: N enrich, M telemTUI status-bar segment (coverage-status.mdrow "BackgroundSupervisor Phase 2", deferred from ci-1386 for a retry with a forced backlog), the segment never rendered across two full live-testing sessions — despite confirming, via code reading and log evidence, that background enrichment tasks (memory.graphextraction) genuinely run in-flight for 20-30 seconds after every turn.Root cause:
Agent::reap_background_tasks_and_update_metrics(crates/zeph-core/src/agent/mod.rs:1278) is documented as "Called at the top of each turn, before any user message processing" — this is the only call site that refreshesMetricsSnapshot.bg_enrichment_inflight/bg_telemetry_inflight(crates/zeph-core/src/agent/mod.rs:1289-1290) fromBackgroundSupervisor::metrics_snapshot(). Since enrichment tasks (graph/persona/trajectory extraction, spawned frompersist_messageafter a turn's response) run after a turn completes, and the metrics are only refreshed before the next turn starts, thebg: N enrich, M telemsegment can only ever show a non-zero value in the narrow case where a new turn's reap happens to run while the previous turn's background task is still in flight. If the user does not send another message during that ~20-30s window (the common case — most users pause to read the response), the segment permanently displays 0/absent for that backlog, even though real background work is actively running.This contradicts the TUI Rule in
CLAUDE.md("Any background or implicit operation in the TUI ... must be accompanied by a visible system status indicator ... The user must always know what is happening behind the scenes") — the current turn-gated refresh means the indicator is frequently absent exactly when it would be most informative (while the user is idle, waiting, and the background task is the only ongoing activity).Reproduction Steps
.local/config/testing.tomlwith[agent.supervisor] enrichment_limit = 1,telemetry_limit = 1, local Ollama provider (gemma4:26b) for chat +memory.graph.extract_provider(cloud accounts exhausted, standard workaround).cargo run --features full -- --config <scratch-config> --tui.local/testing/debug/zeph-acp.<date>.login this build — tracing writes to a dated file appender in TUI mode, not to the redirected stderr) forzeph_memory::semantic::graph: graph extraction timed out, which fires ~20-30s after the response (matchingextraction_timeout_secs) — confirming a real, ~20-30s-long background task is in flight during that window.bg: N enrich, M telemsegment never appears.reap()to run while the first turn's enrichment is still in flight) also did not reliably produce the segment — the new turn's ownreap()appears to run essentially immediately after the message is submitted, likely winning the race againstpersist_message's enrichment-task spawn from the previous turn (which itself only happens after the response is fully persisted).Expected Behavior
Per the TUI Rule, any in-flight background task should be visibly indicated to the user for as long as it is actually running — not only during the brief, hard-to-hit window where a new turn's start happens to coincide with a still-running previous-turn background task.
Actual Behavior
bg_enrichment_inflight/bg_telemetry_inflightare only ever refreshed once per turn, at turn start (reap_background_tasks_and_update_metrics,crates/zeph-core/src/agent/mod.rs:1278), so the segment is effectively invisible during the common "respond then wait" idle period, which is exactly when background enrichment work is happening.Environment
1fe1d0e2.local/config/scratch-1387-bgsup.toml(scratch copy of.local/config/testing.toml),[agent.supervisor] enrichment_limit = 1, telemetry_limit = 1full,--tuigemma4:26b(cloud exhausted)Logs / Evidence
(~20s gap between response and the enrichment task's own timeout — confirming it was genuinely in flight that whole time) — during this exact window (12:53:40-12:55:40 local time, dense 1s-interval
tmux capture-panepolling), the status bar's last segment never once readbg:.Also noted in passing (secondary observation, not filed separately): the
bg_task{class="enrichment", task="graph_extraction"}tracing span fromBackgroundSupervisor::spawn(crates/zeph-core/src/agent/agent_supervisor.rs) does not appear to wrap the "graph extraction timed out" log line even thoughSemanticMemory::spawn_graph_extraction's innertokio::spawnisEXEMPT-annotated as "awaited inside BackgroundSupervisor task" (crates/zeph-memory/src/semantic/graph.rs:910) — the innertokio::spawn'd task appears to run outside the outer span's instrumented context (a.instrument()on an outer future does not propagate into a separately-spawned nested task). This is a tracing/observability gap, not the root cause of the missing status-bar segment (the atomicclass_inflightcounter is updated synchronously by the outer, correctly-instrumentedBackgroundSupervisor::spawn()closure regardless of the inner task's span attribution), but worth a look if a follow-up touches this code.Related
.local/testing/coverage-status.mdrow "BackgroundSupervisor Phase 2 (supervisor metrics)" — this issue supersedes the "timing/observation miss" theory from ci-1386 with a structural root cause.