diff --git a/emrg/server/daemon.py b/emrg/server/daemon.py index 5ca7b3e2..75ad50a2 100644 --- a/emrg/server/daemon.py +++ b/emrg/server/daemon.py @@ -8055,25 +8055,52 @@ async def _run_boss_tool( done, _ = await asyncio.wait({child_task}, timeout=timeout_s) except asyncio.CancelledError: # The executor's own round was cancelled. The owner is not left running - # behind it. + # behind it — and, like the timeout below, this call delivered nothing, + # so it must not consume the window (issue #2499): the same session's + # next round would otherwise be refused for four hours by a call that + # never put a question to anyone. child_task.cancel() await asyncio.gather(child_task, return_exceptions=True) + self._unconsume_the_window(state) raise if done: return child_task.result() child_task.cancel() await asyncio.gather(child_task, return_exceptions=True) + self._unconsume_the_window(state) logger.warning( "[boss] timed out after %ss: parent=%s child=%s", timeout_s, parent_session_id, state["child"], ) return {"error": ( f"boss: the owner did not answer within {timeout_s}s, so its turn was " - "cancelled. Nothing from it was delivered. Owner session: " - f"{state['child']}. Raise `timeout_s` if the owner needs longer to read " - "this session's history." + "cancelled. Nothing from it was delivered, and this call did not " + "consume the re-ask window, so retrying starts a turn. Raise " + "`timeout_s` if the owner needs longer to read this session's history. " + f"Owner session: {state['child']}." )} + @staticmethod + def _unconsume_the_window(state: dict) -> None: + """Put the owner clock back where this call found it (issue #2499). + + A call that delivered nothing must not consume the four-hour window. The + window exists because *a direction that was just given stands*; a call + cancelled by `timeout_s`, or with its own round, gave no direction, so a + stamp left standing refuses the retry the timeout error asks for and makes + that error's only remedy impossible to carry out. + + The stamp still goes down *before* the turn runs, and that is deliberate — + a turn that raised keeps it, because it ran and re-buying it is the cost + the window exists to prevent. So this restores rather than withholds: the + two outcomes are told apart here, one frame up, and not by moving the stamp. + """ + owner = state.get("owner") + if owner is None: + # Cancelled before the call got as far as stamping anything. + return + owner.set_boss_asked_at(state.get("asked_at_before")) + async def _run_boss_child( self, *, parent_session_id: str, parent_cwd: str, intent: str, state: dict, parent_tools: list[str] | None = None, @@ -8134,6 +8161,13 @@ async def _run_boss_child( # Stamped before the turn runs, never after it: a turn that dies mid-way # must still leave the clock written, or the next call pays for the same # judgement again with nothing to show for the first. + # + # Both halves are handed to the caller as well, because the two ways a + # call can end without answering are decided one frame up: `_run_boss_tool` + # holds the bound, and it is the only place that knows a turn was taken + # away rather than finished. Nothing here distinguishes them. + state["owner"] = child + state["asked_at_before"] = last_asked child.set_boss_asked_at(asked_at) prompt = _get_jinja_env().get_template("boss.j2").render( diff --git a/emrg/session.py b/emrg/session.py index afa66bc3..f34da7cd 100644 --- a/emrg/session.py +++ b/emrg/session.py @@ -621,17 +621,26 @@ def boss_asked_at(self) -> float | None: """ return self._boss_asked_at - def set_boss_asked_at(self, when: float) -> None: + def set_boss_asked_at(self, when: float | None) -> None: """Persist the instant this session was last asked, into ``meta.json``. The only writer of the key, and it is called *before* the owner's turn runs rather than after it: a stamp written on completion leaves a turn that died looking like one that never happened, and the next call would then pay for the same judgement a second time. + + ``None`` clears it, and the key leaves ``meta.json`` with it — the state a + session that was never asked is in. That is how a call which delivered + nothing gives the window back (issue #2499): the clock exists to make a + direction that *was* given stand, and a call that was cancelled gave none. """ - self._boss_asked_at = float(when) + self._boss_asked_at = None if when is None else float(when) self._save_meta() - logger.info("session owner clock set: %s -> %.0f", self.session_id, self._boss_asked_at) + logger.info( + "session owner clock set: %s -> %s", + self.session_id, + "never" if self._boss_asked_at is None else f"{self._boss_asked_at:.0f}", + ) # ── Sandbox tier ────────────────────────────────────────── diff --git a/tests/test_boss_tool.py b/tests/test_boss_tool.py index dceea8f6..6fd7923f 100644 --- a/tests/test_boss_tool.py +++ b/tests/test_boss_tool.py @@ -598,3 +598,117 @@ def test_the_clock_is_written_by_its_own_setter(tmp_path): "the setter did not write the clock: on disk is where a restart reads it" ) assert session.boss_asked_at == 1761000000.0 + + +# ── a call that delivered nothing does not consume the window (issue #2499) ── +# +# The clock is stamped before the turn runs, so a turn that *died* keeps it — that +# guarantee is what `test_a_turn_that_died_still_leaves_the_clock` pins. The two +# branches below are the other case: the turn was taken away before it could +# answer, and a stamp left standing refuses the very retry the timeout error asks +# for. "Delivered nothing" and "died mid-way" are different outcomes, so they are +# told apart rather than the stamp moved wholesale to after the turn. + + +def _ask_with_timeout( + server: EmrgServer, tmp_path, timeout_s: int = 30, session_id: str = "task-1", +) -> dict: + """One whole `boss` call, bound included — the layer the timeout lives in.""" + return asyncio.run(server._run_boss_tool( + parent_session_id=session_id, parent_cwd=str(tmp_path), + timeout_s=timeout_s, intent="ask", parent_tools=["read"], + )) + + +def test_a_call_that_timed_out_does_not_consume_the_window(tmp_path, monkeypatch): + """Issue #2499: the retry a timeout error asks for must start a turn. + + Nothing was decided by a call that was cancelled, so there is no stance for + the window to protect — and the busy notice that a standing stamp would + produce tells the round to carry on as if one had been given. + """ + server = _server(tmp_path, monkeypatch) + + async def never_answers(req, ws, session, cancel_event, **kwargs): + await asyncio.sleep(3600) + + server._run_tool_loop_locked = never_answers + + timed_out = _ask_with_timeout(server, tmp_path, timeout_s=1) + assert timed_out.get("error"), ( + f"a call that never answered came back as a result: {timed_out}" + ) + assert "did not answer within" in timed_out["error"] + + seen = _stub_the_loop(server) + retry = _ask_with_timeout(server, tmp_path) + + assert len(seen) == 1, ( + "the retry after a timeout started no owner turn: the cancelled call " + "consumed the four-hour window, so `Raise timeout_s` — the only remedy the " + "error offers — cannot be carried out" + ) + assert BUSY_MARKER not in retry.get("text", ""), ( + "the retry was answered with the busy notice instead of a stance" + ) + + +def test_a_call_cancelled_with_its_round_does_not_consume_the_window( + tmp_path, monkeypatch, +): + """The round that asked was cancelled: same outcome, nothing delivered.""" + server = _server(tmp_path, monkeypatch) + started = asyncio.Event() + + async def never_answers(req, ws, session, cancel_event, **kwargs): + started.set() + await asyncio.sleep(3600) + + server._run_tool_loop_locked = never_answers + + async def scenario(): + task = asyncio.create_task(server._run_boss_tool( + parent_session_id="task-1", parent_cwd=str(tmp_path), + timeout_s=600, intent="ask", parent_tools=["read"], + )) + await asyncio.wait_for(started.wait(), timeout=5) + task.cancel() + with pytest.raises(asyncio.CancelledError): + await task + + asyncio.run(scenario()) + + owner = server._get_or_create_session("boss-task-1", _boss_cwd(tmp_path)) + assert owner.boss_asked_at is None, ( + "a call whose round was cancelled wrote the clock, so the same session's " + "next round is refused for four hours by a call that delivered nothing" + ) + meta_path = _boss_cwd(tmp_path).parent.parent / "meta.json" + meta = json.loads(meta_path.read_text(encoding="utf-8")) + assert "boss_asked_at" not in meta, ( + "the clock is still on disk, and on disk is what a restart reads" + ) + + +def test_a_call_that_answered_still_consumes_the_window(tmp_path, monkeypatch): + """The control: the window's own feature must survive the fix. + + Without this arm the timeout fix could be made by stamping only on delivery, + or by deleting the stamp — both of which would delete issue #2495's feature + and leave every test above green. + """ + server = _server(tmp_path, monkeypatch) + _stub_the_loop(server) + + answered = _ask_with_timeout(server, tmp_path) + assert not answered.get("error"), answered + assert "The owner answered" in answered["text"], answered["text"][:120] + + seen = _stub_the_loop(server) + second = _ask_with_timeout(server, tmp_path) + + assert seen == [], ( + "an owner that answered did not consume the window, so the second call " + "paid for the same judgement again" + ) + assert second["text"].startswith(BUSY_MARKER), second["text"][:80]