Files
roboco/tests/unit/gateway/test_audit_on_rejection.py
T
93739a9dca fix(notifications): stop tick-wide row locks + poisoned-session swallows behind the PendingRollbackError 500s (#743)
* fix(notifications): release re-escalation row locks per row; stop swallowing DB errors in notify_get

The re-escalation sweep ran one tick-wide transaction, so each CAS
claim's row lock was held across every remaining delivery until the
single commit — a concurrent mark-read UPDATE on a claimed row starved
into the 60s lock_timeout. The sweep now commits per row (claim commit
releases the lock before delivery and makes the burned slot durable),
re-fetches each row by snapshotted id so one row's rollback can't
expire the rest of the tick, and savepoints each recipient's delivery.

notify_get's bare except swallowed the resulting LockNotAvailableError
into a false "notification not found" and returned a poisoned session
to the commit-at-send middleware, which blew up with
PendingRollbackError; it now catches only the two domain outcomes.

defer_after_commit's listeners fire on SAVEPOINT release too, which
would have drained deferred telegram/bus work before real durability —
they now skip savepoint boundaries via get_nested_transaction() (the
root get_transaction() is non-None inside the listener even at a real
commit). acknowledge_for_recipient's Redis dedup-clear moved before the
flush so the row lock never spans a Redis round-trip. The five
best-effort CEO-notify swallows that persist notification rows are
savepointed.

* fix(services): contain swallowed best-effort DB write failures instead of poisoning the session

Sweep of the same class as the notify_get incident: broad
except-Exception handlers that swallow a failure whose try-body writes
through the shared session leave the session rollback-pending, and the
verb/request then dies later with PendingRollbackError at
commit-at-send. Confirmed-dangerous sites now run the write inside a
savepoint (safe since defer_after_commit skips savepoint boundaries):
ceo_approve's verified-stamp, completion/pitch/postmortem-style CEO
notifies, _inherit_upstream_base, _link_commit_to_task (covers every
commit route), board-program LEARN records, the QA/PR-gate/PM-merge
verified-stamps, and the documenter->PM handoff.
_ack_pending_wake_notifications gets the same treatment so a wake-ack
failure can't fail the A2A read. telegram_inbound's per-update loop and
intake confirm roll back explicitly instead (their success paths commit
mid-flow, so a savepoint doesn't fit).

A swallowed savepoint rollback fully expires any ORM object mutated
inside the block, and the next attribute read raises MissingGreenlet —
strictly worse than the original bug. The two paths that keep using the
object after the swallow (doc handoff's envelope build, base
inheritance's claim continuation) refresh it in the except path;
regression tests run against a real session and were verified to fail
with the refresh reverted.

* test: shape mocked session.execute results so sync accessors stop leaking unawaited coroutines

An AsyncMock's auto-created children are themselves AsyncMock, so
production code that correctly awaits session.execute() and then calls
sync accessors (.scalars().all(), .scalar_one_or_none()) on the result
was silently collecting unawaited coroutines in 22 test files — 80
RuntimeWarnings per unit run, and in test_flow_soup_guard one mock
raised a real TypeError that a coincidentally-matching invalid_state
envelope masked. Each affected fixture now returns a plain MagicMock
shaped like a real Result. Zero AsyncMock warnings remain.

* docs: document per-row sweep commits and the savepoint/refresh containment pattern

---------

Co-authored-by: Renn F <rennf93@users.noreply.github.com>
2026-07-30 16:35:42 +02:00

249 lines
8.9 KiB
Python

"""Every Envelope rejection from a Choreographer verb writes an audit row.
Choreographer takes an ``audit`` dependency but historically never invoked
it. The result: every rejection envelope (invalid_state, not_authorized,
tracing_gap, not_found) silently disappeared. With no forensic trail, a
stuck flow had no breadcrumbs.
These tests pin the ``gateway.rejected`` audit-write behavior across the
range of rejection-returning verbs, including:
- not_authorized rejections (PM cannot execute code, role-typed claim)
- invalid_state rejections (no active task, expected status mismatch)
- tracing_gap rejections (missing notes, missing journal entries)
- not_found rejections (unknown task id)
The audit call is fire-and-forget; an exception inside ``log_event`` must
not propagate or alter the envelope returned to the agent.
"""
from __future__ import annotations
from datetime import UTC, datetime
from typing import Any
from unittest.mock import AsyncMock, MagicMock
from uuid import uuid4
import pytest
from roboco.services.gateway.choreographer import Choreographer, ChoreographerDeps
from roboco.services.gateway.envelope import Envelope
def _make_deps(**overrides: Any) -> ChoreographerDeps:
base: dict[str, Any] = {
"task": AsyncMock(),
"work_session": AsyncMock(),
"git": AsyncMock(),
"a2a": AsyncMock(),
"journal": AsyncMock(),
"audit": AsyncMock(),
"evidence_repo": AsyncMock(),
}
base.update(overrides)
# Findings-ledger reads (ReviewFindingsRepository.list_for_task) go
# through session.execute — an unconfigured AsyncMock's awaited result
# is itself an AsyncMock, so a plain sync `.scalars()` call on it leaks
# an unawaited coroutine. Empty scalars result (no findings).
base["task"].session.execute = AsyncMock(
return_value=MagicMock(
scalars=MagicMock(return_value=MagicMock(all=MagicMock(return_value=[])))
)
)
repo = base["evidence_repo"]
for method in (
"list_unread_a2a",
"list_unread_mentions",
"list_pending_notifications",
"task_metadata_gaps",
"recent_team_activity",
"blockers_in_lane",
"journal_highlights_for_task",
):
getattr(repo, method).return_value = []
# C8: default-fresh journal:decision so PM-decision gate passes.
# Tests that exercise the gate boundary stub their own value.
# The check matches MagicMock and AsyncMock (the two default sentinel
# types pytest's unittest.mock leaves on un-stubbed return_values).
_ldef = base["journal"].latest_decision_at.return_value
if type(_ldef).__name__ in ("MagicMock", "AsyncMock"):
base["journal"].latest_decision_at.return_value = datetime.now(UTC)
return ChoreographerDeps(**base)
# ---------------------------------------------------------------------------
# Primary acceptance test: PM cannot claim a code task — not_authorized path
# ---------------------------------------------------------------------------
@pytest.mark.asyncio
async def test_pm_cannot_execute_code_writes_audit_row() -> None:
"""A cell_pm calling i_will_work_on on a code task must:
1. Return an Envelope with error == 'not_authorized'
2. Write a gateway.rejected audit event with verb + reason details
"""
aid = uuid4()
tid = uuid4()
code_task = MagicMock(
id=tid,
status="pending",
assigned_to=aid,
task_type="code",
priority=1,
parent_task_id=None,
sequence=0,
team="backend",
)
task_svc = AsyncMock()
task_svc.get.return_value = code_task
task_svc.agent_for.return_value = MagicMock(role="cell_pm", team="backend")
task_svc.list_in_progress_for_agent.return_value = []
task_svc.list_paused_for_agent.return_value = []
task_svc.get_subtasks.return_value = []
audit_svc = AsyncMock()
deps = _make_deps(task=task_svc, audit=audit_svc)
c = Choreographer(deps)
env = await c.i_will_work_on(agent_id=aid, task_id=tid, plan="x")
assert env.error == "not_authorized"
audit_svc.log_event.assert_awaited()
args = audit_svc.log_event.await_args
assert args.kwargs["event_type"] == "gateway.rejected"
assert args.kwargs["details"]["verb"] == "i_will_work_on"
assert args.kwargs["details"]["reason"] == "not_authorized"
# ---------------------------------------------------------------------------
# not_found path: unknown task id
# ---------------------------------------------------------------------------
@pytest.mark.asyncio
async def test_unknown_task_writes_audit_row() -> None:
"""not_found rejection (unknown task id) is audited."""
aid = uuid4()
tid = uuid4()
task_svc = AsyncMock()
task_svc.get.return_value = None
audit_svc = AsyncMock()
deps = _make_deps(task=task_svc, audit=audit_svc)
c = Choreographer(deps)
env = await c.i_am_done(aid, tid, notes="something")
assert env.error == "not_found"
audit_svc.log_event.assert_awaited()
args = audit_svc.log_event.await_args
assert args.kwargs["event_type"] == "gateway.rejected"
assert args.kwargs["details"]["verb"] == "i_am_done"
assert args.kwargs["details"]["reason"] == "not_found"
# ---------------------------------------------------------------------------
# Happy path must NOT write an audit row.
# ---------------------------------------------------------------------------
@pytest.mark.asyncio
async def test_successful_verb_does_not_write_audit_row() -> None:
"""Successful (non-error) Envelope must not emit gateway.rejected audit."""
aid = uuid4()
task_svc = AsyncMock()
task_svc.list_assigned_for_agent.return_value = []
task_svc.list_paused_for_agent.return_value = []
audit_svc = AsyncMock()
deps = _make_deps(task=task_svc, audit=audit_svc)
c = Choreographer(deps)
env = await c.give_me_work(aid)
# No rejection, so no audit row.
assert env.error is None
audit_svc.log_event.assert_not_awaited()
# ---------------------------------------------------------------------------
# Audit failure must NOT block the verb (best-effort rule).
# ---------------------------------------------------------------------------
@pytest.mark.asyncio
async def test_audit_log_event_failure_does_not_propagate() -> None:
"""If log_event raises, the verb still returns the rejection envelope."""
aid = uuid4()
tid = uuid4()
task_svc = AsyncMock()
# Unknown task id triggers not_found rejection on i_am_done.
task_svc.get.return_value = None
audit_svc = AsyncMock()
audit_svc.log_event.side_effect = RuntimeError("audit DB down")
deps = _make_deps(task=task_svc, audit=audit_svc)
c = Choreographer(deps)
# Must not raise; the rejection envelope should still come back.
env = await c.i_am_done(aid, tid, notes="x")
assert env.error == "not_found"
audit_svc.log_event.assert_awaited()
# ---------------------------------------------------------------------------
# remediate must ride along into the audit row — it's the only place a
# conventions-gate rejection's file:line violation listing lives.
# ---------------------------------------------------------------------------
@pytest.mark.asyncio
async def test_rejection_remediate_lands_in_audit_details() -> None:
"""A rejection's `remediate` hint is copied into the audit row's details.
Without this, an operator reading `gateway.rejected` audit rows for a
conventions-gate rejection sees only the summary message — the
actionable detail lives solely in `remediate`.
"""
aid = uuid4()
tid = uuid4()
code_task = MagicMock(
id=tid,
status="pending",
assigned_to=aid,
task_type="code",
priority=1,
parent_task_id=None,
sequence=0,
team="backend",
)
task_svc = AsyncMock()
task_svc.get.return_value = code_task
task_svc.agent_for.return_value = MagicMock(role="cell_pm", team="backend")
task_svc.list_in_progress_for_agent.return_value = []
task_svc.list_paused_for_agent.return_value = []
task_svc.get_subtasks.return_value = []
audit_svc = AsyncMock()
deps = _make_deps(task=task_svc, audit=audit_svc)
c = Choreographer(deps)
env = await c.i_will_work_on(agent_id=aid, task_id=tid, plan="x")
assert env.error == "not_authorized"
assert env.remediate
args = audit_svc.log_event.await_args
assert args.kwargs["details"]["remediate"] == env.remediate
@pytest.mark.asyncio
async def test_rejection_without_remediate_omits_audit_key() -> None:
"""A rejection with no remediate must not add a null key to the row."""
aid = uuid4()
tid = uuid4()
audit_svc = AsyncMock()
deps = _make_deps(audit=audit_svc)
c = Choreographer(deps)
env = Envelope(error="not_found", message="bare rejection, no remediate")
await c._emit_rejection(env, agent_id=aid, task_id=tid, verb="test_verb")
args = audit_svc.log_event.await_args
assert "remediate" not in args.kwargs["details"]