Skip to content

Commit bea62bb

Browse files
fix(task): a step completion a later attempt fenced off raises instead of vanishing
record_step_complete_sync declined a completion dispatched under an attempt epoch older than the instance's, or journaled before a re-register, by returning None, and the async record_step_complete swallowed every error. A dispatcher still on an old epoch therefore lost every step's writes without a word, and its dependents ran on a context without them. Both refusals now raise SupersededAttemptError (logged as a warning), which record_step_complete lets through while still only logging a store error. Task.run's own dispatch is unaffected: it takes its epoch from its registration, and a drained straggler's late write lands in a cancelled future. A run a re-register superseded now stops at its first refused write instead of running on with every write dropped. register_task_instance documents the epoch contract for callers that dispatch steps themselves. The loud error also exposed a journal test whose step was recorded under a stale epoch, so it passed without the step ever landing; it now records under the new run's epoch. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
1 parent bc3db30 commit bea62bb

5 files changed

Lines changed: 98 additions & 14 deletions

File tree

‎src/agent_env/task/__init__.py‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,8 @@
55
from .store import (
66
TaskStore, TaskQuery, get_task_store, set_task_store, reset_task_store,
77
TaskInstance, TaskInstanceStore, get_task_instance_store, set_task_instance_store, reset_task_instance_store,
8-
TaskStepResult, TaskStepStatus, record_step_complete, record_task_cancelled, record_task_failure,
8+
TaskStepResult, TaskStepStatus, SupersededAttemptError, record_step_complete, record_task_cancelled,
9+
record_task_failure,
910
)
1011

