fix: restore complete message timestamp coverage
This commit is contained in:
@@ -32,6 +32,7 @@ import re
|
||||
from pathlib import Path
|
||||
from typing import Any, Dict, List, Optional
|
||||
|
||||
from agent.message_metadata import stamp_message_timestamp
|
||||
from agent.tool_result_classification import (
|
||||
FILE_MUTATING_TOOL_NAMES as _FILE_MUTATING_TOOLS,
|
||||
)
|
||||
@@ -557,13 +558,13 @@ def make_tool_result_message(
|
||||
callers should compare by value, not by ``is``.
|
||||
"""
|
||||
wrapped = _maybe_wrap_untrusted(name, content)
|
||||
message = {
|
||||
message = stamp_message_timestamp({
|
||||
"role": "tool",
|
||||
"name": name,
|
||||
"tool_name": name,
|
||||
"content": wrapped,
|
||||
"tool_call_id": tool_call_id,
|
||||
}
|
||||
})
|
||||
try:
|
||||
risk_metadata = _tool_output_risk_metadata(name, content)
|
||||
except Exception as exc:
|
||||
|
||||
@@ -46,6 +46,7 @@ def test_closing_makes_next_user_message_alternation_safe():
|
||||
produce the ``tool → user`` shape strict providers choke on."""
|
||||
messages = _tool_tail()
|
||||
close_interrupted_tool_sequence(messages, None)
|
||||
assert isinstance(messages[-1]["timestamp"], float)
|
||||
follow_on = messages + [{"role": "user", "content": "they do! increase the timing"}]
|
||||
_assert_no_tool_then_user(follow_on)
|
||||
|
||||
@@ -65,4 +66,3 @@ def test_user_tail_is_left_untouched():
|
||||
assert close_interrupted_tool_sequence(messages, None) is False
|
||||
assert len(messages) == 1
|
||||
|
||||
|
||||
|
||||
@@ -72,6 +72,7 @@ def test_codex_success_flushes_and_reports_persisted():
|
||||
effective_task_id="task-1",
|
||||
)
|
||||
assert result["completed"] is True
|
||||
assert isinstance(result["messages"][-1]["timestamp"], float)
|
||||
# With the agent as sole persister, the gateway must SKIP its DB write.
|
||||
assert result["agent_persisted"] is True
|
||||
|
||||
@@ -152,6 +153,10 @@ def test_codex_turn_persists_each_message_exactly_once():
|
||||
# Exactly one user turn, exactly one assistant turn — no duplicates.
|
||||
assert contents.count("USER_TURN") == 1, contents
|
||||
assert contents.count("CODEX_ASSISTANT") == 1, contents
|
||||
assistant_row = next(
|
||||
row for row in rows if row["content"] == "CODEX_ASSISTANT"
|
||||
)
|
||||
assert isinstance(assistant_row["timestamp"], float)
|
||||
# session_search can now see the codex conversation.
|
||||
hits = {r["session_id"] for r in db.search_messages("CODEX_ASSISTANT")}
|
||||
assert sid in hits
|
||||
|
||||
@@ -220,6 +220,12 @@ def test_mixed_batch_preserves_tool_call_result_pairing(agent_env):
|
||||
# and each must have exactly one matching tool result.
|
||||
assert set(tc_ids) == {"call_0", "call_1"}
|
||||
assert sorted(result_ids) == sorted(tc_ids)
|
||||
assert all(
|
||||
isinstance(message.get("timestamp"), float)
|
||||
for message in msgs
|
||||
if isinstance(message, dict)
|
||||
and message.get("role") in {"user", "assistant", "tool"}
|
||||
)
|
||||
|
||||
|
||||
|
||||
@@ -246,4 +252,3 @@ def test_invalid_tool_exhaustion_closes_tool_tail(agent_env):
|
||||
assert msgs[-1].get("role") == "assistant"
|
||||
assert "invalid tool call" in (msgs[-1].get("content") or "").lower()
|
||||
|
||||
|
||||
|
||||
@@ -62,6 +62,24 @@ class TestEstimateMessagesTokensRough:
|
||||
assert result > 0
|
||||
assert result == (len(str(msg)) + 3) // 4
|
||||
|
||||
def test_persistence_timestamp_does_not_change_estimate(self):
|
||||
"""Durability metadata must not create artificial context pressure."""
|
||||
msg = {
|
||||
"role": "assistant",
|
||||
"content": "done",
|
||||
"tool_calls": [
|
||||
{
|
||||
"id": "call-1",
|
||||
"function": {"name": "terminal", "arguments": "{}"},
|
||||
}
|
||||
],
|
||||
}
|
||||
stamped = {**msg, "timestamp": 1_781_976_577.123456}
|
||||
|
||||
assert estimate_messages_tokens_rough([stamped]) == (
|
||||
estimate_messages_tokens_rough([msg])
|
||||
)
|
||||
|
||||
def test_message_with_list_content(self):
|
||||
"""Vision messages with multimodal content arrays.
|
||||
|
||||
|
||||
@@ -135,6 +135,12 @@ class TestUntrustedWrapping:
|
||||
|
||||
class TestMakeToolResultMessage:
|
||||
|
||||
def test_message_is_timestamped_when_result_is_created(self, monkeypatch):
|
||||
monkeypatch.setattr("agent.message_metadata.wall_time", lambda: 123.5)
|
||||
|
||||
msg = make_tool_result_message("terminal", "ok", "call_timestamp")
|
||||
|
||||
assert msg["timestamp"] == 123.5
|
||||
|
||||
def test_high_risk_message_content_wrapped(self):
|
||||
msg = make_tool_result_message("web_extract", SAMPLE_LONG_TEXT, "call_2")
|
||||
|
||||
@@ -203,11 +203,21 @@ def test_returns_turn_context_with_user_message_appended():
|
||||
assert isinstance(ctx, TurnContext)
|
||||
assert ctx.user_message == "hello"
|
||||
# The user turn was appended and indexed.
|
||||
assert ctx.messages[-1] == {"role": "user", "content": "hello"}
|
||||
assert ctx.messages[-1]["role"] == "user"
|
||||
assert ctx.messages[-1]["content"] == "hello"
|
||||
assert isinstance(ctx.messages[-1]["timestamp"], float)
|
||||
assert ctx.current_turn_user_idx == len(ctx.messages) - 1
|
||||
assert ctx.active_system_prompt == "SYSTEM"
|
||||
|
||||
|
||||
def test_user_message_preserves_platform_event_timestamp():
|
||||
agent = _FakeAgent()
|
||||
|
||||
ctx = _build(agent, persist_user_timestamp=123.5)
|
||||
|
||||
assert ctx.messages[-1]["timestamp"] == 123.5
|
||||
|
||||
|
||||
# ── Trivial-prompt prefetch gate (PR #25350 salvage) ─────────────────────────
|
||||
#
|
||||
# The prologue is the ONLY place the per-turn synchronous
|
||||
@@ -267,7 +277,10 @@ def test_turn_start_replaces_stale_parent_history_with_compression_child():
|
||||
assert agent._current_turn_id.startswith("compression-child:")
|
||||
log_context.assert_called_once_with("compression-child")
|
||||
assert ctx.conversation_history == compacted_history
|
||||
assert ctx.messages == compacted_history + [{"role": "user", "content": "hello"}]
|
||||
assert ctx.messages[:-1] == compacted_history
|
||||
assert ctx.messages[-1]["role"] == "user"
|
||||
assert ctx.messages[-1]["content"] == "hello"
|
||||
assert isinstance(ctx.messages[-1]["timestamp"], float)
|
||||
assert all(message.get("content") != "stale parent" for message in ctx.messages)
|
||||
|
||||
|
||||
@@ -309,6 +322,7 @@ def test_pending_cli_message_uses_clean_override_for_api_local_note():
|
||||
assert ctx.messages[-1] is staged
|
||||
assert ctx.messages[-1]["content"] == "[MODEL NOTE]\n\nclean prompt"
|
||||
assert ctx.messages[-1]["_db_persisted"] is True
|
||||
assert isinstance(ctx.messages[-1]["timestamp"], float)
|
||||
assert agent._pending_cli_user_message is None
|
||||
|
||||
|
||||
@@ -438,4 +452,3 @@ def test_prologue_does_not_title_machine_driven_runs(platform):
|
||||
overwritten or never read.
|
||||
"""
|
||||
assert not _title_turn(platform).called
|
||||
|
||||
|
||||
@@ -123,9 +123,57 @@ def test_final_response_closes_tool_tail_before_persistence(monkeypatch):
|
||||
_turn_exit_reason="fallback_prior_turn_content",
|
||||
)
|
||||
|
||||
assert result["messages"][-1] == {"role": "assistant", "content": "Done."}
|
||||
assert result["messages"][-1]["role"] == "assistant"
|
||||
assert result["messages"][-1]["content"] == "Done."
|
||||
assert isinstance(result["messages"][-1]["timestamp"], float)
|
||||
assert agent.persisted_messages is not None
|
||||
assert agent.persisted_messages[-1] == {"role": "assistant", "content": "Done."}
|
||||
assert agent.persisted_messages[-1] == result["messages"][-1]
|
||||
|
||||
|
||||
def test_fallback_timestamp_survives_delayed_sqlite_persistence(
|
||||
monkeypatch, tmp_path
|
||||
):
|
||||
"""The durable row records message creation, not the later DB flush."""
|
||||
from hermes_state import SessionDB
|
||||
|
||||
created_at = 1_781_976_577.25
|
||||
persisted_at = created_at + 600
|
||||
monkeypatch.setattr("agent.message_metadata.wall_time", lambda: created_at)
|
||||
monkeypatch.setattr("hermes_state.time.time", lambda: persisted_at)
|
||||
monkeypatch.setattr("hermes_cli.plugins.invoke_hook", lambda *_a, **_kw: [])
|
||||
|
||||
db = SessionDB(db_path=tmp_path / "state.db")
|
||||
db.create_session("sess-test", source="cli")
|
||||
agent = FakeAgent()
|
||||
|
||||
def persist_to_sqlite(messages, _conversation_history):
|
||||
db.replace_messages(agent.session_id, messages)
|
||||
agent.persisted_messages = db.get_messages_as_conversation(agent.session_id)
|
||||
|
||||
agent._persist_session = persist_to_sqlite
|
||||
messages = [
|
||||
{"role": "user", "content": "do it", "timestamp": created_at - 1},
|
||||
{"role": "tool", "content": "ok", "tool_call_id": "call-1"},
|
||||
]
|
||||
|
||||
finalize_turn(
|
||||
agent,
|
||||
final_response="Done.",
|
||||
api_call_count=2,
|
||||
interrupted=False,
|
||||
failed=False,
|
||||
messages=messages,
|
||||
conversation_history=[],
|
||||
effective_task_id="task",
|
||||
turn_id="turn",
|
||||
user_message="do it",
|
||||
original_user_message="do it",
|
||||
_should_review_memory=False,
|
||||
_turn_exit_reason="fallback_prior_turn_content",
|
||||
)
|
||||
|
||||
assert agent.persisted_messages[-1]["timestamp"] == created_at
|
||||
assert agent.persisted_messages[-1]["timestamp"] != persisted_at
|
||||
|
||||
|
||||
def test_final_response_fills_pure_tool_call_tail(monkeypatch):
|
||||
|
||||
@@ -411,7 +411,9 @@ def test_chat_clears_previous_turn_persistence_override_before_staging():
|
||||
assert agent.staged_override is None
|
||||
assert agent._persist_user_message_idx is None
|
||||
assert agent._persist_user_message_timestamp is None
|
||||
assert agent.staged_message == {"role": "user", "content": "new prompt"}
|
||||
assert agent.staged_message["role"] == "user"
|
||||
assert agent.staged_message["content"] == "new prompt"
|
||||
assert isinstance(agent.staged_message["timestamp"], float)
|
||||
|
||||
|
||||
|
||||
|
||||
@@ -323,10 +323,13 @@ class TestModelFacingMessagesUnchanged:
|
||||
|
||||
@pytest.mark.parametrize("dispatch_mode", ["sequential", "concurrent"])
|
||||
def test_model_facing_messages_identical_with_focus_on_vs_off(self, dispatch_mode):
|
||||
# Focus ON == the existing tool_progress "off" suppression path.
|
||||
focus_on = _run_fake_turn(FOCUS_TOOL_PROGRESS_MODE, dispatch_mode)
|
||||
# Focus OFF == the default noisy display mode.
|
||||
focus_off = _run_fake_turn("all", dispatch_mode)
|
||||
# Creation timestamps are durable metadata, so hold the clock steady
|
||||
# while comparing otherwise identical turns.
|
||||
with patch("agent.message_metadata.wall_time", return_value=1_700_000_000.0):
|
||||
# Focus ON == the existing tool_progress "off" suppression path.
|
||||
focus_on = _run_fake_turn(FOCUS_TOOL_PROGRESS_MODE, dispatch_mode)
|
||||
# Focus OFF == the default noisy display mode.
|
||||
focus_off = _run_fake_turn("all", dispatch_mode)
|
||||
|
||||
assert focus_on == focus_off, (
|
||||
"focus view altered the model-facing messages — display-only "
|
||||
|
||||
@@ -135,10 +135,12 @@ def test_current_user_turn_is_persisted_before_provider_call(agent):
|
||||
assert observed[0][0] == "persist"
|
||||
assert observed[1][0] == "provider"
|
||||
persisted_messages = observed[0][1]
|
||||
assert persisted_messages[-1] == {
|
||||
"role": "user",
|
||||
"content": "new message that must survive a crash",
|
||||
}
|
||||
assert persisted_messages[-1]["role"] == "user"
|
||||
assert (
|
||||
persisted_messages[-1]["content"]
|
||||
== "new message that must survive a crash"
|
||||
)
|
||||
assert isinstance(persisted_messages[-1]["timestamp"], float)
|
||||
|
||||
|
||||
class TestHTTP413Compression:
|
||||
|
||||
@@ -608,6 +608,7 @@ class TestBuildAssistantMessageEmptyContentPad:
|
||||
"Builder must store textless turns as-is — wire repair is owned "
|
||||
"by repair_empty_non_final_messages at the send boundary."
|
||||
)
|
||||
assert isinstance(msg["timestamp"], float)
|
||||
|
||||
|
||||
def test_tool_call_turn_content_left_empty(self):
|
||||
@@ -622,6 +623,7 @@ class TestBuildAssistantMessageEmptyContentPad:
|
||||
)
|
||||
assert msg["content"] == ""
|
||||
assert msg["tool_calls"]
|
||||
assert isinstance(msg["timestamp"], float)
|
||||
|
||||
def test_non_empty_content_unchanged(self):
|
||||
from agent.chat_completion_helpers import build_assistant_message
|
||||
@@ -630,6 +632,7 @@ class TestBuildAssistantMessageEmptyContentPad:
|
||||
agent = self._agent_for_builder()
|
||||
msg = build_assistant_message(agent, _mock_assistant_msg(content="hi"), "stop")
|
||||
assert msg["content"] == "hi"
|
||||
assert isinstance(msg["timestamp"], float)
|
||||
|
||||
|
||||
class TestSendTimeEmptyAssistantPad:
|
||||
|
||||
@@ -3496,10 +3496,12 @@ class TestRunConversation:
|
||||
# Partial reply is surfaced and persisted as an assistant turn so the
|
||||
# next turn remembers what the model said.
|
||||
assert result["final_response"] == "Sure, here's how to do it: first"
|
||||
assert result["messages"][-1] == {
|
||||
"role": "assistant",
|
||||
"content": "Sure, here's how to do it: first",
|
||||
}
|
||||
assert result["messages"][-1]["role"] == "assistant"
|
||||
assert (
|
||||
result["messages"][-1]["content"]
|
||||
== "Sure, here's how to do it: first"
|
||||
)
|
||||
assert isinstance(result["messages"][-1]["timestamp"], float)
|
||||
|
||||
def test_redirect_during_thinking_retries_same_turn_with_context(self, agent):
|
||||
"""A corrective follow-up does not end the turn, and displayed reasoning
|
||||
|
||||
Reference in New Issue
Block a user