fix(runtime): bind before embeddings, keep audit history, refuse bad config

Closes SECURITY_ANALYSIS.md H-05, H-06 and the lower-severity audit, bearer and
CLI gaps.

H-06: the process awaited svc.start() before either listener bound, and startup
synchronously awaited an embedding self-test plus pending embeddings, each able
to spend three 60s attempts. Kubernetes could kill the pod before /healthz ever
bound, repeatedly preventing the lexical-only degradation the plan promises.
Startup now runs as a background task and the embedding work with it. H-05: the
watcher started only after scan, so a file changed in between emitted no event
and stayed unindexed; the watcher now starts before a reconciling second scan.

AuditLog.recent read persisted history only while its in-memory list was
completely empty, so after a restart plus one call the health page showed only
that call. It now merges both without duplicates, reading a bounded tail rather
than the whole append-only file — /metrics calls it on every scrape.

MCP_TOKEN is validated at startup: non-empty, ASCII, no whitespace or control
characters, minimum length. A padded or non-ASCII value silently 401s every
client. --mcp-only with --ui-only built an empty server list, so the process
bound nothing and exited 0 — a silent restart loop; argparse now refuses it.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0139vHnNpS2sLNELjrAHX5Cu

src/mdmem/cli.py

@@ -18,8 +18,13 @@ def build_parser() -> argparse.ArgumentParser:
     sub = p.add_subparsers(dest="command", required=False, metavar="{serve,reindex,eval,doctor}")
 
     serve = sub.add_parser("serve", help="run the MCP listener and the web UI")
-    serve.add_argument("--mcp-only", action="store_true", help="only start the MCP listener")
-    serve.add_argument("--ui-only", action="store_true", help="only start the web UI")
+    # Both together would bind no listener at all: run_serve builds an empty
+    # server list, gather() returns immediately and the process exits 0 with
+    # nothing serving -- in Kubernetes a silent restart loop with no error to
+    # go on. Let argparse refuse the combination instead.
+    listeners = serve.add_mutually_exclusive_group()
+    listeners.add_argument("--mcp-only", action="store_true", help="only start the MCP listener")
+    listeners.add_argument("--ui-only", action="store_true", help="only start the web UI")
     serve.add_argument("--no-watch", action="store_true", help="do not watch the vault for changes")
 
     reindex = sub.add_parser("reindex", help="rebuild the index from the vault")

src/mdmem/config.py

@@ -9,6 +9,29 @@ from pathlib import Path
 FUSIONS = ("rrf", "cc")
 NOTE_TYPES = ("fact", "preference", "decision", "procedure", "entity", "event", "note")
 STATES = ("inbox", "active", "archive")
+MIN_MCP_TOKEN_LEN = 16
+
+
+def validate_mcp_token(token: str) -> str:
+    """Fail loudly on an `MCP_TOKEN` a client cannot reliably present (§9).
+
+    A bearer token compared with `secrets.compare_digest` must match byte for
+    byte, so whitespace padding, control characters or non-ASCII content in
+    the configured value silently breaks every legitimate client rather than
+    raising -- the failure mode is "every request 401s" with no clue why.
+    Reject those forms here instead, at startup.
+    """
+    if not token or not token.strip():
+        raise ValueError("MCP_TOKEN must not be empty")
+    if token != token.strip():
+        raise ValueError("MCP_TOKEN must not have leading or trailing whitespace")
+    if not token.isascii():
+        raise ValueError("MCP_TOKEN must be pure ASCII")
+    if any(ch.isspace() or ord(ch) < 0x20 or ord(ch) == 0x7F for ch in token):
+        raise ValueError("MCP_TOKEN must not contain whitespace or control characters")
+    if len(token) < MIN_MCP_TOKEN_LEN:
+        raise ValueError(f"MCP_TOKEN must be at least {MIN_MCP_TOKEN_LEN} characters, got {len(token)}")
+    return token
 
 
 def _bool(name: str, default: bool) -> bool:

