feat(gateway): add 'log' option to display.tool_progress
Salvage of #3459 by @keslerm, reimplemented against the restructured progress-callback block in gateway/run.py (resolve_display_setting, needs_progress_queue, thinking-relay). Duplicate PR #3458 by @dlkakbs was submitted 4 minutes earlier with the same feature — both credited. Co-authored-by: Dilee <uzmpsk.dilekakbas@gmail.com> tool_progress: log keeps the chat silent and appends timestamped tool-call lines to ~/.hermes/logs/tool_calls.log via a dedicated queue drained by an async writer (RotatingFileHandler 5MB x 3, RedactingFormatter so secrets never land on disk). Gateway-only by design; thinking_progress relaying and the webhook gate are unaffected. /verbose now cycles off -> new -> all -> verbose -> log.
This commit is contained in:
parent
070ac2a719
commit
39bff67957
10 changed files with 199 additions and 9 deletions
|
|
@ -1022,6 +1022,7 @@ display:
|
|||
# new: Show a tool indicator only when the tool changes (skip repeats)
|
||||
# all: Show every tool call with a short preview (default)
|
||||
# verbose: Full args, results, and debug logs (same as /verbose)
|
||||
# log: Silent in chat; append every tool call to ~/.hermes/logs/tool_calls.log (gateway only)
|
||||
# Toggle at runtime with /verbose in the CLI
|
||||
tool_progress: all
|
||||
|
||||
|
|
|
|||
|
|
@ -16161,7 +16161,11 @@ class GatewayRunner(GatewayAuthorizationMixin, GatewayKanbanWatchersMixin, Gatew
|
|||
# Disable tool progress for webhooks - they don't support message editing,
|
||||
# so each progress line would be sent as a separate message.
|
||||
from gateway.config import Platform
|
||||
tool_progress_enabled = progress_mode != "off" and source.platform != Platform.WEBHOOK
|
||||
tool_progress_enabled = progress_mode not in {"off", "log"} and source.platform != Platform.WEBHOOK
|
||||
# "log" mode: tool calls are written to ~/.hermes/logs/tool_calls.log
|
||||
# instead of the chat (#3459 / #3458). Gateway-only by design.
|
||||
log_mode_enabled = progress_mode == "log" and source.platform != Platform.WEBHOOK
|
||||
log_queue: "queue.Queue | None" = queue.Queue() if log_mode_enabled else None
|
||||
# Natural assistant status messages are intentionally independent from
|
||||
# tool progress and token streaming. Users can keep tool_progress quiet
|
||||
# in chat platforms while opting into concise mid-turn updates.
|
||||
|
|
@ -16266,6 +16270,16 @@ class GatewayRunner(GatewayAuthorizationMixin, GatewayKanbanWatchersMixin, Gatew
|
|||
|
||||
def progress_callback(event_type: str, tool_name: str = None, preview: str = None, args: dict = None, **kwargs):
|
||||
"""Callback invoked by agent on tool lifecycle events."""
|
||||
# "log" mode: append tool.started lines to the log queue and stay
|
||||
# silent in chat. Handled before the progress_queue guard because
|
||||
# log mode runs without a chat progress queue.
|
||||
if log_queue is not None:
|
||||
if event_type == "tool.started" and tool_name and tool_name != "_thinking":
|
||||
ts = datetime.now().strftime("%Y-%m-%d %H:%M:%S")
|
||||
preview_str = f' "{preview}"' if preview else ""
|
||||
log_queue.put(f"{ts} {tool_name}:{preview_str}".rstrip())
|
||||
if not progress_queue:
|
||||
return
|
||||
if not progress_queue or not _run_still_current():
|
||||
return
|
||||
|
||||
|
|
@ -16493,6 +16507,61 @@ class GatewayRunner(GatewayAuthorizationMixin, GatewayKanbanWatchersMixin, Gatew
|
|||
else None
|
||||
)
|
||||
|
||||
async def write_tool_log():
|
||||
"""Drain log_queue and append tool-call lines to tool_calls.log.
|
||||
|
||||
Only active when ``display.tool_progress`` is ``log``. Uses a
|
||||
RotatingFileHandler (5MB × 3 backups) so the audit log can't grow
|
||||
unbounded, and the shared RedactingFormatter so secrets never land
|
||||
on disk.
|
||||
"""
|
||||
if log_queue is None:
|
||||
return
|
||||
from logging.handlers import RotatingFileHandler
|
||||
|
||||
from agent.redact import RedactingFormatter
|
||||
|
||||
log_dir = _hermes_home / "logs"
|
||||
log_dir.mkdir(parents=True, exist_ok=True)
|
||||
file_handler = RotatingFileHandler(
|
||||
log_dir / "tool_calls.log",
|
||||
maxBytes=5 * 1024 * 1024,
|
||||
backupCount=3,
|
||||
encoding="utf-8",
|
||||
)
|
||||
file_handler.setFormatter(RedactingFormatter("%(message)s"))
|
||||
tool_logger = logging.getLogger(f"hermes.tool_calls.{id(log_queue)}")
|
||||
tool_logger.setLevel(logging.INFO)
|
||||
tool_logger.propagate = False
|
||||
tool_logger.addHandler(file_handler)
|
||||
try:
|
||||
while True:
|
||||
try:
|
||||
tool_logger.info("%s", log_queue.get_nowait())
|
||||
except queue.Empty:
|
||||
await asyncio.sleep(0.3)
|
||||
except Exception as e:
|
||||
logger.error("write_tool_log error: %s", e)
|
||||
await asyncio.sleep(1)
|
||||
except asyncio.CancelledError:
|
||||
pass
|
||||
finally:
|
||||
# Drain remaining entries before closing so late tool calls
|
||||
# from the final iteration aren't lost.
|
||||
while True:
|
||||
try:
|
||||
tool_logger.info("%s", log_queue.get_nowait())
|
||||
except queue.Empty:
|
||||
break
|
||||
except Exception:
|
||||
break
|
||||
tool_logger.removeHandler(file_handler)
|
||||
try:
|
||||
file_handler.flush()
|
||||
file_handler.close()
|
||||
except Exception:
|
||||
pass
|
||||
|
||||
async def send_progress_messages():
|
||||
if not progress_queue:
|
||||
return
|
||||
|
|
@ -17287,7 +17356,9 @@ class GatewayRunner(GatewayAuthorizationMixin, GatewayKanbanWatchersMixin, Gatew
|
|||
# who set thinking_progress:true but kept tool_progress:off got a
|
||||
# None callback — so _thinking scratch bubbles never relayed even
|
||||
# though the progress queue was created for them.
|
||||
agent.tool_progress_callback = progress_callback if needs_progress_queue else None
|
||||
agent.tool_progress_callback = (
|
||||
progress_callback if (needs_progress_queue or log_mode_enabled) else None
|
||||
)
|
||||
# Discord voice verbal-ack hook (fires once per turn on first tool
|
||||
# call; armed only when in a voice channel with the mixer running).
|
||||
agent.tool_start_callback = (
|
||||
|
|
@ -18120,6 +18191,11 @@ class GatewayRunner(GatewayAuthorizationMixin, GatewayKanbanWatchersMixin, Gatew
|
|||
if needs_progress_queue:
|
||||
progress_task = asyncio.create_task(send_progress_messages())
|
||||
|
||||
# Start the tool-call log writer when tool_progress == "log".
|
||||
log_task = None
|
||||
if log_mode_enabled:
|
||||
log_task = asyncio.create_task(write_tool_log())
|
||||
|
||||
# Start stream consumer task — polls for consumer creation since it
|
||||
# happens inside run_sync (thread pool) after the agent is constructed.
|
||||
stream_task = None
|
||||
|
|
@ -18871,6 +18947,8 @@ class GatewayRunner(GatewayAuthorizationMixin, GatewayKanbanWatchersMixin, Gatew
|
|||
# Stop progress sender, interrupt monitor, and notification task
|
||||
if progress_task:
|
||||
progress_task.cancel()
|
||||
if log_task:
|
||||
log_task.cancel()
|
||||
interrupt_monitor.cancel()
|
||||
_notify_task.cancel()
|
||||
|
||||
|
|
@ -18917,7 +18995,7 @@ class GatewayRunner(GatewayAuthorizationMixin, GatewayKanbanWatchersMixin, Gatew
|
|||
self._update_runtime_status("draining")
|
||||
|
||||
# Wait for cancelled tasks
|
||||
for task in [progress_task, interrupt_monitor, tracking_task, _notify_task]:
|
||||
for task in [progress_task, log_task, interrupt_monitor, tracking_task, _notify_task]:
|
||||
if task:
|
||||
try:
|
||||
await task
|
||||
|
|
|
|||
|
|
@ -2899,12 +2899,13 @@ class GatewaySlashCommandsMixin:
|
|||
return t("gateway.verbose.not_enabled")
|
||||
|
||||
# --- cycle mode (per-platform) ----------------------------------------
|
||||
cycle = ["off", "new", "all", "verbose"]
|
||||
cycle = ["off", "new", "all", "verbose", "log"]
|
||||
descriptions = {
|
||||
"off": t("gateway.verbose.mode_off"),
|
||||
"new": t("gateway.verbose.mode_new"),
|
||||
"all": t("gateway.verbose.mode_all"),
|
||||
"verbose": t("gateway.verbose.mode_verbose"),
|
||||
"log": t("gateway.verbose.mode_log"),
|
||||
}
|
||||
|
||||
# Read current effective mode for this platform via the resolver
|
||||
|
|
|
|||
|
|
@ -144,7 +144,7 @@ COMMAND_REGISTRY: list[CommandDef] = [
|
|||
CommandDef("timestamps", "Toggle [HH:MM] timestamps on messages and /history", "Configuration",
|
||||
cli_only=True, args_hint="[on|off|status]",
|
||||
subcommands=("on", "off", "status"), aliases=("ts",)),
|
||||
CommandDef("verbose", "Cycle tool progress display: off -> new -> all -> verbose",
|
||||
CommandDef("verbose", "Cycle tool progress display: off -> new -> all -> verbose -> log",
|
||||
"Configuration", cli_only=True,
|
||||
gateway_config_gate="display.tool_progress_command"),
|
||||
CommandDef("footer", "Toggle gateway runtime-metadata footer on final replies",
|
||||
|
|
|
|||
|
|
@ -4258,7 +4258,7 @@ OPTIONAL_ENV_VARS = {
|
|||
"category": "setting",
|
||||
},
|
||||
# HERMES_TOOL_PROGRESS and HERMES_TOOL_PROGRESS_MODE are deprecated —
|
||||
# now configured via display.tool_progress in config.yaml (off|new|all|verbose).
|
||||
# now configured via display.tool_progress in config.yaml (off|new|all|verbose|log).
|
||||
# The gateway still falls back to these env vars for backward compatibility,
|
||||
# so they live in _EXTRA_ENV_KEYS (known to .env sanitization/reload) but
|
||||
# are intentionally NOT listed here: OPTIONAL_ENV_VARS feeds user-facing
|
||||
|
|
|
|||
|
|
@ -1536,10 +1536,11 @@ def setup_agent_settings(config: dict):
|
|||
print_info(" new — Show tool name only when it changes (less noise)")
|
||||
print_info(" all — Show every tool call with a short preview")
|
||||
print_info(" verbose — Full args, results, and debug logs")
|
||||
print_info(" log — Silent in chat; write every tool call to ~/.hermes/logs/tool_calls.log (gateway only)")
|
||||
|
||||
current_mode = cfg_get(config, "display", "tool_progress", default="all")
|
||||
mode = prompt("Tool progress mode", current_mode)
|
||||
if mode.lower() in {"off", "new", "all", "verbose"}:
|
||||
if mode.lower() in {"off", "new", "all", "verbose", "log"}:
|
||||
if "display" not in config:
|
||||
config["display"] = {}
|
||||
config["display"]["tool_progress"] = mode.lower()
|
||||
|
|
|
|||
|
|
@ -379,6 +379,7 @@ gateway:
|
|||
mode_new: "⚙️ Tool progress: **NEW** — shown when tool changes (preview length: `display.tool_preview_length`, default 40)."
|
||||
mode_all: "⚙️ Tool progress: **ALL** — every tool call shown (preview length: `display.tool_preview_length`, default 40)."
|
||||
mode_verbose: "⚙️ Tool progress: **VERBOSE** — every tool call with full arguments."
|
||||
mode_log: "⚙️ Tool progress: **LOG** — silent in chat; tool calls written to ~/.hermes/logs/tool_calls.log."
|
||||
saved_suffix: "_(saved for **{platform}** — takes effect on next message)_"
|
||||
save_failed: "_(could not save to config: {error})_"
|
||||
|
||||
|
|
|
|||
|
|
@ -48,6 +48,7 @@ AUTHOR_MAP = {
|
|||
"ai-lab@foxmail.com": "CrazyBoyM", # PR #55828 salvage (image_gen openai-codex: wire image-to-image / reference-image editing via Codex Responses input_image parts; magic-byte + read-guard + 25MB-cap + clamp-to-16 hardening)
|
||||
"r0gersm1th@users.noreply.github.com": "r0gersm1th", # PR #3219 salvage (whatsapp bridge: resolve LID sender IDs to phone numbers in the message payload so phone-based allowlists match; commit authored by collaborator r0gersm1th, PR by @ajmeese7)
|
||||
"louis@letsfive.io": "Mibayy", # PR #3296 salvage (status: provider label honors config.yaml model.base_url, not just OPENAI_BASE_URL env)
|
||||
"me@keslerm.com": "keslerm", # PR #3459 salvage (gateway: 'log' tool_progress mode — silent in chat, tool calls appended to ~/.hermes/logs/tool_calls.log via rotating handler; duplicate of #3458 by @dlkakbs who submitted 4 min earlier — both credited)
|
||||
"tarunravi@gmail.com": "tarunravi", # PR #2696 salvage (api-server: inline MEDIA:<path> image tags as base64 data URLs in final responses so remote OpenAI-compatible frontends can render server-local screenshots; the PR's tool-progress-streaming and SSE-sentinel pieces were independently superseded on main)
|
||||
"aqdrgg19@gmail.com": "VolodymyrBg", # PR #2861 salvage (webhook: drop the unused full request payload from retained _delivery_info entries — up to ~1MB dead weight per delivery for the 1h idempotency TTL)
|
||||
"ohyes9711@gmail.com": "CharmingGroot", # PR #2794 salvage (email: guard msg_data[0][1] against malformed IMAP fetch structures so one bad response can't abort the batch and permanently lose seen-marked messages; Message-ID domain falls back to localhost when EMAIL_ADDRESS lacks '@')
|
||||
|
|
|
|||
107
tests/gateway/test_tool_log_mode.py
Normal file
107
tests/gateway/test_tool_log_mode.py
Normal file
|
|
@ -0,0 +1,107 @@
|
|||
"""Tests for the `log` tool_progress mode (salvage of #3459 / #3458).
|
||||
|
||||
`display.tool_progress: log` keeps the chat silent and appends tool-call
|
||||
lines to ~/.hermes/logs/tool_calls.log via write_tool_log's rotating handler.
|
||||
These tests exercise the mode's building blocks without spinning up a full
|
||||
gateway run: the callback log-branch semantics and the writer coroutine.
|
||||
"""
|
||||
|
||||
import asyncio
|
||||
import queue
|
||||
from datetime import datetime
|
||||
|
||||
import pytest
|
||||
|
||||
|
||||
def _log_branch(log_queue, progress_queue, event_type, tool_name, preview=None):
|
||||
"""Replica of the log-mode branch in gateway/run.py progress_callback."""
|
||||
if log_queue is not None:
|
||||
if event_type == "tool.started" and tool_name and tool_name != "_thinking":
|
||||
ts = datetime.now().strftime("%Y-%m-%d %H:%M:%S")
|
||||
preview_str = f' "{preview}"' if preview else ""
|
||||
log_queue.put(f"{ts} {tool_name}:{preview_str}".rstrip())
|
||||
if not progress_queue:
|
||||
return "returned"
|
||||
return "fell-through"
|
||||
|
||||
|
||||
class TestLogBranchSemantics:
|
||||
def test_tool_started_enqueued(self):
|
||||
q = queue.Queue()
|
||||
assert _log_branch(q, None, "tool.started", "terminal", "ls -la") == "returned"
|
||||
line = q.get_nowait()
|
||||
assert "terminal" in line and "ls -la" in line
|
||||
|
||||
def test_tool_completed_not_enqueued(self):
|
||||
q = queue.Queue()
|
||||
_log_branch(q, None, "tool.completed", "terminal")
|
||||
assert q.empty()
|
||||
|
||||
def test_thinking_not_enqueued(self):
|
||||
q = queue.Queue()
|
||||
_log_branch(q, None, "tool.started", "_thinking", "pondering")
|
||||
assert q.empty()
|
||||
|
||||
def test_no_preview_line_has_no_quotes(self):
|
||||
q = queue.Queue()
|
||||
_log_branch(q, None, "tool.started", "todo")
|
||||
line = q.get_nowait()
|
||||
assert line.endswith("todo:")
|
||||
assert '"' not in line
|
||||
|
||||
def test_log_none_falls_through(self):
|
||||
assert _log_branch(None, None, "tool.started", "terminal") == "fell-through"
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_write_tool_log_writes_and_rotates_handler(tmp_path, monkeypatch):
|
||||
"""The writer coroutine drains the queue into logs/tool_calls.log."""
|
||||
import gateway.run as gateway_run
|
||||
|
||||
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
|
||||
|
||||
log_queue: queue.Queue = queue.Queue()
|
||||
log_queue.put("2026-07-02 10:00:00 terminal: \"echo hi\"")
|
||||
log_queue.put("2026-07-02 10:00:01 read_file: \"foo.py\"")
|
||||
|
||||
# Minimal inline copy of write_tool_log wiring (the real coroutine is a
|
||||
# closure inside _run_agent); exercise the same handler configuration.
|
||||
import logging
|
||||
from logging.handlers import RotatingFileHandler
|
||||
|
||||
from agent.redact import RedactingFormatter
|
||||
|
||||
log_dir = tmp_path / "logs"
|
||||
log_dir.mkdir(parents=True, exist_ok=True)
|
||||
handler = RotatingFileHandler(
|
||||
log_dir / "tool_calls.log", maxBytes=5 * 1024 * 1024, backupCount=3,
|
||||
encoding="utf-8",
|
||||
)
|
||||
handler.setFormatter(RedactingFormatter("%(message)s"))
|
||||
tool_logger = logging.getLogger(f"hermes.tool_calls.test.{id(log_queue)}")
|
||||
tool_logger.setLevel(logging.INFO)
|
||||
tool_logger.propagate = False
|
||||
tool_logger.addHandler(handler)
|
||||
try:
|
||||
while True:
|
||||
try:
|
||||
tool_logger.info("%s", log_queue.get_nowait())
|
||||
except queue.Empty:
|
||||
break
|
||||
finally:
|
||||
tool_logger.removeHandler(handler)
|
||||
handler.flush()
|
||||
handler.close()
|
||||
|
||||
content = (log_dir / "tool_calls.log").read_text(encoding="utf-8")
|
||||
assert "terminal" in content
|
||||
assert "read_file" in content
|
||||
assert content.count("\n") == 2
|
||||
await asyncio.sleep(0) # keep the asyncio marker honest
|
||||
|
||||
|
||||
def test_log_mode_disables_chat_progress():
|
||||
"""tool_progress_enabled must be False in log mode (silent in chat)."""
|
||||
for mode, expected in [("all", True), ("log", False), ("off", False)]:
|
||||
enabled = mode not in {"off", "log"}
|
||||
assert enabled is expected
|
||||
|
|
@ -117,8 +117,8 @@ class TestVerboseCommand:
|
|||
monkeypatch.setattr(gateway_run, "_hermes_home", hermes_home)
|
||||
runner = _make_runner()
|
||||
|
||||
# off -> new -> all -> verbose -> off
|
||||
expected = ["new", "all", "verbose", "off"]
|
||||
# off -> new -> all -> verbose -> log -> off
|
||||
expected = ["new", "all", "verbose", "log", "off"]
|
||||
for mode in expected:
|
||||
result = await runner._handle_verbose_command(_make_event())
|
||||
saved = yaml.safe_load(config_path.read_text(encoding="utf-8"))
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue