From b667a21c992475b42673335bd092424741b2abbe Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Sun, 26 Apr 2026 22:18:23 -0400 Subject: [PATCH] chore: document regenerate lifecycle-rollback limitation with warning log (T83.4) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit When a regenerate replaces an assistant_turn that already produced lifecycle transitions (``event_started`` / ``event_completed`` / ``event_cancelled``), those transitions are NOT rolled back before ``detect_event_transitions`` re-runs against the new text. A regenerate-after-completion can therefore double-emit promotion artifacts. Phase 3.5 first cut (per the task plan): documentation + WARNING log naming the affected event_log ids. The actual undo pass is invasive (re-projection / inverse-handler dispatch) and is deferred to Phase 4. Implementation: - TODO docstring block at the top of ``regenerate_assistant_turn``. - Module-level ``_log = logging.getLogger(__name__)``. - Scan immediately after the original assistant_turn row is located: joins event_log lifecycle rows to the events table on event_id so we can scope by chat (lifecycle payloads carry only ``event_id``, not ``chat_id``). Filter ``id > original_assistant_event_id`` as the positional linkage to "transitions emitted as part of (or after) this turn's processing." Decision (asked in the brief): the scan uses the ``id > original`` heuristic rather than scanning for explicit references. Lifecycle event payloads do not carry a back-pointer to the assistant_turn that triggered them — the linkage is positional in the event log. A tighter linkage would require either adding a payload field on lifecycle events (cross-cutting schema change) or threading the just-appended assistant_turn id into ``detect_event_transitions``'s emit calls (narrow but still cross-cutting). The positional heuristic is loose but conservative: a turn that emits no lifecycle events produces no warning, and the warning's purpose is operator-visible breadcrumbs not an exact rollback set. Test: test_regenerate_with_prior_lifecycle_logs_warning seeds a turn that produced ``event_started`` + ``event_completed`` rows and asserts the WARNING fires with the expected ids. --- chat/services/regenerate.py | 50 +++++++++++++++++++ tests/test_regenerate.py | 95 +++++++++++++++++++++++++++++++++++++ 2 files changed, 145 insertions(+) diff --git a/chat/services/regenerate.py b/chat/services/regenerate.py index c61b684..020f57d 100644 --- a/chat/services/regenerate.py +++ b/chat/services/regenerate.py @@ -70,6 +70,7 @@ from __future__ import annotations import asyncio import json +import logging from sqlite3 import Connection from chat.config import Settings @@ -91,6 +92,8 @@ from chat.state.world import active_scene, get_chat from chat.web.pubsub import publish from chat.web.render import render_turn_html +_log = logging.getLogger(__name__) + async def regenerate_assistant_turn( conn: Connection, @@ -109,6 +112,19 @@ async def regenerate_assistant_turn( Raises :class:`ValueError` when the chat or the assistant_turn event cannot be found — the FastAPI route translates this to 404. + + .. note:: + **Lifecycle-rollback limitation (T83.4, Phase 4 follow-up).** + When the superseded turn already produced lifecycle transitions + (``event_started`` / ``event_completed`` / ``event_cancelled``), + this function does NOT roll those rows back before re-running + ``detect_event_transitions`` against the regenerated text. A + regenerate-after-completion can therefore double-emit promotion + artifacts if the new text re-completes the same event. Phase 3.5 + only documents the gap and emits a WARNING log naming the + affected event_log ids; the actual undo pass is invasive + (re-projection / inverse-handler dispatch) and is deferred to + Phase 4. See the ``# T83.4`` block below for the warning emit. """ chat = get_chat(conn, chat_id) if chat is None: @@ -141,6 +157,40 @@ async def regenerate_assistant_turn( original_assistant_payload = json.loads(row[0]) original_user_turn_id = original_assistant_payload.get("user_turn_id") + # T83.4: scan for downstream lifecycle transitions emitted by the + # superseded turn — they're not being rolled back (see method + # docstring). Heuristic: any ``event_started`` / ``event_completed`` + # / ``event_cancelled`` event_log row with id strictly greater than + # the original assistant_turn's id was emitted as part of (or after) + # that turn's processing. Lifecycle events don't carry ``chat_id`` + # in their payload (their payload references an ``event_id`` FK to + # the ``events`` table, which holds chat_id), so we join through + # ``events`` to scope to this chat. + # + # A WARNING log surfaces the affected event ids so operators can + # spot double-emit cases until the Phase 4 rollback pass lands. + unrolled_lifecycle = conn.execute( + "SELECT el.id, el.kind FROM event_log AS el " + "JOIN events AS ev " + " ON ev.event_id = json_extract(el.payload_json, '$.event_id') " + "WHERE el.kind IN (" + " 'event_started', 'event_completed', 'event_cancelled'" + " ) " + " AND ev.chat_id = ? " + " AND el.id > ? " + "ORDER BY el.id ASC", + (chat_id, original_assistant_event_id), + ).fetchall() + if unrolled_lifecycle: + _log.warning( + "regenerate_assistant_turn: %d lifecycle transition(s) from " + "superseded turn %s are NOT being rolled back (Phase 4 " + "follow-up). Affected event ids: %s", + len(unrolled_lifecycle), + original_assistant_event_id, + [r[0] for r in unrolled_lifecycle], + ) + # 1a. Look up any sibling interjection beat in the same turn group # (T73.2). The original group is (primary + optional interjection), # both pinned to the same ``user_turn_id``. The interjection has a diff --git a/tests/test_regenerate.py b/tests/test_regenerate.py index 0ffbd37..d8a2d65 100644 --- a/tests/test_regenerate.py +++ b/tests/test_regenerate.py @@ -664,6 +664,101 @@ def test_regenerate_drops_interjection_when_classifier_returns_false( assert "interjection_of" not in new_primary_payload +def test_regenerate_with_prior_lifecycle_logs_warning(tmp_path, monkeypatch, caplog): + """T83.4: when the superseded assistant_turn already produced + lifecycle transitions (event_started / event_completed / + event_cancelled), regenerate emits a WARNING naming the un-rolled- + back transitions. Phase 3.5 documents the gap; the actual rollback + is Phase 4 work. + """ + import asyncio + import logging + + from chat.config import Settings + from chat.db.migrate import apply_migrations + from chat.eventlog.log import append_and_apply + from chat.services.regenerate import regenerate_assistant_turn + + db_path = tmp_path / "test.db" + cfg = tmp_path / "config.toml" + cfg.write_text('featherless_api_key = "test"\n') + monkeypatch.setenv("CHAT_CONFIG_PATH", str(cfg)) + monkeypatch.setenv("CHAT_DB_PATH", str(db_path)) + apply_migrations(db_path) + + _ut_id, at_id = _seed_with_one_turn(db_path) + + # After the assistant_turn lands, simulate that the turn flow + # produced an event_completed transition. ``append_and_apply`` is + # the standard path so the events projection updates. + with open_db(db_path) as conn: + append_and_apply( + conn, + kind="event_planned", + payload={ + "event_id": "evt_x", + "chat_id": "chat_bot_a", + "kind": "story_event", + "props": {}, + "planned_for": "2026-04-30T18:00:00+00:00", + }, + ) + append_and_apply( + conn, + kind="event_started", + payload={ + "event_id": "evt_x", + "started_at": "2026-04-30T19:00:00+00:00", + }, + ) + completed_id = append_and_apply( + conn, + kind="event_completed", + payload={ + "event_id": "evt_x", + "completed_at": "2026-04-30T19:30:00+00:00", + }, + ) + assert completed_id is not None + + state_canned = json.dumps( + {"affinity_delta": 0, "trust_delta": 0, "knowledge_facts": []} + ) + mock_client = MockLLMClient( + canned=["Refreshed reply.", state_canned, state_canned] + ) + settings = Settings(featherless_api_key="test") + + caplog.set_level(logging.WARNING, logger="chat.services.regenerate") + + with open_db(db_path) as conn: + asyncio.run( + regenerate_assistant_turn( + conn, + mock_client, + settings=settings, + chat_id="chat_bot_a", + original_assistant_event_id=at_id, + ) + ) + + # The warning records the count and at least one of the affected + # event_log ids (event_started + event_completed = at minimum 2). + warnings = [ + r for r in caplog.records if r.levelname == "WARNING" + ] + matching = [w for w in warnings if "lifecycle transition" in w.getMessage()] + assert matching, ( + "expected a WARNING about un-rolled-back lifecycle transitions; " + f"got: {[w.getMessage() for w in warnings]}" + ) + msg = matching[0].getMessage() + # Reference the original superseded turn's id and the event_completed + # row's id. + assert str(at_id) in msg + assert str(completed_id) in msg + + def test_regenerate_sibling_lookup_scoped_to_chat(tmp_path, monkeypatch): """T83.3: regenerate's sibling-interjection lookup is scoped to the chat being regenerated.