fix(cron): banner-only bot-chat failure names the exit code; persisted stdout tail capped and scrubbed

Review follow-up for the both-streams change.

- `_format_failure_streams` now always leads with `exit code N`, drops the
  `Resumed session` / `session_id:` banner lines from the stdout tail, and
  says `stdout was only the resume banner` when nothing else was printed —
  so the issue's exact shape (empty stderr, banner-only stdout) records a
  reason instead of echoing the banner, which is what main already did.
- The persisted stdout tail is the model's answer: cap it at 200 chars
  (stderr keeps 500) and run the whole detail through
  `agent.redact.redact_sensitive_text(force=True, redact_url_credentials=True)`,
  the same scrub `cron.incidents` and `cron.delivery_queue` apply to their
  persisted errors — `last_delivery_error` had none.
- Tests: the banner-only test now pins the exit-code/banner-only wording;
  one new test pins the 200-char cap and the scrub. Both red on the
  previous head.
This commit is contained in:
teknium1
2026-09-16 14:25:31 -07:00
committed by Teknium
parent 6e89b8f36c
commit 3719e04d74
2 changed files with 49 additions and 17 deletions

View File

@@ -653,25 +653,38 @@ def _get_bot_chat_delivery_timeout() -> int:
return 600
_BOT_CHAT_STREAM_TAIL = 500
_BOT_CHAT_STDERR_TAIL = 500
# stdout is the model's answer; only a short tail is persisted (jobs.json / ledger).
_BOT_CHAT_STDOUT_TAIL = 200
_BOT_CHAT_BANNER_PREFIXES = ("Resumed session", "session_id:")
def _format_failure_streams(result) -> str:
"""Labeled stderr+stdout tails for a failed delivery turn ("": none).
"""Exit code plus labeled, redacted stderr/stdout tails for a failed delivery turn.
``-Q`` reports the resume banner and ``session_id:`` on stderr while the
response rides stdout, so ``stderr or stdout`` discards half the signal —
and when stderr is empty and stdout holds only the banner, the recorded
error carries zero diagnostics (#104056). Both tails are kept, capped.
``-Q`` reports the resume banner and ``session_id:`` while the response
rides stdout, so ``stderr or stdout`` discarded half the signal — and when
stderr is empty and stdout holds only the banner, the recorded error
carried zero diagnostics (#104056). The banner lines are dropped from the
stdout tail so what remains is the reason; the exit code is always named.
The text lands in ``last_delivery_error`` on disk, so it is scrubbed like
``cron.incidents`` / ``cron.delivery_queue`` scrub their persisted errors.
"""
from agent.redact import redact_sensitive_text
err = (getattr(result, "stderr", None) or "").strip()
out = (getattr(result, "stdout", None) or "").strip()
parts = []
parts = [f"exit code {getattr(result, 'returncode', '?')}"]
if err:
parts.append(f"stderr: {err[-_BOT_CHAT_STREAM_TAIL:]}")
parts.append(f"stderr: {err[-_BOT_CHAT_STDERR_TAIL:]}")
if out:
parts.append(f"stdout: {out[-_BOT_CHAT_STREAM_TAIL:]}")
return " | ".join(parts)
kept = "\n".join(
line for line in out.splitlines()
if line.strip() and not line.strip().lstrip("↻ ").startswith(_BOT_CHAT_BANNER_PREFIXES))
parts.append(
f"stdout: {kept[-_BOT_CHAT_STDOUT_TAIL:]}" if kept
else "stdout was only the resume banner")
return redact_sensitive_text(" | ".join(parts), force=True, redact_url_credentials=True)
def _deliver_to_bot_chat(job: dict, content: str, profile: str, *, deferred: Optional[dict] = None) -> Optional[str]:
@@ -807,12 +820,12 @@ def _deliver_to_bot_chat(job: dict, content: str, profile: str, *, deferred: Opt
if result.returncode != 0:
tail = _format_failure_streams(result)
logger.warning(
"Job '%s': bot-chat delivery to profile '%s' failed (exit %s) at %s%s",
job_id, profile_label, result.returncode, home, f": {tail}" if tail else "")
"Job '%s': bot-chat delivery to profile '%s' failed at %s: %s",
job_id, profile_label, home, tail)
return (
f"Hermes could not deliver this result to Bot Chat (profile '{profile_label}'). "
"The result is saved; run `hermes cron runs` to see it, or `hermes doctor` if this keeps happening"
+ (f". Details: {tail}" if tail else ""))
f". Details: {tail}")
logger.info("Job '%s': delivered to Bot Chat of profile '%s'", job_id, profile_label)
return None
except subprocess.TimeoutExpired:

View File

@@ -169,20 +169,39 @@ def test_deliver_failure_reports_both_streams_labeled():
assert "stdout: banner out" in err
def test_deliver_failure_stdout_only_when_stderr_empty():
def test_deliver_failure_banner_only_stdout_names_exit_code_not_banner():
"""The reported shape: empty stderr, stdout holding only the resume
banner — the recorded error must still carry it (#104056)."""
banner = 'Resumed session 20260905_121420_8084c7 "Bot Chat" (1 user message, 1 total messages)'
banner — the recorded error must say what happened (exit code, banner-only
stdout) instead of echoing the banner as if it were a reason (#104056)."""
banner = ('↻ Resumed session 20260905_121420_8084c7 "Bot Chat" (1 user message, 1 total messages)'
'\n\nsession_id: 20260905_121420_8084c7')
with mock.patch.object(
sched.subprocess, "run",
return_value=_completed(returncode=1, stdout=banner, stderr=""),
), mock.patch.object(sched_delivery.shutil, "which", return_value="/usr/bin/hermes"):
err = _deliver_to_bot_chat({"id": "j1", "name": "n"}, "out", "")
assert err is not None
assert "stdout: " + banner in err
assert "exit code 1" in err
assert "stdout was only the resume banner" in err
assert "Resumed session" not in err
assert "stderr:" not in err
def test_deliver_failure_persisted_stdout_tail_is_short_and_redacted():
"""``last_delivery_error`` lands in jobs.json / the ledger: the model's
answer on stdout is capped to a short tail and secrets are scrubbed."""
answer = "x" * 5000 + "\nToken: sk-ant-api03-" + "A" * 80 + " done"
with mock.patch.object(
sched.subprocess, "run",
return_value=_completed(returncode=1, stdout=answer, stderr="boom-err"),
), mock.patch.object(sched_delivery.shutil, "which", return_value="/usr/bin/hermes"):
err = _deliver_to_bot_chat({"id": "j1", "name": "n"}, "out", "")
assert err is not None
stdout_part = err.split("stdout: ", 1)[1]
assert len(stdout_part) <= 200
assert "sk-ant-api03-" + "A" * 80 not in err
def test_deliver_timeout_returns_error_string():
with mock.patch.object(
sched.subprocess, "run",