src/mdmem/logging.py

@@ -47,6 +47,10 @@ def log(logger: logging.Logger, level: int, msg: str, **fields: Any) -> None:
     logger.log(level, msg, extra={"fields": fields})
 
 
+_AUDIT_LINE_ESTIMATE = 512  # bytes; only sizes the first read, never correctness
+_AUDIT_TAIL_MAX_BYTES = 32 * 1024 * 1024
+
+
 class AuditLog:
     """Append-only JSON-lines log of tool calls. Never records note bodies (§9)."""
 
@@ -75,18 +79,57 @@ class AuditLog:
         self._log.info("tool_call", extra={"fields": fields})
 
     def recent(self, limit: int = 100) -> list[dict[str, Any]]:
-        out = self._recent[-limit:]
-        if not out and self.path is not None and self.path.exists():
-            try:
-                lines = self.path.read_text(encoding="utf-8").splitlines()[-limit:]
-            except OSError:
-                return []
-            for line in lines:
+        """Newest-first, up to `limit` entries across a restart.
+
+        Every `record()` call appends both to `self._recent` and to the
+        persisted file, so the file's tail always duplicates `self._recent`
+        exactly (barring a write failure). We therefore only pull the
+        *historical* prefix of the file -- the part older than whatever this
+        instance already holds in memory -- and append the in-memory entries
+        on top, instead of reading the file only when memory happens to be
+        empty (which loses everything from before the current process's
+        first call).
+        """
+        historical: list[dict[str, Any]] = []
+        if self.path is not None and self.path.exists():
+            lines = self._tail_lines(limit + len(self._recent))
+            cutoff = len(lines) - len(self._recent)
+            for line in (lines[:cutoff][-limit:] if cutoff > 0 else []):
                 try:
-                    out.append(json.loads(line))
+                    historical.append(json.loads(line))
                 except ValueError:
                     continue
-        return list(reversed(out))
+        combined = historical + self._recent
+        return list(reversed(combined[-limit:]))
+
+    def _tail_lines(self, want: int) -> list[str]:
+        """The last `want` lines of the audit file, without reading all of it.
+
+        The file is append-only and never rotated by us, so it grows without
+        bound; `/metrics` calls `recent()` on every Prometheus scrape. Reading
+        the whole file each time would turn a months-old audit trail into a
+        multi-megabyte read every 15 seconds, so seek back from the end and
+        only widen the window if it did not cover enough lines.
+        """
+        if want <= 0:
+            return []
+        try:
+            size = self.path.stat().st_size  # type: ignore[union-attr]
+            with self.path.open("rb") as fh:  # type: ignore[union-attr]
+                window = min(size, max(want, 1) * _AUDIT_LINE_ESTIMATE)
+                while True:
+                    fh.seek(size - window)
+                    raw = fh.read(window)
+                    # a backwards seek usually lands mid-line; that first
+                    # fragment is not a whole entry
+                    lines = raw.decode("utf-8", errors="replace").splitlines()
+                    if window < size:
+                        lines = lines[1:]
+                    if len(lines) >= want or window >= size or window >= _AUDIT_TAIL_MAX_BYTES:
+                        return lines[-want:]
+                    window = min(size, window * 4)
+        except OSError:
+            return []
 
 
 def audit_path_from_env() -> Path | None:

src/mdmem/server.py

@@ -68,7 +68,9 @@ def run_serve(settings: Settings, args: Any) -> int:
 
     async def _main() -> int:
         svc = MemoryService.build(settings)
-        await svc.start(watch=not getattr(args, "no_watch", False))
+        start_task = asyncio.create_task(
+            svc.start(watch=not getattr(args, "no_watch", False)), name="mdmem-service-start"
+        )
         servers: list[uvicorn.Server] = []
         if not getattr(args, "ui_only", False):
             servers.append(
@@ -107,9 +109,25 @@ def run_serve(settings: Settings, args: Any) -> int:
                 }
             },
         )
