phase: 187_sync_peak_memory_line
Build and Push Containers / build-and-push-app (push) Successful in 1m47s
Build and Push Containers / build-and-push-db (push) Successful in 13s

**Phase 187 — final verification pass: all criteria met, repo 100% green.**

Verified (all four tasks already in `complete/`)
- `app/core/memory.py`: `rss_mb` / `rss_peak_mb` / `cgroup_peak_mb` / `fmt_mb`, pure stdlib, never-raise, **100%** coverage, 24 branch tests.
- Lifecycle lines append-only: `sync: started … rss_mb=`, all three terminals `… rss_mb= rss_peak_mb=` (failed = sanitized one-liner beside the surviving `logger.exception`), `import: summary … rss_mb=`; prefixes byte-identical.
- `GET /api/sync/status`: additive `rss_mb`/`rss_peak_mb` (`int|null`), keyed off the ONE `_sample_rss` (run start, phase transitions, forced terminals, 5 s-throttled hook), `peak >= current` invariant, anonymous 403.
- `sources.js` `fmtSyncPeakClause`: ` · peak <N> MB` trailing the counts line / "Sync cancelled", nothing when null, no new control/live region.

Gates (exact commands)
- `uv run pytest --cov=app --cov-report=term-missing` → **4570 passed**, TOTAL **99%**, `app/api/sync.py` **100%**, `app/core/memory.py` **100%**
- `uv run ruff check .` → clean · `uv run pyright` → **0 errors**
- `uv run pytest tests/e2e/test_sync_peak_memory_visible.py -v --no-cov` → **5 passed in isolation** (ran twice)
- All 27 touched E2E families re-run **in isolation**, all green (progress_box 8, cancel 3, status_freshness 4, summary_visibility 3, sync_button 3, session_reset 4, git_freeze 2, git_log_stream_dates 5, PDF/image suites, …)

Completion criteria: every checkbox ✅ except the commit + phase-dir move, which belong to the harness.

Documentation
- README reviewed in full (pages, commands, config tables cross-checked against `app/config.py` — 85 env rows, all defaults match; phase-187 ops section, greps, process-vs-cgroup caveat): consistent, no changes needed.
- `AGENTS.md`: **fixed one pre-existing inconsistency** — rule 6 claimed the no-CDN test covers "the index page"; it actually parametrizes 10 pages (all but `/doc-edit.html`).

Notable
- Two failures early in the pass were self-inflicted by running the E2E module concurrently with the full suite on the shared Postgres (TRUNCATE deadlock + one order-dependent `test_overview` flake); both vanish under the documented serial isolation — no code defect, no change made.
- **PLAN §9 still needs the owner's reconciliation** (phase 187 adds the sync memory fields + two status keys; PLAN is never agent-edited — AGENTS rule 10 carries the spec). `TODO.md` holds an unrelated owner note, left untouched.

