From 6bdc6cf0bd737daef720289c39b61d860acff7ae Mon Sep 17 00:00:00 2001 From: Patrick Buckley Date: Mon, 11 May 2026 16:29:41 -0700 Subject: [PATCH] feat(audit): emit memory tool save/update/delete events MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Previously only the admin-console DELETE route emitted memory.delete audit rows, so a long-running session whose memory was deleted via the admin UI had no log trail showing what happened — masking out-of-band deletes as apparent tool bugs. The save branch now stamps memory.save (new row) or memory.update (upsert); the delete branch does a lookup-then-delete-by-id pair so the audit can record the resolved memory_id and type. All emissions are best-effort: failures log at debug and swallow so an audit hiccup never breaks the tool call itself. Reads (get/search/list) remain un-audited. --- tests/test_session.py | 196 ++++++++++++++++++++++++++++++++++++++ turnstone/core/session.py | 84 +++++++++++++++- 2 files changed, 275 insertions(+), 5 deletions(-) diff --git a/tests/test_session.py b/tests/test_session.py index b4d44881..9819ecc2 100644 --- a/tests/test_session.py +++ b/tests/test_session.py @@ -1974,6 +1974,202 @@ class TestCoordinatorMemoryScope: assert scopes == ["workstream", "user", "global"] +class TestMemoryToolAudit: + """Mutating memory tool actions emit audit rows. + + Closes the gap that masked the May 2026 vllm_fork_overlay_pattern + investigation: only the admin-console DELETE route emitted + ``memory.delete``, so a long-running session whose memory was + deleted via the admin UI couldn't tell from logs alone whether the + row had been deleted out-of-band, never persisted, or was never + visible. Read actions (get/search/list) intentionally stay + un-audited — auditing reads would multiply audit volume without + forensic value. + """ + + @staticmethod + def _audit_rows(action: str) -> list[dict]: + from turnstone.core.storage._registry import get_storage + + return get_storage().list_audit_events(action=action) + + def test_save_new_emits_memory_save(self, tmp_db): + session = _make_session(ws_id="ws-1", user_id="user-1") + item = session._prepare_memory( + "call_1", + { + "action": "save", + "name": "fact_one", + "content": "alpha content", + "scope": "user", + "type": "reference", + }, + ) + assert "error" not in item + session._exec_memory(item) + + rows = self._audit_rows("memory.save") + assert len(rows) == 1 + row = rows[0] + assert row["user_id"] == "user-1" + assert row["resource_type"] == "memory" + assert row["resource_id"] # memory_id was populated + detail = json.loads(row["detail"]) + assert detail["name"] == "fact_one" + assert detail["scope"] == "user" + assert detail["scope_id"] == "user-1" + assert detail["type"] == "reference" + assert detail["ws_id"] == "ws-1" + # The "create" path must NOT also stamp an update row. + assert self._audit_rows("memory.update") == [] + + def test_save_global_scope_emits_empty_scope_id(self, tmp_db): + """Global memories have no scope_id — the audit row's detail + must still carry the key (with value ``""``) so a forensic + consumer can distinguish ``scope='global'`` from a row that + forgot to populate ``scope_id`` for a scoped write.""" + session = _make_session(ws_id="ws-1", user_id="user-1") + item = session._prepare_memory( + "call_1", + { + "action": "save", + "name": "fact_global", + "content": "shared content", + "scope": "global", + }, + ) + assert "error" not in item + session._exec_memory(item) + + rows = self._audit_rows("memory.save") + assert len(rows) == 1 + detail = json.loads(rows[0]["detail"]) + assert detail["scope"] == "global" + assert detail["scope_id"] == "" + assert detail["ws_id"] == "ws-1" + + def test_save_upsert_emits_memory_update(self, tmp_db): + session = _make_session(ws_id="ws-1", user_id="user-1") + for content in ("first", "second"): + item = session._prepare_memory( + "call_x", + { + "action": "save", + "name": "fact_one", + "content": content, + "scope": "user", + "type": "reference", + }, + ) + session._exec_memory(item) + + saves = self._audit_rows("memory.save") + updates = self._audit_rows("memory.update") + assert len(saves) == 1 + assert len(updates) == 1 + # Same memory_id on both rows — the update audits the row save created. + assert saves[0]["resource_id"] == updates[0]["resource_id"] + + def test_delete_emits_memory_delete(self, tmp_db): + session = _make_session(ws_id="ws-1", user_id="user-1") + save_item = session._prepare_memory( + "call_1", + { + "action": "save", + "name": "fact_one", + "content": "alpha", + "scope": "user", + "type": "reference", + }, + ) + session._exec_memory(save_item) + saved_memory_id = self._audit_rows("memory.save")[0]["resource_id"] + + delete_item = session._prepare_memory( + "call_2", + {"action": "delete", "name": "fact_one", "scope": "user"}, + ) + _, msg = session._exec_memory(delete_item) + assert "Deleted memory" in msg + + rows = self._audit_rows("memory.delete") + assert len(rows) == 1 + # resource_id must point at the same row save audited — proves + # delete-by-name resolved to the right row before recording. + assert rows[0]["resource_id"] == saved_memory_id + detail = json.loads(rows[0]["detail"]) + assert detail["name"] == "fact_one" + assert detail["scope"] == "user" + assert detail["type"] == "reference" + + def test_delete_not_found_emits_no_audit(self, tmp_db): + session = _make_session(ws_id="ws-1", user_id="user-1") + delete_item = session._prepare_memory( + "call_1", + {"action": "delete", "name": "no_such_mem", "scope": "user"}, + ) + _, msg = session._exec_memory(delete_item) + assert "not found" in msg + assert self._audit_rows("memory.delete") == [] + + def test_reads_emit_no_audit(self, tmp_db): + session = _make_session(ws_id="ws-1", user_id="user-1") + session._exec_memory( + session._prepare_memory( + "call_save", + { + "action": "save", + "name": "fact_one", + "content": "alpha", + "scope": "user", + }, + ) + ) + + for spec in ( + {"action": "get", "name": "fact_one", "scope": "user"}, + {"action": "search", "query": "fact"}, + {"action": "list"}, + ): + item = session._prepare_memory("call_read", spec) + assert "error" not in item + session._exec_memory(item) + + # Only the save above should have audited. + save_count = len(self._audit_rows("memory.save")) + update_count = len(self._audit_rows("memory.update")) + delete_count = len(self._audit_rows("memory.delete")) + assert (save_count, update_count, delete_count) == (1, 0, 0) + + def test_audit_failure_does_not_break_tool_call(self, tmp_db): + """A blow-up inside record_audit must not propagate to the LLM. + + Auditing is best-effort instrumentation; a storage hiccup that + prevents the audit row from landing must not also lose the + save/delete the user actually asked for. + """ + session = _make_session(ws_id="ws-1", user_id="user-1") + item = session._prepare_memory( + "call_1", + { + "action": "save", + "name": "fact_one", + "content": "alpha", + "scope": "user", + }, + ) + with patch( + "turnstone.core.audit.record_audit", + side_effect=RuntimeError("audit storage exploded"), + ): + _, msg = session._exec_memory(item) + assert "Saved memory 'fact_one'" in msg + # The save itself still landed. + from turnstone.core.memory import get_structured_memory_by_name + + assert get_structured_memory_by_name("fact_one", "user", "user-1") is not None + + class TestPerKindToolVariants: """Verify the ``kind_variants`` metadata applies per-kind tool overrides. diff --git a/turnstone/core/session.py b/turnstone/core/session.py index 69b80f1f..d06b70fe 100644 --- a/turnstone/core/session.py +++ b/turnstone/core/session.py @@ -50,7 +50,7 @@ from turnstone.core.log import get_logger from turnstone.core.memory import ( count_structured_memories, delete_messages_after, - delete_structured_memory, + delete_structured_memory_by_id, delete_workstream, get_skill_by_name, get_structured_memory_by_name, @@ -9638,6 +9638,56 @@ class ChatSession: return content + def _audit_memory_event( + self, + action: str, + memory_id: str, + *, + name: str, + scope: str, + scope_id: str, + mem_type: str, + ) -> None: + """Emit an audit row for a mutating memory tool action. + + Closes the audit gap that previously masked out-of-band deletes + when investigating "save reports success but get returns + not-found": only the admin-console DELETE route emitted + ``memory.delete`` rows, so a long-running session whose row was + deleted by the console UI couldn't tell from logs alone whether + the row had been deleted, never persisted, or was never visible. + + ``scope_id`` is the empty string for ``scope='global'`` and the + actor's user_id / ws_id for the other scopes — written as-is so + forensic queries can filter on it. ``ws_id`` always rides in + the detail (``self._ws_id`` is unconditional on ChatSession). + + Best-effort: failures log at debug and swallow so an audit hiccup + never breaks the tool call itself. Reads (get/search/list) are + intentionally not audited — they'd multiply audit volume + without forensic value. + """ + try: + from turnstone.core.audit import record_audit + + detail: dict[str, Any] = { + "name": name, + "scope": scope, + "scope_id": scope_id, + "type": mem_type, + "ws_id": self._ws_id, + } + record_audit( + get_storage(), + self._user_id, + action, + "memory", + memory_id, + detail, + ) + except Exception: + log.debug("memory.audit_failed action=%s name=%s", action, name, exc_info=True) + def _exec_memory(self, item: dict[str, Any]) -> tuple[str, str]: """Execute a memory tool action.""" call_id = item["call_id"] @@ -9659,6 +9709,14 @@ class ChatSession: return call_id, msg self._invalidate_memory_cache() self._init_system_messages() + self._audit_memory_event( + "memory.update" if old is not None else "memory.save", + memory_id, + name=item["name"], + scope=item["scope"], + scope_id=item["scope_id"], + mem_type=item["mem_type"], + ) if old is not None: msg = f"Updated memory '{item['name']}' (type={item['mem_type']}, scope={item['scope']})" else: @@ -9691,20 +9749,36 @@ class ChatSession: if action == "delete": scopes = item["scopes_to_try"] - deleted = False + deleted: dict[str, str] | None = None deleted_scope = "" + deleted_scope_id = "" + # Look up first so the audit row can record the deleted + # memory_id + type (delete-by-name returns only a bool). + # Falling back through the scope walk keeps the current + # narrowest-first IC semantics; coord sessions only see + # ``coordinator`` here. for scope, scope_id in scopes: - if delete_structured_memory(item["name"], scope, scope_id): - deleted = True + existing = get_structured_memory_by_name(item["name"], scope, scope_id) + if existing and delete_structured_memory_by_id(existing["memory_id"]): + deleted = existing deleted_scope = scope + deleted_scope_id = scope_id break - if not deleted: + if deleted is None: tried = ", ".join(s for s, _ in scopes) msg = f"Error: memory '{item['name']}' not found (searched scopes: {tried})" self._report_tool_result(call_id, "memory", msg, is_error=True) else: self._invalidate_memory_cache() self._init_system_messages() + self._audit_memory_event( + "memory.delete", + deleted["memory_id"], + name=item["name"], + scope=deleted_scope, + scope_id=deleted_scope_id, + mem_type=deleted.get("type", ""), + ) msg = f"Deleted memory '{item['name']}' (scope={deleted_scope})" self._report_tool_result(call_id, "memory", msg) return call_id, msg