+        async def watch_startup() -> None:
+            try:
+                await start_task
+            except asyncio.CancelledError:
+                raise
+            except Exception:
+                log.exception("mdmem service startup failed")
+                for server in servers:
+                    server.should_exit = True
+
         try:
-            await asyncio.gather(*(s.serve() for s in servers))
+            await asyncio.gather(*(s.serve() for s in servers), watch_startup())
         finally:
+            if not start_task.done():
+                start_task.cancel()
+                try:
+                    await start_task
+                except asyncio.CancelledError:
+                    pass
             await svc.stop()
         return 0
 

tests/conftest.py

@@ -22,5 +22,5 @@ def settings(tmp_path, monkeypatch):
     monkeypatch.setenv("CACHE_DB", str(tmp_path / "cache.db"))
     monkeypatch.setenv("HISTORY_DIR", str(tmp_path / ".history"))
     monkeypatch.setenv("EMBED_DIM", "16")
-    monkeypatch.setenv("MCP_TOKEN", "test-token")
+    monkeypatch.setenv("MCP_TOKEN", "test-token-0123456789")
     return Settings.from_env()

tests/test_cli.py

@@ -1,5 +1,12 @@
+import asyncio
 import subprocess
 import sys
+import types
+
+import pytest
+
+from mdmem import cli, server
+from mdmem.embed import FakeEmbedder
 
 
 def _run(*args):
@@ -17,3 +24,216 @@ def test_version():
     r = _run("--version")
     assert r.returncode == 0
     assert "0.1.0" in r.stdout