1112
__all__ = [
@@ -23,6 +24,7 @@
2324
"TaskInstanceStore",
2425
"TaskStepResult",
2526
"TaskStepStatus",
27+
"SupersededAttemptError",
2628
"get_task_instance_store",
2729
"set_task_instance_store",
2830
"reset_task_instance_store",

‎src/agent_env/task/store.py‎

Lines changed: 31 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -222,6 +222,16 @@ def to_dict(self) -> dict:
222222
return dataclasses.asdict(self)
223223

224224

225+
class SupersededAttemptError(RuntimeError):
226+
"""A step's completion was refused because a later attempt owns the instance (a rollback or a re-register moved
227+
it on), so nothing the step produced was recorded and its caller must not carry on as if it had been."""
228+
229+
def __init__(self, instance_id: str, step_id: str, reason: str):
230+
super().__init__(f"step {step_id!r} of instance {instance_id!r} was not recorded: {reason}")
231+
self.instance_id = instance_id
232+
self.step_id = step_id
233+
234+
225235
def _fresh_run_state(start_step: int, completed_step_docs: list[dict]) -> dict:
226236
"""The fields a run owns. A re-register resets exactly these, so both registration paths
227237
have to agree on them; ``rev`` and the generation are bumped there instead and live in
@@ -656,6 +666,9 @@ def record_step_complete_sync(
656666
in-flight ``to_thread`` call, so this fence, not the cancel, stops the drained
657667
step's write.
658668
669+
Either refusal raises ``SupersededAttemptError``: the step's results were not recorded,
670+
and a caller that went on would hand its dependents a context without them.
671+
659672
Replaces the old aggregation-pipeline update: the dedupe and the
660673
``$size``/``$cond`` derivations run in Python, so any backend can implement it
661674
with a plain conditional update.
@@ -673,16 +686,17 @@ def record_step_complete_sync(
673686
)
674687
journaled = None
675688
seq, journaled_generation = journaled if journaled is not None else (None, None)
689+
declined: list[str] = [] # why the deciding _mutate refused, if it did
676690

677691
def _mutate(doc: dict) -> UpdateSpec | None:
692+
declined.clear()
678693
if journaled_generation is not None and doc.get(_GENERATION, 0) != journaled_generation:
679-
logger.warning(
680-
"Declining completion of step %s for instance_id=%s: the run was "
681-
"re-registered (generation %s -> %s) after the step journaled",
682-
step_id, instance_id, journaled_generation, doc.get(_GENERATION, 0),
683-
)
694+
declined.append(f"the run was re-registered (generation {journaled_generation} -> "
695+
f"{doc.get(_GENERATION, 0)}) after the step journaled")
684696
return None
685697
if doc.get("attempt_epoch", 0) > attempt_epoch:
698+
declined.append(f"it was dispatched under attempt epoch {attempt_epoch}, but a later attempt owns the "
699+
f"instance at epoch {doc.get('attempt_epoch', 0)}")
686700
return None
687701
# Position is the replay order, so a re-record moves to the end, items included.
688702
rerecorded = any(c.get("step_id") == step_id for c in doc.get("completed_steps", []))
@@ -717,6 +731,10 @@ def _mutate(doc: dict) -> UpdateSpec | None:
717731
TASK_STEP_JOURNAL_COLLECTION,
718732
Filter.of(instance_id=instance_id, step_id=step_id, seq=seq),
719733
)
734+
if result is None and declined:
735+
error = SupersededAttemptError(instance_id, step_id, declined[0])
736+
logger.warning("%s", error)
737+
raise error
720738

721739
def record_task_failure_sync(
722740
self,
@@ -832,6 +850,9 @@ def register_task_instance(
832850
833851
With ``instance_id``: idempotent upsert, and a failure raises, since the caller already handed that id out.
834852
Without: random-id insert, and a failure is logged and the run goes unrecorded.
853+
854+
Re-registering an existing instance advances its ``attempt_epoch``. A caller that dispatches the run's steps itself
855+
must record them under the returned instance's ``attempt_epoch``; an older one raises ``SupersededAttemptError``.
835856
"""
836857
try:
837858
store = get_task_instance_store()
@@ -885,13 +906,18 @@ async def record_step_complete(
885906
contention). Concurrent finishers converge without losing each other's
886907
entries; ``completed_steps`` keeps first-appearance order. ``attempt_epoch``
887908
fences a write from a rolled-back attempt (see ``record_step_complete_sync``).
909+
910+
A store error is logged, not raised. A completion a later attempt fenced off raises
911+
``SupersededAttemptError``: retrying it cannot land, so a dispatcher should end the step.
888912
"""
889913
entry = dataclasses.asdict(TaskStepResult(step_id=step_id, status=status))
890914
try:
891915
await asyncio.to_thread(
892916
get_task_instance_store().record_step_complete_sync,
893917
instance_id, entry, ops, total_steps, completed_at_utc, attempt_epoch,
894918
)
919+
except SupersededAttemptError:
920+
raise
895921
except Exception:
896922
logger.error(
897923
"Failed to record step complete for instance_id=%s step_id=%s",

‎tst/integration/env/task_step/test_record_step_concurrency.py‎

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111
from agent_env.store.document_store import Filter
1212
from agent_env.task.store import (
1313
TASK_INSTANCES_COLLECTION,
14+
SupersededAttemptError,
1415
get_task_instance_store,
1516
record_step_complete,
1617
seed_task_instance_context,
@@ -129,6 +130,26 @@ async def write(step_id: str, key: str, value: dict) -> None:
129130
journal.assert_journal_replays(instance_id, expect_steps={"sA", "sB"}, seeded=False)
130131

131132

133+
@pytest.mark.integration
134+
@pytest.mark.asyncio
135+
async def test_a_completion_under_an_epoch_a_re_register_left_behind_raises():
136+
"""A re-register advances the instance's attempt epoch. A completion still dispatched under the old one raises and
137+
lands nothing on the configured store; one under the epoch the re-register returned lands."""
138+
store = get_task_instance_store()
139+
created = store.create_instance(task_id=f"concurrency-test-{uuid.uuid4().hex[:6]}", task_version=1, total_steps=2)
140+
reregistered = store.upsert_instance(created.instance_id, created.task_id, 1, 2)
141+
ops = build_context_update_ops(TaskStepContext(), TaskStepContext(metadata={"s0": "deployed"}))
142+
143+
with pytest.raises(SupersededAttemptError, match="dispatched under attempt epoch 0"):
144+
await record_step_complete(created.instance_id, "s0", ops, 2, "now")
145+
await record_step_complete(created.instance_id, "s0", ops, 2, "now", attempt_epoch=reregistered.attempt_epoch)
146+
147+
doc = store._doc_store.find_one(TASK_INSTANCES_COLLECTION, Filter.of(instance_id=created.instance_id))
148+
assert reregistered.attempt_epoch == 1
149+
assert [c["step_id"] for c in doc["completed_steps"]] == ["s0"]
150+
assert doc["context"]["metadata"]["s0"] == "deployed"
151+
152+
132153
@pytest.mark.integration
133154
@pytest.mark.asyncio
134155
async def test_journal_lifecycle():

‎tst/unit/task/step_journal_test.py‎

Lines changed: 7 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,7 @@
1414
from agent_env.store import Filter, LocalSqliteDocumentStore, Sort
1515
from agent_env.task.step_journal import _union, commit_ordered, replay_context
1616
from agent_env.task.store import (
17-
TASK_STEP_JOURNAL_COLLECTION, TaskInstanceStore, TaskStepResult, TaskStepStatus,
17+
TASK_STEP_JOURNAL_COLLECTION, SupersededAttemptError, TaskInstanceStore, TaskStepResult, TaskStepStatus,
1818
seed_task_instance_context, set_task_instance_store,
1919
undo_steps,
2020
)
@@ -50,8 +50,8 @@ def _ops(pre_md, post_md, **scalars):
5050
TaskStepContext(metadata=dict(post_md), **scalars))
5151

5252

53-
def _record(store, iid, step_id, ops, total=9, status="success"):
54-
store.record_step_complete_sync(iid, {"step_id": step_id, "status": status}, ops, total, "now")
53+
def _record(store, iid, step_id, ops, total=9, status="success", epoch=0):
54+
store.record_step_complete_sync(iid, {"step_id": step_id, "status": status}, ops, total, "now", epoch)
5555

5656

5757
def _journal(store, iid):
@@ -480,7 +480,8 @@ def test_a_retired_entry_is_never_replayed_into_the_new_run(store):
480480
with pytest.raises(ValueError, match="no journal seed"):
481481
store.undo_steps_sync("i", {"s0"}) # the retired seed is not a base
482482
seed_task_instance_context("i", TaskStepContext(metadata={"new": True}))
483-
_record(store, "i", "s0", _ops({"new": True}, {"new": True, "a": 1}))
483+
_record(store, "i", "s0", _ops({"new": True}, {"new": True, "a": 1}), epoch=1) # under the new run's epoch
484+
assert _doc(store, "i")["context"]["metadata"] == {"new": True, "a": 1} # so s0 really landed
484485
after = store.undo_steps_sync("i", {"s0"})
485486
assert after["context"]["metadata"] == {"new": True} # the new run's seed, not {"old": True}
486487

@@ -511,7 +512,8 @@ def journal_then_reregister(docs, instance_id, step_id, ops, status, **kw):
511512
store.upsert_instance(instance_id="i", task_id="t", task_version=1, total_steps=3)
512513
return out
513514
monkeypatch.setattr(store, "_journal_step", journal_then_reregister)
514-
_record(store, "i", "s0", _ops({"base": 1}, {"base": 1, "a": 1}), total=3) # must be declined
515+
with pytest.raises(SupersededAttemptError, match="re-registered"): # declined, out loud
516+
_record(store, "i", "s0", _ops({"base": 1}, {"base": 1, "a": 1}), total=3)
515517

516518
d = _doc(store, "i")
517519
assert d["completed_steps"] == [] # the superseded run's step did not land

‎tst/unit/task_step/retry_test.py‎

Lines changed: 36 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,7 @@
3030
from agent_env.task.store import (
3131
TASK_INSTANCES_COLLECTION,
3232
TASK_STEP_JOURNAL_COLLECTION,
33+
SupersededAttemptError,
3334
TaskInstanceStore,
3435
set_task_instance_store,
3536
)
@@ -860,7 +861,8 @@ def test_stale_epoch_write_is_fenced_and_leaves_no_journal_hole(store):
860861
assert doc["attempt_epoch"] == 1 and "s1" not in doc["context"]["metadata"]
861862

862863
_record(store, iid, "s1", {"s0": 1}, {"s0": 1, "s1": "attempt2"}, epoch=1) # the re-run
863-
_record(store, iid, "s1", {"s0": 1}, {"s0": 1, "s1": "attempt1"}, epoch=0) # the zombie
864+
with pytest.raises(SupersededAttemptError, match="epoch 0"): # the zombie, refused out loud
865+
_record(store, iid, "s1", {"s0": 1}, {"s0": 1, "s1": "attempt1"}, epoch=0)
864866

865867
d = _doc(store, iid)
866868
assert d["context"]["metadata"]["s1"] == "attempt2" # fenced
@@ -885,7 +887,8 @@ def test_a_writer_that_passed_the_fence_before_the_undo_cannot_displace_the_reru
885887

886888
real_bump = store._bump_journal_seq
887889
monkeypatch.setattr(store, "_bump_journal_seq", lambda _s, _iid: dict(stale_view)) # resumes on its stale read
888-
_record(store, iid, "s1", {"s0": 1}, {"s0": 1, "s1": "attempt1"}, epoch=0)
890+
with pytest.raises(SupersededAttemptError):
891+
_record(store, iid, "s1", {"s0": 1}, {"s0": 1, "s1": "attempt1"}, epoch=0)
889892
monkeypatch.setattr(store, "_bump_journal_seq", real_bump)
890893

891894
d = _doc(store, iid)
@@ -929,6 +932,36 @@ def test_current_epoch_write_lands_after_an_undo(store):
929932
assert d["context"]["metadata"] == {"s0": 2} and d["attempt_epoch"] == 1
930933

931934

935+
def test_a_dispatcher_still_on_the_old_epoch_after_a_re_register_is_told_its_write_did_not_land(store):
936+
# A caller that pre-creates the instance and then re-registers it moves it to epoch 1. A step it
937+
# still records under epoch 0 used to vanish, so dependents ran on a context without it.
938+
iid = _seeded(store)
939+
store.upsert_instance(iid, "t", 1, total_steps=3)
940+
store.seed_context(iid, build_context_update_ops(None, TaskStepContext()))
941+
with pytest.raises(SupersededAttemptError, match="dispatched under attempt epoch 0"):
942+
_record(store, iid, "s0", {}, {"s0": "deployed"}, epoch=0)
943+
assert _doc(store, iid)["completed_steps"] == []
944+
_record(store, iid, "s0", {}, {"s0": "deployed"}, epoch=_doc(store, iid)["attempt_epoch"])
945+
d = _doc(store, iid)
946+
assert d["context"]["metadata"] == {"s0": "deployed"} and [c["step_id"] for c in d["completed_steps"]] == ["s0"]
947+
948+
949+
@pytest.mark.asyncio
950+
async def test_record_step_complete_raises_a_fenced_write_and_still_only_logs_a_store_error(store, monkeypatch, caplog):
951+
iid = _seeded(store)
952+
store.upsert_instance(iid, "t", 1, total_steps=3)
953+
with pytest.raises(SupersededAttemptError):
954+
await store_mod.record_step_complete(iid, "s0", _ops({}, {"s0": 1}), 3, "now", attempt_epoch=0)
955+
956+
def store_down(*_args, **_kwargs):
957+
raise RuntimeError("store down")
958+
959+
monkeypatch.setattr(store, "record_step_complete_sync", store_down)
960+
with caplog.at_level(logging.ERROR):
961+
await store_mod.record_step_complete(iid, "s0", _ops({}, {"s0": 1}), 3, "now", attempt_epoch=1)
962+
assert "Failed to record step complete" in caplog.text
963+
964+
932965
class _Gated:
933966
type = "gated"
934967

@@ -953,7 +986,7 @@ async def test_an_attempt_a_re_register_superseded_writes_nothing_to_the_run(sto
953986
await asyncio.sleep(0)
954987
store.upsert_instance("i", "t", 1, 2)
955988
gate.set()
956-
with pytest.raises(RuntimeError, match="superseded boom"):
989+
with pytest.raises(SupersededAttemptError, match="'s0'"): # stops at its first refused write; s1 never runs
957990
await superseded
958991
d = _doc(store, "i")
959992
assert (d["status"], d["completed_steps"], d["context"]["metadata"]) == ("running", [], {})

0 commit comments

Comments
 (0)