diff --git a/docs/api-reference.md b/docs/api-reference.md index 7ddedbdc..533c6b9f 100644 --- a/docs/api-reference.md +++ b/docs/api-reference.md @@ -948,6 +948,7 @@ All fields are optional. The body can be empty or an empty JSON object. | `name` | string | Auto-generated workstream name | | `resumed` | bool | Whether a previous session was successfully resumed | | `message_count` | int | Number of messages in the resumed session (0 if fresh) | +| `initial_message_status` | string | Present ONLY when the workstream was created but its `initial_message` could not be delivered: `"queue_full"` (a raced live worker's interjection queue was at capacity — resend via `/send`; any uploads stay staged) or `"refused_closed"` (the workstream was closed mid-create). Absent whenever the message was dispatched. | **Error (limit reached):** diff --git a/sdk/typescript/openapi-console.json b/sdk/typescript/openapi-console.json index 4731bfd2..bd2b0895 100644 --- a/sdk/typescript/openapi-console.json +++ b/sdk/typescript/openapi-console.json @@ -2,7 +2,7 @@ "openapi": "3.1.0", "info": { "title": "turnstone Console API", - "version": "1.7.0a6", + "version": "1.7.0rc1", "description": "Cluster-wide visibility and control across all turnstone nodes." }, "paths": { @@ -6688,7 +6688,7 @@ "tags": [ "Coordinator" ], - "description": "Aggregates the persisted row, a best-effort live block from the owning node (or the in-process coordinator manager for ``kind=\"coordinator\"`` rows), and the tail of the message history. Gated on the ``admin.cluster.inspect`` permission (granted to ``builtin-admin`` via migration 040; revoke or reassign to a custom role for tighter control). ``live`` is null on node unreachability / 5xx so callers can degrade gracefully.", + "description": "Aggregates the persisted row, a best-effort live block from the owning node (or the in-process coordinator manager for ``kind=\"coordinator\"`` rows), and the tail of the message history. Gated on the ``admin.cluster.inspect`` permission (granted to ``builtin-admin`` via migration 040; revoke or reassign to a custom role for tighter control). A workstream attached to a *private* project stays confidential to its members: a permitted caller who isn't its owner / creator / project member gets a 404 (same masking as an unknown id). ``live`` is null on node unreachability / 5xx so callers can degrade gracefully.", "parameters": [ { "name": "ws_id", @@ -13361,7 +13361,7 @@ "type": "object" }, "PendingApprovalItem": { - "description": "One pending tool-call inside a ``PendingApprovalDetail`` envelope.\n\nMirrors the dict ``SessionUIBase.serialize_pending_approval_detail``\nemits per item. ``heuristic_verdict`` / ``judge_verdict`` are kept\nloosely-typed because the underlying verdict shape varies by tier;\nconsumers that want the full structure can decode against\n:class:`turnstone.sdk.events.IntentVerdictEvent`.", + "description": "One pending tool-call inside a ``PendingApprovalDetail`` envelope.\n\nMirrors the dict ``SessionUIBase.serialize_pending_approval_details``\nemits per item inside each cycle entry. ``heuristic_verdict`` / ``judge_verdict`` are kept\nloosely-typed because the underlying verdict shape varies by tier;\nconsumers that want the full structure can decode against\n:class:`turnstone.sdk.events.IntentVerdictEvent`.", "properties": { "call_id": { "default": "", diff --git a/sdk/typescript/openapi-server.json b/sdk/typescript/openapi-server.json index 2cb9eb63..03d7270d 100644 --- a/sdk/typescript/openapi-server.json +++ b/sdk/typescript/openapi-server.json @@ -2,7 +2,7 @@ "openapi": "3.1.0", "info": { "title": "turnstone Server API", - "version": "1.7.0a6", + "version": "1.7.0rc1", "description": "Single-node workstream management, chat interaction, and real-time streaming." }, "paths": { @@ -2564,6 +2564,19 @@ }, "title": "Attachment Ids", "type": "array" + }, + "initial_message_status": { + "anyOf": [ + { + "type": "string" + }, + { + "type": "null" + } + ], + "default": null, + "description": "Present ONLY when the workstream was created but its initial_message could not be delivered: 'queue_full' (a raced live worker's interjection queue was at capacity \u2014 resend via /send; any uploads stay staged) or 'refused_closed' (the workstream was closed mid-create). Absent whenever the message was dispatched.", + "title": "Initial Message Status" } }, "required": [ @@ -2747,7 +2760,7 @@ "type": "object" }, "PendingApprovalItem": { - "description": "One pending tool-call inside a ``PendingApprovalDetail`` envelope.\n\nMirrors the dict ``SessionUIBase.serialize_pending_approval_detail``\nemits per item. ``heuristic_verdict`` / ``judge_verdict`` are kept\nloosely-typed because the underlying verdict shape varies by tier;\nconsumers that want the full structure can decode against\n:class:`turnstone.sdk.events.IntentVerdictEvent`.", + "description": "One pending tool-call inside a ``PendingApprovalDetail`` envelope.\n\nMirrors the dict ``SessionUIBase.serialize_pending_approval_details``\nemits per item inside each cycle entry. ``heuristic_verdict`` / ``judge_verdict`` are kept\nloosely-typed because the underlying verdict shape varies by tier;\nconsumers that want the full structure can decode against\n:class:`turnstone.sdk.events.IntentVerdictEvent`.", "properties": { "call_id": { "default": "", diff --git a/sdk/typescript/src/types.ts b/sdk/typescript/src/types.ts index b2457381..b656ea4a 100644 --- a/sdk/typescript/src/types.ts +++ b/sdk/typescript/src/types.ts @@ -164,6 +164,13 @@ export interface CreateWorkstreamResponse { message_count?: number; /** Ids of attachments saved by this request (multipart variant only). */ attachment_ids?: string[]; + /** + * Present ONLY when the workstream was created but its initial_message + * could not be delivered: "queue_full" (raced live worker's interjection + * queue at capacity — resend via /send; uploads stay staged) or + * "refused_closed" (workstream closed mid-create). + */ + initial_message_status?: "queue_full" | "refused_closed"; } export interface CloseWorkstreamRequest { diff --git a/tests/_helpers.py b/tests/_helpers.py index 605a721d..5c88ae71 100644 --- a/tests/_helpers.py +++ b/tests/_helpers.py @@ -3,9 +3,37 @@ not fixtures, and several test files want to import them directly.""" from __future__ import annotations -from typing import Any +import time +from typing import TYPE_CHECKING, Any from unittest.mock import MagicMock +if TYPE_CHECKING: + from collections.abc import Callable + + +def wait_until(cond: Callable[[], bool], timeout: float = 5.0) -> None: + """Poll ``cond`` to True within ``timeout`` or fail the test. + + The worker/wake tests can't join threads by identity: + ``session_worker.send`` assigns ``ws.worker_thread`` under the lock + BEFORE ``t.start()``, so the instant a dispatching call returns, a + fast worker may already have run its exit backstop and installed the + (not-yet-started) wake thread — joining whatever ``ws.worker_thread`` + points at races ``RuntimeError: cannot join thread before it is + started``. Poll outcomes instead. + """ + deadline = time.monotonic() + timeout + while time.monotonic() < deadline: + if cond(): + return + time.sleep(0.005) + if cond(): + # Final re-check: the condition can become true during the last + # sleep (or a CI descheduling stall past the deadline) — failing + # without re-looking makes the helper itself a flake source. + return + raise AssertionError("condition not met within timeout") + def make_chat_session(**overrides: Any) -> Any: """Build a minimal ``ChatSession`` with sane test defaults. diff --git a/tests/test_coordinator_adapter.py b/tests/test_coordinator_adapter.py index 6a0fb502..0efd7b00 100644 --- a/tests/test_coordinator_adapter.py +++ b/tests/test_coordinator_adapter.py @@ -245,6 +245,24 @@ def test_cleanup_ui_tolerates_missing_session_and_ui() -> None: ws.session = None ws.ui = None adapter.cleanup_ui(ws) # no crash + assert ws._closed is True # still marked dead + + +def test_cleanup_ui_marks_workstream_closed() -> None: + """Every teardown path — close, close_idle, EVICTION, delete, + discard — funnels through cleanup_ui, which marks the object dead + under ``ws._lock`` BEFORE the teardown body runs. The wake paths + that hold OBJECT references (the watch ``wake_fn``, + ``session_worker``'s exit backstop) gate on ``_closed``, and + ``session_worker.send`` re-checks it under the same lock — without + this write here, a wake racing an eviction or delete (which never + set the flag) would spawn a full unattended turn on the torn-down + session.""" + adapter, _ = _make_adapter() + ws = _make_ws() + assert ws._closed is False + adapter.cleanup_ui(ws) + assert ws._closed is True # --------------------------------------------------------------------------- diff --git a/tests/test_idle_nudge_wake_integration.py b/tests/test_idle_nudge_wake_integration.py index acedabd1..9d36aaa1 100644 --- a/tests/test_idle_nudge_wake_integration.py +++ b/tests/test_idle_nudge_wake_integration.py @@ -28,8 +28,10 @@ from unittest.mock import MagicMock, patch import pytest +from tests._helpers import wait_until as _wait_until from tests.test_session_manager import FakeStorage -from turnstone.core.idle_nudge_watcher import IdleNudgeWatcher +from turnstone.core import session_worker +from turnstone.core.idle_nudge_watcher import IdleNudgeWatcher, wake_workstream_if_pending from turnstone.core.session import ChatSession from turnstone.core.session_manager import SessionManager from turnstone.core.trajectory import dicts_from_turns, turn_from_dict @@ -299,6 +301,72 @@ def test_idle_event_with_empty_queue_does_not_dispatch_wake(real_mgr, tmp_db): watcher.shutdown() +def test_watch_fire_on_already_idle_session_drives_wake_send(real_mgr, tmp_db): + """A watch firing on an ALREADY-idle workstream sees no IDLE + transition, so :class:`IdleNudgeWatcher` never re-checks the queue — + the dispatch closure's ``wake_fn`` must drive the wake itself. + + Boundary path under test (only the LLM stream is patched): + dispatch closure (real, built by ``set_watch_runner``) + → NudgeQueue.enqueue (real) + → wake_fn → wake_workstream_if_pending (real) + → session_worker.send (real) → daemon thread + → ChatSession.deliver_wake_nudge_from_queue (real) + → ChatSession.send("") → watch_triggered system turn in history + """ + mgr, _adapter = real_mgr + ws = mgr.create(user_id="u1", name="watch-wake-int", skill=None) + assert ws.session is not None + + captured: dict[str, Any] = {} + + class _StubRunner: + def set_dispatch_fn(self, ws_id: str, fn: Any) -> None: + captured["fn"] = fn + + # Production wiring shape (server.py): wake_fn closes over the + # Workstream OBJECT — not its id — so eviction+restore id drift + # can't strand the wake. + ws.session.set_watch_runner( + _StubRunner(), wake_fn=lambda: wake_workstream_if_pending(ws, trigger="watch-fire") + ) + + with ( + patch.object(ws.session, "_create_stream_with_retry", return_value=iter([])), + patch.object( + ws.session, + "_stream_response", + return_value={"role": "assistant", "content": "ok"}, + ), + patch.object(ws.session, "_update_token_table"), + patch.object(ws.session, "_print_status_line"), + patch.object(ws.session, "_visible_memory_count", return_value=0), + patch("turnstone.core.session.save_message"), + ): + ws.session._title_generated = True + # Idle all along — no worker, and no state transition coming. + assert ws.state is WorkstreamState.IDLE + + # Simulate the WatchRunner poll thread delivering a fire. + captured["fn"]({"type": "watch_triggered", "text": "deploy finished: OK"}, "watch-1") + + _wait_for_worker_done(ws) + + # Queue drained by the wake — not parked until the next user message. + assert len(ws.session._nudge_queue) == 0 + + msgs = dicts_from_turns(ws.session.messages) + user_msgs = [m for m in msgs if m.get("role") == "user"] + assert user_msgs, "expected a synthesized user message from the wake" + assert user_msgs[-1]["content"] == "" + assert user_msgs[-1].get("_source") == "system_nudge" + sys_turns = [m for m in msgs if m.get("role") == "system"] + assert any( + m.get("_source") == "watch_triggered" and "deploy finished: OK" in m.get("content", "") + for m in sys_turns + ), f"expected a watch_triggered system turn, got {sys_turns!r}" + + @pytest.fixture def coord_mgr() -> tuple[SessionManager, _BuildRealSessionAdapter, FakeStorage]: """Real coord-side SessionManager with the adapter's kind set to @@ -411,3 +479,120 @@ def test_coord_idle_with_active_children_emits_envelope_via_real_managers(coord_ finally: watcher.shutdown() observer.shutdown() + + +def test_coord_idle_emitted_from_worker_thread_still_wakes(coord_mgr, tmp_db): + """The production-shaped race the test above does NOT exercise: in + production, IDLE is emitted from INSIDE the worker (``set_state`` + subscribers fire on the calling thread — the coord's send emits IDLE + before its worker exits). The watcher's wake dispatch therefore + lands on ``session_worker.send``'s reuse path while the + transitioning worker still owns the flag, and no-ops. Without the + ownership-clear backstop the ``idle_children`` nudge strands until + the next user message — a coord that forgot ``wait_for_workstream`` + never revives. + + Boundary path under test: + worker thread: mgr.set_state(IDLE) + → observer enqueues (real) → watcher wake no-ops (worker owns flag) + → run() returns → session_worker._runner finally clears the flag + → _retry_pending_wake → wake_workstream_if_pending (real) + → wake daemon → deliver_wake_nudge_from_queue → send("") + → idle_children system turn in history + """ + from turnstone.console.coordinator_idle_observer import CoordinatorIdleObserver + from turnstone.core.workstream import WorkstreamKind as _Kind + + mgr, adapter, storage = coord_mgr + observer = CoordinatorIdleObserver(mgr, storage) + observer.start() + watcher = IdleNudgeWatcher(mgr) + watcher.start() + + try: + coord = mgr.create(user_id="u1", name="parent-coord-2", skill=None) + assert coord.session is not None + + storage.register_workstream( + "child-x", + user_id="u1", + name="crawl-docs", + kind=_Kind.INTERACTIVE, + parent_ws_id=coord.id, + state="running", + ) + + coord.session.messages.append(turn_from_dict({"role": "user", "content": "spawn 1"})) + coord.session.messages.append(turn_from_dict({"role": "assistant", "content": "ok"})) + + with ( + patch.object(coord.session, "_create_stream_with_retry", return_value=iter([])), + patch.object( + coord.session, + "_stream_response", + return_value={"role": "assistant", "content": "ack"}, + ), + patch.object(coord.session, "_full_messages", return_value=[]), + patch.object(coord.session, "_update_token_table"), + patch.object(coord.session, "_print_status_line"), + patch.object(coord.session, "_visible_memory_count", return_value=0), + patch("turnstone.core.session.save_message"), + ): + coord.session._title_generated = True + + # Drive the IDLE transition from INSIDE a session_worker + # worker, as production does. + ok = session_worker.send( + coord, + enqueue=lambda: None, + run=lambda: mgr.set_state(coord.id, WorkstreamState.IDLE), + thread_name="coord-send-sim", + ) + assert ok is True + # Without the backstop the queue never drains (the watcher's + # transition-time wake no-opped against the sim worker) and + # this poll times out. Queue-empty implies the wake worker's + # drain ran, so the follow-up flag poll waits for ITS exit. + _wait_until(lambda: len(coord.session._nudge_queue) == 0) + _wait_for_worker_done(coord) + + # Queue drained by the wake, not waiting on the next user message. + assert len(coord.session._nudge_queue) == 0 + msgs = dicts_from_turns(coord.session.messages) + user_msgs = [m for m in msgs if m.get("role") == "user"] + wake_msg = user_msgs[-1] + assert wake_msg["content"] == "" + assert wake_msg.get("_source") == "system_nudge" + idle_turns = [ + m for m in msgs if m.get("role") == "system" and m["_source"] == "idle_children" + ] + assert len(idle_turns) == 1 + assert "crawl-docs" in idle_turns[0]["content"] + assert "wait_for_workstream" in idle_turns[0]["content"] + finally: + watcher.shutdown() + observer.shutdown() + + +def test_wake_delivery_contains_generation_cancelled(tmp_db): + """A close/force-cancel racing the wake turn raises + ``GenerationCancelled`` (a BaseException) out of ``send("")`` — the + wake method must contain it: it IS the wake worker's ``run()`` + closure, and ``session_worker._runner`` catches only ``Exception``, + so an escape would land in ``threading.excepthook`` as stderr noise + on every close-vs-wake race.""" + from tests._helpers import make_chat_session + from turnstone.core.session import GenerationCancelled + + session = make_chat_session() + session._nudge_queue.enqueue("idle_children", "kids waiting", "any") + + def _cancelled_send(*_a: Any, **_k: Any) -> None: + raise GenerationCancelled + + session.send = _cancelled_send # type: ignore[method-assign] + + session.deliver_wake_nudge_from_queue() # must not raise + + assert session._wake_source_tag == "" + assert session._wake_drained_reminders is None diff --git a/tests/test_idle_nudge_watcher.py b/tests/test_idle_nudge_watcher.py index 61d5f23e..fcde8285 100644 --- a/tests/test_idle_nudge_watcher.py +++ b/tests/test_idle_nudge_watcher.py @@ -9,13 +9,14 @@ module-level function to capture calls without spawning real threads. from __future__ import annotations import contextlib +import logging import threading from typing import Any from unittest.mock import patch import pytest -from turnstone.core.idle_nudge_watcher import IdleNudgeWatcher +from turnstone.core.idle_nudge_watcher import IdleNudgeWatcher, wake_workstream_if_pending from turnstone.core.nudge_queue import NudgeQueue from turnstone.core.workstream import WorkstreamState @@ -32,6 +33,7 @@ class _FakeSession: class _FakeWorkstream: def __init__(self, ws_id: str = "ws-test") -> None: self.id = ws_id + self.state = WorkstreamState.IDLE self.session: _FakeSession | None = _FakeSession() self._lock = threading.Lock() self._worker_running = False @@ -163,3 +165,117 @@ class TestIdleNudgeWatcher: watcher.start() watcher.shutdown() watcher.shutdown() # no error + + +class TestWakeWorkstreamIfPending: + """Direct tests for the shared wake gate. + + The IDLE-transition path (via the watcher) is covered above; these + pin the gates the watch dispatch closure relies on when it calls + the helper directly, with no state event involved. + """ + + def test_wakes_idle_ws_with_pending_entry(self, fake_mgr_and_ws): + _mgr, ws = fake_mgr_and_ws + ws.session._nudge_queue.enqueue("watch_triggered", "output", "any") + with patch("turnstone.core.session_worker.send", return_value=True) as mock_send: + assert wake_workstream_if_pending(ws) is True + assert mock_send.call_count == 1 + kwargs = mock_send.call_args.kwargs + assert kwargs["enqueue"]() is None + kwargs["run"]() + assert ws.session.deliver_wake_nudge_from_queue_called == 1 + assert kwargs["thread_name"].startswith("wake-nudge-") + + def test_skips_session_none(self, fake_mgr_and_ws): + _mgr, ws = fake_mgr_and_ws + ws.session = None + with patch("turnstone.core.session_worker.send") as mock_send: + assert wake_workstream_if_pending(ws) is False + assert mock_send.call_count == 0 + + def test_skips_closed_ws(self, fake_mgr_and_ws): + """A workstream mid-``close()`` must not get a wake spawned on + its torn-down session, even while its ``state`` field still + reads IDLE (there is no CLOSED member — close uses the + ``_closed`` tombstone).""" + _mgr, ws = fake_mgr_and_ws + ws.session._nudge_queue.enqueue("watch_triggered", "output", "any") + ws._closed = True + with patch("turnstone.core.session_worker.send") as mock_send: + assert wake_workstream_if_pending(ws) is False + assert mock_send.call_count == 0 + + def test_skips_non_idle_states(self, fake_mgr_and_ws): + """Busy states imply a live worker that drains at its own seams; + ERROR stays parked for the operator — neither gets a wake.""" + _mgr, ws = fake_mgr_and_ws + ws.session._nudge_queue.enqueue("watch_triggered", "output", "any") + with patch("turnstone.core.session_worker.send") as mock_send: + for state in ( + WorkstreamState.RUNNING, + WorkstreamState.THINKING, + WorkstreamState.ATTENTION, + WorkstreamState.ERROR, + ): + ws.state = state + assert wake_workstream_if_pending(ws) is False + assert mock_send.call_count == 0 + + def test_skips_tool_only_entries(self, fake_mgr_and_ws): + """Tool-channel entries belong to the next tool-result seam — a + synthetic empty user turn can't drain them, so no wake.""" + _mgr, ws = fake_mgr_and_ws + ws.session._nudge_queue.enqueue("tool_error", "check memories", "tool") + with patch("turnstone.core.session_worker.send") as mock_send: + assert wake_workstream_if_pending(ws) is False + assert mock_send.call_count == 0 + + def test_dispatched_path_logs_trigger(self, fake_mgr_and_ws, caplog): + """A fresh spawn — ``send`` returns True without touching the + passed ``enqueue`` — emits ``nudge_wake.dispatched`` tagged with + the trigger label (structlog renders the event name + ``%s`` + placeholders into ``msg``; substring-match like the sibling + nudge_queue tests).""" + _mgr, ws = fake_mgr_and_ws + ws.session._nudge_queue.enqueue("watch_triggered", "output", "any") + with ( + patch("turnstone.core.session_worker.send", return_value=True) as mock_send, + caplog.at_level(logging.INFO, logger="turnstone.core.idle_nudge_watcher"), + ): + assert wake_workstream_if_pending(ws, trigger="idle-transition") is True + assert mock_send.call_count == 1 + dispatched = [r for r in caplog.records if "nudge_wake.dispatched" in r.getMessage()] + assert len(dispatched) == 1 + assert dispatched[0].levelno == logging.INFO + assert "trigger=" in dispatched[0].getMessage() + # The reuse-path drop line must not appear on a fresh spawn. + assert not any("nudge_wake.deferred_worker_busy" in r.getMessage() for r in caplog.records) + + def test_deferred_path_logs_worker_busy(self, fake_mgr_and_ws, caplog): + """The reuse path — ``send`` invokes the passed ``enqueue`` and + returns True — emits ``nudge_wake.deferred_worker_busy`` instead + of ``dispatched``. The entry stays owed to the owning worker's + exit backstop; the return value is still True.""" + _mgr, ws = fake_mgr_and_ws + ws.session._nudge_queue.enqueue("watch_triggered", "output", "any") + + def _reuse_send(_ws: Any, *, enqueue: Any, run: Any, thread_name: Any) -> bool: + # Mimic a live worker owning the workstream: send routes the + # wake to the no-op enqueue rather than spawning a daemon. + enqueue() + return True + + with ( + patch("turnstone.core.session_worker.send", side_effect=_reuse_send) as mock_send, + caplog.at_level(logging.INFO, logger="turnstone.core.idle_nudge_watcher"), + ): + assert wake_workstream_if_pending(ws, trigger="idle-transition") is True + assert mock_send.call_count == 1 + deferred = [ + r for r in caplog.records if "nudge_wake.deferred_worker_busy" in r.getMessage() + ] + assert len(deferred) == 1 + assert deferred[0].levelno == logging.INFO + assert "trigger=" in deferred[0].getMessage() + assert not any("nudge_wake.dispatched" in r.getMessage() for r in caplog.records) diff --git a/tests/test_server_attachments_endpoints.py b/tests/test_server_attachments_endpoints.py index 10017e5f..7937557d 100644 --- a/tests/test_server_attachments_endpoints.py +++ b/tests/test_server_attachments_endpoints.py @@ -459,6 +459,11 @@ class TestSendMessageAttachments: session = MagicMock() session._cancel_event = threading.Event() session.queue_message = MagicMock() + # A bare Mock's auto-created ``_nudge_queue`` (truthy, has_pending + # truthy, no-op deliver) turns the worker-exit wake backstop into an + # endless respawn loop; declare this a stub session WITHOUT a queue + # so the wake gate's stub-guard bails. + session._nudge_queue = None captured: dict = {} def fake_send(message, attachments=None, send_id=None): @@ -480,6 +485,7 @@ class TestSendMessageAttachments: ws.session = session ws.worker_thread = None ws._worker_running = False + ws._closed = False # a bare Mock attr is truthy → send() would refuse ws._lock = threading.RLock() mgr.get.return_value = ws return captured, session @@ -658,6 +664,9 @@ class TestQueuedSendWithAttachments: session = MagicMock() session._cancel_event = threading.Event() session.queue_message = fake_queue_message + # Stub session without a NudgeQueue — see _wire_ws for why a bare + # Mock queue would feed the exit backstop an endless wake loop. + session._nudge_queue = None ui = MagicMock() ui._ws_lock = threading.Lock() @@ -675,6 +684,7 @@ class TestQueuedSendWithAttachments: ws.session = session ws.worker_thread = worker ws._worker_running = True + ws._closed = False # a bare Mock attr is truthy → send() would refuse ws._lock = threading.RLock() mgr.get.return_value = ws return captured @@ -738,6 +748,7 @@ class TestBusyWorkerAttachments: ws.ui = ui ws.session = session ws.worker_thread = worker + ws._closed = False # a bare Mock attr is truthy → send() would refuse ws._lock = threading.RLock() mgr.get.return_value = ws return ws, session diff --git a/tests/test_server_attachments_on_create.py b/tests/test_server_attachments_on_create.py index c6d24599..d0e8d12d 100644 --- a/tests/test_server_attachments_on_create.py +++ b/tests/test_server_attachments_on_create.py @@ -434,6 +434,91 @@ class TestCreateMultipart: # pane's rehydrate can't observe it as still-staged. assert get_attachment_buffer().get(aid, ws_id=ws_id, user_id="userA") is None + def test_create_raced_by_live_worker_keeps_attachments_staged(self, app_client, monkeypatch): + """The enqueue branch (caller-supplied ws_id raced by a concurrent + /send claiming the worker first) can't deliver attachments through + the interjection seam — they must REMAIN STAGED so the composer + still shows them and the user's next send delivers them, while the + message text itself rides the queue.""" + from turnstone.core import session_worker + from turnstone.core.attachment_buffer import get_attachment_buffer + + client, _sessions, _gq = app_client + queued: list[str] = [] + + def _record_queue(self, text, *a, **k): + queued.append(text) + return ("", "normal", "msg-x") + + monkeypatch.setattr(_FakeSession, "queue_message", _record_queue) + + def _live_worker_send(ws, *, enqueue, run, thread_name=None): + enqueue() # a worker already owns the ws — reuse path + return True + + monkeypatch.setattr(session_worker, "send", _live_worker_send) + + meta = {"name": "raced", "initial_message": "look at this file"} + resp = client.post( + "/v1/api/workstreams/new", + data={"meta": json.dumps(meta)}, + files=[("file", ("notes.md", b"# hello\n", "text/markdown"))], + headers=_auth("userA"), + ) + assert resp.status_code == 200, resp.text + ws_id = resp.json()["ws_id"] + aid = resp.json()["attachment_ids"][0] + + assert queued == ["look at this file"] # text preserved via the queue + # NOT drained: the upload stays staged, recoverable on the next send. + assert get_attachment_buffer().get(aid, ws_id=ws_id, user_id="userA") is not None + # Delivered path → no dropped-message marker on the response. + assert "initial_message_status" not in resp.json() + + def test_create_raced_queue_full_reports_dropped_message(self, app_client, monkeypatch): + """``queue.Full`` on the raced enqueue path must not read as + success: it propagates out of ``_enqueue_init`` into + ``session_worker.send``'s backpressure branch (→ ``False``), and + the create response carries ``initial_message_status: + "queue_full"`` instead of a bare 200 implying the first message + was delivered. Attachments stay staged for the retry.""" + import queue as _queue + + from turnstone.core import session_worker + from turnstone.core.attachment_buffer import get_attachment_buffer + + client, _sessions, _gq = app_client + + def _full_queue(self, *a, **k): + raise _queue.Full + + monkeypatch.setattr(_FakeSession, "queue_message", _full_queue) + + def _live_worker_send(ws, *, enqueue, run, thread_name=None): + # Mirror the real send()'s reuse-path backpressure contract: + # queue.Full → False, never a raise to the caller. + try: + enqueue() + except _queue.Full: + return False + return True + + monkeypatch.setattr(session_worker, "send", _live_worker_send) + + meta = {"name": "raced-full", "initial_message": "look at this file"} + resp = client.post( + "/v1/api/workstreams/new", + data={"meta": json.dumps(meta)}, + files=[("file", ("notes.md", b"# hello\n", "text/markdown"))], + headers=_auth("userA"), + ) + assert resp.status_code == 200, resp.text + body = resp.json() + assert body["initial_message_status"] == "queue_full" + # Attachments untouched — the composer chips survive for the retry. + aid = body["attachment_ids"][0] + assert get_attachment_buffer().get(aid, ws_id=body["ws_id"], user_id="userA") is not None + def test_create_with_attachments_no_initial_message_keeps_staged(self, app_client): import hashlib @@ -527,3 +612,28 @@ class TestCreateJsonStillWorks: assert data["ws_id"] # New optional field, but always emitted (empty list when absent) assert data["attachment_ids"] == [] + + def test_initial_message_routes_through_session_worker_send(self, app_client): + """The initial-message worker is dispatched via + ``session_worker.send`` (not an inlined ``threading.Thread``) so it + inherits the ownership-clear wake backstop. Patching the module + attribute captures the wiring without spawning a thread — server.py + calls ``session_worker.send`` as a module attribute even from its + local import.""" + from unittest.mock import patch + + client, _sessions, _gq = app_client + with patch("turnstone.core.session_worker.send", return_value=True) as mock_send: + resp = client.post( + "/v1/api/workstreams/new", + json={"name": "init-dispatch", "initial_message": "go"}, + headers=_auth("userA"), + ) + assert resp.status_code == 200, resp.text + assert mock_send.call_count == 1 + kwargs = mock_send.call_args.kwargs + assert kwargs["thread_name"].startswith("ws-init-") + # ``run`` is the init closure the shared dispatcher spawns; the + # dead-by-construction ``enqueue`` branch is still wired (loudly). + assert callable(kwargs["run"]) + assert callable(kwargs["enqueue"]) diff --git a/tests/test_session.py b/tests/test_session.py index 23d82c35..d8236a2f 100644 --- a/tests/test_session.py +++ b/tests/test_session.py @@ -5086,6 +5086,55 @@ class TestMetacognitiveBuffers: assert sys_turn["_source"] == "tool_error" assert sys_turn["content"] == "you hit an error; check memory" + def test_denial_nudge_queues_on_tool_channel(self, tmp_db): + """A denial responds to the tool batch the user just rejected — the + producer must queue it on the TOOL channel so it drains through + ``_collect_advisories`` alongside the denied results (the same seam + tool_error / repeat use), not sit on the user channel until the next + user-message seam — by which point the model has already reacted to + the denial without the nudge. + + Drives the REAL ``_execute_tools`` two-phase gate with real + ``_nudges_enabled`` / ``should_nudge`` gating; only the prepare + step and the UI approval are stubbed.""" + from turnstone.core.metacognition import format_nudge + + session = _make_session() + # ``should_nudge`` skips the very first message — give the session + # the natural pre-batch shape (user turn + assistant tool-call turn). + session.messages.append(turn_from_dict({"role": "user", "content": "do the thing"})) + session.messages.append(turn_from_dict({"role": "assistant", "content": "calling"})) + + item = { + "call_id": "call_1", + "func_name": "notify", + "needs_approval": True, + # Must NOT run — a denied tool never executes. + "execute": lambda p: (p["call_id"], "EXECUTED — must not happen"), + } + with ( + patch.object(session, "_safe_prepare_tool", return_value=item), + patch.object(session.ui, "approve_tools", return_value=(False, "use /tmp instead")), + patch.object(session, "_visible_memory_count", return_value=0), + ): + tool_calls = [ + { + "id": "call_1", + "type": "function", + "function": {"name": "notify", "arguments": "{}"}, + } + ] + results, feedback = session._execute_tools(tool_calls) + + # The denied item surfaced the operator's feedback as its result… + assert results == [("call_1", "Denied by user: use /tmp instead")] + assert feedback is None + # …and the denial nudge is queued on the TOOL channel, so the same + # batch's ``_collect_advisories`` drain delivers it; nothing defers + # to the next user turn. + assert session._nudge_queue.pending(channel="tool") == [("denial", format_nudge("denial"))] + assert session._nudge_queue.pending(channel="user") == [] + def test_queued_message_appends_system_turn_after_tool_batch(self, tmp_db): """A queued message arriving during a tool batch becomes a first-class ``{"role": "system", "_source": "user_interjection"}`` diff --git a/tests/test_session_worker.py b/tests/test_session_worker.py index e2a4021b..0a2a1bc0 100644 --- a/tests/test_session_worker.py +++ b/tests/test_session_worker.py @@ -2,7 +2,7 @@ The shared worker dispatch is load-bearing for both the interactive ``/v1/api/workstreams/{ws_id}/send`` HTTP handler and the coordinator -``CoordinatorAdapter.send`` path. Tests cover the four invariants the +``CoordinatorAdapter.send`` path. Tests cover the five invariants the module must hold: * live worker → enqueue, no thread spawn @@ -10,10 +10,14 @@ module must hold: * concurrent ``send`` calls produce exactly one worker thread (Stage 1 bug-1 — the racy ``Thread.is_alive()`` gate stays caught) * ``_worker_running`` cleared in ``finally`` even on uncaught exception +* ownership-clear wake backstop: a worker exiting with USER_DRAIN + nudges queued on an IDLE workstream spawns the wake send that the + IDLE fan-out (which ran on this worker's own thread) had to drop -Callers pass no-arg closures, so this module never touches -``ws.session`` — keeps the contract narrow and lets watch-style -dispatchers drive a session that isn't installed on ``ws``. +Callers pass no-arg closures, so dispatch never touches ``ws.session``; +the exit backstop only PEEKS it defensively (``getattr`` for +``_nudge_queue``, bail on stubs) — watch-style dispatchers can still +drive a session that isn't installed on ``ws``. """ from __future__ import annotations @@ -22,8 +26,10 @@ import queue import threading from typing import Any +from tests._helpers import wait_until as _wait_until from turnstone.core import session_worker -from turnstone.core.workstream import Workstream +from turnstone.core.nudge_queue import USER_DRAIN, NudgeQueue +from turnstone.core.workstream import Workstream, WorkstreamState class _SendSession: @@ -140,6 +146,41 @@ def test_enqueue_unexpected_exception_returns_false_logged() -> None: assert ws._worker_running is True +def test_closed_workstream_refused_no_spawn() -> None: + """Authoritative closed-check: ``close()`` sets ``_closed`` under + ``ws._lock``, so a wake (or send) racing it must be refused HERE — + the wake gate's lockless peek can go stale, and a spawn past this + point would run a full unattended turn (inference, tool calls, + storage writes) on a workstream whose ``ws_closed`` already fired. + """ + session = _SendSession() + ws = _make_ws(session) + ws._closed = True + + ok = _send_message(ws, session, "hello") + + assert ok is False + assert session.send_calls == [] + assert session.queue_calls == [] + assert ws.worker_thread is None + assert ws._worker_running is False + + +def test_closed_workstream_refused_on_reuse_path_too() -> None: + """The refusal precedes the enqueue branch: no interjection is queued + onto a session whose workstream is already closed.""" + session = _SendSession() + ws = _make_ws(session) + ws._worker_running = True + ws._closed = True + + ok = _send_message(ws, session, "hello") + + assert ok is False + assert session.queue_calls == [] + assert ws._worker_running is True # untouched — not ours to clear + + # --------------------------------------------------------------------------- # _worker_running lifecycle # --------------------------------------------------------------------------- @@ -301,6 +342,141 @@ def test_thread_name_explicit_override() -> None: ws.worker_thread.join(timeout=2.0) +class _WakeCapableSession(_SendSession): + """Adds the ChatSession surface the exit backstop peeks at.""" + + def __init__(self, **kwargs: Any) -> None: + super().__init__(**kwargs) + self._nudge_queue = NudgeQueue() + self.deliver_calls = 0 + self.deliver_thread_names: list[str] = [] + self.delivered = threading.Event() + + def deliver_wake_nudge_from_queue(self) -> None: + # Mirror the real contract: the wake drains its own queue, so + # the wake worker's OWN exit backstop sees nothing pending and + # the chain converges instead of spawning wakes forever. + self.deliver_calls += 1 + self.deliver_thread_names.append(threading.current_thread().name) + self._nudge_queue.drain(USER_DRAIN) + self.delivered.set() + + +class TestWorkerExitWakeBackstop: + """A worker exiting while its (idle) workstream has USER_DRAIN + nudges queued spawns the wake send the IDLE fan-out had to drop. + + Production shape being modelled: ``set_state(IDLE)`` fires its + subscribers on the worker thread from inside ``run()`` — + ``CoordinatorIdleObserver`` enqueues ``idle_children``, then + ``IdleNudgeWatcher``'s wake dispatch lands on the reuse path + (this very worker still owns the flag) and no-ops. The enqueue + inside ``run`` below stands in for that observer enqueue. + """ + + def test_worker_exit_delivers_pending_wake(self) -> None: + session = _WakeCapableSession() + ws = _make_ws(session) + assert ws.state is WorkstreamState.IDLE # dataclass default + + def run() -> None: + # What the IDLE fan-out's observer does, on this thread. + session._nudge_queue.enqueue("idle_children", "kids waiting", "any") + + ok = session_worker.send(ws, enqueue=lambda: None, run=run) + assert ok is True + + # The wake is delivered on a fresh wake-named worker thread… + assert session.delivered.wait(timeout=2.0), ( + "exit backstop did not deliver the pending nudge" + ) + assert session.deliver_thread_names[0].startswith("wake-nudge-") + # …after which the wake worker's own exit backstop sees an empty + # queue and the chain converges: flag at rest, exactly one deliver. + _wait_until(lambda: ws._worker_running is False) + assert session.deliver_calls == 1 + assert len(session._nudge_queue) == 0 + + def test_worker_exit_no_wake_when_queue_empty(self) -> None: + session = _WakeCapableSession() + ws = _make_ws(session) + + ok = session_worker.send(ws, enqueue=lambda: None, run=lambda: None) + assert ok is True + original = ws.worker_thread + assert original is not None + original.join(timeout=2.0) + + assert ws.worker_thread is original # no wake spawned + assert session.deliver_calls == 0 + assert ws._worker_running is False + + def test_worker_exit_no_wake_for_stub_session_without_queue(self) -> None: + """The narrow-contract escape hatch: a session without a + ``_nudge_queue`` (watch-style stubs) is skipped by the shared + wake gate's own defensive peek — no AttributeError, no wake.""" + session = _SendSession() + ws = _make_ws(session) + + ok = _send_message(ws, session, "hello") + assert ok is True + original = ws.worker_thread + assert original is not None + original.join(timeout=2.0) + + assert ws.worker_thread is original + assert ws._worker_running is False + + def test_worker_exit_no_wake_when_state_not_idle(self) -> None: + """An ERROR exit stays parked for the operator — pending nudges + wait for the next real interaction rather than burning + unattended inference on a failed session.""" + session = _WakeCapableSession() + ws = _make_ws(session) + + def run() -> None: + session._nudge_queue.enqueue("idle_children", "kids waiting", "any") + ws.state = WorkstreamState.ERROR + + ok = session_worker.send(ws, enqueue=lambda: None, run=run) + assert ok is True + original = ws.worker_thread + assert original is not None + original.join(timeout=2.0) + + assert ws.worker_thread is original + assert session.deliver_calls == 0 + assert len(session._nudge_queue) == 1 # still queued for later seams + + def test_abandoned_worker_does_not_run_wake_backstop(self) -> None: + """Only the owner retries: an abandoned worker (successor claimed + the flag) finishing late must not spawn a wake — the successor's + own exit runs the backstop.""" + send_gate = threading.Event() + session = _WakeCapableSession(send_gate=send_gate) + ws = _make_ws(session) + + ok = _send_message(ws, session, "hello") + assert ok is True + abandoned = ws.worker_thread + assert abandoned is not None + + session._nudge_queue.enqueue("idle_children", "kids waiting", "any") + sentinel = threading.Thread(target=lambda: None, name="successor") + with ws._lock: + ws.worker_thread = sentinel + ws._worker_running = True + + send_gate.set() + abandoned.join(timeout=3.0) + assert not abandoned.is_alive() + + # No wake spawned by the abandoned thread; ownership intact. + assert ws.worker_thread is sentinel + assert session.deliver_calls == 0 + assert ws._worker_running is True + + def test_does_not_deadlock_when_run_briefly_grabs_ws_lock() -> None: """Sanity check: ``run`` is invoked OUTSIDE ``ws._lock``. A worker body that briefly takes the lock (e.g. to update worker state) diff --git a/tests/test_watch.py b/tests/test_watch.py index 16c9de1a..d7e7138c 100644 --- a/tests/test_watch.py +++ b/tests/test_watch.py @@ -2,11 +2,15 @@ from __future__ import annotations +import threading +import time from datetime import UTC, datetime +from typing import Any from unittest.mock import MagicMock import pytest +from tests._helpers import wait_until from turnstone.core.watch import ( WatchRunner, build_watch_reminder, @@ -545,8 +549,12 @@ class TestWatchRunner: assert runner.get_dispatch_fn("ws-1") is fn # Unknown ws → None. assert runner.get_dispatch_fn("ws-missing") is None - # After removal → None. - runner.remove_dispatch_fn("ws-1") + # Owner-checked removal: a non-owner's teardown must not remove a + # still-live registration (restore shell vs reopened pane). + runner.remove_dispatch_fn("ws-1", owner=MagicMock()) + assert runner.get_dispatch_fn("ws-1") is fn + # The owner (or a blind removal) does remove it. + runner.remove_dispatch_fn("ws-1", owner=fn) assert runner.get_dispatch_fn("ws-1") is None def test_run_command_success(self): @@ -566,3 +574,716 @@ class TestWatchRunner: output, code = runner._run_command("sleep 30") assert "timed out" in output.lower() assert code == -1 + + +def _watch_row(**over: Any) -> dict[str, Any]: + """A firing watch row (condition matches ``echo hello``); override + fields per test.""" + row: dict[str, Any] = { + "watch_id": "abc123", + "ws_id": "ws-1", + "name": "test-watch", + "command": "echo hello", + "stop_on": '"hello" in output', + "max_polls": 100, + "poll_count": 0, + "last_output": None, + "interval_secs": 60, + "created": datetime.now(UTC).strftime("%Y-%m-%dT%H:%M:%S"), + } + row.update(over) + return row + + +def _slow_restore(runner: WatchRunner, ws_id: str, calls: list[str], lock: threading.Lock) -> Any: + """Restore_fn stand-in: record the call, register a dispatch fn (as the + real restore does via ``set_watch_runner``), and sleep briefly so a + concurrent second caller is guaranteed to be waiting on ``_restore_lock`` + when we return. + """ + with lock: + calls.append(ws_id) + time.sleep(0.05) + fn = MagicMock() + runner.set_dispatch_fn(ws_id, fn) + return fn + + +class TestWatchRunnerDeliveryRetry: + """Delivery failure HOLDS the built reminder and re-delivers it on a + later tick — never re-running the command, so a transient stop_on match + isn't lost — bounded by ``MAX_DELIVERY_ATTEMPTS``. Until delivery lands + the row commits only ``next_poll`` plus the fire's durable poll charge: + no baseline advance and no deactivation of a fire the model never saw, + while a restart mid-hold (which re-runs the command) stays bounded by + ``max_polls``.""" + + def _make_runner(self, storage: Any, **kwargs: Any) -> WatchRunner: + return WatchRunner( + storage=storage, + node_id="test-node", + check_interval=0.1, + tool_timeout=5, + **kwargs, + ) + + def test_delivery_failure_holds_reminder_and_defers_row(self): + storage = MagicMock() + storage.update_watch.return_value = True + # No dispatch fn registered, no restore_fn → delivery fails. + runner = self._make_runner(storage) + + runner._poll_watch(_watch_row()) + + # Row commit is the retry cadence + this fire's durable poll charge + # — the fire stays fully retryable, and a restart mid-hold (which + # re-runs the command) stays bounded by max_polls. + storage.update_watch.assert_called_once() + args, kwargs = storage.update_watch.call_args + assert args[0] == "abc123" + assert set(kwargs) == {"next_poll", "poll_count"} + assert kwargs["poll_count"] == 1 # charged durably at hold time + assert kwargs["next_poll"] # advanced, not cleared + # The reminder is HELD for re-delivery; the row is NOT marked + # terminal-dispatched (the model never saw it). + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery + assert runner._pending_delivery["abc123"]["attempts"] == 1 + with runner._terminal_dispatched_lock: + assert "abc123" not in runner._terminal_dispatched + + def test_redelivery_uses_held_reminder_without_rerunning_command(self): + storage = MagicMock() + storage.update_watch.return_value = True + runner = self._make_runner(storage) + + # Poll 1: fails → holds. Capture the exact held reminder object. + runner._poll_watch(_watch_row()) + with runner._pending_delivery_lock: + held = runner._pending_delivery["abc123"]["reminder"] + + # ws restored: register a fn, and make _run_command explode so the + # test proves re-delivery does NOT re-run the command. + dispatch_fn = MagicMock() + runner.set_dispatch_fn("ws-1", dispatch_fn) + runner._run_command = MagicMock( # type: ignore[method-assign] + side_effect=AssertionError("command must not re-run on re-delivery") + ) + + runner._poll_watch(_watch_row()) + + # Delivered the SAME held reminder; command untouched; committed + # terminal with the ORIGINAL fire's poll_count; hold cleared. + dispatch_fn.assert_called_once() + assert dispatch_fn.call_args[0][0] is held + runner._run_command.assert_not_called() + _a, kwargs = storage.update_watch.call_args + assert kwargs["active"] is False + assert kwargs["poll_count"] == 1 # retries consumed no ADDITIONAL budget + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery + + def test_transient_exhaustion_keeps_watch_active(self): + # A purely transient cause (no fn, no restore → returns False) that + # outlasts the attempt budget must NOT silently deactivate the watch + # — it drops the held reminder, charges ONE poll to the max_polls + # budget, and leaves the watch active to re-fire on its next + # interval. The baseline (last_output) stays uncommitted so a + # delta-style stop_on re-fires on the change the model never saw. + from turnstone.core.watch import MAX_DELIVERY_ATTEMPTS + + storage = MagicMock() + storage.update_watch.return_value = True + runner = self._make_runner(storage) # always fails, transiently + + # Poll 1 fires + holds (attempts=1); polls 2..MAX bump attempts, the + # MAX-th hitting the exhaustion ceiling. + for _ in range(MAX_DELIVERY_ATTEMPTS): + runner._poll_watch(_watch_row()) + + # Hold dropped, but the watch was NEVER deactivated — no active=False + # commit anywhere; the final commit charges the poll and re-schedules + # (no last_output → the fire re-detects next cycle). + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery + deactivations = [ + c for c in storage.update_watch.call_args_list if c.kwargs.get("active") is False + ] + assert deactivations == [] + _a, kwargs = storage.update_watch.call_args # last commit + assert set(kwargs) == {"poll_count", "next_poll"} + assert kwargs["poll_count"] == 1 # one poll charged to the budget + + def test_transient_exhaustion_with_budget_spent_deactivates(self): + # The keep-alive-on-transient behavior is bounded by the watch's own + # max_polls budget: once poll_count reaches it, exhaustion commits + # the held (deactivating) update instead of re-running the command + # every interval forever against an unreachable workstream. + from turnstone.core.watch import MAX_DELIVERY_ATTEMPTS + + storage = MagicMock() + storage.update_watch.return_value = True + runner = self._make_runner(storage) # always fails, transiently + + for _ in range(MAX_DELIVERY_ATTEMPTS): + runner._poll_watch(_watch_row(max_polls=1)) # budget spent on fire 1 + + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery + _a, kwargs = storage.update_watch.call_args # last commit + assert kwargs["active"] is False # deactivated: budget spent + assert kwargs["poll_count"] == 1 + + def test_held_delivery_retries_on_capped_cadence_not_interval(self): + # Re-delivery is a cheap in-memory dispatch — a daily watch whose + # fire hit a busy restore slot must retry within + # DELIVERY_RETRY_CAP_SECS, not sit on the reminder for 24 h. + from turnstone.core.watch import DELIVERY_RETRY_CAP_SECS + + storage = MagicMock() + storage.update_watch.return_value = True + runner = self._make_runner(storage) + + runner._poll_watch(_watch_row(interval_secs=86_400)) + + _a, kwargs = storage.update_watch.call_args + assert set(kwargs) == {"next_poll", "poll_count"} + retry_at = datetime.strptime(kwargs["next_poll"], "%Y-%m-%dT%H:%M:%S").replace(tzinfo=UTC) + delta = (retry_at - datetime.now(UTC)).total_seconds() + assert 0 < delta <= DELIVERY_RETRY_CAP_SECS + 5 # capped, not 86400 + + def test_permanent_unrestorable_deactivates_immediately(self): + # A permanent failure (restore raises WatchWorkstreamUnrestorable, + # e.g. corrupt persona stamp) deactivates the watch on the FIRST + # fire — no held reminder, no waiting out the attempt budget. + from turnstone.core.watch import WatchWorkstreamUnrestorable + + storage = MagicMock() + storage.update_watch.return_value = True + restore_fn = MagicMock(side_effect=WatchWorkstreamUnrestorable("ws-1")) + runner = self._make_runner(storage, restore_fn=restore_fn) + + runner._poll_watch(_watch_row()) + + restore_fn.assert_called_once_with("ws-1") # not retried 5× + _a, kwargs = storage.update_watch.call_args + assert kwargs["active"] is False # deactivated now + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery # nothing held + # The admission slot is released even on the raising path. + with runner._restore_lock: + assert "ws-1" not in runner._restoring + + def test_pending_cleared_on_already_dispatched_retry(self): + # A re-delivery that succeeded but whose row-commit raised leaves + # the id in BOTH _terminal_dispatched and _pending_delivery. The + # next tick's already-dispatched branch must clear the hold too, or + # it leaks once the row deactivates. + storage = MagicMock() + storage.update_watch.return_value = True + runner = self._make_runner(storage) + with runner._terminal_dispatched_lock: + runner._terminal_dispatched.add("abc123") + runner._stash_pending_delivery("abc123", {"text": "x"}, {"active": False}, attempts=1) + + runner._poll_watch(_watch_row()) # hits the already_dispatched branch + + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery + with runner._terminal_dispatched_lock: + assert "abc123" not in runner._terminal_dispatched + + def test_restore_capacity_full_defers_without_restoring(self): + # When MAX_CONCURRENT_RESTORES restores are already in flight, a + # new evicted-ws poll must DEFER (return False, hold) rather than + # block a poll slot — and must not start a restore. + from turnstone.core.watch import MAX_CONCURRENT_RESTORES + + storage = MagicMock() + storage.update_watch.return_value = True + restore_fn = MagicMock(return_value=MagicMock()) + runner = self._make_runner(storage, restore_fn=restore_fn) + # Saturate the restore admission with other in-flight ws_ids. + with runner._restore_lock: + for i in range(MAX_CONCURRENT_RESTORES): + runner._restoring[f"other-{i}"] = time.monotonic() + + result = runner._dispatch_result("ws-evicted", {"text": "x"}, "w1") + + assert result is False # deferred + restore_fn.assert_not_called() # no restore admitted + + def test_race_won_admission_delivers_outside_restore_lock(self): + # A dispatch fn registered between the fast-path miss and the + # admission check must be delivered WITHOUT holding _restore_lock: + # the closure can block (ws._lock, wake-thread spawn), and running + # it under the lock serialises every restore admission on the node + # behind one delivery. + storage = MagicMock() + storage.update_watch.return_value = True + restore_fn = MagicMock(return_value=None) + runner = self._make_runner(storage, restore_fn=restore_fn) + + lock_free_during_dispatch: list[bool] = [] + + def probe(reminder: dict[str, Any], watch_id: str) -> None: + ok = runner._restore_lock.acquire(blocking=False) + lock_free_during_dispatch.append(ok) + if ok: + runner._restore_lock.release() + + real_try = runner._try_dispatch_fn + calls = {"n": 0} + + def fake_try(ws_id: str, reminder: dict[str, Any], watch_id: str) -> bool | None: + calls["n"] += 1 + if calls["n"] == 1: + # Simulate a restore completing between the fast path and + # the admission check: the fn appears "while we waited". + runner.set_dispatch_fn("ws-1", probe) + return None + return real_try(ws_id, reminder, watch_id) + + runner._try_dispatch_fn = fake_try # type: ignore[method-assign] + + result = runner._dispatch_result("ws-1", {"text": "x"}, "w1") + + assert result is True # race-won fn delivered + assert lock_free_during_dispatch == [True] # ...outside the lock + restore_fn.assert_not_called() # no restore admitted for a live fn + + def test_restore_returning_none_holds(self): + storage = MagicMock() + storage.update_watch.return_value = True + restore_fn = MagicMock(return_value=None) # e.g. all slots active + runner = self._make_runner(storage, restore_fn=restore_fn) + + runner._poll_watch(_watch_row()) + + restore_fn.assert_called_once_with("ws-1") + _a, kwargs = storage.update_watch.call_args + assert set(kwargs) == {"next_poll", "poll_count"} + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery + + def test_live_fn_raise_holds_without_restoring(self): + # A registered fn that RAISES means the ws is live; we must NOT fall + # through to restore (that would spawn a duplicate session on a live + # conversation). The reminder is held for re-delivery instead. + storage = MagicMock() + storage.update_watch.return_value = True + restore_fn = MagicMock() + runner = self._make_runner(storage, restore_fn=restore_fn) + runner.set_dispatch_fn("ws-1", MagicMock(side_effect=RuntimeError("stale closure"))) + + runner._poll_watch(_watch_row()) + + restore_fn.assert_not_called() + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery + _a, kwargs = storage.update_watch.call_args + assert set(kwargs) == {"next_poll", "poll_count"} + + def test_forget_terminal_dispatched_clears_held_reminder(self): + # User-cancel takes the row out of the due view; its held reminder + # must be dropped too or it would leak (never re-polled). + storage = MagicMock() + storage.update_watch.return_value = True + runner = self._make_runner(storage) + runner._poll_watch(_watch_row()) + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery + + runner.forget_terminal_dispatched("abc123") + + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery + + def test_abandon_write_failure_keeps_hold_for_write_retry(self): + # Reads-succeed/writes-fail storage (e.g. disk-full SQLite): a + # failed abandon commit must keep the hold so the next tick retries + # the WRITE via the redeliver path — the clear-first order let the + # row re-list into a fresh COMMAND RUN every attempt-budget cycle, + # forever, with the poll budget never advancing. + from turnstone.core.watch import WatchWorkstreamUnrestorable + + storage = MagicMock() + storage.update_watch.return_value = True + runner = self._make_runner(storage) + runner._poll_watch(_watch_row()) # fire → hold (write still OK here) + with runner._pending_delivery_lock: + pending = dict(runner._pending_delivery["abc123"]) + + runner._restore_fn = MagicMock( # type: ignore[assignment] + side_effect=WatchWorkstreamUnrestorable("ws-1") + ) + storage.update_watch.side_effect = RuntimeError("disk full") + + with pytest.raises(RuntimeError): + runner._redeliver_pending(_watch_row(), pending) + + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery # hold survived + + def test_unrestorable_abandon_write_failure_keeps_hold(self): + # Fresh-fire permanent failure whose deactivation write fails must + # not strand the still-active row into a fresh command run every + # tick: the stash routes the next tick into the redeliver path, + # which retries the WRITE — never the command. + from turnstone.core.watch import WatchWorkstreamUnrestorable + + storage = MagicMock() + storage.update_watch.side_effect = RuntimeError("disk full") + restore_fn = MagicMock(side_effect=WatchWorkstreamUnrestorable("ws-1")) + runner = self._make_runner(storage, restore_fn=restore_fn) + + with pytest.raises(RuntimeError): + runner._poll_watch(_watch_row()) + + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery # hold survived + + # Next tick: the write retries and lands; the command never re-runs. + runner._run_command = MagicMock( # type: ignore[method-assign] + side_effect=AssertionError("command must not re-run") + ) + storage.update_watch.side_effect = None + storage.update_watch.return_value = True + + runner._poll_watch(_watch_row()) + + runner._run_command.assert_not_called() + _a, kwargs = storage.update_watch.call_args + assert kwargs["active"] is False # deactivation landed on the retry + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery + + def test_exhaustion_write_failure_keeps_hold_for_write_retry(self): + # Same pathology on the transient-exhaustion branch: the charge + # commit failing must keep the hold (write retried next tick), not + # drop it into a fresh command cycle with the budget never durable. + from turnstone.core.watch import MAX_DELIVERY_ATTEMPTS + + storage = MagicMock() + storage.update_watch.return_value = True + runner = self._make_runner(storage) # no fn, no restore → transient + runner._poll_watch(_watch_row()) # fire → hold + with runner._pending_delivery_lock: + runner._pending_delivery["abc123"]["attempts"] = MAX_DELIVERY_ATTEMPTS - 1 + pending = dict(runner._pending_delivery["abc123"]) + + storage.update_watch.side_effect = RuntimeError("disk full") + + with pytest.raises(RuntimeError): + runner._redeliver_pending(_watch_row(), pending) + + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery # hold survived + + +class TestWatchRunnerCancelRace: + """User-cancel racing the poll pool: the delivery paths re-check the + row's active state so a cancelled watch can neither deliver nor leak a + held reminder, and the tick sweep mops up the one interleaving the + point checks can't reach (a stash landing after the cancel path's + ``forget_terminal_dispatched`` already cleared).""" + + def _make_runner(self, storage: Any, **kwargs: Any) -> WatchRunner: + return WatchRunner( + storage=storage, + node_id="test-node", + check_interval=0.1, + tool_timeout=5, + **kwargs, + ) + + def test_hold_dropped_when_watch_cancelled_mid_fire(self): + # Cancel lands while the fire's command is running: the hold path + # re-checks the row and DROPS instead of stashing — an inactive row + # never re-lists, so a stash here would leak for the process + # lifetime with nothing ever retrying or clearing it. + storage = MagicMock() + storage.update_watch.return_value = True + storage.is_watch_active.return_value = False + runner = self._make_runner(storage) # no fn, no restore → would hold + + runner._poll_watch(_watch_row()) + + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery + # No retry-cadence commit either — the row already left the view. + storage.update_watch.assert_not_called() + + def test_redelivery_dropped_when_watch_cancelled(self): + # Cancel lands between the due listing and the redelivery dispatch: + # deliver nothing (the model must not act on — nor a restore be + # spawned for — a watch the user just cancelled) and drop the hold. + storage = MagicMock() + storage.update_watch.return_value = True + runner = self._make_runner(storage) + runner._poll_watch(_watch_row()) # fails → holds (row still active) + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery + + storage.is_watch_active.return_value = False # user cancels + dispatch_fn = MagicMock() + runner.set_dispatch_fn("ws-1", dispatch_fn) # ws even came back live + + runner._poll_watch(_watch_row()) + + dispatch_fn.assert_not_called() + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery + # The only row write remains the initial hold's cadence commit — + # no terminal commit lands over the cancel's row state. + assert storage.update_watch.call_count == 1 + + def test_tick_sweeps_cancelled_holds(self): + # The residual interleaving: a stash that landed AFTER the cancel's + # forget_terminal_dispatched cleared (its active re-check passed + # just before the cancel's row write). The sweep drops it within + # one tick. + storage = MagicMock() + storage.update_watch.return_value = True + storage.list_due_watches.return_value = [] + runner = self._make_runner(storage) + runner._stash_pending_delivery("abc123", {"text": "x"}, {"active": False}, attempts=1) + storage.is_watch_active.return_value = False # row already cancelled + + runner._tick() + + with runner._pending_delivery_lock: + assert "abc123" not in runner._pending_delivery + + def test_tick_sweep_keeps_active_holds(self): + storage = MagicMock() + storage.update_watch.return_value = True + storage.list_due_watches.return_value = [] + runner = self._make_runner(storage) + runner._stash_pending_delivery("abc123", {"text": "x"}, {"active": False}, attempts=1) + storage.is_watch_active.return_value = True + + runner._tick() + + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery + + def test_active_checks_bias_toward_delivery_on_storage_error(self): + # is_watch_active RAISING must not drop a fire: the sweep keeps the + # hold and the delivery paths proceed (bounded by their own attempt + # and poll budgets) — a storage blip is not a cancellation. + storage = MagicMock() + storage.update_watch.return_value = True + storage.list_due_watches.return_value = [] + storage.is_watch_active.side_effect = RuntimeError("storage down") + runner = self._make_runner(storage) + runner._stash_pending_delivery("abc123", {"text": "x"}, {"active": False}, attempts=1) + + runner._tick() # sweep: biased active → kept + + with runner._pending_delivery_lock: + assert "abc123" in runner._pending_delivery + + +class TestWatchRunnerRestoreSerialization: + """Two watches on ONE evicted workstream, polled concurrently, must + trigger the restore path at most once — otherwise each spawns a live + auto-approved session racing writes into one conversation history.""" + + def test_concurrent_same_ws_restores_once(self): + storage = MagicMock() + storage.update_watch.return_value = True + restore_calls: list[str] = [] + calls_lock = threading.Lock() + + runner = WatchRunner( + storage=storage, + node_id="n", + check_interval=0.1, + tool_timeout=5, + restore_fn=lambda ws_id: _slow_restore(runner, ws_id, restore_calls, calls_lock), + ) + + reminder = {"type": "watch_triggered", "text": "x"} + barrier = threading.Barrier(2) + results: list[bool] = [] + results_lock = threading.Lock() + + def call(wid: str) -> None: + barrier.wait(timeout=2.0) + ok = runner._dispatch_result("ws-shared", reminder, wid) + with results_lock: + results.append(ok) + + threads = [threading.Thread(target=call, args=(f"w{i}",)) for i in range(2)] + for t in threads: + t.start() + for t in threads: + t.join(timeout=3.0) + + # Exactly one restore ran; the winner delivered (True) and the other + # DEFERRED (False, holds + re-delivers next tick) rather than blocking + # its poll slot on the in-flight restore or restoring a second time. + assert restore_calls == ["ws-shared"] + assert sorted(results) == [False, True] + # Admission slot released after the restore. + with runner._restore_lock: + assert "ws-shared" not in runner._restoring + + def test_wedged_restore_admissions_defer_and_alert(self, caplog): + # Admission entries older than RESTORE_STALL_ALERT_SECS are alerted + # on but NEVER evicted: the wedged poll thread's pool slot is never + # released, so reclaiming its admission would just readmit a restore + # that can wedge another pool thread on the same cause — trading + # this capped degraded state (restores blocked, polling intact) for + # total poll-pool collapse. New restores keep deferring; the error + # log is the operator's restart signal. + from turnstone.core.watch import RESTORE_STALL_ALERT_SECS + + storage = MagicMock() + storage.update_watch.return_value = True + restore_fn = MagicMock(return_value=MagicMock()) + runner = WatchRunner( + storage=storage, + node_id="n", + check_interval=0.1, + tool_timeout=5, + restore_fn=restore_fn, + ) + stalled_at = time.monotonic() - RESTORE_STALL_ALERT_SECS - 1 + with runner._restore_lock: + runner._restoring["wedged-1"] = stalled_at + runner._restoring["wedged-2"] = stalled_at # both slots wedged + + with caplog.at_level("ERROR"): + result = runner._dispatch_result("ws-new", {"text": "x"}, "w1") + + assert result is False # wedged capacity stays consumed → defer + restore_fn.assert_not_called() + with runner._restore_lock: + assert "wedged-1" in runner._restoring + assert "wedged-2" in runner._restoring + assert any("watch_runner.restore_admission_wedged" in r.message for r in caplog.records) + + +class TestWatchRunnerConcurrency: + """The tick thread only enumerates due rows; polls run on bounded + daemon threads. Pins: genuine concurrency, per-watch in-flight + dedup, saturation leaving rows due (not dropped), and ``stop`` + draining in-flight polls.""" + + def _make_runner(self, rows: list[dict[str, Any]], **kwargs: Any) -> WatchRunner: + storage = MagicMock() + storage.update_watch.return_value = True + storage.list_due_watches.return_value = rows + return WatchRunner( + storage=storage, + node_id="test-node", + check_interval=0.1, + tool_timeout=5, + **kwargs, + ) + + @staticmethod + def _wait_in_flight_empty(runner: WatchRunner, timeout: float = 3.0) -> None: + def _drained() -> bool: + with runner._in_flight_lock: + return not runner._in_flight + + wait_until(_drained, timeout=timeout) + + def test_tick_polls_concurrently(self): + rows = [_watch_row(watch_id=f"w{i}", ws_id=f"ws-{i}") for i in range(3)] + runner = self._make_runner(rows) + + all_in = threading.Event() + release = threading.Event() + barrier = threading.Barrier(3) + + def fake_poll(_row: dict[str, Any]) -> None: + # All three poll threads must be inside simultaneously for the + # barrier to trip — serial execution would deadlock here (and + # fail via the barrier timeout instead). + barrier.wait(timeout=2.0) + all_in.set() + release.wait(timeout=2.0) + + runner._poll_watch = fake_poll # type: ignore[method-assign] + runner._tick() + + assert all_in.wait(timeout=2.0), "polls did not run concurrently" + release.set() + self._wait_in_flight_empty(runner) + + def test_tick_skips_in_flight_watch(self): + rows = [_watch_row(watch_id="w0", ws_id="ws-0")] + runner = self._make_runner(rows) + polled: list[str] = [] + runner._poll_watch = lambda row: polled.append(row["watch_id"]) # type: ignore[method-assign] + + # Simulate a slow poll from a previous tick still running. + with runner._in_flight_lock: + runner._in_flight.add("w0") + + runner._tick() + + assert polled == [] + # The foreign in-flight entry was not clobbered by the skip. + with runner._in_flight_lock: + assert "w0" in runner._in_flight + + def test_tick_saturation_leaves_rows_due(self): + rows = [_watch_row(watch_id=f"w{i}", ws_id=f"ws-{i}") for i in range(2)] + runner = self._make_runner(rows, max_concurrent_polls=1) + + started = threading.Event() + release = threading.Event() + polled: list[str] = [] + + def fake_poll(row: dict[str, Any]) -> None: + polled.append(row["watch_id"]) + started.set() + release.wait(timeout=2.0) + + runner._poll_watch = fake_poll # type: ignore[method-assign] + runner._tick() + assert started.wait(timeout=2.0) + + # Only the first row got a slot this tick; the second stays due + # for the next tick rather than being dropped. + assert polled == ["w0"] + release.set() + self._wait_in_flight_empty(runner) + + # Next tick (slot free again) picks up the remaining row. + runner._storage.list_due_watches.return_value = [rows[1]] + runner._tick() + self._wait_in_flight_empty(runner) + assert polled == ["w0", "w1"] + + def test_stop_waits_for_in_flight_polls(self): + rows = [_watch_row(watch_id="w0", ws_id="ws-0")] + runner = self._make_runner(rows) + + started = threading.Event() + release = threading.Event() + + def fake_poll(_row: dict[str, Any]) -> None: + started.set() + release.wait(timeout=3.0) + + runner._poll_watch = fake_poll # type: ignore[method-assign] + runner._tick() + assert started.wait(timeout=2.0) + + stopper = threading.Thread(target=runner.stop, daemon=True) + stopper.start() + # stop() must be draining (poll still pinned), not returned. + time.sleep(0.15) + assert stopper.is_alive(), "stop() returned while a poll was in flight" + + release.set() + stopper.join(timeout=3.0) + assert not stopper.is_alive() + with runner._in_flight_lock: + assert not runner._in_flight diff --git a/tests/test_watch_dispatch.py b/tests/test_watch_dispatch.py index 74d193e7..e964c124 100644 --- a/tests/test_watch_dispatch.py +++ b/tests/test_watch_dispatch.py @@ -54,9 +54,11 @@ def _make_session_for_dispatch(**kwargs: Any) -> ChatSession: return ChatSession(**defaults) -def _register_runner(session: ChatSession) -> tuple[Any, Any]: +def _register_runner(session: ChatSession, wake_fn: Any = None) -> tuple[Any, Any]: """Attach a minimal stub ``WatchRunner`` to *session* and return the ``(runner, dispatch_fn)`` pair captured by ``set_dispatch_fn``. + ``wake_fn`` rides through to ``set_watch_runner`` (default ``None`` + matches the pre-wake wiring most tests here exercise). """ captured: dict[str, Any] = {} @@ -65,7 +67,7 @@ def _register_runner(session: ChatSession) -> tuple[Any, Any]: captured["fn"] = fn runner = _StubRunner() - session.set_watch_runner(runner) + session.set_watch_runner(runner, wake_fn=wake_fn) return runner, captured["fn"] @@ -400,3 +402,216 @@ class TestMetadataPropagation: assert len(snapshot) == 1 _nt, _text, meta = snapshot[0] assert meta is None + + +# --------------------------------------------------------------------------- +# Wake trigger +# --------------------------------------------------------------------------- + + +class TestWakeFn: + """``set_watch_runner``'s optional ``wake_fn`` fires once per enqueued + dispatch — AFTER the entry lands — so a watch firing on an + already-idle workstream (no IDLE transition for the + ``IdleNudgeWatcher`` to observe) can spawn the wake worker that + drains it. Failures are contained: the enqueue must survive a + raising ``wake_fn``, because a propagated raise would abort + ``WatchRunner._poll_watch`` before the watch-row update commits and + re-fire the same reminder every subsequent tick. + """ + + def test_wake_fn_called_after_enqueue(self, tmp_db): + session = _make_session_for_dispatch() + depth_at_wake: list[int] = [] + _runner, dispatch = _register_runner( + session, wake_fn=lambda: depth_at_wake.append(len(session._nudge_queue)) + ) + + dispatch(_reminder("watch fired body"), "watch-1") + + # Fired exactly once, and the entry was already queued when it ran + # — the wake worker's drain must be able to see the fresh entry. + assert depth_at_wake == [1] + + def test_wake_fn_not_called_when_payload_sanitizes_empty(self, tmp_db): + """A fire whose payload strips to nothing enqueues nothing — and + must not wake anything either (a wake with an empty queue would + just spawn a worker that no-ops at the drain guard).""" + session = _make_session_for_dispatch() + wake = MagicMock() + _runner, dispatch = _register_runner(session, wake_fn=wake) + + dispatch(_reminder("\x07\x0b\x7f"), "watch-1") + + assert len(session._nudge_queue) == 0 + wake.assert_not_called() + + def test_wake_fn_exception_is_contained(self, tmp_db, caplog): + session = _make_session_for_dispatch() + wake = MagicMock(side_effect=RuntimeError("boom")) + _runner, dispatch = _register_runner(session, wake_fn=wake) + + with caplog.at_level("WARNING"): + dispatch(_reminder("body"), "watch-1") # must not raise + + # Entry survived; the failure surfaced as a warning, not a raise + # up into the poll loop. + assert len(session._nudge_queue) == 1 + assert any("watch_dispatch.wake_failed" in r.message for r in caplog.records), ( + "expected a watch_dispatch.wake_failed warning record" + ) + + +class _RecordingRunner: + """Stub WatchRunner recording registration/removal order. Mirrors the + production owner-checked removal semantics — the resume tail passes + ``owner`` and peeks ``get_dispatch_fn`` before re-registering.""" + + def __init__(self) -> None: + self.events: list[tuple[str, str]] = [] + self.fns: dict[str, Any] = {} + + def set_dispatch_fn(self, ws_id: str, fn: Any) -> None: + self.events.append(("set", ws_id)) + self.fns[ws_id] = fn + + def get_dispatch_fn(self, ws_id: str) -> Any: + return self.fns.get(ws_id) + + def remove_dispatch_fn(self, ws_id: str, owner: Any = None) -> None: + if owner is not None and self.fns.get(ws_id) is not owner: + return + self.events.append(("remove", ws_id)) + self.fns.pop(ws_id, None) + + +class TestResumeReRegistration: + """A non-fork ``resume()`` rebinds ``_ws_id``; the dispatch + registration must FOLLOW that identity — otherwise watches stamped + with the adopted id never find the live session, and every fire + takes the restore path, spawning a duplicate auto-approved session + racing writes into the same conversation (CLI ``--resume`` and the + ``/resume`` command both hit this).""" + + def _saved_ws(self, ws_id: str) -> None: + from turnstone.core.memory import register_workstream, save_message + + register_workstream(ws_id) + save_message(ws_id, "user", "hi") + + def test_nonfork_resume_moves_registration_to_adopted_id(self, tmp_db): + self._saved_ws("resume-target") + session = _make_session_for_dispatch() + old_id = session._ws_id + runner = _RecordingRunner() + session.set_watch_runner(runner, wake_fn=None) + + assert session.resume("resume-target") is True + + # New key live BEFORE the old key is removed — a fire during the + # transition can never observe an empty registry (which would + # divert it to the restore path). + assert runner.events == [ + ("set", old_id), + ("set", "resume-target"), + ("remove", old_id), + ] + assert set(runner.fns) == {"resume-target"} + + def test_fork_resume_keeps_registration(self, tmp_db): + self._saved_ws("fork-src") + session = _make_session_for_dispatch() + old_id = session._ws_id + runner = _RecordingRunner() + session.set_watch_runner(runner, wake_fn=None) + + assert session.resume("fork-src", fork=True) is True + + # Fork keeps its own identity — registration untouched. + assert runner.events == [("set", old_id)] + + def test_resume_without_runner_is_noop(self, tmp_db): + # CLI --resume / restore-fn shape: resume() runs BEFORE any + # set_watch_runner call — nothing to re-register, nothing raises. + self._saved_ws("resume-bare") + session = _make_session_for_dispatch() + + assert session.resume("resume-bare") is True + assert session._watch_runner is None + + def test_reregistered_closure_keeps_wake_fn(self, tmp_db): + # The stored wake_fn rides the re-registration: a watch firing on + # the ADOPTED id must still wake the workstream. + self._saved_ws("resume-wake") + session = _make_session_for_dispatch() + runner = _RecordingRunner() + wake = MagicMock() + session.set_watch_runner(runner, wake_fn=wake) + + assert session.resume("resume-wake") is True + + runner.fns["resume-wake"](_reminder("watch output"), "w1") + assert len(session._nudge_queue) == 1 + wake.assert_called_once() + + def test_resume_does_not_steal_another_live_registration(self, tmp_db): + # In-session /resume of a workstream that is OPEN IN ANOTHER PANE + # (a degenerate two-live-sessions state): the original owner keeps + # its watch fires — the adopter neither clobbers the target's + # registration nor (on a later resume-away or close) deletes it. + self._saved_ws("shared-A") + self._saved_ws("other-C") + runner = _RecordingRunner() + + pane_a = _make_session_for_dispatch() + pane_a._ws_id = "shared-A" # pane A opened A and registered + pane_a.set_watch_runner(runner, wake_fn=None) + fn_a = runner.fns["shared-A"] + + pane_b = _make_session_for_dispatch() + pane_b.set_watch_runner(runner, wake_fn=None) + + assert pane_b.resume("shared-A") is True + # Pane A's registration survived the adoption… + assert runner.fns["shared-A"] is fn_a + + assert pane_b.resume("other-C") is True + # …and the resume-away removed only pane B's own (absent) claim. + assert runner.fns["shared-A"] is fn_a + assert "other-C" in runner.fns + + def test_new_command_moves_registration_to_fresh_id(self, tmp_db): + # /new is the other identity rebind: watches created AFTER it stamp + # the fresh id and must reach this session, while the old + # workstream's fires must stop landing in a conversation that no + # longer shows them (they divert to the restore path instead). + session = _make_session_for_dispatch() + old_id = session._ws_id + runner = _RecordingRunner() + session.set_watch_runner(runner, wake_fn=None) + + # handle_command's return means "should exit" — /new never exits. + assert session.handle_command("/new") is False + + assert session._ws_id != old_id + assert set(runner.fns) == {session._ws_id} + assert ("remove", old_id) in runner.events + + def test_close_removes_only_own_registration(self, tmp_db): + # A watch-restore shell and a reopened pane can serve one ws_id in + # sequence; the shell's later teardown must not unregister the pane. + self._saved_ws("shared-W") + runner = _RecordingRunner() + + shell = _make_session_for_dispatch() + shell._ws_id = "shared-W" + shell.set_watch_runner(runner, wake_fn=None) + + pane = _make_session_for_dispatch() + pane._ws_id = "shared-W" + pane.set_watch_runner(runner, wake_fn=None) # pane re-registers (last writer) + pane_fn = runner.fns["shared-W"] + + shell.close() # shell reaped (close_idle / eviction) + + assert runner.fns.get("shared-W") is pane_fn # pane still registered diff --git a/tests/test_watch_integration.py b/tests/test_watch_integration.py index ac16e54c..bc924214 100644 --- a/tests/test_watch_integration.py +++ b/tests/test_watch_integration.py @@ -340,8 +340,8 @@ def test_poll_watch_terminal_fire_survives_drain( monkeypatch.setattr(session._nudge_queue, "enqueue", _spy_enqueue) # For the max_polls=1 case the first poll has prev_output=None and - # would not normally fire on output change; the max_polls branch - # at watch.py:412-414 still marks is_final=True so dispatch runs. + # would not normally fire on output change; _poll_watch's max_polls + # branch still marks is_final=True so dispatch runs. due = storage.list_due_watches("2099-01-01T00:00:00") matching = [r for r in due if r["watch_id"] == f"w-regression-{label}"] assert len(matching) == 1, f"watch row not picked up by list_due_watches: {due!r}" diff --git a/turnstone/api/server_schemas.py b/turnstone/api/server_schemas.py index 6cec7960..b81a98ae 100644 --- a/turnstone/api/server_schemas.py +++ b/turnstone/api/server_schemas.py @@ -224,6 +224,17 @@ class CreateWorkstreamResponse(BaseModel): "/v1/api/workstreams/{ws_id}/send." ), ) + initial_message_status: str | None = Field( + default=None, + description=( + "Present ONLY when the workstream was created but its " + "initial_message could not be delivered: 'queue_full' (a raced " + "live worker's interjection queue was at capacity — resend via " + "/send; any uploads stay staged) or 'refused_closed' (the " + "workstream was closed mid-create). Absent whenever the message " + "was dispatched." + ), + ) class CloseWorkstreamRequest(BaseModel): diff --git a/turnstone/core/adapters/_ui_cleanup.py b/turnstone/core/adapters/_ui_cleanup.py index 49d9ebbe..258e9d40 100644 --- a/turnstone/core/adapters/_ui_cleanup.py +++ b/turnstone/core/adapters/_ui_cleanup.py @@ -23,12 +23,28 @@ if TYPE_CHECKING: def cleanup_session_ui(ws: Workstream) -> None: """Shared SessionKindAdapter cleanup_ui implementation. - Unblocks pending approval / plan / foreground events on the - workstream's UI, broadcasts ``ws_closed`` to per-UI listener - queues, then cancels + closes the session. The ``hasattr`` checks - guard stub UIs used in tests — the real ``WebUI`` / + Marks the workstream object dead (``ws._closed``) FIRST, under + ``ws._lock``, then unblocks pending approval / plan / foreground + events on the workstream's UI, broadcasts ``ws_closed`` to per-UI + listener queues, and cancels + closes the session. The ``hasattr`` + checks guard stub UIs used in tests — the real ``WebUI`` / ``ConsoleCoordinatorUI`` always have these attributes. + + The flag write lives HERE because every teardown path funnels + through this function — ``close``, ``close_idle``, EVICTION, + ``delete``, ``discard`` — and per-path writes are not enough: a + flag set by only some paths, or set after this teardown body, + leaves windows where the workstream is being torn down while + still reading as live. The wake paths that hold OBJECT + references (the watch ``wake_fn``, ``session_worker``'s exit + backstop) gate on this flag, and ``session_worker.send`` + re-checks it under the same lock: once this write lands, no wake + can spawn a worker on the torn-down session — including on + evicted or deleted workstreams, and including during the + remainder of this teardown. """ + with ws._lock: + ws._closed = True if ws.session is not None and hasattr(ws.session, "cancel"): ws.session.cancel() ui = ws.ui diff --git a/turnstone/core/idle_nudge_watcher.py b/turnstone/core/idle_nudge_watcher.py index 8b940bf9..47a78a91 100644 --- a/turnstone/core/idle_nudge_watcher.py +++ b/turnstone/core/idle_nudge_watcher.py @@ -1,8 +1,18 @@ -"""Idle wake-trigger for the metacog NudgeQueue pipeline. +"""Idle wake-triggers for the metacog NudgeQueue pipeline. -Hosts :class:`IdleNudgeWatcher` plus the -:func:`install_idle_nudge_watcher` / :func:`shutdown_idle_nudge_watchers` -lifespan helpers. Pulled out of :mod:`turnstone.core.metacognition` +Hosts the two wake entry points plus their lifespan helpers: + +* :class:`IdleNudgeWatcher` — event-driven: a workstream transitions + to IDLE while nudges are ALREADY queued. +* :func:`wake_workstream_if_pending` — the shared wake gate, also + called directly by asynchronous producers that enqueue onto an + ALREADY-idle workstream (the watch dispatch closure, via + ``ChatSession.set_watch_runner``'s ``wake_fn``). Such producers see + no IDLE transition — the workstream has been idle all along — so + the watcher alone would leave their entries queued until the next + user message. + +Pulled out of :mod:`turnstone.core.metacognition` because the watcher is subscriber-lifecycle / runtime-orchestration code with different concerns from the static nudge-text templates and detection heuristics that live in metacognition; mixing them grew the @@ -23,25 +33,110 @@ if TYPE_CHECKING: from collections.abc import Callable from turnstone.core.session_manager import SessionManager + from turnstone.core.workstream import Workstream log = get_logger(__name__) +def wake_workstream_if_pending(ws: Workstream, *, trigger: str = "unspecified") -> bool: + """Spawn a wake send for *ws* when it is idle with drainable nudges. + + The shared gate behind both wake triggers: + + * :class:`IdleNudgeWatcher` — the workstream just transitioned to + IDLE with nudges already queued. + * the watch dispatch closure (``ChatSession.set_watch_runner``'s + ``wake_fn``) — a watch fired on a workstream that is ALREADY + idle, so no IDLE transition will ever re-check the queue. + + *trigger* is a short label naming which path requested the wake + (``"idle-transition"``, ``"watch-fire"``, ``"worker-exit"``); it is + used only to tag the log lines below and never affects control flow. + + Gates, in order: + + * ``ws.session is None`` — workstream tracked but session not + built — or a bare stub session without a NudgeQueue (watch-style + dispatchers drive sessions that aren't installed on the + workstream). + * ``ws._closed`` — ``close()`` already ran (or is racing us); its + storage row says ``closed`` and a wake send would drive a + torn-down session. Lockless FAST-PATH only: a stale ``False`` + falls through to ``session_worker.send``, which re-checks + ``_closed`` under ``ws._lock`` — the same lock ``close()`` sets + it under — and refuses, so a wake racing a close can never spawn + a worker on the torn-down session. + * ``ws.state is not IDLE`` — a busy workstream's worker drains the + queue at its own seams (``ATTENTION``/``THINKING``/``RUNNING`` + all imply a live worker), and ``ERROR`` stays parked for the + operator rather than burning inference unattended. + * nothing drainable under ``USER_DRAIN`` — tool-only entries + belong to the next tool-result seam, not a synthetic empty user + turn (``deliver_wake_nudge_from_queue`` would no-op on them). + + Past the gates, exactly one info line is emitted per call: + + * ``nudge_wake.deferred_worker_busy`` — the reuse-path drop: a + worker owned the workstream, so ``session_worker.send`` called + the no-op ``enqueue`` instead of spawning. The entry stays + queued; the owning worker's exit backstop (or its next drain + seam) delivers it. + * ``nudge_wake.dispatched`` — a fresh wake daemon was spawned. + + Returns ``True`` iff the wake was handed to + ``session_worker.send`` — which may still downgrade it to a no-op + enqueue when a worker owns the workstream (see the race-semantics + section on :class:`IdleNudgeWatcher`). + """ + session = ws.session + if session is None or ws._closed or ws.state is not WorkstreamState.IDLE: + return False + nudge_queue = getattr(session, "_nudge_queue", None) + if nudge_queue is None or not nudge_queue.has_pending(USER_DRAIN): + return False + + deferred = False + + def _noop_enqueue() -> None: + nonlocal deferred + deferred = True + + ok = session_worker.send( + ws, + enqueue=_noop_enqueue, + run=session.deliver_wake_nudge_from_queue, + thread_name=f"wake-nudge-{ws.id[:8]}", + ) + if deferred: + log.info("nudge_wake.deferred_worker_busy ws=%s trigger=%s", ws.id[:8], trigger) + elif ok: + log.info("nudge_wake.dispatched ws=%s trigger=%s", ws.id[:8], trigger) + return ok + + class IdleNudgeWatcher: """Convert a workstream IDLE transition into a wake send when the session has queued nudges. Subscribes to :meth:`SessionManager.subscribe_to_state` and listens - for ``WorkstreamState.IDLE``. If the workstream's + for ``WorkstreamState.IDLE``, then defers to + :func:`wake_workstream_if_pending` (the shared gate — see its + docstring for the full gate order). If the workstream's :class:`NudgeQueue` has any drainable entry for the wake's drain - filter (``USER_DRAIN`` — channels ``"user"`` or ``"any"``), - dispatches via ``session_worker.send`` with a no-op ``enqueue`` - callback. Tool-only entries don't fire the wake — they belong to - the next tool-result seam, not a synthetic empty user turn — - otherwise every IDLE event with a queued tool advisory would spawn - a wake daemon that immediately no-ops at + filter (``USER_DRAIN`` — channels ``"user"`` or ``"any"``), the + gate dispatches via ``session_worker.send`` with a no-op + ``enqueue`` callback. Tool-only entries don't fire the wake — + they belong to the next tool-result seam, not a synthetic empty + user turn — otherwise every IDLE event with a queued tool advisory + would spawn a wake daemon that immediately no-ops at ``deliver_wake_nudge_from_queue``'s drain guard. + This watcher only covers nudges that are already queued when the + IDLE transition fires. Producers that enqueue asynchronously onto + an already-idle workstream (watch fires) call + :func:`wake_workstream_if_pending` themselves — there is no state + transition for this watcher to observe in that case. + **Race semantics.** ``session_worker.send`` decides atomically under ``ws._lock`` whether a worker thread already owns the workstream. Three outcomes: @@ -51,10 +146,17 @@ class IdleNudgeWatcher: drains its own queue and runs the synthetic empty-user turn). * Worker running → call our ``enqueue`` lambda, which is a no-op. The wake is silently dropped; the queued nudge stays in - ``NudgeQueue`` and the in-flight worker picks it up at its next - user-message-attach or tool-result seam (whichever fires first - for the entry's channel). This is the load-bearing fallback — - we never spawn a competing worker. + ``NudgeQueue``. We never spawn a competing worker. This branch + is the COMMON case for IDLE-transition wakes, not the exception: + ``set_state`` subscribers fire on the calling thread, and IDLE + is emitted from inside ``run()`` at the end of a send — so the + transitioning worker still owns the flag while this watcher + dispatches. Delivery is then owed to one of two follow-ups: + the in-flight worker's next drain seam (when IDLE fired + mid-turn), or — for the end-of-send case, where no later seam + exists — ``session_worker``'s ownership-clear backstop + (``_retry_pending_wake``), which re-runs + :func:`wake_workstream_if_pending` the moment the worker exits. * Workstream gone (``ws is None``) or session not built (``ws.session is None``) → bail. @@ -82,17 +184,9 @@ class IdleNudgeWatcher: if state is not WorkstreamState.IDLE: return ws = self._manager.get(ws_id) - if ws is None or ws.session is None: + if ws is None: return - session = ws.session - if not session._nudge_queue.has_pending(USER_DRAIN): - return - session_worker.send( - ws, - enqueue=lambda: None, - run=session.deliver_wake_nudge_from_queue, - thread_name=f"wake-nudge-{ws.id[:8]}", - ) + wake_workstream_if_pending(ws, trigger="idle-transition") self._callback = _on_state self._manager.subscribe_to_state(_on_state) diff --git a/turnstone/core/session.py b/turnstone/core/session.py index 68e9df81..06bef381 100644 --- a/turnstone/core/session.py +++ b/turnstone/core/session.py @@ -191,7 +191,7 @@ from turnstone.ui.colors import DIM, GRAY, GREEN, RED, RESET, YELLOW, bold, cyan log = get_logger(__name__) if TYPE_CHECKING: - from collections.abc import Iterable, Iterator + from collections.abc import Callable, Iterable, Iterator from turnstone.core.config_store import ConfigStore from turnstone.core.healthcheck import BackendHealthTracker, HealthTrackerRegistry @@ -1485,6 +1485,16 @@ class ChatSession: self._notify_count = 0 # Watch support: server-level runner injected via set_watch_runner() self._watch_runner: Any = None # WatchRunner | None + # The wake_fn last passed to set_watch_runner, kept so a non-fork + # resume() can re-register the dispatch closure under the adopted + # ws_id with the same wake wiring (registration follows identity). + self._watch_wake_fn: Callable[[], object] | None = None + # The dispatch closure this session last registered — the OWNER + # token for registry removals: multiple live sessions can + # transiently serve one ws_id (watch-restore shell vs a reopened + # pane; in-session /resume of an id open in another pane), and a + # blind removal on teardown would unregister the OTHER session. + self._watch_dispatch_fn: Callable[[dict[str, Any], str], None] | None = None # Metacognitive nudges: ephemeral prompts for proactive memory use. # One ``NudgeQueue`` per session; producers tag each entry with a # channel and consumers drain by filter, emitting each drained nudge @@ -2823,7 +2833,7 @@ class ChatSession: else: self._tool_search = None - def set_watch_runner(self, runner: Any) -> None: + def set_watch_runner(self, runner: Any, wake_fn: Callable[[], object] | None = None) -> None: """Inject the server-level WatchRunner and register a dispatch fn that routes watch results onto this session's NudgeQueue. @@ -2842,14 +2852,37 @@ class ChatSession: sourced from arbitrary shell output can't tamper with the envelope at interpolation time. + ``wake_fn`` runs once per enqueued fire, AFTER the entry lands + on the queue. The server wires it to + :func:`turnstone.core.idle_nudge_watcher.wake_workstream_if_pending` + closed over this session's Workstream: a watch firing on an + ALREADY-idle workstream sees no IDLE transition, so without an + explicit wake the entry would sit queued until the next user + message. Busy workstreams stay safe — the wake gate defers to + ``session_worker.send``'s atomic ownership check, which + downgrades the wake to a no-op while a worker owns the session + (the in-flight worker drains the ``"any"``-channel entry at its + next seam). Exceptions from ``wake_fn`` are logged and + swallowed: the enqueue already happened, and a raise here would + abort ``WatchRunner._poll_watch`` before the watch-row update + commits — re-firing the same reminder every subsequent tick. + No ``valid_until`` predicate is wired: ``WatchRunner._poll_watch`` commits ``active=False`` for terminal fires right after dispatch returns, and an ``is_watch_active`` predicate would race that write at drain time and drop the fire the model was meant to see. A user-cancelled watch's last splat is informative (the reminder carries ``is_final=True``), not stale-noise to suppress. + + The registration is keyed on ``self._ws_id`` AT CALL TIME. The + identity-rebind sites (non-fork :meth:`resume`, ``/new``) call + :meth:`_follow_watch_registration` to move it onto the new id + (re-invoking this method with the ``wake_fn`` stored below) — + callers therefore don't need to order their own + ``set_watch_runner``/``resume`` calls. """ self._watch_runner = runner + self._watch_wake_fn = wake_fn nudge_queue = self._nudge_queue ws_id = self._ws_id @@ -2892,7 +2925,13 @@ class ChatSession: "any", metadata=metadata or None, ) + if wake_fn is not None: + try: + wake_fn() + except Exception: + log.warning("watch_dispatch.wake_failed ws=%s", ws_id, exc_info=True) + self._watch_dispatch_fn = _dispatch runner.set_dispatch_fn(self._ws_id, _dispatch) def close(self) -> None: @@ -2929,8 +2968,12 @@ class ChatSession: self._mcp_prompt_cb, user_id=self._mcp_listener_user_id ) self._mcp_prompt_cb = None - if self._watch_runner: - self._watch_runner.remove_dispatch_fn(self._ws_id) + if self._watch_runner and self._watch_dispatch_fn is not None: + # Owner-checked: a watch-restore shell and a reopened pane can + # both have served this ws_id — tearing down one must not + # unregister the other (whose next fire would then restore a + # DUPLICATE auto-approved session onto the live conversation). + self._watch_runner.remove_dispatch_fn(self._ws_id, owner=self._watch_dispatch_fn) if self._coord_client is not None and hasattr(self._coord_client, "close"): try: self._coord_client.close() @@ -3369,6 +3412,9 @@ class ChatSession: turns = load_message_turns(ws_id) if not turns: return False + # Pre-rebind identity, for moving the watch dispatch registration + # onto the adopted id at the end of a successful non-fork resume. + old_ws_id = self._ws_id # Load persisted config and parse the persona stamp BEFORE touching # session identity/history: a corrupt stamp must raise while this # session is still intact — the web /command surface reports the @@ -3585,9 +3631,42 @@ class ChatSession: cooldown_secs=self._mem_cfg.nudge_cooldown, ): self._queue_user_advisory("resume", format_nudge("resume")) + if not fork: + self._follow_watch_registration(old_ws_id) self._init_system_messages() return True + def _follow_watch_registration(self, old_ws_id: str) -> None: + """Move the watch dispatch registration onto the current + ``_ws_id`` after an identity rebind (non-fork :meth:`resume`, + ``/new``). + + The registry is keyed by ``_ws_id`` at registration time. + Without the move, watches stamped with the NEW id never find + this live session — every fire takes the restore path and + spawns a DUPLICATE auto-approved session racing writes into the + same conversation — while fires for the OLD id keep delivering + into a session that no longer displays that conversation. The + new key goes live BEFORE the old one is removed so no fire can + observe a window with no registration at all (which would + likewise divert to the restore path). If ANOTHER live session + already serves the new id (in-session /resume of a workstream + open in a second pane — an inherently degenerate two-writers + state), its registration is NOT stolen: the original owner + keeps its watch fires. Removal of the old key is owner-checked + for the same reason. + """ + if self._watch_runner is None: + return + old_fn = self._watch_dispatch_fn + existing = self._watch_runner.get_dispatch_fn(self._ws_id) + if existing is None or existing is old_fn: + self.set_watch_runner(self._watch_runner, wake_fn=self._watch_wake_fn) + else: + log.warning("watch_registry.adopted_id_owned_elsewhere ws=%s", self._ws_id[:8]) + if old_ws_id != self._ws_id: + self._watch_runner.remove_dispatch_fn(old_ws_id, owner=old_fn) + def _nudges_enabled(self, nudge_type: str) -> bool: """Config gate + persona lever 4 for metacognitive nudges. @@ -6023,8 +6102,9 @@ class ChatSession: # Operator context for this result: output-guard # findings + queued user messages (Seam 1), plus - # tool-channel metacog nudges (tool_error / repeat) and - # any-channel nudges (watch_triggered / idle_children). + # tool-channel metacog nudges (tool_error / repeat / + # denial) and any-channel nudges (watch_triggered / + # idle_children). # All of them are now emitted as first-class # ``{"role": "system"}`` turns AFTER this clean tool # message (uniform attach rule) — the tool message content @@ -6239,10 +6319,11 @@ class ChatSession: def _drain_pending_advisories(self) -> None: """Drop every pending nudge regardless of channel. - Tool-channel nudges (``tool_error``, ``repeat``) queued earlier - in this batch and user-channel nudges (``correction``, - ``denial``, …) queued during ``_check_metacognitive_nudge`` but - not yet drained share the same per-session :class:`NudgeQueue`. + Tool-channel nudges (``tool_error``, ``repeat``, ``denial``) + queued earlier in this batch and user-channel nudges + (``correction``, …) queued during ``_check_metacognitive_nudge`` + but not yet drained share the same per-session + :class:`NudgeQueue`. When a generation is abandoned (cancel, KeyboardInterrupt, unexpected exception) the entire queue drops so nothing bleeds into the next send's tool loop or next user turn. @@ -8653,10 +8734,11 @@ class ChatSession: ``priority`` so the UI can frame important interjections distinctly. Cancel / exception / no-tool-call paths drain the queue as a real user row instead (Seams 2 and 3). - - **Metacognitive tool-channel nudges** (``tool_error`` / ``repeat``) - and any-channel nudges (``watch_triggered`` / ``idle_children``) - — drained on the last result. ``meta`` carries the producer's - optional fields (e.g. ``watch_triggered``'s ``watch_name``). + - **Metacognitive tool-channel nudges** (``tool_error`` / + ``repeat`` / ``denial``) and any-channel nudges + (``watch_triggered`` / ``idle_children``) — drained on the last + result. ``meta`` carries the producer's optional fields + (e.g. ``watch_triggered``'s ``watch_name``). Empty when no advisories apply (common case). Guard findings attach per-result; queued messages and metacognitive nudges drain @@ -8867,7 +8949,13 @@ class ChatSession: memory_count=self._visible_memory_count(), cooldown_secs=self._mem_cfg.nudge_cooldown, ): - self._queue_user_advisory("denial", format_nudge("denial")) + # Tool channel, not user: the denial is a response to THIS + # batch, so the nudge rides ``_collect_advisories`` alongside + # the denied tool results (same seam as tool_error / repeat) + # instead of deferring to the next user-message seam — by + # which point the model has already reacted to the denial + # without it. + self._queue_tool_advisory("denial", format_nudge("denial")) # Phase 3: execute (check cancellation before starting) self._check_cancelled() @@ -10599,8 +10687,10 @@ class ChatSession: Drains in ``_emit_pending_user_nudges`` and is appended as a first-class ``{"role": "system"}`` turn AFTER the user turn. Used - for nudges that respond to user behaviour: ``correction``, - ``denial``, ``resume``, ``start``, ``completion``. + for nudges that respond to the user's message: ``correction``, + ``resume``, ``start``, ``completion``. (``denial`` is user + behaviour too, but it responds to a specific TOOL BATCH — it + rides the tool channel so it lands with the denied results.) No-ops while the session is inside a wake-driven turn (``_wake_source_tag`` set) so model behaviour during the wake @@ -10624,8 +10714,8 @@ class ChatSession: the system turns sit after the user turn they advise (uniform attach rule). Each drained nudge becomes one ``{"role": "system", "_source": , ...}`` turn via :meth:`_append_system_turn` - — the source is the nudge type (``correction`` / ``denial`` / - ``resume`` / ``start`` / ``completion`` / ``idle_children`` / + — the source is the nudge type (``correction`` / ``resume`` / + ``start`` / ``completion`` / ``idle_children`` / ``watch_triggered``) and any optional metadata (e.g. ``watch_triggered``'s ``watch_name``) rides as sibling keys. ``_append_system_turn`` persists each row and fires the live @@ -10662,8 +10752,9 @@ class ChatSession: Drains in ``_collect_advisories`` alongside guard findings, then is emitted as a first-class ``{"role": "system"}`` turn AFTER the tool batch (see the per-result loop in ``_run_loop``). Used for nudges - that respond to model behaviour at a tool boundary: ``tool_error``, - ``repeat``. + that respond to a tool batch: ``tool_error``, ``repeat`` (model + behaviour), and ``denial`` (the operator rejected the batch — the + nudge belongs next to the denied results it explains). No-ops while the session is inside a wake-driven turn (see ``_queue_user_advisory`` for the rationale). @@ -10723,6 +10814,14 @@ class ChatSession: self._wake_drained_reminders = wake_reminders try: self.send("", from_wake=True) + except GenerationCancelled: + # A close/force-cancel raced this unattended wake turn. This + # method IS the wake worker's run() closure, and + # ``session_worker._runner`` catches only ``Exception`` — a + # BaseException here would escape to ``threading.excepthook`` + # as stderr noise. The teardown gates stop any respawn; the + # cancellation itself is the intended outcome. + log.info("wake_nudge.cancelled ws=%s", self._ws_id[:8]) finally: self._wake_source_tag = "" self._wake_drained_reminders = None @@ -15882,15 +15981,22 @@ class ChatSession: # view (already-inactive or just-cancelled with empty # next_poll), so the runner's retry-deactivate branch will # never reclaim a pending ``_terminal_dispatched`` entry. - # Clear it here to bound the lifetime of any leftover from - # a previous dispatch-then-failed-row-write. - if self._watch_runner is not None: - self._watch_runner.forget_terminal_dispatched(target["watch_id"]) + # Clear it via ``forget_terminal_dispatched`` to bound the + # lifetime of any leftover from a previous + # dispatch-then-failed-row-write — AFTER the row write, per + # that method's ordering contract: the runner's delivery + # paths re-check the row before stashing, so clearing first + # would let a racing poll thread re-stash a held reminder + # behind the clear. if not target["active"]: + if self._watch_runner is not None: + self._watch_runner.forget_terminal_dispatched(target["watch_id"]) msg = f'Watch "{target["name"]}" already completed (auto-cancelled).' self._report_tool_result(call_id, "watch", msg) return call_id, msg storage.update_watch(target["watch_id"], active=False, next_poll="") + if self._watch_runner is not None: + self._watch_runner.forget_terminal_dispatched(target["watch_id"]) msg = f'Watch "{target["name"]}" cancelled.' self._report_tool_result(call_id, "watch", msg) return call_id, msg @@ -16371,14 +16477,20 @@ class ChatSession: self._last_usage = None self._calibrated_msg_count = 0 self._msg_tokens = [] + old_ws_id = self._ws_id self._ws_id = uuid.uuid4().hex # A brand-new ws_id is the same class of identity change as a # non-fork resume(): the old workstream's participant state must - # not leak into this empty one, and its trust nonces must not - # carry over (see resume()'s matching reset + remint). + # not leak into this empty one, its trust nonces must not carry + # over (see resume()'s matching reset + remint), and the watch + # dispatch registration must follow the identity — otherwise + # watches created here (stamped with the new id) never reach + # this session, and the old workstream's fires land in a + # conversation that no longer shows them. self._reset_shared_state() self._envelope_nonce = fence.mint_nonce() self._sender_label_nonce = fence.mint_nonce() + self._follow_watch_registration(old_ws_id) self._title_generated = False # The session keeps its persona across /new (the stamp is # re-written by _save_config below) — carry the display slug diff --git a/turnstone/core/session_routes.py b/turnstone/core/session_routes.py index da2f0498..30e2a17f 100644 --- a/turnstone/core/session_routes.py +++ b/turnstone/core/session_routes.py @@ -2772,15 +2772,21 @@ def make_create_handler( attachment_ids, ) - return JSONResponse( - { - "ws_id": ws.id, - "name": ws.name, - "resumed": bool(extra_response.get("resumed", False)), - "message_count": int(extra_response.get("message_count", 0)), - "attachment_ids": attachment_ids, - } - ) + create_payload: dict[str, Any] = { + "ws_id": ws.id, + "name": ws.name, + "resumed": bool(extra_response.get("resumed", False)), + "message_count": int(extra_response.get("message_count", 0)), + "attachment_ids": attachment_ids, + } + if extra_response.get("initial_message_status"): + # Present only when the post-install hook could NOT deliver + # the initial message (raced live worker, interjection queue + # full) — the workstream exists, but a bare 200 would read as + # "first message accepted". Mirrors /send's in-body + # ``queue_full`` backpressure surface. + create_payload["initial_message_status"] = str(extra_response["initial_message_status"]) + return JSONResponse(create_payload) return create @@ -3798,6 +3804,27 @@ def make_detail_handler(cfg: SessionEndpointConfig) -> Handler: # mismatch, and tombstoned rows — all surface as 404. return JSONResponse({"error": cfg.not_found_label}, status_code=404) + # A detail GET that lazily rehydrates IS an open — run the + # same kind-specific post-load the open handler runs. + # Skipping it leaves the now-live session with no watch + # dispatch registration (its next watch fire would take the + # restore path and spawn a duplicate auto-approved session + # racing writes into this live conversation) and never tells + # dashboards the workstream came live (``ws_created``). + if cfg.open_post_load is not None: + try: + # Off-loop: interactive's post_load does blocking + # storage I/O (display-name lookup). + await asyncio.to_thread(cfg.open_post_load, request, ws) + except Exception: + # Post-load is observational — never let a hook bug + # block the detail response. Log + continue. + log.debug( + "ws.detail.post_load_failed ws=%s", + ws.id[:8], + exc_info=True, + ) + # Pending-approval snapshot — lets a freshly-loaded chat tab # paint the inline approval gate from this single response # instead of waiting for the SSE approve_request replay (which @@ -4097,6 +4124,12 @@ def make_send_handler(cfg: SessionEndpointConfig) -> Handler: thread_name=f"send-worker-{ws.id[:8]}", ) if not ok: + if ws._closed: + # ``send`` refused because the workstream closed between our + # resolution and the dispatch — a ``queue_full`` here would + # tell the client to retry a workstream whose very next + # resolution 404s. Mirror the resolution miss instead. + return JSONResponse({"error": cfg.not_found_label}, status_code=404) # queue.Full or session-disappeared race — surface as # queue_full so clients retry rather than 500. ``attached_ids`` # is always empty on this path (the dispatch never took diff --git a/turnstone/core/session_worker.py b/turnstone/core/session_worker.py index b60345b2..923b4ddd 100644 --- a/turnstone/core/session_worker.py +++ b/turnstone/core/session_worker.py @@ -18,11 +18,22 @@ with no consumer. The flag transitions atomically inside the same lock this module holds, so both coord and interactive callers inherit the fix. -This module owns ONLY the dispatch decision and the -``_worker_running`` lifecycle. Per-kind concerns — session resolution, +This module owns ONLY the dispatch decision, the ``_worker_running`` +lifecycle, and the ownership-clear wake backstop +(:func:`_retry_pending_wake`). Per-kind concerns — session resolution, attachment resolution, error surfacing, UI callbacks, ``GenerationCancelled`` handling — live in the caller's ``enqueue`` / ``run`` no-arg closures. + +The wake backstop exists because IDLE state fans out from INSIDE +``run()`` (``set_state`` subscribers fire on the calling thread — the +worker that did the transition). Any wake the IDLE fan-out dispatches +(``IdleNudgeWatcher``) therefore lands on the reuse path while this +worker still owns the flag and no-ops; with IDLE emitted at the END of +a send there is no later seam in this worker to drain the queue, so +the nudge would strand until the next user message. Re-running the +wake gate at the exact moment ownership clears is the only spot that +closes the window without ever racing a competing worker. """ from __future__ import annotations @@ -41,6 +52,41 @@ if TYPE_CHECKING: log = get_logger(__name__) +def _retry_pending_wake(ws: Workstream) -> None: + """Deliver nudges that arrived while the exiting worker owned *ws*. + + Runs in the worker's ``finally`` immediately after it cleared + ``_worker_running`` (owner only — abandoned threads skip it). The + canonical strand it closes: the coordinator's ``idle_children`` + nudge, enqueued by ``CoordinatorIdleObserver`` during the IDLE + fan-out at the end of the coord's send — the fan-out runs on the + worker thread, so ``IdleNudgeWatcher``'s wake dispatch hits the + reuse path and no-ops, and nothing else ever re-checks the queue. + The same window covers a watch ``wake_fn`` firing while a worker + is mid-exit. + + The wake gate + (:func:`~turnstone.core.idle_nudge_watcher.wake_workstream_if_pending`) + owns every defensive check — session missing, bare stub without a + NudgeQueue (watch-style dispatchers drive sessions that aren't + installed on the workstream), closed, non-idle, nothing pending — + and its ``session_worker.send`` dispatch is the same atomic spawn + as any other: a successor worker claimed between our flag-clear + and the retry just downgrades the wake to a no-op enqueue again, + and THAT worker's own exit re-runs this backstop. Convergence is + owned by the producers' gates (cooldown, hard caps, ``valid_until`` + predicates): a wake worker whose drain empties the queue retries + once at its own exit, sees nothing pending, and stops. + """ + # Local import: idle_nudge_watcher imports this module at top level. + from turnstone.core.idle_nudge_watcher import wake_workstream_if_pending + + try: + wake_workstream_if_pending(ws, trigger="worker-exit") + except Exception: + log.warning("session_worker.wake_retry_failed ws=%s", ws.id[:8], exc_info=True) + + def send( ws: Workstream, *, @@ -63,10 +109,11 @@ def send( Returns: ``True`` on successful enqueue (existing worker accepted) or thread spawn (no live worker). - ``False`` when ``enqueue`` raises ``queue.Full`` (queue at - capacity — caller surfaces 429) or any other exception - (logged). Falling through to spawn a second worker on a full - queue would corrupt ChatSession state. + ``False`` when the workstream is already closed (see below), or + when ``enqueue`` raises ``queue.Full`` (queue at capacity — + caller surfaces 429) or any other exception (logged). Falling + through to spawn a second worker on a full queue would corrupt + ChatSession state. """ name = thread_name or f"session-worker-{ws.id[:8]}" @@ -85,6 +132,7 @@ def send( # close style signals if the runtime ever delivers them). log.exception("session_worker.uncaught ws=%s", ws.id[:8]) finally: + was_owner = False with ws._lock: # Only clear the flag if THIS thread is still the current # worker. A force-cancel abandons the worker @@ -96,8 +144,23 @@ def send( # spawns a second concurrent worker on the same session. if ws.worker_thread is threading.current_thread(): ws._worker_running = False + was_owner = True + # Outside the lock (the retry's wake dispatch re-acquires it). + # Owner only: an abandoned thread retrying would race the + # successor's own exit backstop for no benefit. + if was_owner: + _retry_pending_wake(ws) with ws._lock: + if ws._closed: + # Authoritative closed-check: ``SessionManager.close`` sets + # ``_closed`` under this same lock, so unlike the wake gate's + # lockless peek this read cannot go stale. Without it, a + # wake (or send) racing ``close()`` spawns a worker that runs + # a full unattended turn — inference, tool calls, storage + # writes — on a workstream whose ``ws_closed`` already fired. + log.info("session_worker.closed_refused ws=%s", ws.id[:8]) + return False if ws._worker_running: try: enqueue() diff --git a/turnstone/core/watch.py b/turnstone/core/watch.py index 8f6f2f2d..7c2caae0 100644 --- a/turnstone/core/watch.py +++ b/turnstone/core/watch.py @@ -13,6 +13,7 @@ import json import re import subprocess import threading +import time from datetime import UTC, datetime, timedelta from typing import TYPE_CHECKING, Any @@ -33,6 +34,49 @@ MIN_INTERVAL = 10 # seconds MAX_INTERVAL = 86_400 # 24 hours DEFAULT_MAX_POLLS = 100 MAX_OUTPUT_SIZE = 65_536 # truncate stored/dispatched output at 64 KB +# Cap on delivery re-attempts for a fire whose workstream can't be +# reached (evicted + transiently unrestorable — all restore slots busy). +# On exhaustion the held reminder is dropped and one poll is charged to +# the watch's own ``max_polls`` budget: with budget left the watch stays +# ACTIVE and the fire cycle repeats on its normal cadence; with the +# budget spent it deactivates (loudly) — so a persistently unreachable +# workstream can never re-run its command forever. A PERMANENT failure +# (:class:`WatchWorkstreamUnrestorable`, e.g. corrupt persona stamp) +# deactivates immediately without waiting out either budget. +MAX_DELIVERY_ATTEMPTS = 5 +# Cap on the held-reminder retry delay. Re-delivery is a cheap in-memory +# dispatch (never a command re-run), so it retries on a short cadence — +# ``min(interval_secs, this)`` — rather than the watch's own interval: a +# daily watch whose fire hit a busy restore slot must not sit on its +# reminder for 24 h when the cause clears in seconds. +DELIVERY_RETRY_CAP_SECS = 60 +# Cap on concurrent restore paths in flight across the poll pool. Kept +# below ``max_concurrent_polls`` so a burst of evicted-workstream fires +# can never occupy every poll slot on slow restores (leaving normal polls +# unserved) and can't drain the shared DB connection pool. A poll that +# would exceed the cap DEFERS (holds its reminder, releases its slot) +# instead of blocking. +MAX_CONCURRENT_RESTORES = 2 +# Age past which an in-flight restore's admission entry is presumed +# wedged inside ``restore_fn`` and ALERTED on (error log at every +# refused admission). Ten minutes exceeds every configured storage / +# MCP timeout by an order of magnitude, so a genuine restore never +# trips it. Deliberately detection-ONLY — the entry is never evicted: +# the wedged poll thread's pool slot is never released, so reclaiming +# its admission would just readmit a restore that can wedge ANOTHER +# pool thread on the same cause, converting this capped degraded state +# (restores blocked, normal polling intact) into total poll-pool +# collapse, one slot per threshold period. Recovery from a genuine +# wedge is a process restart; the loud log is what tells the operator. +RESTORE_STALL_ALERT_SECS = 600.0 +# Cap on ``stop()``'s in-flight-poll drain. Shutdown runs under an +# external deadline (systemd's stop timeout defaults to 90 s), and the +# teardown steps AFTER the watch runner — state-writer drain, node +# deregistration — must still get their turn, so the drain waits +# ``min(tool_timeout, this) + 5`` rather than a full ``tool_timeout`` +# (default 120 s). An abandoned poll is loud and safe: its row stays +# due and re-polls on the next boot. +STOP_DRAIN_CAP_SECS = 30.0 # Safe builtins exposed to condition expressions. _SAFE_BUILTINS: dict[str, Any] = { @@ -258,6 +302,11 @@ def build_watch_reminder( } +def _iso_in(seconds: float) -> str: + """``now + seconds`` in the storage layer's naive-UTC second format.""" + return (datetime.now(UTC) + timedelta(seconds=seconds)).strftime("%Y-%m-%dT%H:%M:%S") + + def format_interval(secs: float) -> str: """Human-readable duration (e.g. ``'5m'``, ``'1h30m'``).""" if secs < 60: @@ -276,11 +325,41 @@ def format_interval(secs: float) -> str: # --------------------------------------------------------------------------- +class WatchWorkstreamUnrestorable(Exception): # noqa: N818 + """Raised by a ``restore_fn`` when a watch's workstream can NEVER be + restored (e.g. a corrupt persona stamp the operator must fix), as + opposed to a transient failure (all restore slots busy) which returns + ``None``. Signals :class:`WatchRunner` to stop retrying delivery and + deactivate the watch immediately rather than burning the whole + attempt budget on a cause that can't clear on its own. + """ + + class WatchRunner: """Polls the database for due watches and dispatches results. Runs as a daemon thread in the server process, analogous to ``TaskScheduler`` in the console. + + Poll execution is CONCURRENT and bounded: the tick thread only + enumerates due rows and hands each to a short-lived daemon thread + gated by a semaphore (``max_concurrent_polls``), so one hung + command — itself bounded by ``tool_timeout`` — delays at most one + slot instead of head-of-line blocking every watch on the node. A + per-``watch_id`` in-flight set prevents double-polling rows that + keep appearing in ``list_due_watches`` while their (slow) poll is + still running. When a fire can't reach its workstream, the built + reminder is HELD and re-delivered on a short retry cadence + (``min(interval_secs, DELIVERY_RETRY_CAP_SECS)``, never re-running + the command); transient failures retry up to + :data:`MAX_DELIVERY_ATTEMPTS`, after which one poll is charged to the + watch's ``max_polls`` budget and the fire cycle repeats on its normal + cadence — or, with the budget spent, the watch deactivates loudly. A + permanent :class:`WatchWorkstreamUnrestorable` deactivates it at + once. Restore is admission-controlled (per-ws_id + dedup + a :data:`MAX_CONCURRENT_RESTORES` cap, both without blocking a + poll slot) so two watches on one evicted workstream can't each spawn a + live session and a restore burst can't starve the poll pool. """ def __init__( @@ -290,6 +369,7 @@ class WatchRunner: *, check_interval: float = 15.0, tool_timeout: float = 30.0, + max_concurrent_polls: int = 4, restore_fn: Callable[[str], Callable[[dict[str, Any], str], None] | None] | None = None, ) -> None: self._storage = storage @@ -297,10 +377,48 @@ class WatchRunner: self._check_interval = check_interval self._tool_timeout = tool_timeout self._restore_fn = restore_fn + # Bounded poll concurrency (see class docstring). The slot is + # acquired on the tick thread and released in ``_poll_one``'s + # ``finally``; the in-flight set is keyed by watch_id and holds + # entries for exactly the lifetime of their poll thread. + self._poll_slots = threading.BoundedSemaphore(max_concurrent_polls) + self._in_flight: set[str] = set() + self._in_flight_lock = threading.Lock() self._dispatch_fns: dict[str, Callable[[dict[str, Any], str], None]] = {} self._dispatch_lock = threading.Lock() + # Restore admission control. The restore path (``manager.create`` + # + ``session.resume``) must not run twice for one ws_id, or two + # watches on the same evicted workstream — polled on separate pool + # threads — would each spawn a live auto-approved session racing + # writes into one conversation history. ``_restoring`` tracks the + # ws_ids with a restore in flight; ``_restore_lock`` guards it but + # is held only for the fast admit/reject check, NEVER across the + # slow restore (which would pin the caller's poll slot and starve + # the pool). A poll is admitted only when its ws_id isn't already + # restoring AND fewer than :data:`MAX_CONCURRENT_RESTORES` restores + # are in flight; otherwise it DEFERS (holds its reminder, releases + # its slot) and re-delivers on the capped retry cadence — by which + # point the winning restore has registered a dispatch fn. Values + # are ``time.monotonic()`` admission stamps, used ONLY to alert on + # wedged restores (:data:`RESTORE_STALL_ALERT_SECS`); entries are + # removed solely by their own restore's ``finally``. + self._restoring: dict[str, float] = {} + self._restore_lock = threading.Lock() + + # Held reminders whose delivery failed, keyed by watch_id. Value: + # ``{"reminder", "update_fields", "attempts"}``. Held deliveries + # are always TERMINAL fires (``fired ⟹ is_final``, and reminders + # are only built for final polls), so committing ``update_fields`` + # always deactivates the row. A later tick re-DELIVERS the + # reminder (never re-runs the command, so a transient stop_on + # match survives) up to :data:`MAX_DELIVERY_ATTEMPTS`. Access is + # guarded, though the per-watch_id in-flight gate already + # serialises pollers for a given watch_id. + self._pending_delivery: dict[str, dict[str, Any]] = {} + self._pending_delivery_lock = threading.Lock() + # Watch ids whose terminal reminder has already been dispatched # but whose row write has not yet been confirmed. Populated # between ``_dispatch_result`` and ``update_watch`` in @@ -330,6 +448,31 @@ class WatchRunner: if self._thread is not None: self._thread.join(timeout=self._check_interval + 5) self._thread = None + # Drain in-flight polls so their storage writes land before + # teardown. A poll's command can block up to ``tool_timeout``, so + # bound the wait on THAT (not the tick cadence): a poll that + # started just before ``stop()`` may legitimately still be running + # its command, and a ``check_interval``-based deadline would + # abandon it mid-run and skip its commit. The wait is capped at + # :data:`STOP_DRAIN_CAP_SECS` though — shutdown itself runs under + # an external deadline (systemd stop timeout), and the teardown + # steps queued after us must still run. On the deadline we + # abandon loudly; the daemon threads die with the process and the + # abandoned rows stay due (re-polled on next boot). + deadline = time.monotonic() + min(self._tool_timeout, STOP_DRAIN_CAP_SECS) + 5 + while time.monotonic() < deadline: + with self._in_flight_lock: + if not self._in_flight: + break + time.sleep(0.05) + else: + with self._in_flight_lock: + leftover = len(self._in_flight) + # Only warn on a genuine abandonment — the last poll can drain + # in the same window the deadline is crossed, and a count=0 + # warning would be a false alarm for log-based monitoring. + if leftover: + log.warning("watch_runner.stop_abandoned_polls count=%d", leftover) log.info("watch_runner.stopped") # -- Dispatch function registry ------------------------------------------ @@ -353,8 +496,21 @@ class WatchRunner: with self._dispatch_lock: self._dispatch_fns[ws_id] = fn - def remove_dispatch_fn(self, ws_id: str) -> None: + def remove_dispatch_fn( + self, ws_id: str, owner: Callable[[dict[str, Any], str], None] | None = None + ) -> None: + """Remove the registration for ``ws_id`` — with ``owner`` given, + ONLY if the registered fn IS that closure. Multiple live + sessions can transiently serve one ws_id (a watch-restore shell + vs a reopened pane; an in-session ``/resume`` of an id open in + another pane), and a blind removal from one session's teardown + would silently unregister the OTHER, still-live session — its + next fire would then take the restore path and spawn a duplicate + auto-approved session onto the live conversation. + """ with self._dispatch_lock: + if owner is not None and self._dispatch_fns.get(ws_id) is not owner: + return self._dispatch_fns.pop(ws_id, None) def get_dispatch_fn(self, ws_id: str) -> Callable[[dict[str, Any], str], None] | None: @@ -367,8 +523,9 @@ class WatchRunner: return self._dispatch_fns.get(ws_id) def forget_terminal_dispatched(self, watch_id: str) -> None: - """Discard ``watch_id`` from the pending-terminal-dispatched - set if present. Called by paths that take a watch out of + """Discard ``watch_id`` from the runner's per-watch transient + state (terminal-dispatched set AND any held pending delivery). + Called by paths that take a watch out of :meth:`StorageBackend.list_due_watches` view independent of the runner's own poll (most importantly the user-cancel path in :meth:`ChatSession._exec_watch`). Without this, a @@ -377,10 +534,21 @@ class WatchRunner: the user-cancel writes ``next_poll=''`` which excludes the row from ``list_due_watches``, so the retry-deactivate branch at the top of :meth:`_poll_watch` never fires to clear the - entry. + entry. Held reminders are dropped for the same reason: a + cancelled watch's row leaves the due view, so its pending + re-delivery would never be retried and would leak. + + Call this AFTER the row write that takes the watch out of the + active view: the delivery paths re-check ``is_watch_active`` + before stashing or dispatching, so with the write already + visible a racing poll thread drops its own hold instead of + re-stashing behind this clear. (The residual + check-before-write / stash-after-clear interleaving is mopped + up by :meth:`_sweep_cancelled_holds` within one tick.) """ with self._terminal_dispatched_lock: self._terminal_dispatched.discard(watch_id) + self._clear_pending_delivery(watch_id) # -- Main loop ----------------------------------------------------------- @@ -399,6 +567,7 @@ class WatchRunner: def _tick(self) -> None: if self._storage is None: return + self._sweep_cancelled_holds() now = datetime.now(UTC).strftime("%Y-%m-%dT%H:%M:%S") due = self._storage.list_due_watches(now) for watch_row in due: @@ -408,13 +577,60 @@ class WatchRunner: row_node = watch_row.get("node_id", "") if row_node and row_node != self._node_id: continue + watch_id = str(watch_row.get("watch_id", "")) + with self._in_flight_lock: + if watch_id in self._in_flight: + # Still polling from a previous tick (slow command) — + # the row keeps listing as due until its update + # commits; don't double-poll it. + continue + self._in_flight.add(watch_id) + if not self._poll_slots.acquire(blocking=False): + # Pool saturated: the remaining due rows stay due and the + # next tick retries them — nothing is dropped, delivery is + # just deferred by up to ``check_interval``. + with self._in_flight_lock: + self._in_flight.discard(watch_id) + log.debug("watch_runner.poll_slots_saturated") + break try: - self._poll_watch(watch_row) + threading.Thread( + target=self._poll_one, + args=(watch_row,), + daemon=True, + name=f"watch-poll-{watch_id[:8]}", + ).start() except Exception: - log.exception( - "watch_runner.poll_error", - extra={"watch_id": watch_row.get("watch_id")}, - ) + # Spawn failure (e.g. OS thread exhaustion) must not leak + # the slot or the in-flight entry, and must NOT abort the + # rest of this tick — the failed watch stays due and + # retries next tick while its siblings still get polled + # (a raise here would unwind out of the un-guarded + # due-row loop and skip every remaining due watch). + with self._in_flight_lock: + self._in_flight.discard(watch_id) + self._poll_slots.release() + log.exception("watch_runner.poll_spawn_failed", extra={"watch_id": watch_id}) + continue + + def _poll_one(self, watch_row: dict[str, Any]) -> None: + """Run one ``_poll_watch`` on a pool thread. + + Always releases the slot and the in-flight entry, even on an + unexpected raise — a leaked slot would shrink the pool for the + rest of the process lifetime. + """ + try: + self._poll_watch(watch_row) + except Exception: + log.exception( + "watch_runner.poll_error", + extra={"watch_id": watch_row.get("watch_id")}, + ) + finally: + with self._in_flight_lock: + self._in_flight.discard(str(watch_row.get("watch_id", ""))) + self._poll_slots.release() def _poll_watch(self, watch_row: dict[str, Any]) -> None: watch_id = watch_row["watch_id"] @@ -437,10 +653,33 @@ class WatchRunner: self._storage.update_watch(watch_id, active=False, next_poll="") with self._terminal_dispatched_lock: self._terminal_dispatched.discard(watch_id) + # A held reminder for an already-dispatched watch means a + # re-delivery SUCCEEDED but its row-commit raised (leaving + # the id in both sets). The reminder is delivered, so drop + # the hold here — otherwise, once we deactivate the row it + # never re-lists and the entry would leak forever. + self._clear_pending_delivery(watch_id) except Exception: log.exception("watch_runner.retry_deactivate_failed", extra={"watch_id": watch_id}) return + # Held-reminder re-delivery: a prior poll fired but couldn't reach + # this watch's workstream. Re-DELIVER the stashed reminder without + # re-running the command (so a stop_on match that was momentarily + # true isn't lost to a fresh run), bounded by MAX_DELIVERY_ATTEMPTS. + # The per-watch_id in-flight gate in _tick serialises POLLERS for + # this watch_id; the user-cancel path's forget_terminal_dispatched + # runs on a worker thread and CAN race this peek — which is why + # _redeliver_pending re-checks the row's active state before + # dispatching, the hold paths re-check before stashing, and + # _sweep_cancelled_holds mops up any stash that still lands after + # a cancel's clear. + with self._pending_delivery_lock: + pending = self._pending_delivery.get(watch_id) + if pending is not None: + self._redeliver_pending(watch_row, pending) + return + # Safety check blocked = is_command_blocked(command) if blocked: @@ -474,6 +713,23 @@ class WatchRunner: now = datetime.now(UTC) now_str = now.strftime("%Y-%m-%dT%H:%M:%S") + # Build the row update this poll intends to commit, UP FRONT, so a + # delivery failure can stash it verbatim alongside the reminder + # (see :meth:`_redeliver_pending`) instead of recomputing it at + # re-delivery time. + update_fields: dict[str, Any] = { + "poll_count": poll_count, + "last_output": output, + "last_exit_code": exit_code, + "last_poll": now_str, + } + if is_final: + update_fields["active"] = False + update_fields["next_poll"] = "" + else: + next_poll = now + timedelta(seconds=watch_row["interval_secs"]) + update_fields["next_poll"] = next_poll.strftime("%Y-%m-%dT%H:%M:%S") + # Dispatch before committing the row update. Belt-and-braces # given the rest of the fix (closure no longer wires a # ``valid_until`` predicate, cancel-by-name uses @@ -485,7 +741,12 @@ class WatchRunner: # ``_terminal_dispatched`` guard above it also bounds the # duplicate-fire blast radius if the row write fails after the # reminder shipped. - if fired or is_final: + # + # ``fired ⟹ is_final`` (see the assignment above), so reminders + # are built ONLY for terminal polls — the held-delivery machinery + # relies on that (a committed ``update_fields`` always + # deactivates). + if is_final: # Compute elapsed from created time elapsed_secs = 0.0 if created: @@ -506,34 +767,34 @@ class WatchRunner: is_final=is_final, reason=reason, ) - self._dispatch_result(ws_id, reminder, watch_id) - if is_final: - # Mark BEFORE the row write so a raise below routes the - # next tick into the retry-deactivate branch instead of - # re-firing the reminder. - with self._terminal_dispatched_lock: - self._terminal_dispatched.add(watch_id) - - # Update DB - update_fields: dict[str, Any] = { - "poll_count": poll_count, - "last_output": output, - "last_exit_code": exit_code, - "last_poll": now_str, - } - if is_final: - update_fields["active"] = False - update_fields["next_poll"] = "" + try: + delivered = self._dispatch_result(ws_id, reminder, watch_id) + except WatchWorkstreamUnrestorable: + # Permanent: the workstream can never be restored (corrupt + # persona stamp / history gone). Stash BEFORE the abandon + # write — not for delivery (there is nowhere to deliver), + # but so a failing deactivation write routes the next tick + # into the redeliver path (which retries the WRITE) instead + # of the still-active row re-listing into a fresh command + # run every tick with the budget never advancing. On a + # successful write, _abandon_delivery clears the stash + # immediately (write-then-clear). + self._stash_pending_delivery(watch_id, reminder, update_fields, attempts=1) + self._abandon_delivery(watch_id, ws_id, update_fields, reason="unrestorable") + return + if not delivered: + # Transiently undeliverable (ws evicted + slots busy, or + # restore admission deferred). HOLD the built reminder + + # its intended row update for re-delivery on the capped + # retry cadence, advancing next_poll and durably charging + # this fire's poll — no baseline advance and no command + # re-run (which would lose a transient stop_on match); + # see :meth:`_hold_delivery` for why the charge commits. + self._hold_delivery(watch_row, reminder, update_fields, attempts=1) + return + self._commit_terminal_update(watch_id, update_fields) else: - next_poll = now + timedelta(seconds=watch_row["interval_secs"]) - update_fields["next_poll"] = next_poll.strftime("%Y-%m-%dT%H:%M:%S") - self._storage.update_watch(watch_id, **update_fields) - - if is_final: - # Row write committed; the retry-deactivate branch will - # never be reached for this watch_id. - with self._terminal_dispatched_lock: - self._terminal_dispatched.discard(watch_id) + self._storage.update_watch(watch_id, **update_fields) log.debug( "watch_runner.polled", @@ -568,38 +829,395 @@ class WatchRunner: except Exception as exc: return f"[command failed: {exc}]", -1 - def _dispatch_result(self, ws_id: str, reminder: dict[str, Any], watch_id: str) -> None: + def _try_dispatch_fn(self, ws_id: str, reminder: dict[str, Any], watch_id: str) -> bool | None: + """Deliver via the registered dispatch fn, if one exists. + + Returns ``True`` (delivered), ``False`` (a fn is registered but it + raised — the ws is live, so the caller must NOT restore, which + would spawn a duplicate session), or ``None`` (no fn registered — + the ws may be evicted and the caller should try to restore). + """ + with self._dispatch_lock: + fn = self._dispatch_fns.get(ws_id) + if fn is None: + return None + try: + fn(reminder, watch_id) + return True + except Exception: + log.exception("watch_runner.dispatch_error", extra={"ws_id": ws_id}) + return False + + def _dispatch_result(self, ws_id: str, reminder: dict[str, Any], watch_id: str) -> bool: """Deliver a watch result to the owning workstream. ``reminder`` is the structured dict produced by :func:`build_watch_reminder` — ``text`` is the formatted body (matched by the dispatch closure's :func:`sanitize_payload` pass) and the optional fields ride as queue-entry metadata. + + Returns ``True`` iff a dispatch closure ran without raising — the + registered one, or the one the restore path produced. ``False`` + means the reminder was not delivered for a TRANSIENT reason (no fn + + slots busy, restore admission deferred, or a live fn raised); the + caller HOLDS the reminder and re-delivers on the capped retry + cadence. Raises + :class:`WatchWorkstreamUnrestorable` for a PERMANENT failure so the + caller can deactivate the watch instead of retrying. """ - with self._dispatch_lock: - fn = self._dispatch_fns.get(ws_id) + delivered = self._try_dispatch_fn(ws_id, reminder, watch_id) + if delivered is not None: + return delivered - if fn is not None: - try: - fn(reminder, watch_id) - return - except Exception: - log.exception("watch_runner.dispatch_error", extra={"ws_id": ws_id}) + # No dispatch fn — the workstream may be evicted. Admit a restore + # only when this ws isn't already restoring and the concurrent- + # restore cap has room; hold ``_restore_lock`` for that fast check + # ONLY (never across the slow restore, which would pin this poll + # slot). A rejected poll defers (holds + re-delivers on the + # capped retry cadence). + if self._restore_fn is None: + log.warning( + "watch_runner.dispatch_failed", + extra={"ws_id": ws_id, "reason": "no dispatch fn and no restore_fn"}, + ) + return False - # Workstream may be evicted — try to restore - if self._restore_fn is not None: + deliver_after_admission = False + with self._restore_lock: + # Re-check: a restore that completed while we waited for the + # lock may already have registered a fn for this ws_id. This + # is a PRESENCE check only — the dispatch closure itself can + # block (it takes ``ws._lock`` and may spawn a wake thread), + # and running it here would serialise every restore admission + # on the node behind one delivery. (Lock order: _restore_lock + # → _dispatch_lock via get_dispatch_fn; nothing takes them in + # the reverse order.) + if self.get_dispatch_fn(ws_id) is not None: + deliver_after_admission = True + else: + # Alert on admission entries past the stall threshold — + # a restore wedged inside ``restore_fn`` (its poll thread + # is blocked, so the release in the ``finally`` below can + # never run) holds this capacity for the process + # lifetime. Detection ONLY: see + # :data:`RESTORE_STALL_ALERT_SECS` for why reclaiming the + # entry would make the failure strictly worse. + now = time.monotonic() + for rid, started in self._restoring.items(): + if now - started > RESTORE_STALL_ALERT_SECS: + log.error( + "watch_runner.restore_admission_wedged", + extra={"ws_id": rid, "stalled_secs": round(now - started, 1)}, + ) + if ws_id in self._restoring or len(self._restoring) >= MAX_CONCURRENT_RESTORES: + # Same-ws restore already running, or the pool is at + # its restore cap — defer rather than block a poll + # slot. + return False + self._restoring[ws_id] = now + if deliver_after_admission: + # The fn appeared while we waited: deliver OUTSIDE the lock. + # ``None`` (it vanished again — an eviction race) defers like + # any other transient. + return bool(self._try_dispatch_fn(ws_id, reminder, watch_id)) + + try: + restored_fn = self._restore_fn(ws_id) # may raise WatchWorkstreamUnrestorable + except WatchWorkstreamUnrestorable: + raise # permanent — caller deactivates the watch + except Exception: + log.exception("watch_runner.restore_error", extra={"ws_id": ws_id}) + return False + finally: + with self._restore_lock: + self._restoring.pop(ws_id, None) + + if restored_fn is not None: try: - restored_fn = self._restore_fn(ws_id) - if restored_fn is not None: - restored_fn(reminder, watch_id) - return + restored_fn(reminder, watch_id) + return True except Exception: - log.exception("watch_runner.restore_error", extra={"ws_id": ws_id}) + log.exception("watch_runner.restore_dispatch_error", extra={"ws_id": ws_id}) + return False log.warning( "watch_runner.dispatch_failed", - extra={"ws_id": ws_id, "reason": "no dispatch function and restore failed"}, + extra={"ws_id": ws_id, "reason": "restore produced no dispatch fn"}, ) + return False + + # -- Held-reminder re-delivery ------------------------------------------- + # + # Everything held here is a TERMINAL fire (``fired ⟹ is_final`` in + # ``_poll_watch``, and reminders are built only for final polls), so a + # committed ``update_fields`` always deactivates the row. The delivery + # outcome state machine — commit-with-terminal-mark, abandon, hold — + # lives in the three helpers below so ``_poll_watch`` (fresh fire) and + # ``_redeliver_pending`` can't drift apart on the fragile ordering. + + def _watch_still_active(self, watch_id: str) -> bool: + """``True`` unless the row has CLEANLY left the active view (user + cancel / deletion). A storage error biases toward ``True``: + delivery paths keep retrying on a blip — bounded by their own + attempt and poll budgets — rather than dropping a fire. + """ + try: + return bool(self._storage.is_watch_active(watch_id)) + except Exception: + return True + + def _stash_pending_delivery( + self, + watch_id: str, + reminder: dict[str, Any], + update_fields: dict[str, Any], + *, + attempts: int, + ) -> None: + """Hold ``reminder`` + its intended row update for re-delivery.""" + with self._pending_delivery_lock: + self._pending_delivery[watch_id] = { + "reminder": reminder, + "update_fields": update_fields, + "attempts": attempts, + } + + def _clear_pending_delivery(self, watch_id: str) -> None: + with self._pending_delivery_lock: + self._pending_delivery.pop(watch_id, None) + + def _commit_terminal_update(self, watch_id: str, update_fields: dict[str, Any]) -> None: + """Commit a DELIVERED terminal fire's row update with the + ``_terminal_dispatched`` mark held across the write: if the write + raises, the next tick routes into the retry-deactivate branch at + the top of :meth:`_poll_watch` instead of re-firing a reminder the + model already saw. + """ + with self._terminal_dispatched_lock: + self._terminal_dispatched.add(watch_id) + self._storage.update_watch(watch_id, **update_fields) + # Row write committed; the retry-deactivate branch will never be + # reached for this watch_id. + with self._terminal_dispatched_lock: + self._terminal_dispatched.discard(watch_id) + + def _abandon_delivery( + self, + watch_id: str, + ws_id: str, + update_fields: dict[str, Any], + *, + reason: str, + attempts: int | None = None, + ) -> None: + """Give up on delivering this fire: commit the intended row + update (deactivating the terminal watch), then drop any held + reminder. Write-then-clear: a failed commit leaves the hold in + place, so the next tick retries via the REDELIVER path (dispatch + → same terminal outcome → retry this write) without re-running + the command — clearing first would let the row re-list into a + fresh command run every attempt-budget cycle, forever, whenever + storage can read but not write (e.g. disk-full SQLite), with the + poll budget never advancing. The clear itself is pure in-memory + and cannot fail after a successful commit, so no ordering leaks + the hold. + """ + self._storage.update_watch(watch_id, **update_fields) + self._clear_pending_delivery(watch_id) + extra: dict[str, Any] = {"watch_id": watch_id, "ws_id": ws_id, "reason": reason} + if attempts is not None: + extra["attempts"] = attempts + log.error("watch_runner.delivery_abandoned", extra=extra) + + def _hold_delivery( + self, + watch_row: dict[str, Any], + reminder: dict[str, Any], + update_fields: dict[str, Any], + *, + attempts: int, + ) -> None: + """Stash the reminder + intended update and advance ``next_poll`` + (by the capped retry delay) so the row re-lists for re-delivery + soon — without advancing its baseline or running its command. + Re-delivery is a cheap in-memory dispatch, so it retries on + ``min(interval_secs, DELIVERY_RETRY_CAP_SECS)`` rather than the + watch's own interval: a daily watch must not sit on its fired + reminder for 24 h because a restore slot was briefly busy. + + The poll charge (``update_fields["poll_count"]``) is committed + alongside ``next_poll``: the hold itself lives only in this + process, so a restart mid-hold re-lists the row and re-runs the + (possibly side-effectful) command — with the charge durable those + re-runs stay bounded by the watch's own ``max_polls``, matching + the in-memory exhaustion path, plus at most ONE regeneration run + per restart when the held fire had already spent the budget (the + re-list runs the command before the cap check so the lost + reminder is regenerated rather than silently dropped). The + baseline (``last_output``) stays uncommitted so a delta-style + ``stop_on`` re-detects the change the model never saw. + + Dropped instead when the row has left the active view: the user + cancelled while this fire was in flight, and a stash landing + after the cancel path's :meth:`forget_terminal_dispatched` would + leak the hold forever (an inactive row never re-lists to retry + it) and violate that method's drop guarantee. + """ + watch_id = watch_row["watch_id"] + ws_id = watch_row["ws_id"] + if not self._watch_still_active(watch_id): + self._clear_pending_delivery(watch_id) + log.info( + "watch_runner.hold_dropped_cancelled", + extra={"watch_id": watch_id, "ws_id": ws_id, "attempts": attempts}, + ) + return + retry_secs = min(int(watch_row["interval_secs"]), DELIVERY_RETRY_CAP_SECS) + self._stash_pending_delivery(watch_id, reminder, update_fields, attempts=attempts) + retry_poll = _iso_in(retry_secs) + self._storage.update_watch( + watch_id, + next_poll=retry_poll, + poll_count=int(update_fields["poll_count"]), + ) + log.warning( + "watch_runner.delivery_deferred", + extra={ + "watch_id": watch_id, + "ws_id": ws_id, + "attempts": attempts, + "next_retry": retry_poll, + }, + ) + + def _redeliver_pending(self, watch_row: dict[str, Any], pending: dict[str, Any]) -> None: + """Re-attempt delivery of a held reminder WITHOUT re-running the + command. + + Five outcomes: + + * **Watch cancelled** — the user-cancel path raced the due + listing. Drop the hold and deliver nothing: cancel's + :meth:`forget_terminal_dispatched` promises the held reminder + is dropped, and delivering here could even RESTORE a session + for a watch the user just cancelled. + * **Delivered** — commit the row update stashed at fire time (which + deactivates the terminal watch) and clear the hold. The hold is + cleared BEFORE the commit so that a commit failure can't strand + it (the row then re-lists and the ``already_dispatched`` guard + finishes deactivation). + * **Permanent failure** (:class:`WatchWorkstreamUnrestorable`) — + deactivate the watch now and drop the reminder; it can never be + delivered. + * **Transient failure past** :data:`MAX_DELIVERY_ATTEMPTS`, poll + budget remaining — drop the held reminder, charge ONE poll to the + watch's ``max_polls`` budget, and leave it ACTIVE on its normal + cadence: a temporary cause (restore slots saturated under load) + doesn't silently turn the watch off, it re-fires and re-attempts + delivery next interval. The baseline (``last_output``) is + deliberately NOT committed, so a delta-style ``stop_on`` re-fires + on the same change the model never saw. + * **Transient exhaustion with the poll budget spent** — commit the + held update (deactivates). Without this bound a persistently + unreachable workstream would re-run its command every interval + forever, past the user's own ``max_polls``. + """ + watch_id = watch_row["watch_id"] + ws_id = watch_row["ws_id"] + reminder = pending["reminder"] + update_fields = pending["update_fields"] + + if not self._watch_still_active(watch_id): + self._clear_pending_delivery(watch_id) + log.info( + "watch_runner.redelivery_dropped_cancelled", + extra={"watch_id": watch_id, "ws_id": ws_id}, + ) + return + + try: + delivered = self._dispatch_result(ws_id, reminder, watch_id) + except WatchWorkstreamUnrestorable: + self._abandon_delivery(watch_id, ws_id, update_fields, reason="unrestorable") + return + + if delivered: + # Clear the hold FIRST: if the commit below raises, the row + # re-lists and the ``already_dispatched`` branch deactivates it + # — with the hold already gone there's nothing to leak. + self._clear_pending_delivery(watch_id) + self._commit_terminal_update(watch_id, update_fields) + log.info( + "watch_runner.delivery_recovered", + extra={"watch_id": watch_id, "ws_id": ws_id}, + ) + return + + attempts = int(pending["attempts"]) + 1 + if attempts >= MAX_DELIVERY_ATTEMPTS: + poll_count = int(update_fields.get("poll_count", 0)) + max_polls = int(watch_row.get("max_polls", DEFAULT_MAX_POLLS)) + if poll_count >= max_polls: + # Poll budget spent — deactivate rather than re-run the + # command forever against an unreachable workstream. + self._abandon_delivery( + watch_id, + ws_id, + update_fields, + reason="poll_budget_exhausted", + attempts=attempts, + ) + return + # Budget remains: charge this cycle's poll, then drop the hold + # and let the watch re-fire on its own cadence. next_poll uses + # the FULL interval (a fresh command cycle, not a cheap + # re-delivery) and the baseline stays uncommitted so the fire + # re-detects. Write-then-clear, mirroring _abandon_delivery: a + # failed charge commit keeps the hold, so the next tick retries + # THIS branch instead of the row re-listing into a fresh + # command run with the budget never advancing. + self._storage.update_watch( + watch_id, + poll_count=poll_count, + next_poll=_iso_in(int(watch_row["interval_secs"])), + ) + self._clear_pending_delivery(watch_id) + log.warning( + "watch_runner.delivery_abandoned", + extra={ + "watch_id": watch_id, + "ws_id": ws_id, + "attempts": attempts, + "reason": "transient_exhausted", + "watch_active": True, + "poll_count": poll_count, + "max_polls": max_polls, + }, + ) + return + + self._hold_delivery(watch_row, reminder, update_fields, attempts=attempts) + + def _sweep_cancelled_holds(self) -> None: + """Drop held deliveries whose rows have left the active view. + + The cancel paths call :meth:`forget_terminal_dispatched`, but a + poll thread that already passed its own active re-check can + re-stash a hold microseconds AFTER that clear — no ordering + between the cancel's row write and the in-memory stash can + prevent it without a per-watch lock spanning storage I/O. An + inactive row never re-lists, so nothing else would ever retry or + drop such an entry; this tick-time sweep bounds the leak (and + any post-cancel redelivery) to one ``check_interval``. Iterates + only currently-held ids — holds are rare and short-lived — so + the steady-state per-tick cost is zero storage reads. + """ + with self._pending_delivery_lock: + held_ids = list(self._pending_delivery) + for watch_id in held_ids: + if not self._watch_still_active(watch_id): + self._clear_pending_delivery(watch_id) + log.info("watch_runner.hold_swept_cancelled", extra={"watch_id": watch_id}) def _deactivate_watch(self, watch_id: str) -> None: self._storage.update_watch(watch_id, active=False, next_poll="") diff --git a/turnstone/server.py b/turnstone/server.py index 05570c31..1fa7b086 100644 --- a/turnstone/server.py +++ b/turnstone/server.py @@ -33,7 +33,7 @@ from pathlib import Path from typing import TYPE_CHECKING, Any if TYPE_CHECKING: - from collections.abc import Iterable + from collections.abc import Callable, Iterable from sse_starlette import EventSourceResponse from starlette.applications import Starlette @@ -55,6 +55,7 @@ from turnstone.core.auth import ( _DenyFilter, jwt_version_slot, ) +from turnstone.core.idle_nudge_watcher import wake_workstream_if_pending from turnstone.core.log import get_logger from turnstone.core.metrics import metrics as _metrics from turnstone.core.ratelimit import resolve_client_ip @@ -772,6 +773,19 @@ def _interactive_events_replay( yield {"type": "intent_verdict", **v} +def _watch_fire_wake_fn(ws: Workstream) -> Callable[[], object]: + """Wake closure for watch fires, for ``ChatSession.set_watch_runner``. + + Closes over the Workstream OBJECT, never its id: after an + eviction+restore the manager tracks the workstream under a fresh id + while the watch rows keep the resumed session's ``_ws_id``, so an + id-keyed ``manager.get`` lookup at fire time would miss. Shared by + every ``set_watch_runner`` site (create, reopen, watch-restore, + CLI ``--resume``) so they can't drift on that subtlety. + """ + return lambda: wake_workstream_if_pending(ws, trigger="watch-fire") + + def _interactive_open_post_load(request: Request, ws: Workstream) -> None: """Post-load hook for the lifted interactive ``open`` body. @@ -794,6 +808,13 @@ def _interactive_open_post_load(request: Request, ws: Workstream) -> None: handler-side emission is the load-bearing path on interactive; ``InteractiveAdapter.emit_rehydrated`` is a no-op stub precisely because this enqueue lives here. + 4. Re-wire the watch dispatch registration. The workstream's + previous ``close()`` removed its registration, and nothing on + the ``open`` path restored it — so a watch firing on a + REOPENED, actively-viewed workstream found no dispatch fn and + took the restore path, spawning a duplicate auto-approved + session that raced turns into the same conversation the live + one was showing. """ from turnstone.core.memory import get_workstream_display_name @@ -803,6 +824,12 @@ def _interactive_open_post_load(request: Request, ws: Workstream) -> None: if isinstance(ui, WebUI) and session is not None and session.messages: ui._enqueue({"type": "clear_ui"}) + runner = getattr(request.app.state, "watch_runner", None) + if runner is not None and session is not None: + # ``mgr.open`` already resumed, so this keys the registration on + # the adopted id (and ``resume()`` re-registers by itself anyway). + session.set_watch_runner(runner, wake_fn=_watch_fire_wake_fn(ws)) + gq: queue.Queue[dict[str, Any]] | None = getattr(request.app.state, "global_queue", None) if gq is not None: with contextlib.suppress(queue.Full): @@ -2104,7 +2131,7 @@ async def _interactive_create_post_install( ws.ui.auto_approve = True runner = getattr(request.app.state, "watch_runner", None) if runner and ws.session: - ws.session.set_watch_runner(runner) + ws.session.set_watch_runner(runner, wake_fn=_watch_fire_wake_fn(ws)) gq: queue.Queue[dict[str, Any]] = request.app.state.global_queue # Emit ``ws_created`` on the global queue for SSE consumers # (console). Held until past attachment validation in the @@ -2228,7 +2255,9 @@ async def _interactive_create_post_install( # Initial-message worker thread. initial_message = body.get("initial_message", "").strip() + initial_message_status = "" if initial_message and ws.session is not None: + from turnstone.core import session_worker from turnstone.core.attachments import ( resolve_staged_attachments as _resolve_staged, ) @@ -2236,20 +2265,13 @@ async def _interactive_create_post_install( session = ws.session send_id = uuid.uuid4().hex resolved_atts: list[Any] = [] + staged_ord: list[str] = [] if attachment_ids: - # Resolve (peek) the staged uploads, then drain them from the buffer - # now. The inlined first turn is their only consumer and it always - # commits at create (no queue rejection by construction), so leaving - # them staged would let the freshly-opened pane's rehydrate race the - # worker's write-time drain and paint them as still-pending composer - # chips. ``_append_user_turn``'s own per-id discard then no-ops. - resolved_atts, _ord, _drop = _resolve_staged(attachment_ids, ws.id, uid) - if _ord: - from turnstone.core.attachment_buffer import get_attachment_buffer - - _buf = get_attachment_buffer() - for _aid in _ord: - _buf.discard(_aid, ws_id=ws.id, user_id=uid) + # Resolve (peek) the staged uploads. The buffer DRAIN happens + # after the dispatch below, and only on the spawn path — the + # enqueue path can't deliver attachments, so there they must + # stay staged (see ``_enqueue_init``). + resolved_atts, staged_ord, _drop = _resolve_staged(attachment_ids, ws.id, uid) def _run_initial() -> None: try: @@ -2268,31 +2290,89 @@ async def _interactive_create_post_install( _fire_notify_targets(ws, last_content) except Exception: log.warning("notify_completion.hook_error", ws_id=ws.id, exc_info=True) - with ws._lock: - # Only clear the flag if THIS thread is still the current - # worker — a force-cancel abandons this thread and a - # follow-up send may already have spawned a successor; an - # abandoned initial-send worker finishing late must not - # clobber that successor's running flag (mirrors the guard - # in session_worker._runner). - if ws.worker_thread is threading.current_thread(): - ws._worker_running = False - # Inlined rather than via ``session_worker.send`` because at - # workstream creation no live worker can exist by - # construction — the enqueue branch of the shared dispatch - # is dead code here. ``_worker_running`` + ``ws.worker_thread`` - # are set together under ``ws._lock`` so a path-keyed send - # arriving immediately after creation observes the running - # state via the shared session_worker gate instead of racing - # into a parallel worker. - with ws._lock: - ws._worker_running = True - t = threading.Thread(target=_run_initial, daemon=True, name=f"ws-init-{ws.id[:8]}") - ws.worker_thread = t - t.start() + init_enqueued = False - return {"resumed": resumed, "message_count": message_count} + def _enqueue_init() -> None: + # Reached only if a worker already owns this freshly-created ws + # — possible solely with a caller-supplied ws_id raced by a + # concurrent /send. Don't drop the user's first message: queue + # its TEXT as an interjection so the live worker delivers it. + # Attachments can't ride the interjection seam (queue_message + # rejects them), so they stay STAGED instead (the drain below + # is skipped on this branch): the composer keeps showing them + # as pending chips and the user's next send delivers them. + # + # No try/except: ``queue.Full`` must reach + # ``session_worker.send``'s backpressure branch so it returns + # ``False`` — the same surface the /send path reports as + # ``queue_full`` — instead of this create responding as if the + # message were delivered. + nonlocal init_enqueued + init_enqueued = True + session.queue_message(initial_message) + if resolved_atts: + log.warning( + "ws_init.live_worker_at_creation ws=%s — %d attachment(s) left staged " + "(cannot ride the interjection seam); message text queued, attachments " + "stay in the composer for the next send", + ws.id[:8], + len(resolved_atts), + ) + + # Routed through ``session_worker.send`` so the init worker + # inherits ``_runner``'s ownership-clear wake backstop + # (``_retry_pending_wake``): a nudge enqueued during the initial + # send (e.g. a watch fire on a schedule-created workstream) no + # longer strands until the next user message. The enqueue branch + # is unreachable by construction (no worker can own a ws at + # creation) unless a caller-supplied ws_id is raced — hence + # ``_enqueue_init`` preserves the message and leaves the staged + # attachments recoverable instead of assuming the branch is dead. + init_ok = session_worker.send( + ws, + enqueue=_enqueue_init, + run=_run_initial, + thread_name=f"ws-init-{ws.id[:8]}", + ) + if not init_ok: + # Two refusal shapes: the raced live worker's interjection + # queue rejected the text (``init_enqueued=True`` — queue.Full, + # the condition /send surfaces as ``queue_full``), or ``send`` + # refused outright because the workstream was closed under our + # feet (``init_enqueued=False`` — a create raced by an off-loop + # close). Either way the workstream exists and the first + # message was NOT delivered; say so instead of answering as if + # it were. Attachments stay staged on both paths (the drain + # below is gated on ``init_ok``) so the composer chips survive + # for the user's retry. + initial_message_status = "queue_full" if init_enqueued else "refused_closed" + log.error( + "ws_init.initial_message_dropped ws=%s (%s)", + ws.id[:8], + initial_message_status, + ) + if staged_ord and not init_enqueued and init_ok: + # Spawn path took the message: drain the staged copies NOW, + # before this handler returns — the pane's rehydrate can only + # start after it receives this response, so it can never + # observe the consumed uploads as still-pending composer + # chips. (``enqueue`` runs synchronously inside ``send``, so + # ``init_enqueued`` is settled here.) ``_append_user_turn``'s + # own per-id discard then no-ops. + from turnstone.core.attachment_buffer import get_attachment_buffer + + _buf = get_attachment_buffer() + for _aid in staged_ord: + _buf.discard(_aid, ws_id=ws.id, user_id=uid) + + out: dict[str, Any] = {"resumed": resumed, "message_count": message_count} + if initial_message_status: + # Only present when the initial message was NOT delivered — the + # factory passes it through to the response so API clients don't + # read the 200 as "first message accepted". + out["initial_message_status"] = initial_message_status + return out def _audit_workstream_created( @@ -2500,6 +2580,13 @@ async def cancel_watch(request: Request) -> JSONResponse: if watch_node and node_id and watch_node != node_id: return JSONResponse({"error": "Watch belongs to another node"}, status_code=403) storage.update_watch(watch_id, active=False, next_poll="") + # AFTER the row write, per forget_terminal_dispatched's ordering + # contract: drop the runner's transient state for this id (held + # reminder / terminal-dispatched mark) — the inactive row never + # re-lists, so nothing else would ever clear it. + runner = getattr(request.app.state, "watch_runner", None) + if runner is not None: + runner.forget_terminal_dispatched(watch_id) return JSONResponse({"status": "ok", "watch_id": watch_id}) @@ -4077,7 +4164,11 @@ async def _lifespan(app: Starlette) -> AsyncGenerator[None, None]: if tls_client is not None: await tls_client.stop_renewal() if app.state.watch_runner: - app.state.watch_runner.stop() + # ``stop()`` drains in-flight polls (bounded, but up to ~35 s) — + # run it off the event loop like the state-writer below so SSE + # teardown and the remaining shutdown steps aren't frozen behind + # a watch command that's still finishing. + await asyncio.to_thread(app.state.watch_runner.stop) from turnstone.core.idle_nudge_watcher import shutdown_idle_nudge_watchers shutdown_idle_nudge_watchers(app) @@ -4964,7 +5055,7 @@ def main() -> None: # Create WatchRunner (periodic command polling, server-level) from turnstone.core.storage import get_storage as _get_storage - from turnstone.core.watch import WatchRunner + from turnstone.core.watch import WatchRunner, WatchWorkstreamUnrestorable # Create session manager first (watch restore_fn captures it). interactive_adapter = InteractiveAdapter( @@ -5023,25 +5114,110 @@ def main() -> None: on the rehydrated session, so ``WatchRunner._dispatch_result`` can re-deliver the current message into the rehydrated workstream's :class:`NudgeQueue` without a second pass through ``restore_fn``. + + Failure taxonomy: two failures are PERMANENT — the persona-stamp + pre-read raising (corrupt stamp, nothing created yet) and + ``resume()`` returning ``False`` (no stored turns: the target's + history is gone, so there is nothing to deliver into and every + retry would rebuild this shell just to fail again). Everything + else after ``manager.create`` is treated as transient — the + half-built shell is closed so a failed attempt can't leak a + ``max_active`` slot, and the runner holds the reminder and + retries, bounded by the watch's own poll budget. Deliberately + NOT mapping post-create ``ValueError`` to permanent: ``resume`` + can raise it for reasons beyond the corrupt-stamp contract, and + a misclassification here silently kills the user's watch. """ try: - ws = manager.create(user_id="", name="watch-restore", **_resume_persona_kwargs(ws_id)) + persona_kwargs = _resume_persona_kwargs(ws_id) + except ValueError as exc: + # PERMANENT: corrupt persona stamp. Refuse to run the watch + # under an envelope the operator didn't choose (it would be + # unattended AND auto-approved), and signal the runner to stop + # retrying and deactivate the watch rather than burn the whole + # attempt budget on a cause that can't clear on its own. + log.warning("watch_restore: corrupt persona stamp on ws %s", ws_id, exc_info=True) + raise WatchWorkstreamUnrestorable(ws_id) from exc + + try: + ws = manager.create(user_id="", name="watch-restore", **persona_kwargs) + except RuntimeError: + # TRANSIENT: all restore slots active right now. Return None so + # the runner holds the reminder and retries on a later tick. + log.warning("watch_restore: cannot restore ws %s (all slots active)", ws_id) + return None + + try: # Restored workstreams run unattended — auto-approve tool calls # to avoid blocking forever on approval with no connected user. if isinstance(ws.ui, WebUI): ws.ui.auto_approve = True - if ws.session: - ws.session.resume(ws_id) - ws.session.set_watch_runner(_watch_runner) - return _watch_runner.get_dispatch_fn(ws.session._ws_id) - except RuntimeError: - log.warning("watch_restore: cannot restore ws %s (all slots active)", ws_id) - except ValueError: - # Corrupt persona stamp — refuse to run the watch under an - # envelope the operator didn't choose (it would be unattended - # AND auto-approved); the watch stays queued for a manual open. - log.warning("watch_restore: corrupt persona stamp on ws %s", ws_id, exc_info=True) - return None + if ws.session is None: + raise RuntimeError("created workstream has no session") + if not ws.session.resume(ws_id): + # ``resume``'s turn loader swallows storage errors into [] + # (memory.load_message_turns), so False here is EITHER + # "history is gone" (permanent — without this check the + # fresh session keeps its own fresh ``_ws_id``, the + # registration below keys on THAT, and the reminder would + # be "delivered" into a blank, orphaned, auto-approved + # session while the watch deactivates as delivered) OR a + # transient read blip. Re-probe with the RAISING storage + # call before declaring permanence: misclassifying a blip + # silently kills the user's watch and drops the fired + # reminder. + with contextlib.suppress(Exception): + manager.close(ws.id) + try: + turns_exist = bool(_get_storage().load_message_turns(ws_id, checkpointed=True)) + except Exception: + log.warning( + "watch_restore: turns probe failed for ws %s (treating as transient)", + ws_id, + exc_info=True, + ) + return None + if turns_exist: + # Rows exist but resume()'s read came back empty — a + # blip. Retry on the held-delivery cadence. + log.warning("watch_restore: empty resume read for ws %s (blip)", ws_id) + return None + log.warning("watch_restore: ws %s has no stored turns", ws_id) + raise WatchWorkstreamUnrestorable(ws_id) + # A live registration may have appeared while this shell was + # being built — the user reopening the workstream mid-restore + # (``mgr.open`` + post-load registers their PANE). The pane + # wins: deliver into it and close the redundant shell. + # Registering ours would silently clobber the pane's — every + # later fire would run unattended in the shell while the user + # watches a conversation that never shows its watch results. + # (A pane registration landing in the microseconds between + # this check and the set below can still be clobbered; that + # residue requires the reopen to race a window ~10^6 times + # narrower than the restore itself.) + existing = _watch_runner.get_dispatch_fn(ws_id) + if existing is not None: + log.info("watch_restore: live registration appeared for ws %s — yielding", ws_id) + with contextlib.suppress(Exception): + manager.close(ws.id) + return existing + # ``ws`` is the freshly created workstream (manager-tracked id) + # even though the session resumed the original ``ws_id`` — the + # wake must target the live Workstream object, and firing it + # is what lets an unattended restore actually RUN the watch + # result (auto_approve above exists for exactly that turn). + ws.session.set_watch_runner(_watch_runner, wake_fn=_watch_fire_wake_fn(ws)) + return _watch_runner.get_dispatch_fn(ws.session._ws_id) + except WatchWorkstreamUnrestorable: + raise # shell already closed at the raise site above + except Exception: + # TRANSIENT: the shell exists but never became the watch's live + # target — close it (untrack + mark closed) so the failed + # attempt doesn't hold a max_active slot forever. + log.warning("watch_restore: resume failed for ws %s", ws_id, exc_info=True) + with contextlib.suppress(Exception): + manager.close(ws.id) + return None _watch_runner = WatchRunner( storage=_get_storage(), @@ -5067,10 +5243,16 @@ def main() -> None: if args.skip_permissions or config_store.get("tools.skip_permissions"): ws.ui.auto_approve = True assert ws.session is not None - ws.session.set_watch_runner(_watch_runner) if not ws.session.resume(target_id): log.error("Workstream '%s' has no messages.", args.resume) sys.exit(1) + # AFTER the successful resume (mirroring the restore fn's order), + # so the registration keys on the adopted ``target_id`` — the id + # the session's watch rows are stamped with. Registered before + # resume, the registry key would be the create-time id no watch + # row references, and every fire would restore a SECOND + # auto-approved session onto the operator's live conversation. + ws.session.set_watch_runner(_watch_runner, wake_fn=_watch_fire_wake_fn(ws)) log.info("Resumed workstream %s (%d messages)", target_id, len(ws.session.messages)) # Record detected model and judge status in metrics