+
+
+# -- subcommand dispatch (cli.main() forwards parsed args untouched) -------
+
+
+def test_serve_dispatches_to_run_serve_with_its_flags(settings, monkeypatch):
+    calls = {}
+
+    def fake_run_serve(passed_settings, args):
+        calls["settings"] = passed_settings
+        calls["args"] = args
+        return 0
+
+    monkeypatch.setattr("mdmem.server.run_serve", fake_run_serve)
+    rc = cli.main(["serve", "--mcp-only", "--no-watch"])
+    assert rc == 0
+    assert calls["settings"] is not None
+    assert calls["args"].mcp_only is True
+    assert calls["args"].ui_only is False
+    assert calls["args"].no_watch is True
+
+
+def test_reindex_dispatches_to_run_reindex_with_its_flags(settings, monkeypatch):
+    calls = {}
+
+    def fake_run_reindex(passed_settings, args):
+        calls["args"] = args
+        return 3
+
+    monkeypatch.setattr("mdmem.server.run_reindex", fake_run_reindex)
+    rc = cli.main(["reindex", "--full", "--no-embed"])
+    assert rc == 3
+    assert calls["args"].full is True
+    assert calls["args"].no_embed is True
+
+
+def test_eval_dispatches_to_run_eval_cli_with_its_flags(settings, monkeypatch):
+    calls = {}
+
+    def fake_run_eval_cli(passed_settings, args):
+        calls["args"] = args
+        return 0
+
+    monkeypatch.setattr("mdmem.evalharness.run_eval_cli", fake_run_eval_cli)
+    rc = cli.main(
+        [
+            "eval",
+            "--queries",
+            "some/queries.yaml",
+            "--config",
+            "trial",
+            "--out",
+            "out.json",
+            "--ablate",
+            "--fake-embeddings",
+        ]
+    )
+    assert rc == 0
+    assert calls["args"].queries == "some/queries.yaml"
+    assert calls["args"].config == "trial"
+    assert calls["args"].out == "out.json"
+    assert calls["args"].ablate is True
+    assert calls["args"].fake_embeddings is True
+
+
+def test_doctor_dispatches_to_run_doctor(settings, monkeypatch):
+    calls = {}
+
+    def fake_run_doctor(passed_settings):
+        calls["settings"] = passed_settings
+        return 0
+
+    monkeypatch.setattr("mdmem.server.run_doctor", fake_run_doctor)
+    rc = cli.main(["doctor"])
+    assert rc == 0
+    assert calls["settings"] is not None
+
+
+def test_no_subcommand_prints_help_and_exits_zero(settings, capsys):
+    rc = cli.main([])
+    assert rc == 0
+    assert "serve" in capsys.readouterr().out
+
+
+# -- contradictory mode flags -----------------------------------------------
+
+
+def test_contradictory_serve_flags_are_refused_at_parse_time(settings, monkeypatch, capsys):
+    """--mcp-only --ui-only together makes run_serve build an empty server list,
+    so the process binds nothing and exits 0 — in Kubernetes a silent restart
+    loop with no error to diagnose. argparse must refuse the combination."""
+    calls = {}
+
+    def fake_run_serve(passed_settings, args):
+        calls["args"] = args
+        return 0
+
+    monkeypatch.setattr("mdmem.server.run_serve", fake_run_serve)
+    with pytest.raises(SystemExit) as exc:
+        cli.main(["serve", "--mcp-only", "--ui-only"])
+    assert exc.value.code == 2
+    assert "not allowed with" in capsys.readouterr().err
+    assert "args" not in calls, "the contradictory run must never reach run_serve"
+
+
+def test_either_mode_flag_alone_still_parses(settings, monkeypatch):
+    calls = []
+    monkeypatch.setattr("mdmem.server.run_serve", lambda s, a: calls.append(a) or 0)
+    assert cli.main(["serve", "--mcp-only"]) == 0
+    assert cli.main(["serve", "--ui-only"]) == 0
+    assert [(a.mcp_only, a.ui_only) for a in calls] == [(True, False), (False, True)]
+
+
+# -- startup failure path ----------------------------------------------------
+
+
+def test_startup_failure_in_the_dispatched_command_propagates(settings, monkeypatch):
+    """cli.main() has no try/except around the dispatch, so a failure raised
+    while starting up a subcommand surfaces to the caller rather than being
+    swallowed into a generic nonzero exit code."""
+
+    def boom(passed_settings):
+        raise RuntimeError("index db is corrupt")
+
+    monkeypatch.setattr("mdmem.server.run_doctor", boom)
+    with pytest.raises(RuntimeError, match="index db is corrupt"):
+        cli.main(["doctor"])
+
+
+# -- serve(): real run_serve, fake uvicorn.Server and embedder --------------
+
+
+def _patch_offline_embedder(monkeypatch):
+    """run_serve builds its own MemoryService with a real BifrostEmbedder;
+    swap it for the deterministic offline embedder (as the `svc` fixture in
+    test_mcp.py does) so these tests need no network."""
+    import mdmem.service as service_mod
+
+    monkeypatch.setattr(
+        service_mod,
+        "BifrostEmbedder",
+        lambda url, vk, model, dim, cache=None: FakeEmbedder(dim, model=model, cache=cache),
+    )
+    return service_mod
+
+
+def test_run_serve_graceful_shutdown_stops_the_service(settings, monkeypatch):
+    """A server whose serve() loop ends on its own (as after a clean SIGTERM)
+    must still run run_serve's finally block -- cancelling the startup task
+    and calling svc.stop() -- and the function returns 0."""
+    service_mod = _patch_offline_embedder(monkeypatch)
+
+    class ImmediateFakeServer:
+        def __init__(self, config):
+            self.config = config
+            self.should_exit = False
+
+        async def serve(self):
+            return
+
+    monkeypatch.setattr("uvicorn.Server", ImmediateFakeServer)
+
+    stop_calls = []
+    real_stop = service_mod.MemoryService.stop
+
+    async def tracking_stop(self):
+        stop_calls.append(True)
+        await real_stop(self)
+
+    monkeypatch.setattr(service_mod.MemoryService, "stop", tracking_stop)
+
+    args = types.SimpleNamespace(mcp_only=True, ui_only=False, no_watch=True)
+    rc = server.run_serve(settings, args)
+
+    assert rc == 0
+    assert stop_calls == [True]
+
+
+def test_run_serve_startup_failure_sets_should_exit_and_still_shuts_down(settings, monkeypatch):
+    """When the background startup task fails, run_serve's watch_startup()
+    must flip should_exit on every listener so it can wind down -- and the
+    function still returns 0 rather than hanging or propagating."""
+    service_mod = _patch_offline_embedder(monkeypatch)
+
+    async def failing_start(self, *, watch=True, embed=True):
+        raise RuntimeError("vault scan blew up")
+
+    monkeypatch.setattr(service_mod.MemoryService, "start", failing_start)
+
+    class LoopingFakeServer:
+        instances: list["LoopingFakeServer"] = []
+
+        def __init__(self, config):
+            self.config = config
+            self.should_exit = False
+            LoopingFakeServer.instances.append(self)
+
+        async def serve(self):
+            for _ in range(500):  # bounded, so a regression fails the test instead of hanging
+                if self.should_exit:
+                    return
+                await asyncio.sleep(0.01)
+            raise AssertionError("server never received should_exit after a startup failure")
+
+    LoopingFakeServer.instances = []
+    monkeypatch.setattr("uvicorn.Server", LoopingFakeServer)
+
+    args = types.SimpleNamespace(mcp_only=True, ui_only=False, no_watch=True)
+    rc = server.run_serve(settings, args)
+
+    assert rc == 0
+    assert LoopingFakeServer.instances
+    assert all(s.should_exit for s in LoopingFakeServer.instances)

