ReviewGate: a previous round's pass timer escalates the current round, because attempt resets to 0 each round and timers are never cancelled

apps/arbiter/lib/arbiter/worker/review_gate.ex

@@ -1225,18 +1225,26 @@ defmodule Arbiter.Worker.ReviewGate do
   # A stale exit from an worker we've moved on from.
   def handle_info({:worker_exited, _other, _status}, state), do: {:noreply, state}
 
-  # Timeouts are tagged with the attempt that scheduled them so a stale timer
-  # from a prior pass can't escalate a pass that has already advanced.
-  def handle_info({:timeout, _attempt}, %{reported?: true} = state), do: {:noreply, state}
+  # Timeouts are tagged with the {round, attempt} pair that scheduled them so
+  # a stale timer from a prior pass can't escalate a pass that has already
+  # advanced. `attempt` alone is not enough (bd-28u8v4): it resets to 0 at the
+  # start of every round (bd-bgeo6i, so reprompt budgets start fresh), so
+  # round N's implementer and round N+1's implementer are both launched as the
+  # same attempt number and a timer armed for the former would otherwise be
+  # accepted as belonging to the latter. `round` never repeats within a gate's
+  # lifetime, so the pair is unique for as long as the gate runs.
+  def handle_info({:timeout, _round, _attempt}, %{reported?: true} = state),
+    do: {:noreply, state}
 
   # A reviewing pass hit the ceiling. Before escalating as timed-out, retry the
   # pass once with a fresh reviewer mind (bd-78vg4v): a hung / overloaded session
   # is usually transient API variance, not a code problem, and a clean second
   # attempt converges where the first stalled. Only the reviewing phase is
   # retried — a revising (implementer) pass still escalates on timeout below.
   def handle_info(
-        {:timeout, attempt},
-        %{attempt: attempt, phase: :reviewing, timeout_retries_left: budget} = state
+        {:timeout, round, attempt},
+        %{round: round, attempt: attempt, phase: :reviewing, timeout_retries_left: budget} =
+          state
       )
       when budget > 0 and is_binary(state.current_prompt) do
     Logger.warning(
@@ -1266,15 +1274,15 @@ defmodule Arbiter.Worker.ReviewGate do
     end
   end
 
-  def handle_info({:timeout, attempt}, %{attempt: attempt} = state) do
+  def handle_info({:timeout, round, attempt}, %{round: round, attempt: attempt} = state) do
     Logger.warning(
       "ReviewGate: #{state.phase} pass timed out for task=#{state.task_id} (round #{state.round})"
     )
 
     escalate_timeout(state)
   end
 
-  def handle_info({:timeout, _stale}, state), do: {:noreply, state}
+  def handle_info({:timeout, _stale_round, _stale_attempt}, state), do: {:noreply, state}
 
   # Author died before we could report — nothing to do.
   def handle_info({:DOWN, _ref, :process, pid, _reason}, %{author: pid} = state) do
@@ -3878,7 +3886,7 @@ defmodule Arbiter.Worker.ReviewGate do
 
     case spawn_worker(state, id, role, prompt, command) do
       {:ok, pid} ->
-        Process.send_after(self(), {:timeout, attempt}, timeout_ms)
+        Process.send_after(self(), {:timeout, state.round, attempt}, timeout_ms)
 
         {:ok,
          %{

apps/arbiter/test/arbiter/worker/review_gate_test.exs

@@ -57,6 +57,12 @@ defmodule Arbiter.Worker.ReviewGateTest do
                                      __DIR__
                                    )
   @timeout_retry Path.expand("../../fixtures/review_timeout_retry.sh", __DIR__)
+  @reject_twice Path.expand("../../fixtures/review_reject_twice.sh", __DIR__)
+  @revise_slow_then_fast Path.expand("../../fixtures/revise_slow_then_fast.sh", __DIR__)
+  @reject_slow_then_approve_fast Path.expand(
+                                   "../../fixtures/review_reject_slow_then_approve_fast.sh",
+                                   __DIR__
+                                 )
   @hang Path.expand("../../fixtures/review_hang.sh", __DIR__)
   @auth_expired Path.expand("../../fixtures/review_auth_expired.sh", __DIR__)
   @quota_exhausted Path.expand("../../fixtures/review_quota_exhausted.sh", __DIR__)
@@ -3576,6 +3582,158 @@ defmodule Arbiter.Worker.ReviewGateTest do
       assert [%{round: 1, verdict: nil}] = impl_rounds
     end
 
+    # bd-28u8v4: `attempt` resets to 0 at the start of every round (bd-bgeo6i),
+    # so round 1's implementer and round 2's implementer are both launched as
+    # `attempt` 2 within their own round. The timer armed for round 1's
+    # implementer must not be able to escalate round 2's implementer just
+    # because the attempt numbers collide.
+    #
+    # Round 1's implementer (`revise_slow_then_fast.sh`) sleeps for most of the
+    # per-pass timeout before committing — long enough that its stale timer
+    # fires only AFTER round 2's implementer has already launched. Round 2's
+    # implementer then keeps running well past that stale-timer instant, but
+    # still comfortably within its own fresh timeout. With the bug, the stale
+    # round-1 timer escalates round 2's revising pass as timed-out; fixed, the
+    # gate ignores it and round 2's implementer is allowed its own full
+    # budget, converging normally when round 3 approves.
+    test "a round-1 implementer's timer does not escalate a round-2 implementer at the same attempt",
+         %{repo: repo, ws: ws} do
+      task = new_task(ws)
+      branch = "feature/rev"
+      :ok = seed_feature_branch(repo, branch)
+
+      {:ok, pid} =
+        Worker.start(
+          task_id: task.id,
+          repo: "trib/repo",
+          workspace_id: ws.id,
+          meta: %{
+            branch: branch,
+            repo_path: repo,
+            target_branch: "main",
+            merge_title: "Merge #{task.id}",
+            review_required: true,
+            review_rounds: 3,
+            worktree_path: repo,
+            review_command: [@reject_twice],
+            # pass 1 (round-1 implementer) sleeps 1.9s; pass 2 (round-2
+            # implementer) sleeps 1.0s — both well under the 2.5s per-pass
+            # timeout on their own, but round 1's stale timer (armed at
+            # implementer-1-start + 2.5s) lands mid-flight through round 2's
+            # implementer run.
+            revise_command: [@revise_slow_then_fast, "19", "10"],
+            review_timeout_ms: 2_500
+          }
+        )
+
+      on_exit(fn -> if Process.alive?(pid), do: GenServer.stop(pid, :normal) end)
+      :ok = Worker.advance(pid, :claude)
+      send(pid, {:__claude_session_done__, "arb done"})
+
+      # Round 1 rejects → slow implementer revises → round 2 rejects → second
+      # implementer revises (surviving the stale round-1 timer) → round 3
+      # approves → merge. No timeout escalation anywhere in between.
+      wait_until(fn -> match?(%{status: :completed}, Worker.state(pid)) end, 12_000)
+      assert merge_commit_count(repo) == 1
+      refute Worker.state(pid).meta[:failure_reason]
+
+      review_id = ReviewGate.reviewer_task_id(task.id)
+      runs = Ash.read!(Arbiter.Workers.Run)
+
+      assert Enum.any?(runs, &(&1.task_id == review_id <> "#impl1")),
+             "expected a distinct implementer run row for round 1"
+
+      assert Enum.any?(runs, &(&1.task_id == review_id <> "#impl2")),
+             "expected a distinct implementer run row for round 2 — it must not have been " <>
+               "killed by round 1's stale timer"
+
+      require Ash.Query
+
+      rounds =
+        Arbiter.ReviewGate.Round
+        |> Ash.Query.filter(task_id == ^task.id)
+        |> Ash.Query.sort(round: :asc, inserted_at: :asc)
+        |> Ash.read!()
+
+      # No round anywhere recorded a timed-out verdict — the only source of
+      # `:timed_out` in this gate's vocabulary is the very bug under test.
+      refute Enum.any?(rounds, &(&1.verdict == :timed_out))
+    end
+
+    # bd-28u8v4: the reviewer-side sibling of the collision above. Round 1's
+    # reviewer (`attempt` 1) sleeps close to the per-pass timeout before
+    # REQUEST_CHANGES; the implementer commits immediately; round 2's
+    # reviewer is launched as `attempt` 1 again (bd-bgeo6i resets `attempt`
+    # per round) and is still running when round 1's reviewer timer fires.
+    # With the bug, that stale timer's `{:timeout, attempt}` matches round
+    # 2's reviewer and either retries or escalates it as timed-out; fixed,
+    # the gate ignores it because the timer is tagged with round 1, not
+    # round 2, and round 2's reviewer is left to approve normally.
+    test "a round-1 reviewer's timer does not time out a round-2 reviewer at the same attempt",
+         %{repo: repo, ws: ws} do
+      task = new_task(ws)
+      branch = "feature/rev"
+      :ok = seed_feature_branch(repo, branch)
+
+      {:ok, pid} =
+        Worker.start(
+          task_id: task.id,
+          repo: "trib/repo",
+          workspace_id: ws.id,
+          meta: %{
+            branch: branch,
+            repo_path: repo,
+            target_branch: "main",
+            merge_title: "Merge #{task.id}",
+            review_required: true,
+            review_rounds: 2,
+            worktree_path: repo,
+            # pass 1 (round-1 reviewer) sleeps 1.9s and rejects; every later
+            # pass (round-2 reviewer) sleeps 1.0s and approves — both well
+            # under the 2.5s per-pass timeout on their own, but round 1's
+            # stale timer (armed at reviewer-1-start + 2.5s) lands mid-flight
+            # through round 2's reviewer run.
+            review_command: [@reject_slow_then_approve_fast, "19", "10"],
+            revise_command: [@revise_commit],
+            review_timeout_ms: 2_500
+          }
+        )
+
+      on_exit(fn -> if Process.alive?(pid), do: GenServer.stop(pid, :normal) end)
+      :ok = Worker.advance(pid, :claude)
+      send(pid, {:__claude_session_done__, "arb done"})
+
+      # Round 1 rejects (slowly) → implementer revises (fast) → round 2
+      # approves (surviving the stale round-1 reviewer timer) → merge. No
+      # timeout escalation or spurious timeout-retry run anywhere in between.
+      wait_until(fn -> match?(%{status: :completed}, Worker.state(pid)) end, 12_000)
+      assert merge_commit_count(repo) == 1
+      refute Worker.state(pid).meta[:failure_reason]
+
+      review_id = ReviewGate.reviewer_task_id(task.id)
+      runs = Ash.read!(Arbiter.Workers.Run)
+
+      assert Enum.any?(runs, &(&1.task_id == review_id <> "#r2")),
+             "expected a distinct round-2 reviewer run row — it must not have been " <>
+               "killed by round 1's stale timer"
+
+      refute Enum.any?(runs, &String.contains?(&1.task_id, "#r2#t")),
+             "round 1's stale timer must not have triggered a spurious round-2 " <>
+               "reviewer timeout-retry run"
+
+      require Ash.Query
+
+      rounds =
+        Arbiter.ReviewGate.Round
+        |> Ash.Query.filter(task_id == ^task.id)
+        |> Ash.Query.sort(round: :asc, inserted_at: :asc)
+        |> Ash.read!()
+
+      # No round anywhere recorded a timed-out verdict — the only source of
+      # `:timed_out` in this gate's vocabulary is the very bug under test.
+      refute Enum.any?(rounds, &(&1.verdict == :timed_out))
+    end
+
     # bd-78vg4v: a large implementer transcript is CAPPED (head+tail) when
     # recorded into the durable thread, so the round-2 re-review prompt stays
     # bounded instead of ballooning past round-1's. The @revise_huge fixture

apps/arbiter/test/fixtures/review_reject_slow_then_approve_fast.sh

@@ -0,0 +1,51 @@
+#!/bin/sh
+# Fixture: a reviewer (ReviewGate) worker for bd-28u8v4 — the round-1
+# REVIEWER pass-timer collision (the sibling of `revise_slow_then_fast.sh` /
+# `review_reject_twice.sh`, which cover the IMPLEMENTER side). Pass 1
+# (round-1 reviewer, `attempt` 1) sleeps close to the per-pass timeout before
+# REQUEST_CHANGES; every later pass (round-2+ reviewer, `attempt` 1 again —
+# `dispatch_next_review/2` resets `attempt` per round) sleeps briefly before
+# APPROVE. Paired with an implementer that commits immediately, this drives a
+# round-1 reviewer timer to fire WHILE the round-2 reviewer — at the same
+# `attempt` number — is still mid-flight, without ever depending on the
+# implementer pass to absorb the collision.
+#
+# `$1` is the sleep duration in tenths of a second for the FIRST (round-1)
+# pass; `$2` is the sleep duration in tenths of a second for every LATER
+# pass (default 0). A counter (kept in `.git`, so it never shows up in `git
+# status --porcelain`) tells the passes apart.
+sleep_tenths_1="${1:-19}"
+sleep_tenths_later="${2:-0}"
+git_dir="$(git rev-parse --git-dir)"
+counter_file="$git_dir/review_reject_slow_then_approve_fast_pass"
+pass=0
+[ -f "$counter_file" ] && pass="$(cat "$counter_file")"
+pass=$((pass + 1))
+echo "$pass" > "$counter_file"
+
+if [ "$pass" -eq 1 ]; then
+  sleep_tenths="$sleep_tenths_1"
+else
+  sleep_tenths="$sleep_tenths_later"
+fi
+
+if [ "$sleep_tenths" -gt 0 ]; then
+  whole=$((sleep_tenths / 10))
+  tenth=$((sleep_tenths % 10))
+  sleep "${whole}.${tenth}"
+fi
+
+if [ "$pass" -eq 1 ]; then
+  echo "reviewing pass $pass: rejecting"
+  echo "VERDICT: REQUEST_CHANGES"
+  echo "findings: [high] guard.txt:1 needs another pass"
+  echo "arb done"
+else
+  echo "reviewing pass $pass: approving"
+  echo "VERDICT: APPROVE"
+  echo "DISPOSITIONS:"
+  echo "- [ADDRESSED] F1.1 — anchored in guard.txt:1 on the round-1 revise"
+  echo "findings: none"
+  echo "arb done"
+fi
+exit 0

apps/arbiter/test/fixtures/review_reject_twice.sh

@@ -0,0 +1,32 @@
+#!/bin/sh
+# Fixture: a reviewer (ReviewGate) worker for bd-28u8v4 — the round-1 pass
+# timer collision. REQUEST_CHANGES on its first TWO passes (round 1 and round
+# 2), then APPROVE on every later pass. Paired with
+# `revise_slow_then_fast.sh` (the implementer) to drive a gate through TWO
+# revise rounds, so a round-1 implementer's stale timeout timer has a round-2
+# implementer pass — at the same `attempt` number — to collide with.
+#
+# A counter (kept in `.git`, so it never shows up in `git status
+# --porcelain`) tracks how many reviewing passes have run.
+git_dir="$(git rev-parse --git-dir)"
+counter_file="$git_dir/review_reject_twice_pass"
+pass=0
+[ -f "$counter_file" ] && pass="$(cat "$counter_file")"
+pass=$((pass + 1))
+echo "$pass" > "$counter_file"
+
+if [ "$pass" -le 2 ]; then
+  echo "reviewing pass $pass: rejecting"
+  echo "VERDICT: REQUEST_CHANGES"
+  echo "findings: [high] guard.txt:1 needs another pass"
+  echo "arb done"
+else
+  echo "reviewing pass $pass: approving"
+  echo "VERDICT: APPROVE"
+  echo "DISPOSITIONS:"
+  echo "- [ADDRESSED] F1.1 — anchored in guard.txt:1 on the round-1 revise"
+  echo "- [ADDRESSED] F2.1 — anchored in guard.txt:1 on the round-2 revise"
+  echo "findings: none"
+  echo "arb done"
+fi
+exit 0

apps/arbiter/test/fixtures/revise_slow_then_fast.sh

@@ -0,0 +1,47 @@
+#!/bin/sh
+# Fixture: an IMPLEMENTER worker for bd-28u8v4 — the round-1 pass timer
+# collision. The round-1 revise pass sleeps for most of the per-pass
+# `review_timeout_ms` budget (but still comfortably within it) before
+# committing; the round-2 revise pass commits immediately. Paired with
+# `review_reject_twice.sh` (the reviewer, which rejects rounds 1 and 2 then
+# approves), this reproduces the exact collision from bd-28u8v4: round 1's
+# implementer and round 2's implementer are both the SECOND pass launched in
+# their own round (`attempt` 2), so a timer armed for round 1's implementer
+# and never cancelled/disambiguated would fire while round 2's implementer is
+# still well within its own fresh budget.
+#
+# `$1` is the sleep duration in tenths of a second for the FIRST (round-1)
+# pass; `$2` is the sleep duration in tenths of a second for the SECOND
+# (round-2) pass (default 0). Every later pass commits immediately. A counter
+# (kept in `.git`) tells the passes apart.
+sleep_tenths_1="${1:-13}"
+sleep_tenths_2="${2:-0}"
+git_dir="$(git rev-parse --git-dir)"
+counter_file="$git_dir/revise_slow_then_fast_pass"
+pass=0
+[ -f "$counter_file" ] && pass="$(cat "$counter_file")"
+pass=$((pass + 1))
+echo "$pass" > "$counter_file"
+
+sleep_tenths=0
+if [ "$pass" -eq 1 ]; then
+  sleep_tenths="$sleep_tenths_1"
+elif [ "$pass" -eq 2 ]; then
+  sleep_tenths="$sleep_tenths_2"
+fi
+
+if [ "$sleep_tenths" -gt 0 ]; then
+  # sleep supports fractional seconds via a tenths-to-decimal conversion.
+  whole=$((sleep_tenths / 10))
+  tenth=$((sleep_tenths % 10))
+  sleep "${whole}.${tenth}"
+fi
+
+echo "implementer: addressing the reviewer's findings on this branch (pass $pass)"
+echo "anchored guard (pass $pass)" >> guard.txt
+git add guard.txt >/dev/null 2>&1
+git -c user.email=fixture@example.com -c user.name=Fixture \
+  commit -q -m "address reviewer finding F1.1 (pass $pass)" >/dev/null 2>&1
+echo "FIXED: anchored the match in guard.txt:1 (pass $pass)"
+echo "arb done"
+exit 0