Next pending phase: `188_chunks_hnsw_index`.
This commit is contained in:
2026-10-16 15:22:51 -04:00
parent 644f7de696
commit c054b47df5
72 changed files with 3826 additions and 96 deletions
+377 -14
View File
@@ -86,12 +86,20 @@ empty, the final file counts kept, the chunk position cleared) and a
second run after the cancel completes to ``success`` (the restart is
clean — the stale cancel event did not bleed in, and only the
completed run bumps the sources version).
Phase 187 (task 02): every sync LIFECYCLE line carries the process
memory — ``sync: started … rss_mb=N``, and ``… rss_mb=N rss_peak_mb=M``
on all three terminals (success, cancelled, failed) plus the importer's
``import: summary …``. The fields are APPENDED (LOCKED A2), so every
pre-phase prefix below is byte-identical and the pins here assert BOTH
halves of that contract.
"""
from __future__ import annotations
import asyncio
import logging
import os
import re
import subprocess
import textwrap
import threading
@@ -109,6 +117,7 @@ from sqlalchemy.orm import Session
from app.api import sync as sync_api
from app.config import Settings
from app.core.memory import fmt_mb, rss_mb, rss_peak_mb
from app.db import SessionLocal, db_available
from app.main import app as fastapi_app
from app.models import Document, GitSource
@@ -130,14 +139,21 @@ def _fresh_sync_state() -> Iterator[None]:
Phase 134 (task 01): the module ``_cancel_event`` joins the reset —
a stale (set) event from a previous test's cancelled run would
otherwise bleed into the next run's boundary checks."""
otherwise bleed into the next run's boundary checks.
Phase 187 (task 03): so does the memory-sampling guard
(``_rss_sampled_at``) — module-global state beside ``_status``.
Leaving it set would make one test's sample answer for the next
one's "did the run read the number?" assertion."""
sync_api._status = sync_api.SyncStatus()
sync_api._task = None
sync_api._cancel_event = asyncio.Event()
sync_api._rss_sampled_at = float("-inf")
yield
sync_api._status = sync_api.SyncStatus()
sync_api._task = None
sync_api._cancel_event = asyncio.Event()
sync_api._rss_sampled_at = float("-inf")
@pytest.fixture(autouse=True)
@@ -307,6 +323,21 @@ def _wait_phase(client: TestClient, want: str, timeout: float = 5.0) -> dict:
time.sleep(0.02)
#: Phase 187 (task 02): the ONE rendering :func:`app.core.memory.fmt_mb`
#: allows for an MB field — ``?`` when the platform cannot know (no
#: ``/proc``, no ``resource``), else a positive integer (never ``None``,
#: never a float or a negative).
MB = r"(?:\?|[1-9][0-9]*)"
def _log_lines(caplog: pytest.LogCaptureFixture, prefix: str) -> list[str]:
"""Captured messages starting with ``prefix`` — the lifecycle lines
are pinned by their PRE-phase prefix, so the append-only contract
(LOCKED A2) is visible in the assertion itself.
"""
return [r.getMessage() for r in caplog.records if r.getMessage().startswith(prefix)]
class FakeImportSources:
"""Records every ``import_sources`` call; returns a canned summary."""
@@ -546,6 +577,10 @@ def test_admin_sync_success_reports_full_detail(
"current_summary": None,
"summaries_done": 0,
"summaries_total": 0,
# Phase 187 (task 03): the memory keys — null/null on a run that
# never happened (never 0, and the page renders no peak clause).
"rss_mb": None,
"rss_peak_mb": None,
}
r = sync_client.post("/api/sync")
@@ -1567,7 +1602,11 @@ def test_summaries_phase_reports_the_affected_count_as_total(
def test_git_failure_marks_failed_and_skips_import(
sync_client: TestClient, monkeypatch: pytest.MonkeyPatch, db: Session, tmp_path: Path
sync_client: TestClient,
monkeypatch: pytest.MonkeyPatch,
db: Session,
tmp_path: Path,
caplog: pytest.LogCaptureFixture,
) -> None:
repo_url = f"file://{tmp_path / 'bad.git'}"
_seed(db, repo_url)
@@ -1592,9 +1631,9 @@ def test_git_failure_marks_failed_and_skips_import(
monkeypatch.setattr(sync_api, "regenerate_overview", fake_overview)
_login(sync_client)
assert sync_client.post("/api/sync").status_code == 202
body = _poll(sync_client, "failed")
with caplog.at_level(logging.INFO, logger="app.api.sync"):
assert sync_client.post("/api/sync").status_code == 202
body = _poll(sync_client, "failed")
assert "bad.git" in body["error"] # the failing repo is named
assert "fatal: repository not found" in body["error"]
assert body["detail"] == {}
@@ -1613,6 +1652,21 @@ def test_git_failure_marks_failed_and_skips_import(
# Phase 53: a FAILED sync never bumps — the version is untouched.
assert current_sources_version(db) == 0
# Phase 187 (task 02): the failed funnel keeps its traceback AND
# gains ONE sanitized one-line summary (LOCKED A2 — appended, so the
# pre-phase ``sync: failed`` label is untouched). Asserted before the
# restart below, which fails a SECOND time.
tracebacks = [
r for r in caplog.records if r.getMessage() == "sync: failed" and r.exc_info
]
assert len(tracebacks) == 1, "logger.exception must still write the traceback"
failed = _log_lines(caplog, "sync: failed state=failed")
assert len(failed) == 1, failed
assert failed[0].startswith("sync: failed state=failed files_done=0 files_total=0")
assert re.search(
rf" rss_mb={MB} rss_peak_mb={MB} error=.*bad\.git", failed[0]
), failed[0]
# A failed run leaves the system restartable: a new POST is accepted.
assert sync_client.post("/api/sync").status_code == 202
_poll(sync_client, "failed")
@@ -1855,7 +1909,11 @@ def test_missing_local_dir_fails_loudly_and_imports_nothing(
def test_import_error_is_reported_with_credentials_masked(
sync_client: TestClient, monkeypatch: pytest.MonkeyPatch, db: Session, tmp_path: Path
sync_client: TestClient,
monkeypatch: pytest.MonkeyPatch,
db: Session,
tmp_path: Path,
caplog: pytest.LogCaptureFixture,
) -> None:
repo_url = f"file://{tmp_path / 'repo.git'}"
_seed(db, repo_url)
@@ -1892,9 +1950,9 @@ def test_import_error_is_reported_with_credentials_masked(
monkeypatch.setattr(sync_api, "regenerate_overview", FakeOverview(ok=True))
_login(sync_client)
assert sync_client.post("/api/sync").status_code == 202
body = _poll(sync_client, "failed")
with caplog.at_level(logging.INFO, logger="app.api.sync"):
assert sync_client.post("/api/sync").status_code == 202
body = _poll(sync_client, "failed")
assert "*****@aipi.reeseapps.com" in body["error"] # credentials masked
assert "user:secret" not in body["error"]
assert "connection refused" in body["error"] # the reason survives
@@ -1905,6 +1963,16 @@ def test_import_error_is_reported_with_credentials_masked(
assert body["current_summary"] is None
assert body["summaries_done"] == 0 and body["summaries_total"] == 0
# Phase 187 (task 02): the one-line failed summary logs the SAME
# masked string the status field carries — the raw exception text
# never reaches the log through this line (the ``logger.exception``
# traceback is the pre-phase surface, unchanged).
failed = _log_lines(caplog, "sync: failed state=failed")
assert len(failed) == 1, failed
assert "*****@aipi.reeseapps.com" in failed[0]
assert "user:secret" not in failed[0]
assert re.search(rf" rss_mb={MB} rss_peak_mb={MB} error=", failed[0]), failed[0]
# --- phase 41: model probe (fail fast before any clone) --------------------
@@ -2350,12 +2418,29 @@ def test_cancel_mid_run_lands_in_cancelled_then_resyncs_clean(
assert body["files_done"] == 1 and body["files_total"] == 3
# ... and the chunk position clears (the phase-129 convention).
assert body["current_chunk"] == 0 and body["chunks_total"] == 0
# PLAN §9: the ample-logging line for the converted cancel.
assert any(
r.getMessage()
== "sync: cancelled by user state=cancelled files_done=1 files_total=3"
for r in caplog.records
# Phase 187 (task 03): the CANCELLED terminal keeps the memory pair
# too — a cancelled run is exactly the run an operator wants the
# number for (the walk stopped, the box is still hot), and the
# phase-64 keep-final-values convention covers it like the counts.
if _memory_is_knowable():
assert body["rss_mb"] is not None and body["rss_peak_mb"] is not None, body
assert body["rss_peak_mb"] >= body["rss_mb"] - _MB_SLACK, body
else:
assert body["rss_mb"] is None and body["rss_peak_mb"] is None, body
# PLAN §9: the ample-logging line for the converted cancel. Phase
# 187 (task 02) APPENDS the two memory fields (LOCKED A2) — the
# pre-phase prefix is byte-identical, the tail is `?` or a positive
# integer, and NOTHING else was inserted or reworded.
cancelled = _log_lines(caplog, "sync: cancelled by user ")
assert len(cancelled) == 1, cancelled
assert cancelled[0].startswith(
"sync: cancelled by user state=cancelled files_done=1 files_total=3"
)
assert re.fullmatch(
rf"sync: cancelled by user state=cancelled files_done=1 files_total=3"
rf" rss_mb={MB} rss_peak_mb={MB}",
cancelled[0],
), cancelled[0]
# The cancelled run never reached the version bump.
assert current_sources_version(db) == 0
@@ -2518,3 +2603,281 @@ def test_git_row_branch_mismatch_button_path_fails_loud(
assert proc.returncode == 0 and proc.stdout.strip() == "main"
assert (dest / "a.md").is_file()
assert not (dest / "b.md").exists()
# --- phase 187 (task 02): the lifecycle lines carry the memory numbers ----
def test_success_lifecycle_lines_carry_memory_fields(
sync_client: TestClient,
monkeypatch: pytest.MonkeyPatch,
db: Session,
tmp_path: Path,
caplog: pytest.LogCaptureFixture,
) -> None:
"""The owner incident (2026-10-15) turned "how much RAM did that sync
use?" into archaeology across three boots' ``systemd`` teardown lines
— with one boot missing entirely. From now on ONE grep answers it:
``sync: started … rss_mb=N`` and ``sync: done detail=… rss_mb=N
rss_peak_mb=M``. Both fields are APPENDED after the existing ones
(LOCKED A2), so the pre-phase prefix stays byte-identical; the value
is a positive integer MB or ``?`` where the platform cannot know
(:mod:`app.core.memory` never raises).
"""
repo_url = f"file://{tmp_path / 'repo.git'}"
_seed(db, repo_url)
_stub_env(monkeypatch)
monkeypatch.setattr(
sync_api,
"get_settings",
lambda: _settings(sources_dir=str(tmp_path / "bor")),
)
_, fake_clone = _fake_clone()
monkeypatch.setattr(sync_api, "clone_or_pull", fake_clone)
_stub_probe(monkeypatch)
monkeypatch.setattr(
sync_api, "import_sources", FakeImportSources(ImportSummary(files=1, added=1))
)
monkeypatch.setattr(sync_api, "regenerate_overview", FakeOverview(ok=True))
monkeypatch.setattr(sync_api, "generate_folder_summaries", FakeFolderSummaries())
_login(sync_client)
with caplog.at_level(logging.INFO, logger="app.api.sync"):
assert sync_client.post("/api/sync").status_code == 202
body = _poll(sync_client, "success")
assert body["state"] == "success"
started = _log_lines(caplog, "sync: started ")
assert len(started) == 1, started
assert started[0].startswith("sync: started repos=1 origin=db git=1 local=0")
assert re.fullmatch(
rf"sync: started repos=1 origin=db git=1 local=0 rss_mb={MB}", started[0]
), started[0]
done = _log_lines(caplog, "sync: done ")
assert len(done) == 1, done
# The pre-existing prefix, the detail dict still first, the two new
# fields trailing — nothing renamed, reordered or re-typed.
assert done[0].startswith("sync: done detail={'files': 1,")
assert re.search(rf" rss_mb={MB} rss_peak_mb={MB}$", done[0]), done[0]
# --- phase 187 (task 03): the status carries the memory pair --------------
#
# The same numbers the lifecycle lines carry, on the surface the Sources
# page polls: two ADDITIVE keys (rss_mb / rss_peak_mb, int | null),
# null until a run samples them and the FINAL pair in every terminal
# (the phase-64 keep-final-values convention). The exposure guard is the
# route's own admin gate — the Sources view is admin-only (PLAN B5), so
# no memory number ever leaves the app on an anonymous surface.
#: The status payload's key set BEFORE phase 187 — the additive pin's
#: left-hand side (the payload is exactly this set plus the memory pair,
#: forever).
_PRE_187_STATUS_KEYS = frozenset(
{
"state",
"started_at",
"finished_at",
"detail",
"error",
"current_file",
"files_done",
"files_total",
"current_chunk",
"chunks_total",
"images_done",
"images_total",
"phase",
"current_summary",
"summaries_done",
"summaries_total",
}
)
#: Phase 187 (task 03): the two additive memory keys.
_MEMORY_KEYS = frozenset({"rss_mb", "rss_peak_mb"})
#: The pair is read from two DIFFERENT kernel counters and the high-water
#: refreshes LAZILY, so a raw ``rss_peak_mb()`` really can sit under a raw
#: ``rss_mb()`` (measured: ``rss_mb=164`` against ``rss_peak_mb=162``) —
#: the nuance ``app/core/memory.py`` documents. Task 04 moved the fix to
#: the ONE place the pair is published (:func:`app.api.sync._sample_rss`,
#: which lifts a lagging peak to the current reading), so the slack here is
#: ZERO and the assertion is the invariant itself: a reported peak below
#: the run's own current footprint is a false number, not a smaller one.
_MB_SLACK = 0
def _memory_is_knowable() -> bool:
"""Does THIS platform answer the two helpers? Linux (the deploy
target: ``/proc`` + ``resource``) always does; a runner without
either gets null/null and the value pins step aside — the SHAPE pins
never do, because ``null`` is the honest answer there too."""
return rss_mb() is not None and rss_peak_mb() is not None
def _stub_a_one_file_run(
monkeypatch: pytest.MonkeyPatch, db: Session, tmp_path: Path
) -> None:
"""The shortest honest run: one git row, a stub clone that writes one
file, a stubbed import (the runner's own numbers are what's under
test, not the importer's)."""
_seed(db, f"file://{tmp_path / 'repo.git'}")
_stub_env(monkeypatch)
monkeypatch.setattr(
sync_api,
"get_settings",
lambda: _settings(sources_dir=str(tmp_path / "bor")),
)
_, fake_clone = _fake_clone()
monkeypatch.setattr(sync_api, "clone_or_pull", fake_clone)
_stub_probe(monkeypatch)
monkeypatch.setattr(
sync_api, "import_sources", FakeImportSources(ImportSummary(files=1, added=1))
)
monkeypatch.setattr(sync_api, "regenerate_overview", FakeOverview(ok=True))
monkeypatch.setattr(sync_api, "generate_folder_summaries", FakeFolderSummaries())
def test_memory_status_keys_are_the_only_addition_and_null_before_a_run(
sync_client: TestClient,
) -> None:
"""The additive pin on the wire: the payload's key set is EXACTLY the
pre-phase-187 set plus ``rss_mb`` / ``rss_peak_mb``, and a run that
never happened answers ``null`` / ``null`` — not 0, not a plausible
number. That null is also what makes the Sources page render the
counts line with no peak clause after an app restart."""
_login(sync_client)
body = sync_client.get("/api/sync/status").json()
assert set(body) == _PRE_187_STATUS_KEYS | _MEMORY_KEYS, set(body)
assert body["rss_mb"] is None
assert body["rss_peak_mb"] is None
# The pre-existing shapes, unchanged: the state word, the two ISO
# slots, the counts, the phase machine.
assert body["state"] == "idle"
assert body["started_at"] is None and body["finished_at"] is None
assert body["detail"] == {} and body["error"] is None
assert body["files_done"] == 0 and body["files_total"] == 0
assert body["current_chunk"] == 0 and body["chunks_total"] == 0
assert body["images_done"] == 0 and body["images_total"] == 0
assert body["phase"] is None and body["current_summary"] is None
assert body["summaries_done"] == 0 and body["summaries_total"] == 0
def test_success_terminal_status_keeps_the_final_memory_pair(
sync_client: TestClient,
monkeypatch: pytest.MonkeyPatch,
db: Session,
tmp_path: Path,
caplog: pytest.LogCaptureFixture,
) -> None:
"""After a run the payload answers the incident's question directly:
both keys are integers here (Linux), the peak is the run's
high-water next to the final counts (within the documented MB
slack), and the pair SURVIVES the run — a later poll, i.e. the page
reloaded after the sync, still shows it. The ``sync: done`` line
logs the SAME pair: one reading, two surfaces."""
_stub_a_one_file_run(monkeypatch, db, tmp_path)
_login(sync_client)
with caplog.at_level(logging.INFO, logger="app.api.sync"):
assert sync_client.post("/api/sync").status_code == 202
body = _poll(sync_client, "success")
assert body["state"] == "success"
current, peak = body["rss_mb"], body["rss_peak_mb"]
assert current is None or isinstance(current, int)
assert peak is None or isinstance(peak, int)
if _memory_is_knowable():
assert current is not None and peak is not None, body
assert current > 0 and peak > 0, body
assert peak >= current - _MB_SLACK, (
"the published pair broke its peak >= current invariant — the"
" sampling point must lift a lazily-refreshed high-water to the"
f" current reading (slack {_MB_SLACK} MB):"
f" current={current} peak={peak}"
)
# The terminal keeps the pair (no re-sample, no reset between the
# run and the next poll — the page can be reloaded at leisure).
again = sync_client.get("/api/sync/status").json()
assert (again["rss_mb"], again["rss_peak_mb"]) == (current, peak), again
# Log / payload agreement: the line the operator greps and the key
# the page renders come off the same reading.
done = _log_lines(caplog, "sync: done ")
assert len(done) == 1, done
assert done[0].endswith(
f"rss_mb={fmt_mb(current)} rss_peak_mb={fmt_mb(peak)}"
), done[0]
# The pre-existing payload is untouched by all of this.
assert set(again) == _PRE_187_STATUS_KEYS | _MEMORY_KEYS
assert again["files_done"] == 0 or isinstance(again["files_done"], int)
def test_failed_terminal_keeps_the_memory_pair(
sync_client: TestClient,
monkeypatch: pytest.MonkeyPatch,
db: Session,
tmp_path: Path,
) -> None:
"""A run that dies is exactly the run whose memory matters, so the
FAILED funnel samples too: the payload keeps the pair beside the
sanitized error (the task-02 line logs the same pair)."""
repo_url = f"file://{tmp_path / 'missing.git'}"
_seed(db, repo_url)
_stub_env(monkeypatch)
monkeypatch.setattr(
sync_api,
"get_settings",
lambda: _settings(sources_dir=str(tmp_path / "bor")),
)
_stub_probe(monkeypatch)
def broken_clone(url: str, dest: Path | str, branch: str | None = None) -> Path:
raise GitSyncError(f"git clone failed for {url}")
monkeypatch.setattr(sync_api, "clone_or_pull", broken_clone)
monkeypatch.setattr(
sync_api,
"import_sources",
FakeImportSources(ImportSummary()), # must never run
)
_login(sync_client)
assert sync_client.post("/api/sync").status_code == 202
body = _poll(sync_client, "failed")
assert "missing.git" in body["error"]
assert body["detail"] == {}
if _memory_is_knowable():
assert body["rss_mb"] is not None and body["rss_peak_mb"] is not None, body
assert body["rss_peak_mb"] >= body["rss_mb"] - _MB_SLACK, body
else: # a platform that cannot know still answers, with null
assert body["rss_mb"] is None and body["rss_peak_mb"] is None, body
def test_memory_pair_is_never_an_anonymous_surface(
sync_client: TestClient,
monkeypatch: pytest.MonkeyPatch,
db: Session,
tmp_path: Path,
) -> None:
"""A4's exposure guard on the wire: the status route is
``require_admin``, and the new keys ride that gate — an anonymous
visitor gets the pre-phase 403 with the pre-phase body, with or
without a run in flight (the Sources view is the only place the
number renders, and it is admin-only)."""
anonymous = TestClient(fastapi_app)
r = anonymous.get("/api/sync/status")
assert r.status_code == 403
assert r.json() == {"detail": "admin only"}
_stub_a_one_file_run(monkeypatch, db, tmp_path)
_login(sync_client)
assert sync_client.post("/api/sync").status_code == 202
_poll(sync_client, "success")
r = anonymous.get("/api/sync/status")
assert r.status_code == 403, "no memory number on an anonymous surface"
assert r.json() == {"detail": "admin only"}