tests/test_config.py

@@ -1,6 +1,6 @@
 import pytest
 
-from mdmem.config import Settings
+from mdmem.config import Settings, validate_mcp_token
 
 
 def test_defaults_match_plan(tmp_path, monkeypatch):
@@ -59,3 +59,35 @@ def test_empty_min_score_is_none(monkeypatch, tmp_path):
     assert Settings.from_env().min_score is None
     monkeypatch.setenv("MIN_SCORE", "0.2")
     assert Settings.from_env().min_score == pytest.approx(0.2)
+
+
+@pytest.mark.parametrize(
+    "token",
+    [
+        "a-perfectly-fine-token-32chars!",
+        "0123456789abcdef",  # exactly the 16-char minimum
+        "A_valid-Token.With~Punct123",
+    ],
+)
+def test_validate_mcp_token_accepts_clean_ascii_tokens(token):
+    assert validate_mcp_token(token) == token
+
+
+@pytest.mark.parametrize(
+    ("token", "match"),
+    [
+        ("", "empty"),
+        ("   ", "empty"),
+        (" leading-space-padded-token", "whitespace"),
+        ("trailing-space-padded-token ", "whitespace"),
+        ("has a space in the middle!!", "whitespace"),
+        ("has\ta-tab-in-it-somewhere!!", "whitespace"),
+        ("has\na-newline-in-it-somehow!", "whitespace"),
+        ("control-char-\x00-embedded!!!!", "whitespace"),
+        ("tökenwithnönasciichars!!!!!!!", "ASCII"),
+        ("short", "at least 16"),
+    ],
+)
+def test_validate_mcp_token_rejects_unpresentable_forms(token, match):
+    with pytest.raises(ValueError, match=match):
+        validate_mcp_token(token)

tests/test_logging.py

