confluence_web/tests/backend/test_failure_diagnostics.py
Artur Mukhamadiev 6743c358f5 diagnostics: explain why a run failed instead of just "execution_failed"
Every internal failure was mapped to a fixed sanitized code before anything
recorded the cause, so an intermittent execution_failed was undebuggable: an
exhausted model-call budget, a model turn with no text, and a genuine crash all
looked identical.

The bridge now writes one bounded line to container stderr on failure with the
code, the internal reason, the state and both call counters, and the failure
sites pass a reason (budget exhausted, empty final answer with its content block
types, token counts against the limits). The wire error is unchanged.

The backend logs the agent's terminal code together with its own call counters,
and the sanitized tail of container stderr rather than only its byte count.
deploy/logging.json gives every logger a timestamp (uvicorn's default config
leaves non-uvicorn loggers on logging's fallback handler); override with
CONFLUENCE_WEB_LOG_CONFIG.
2026-09-16 19:48:50 +03:00

115 lines
4.5 KiB
Python

"""A failed run must leave an operator-readable trace in the backend log.
The wire error is a fixed sanitized code ("execution_failed"), so the log is the only
place the actual reason appears: the agent's own stderr line plus the backend's call
counters at the moment the agent gave up.
"""
from __future__ import annotations
import logging
from pathlib import Path
import pytest
from backend.artifacts import ArtifactStore
from backend.containers import FakeContainerManager
from backend.dev.fake_peer import ScriptedContainerPeer
from backend.errors import ExecutionFailedError
from backend.model import FakeModelAdapter
from backend.runner import QueryRunner
from backend.settings import Settings
from tests.backend.conftest import make_test_confluence_client_factory
AGENT_DIAGNOSTIC = (
'[agent] run failed code=execution_failed reason="Empty final answer (content blocks: none)" '
"state=RUNNING model_calls=50/50 tool_calls=12/100 pending=0 remaining_ms=412000\n"
)
class DiagnosticContainerManager(FakeContainerManager):
"""Fake container that writes one stderr line, as the real agent does when it fails."""
def __init__(self, diagnostic: bytes):
super().__init__(lambda: ScriptedContainerPeer(scenario="agent_error"))
self.diagnostic = diagnostic
async def create_and_run(self, query_id: str):
handle = await super().create_and_run(query_id)
handle.stderr.feed_data(self.diagnostic)
return handle
async def run_failing_query(tmp_path: Path, manager: FakeContainerManager) -> None:
runner = QueryRunner(
settings=Settings(approved_confluence_origins=["https://approved.example.com"], query_timeout_seconds=30.0),
container_manager=manager,
artifact_store=ArtifactStore(tmp_path / "artifacts"),
model_adapter=FakeModelAdapter(),
confluence_client_factory=make_test_confluence_client_factory(),
)
with pytest.raises(ExecutionFailedError):
await runner.run(
prompt="Research something long",
confluence_url="https://approved.example.com",
confluence_pat="test-pat-12345678901234567890",
session_id="sess_diag",
)
@pytest.mark.asyncio
async def test_failed_run_logs_agent_code_and_call_counters(tmp_path: Path, caplog):
caplog.set_level(logging.WARNING, logger="backend.runner")
await run_failing_query(tmp_path, DiagnosticContainerManager(AGENT_DIAGNOSTIC.encode()))
text = caplog.text
assert "agent terminated with code=execution_failed" in text
assert "model and" in text and "Confluence calls" in text
@pytest.mark.asyncio
async def test_failed_run_logs_the_container_stderr_reason(tmp_path: Path, caplog):
caplog.set_level(logging.WARNING, logger="backend.runner")
await run_failing_query(tmp_path, DiagnosticContainerManager(AGENT_DIAGNOSTIC.encode()))
text = caplog.text
assert "Empty final answer" in text, "the agent's reason must reach the log"
assert "model_calls=50/50" in text
@pytest.mark.asyncio
async def test_stderr_is_bounded_and_token_lookalikes_redacted(tmp_path: Path, caplog):
caplog.set_level(logging.WARNING, logger="backend.runner")
noisy = b"A" * 200_000 + b" Authorization: Bearer supersecrettokenvalue123456\n"
await run_failing_query(tmp_path, DiagnosticContainerManager(noisy))
records = [r for r in caplog.records if "container diagnostics" in r.getMessage()]
assert records, "a noisy failing container must still produce one bounded log record"
message = records[0].getMessage()
assert "supersecrettokenvalue123456" not in message
assert len(message) < 8192
@pytest.mark.asyncio
async def test_successful_run_logs_no_diagnostics(tmp_path: Path, caplog):
caplog.set_level(logging.WARNING, logger="backend.runner")
manager = DiagnosticContainerManager(b"noise on a healthy run\n")
manager.peer_factory = lambda: ScriptedContainerPeer(scenario="standard")
runner = QueryRunner(
settings=Settings(approved_confluence_origins=["https://approved.example.com"], query_timeout_seconds=30.0),
container_manager=manager,
artifact_store=ArtifactStore(tmp_path / "artifacts"),
model_adapter=FakeModelAdapter(),
confluence_client_factory=make_test_confluence_client_factory(),
)
result = await runner.run(
prompt="Research something",
confluence_url="https://approved.example.com",
confluence_pat="test-pat-12345678901234567890",
session_id="sess_ok",
)
assert result["markdown"]
assert "container diagnostics" not in caplog.text