[F061] audit status-transition rows now written in-session (F061/F073/F075)

_emit_status_transition_audit now writes AuditLogTable rows into
self.session synchronously (session.add) instead of dispatching
AuditService.log_task_event fire-and-forget on its own connection.

The audit row now commits/rolls back atomically with the status
transition in the caller's transaction, closing three facets at once:
- F061: audit commit no longer decoupled from the transition commit
- F073: a committed transition can no longer have NO audit row
  (the row rides the same transaction; a swallowed persist can't drop it)
- F075: a transition rolled back inside a verb savepoint no longer
  leaves a phantom audit row (the row is in the savepoint too)

log_task_event is now called only from this helper (narrow blast
radius verified); revision_count increment stays at this single
chokepoint. Cycle-time/bottleneck reconstruction from task.<status>
events is no longer silently corruptible.

Tests: test_emit_status_transition_audit_writes_in_session_atomically,
test_finalize_claim_rollback_emits_reversal_audit, escalation-audit
tests retargeted to in-session AuditLogTable rows.

Also: _canonical_bump_files grep-looseness follow-on (F058) -- filter
by subject, not body; git log --grep matches any message line, so a
non-release commit whose body references chore(release): shadowed the
real release commit. Test
test_canonical_bump_files_ignores_body_only_chore_release_match.
This commit is contained in:
Renn F
2026-06-28 16:32:31 +02:00
parent 532261fed6
commit 7f63e50623
5 changed files with 192 additions and 62 deletions
+22 -6
View File
@@ -416,12 +416,28 @@ def _canonical_bump_files(root: Path, version: str) -> list[str]:
# Subsequent releases derive the canonical bump set from the previous # Subsequent releases derive the canonical bump set from the previous
# ``chore(release):`` commit's touched files — the historical record of # ``chore(release):`` commit's touched files — the historical record of
# what a release bumps. # what a release bumps.
sha = _run_git( #
root, ["log", "--grep", "^chore(release):", "-n1", "--format=%H"] # ``git log --grep "^chore(release):"`` matches ANY message line, including
).strip() # a body line of a non-release commit that merely REFERENCES the
if sha: # ``chore(release):`` type (e.g. a fix commit explaining the derivation). A
raw = _run_git(root, ["show", "--name-only", "--format=", sha]) # newer such commit would shadow the real release commit and the bump plan
return sorted(line.strip() for line in raw.splitlines() if line.strip()) # would list the fix's files instead of the release's. Filter to the
# candidate whose SUBJECT (``%s``) starts with ``chore(release):`` — the
# real release-commit shape ``chore(release): X.Y.Z``. ``%x01`` separates
# sha from subject so a subject may contain spaces unambiguously.
raw = _run_git(
root,
["log", "--grep", "^chore(release):", "--format=%H%x01%s"],
)
for line in raw.splitlines():
if "\x01" not in line:
continue
sha, subject = line.split("\x01", 1)
if subject.startswith("chore(release):"):
files_raw = _run_git(root, ["show", "--name-only", "--format=", sha])
return sorted(
line.strip() for line in files_raw.splitlines() if line.strip()
)
# F058: the FIRST release has no prior ``chore(release):`` commit, so the # F058: the FIRST release has no prior ``chore(release):`` commit, so the
# historical derivation returns ``[]`` and the executor would publish a tag # historical derivation returns ``[]`` and the executor would publish a tag
# with no files bumped (a no-op release masquerading as X.Y.Z). Fall back to # with no files bumped (a no-op release masquerading as X.Y.Z). Fall back to
+42 -23
View File
@@ -662,25 +662,40 @@ class TaskService(BaseService):
task without routing through the strict transition validator record task without routing through the strict transition validator record
the same audit event. No status change may bypass the audit log. the same audit event. No status change may bypass the audit log.
Fire-and-forget, but we hold a strong reference to the background task The row is written into the CALLER's session (``self.session.add``),
(via ``_background_tasks``): the event loop only weak-refs tasks, so so it commits / rolls back ATOMICALLY with the status transition the
without it the audit write can be garbage-collected before it commits. audit journey can never diverge from real task state. This closes three
facets of the fire-and-forget decoupling gap:
* F061/F073 the audit commit is no longer decoupled on a separate
connection whose failures were swallowed; a committed transition now
ALWAYS has its audit row (same transaction), and a persist failure
fails the transition (fail-closed for the metric source of truth)
instead of silently dropping the row.
* F075 a transition rolled back inside a verb savepoint
(``_verb_runner`` wraps composed actions in ``begin_nested``) now
rolls its audit row back too no phantom ``task.<status>`` row for a
transition that did not stick. (The claim-branch-failure rollback in
``_finalize_claim`` is one such site; the savepoint rollback handles
the general case.)
The ``revision_count`` rework counter is incremented synchronously
here (the single chokepoint every transition funnels through).
The explicit ``audit_agent_id`` (capture-before-mutate) wins: callers The explicit ``audit_agent_id`` (capture-before-mutate) wins: callers
like ``submit_for_qa`` clear ``task.claimed_by`` before transitioning like ``submit_for_qa`` clear ``task.claimed_by`` before transitioning
but still want the row attributed to the outgoing agent. Otherwise fall but still want the row attributed to the outgoing agent. Otherwise fall
back to ``task.claimed_by``. back to ``task.claimed_by``. A structurally-invalid id coerces to
``None`` (mirroring ``AuditService._coerce_uuid``) so the row still
lands unattributed rather than FK-violating; a valid-but-deleted agent
id is a real bug worth surfacing as a transition failure.
""" """
import asyncio from roboco.db.tables import AuditLogTable
import contextlib
from roboco.services.audit import get_audit_service
# Rework counter: a bounce INTO needs_revision (not a re-entry) is one # Rework counter: a bounce INTO needs_revision (not a re-entry) is one
# rework cycle. Incremented at this single chokepoint — every transition # rework cycle. Incremented at this single chokepoint — every transition
# path funnels its audit through here exactly once — so the rework rate # path funnels its audit through here exactly once — so the rework rate
# is an O(1) column read. Synchronous (part of this unit of work), # is an O(1) column read. Synchronous (part of this unit of work).
# unlike the fire-and-forget audit rows below.
if ( if (
to_status == TaskStatus.NEEDS_REVISION.value to_status == TaskStatus.NEEDS_REVISION.value
and from_status != TaskStatus.NEEDS_REVISION.value and from_status != TaskStatus.NEEDS_REVISION.value
@@ -694,6 +709,13 @@ class TaskService(BaseService):
else: else:
resolved_audit_agent_id = None resolved_audit_agent_id = None
agent_uuid: UUID | None = None
if resolved_audit_agent_id:
try:
agent_uuid = UUID(resolved_audit_agent_id)
except (ValueError, AttributeError):
agent_uuid = None
details = { details = {
"from_status": from_status, "from_status": from_status,
"to_status": to_status, "to_status": to_status,
@@ -702,20 +724,17 @@ class TaskService(BaseService):
task.team.value if hasattr(task.team, "value") else str(task.team) task.team.value if hasattr(task.team, "value") else str(task.team)
), ),
} }
audit = get_audit_service() for event_type in self._audit_events_for(to_status, agent_role):
with contextlib.suppress(RuntimeError): self.session.add(
loop = asyncio.get_running_loop() AuditLogTable(
for event_type in self._audit_events_for(to_status, agent_role): event_type=event_type,
bg = loop.create_task( agent_id=agent_uuid,
audit.log_task_event( target_type="task",
event_type=event_type, target_id=task.id,
task_id=str(task.id), severity="info",
agent_id=resolved_audit_agent_id, details=dict(details),
details=details,
)
) )
self._background_tasks.add(bg) )
bg.add_done_callback(self._background_tasks.discard)
@staticmethod @staticmethod
def _audit_events_for(to_status: str, agent_role: str | None) -> list[str]: def _audit_events_for(to_status: str, agent_role: str | None) -> list[str]:
@@ -12,11 +12,11 @@ stranded on a board role.
from __future__ import annotations from __future__ import annotations
import asyncio from unittest.mock import AsyncMock, MagicMock
from unittest.mock import AsyncMock, MagicMock, patch
from uuid import uuid4 from uuid import uuid4
import pytest import pytest
from roboco.db.tables import AuditLogTable
from roboco.models.base import AgentRole, TaskStatus, TaskType, Team from roboco.models.base import AgentRole, TaskStatus, TaskType, Team
from roboco.services.task import ( from roboco.services.task import (
TaskService, TaskService,
@@ -528,8 +528,14 @@ async def test_apply_escalation_blocks_non_terminal_task() -> None:
async def test_apply_escalation_emits_blocked_audit_event() -> None: async def test_apply_escalation_emits_blocked_audit_event() -> None:
"""A non-divert escalation sets BLOCKED and MUST record a task.blocked audit """A non-divert escalation sets BLOCKED and MUST record a task.blocked audit
row. The escalate path sets status directly (bypassing the validated row. The escalate path sets status directly (bypassing the validated
transition), and used to skip the audit log entirely.""" transition), and used to skip the audit log entirely.
The audit row is written into the caller's session (F061/F073/F075: it
commits atomically with the transition, not fire-and-forget on a separate
connection), so we assert on the ``AuditLogTable`` added to the session."""
svc = _service() svc = _service()
added: list[object] = []
svc.session.add = MagicMock(side_effect=added.append) # type: ignore[assignment]
task = MagicMock( task = MagicMock(
id=uuid4(), id=uuid4(),
parent_task_id=uuid4(), parent_task_id=uuid4(),
@@ -542,56 +548,52 @@ async def test_apply_escalation_emits_blocked_audit_event() -> None:
status=TaskStatus.IN_PROGRESS, status=TaskStatus.IN_PROGRESS,
) )
_bind(svc, "_is_board_advisory_agent", AsyncMock(return_value=False)) _bind(svc, "_is_board_advisory_agent", AsyncMock(return_value=False))
audit_mock = MagicMock(log_task_event=AsyncMock())
with patch("roboco.services.audit.get_audit_service", return_value=audit_mock): await svc.apply_escalation(
await svc.apply_escalation( task=task,
task=task, target_agent_id=uuid4(),
target_agent_id=uuid4(), escalator_slug="be-pm",
escalator_slug="be-pm", target_slug="main-pm",
target_slug="main-pm", reason="needs a decision",
reason="needs a decision", )
)
# Drain the fire-and-forget audit task so the assertion sees the call.
pending = list(svc._background_tasks)
if pending:
await asyncio.gather(*pending, return_exceptions=True)
assert task.status == TaskStatus.BLOCKED assert task.status == TaskStatus.BLOCKED
audit_mock.log_task_event.assert_awaited_once() rows = [r for r in added if isinstance(r, AuditLogTable)]
kwargs = audit_mock.log_task_event.await_args.kwargs assert any(r.event_type == "task.blocked" for r in rows)
assert kwargs["event_type"] == "task.blocked" blocked = next(r for r in rows if r.event_type == "task.blocked")
assert kwargs["details"]["from_status"] == "in_progress" assert blocked.details["from_status"] == "in_progress"
assert kwargs["details"]["to_status"] == "blocked" assert blocked.details["to_status"] == "blocked"
@pytest.mark.asyncio @pytest.mark.asyncio
async def test_unblock_with_restore_emits_audit_event() -> None: async def test_unblock_with_restore_emits_audit_event() -> None:
"""The PM restore path sets status directly (bypassing the validated """The PM restore path sets status directly (bypassing the validated
transition) and used to skip the audit log; it must record the transition.""" transition) and used to skip the audit log; it must record the transition.
The audit row is written into the caller's session (F061/F073/F075: atomic
with the transition, not fire-and-forget), so we assert on the
``AuditLogTable`` added to the session."""
svc = _service() svc = _service()
added: list[object] = []
svc.session.add = MagicMock(side_effect=added.append) # type: ignore[assignment]
task = MagicMock( task = MagicMock(
id=uuid4(), id=uuid4(),
status=TaskStatus.BLOCKED, status=TaskStatus.BLOCKED,
pre_block_state="in_progress", pre_block_state="in_progress",
pre_block_assignee=None, pre_block_assignee=None,
claimed_by=uuid4(), claimed_by=uuid4(),
team=Team.BACKEND,
) )
_bind(svc, "get", AsyncMock(return_value=task)) _bind(svc, "get", AsyncMock(return_value=task))
audit_mock = MagicMock(log_task_event=AsyncMock())
with patch("roboco.services.audit.get_audit_service", return_value=audit_mock): await svc.unblock_with_restore(uuid4(), uuid4(), restore=True)
await svc.unblock_with_restore(uuid4(), uuid4(), restore=True)
pending = list(svc._background_tasks)
if pending:
await asyncio.gather(*pending, return_exceptions=True)
assert task.status == TaskStatus.IN_PROGRESS assert task.status == TaskStatus.IN_PROGRESS
audit_mock.log_task_event.assert_awaited_once() rows = [r for r in added if isinstance(r, AuditLogTable)]
kwargs = audit_mock.log_task_event.await_args.kwargs assert any(r.event_type == "task.in_progress" for r in rows)
assert kwargs["event_type"] == "task.in_progress" restored = next(r for r in rows if r.event_type == "task.in_progress")
assert kwargs["details"]["from_status"] == "blocked" assert restored.details["from_status"] == "blocked"
assert kwargs["details"]["to_status"] == "in_progress" assert restored.details["to_status"] == "in_progress"
# --------------------------------------------------------------------------- # ---------------------------------------------------------------------------
@@ -130,5 +130,48 @@ def test_first_release_emits_no_version_ref_gap_for_planned_files(
assert not any(g.category == "version_ref" for g in report.gaps) assert not any(g.category == "version_ref" for g in report.gaps)
def test_canonical_bump_files_ignores_body_only_chore_release_match(
tmp_path: Path,
) -> None:
"""A non-release commit whose message BODY references ``chore(release):``
(a body line starting with ``chore(release):``) must NOT be misidentified
as the last release commit.
``git log --grep "^chore(release):"`` matches ANY message line, so a
fix/docs commit that explains the release process (body line
``chore(release): the canonical set ...``) is matched and being newer
shadows the real release commit. The canonical set must come from the
commit whose SUBJECT starts with ``chore(release):`` (the real release
shape ``chore(release): X.Y.Z``), not a body-only match. (Regression: an
earlier fix commit's body referencing ``chore(release):`` was picked up,
so the bump plan listed that fix's files instead of the release's.)
"""
root = _first_release_repo(tmp_path)
# Real release commit (older) touching the version-embedding file + marker.
(root / "RELEASE_MARKER.txt").write_text("released\n", encoding="utf-8")
(root / "pyproject.toml").write_text('version = "0.2.0"\n', encoding="utf-8")
_git(root, "add", "-A")
_git(root, "commit", "-m", "chore(release): 0.2.0")
# A NEWER non-release commit whose BODY has a line starting with the
# release-commit prefix.
(root / "other.py").write_text("x = 1\n", encoding="utf-8")
_git(root, "add", "-A")
_git(
root,
"commit",
"-m",
"fix: tighten release-readiness derivation",
"-m",
"chore(release): the canonical set derives from this commit type",
)
files = _canonical_bump_files(root, "0.2.0")
# The canonical set is the REAL release commit's files...
assert "RELEASE_MARKER.txt" in files
assert "pyproject.toml" in files
# ...NOT the body-only-matching fix commit's file.
assert "other.py" not in files
if __name__ == "__main__": if __name__ == "__main__":
pytest.main([__file__, "-q"]) pytest.main([__file__, "-q"])
+50
View File
@@ -14,6 +14,7 @@ from unittest.mock import AsyncMock, MagicMock, patch
from uuid import uuid4 from uuid import uuid4
import pytest import pytest
from roboco.db.tables import AuditLogTable
from roboco.models.base import ( from roboco.models.base import (
AgentRole, AgentRole,
AgentStatus, AgentStatus,
@@ -1117,6 +1118,55 @@ async def test_finalize_claim_rollback_emits_reversal_audit() -> None:
assert {"from": "claimed", "to": "pending"} in audit_calls assert {"from": "claimed", "to": "pending"} in audit_calls
@pytest.mark.asyncio
async def test_emit_status_transition_audit_writes_in_session_atomically() -> None:
"""F061/F073/F075: the status-transition audit row is written into the
CALLER's session (same transaction as the transition), not fire-and-forget
on a separate connection.
Fire-and-forget decouples the audit commit from the transition commit:
a transition that rolls back inside a verb savepoint leaves a PHANTOM audit
row (F075), and a swallowed persist failure means a committed transition
can have NO audit row (F073) silently corrupting the cycle-time /
bottleneck metrics reconstructed from ``task.<status>`` events (F061).
Writing the row in-session makes it commit/roll back atomically with the
transition, closing all three. Asserted at the unit level: the row is
``session.add``-ed (same txn) with the metric-reconstruction details, and
NO fire-and-forget background task is spawned.
"""
svc = TaskService(MagicMock())
added: list[object] = []
svc.session.add = MagicMock(side_effect=added.append) # type: ignore[assignment]
prior_bg = set(svc._background_tasks)
task = MagicMock(id=uuid4(), claimed_by=uuid4(), team=Team.BACKEND)
svc._emit_status_transition_audit(
task,
from_status="pending",
to_status="claimed",
agent_role="developer",
audit_agent_id=None,
)
# The audit row is added to the CALLER's session (same transaction) — not
# dispatched to a separate fire-and-forget connection.
rows = [r for r in added if isinstance(r, AuditLogTable)]
assert len(rows) == 1
row = rows[0]
assert row.event_type == "task.claimed"
assert row.target_type == "task"
assert row.target_id == task.id
assert row.details["from_status"] == "pending"
assert row.details["to_status"] == "claimed"
assert row.details["agent_role"] == "developer"
assert row.details["team"] == "backend"
# The claiming agent is attributed (resolved from claimed_by).
assert row.agent_id == task.claimed_by
# No fire-and-forget audit task was spawned (the old decoupled path).
assert svc._background_tasks == prior_bg
# --------------------------------------------------------------------------- # ---------------------------------------------------------------------------
# _resolve_doc_abspath — normalize documenter-supplied paths under /app/docs # _resolve_doc_abspath — normalize documenter-supplied paths under /app/docs
# --------------------------------------------------------------------------- # ---------------------------------------------------------------------------