From cf4930c011867d12d9b99c3588c67f7bad2ed206 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Nicholas=20Pi=C3=ABl?= Date: Mon, 20 Jul 2026 11:41:13 +0200 Subject: [PATCH] [argus] patch #44: unattended-silence: no blank-final retry, wider narration backstop, no token logging Three fixes from the 2026-07-18/19 hourly-Telegram-spam incident. 1. EmptyFinalRetryMiddleware (patch #37) retried blank finals on every turn. On an unattended (scheduled-playbook) turn a blank final -- or the '.' no-op sentinel the playbook prompts now ask for -- is the DESIRED outcome (the #31/#32/#34 silence branch suppresses the send), so the retry re-sampled the model into narrating ('No meetings in the window...') and turned compliant silence into hourly channel noise. The middleware now reads 'unattended' from request.runtime.context (the same signal the #30 memory write policy uses) and returns the blank without retrying. Attended turns keep retry-once byte-for-byte. 2. The #34 narrated-silence backstop capped announcements at 120 chars; the real narrations ran to ~250 chars (three-sentence monologues) and sailed through every hour for two days. Cap is now 280, 'calendar/schedule is clear' and 'nothing ... attention' count as announcement phrasing, and a contrast/alert-marker veto ('but', 'however', 'urgent', 'moved', 'cancelled', ...) takes over from the cap as the protection for genuine content behind an announcement-shaped opener. 3. httpx logs every request URL at INFO, so the Telegram bot token appeared in the journal in plaintext on every send. The gateway bootstrap pins httpx/httpcore to WARNING; apply_logging_level only adjusts the deerflow/app hierarchies, so the pin survives the lifespan log-level override. Tests: test_empty_final_retry.py (+TestIsUnattended, +TestUnattendedNeverRetries incl. attended-still-retries guard), test_unattended_silence.py (+6 verbatim incident narrations that must blank, +5 veto cases that must survive). 114 pass in the two files; 1598 pass across the channel/middleware/gateway suites (one unrelated flaky shutdown-timing test passes in isolation). Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_01PDzGEHrugU91DPkeV3MPLY --- PATCHES.md | 53 +++++++++++ backend/CLAUDE.md | 2 +- backend/app/channels/manager.py | 53 +++++++---- backend/app/gateway/app.py | 8 ++ .../empty_final_retry_middleware.py | 37 ++++++++ backend/tests/test_empty_final_retry.py | 87 ++++++++++++++++++- backend/tests/test_unattended_silence.py | 37 +++++++- 7 files changed, 259 insertions(+), 18 deletions(-) diff --git a/PATCHES.md b/PATCHES.md index fc25a173200..ed899a744ef 100644 --- a/PATCHES.md +++ b/PATCHES.md @@ -69,6 +69,7 @@ half is upstreamable, the Argus behavior lives in project config). | [#41](#patch-41) | coerce stringified write_todos arg (planner pipeline) | argus-additive | this PR | | [#42](#patch-42) | subtask card false-"failed" on transient SSE loading gaps | argus-edit | 68a7fd37 | | [#43](#patch-43) | per-run allowed-tools from schedule frontmatter | argus-additive | this PR | +| [#44](#patch-44) | unattended-silence: no blank-final retry, wider narration backstop, no token logging | argus-edit | this PR | Dropped / deferred / not-carried records are at the bottom, followed by the carry budget ledger. @@ -901,6 +902,58 @@ carry budget ledger. --- +## Patch #44 + +**Patch #44 - unattended-silence: no blank-final retry, wider narration +backstop, no token logging** + +- Class: argus-edit (edits the #37 middleware, the #34 heuristic in + `app/channels/manager.py`, and the gateway logging bootstrap) +- Intent: three fixes from the 2026-07-18/19 hourly-Telegram-spam incident. + (1) Patch #37's `EmptyFinalRetryMiddleware` retried blank finals on EVERY + turn; on an unattended (scheduled-playbook) turn a blank final — or the + `.` no-op sentinel the playbook prompts now ask for — is the *desired* + outcome (the #31/#32/#34 silence branch suppresses the send), so the + retry re-sampled the model into narrating ("No meetings in the + window...") and turned compliant silence into hourly channel noise. The + middleware now reads `unattended` from `request.runtime.context` (the + same signal the #30 memory write policy uses) and returns the blank + without retrying; attended turns keep retry-once byte-for-byte. + (2) The #34 narrated-silence backstop capped announcements at 120 chars; + the real narrations ran to ~250 chars (three-sentence monologues) and + sailed through hourly. Cap is now 280, "calendar/schedule is clear" and + "nothing ... attention" count as announcement phrasing, and a + contrast/alert-marker veto ("but", "however", "urgent", "moved", + "cancelled", ...) takes over from the cap as the protection for genuine + content behind an announcement-shaped opener. + (3) httpx logs every request URL at INFO, so the Telegram bot token + appeared in the journal in plaintext on every send; the gateway + bootstrap now pins `httpx`/`httpcore` to WARNING (`apply_logging_level` + only adjusts the deerflow/app hierarchies, so the pin survives the + lifespan log-level override). +- Files: + `backend/packages/harness/deerflow/agents/middlewares/empty_final_retry_middleware.py` + (EDITED, +`_is_unattended` + skip branch), + `backend/app/channels/manager.py` (EDITED, #34 heuristic: cap 120→280, + +2 announcement alternates, +`_SILENCE_VETO_RE`), + `backend/app/gateway/app.py` (EDITED, +httpx/httpcore WARNING pin) +- Tests: `backend/tests/test_empty_final_retry.py` (+`TestIsUnattended`, + +`TestUnattendedNeverRetries` incl. an attended-still-retries regression + guard; `_req` now models an explicit attended runtime), + `backend/tests/test_unattended_silence.py` (+6 verbatim incident + narrations that must blank, +5 veto cases that must survive) +- Delete-when: (1) goes with patch #37 if the blank-final root cause is + fixed upstream. (2) goes with the #31/#32/#34 silence branch when + scheduled runs get a first-class delivery contract (the playbook fire + reporting `silent` instead of the model posting anything at all). + (3) goes if upstream adopts a redacting log filter for channel HTTP + clients. +- Upstream status: none. (3) is generic-upstreamable as a standalone + "don't log bot tokens" fix; (1)/(2) depend on the argus-only scheduled + playbook machinery. + +--- + ## Dropped / deferred / re-expressed (v2.0.0 rebase record - do not re-add blindly) **Dropped as upstream-subsumed (verified during the 2026-06-29/30 rebase):** diff --git a/backend/CLAUDE.md b/backend/CLAUDE.md index 790fb22e949..8c9f6ac96e8 100644 --- a/backend/CLAUDE.md +++ b/backend/CLAUDE.md @@ -229,7 +229,7 @@ Lead-agent middlewares are assembled in strict append order across `packages/har 15. **ViewImageMiddleware** - Injects base64 image data before LLM call (conditional on vision support) 16. **DeferredToolFilterMiddleware** - Hides deferred (MCP) tool schemas from the bound model using a build-time deferred-name set + catalog hash, reading per-thread promotions from `ThreadState.promoted` (hash-scoped, no ContextVar); a tool becomes bound on subsequent turns after `tool_search` returns its schema (optional, if `tool_search.enabled`) 17. **SubagentLimitMiddleware** - Truncates excess `task` tool calls from model response to enforce `MAX_CONCURRENT_SUBAGENTS` limit (optional, if `subagent_enabled`) -18. **EmptyFinalRetryMiddleware** *(argus patch #37)* - Re-invokes the model once when it returns a blank FINAL turn (an AIMessage with no content AND no tool_calls); a blank turn carrying tool_calls is a normal intermediate step and is left alone. Bounded to a single retry (never loops); if the retry is also blank the blank is returned and the visible-marker guards (patch #36 channels, patch #37 web) surface it. Registered before LoopDetection so a retried final still flows through loop/safety `after_model` accounting. +18. **EmptyFinalRetryMiddleware** *(argus patch #37)* - Re-invokes the model once when it returns a blank FINAL turn (an AIMessage with no content AND no tool_calls); a blank turn carrying tool_calls is a normal intermediate step and is left alone. Bounded to a single retry (never loops); if the retry is also blank the blank is returned and the visible-marker guards (patch #36 channels, patch #37 web) surface it. Registered before LoopDetection so a retried final still flows through loop/safety `after_model` accounting. *(argus patch #44)* Unattended (scheduled-playbook) turns are never retried: there a blank final (or the `.` no-op sentinel) is the desired outcome and the channel manager's silence branch suppresses the send; the flag is read from `request.runtime.context["unattended"]`. 19. **LoopDetectionMiddleware** - Detects repeated tool-call loops; hard-stop responses clear both structured `tool_calls` and raw provider tool-call metadata before forcing a final text answer 20. **ClarificationMiddleware** - Intercepts `ask_clarification` tool calls, interrupts via `Command(goto=END)` (must be last) diff --git a/backend/app/channels/manager.py b/backend/app/channels/manager.py index 56f4941bb0b..3e83ac50916 100644 --- a/backend/app/channels/manager.py +++ b/backend/app/channels/manager.py @@ -90,36 +90,59 @@ def _slim_metadata(meta: dict[str, Any]) -> dict[str, Any]: return {k: v for k, v in meta.items() if k not in _METADATA_DROP_KEYS} -# [argus patch #34] A model told to "stay silent" on a contentless unattended -# turn often narrates the decision instead of emitting nothing — e.g. the hourly -# meeting-prep poll posting "No meetings in the window. Staying silent." Such a -# message is itself the noise the silence branch exists to suppress. Match it as -# a SHORT one-liner (real briefs are longer, multi-line, with names/times) whose -# only content is a "nothing to report" and/or "staying silent" announcement. -# Tight on purpose: requires the announcement phrasing AND a length cap, so a -# genuine brief that merely mentions a meeting or the word "silent" is preserved. +# [argus patch #34/#44] A model told to "stay silent" on a contentless +# unattended turn often narrates the decision instead of emitting nothing — +# e.g. the hourly meeting-prep poll posting "No meetings in the window. +# Staying silent." Such a message is itself the noise the silence branch +# exists to suppress. Match it as a one-liner whose only content is a +# "nothing to report" and/or "staying silent" announcement. Patch #44 widened +# this after multi-sentence narrations ("No meetings starting in the next +# 15-20 minutes. The earliest meeting today is at 13:30 (...), which is still +# over 12 hours away. Calendar is clear... Per the hourly check rules, staying +# silent.") sailed past the original 120-char cap every hour for two days: +# the cap is now 280, "calendar/schedule is clear" and "nothing ... attention" +# count as announcement phrasing, and a contrast/alert marker ("but", +# "however", "urgent", "moved", ...) vetoes the match so genuine content +# hiding behind a no-meetings opener is never dropped. _SILENCE_ANNOUNCEMENT_RE = re.compile( r""" ^\W*(?: (?:no|nothing|none)\b .*? \b(?:meeting|meetings|event|events| - report|update|updates|upcoming|scheduled|to\s+report|to\s+share)\b + report|update|updates|upcoming|scheduled|attention| + to\s+report|to\s+share)\b | (?:staying|stay|remaining|going|i'?ll\s+stay|i\s+will\s+stay)\s+silent\b | no\s+output\b + | (?:calendar|schedule)\s+is\s+clear\b ) .*$ """, re.IGNORECASE | re.VERBOSE | re.DOTALL, ) -# A real brief is never this short; the disobedient one-liner is. Cap well above -# the longest plausible announcement, well below any actual brief. -_SILENCE_ANNOUNCEMENT_MAX_LEN = 120 +# [argus patch #44] Real content hiding inside an announcement-shaped opener +# ("No meetings in the window, but your 13:30 moved to 13:00") must never be +# suppressed. Any contrast or alert marker vetoes the announcement match. +# "action"/"required" are deliberately absent: they are staples of the noise +# itself ("no action required"), and a mixed message that opens announcement- +# shaped almost always carries one of the markers below too. +_SILENCE_VETO_RE = re.compile( + r"\b(?:but|however|except|urgent|asap|heads[-\s]?up|fyi|reminder|moved|rescheduled|cancell?ed|postponed)\b", + re.IGNORECASE, +) +# Longest observed narration was ~252 chars (a three-sentence hourly +# meeting-prep monologue); real briefs are multi-line with names/times and +# do not open with announcement phrasing, so the anchor + veto carry the +# safety and the cap is just a backstop against digests. +_SILENCE_ANNOUNCEMENT_MAX_LEN = 280 def _is_silence_announcement(stripped: str) -> bool: - """True if *stripped* is a short 'nothing to report / staying silent' - announcement rather than a real brief. Conservative: length-capped and - phrasing-anchored so genuine briefs are never matched.""" + """True if *stripped* is a 'nothing to report / staying silent' + announcement rather than a real brief. Conservative: length-capped, + phrasing-anchored, and vetoed by contrast/alert markers so genuine + briefs are never matched.""" if len(stripped) > _SILENCE_ANNOUNCEMENT_MAX_LEN: return False + if _SILENCE_VETO_RE.search(stripped): + return False return _SILENCE_ANNOUNCEMENT_RE.match(stripped) is not None diff --git a/backend/app/gateway/app.py b/backend/app/gateway/app.py index 7baa10ce0dc..11f5b7c0fe3 100644 --- a/backend/app/gateway/app.py +++ b/backend/app/gateway/app.py @@ -43,6 +43,14 @@ datefmt="%Y-%m-%d %H:%M:%S", ) +# [argus patch #44] httpx logs every request URL at INFO. For Telegram that +# URL embeds the bot token (api.telegram.org/bot/sendMessage), which +# lands in the journal in plaintext on every channel send. Pin these loggers +# to WARNING; apply_logging_level only adjusts the deerflow/app hierarchies, +# so the pin survives the lifespan log-level override. +for _noisy_logger in ("httpx", "httpcore"): + logging.getLogger(_noisy_logger).setLevel(logging.WARNING) + logger = logging.getLogger(__name__) # Upper bound (seconds) each lifespan shutdown hook is allowed to run. diff --git a/backend/packages/harness/deerflow/agents/middlewares/empty_final_retry_middleware.py b/backend/packages/harness/deerflow/agents/middlewares/empty_final_retry_middleware.py index b8cea2bec38..28fab355538 100644 --- a/backend/packages/harness/deerflow/agents/middlewares/empty_final_retry_middleware.py +++ b/backend/packages/harness/deerflow/agents/middlewares/empty_final_retry_middleware.py @@ -18,6 +18,14 @@ the blank is returned as-is and the downstream visible-marker guards handle it — we never loop. * Everything non-blank is returned unchanged; no message is rewritten here. + * [argus patch #44] Unattended (scheduled-playbook) turns are NEVER retried. + There, a blank final (or the ``.`` no-op sentinel the playbook prompts ask + for) is the *desired* outcome — the channel manager's silence branch + (patches #31/#32/#34) suppresses the send. Retrying it re-samples the + model, which frequently narrates instead ("No meetings in the window...") + and turns a compliant silent turn into hourly channel noise. The flag + rides run_context -> runtime.context (set in app/channels/manager.py), + the same signal the memory write policy uses. Placed before LoopDetectionMiddleware in the lead-agent chain so a retried final still passes through loop detection normally. @@ -38,6 +46,25 @@ logger = logging.getLogger(__name__) +def _is_unattended(request: ModelRequest) -> bool: + """[argus patch #44] True when this model call belongs to an unattended + (scheduled-playbook) run. + + The channel manager sets ``unattended=True`` on run_context, which rides + to ``runtime.context`` (same signal ``memory/write_policy.py`` reads). + Conservative: anything that is not a mapping with a truthy ``unattended`` + key counts as attended, so the retry behavior of interactive turns is + unchanged even when a runtime/context is absent (as in unit tests). + """ + runtime = getattr(request, "runtime", None) + if runtime is None: + return False + ctx = getattr(runtime, "context", None) + if not isinstance(ctx, dict): + return False + return bool(ctx.get("unattended")) + + def _is_blank_final(response: ModelResponse) -> bool: """True when *response*'s last message is a blank FINAL assistant turn. @@ -68,6 +95,11 @@ def wrap_model_call( ) -> ModelCallResult: response = handler(request) if _is_blank_final(response): + if _is_unattended(request): + # [argus patch #44] Silence is the desired outcome on a + # scheduled turn; the channel manager suppresses the send. + logger.info("Blank final on unattended turn; not retrying.") + return response logger.warning("Empty final model turn; retrying once (sync).") retry = handler(request) if not _is_blank_final(retry): @@ -84,6 +116,11 @@ async def awrap_model_call( ) -> ModelCallResult: response = await handler(request) if _is_blank_final(response): + if _is_unattended(request): + # [argus patch #44] Silence is the desired outcome on a + # scheduled turn; the channel manager suppresses the send. + logger.info("Blank final on unattended turn; not retrying.") + return response logger.warning("Empty final model turn; retrying once (async).") retry = await handler(request) if not _is_blank_final(retry): diff --git a/backend/tests/test_empty_final_retry.py b/backend/tests/test_empty_final_retry.py index 2374af8f0fd..022352aa7c9 100644 --- a/backend/tests/test_empty_final_retry.py +++ b/backend/tests/test_empty_final_retry.py @@ -19,6 +19,7 @@ from deerflow.agents.middlewares.empty_final_retry_middleware import ( EmptyFinalRetryMiddleware, _is_blank_final, + _is_unattended, ) from deerflow.utils.messages import NO_RESPONSE_MARKER, is_blank_text @@ -96,9 +97,46 @@ def test_empty_result(self): assert _is_blank_final(_response([])) is False +def _request(unattended=False, runtime="default"): + """ModelRequest stand-in. The middleware reads only `.runtime.context`. + + `runtime="default"` builds an attended interactive request; pass + `runtime=None` for the no-runtime shape some test harnesses produce. + """ + if runtime is None: + return SimpleNamespace(runtime=None) + context = {"unattended": True} if unattended else {} + return SimpleNamespace(runtime=SimpleNamespace(context=context)) + + +class TestIsUnattended: + """[argus patch #44] The unattended flag gates the retry; anything that is + not a mapping with a truthy `unattended` key must count as attended so + interactive behavior is untouched.""" + + def test_unattended_context(self): + assert _is_unattended(_request(unattended=True)) is True + + def test_attended_context(self): + assert _is_unattended(_request()) is False + + def test_no_runtime(self): + assert _is_unattended(_request(runtime=None)) is False + + def test_no_context_attr(self): + assert _is_unattended(SimpleNamespace(runtime=SimpleNamespace())) is False + + def test_non_dict_context(self): + assert _is_unattended(SimpleNamespace(runtime=SimpleNamespace(context="x"))) is False + + def test_falsy_flag(self): + req = SimpleNamespace(runtime=SimpleNamespace(context={"unattended": False})) + assert _is_unattended(req) is False + + class TestEmptyFinalRetryMiddleware: def _req(self): - return MagicMock(name="ModelRequest") + return _request() def test_sync_retries_once_and_returns_nonblank(self): mw = EmptyFinalRetryMiddleware() @@ -152,3 +190,50 @@ async def test_async_no_retry_when_good(self): out = await mw.awrap_model_call(self._req(), handler) assert handler.await_count == 1 assert out is good + + +class TestUnattendedNeverRetries: + """[argus patch #44] On an unattended (scheduled-playbook) turn a blank + final — including the '.' no-op sentinel — is the DESIRED outcome; the + channel manager's silence branch suppresses the send. Retrying re-samples + the model into narrating ("No meetings in the window...") and turns a + compliant silent turn into hourly channel noise.""" + + @pytest.mark.parametrize("content", ["", "\n\n", ".", "…"]) + def test_sync_blank_final_returned_without_retry(self, content): + mw = EmptyFinalRetryMiddleware() + blank = _response([AIMessage(content=content)]) + handler = MagicMock(side_effect=[blank]) + out = mw.wrap_model_call(_request(unattended=True), handler) + assert handler.call_count == 1 # no retry + assert out is blank + + def test_sync_real_final_unaffected(self): + mw = EmptyFinalRetryMiddleware() + good = _response([AIMessage(content="Meeting brief: ...")]) + handler = MagicMock(side_effect=[good]) + out = mw.wrap_model_call(_request(unattended=True), handler) + assert handler.call_count == 1 + assert out is good + + @pytest.mark.asyncio + @pytest.mark.parametrize("content", ["", ".", " "]) + async def test_async_blank_final_returned_without_retry(self, content): + mw = EmptyFinalRetryMiddleware() + blank = _response([AIMessage(content=content)]) + handler = AsyncMock(side_effect=[blank]) + out = await mw.awrap_model_call(_request(unattended=True), handler) + assert handler.await_count == 1 # no retry + assert out is blank + + @pytest.mark.asyncio + async def test_async_attended_still_retries(self): + # Regression guard for the flag plumbing: an explicit attended request + # must keep the original retry-once behavior. + mw = EmptyFinalRetryMiddleware() + blank = _response([AIMessage(content="")]) + good = _response([AIMessage(content="real")]) + handler = AsyncMock(side_effect=[blank, good]) + out = await mw.awrap_model_call(_request(unattended=False), handler) + assert handler.await_count == 2 + assert out is good diff --git a/backend/tests/test_unattended_silence.py b/backend/tests/test_unattended_silence.py index c2c913d4fd6..0324d1b12ce 100644 --- a/backend/tests/test_unattended_silence.py +++ b/backend/tests/test_unattended_silence.py @@ -128,6 +128,32 @@ def test_trivial_filler_is_blanked(self, text): def test_silence_announcement_is_blanked(self, text): assert _is_trivial_unattended_text(text) is True + @pytest.mark.parametrize( + "text", + [ + # [argus patch #44] Verbatim narrations that spammed Telegram + # hourly on 2026-07-18/19 — all over the old 120-char cap: + "No meetings starting in the next 15-20 minutes. Calendar is clear " + "through the rest of Sunday. Per the hourly check rules, staying silent.", + "No meetings starting in the next 15-20 minutes. The earliest meeting " + "today is at 13:30, still over 9 hours away. Calendar is clear through " + "the early morning.", + # The longest observed (~250 chars, three sentences): + "No meetings starting in the next 15-20 minutes. The earliest meeting " + "today is at 13:30 (Kick off: new webtoppings), which is still over 12 " + "hours away. Calendar is clear through the rest of the early morning. " + "Per the hourly check rules, staying silent.", + # The inbox-check flavor ("attention" phrasing): + "Nothing new needs my attention. One unsolicited job application in " + "the inbox, no reply required.", + "No meetings are scheduled to start in the immediate 15-20 minute window.", + # Announcement that leads with the calendar rather than "no": + "Calendar is clear through the rest of Sunday evening. Staying silent.", + ], + ) + def test_multi_sentence_narration_is_blanked(self, text): + assert _is_trivial_unattended_text(text) is True + @pytest.mark.parametrize( "text", [ @@ -144,9 +170,18 @@ def test_silence_announcement_is_blanked(self, text): "Meeting at 15:00 with Acme. They went silent last week, so push for a timeline.", "Standup in 15 min. No blockers reported by the team; ship the release.", "Who: Bob (Acme), Jane (Globex)\nContext: prior thread on pricing\nTalking points:\n- renewal\n- no upcoming gaps", - # Long enough to exceed the announcement cap even if phrased like one: + # Announcement-shaped opener with real content behind it — the + # contrast marker ("but") vetoes the match (patch #44; before + # that the length cap carried this case): "No meetings in the window, but here is the daily digest you asked for: " "three PRs merged, two issues opened, and the Acme renewal call is confirmed for tomorrow at 10.", + # [argus patch #44] More veto cases: genuine alerts that open like + # an announcement must never be suppressed, at any length. + "No meetings in the window, but your 13:30 was moved to 13:00.", + "No meetings in the next 20 minutes. However, the Acme call tomorrow was cancelled.", + "Nothing scheduled. Urgent: the deploy is failing, check #ops.", + "No new meetings. Reminder: send the board deck today.", + "Calendar is clear, but heads-up: the 13:30 kickoff moved rooms.", ], ) def test_real_content_is_preserved(self, text):