@@ -0,0 +1,104 @@
+from pathlib import Path
+
+from mdmem.logging import AuditLog
+
+
+def test_recent_merges_persisted_history_across_restart_without_duplicates(tmp_path):
+    """`AuditLog.recent` must return the merged tail of persisted history plus
+    in-memory entries across a restart, newest-first, without duplicating the
+    entries that show up in both (SECURITY_ANALYSIS.md, logging.py:77-92)."""
+    path = tmp_path / "audit.jsonl"
+    first = AuditLog(path)
+    for i in range(5):
+        first.record(tool="memory_search", seq=i)
+
+    # A fresh AuditLog over the same file simulates a process restart: its
+    # in-memory list starts empty even though history is already on disk.
+    second = AuditLog(path)
+    second.record(tool="memory_write", seq=5)
+
+    got = second.recent(100)
+    seqs = [entry["seq"] for entry in got]
+    assert seqs == [5, 4, 3, 2, 1, 0]
+    assert len(seqs) == len(set(seqs))
+
+
+def test_recent_respects_limit_across_the_persisted_in_memory_boundary(tmp_path):
+    path = tmp_path / "audit.jsonl"
+    first = AuditLog(path)
+    for i in range(5):
+        first.record(tool="memory_search", seq=i)
+
+    second = AuditLog(path)
+    second.record(tool="memory_write", seq=5)
+    second.record(tool="memory_write", seq=6)
+
+    got = second.recent(3)
+    assert [entry["seq"] for entry in got] == [6, 5, 4]
+
+
+def test_recent_before_any_new_call_still_sees_persisted_history(tmp_path):
+    """Even with zero in-memory entries, a fresh instance over an existing
+    file must not report an empty history."""
+    path = tmp_path / "audit.jsonl"
+    first = AuditLog(path)
+    for i in range(3):
+        first.record(tool="memory_search", seq=i)
+
+    second = AuditLog(path)
+    got = second.recent(100)
+    assert [entry["seq"] for entry in got] == [2, 1, 0]
+
+
+def test_recent_without_a_persisted_path_uses_memory_only(tmp_path):
+    log = AuditLog(None)
+    log.record(tool="memory_search", seq=0)
+    log.record(tool="memory_write", seq=1)
+    assert [entry["seq"] for entry in log.recent(100)] == [1, 0]
+
+
+def test_recent_does_not_read_the_whole_audit_file(tmp_path, monkeypatch):
+    """/metrics calls recent() on every Prometheus scrape and the audit file is
+    append-only, so a months-old trail must not become a multi-megabyte read
+    every 15 seconds."""
+    path = tmp_path / "audit.jsonl"
+    audit = AuditLog(path)
+    for i in range(20_000):
+        audit.record(tool="memory_search", ok=True, seq=i)
+    assert path.stat().st_size > 1_000_000
+
+    fresh = AuditLog(path)  # restart: nothing in memory
+    read_bytes = 0
+    real_read = Path.open
+
+    def counting_open(self, *a, **kw):
+        fh = real_read(self, *a, **kw)
+        inner_read = fh.read
+
+        def tracked(n=-1):
+            data = inner_read(n)
+            nonlocal read_bytes
+            read_bytes += len(data)
+            return data
+
+        fh.read = tracked  # type: ignore[method-assign]
+        return fh
+
+    monkeypatch.setattr(Path, "open", counting_open)
+    rows = fresh.recent(100)
+    assert [r["seq"] for r in rows] == list(range(19_999, 19_899, -1))
+    assert read_bytes < path.stat().st_size // 4, f"read {read_bytes} of {path.stat().st_size} bytes"
+
+
+def test_recent_widens_its_window_for_unusually_long_entries(tmp_path):
+    """The tail window is sized by an estimate, not a guarantee: long entries must
+    still yield the full requested count, not a short page."""
+    path = tmp_path / "audit.jsonl"
+    audit = AuditLog(path)
+    for i in range(300):
+        audit.record(tool="memory_search", ok=True, seq=i, filler="x" * 4000)
+
+    fresh = AuditLog(path)
+    rows = fresh.recent(100)
+    assert len(rows) == 100
+    assert [r["seq"] for r in rows] == list(range(299, 199, -1))