From 22c5684b983eac6a81ee015ae80296c4b3dbf5bb Mon Sep 17 00:00:00 2001 From: Teknium <127238744+teknium1@users.noreply.github.com> Date: Mon, 7 Sep 2026 01:47:04 -0700 Subject: [PATCH] fix(agent): clear resumed stream wait status without synthetic reasoning --- agent/chat_completion_nonstream.py | 2 +- agent/chat_completion_stream_monitor.py | 16 +++++- tests/agent/test_nonstream_wait_notice.py | 5 +- tests/agent/test_stream_wait_notice.py | 54 +++++++++++++++++++ website/docs/user-guide/configuration.md | 2 +- .../current/user-guide/configuration.md | 2 +- 6 files changed, 73 insertions(+), 8 deletions(-) create mode 100644 tests/agent/test_stream_wait_notice.py diff --git a/agent/chat_completion_nonstream.py b/agent/chat_completion_nonstream.py index 2c42f80e38..635e83d663 100644 --- a/agent/chat_completion_nonstream.py +++ b/agent/chat_completion_nonstream.py @@ -132,7 +132,7 @@ class _NonStreamRequest: # next heartbeat: reasoning callbacks do not reset the CLI spinner. if (self.wait_notice_started_ts is not None and activity_ts is not None and activity_ts > self.wait_notice_started_ts): - self.agent._emit_wait_notice("Thinking...") + self.agent._emit_wait_notice("") self.wait_notice_started_ts = None if not heartbeat: return diff --git a/agent/chat_completion_stream_monitor.py b/agent/chat_completion_stream_monitor.py index 869cbed870..853a3ebd68 100644 --- a/agent/chat_completion_stream_monitor.py +++ b/agent/chat_completion_stream_monitor.py @@ -21,6 +21,7 @@ class StreamingWaitMonitor: m.last_load_poll = now _load_notice = _managed_local_load_notice(self.agent, self.api_kwargs) if _load_notice is not None: + m.wait_notice_started_ts = None # The local loader now owns the display. self.agent._emit_wait_notice(_load_notice) self.agent._touch_activity("local model loading") m.load_notice_shown, m.load_notice_misses, m.last_heartbeat = True, 0, now # loading IS liveness @@ -40,8 +41,9 @@ class StreamingWaitMonitor: # No chunks for 30s+: say WHAT the wait is and WHEN recovery kicks in. stale = self._stream_stale_timeout _recovery = f"; auto-reconnect at {int(stale)}s" if stale is not None and stale != float("inf") else "" + self._mon.wait_notice_started_ts = self._mon.last_heartbeat self.agent._emit_wait_notice( - f"⏳ waiting on {self.api_kwargs.get('model', 'the provider')} — {waiting_secs}s with no output yet " + f"⏳ waiting on {self.api_kwargs.get('model', 'the provider')} — no stream output for {waiting_secs}s " f"(provider may be slow or overloaded, or the model is thinking{_recovery})") else: # Chunks are flowing — keep the tracker fresh, leave the display alone. @@ -49,18 +51,28 @@ class StreamingWaitMonitor: def _monitor_loop(self) -> None: _HEARTBEAT_INTERVAL = 30.0 # seconds between gateway activity touches - self._mon = SimpleNamespace(last_heartbeat=time.time(), last_load_poll=0.0, load_notice_shown=False, load_notice_misses=0) + self._mon = SimpleNamespace( + last_heartbeat=time.time(), last_load_poll=0.0, + load_notice_shown=False, load_notice_misses=0, wait_notice_started_ts=None, + ) _is_local_base = bool(self.agent.base_url) and is_local_endpoint(self.agent.base_url) while not self._call_done.is_set(): self._call_done.wait(timeout=0.3) _hb_now = time.time() if _is_local_base and self._poll_local_load_notice(_hb_now): continue + # Reasoning callbacks do not clear the classic CLI spinner. The empty + # protocol payload resets status without adding synthetic reasoning. + if (self._mon.wait_notice_started_ts is not None + and self.last_chunk_time["t"] > self._mon.wait_notice_started_ts): + self.agent._emit_wait_notice("") + self._mon.wait_notice_started_ts = None if _hb_now - self._mon.last_heartbeat >= _HEARTBEAT_INTERVAL: self._mon.last_heartbeat = _hb_now self._heartbeat(int(_hb_now - self.last_chunk_time["t"]), _HEARTBEAT_INTERVAL) _stale_elapsed = time.time() - self.last_chunk_time["t"] if _stale_elapsed > self._stream_stale_timeout: + self._mon.wait_notice_started_ts = None # Reconnect status has its own owner. self._kill_stale_stream(_stale_elapsed) if self.agent._interrupt_requested: self._abort_for_interrupt(_stale_elapsed) diff --git a/tests/agent/test_nonstream_wait_notice.py b/tests/agent/test_nonstream_wait_notice.py index cc5ec004c3..845087a0cf 100644 --- a/tests/agent/test_nonstream_wait_notice.py +++ b/tests/agent/test_nonstream_wait_notice.py @@ -88,6 +88,5 @@ def test_resumed_events_clear_only_this_requests_wait_notice(monkeypatch): assert request.run() is sentinel assert len(notices) == 2 assert "no response yet" in notices[0] - assert notices[1] - assert "waiting on" not in notices[1] - assert "no response" not in notices[1] + # Nonempty thinking.delta payloads enter TUI reasoning history. + assert notices[1] == "" diff --git a/tests/agent/test_stream_wait_notice.py b/tests/agent/test_stream_wait_notice.py new file mode 100644 index 0000000000..3e64fa1125 --- /dev/null +++ b/tests/agent/test_stream_wait_notice.py @@ -0,0 +1,54 @@ +"""Resumed chunks clear only the stream monitor's own silence notice.""" +from types import SimpleNamespace + +import pytest + +from agent import chat_completion_helpers as h + + +@pytest.mark.parametrize("local_loading,heartbeat_race", [(False, False), (True, False), (False, True)]) +def test_resumed_chunks_clear_wait_without_erasing_local_load(monkeypatch, local_loading, heartbeat_race): + call = h._StreamingCall.__new__(h._StreamingCall) + notices = [] + now = [1000.0] + call.agent = SimpleNamespace( + base_url="http://localhost:1234" if local_loading else "https://example.com", + _interrupt_requested=False, + _emit_wait_notice=lambda text: notices.append((now[0], text)), + _touch_activity=lambda text: None, + ) + call.api_kwargs = {"model": "test-model"} + call.last_chunk_time = {"t": now[0]} + call._stream_stale_timeout = 180.0 + loading = "Loading local model weights" + monkeypatch.setattr(h, "_managed_local_load_notice", + lambda *args: loading if now[0] >= 1030.6 else None) + monkeypatch.setattr(h.time, "time", lambda: now[0]) + + if heartbeat_race: + heartbeat = call._heartbeat + + def resume_before_notice(waiting_secs, interval): + now[0] += 0.1 + call.last_chunk_time["t"] = now[0] + heartbeat(waiting_secs, interval) + + monkeypatch.setattr(call, "_heartbeat", resume_before_notice) + + class Done: + def is_set(self): + return now[0] >= 1032.0 + + def wait(self, timeout): + now[0] = round(now[0] + timeout, 1) + if not heartbeat_race and now[0] >= 1031.5: + call.last_chunk_time["t"] = now[0] + + call._call_done = Done() + call._monitor_loop() + assert "waiting on" in notices[0][1] + if local_loading: + assert notices[-1][1] == loading + assert not any(text == "" for _, text in notices) + else: + assert notices[1:] == [(1030.4 if heartbeat_race else 1031.5, "")] diff --git a/website/docs/user-guide/configuration.md b/website/docs/user-guide/configuration.md index f7e3928dd1..c08057558f 100644 --- a/website/docs/user-guide/configuration.md +++ b/website/docs/user-guide/configuration.md @@ -1190,7 +1190,7 @@ The **stale non-stream detection** kills non-streaming calls that produce no res This budget bounds every non-streaming call. A provider that accepts a request and then goes silent — connection held open, no bytes, no error — is aborted at the stale timeout and retried, rather than hanging until the much longer socket read timeout (or, for an unattended cron run, until something external kills the process). -The Codex Responses **waiting status** describes silence, not total generation time: active stream events (including reasoning) keep it quiet. If events stop, it reports time without stream events instead of claiming no response has arrived; the notice clears when events resume. When a reconnect starts a fresh first-event watchdog phase, the waiting status follows that phase. This display behavior does not extend the separate wall-clock stale-call budget or change watchdog timeouts. +The Codex Responses **waiting status** describes silence, not total generation time: active stream events (including reasoning) keep it quiet. If events stop, it reports time without stream events instead of claiming no response has arrived; the notice clears when events resume. When a reconnect starts a fresh first-event watchdog phase, the waiting status follows that phase. This display behavior does not extend the separate wall-clock stale-call budget or change watchdog timeouts. Chat-completion streams likewise clear their silence warning promptly when chunks resume, without replacing a local model-loading status. Cron jobs and delegated subagents stream too. They run the request inline on their own thread (the interrupt worker other sessions use wedges inside the gateway's nested thread pools), but the wire request is still `stream: true`, so the **stale stream detection** budget above governs them — every token counts as liveness, so a reasoning model that thinks for minutes is not mistaken for a hung provider, and edge proxies that kill silent connections keep seeing bytes. diff --git a/website/i18n/zh-Hans/docusaurus-plugin-content-docs/current/user-guide/configuration.md b/website/i18n/zh-Hans/docusaurus-plugin-content-docs/current/user-guide/configuration.md index 8868006a8a..ffc9e7f2be 100644 --- a/website/i18n/zh-Hans/docusaurus-plugin-content-docs/current/user-guide/configuration.md +++ b/website/i18n/zh-Hans/docusaurus-plugin-content-docs/current/user-guide/configuration.md @@ -738,7 +738,7 @@ Hermes 对流式传输有单独的超时层，以及用于非流式调用的陈 **陈旧非流检测**终止长时间没有响应的非流式调用。默认情况下，Hermes 在本地端点上禁用此功能，以避免长时间预填充期间的误报。如果您显式设置 `providers..stale_timeout_seconds`、`providers..models..stale_timeout_seconds` 或 `HERMES_API_CALL_STALE_TIMEOUT`，即使在本地端点上也会遵守该显式值。 -Codex Responses 的**等待状态**描述的是没有流事件的时间，而不是生成的总时长：持续收到流事件（包括推理内容）时不会显示等待警告。如果事件停止，提示会显示多久没有收到流事件，而不会声称尚未收到任何响应；事件恢复后提示会清除。当重连进入新的首事件看门狗阶段时，等待状态也会跟随该阶段。这只影响状态显示，不会延长独立的调用总时长限制，也不会更改看门狗超时。 +Codex Responses 的**等待状态**描述的是没有流事件的时间，而不是生成的总时长：持续收到流事件（包括推理内容）时不会显示等待警告。如果事件停止，提示会显示多久没有收到流事件，而不会声称尚未收到任何响应；事件恢复后提示会清除。当重连进入新的首事件看门狗阶段时，等待状态也会跟随该阶段。这只影响状态显示，不会延长独立的调用总时长限制，也不会更改看门狗超时。Chat Completions 流同样会在数据块恢复时及时清除无输出警告，但不会覆盖本地模型加载状态。 ## 上下文压力警告