Files
brain-of-reese/tests/e2e/test_sync_git_freeze.py
T
ducoterra c054b47df5
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_sync_peak_memory_line
**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`.
2026-10-16 15:22:51 -04:00

799 lines
35 KiB
Python
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
"""Phase 179 (task 03) E2E (Playwright, mock-only): the owner's suspicion
pinned end to end against the REAL pipeline — no stub anywhere.
``TODO.md`` L3, verbatim: *"A long git clone seems to freeze the server?
Investigate to find out if this is true."*
**VERDICT (task 01): CONFIRMED. → FIXED (task 02).** The sync's git
steps (``app/api/sync.py::_run_sync`` →
``scripts/git_sync.clone_or_pull`` → ``run_git`` → ``subprocess.run``,
plus the ``file_commit_dates`` walk) used to run ON the app's SINGLE
uvicorn event loop, so a long clone parked the loop thread and NOTHING
was served until git returned — not the 2 s ``GET /api/sync/status``
poll the Sources page lives on, not ``GET /api/health``, not the page's
own assets. The server did not fail; it FROZE. Both git steps now run
in a worker thread (``asyncio.to_thread``), and this module is the real
clone proving the fixed contract (task 02's
``tests/integration/test_sync_git_freeze.py`` pins the same contract
with a 3 s stub in-process; here the clone is a real ``git`` subprocess
cloning a real local repo).
**The timing fixture (locked A4): a GENERATED local ``file://`` repo.**
``BIG_COMMITS`` commits, each adding one ``bulk/blob-<k>.md`` of
``BIG_FILE_BYTES`` **seeded pseudo-random** bytes
(``random.Random(k).randbytes`` — deterministic, and near-INCOMPRESSIBLE:
repeated prose would deflate to nothing and the clone would be
instant), each commit replacing the previous bulk blob so the HISTORY
carries the whole ~150 MiB of objects while the checked-out tip stays
two small files. ``notes/sentinel.md`` (the marker
``RESE-FREEZE-SENTINEL-9d3a``) is the tip's file — the KB assertion
target. The source repo is deliberately left **unpacked** (every
mutating git call runs with ``-c gc.auto=0``, and the fixture asserts
the object store is still pack-free): a ``file://`` clone of a
pack-free repo makes git build the pack for the transfer, which is what
a first clone of a fresh repo really costs.
**Calibration (authoring host, 2026-10-14).** Three consecutive FRESH
``git clone file://<fixture>`` runs: **8.68 / 8.71 / 8.74 s** (median
8.7 s) — the A4 bar is ≥ 5 s, so the fixture carries ~1.7× the required
window. The task's starting point ("start ~200 × ~1 MiB") was tuned to
30 × 5 MiB at the same ~150 MiB total: the clone cost of a pack-free
repo is dominated by the delta search over the object set, so fewer,
larger objects keep the build (~7 s) and the clone stable, and the tip
MUST stay small — see the next paragraph.
**Why the tip is two small files:** the clone is the timing fixture,
NOT the mock import. A 150 MiB working tree would push ~75 000 chunks
through the mock embedder and this module into many minutes; the two
tip files keep the import to ~2 s while the git prelude stays the ~9 s
window every assertion measures.
**Timing paragraph.** The clone window (~8.7 s measured) holds ~4 of the
UI's 2 s status polls. The tests poll at that same 2 s cadence
(``page.request``, the owner's poll) and every one must complete in
**< 1.5 s** — ~150× the measured round trip (~10 ms) and ~6× below the
clone itself, so a git op that slides back onto the event loop (task 01
measured ≈ the full clone) can never pass. The asserted minimum prelude
span (4 s) is the pin that the CLONE really was the long pole, and the
minimum poll count inside it (2) is the pin that the polls really landed
inside it — a fixture that got fast fails loudly instead of passing
vacuously.
Run in isolation (DB must be up: ``podman compose up -d db``; ``git`` on
PATH — a documented environment prerequisite, phase 28):
uv run pytest tests/e2e/test_sync_git_freeze.py -v --no-cov
Isolation (the combined-run convention, the ``test_sync_cancel``
pattern): a per-module app on a dedicated port (the conftest session app
is never started in this isolated run), the deterministic mock LLM on
the conftest port (``E2E_REAL_LLM=1`` is SKIPPED — the CLONE, not the
LLM import, is the timing fixture), a dedicated ``BOR_SOURCES_DIR`` for
the checkout, ``BOR_GIT_SOURCES=file://<big repo>`` (the env-fallback
row), and the shared E2E Postgres truncated before AND after every test.
Wall-time guard: the whole module (the fixture build + two full clones
+ page setup) is budgeted at < 120 s and pinned by the module-scoped
``_wall_guard`` (measured ≈ 30 s end to end on the authoring host) — if
the suite drifts, cut ``BIG_COMMITS``, not the guard.
Test → observable mapping (Playwright Mapping Rule):
1. ``test_status_polls_responsive_during_long_clone`` — the owner's
frozen-server check, end to end: a sync whose first action is the
~8.7 s real clone keeps the whole HTTP surface answering. Every
2 s-cadence ``GET /api/sync/status`` issued inside the git prelude
completes in < 1.5 s while the run reports ``running`` with no phase
and no file (the clone/pull prelude), the page's OWN poll loop keeps
landing 200s (≥ 2 inside the prelude — a frozen loop starves it), the
Sources page stays in its live "Syncing…" state with the Cancel
control still available and NO error surface, and the run lands
``success`` with the sentinel document in the KB (the real clone's
content, reachable through the drill-down catalog).
2. ``test_cancel_during_clone_reaches_terminal`` — phase 134's
cooperative cancel under the off-loop scheduling: with the checkout
deleted (so the run re-clones — a long git phase again), the UI's
Cancel click round-trips in < 1.5 s and the run settles into the
``cancelled`` terminal (``error: null``, ``detail: {}``, no import
ever started) WHILE the abandoned git worker is still writing its
clone (the checkout's worktree is still absent) — the status polls
issued during that window all complete in < 1.5 s, which is
decision A2's observable: the thread runs to completion, the loop
serves everyone else. The UI settles to the neutral "Sync cancelled"
(retry-ready button, no banner, no modal) and the KB stays empty for
the source (the abandoned clone's result is never imported).
"""
from __future__ import annotations
import os
import random
import re
import shutil
import subprocess
import sys
import time
from collections.abc import Iterator
from pathlib import Path
from typing import Any
import httpx
import pytest
from playwright.sync_api import Browser, ConsoleMessage, Page, Response, expect
from sqlalchemy import text
from app.db import SessionLocal
from e2e.auth_helpers import login
from e2e.conftest import (
ADMIN_PASSWORD,
MOCK_PORT,
SESSION_SECRET,
USE_REAL_LLM,
_wait_http,
)
from e2e.sync_helpers import PEAK_CLAUSE, counts_line
from scripts.import_docs import repo_name
REPO = Path(__file__).resolve().parents[2]
#: A per-module app on its own port (the conftest session app owns 8123
#: in a combined run — a same-port second uvicorn would drive the wrong
#: server). Env-overridable, the ``test_sync_cancel`` pattern.
APP_PORT = int(os.environ.get("E2E_APP_PORT_SYNCFREEZE", "8195"))
APP_URL = f"http://127.0.0.1:{APP_PORT}"
#: The fixture repo's directory name — also the source name the import
#: records (the ``repo_name`` basename rule, phase 28) and the checkout
#: dir name under ``BOR_SOURCES_DIR``.
GIT_SOURCE_NAME = "freeze-fixture"
#: The timing fixture (locked A4, see the module docstring's calibration
#: paragraph): ``BIG_COMMITS`` commits × ``BIG_FILE_BYTES`` of seeded
#: pseudo-random bytes ≈ 150 MiB of near-incompressible history, cloned
#: from a pack-free object store → a fresh clone measured 8.68 / 8.71 /
#: 8.74 s on the authoring host (≥ 5 s is the A4 bar). Cut BIG_COMMITS if
#: the module's wall-time guard trips — never the guard.
BIG_COMMITS = 30
BIG_FILE_BYTES = 5 * 1024 * 1024
#: The ONE sentinel document (the tip's content — the bulk blobs live in
#: history only): its row + content prove the REAL clone was fully
#: indexed, and it is the filesystem signal that the clone finished
#: (git writes the worktree LAST, so while this file is absent the
#: abandoned clone is provably still in flight — test 2's A2 pin).
SENTINEL = "RESE-FREEZE-SENTINEL-9d3a"
SENTINEL_DOC = "notes/sentinel.md"
#: The endpoint the UI polls every 2 s, and the cadence itself
#: (``sources.js`` ``SYNC_POLL_MS``) — the tests issue their latency
#: probes on exactly this rhythm, so a number here IS the owner's "the
#: status poll hangs" experience.
GET_STATUS_PATH = "/api/sync/status"
UI_POLL_S = 2.0
#: Every request issued into the clone window must be served in under
#: this (phase 179's number, shared with task 02's integration probe):
#: ~150× the measured round trip, ~6× below the clone.
POLL_CEILING_S = 1.5
#: The minimum span the git prelude must hold (2× below the calibrated
#: 8.7 s clone) and the minimum number of 2 s-cadence polls that must
#: fall inside it — together they fail loudly if the clone ever gets
#: fast enough for the probe set to be vacuous.
MIN_CLONE_WINDOW_S = 4.0
MIN_POLLS_IN_WINDOW = 2
#: Settle budgets: the whole run (clone + mock import + overview +
#: summaries) settles in ≈ 10 s measured, so 90 s is ~9× the run; the UI
#: settles a terminal within one 2 s poll tick, so 15 s is ~7× that.
RUN_SETTLE_TIMEOUT_MS = 90_000
UI_SETTLE_TIMEOUT_MS = 15_000
#: "Synced HH:MM" (``sources.js`` ``fmtSyncTime``) and the settled
#: SUCCESS result line (``fmtSyncResult``) — updated/pruned are 0 here,
#: and the phase-187 peak clause is optional (null pair → no clause).
SYNCED_LABEL = re.compile(r"Synced \d{1,2}:\d{2}")
RESULT_LINE = re.compile(rf"^(\d+) added(?: · (\d+) unchanged)?{PEAK_CLAUSE}$")
#: The console noise the anonymous probes legitimately produce (this
#: module's own tests are admin — the collector stays as the uncaught-JS
#: guard the house uses for every UI assertion).
_CONSOLE_NOISE = re.compile(r"Failed to load resource", re.IGNORECASE)
# ---------------------------------------------------------------------------
# Fixture repo
# ---------------------------------------------------------------------------
def _git(cwd: Path, *args: str) -> None:
"""Run git in *cwd*; a non-zero exit fails the fixture loudly (the
``test_sync_cancel`` helper shape)."""
proc = subprocess.run(["git", *args], cwd=cwd, capture_output=True, text=True)
if proc.returncode != 0:
raise AssertionError(f"git {' '.join(args)} failed: {proc.stderr.strip()}")
def _bulk_bytes(k: int) -> bytes:
"""One bulk blob: ``BIG_FILE_BYTES`` of SEEDED pseudo-random bytes.
Deterministic (``random.Random(k)`` — the same fixture byte-for-byte
on every run, so the calibration holds) and near-INCOMPRESSIBLE:
repeating prose would deflate away and the clone would turn fast,
which is the one thing this fixture must never do."""
return f"# bulk blob {k}\n".encode() + random.Random(k).randbytes(BIG_FILE_BYTES)
@pytest.fixture(scope="module")
def big_git_repo(tmp_path_factory: pytest.TempPathFactory) -> Path:
"""The generated local repo the sync must clone (the timing fixture,
locked A4 — the module docstring's calibration paragraph).
History: ``BIG_COMMITS`` commits each adding one
``bulk/blob-<k>.md`` blob and dropping the previous one, so the pack
the clone transfers carries the whole ~150 MiB while the tip's
working tree is two small files (the mock import is NOT the timing
fixture — the clone is). The tip commit drops the last bulk blob and
adds ``notes/sentinel.md``.
Every mutating git call runs with ``-c gc.auto=0`` and the fixture
asserts the object store is still PACK-FREE: a loose store is what
makes ``git clone`` build the transfer pack (the cost under test).
An auto-gc'd pack would turn the clone into a straight pack copy
(~0.9 s for the same bytes) and hollow the fixture out."""
root = tmp_path_factory.mktemp("sync_git_freeze")
repo = root / GIT_SOURCE_NAME
(repo / "notes").mkdir(parents=True)
(repo / "README.md").write_text(
f"# {GIT_SOURCE_NAME}\n\nPhase 179 fixture repo: the long clone lives in "
"the history, the assertion target in the tip.\n",
encoding="utf-8",
)
_git(repo, "init", "-q", "-b", "main")
_git(repo, "add", "-A")
_git(
repo,
"-c", "user.email=e@x", "-c", "user.name=t",
"-c", "commit.gpgsign=false", "-c", "gc.auto=0", # the fixture never signs, never gc's
"commit", "-qm", "seed",
)
for k in range(1, BIG_COMMITS + 1):
bulk = repo / "bulk"
bulk.mkdir(exist_ok=True)
for stale in bulk.glob("blob-*"):
stale.unlink()
(bulk / f"blob-{k}.md").write_bytes(_bulk_bytes(k))
_git(repo, "-c", "gc.auto=0", "add", "-A")
_git(
repo, "-c", "gc.auto=0",
"-c", "user.email=e@x", "-c", "user.name=t", "-c", "commit.gpgsign=false",
"commit", "-qm", f"bulk {k}",
)
# The tip: the bulk goes, the sentinel stays.
for stale in (repo / "bulk").glob("blob-*"):
stale.unlink()
(repo / SENTINEL_DOC).write_text(
f"# Sentinel\n\nMarker: {SENTINEL}\n\nWritten by the phase-179 fixture; its "
"presence in the KB proves the real clone was indexed.\n",
encoding="utf-8",
)
_git(repo, "-c", "gc.auto=0", "add", "-A")
_git(
repo, "-c", "gc.auto=0",
"-c", "user.email=e@x", "-c", "user.name=t", "-c", "commit.gpgsign=false",
"commit", "-qm", "sentinel",
)
assert (repo / ".git").is_dir()
assert not list((repo / ".git" / "objects" / "pack").glob("*.pack")), (
"the phase-179 fixture must stay pack-free — a packed source turns the "
"clone into a straight pack copy and the timing window away"
)
return repo
# ---------------------------------------------------------------------------
# Module app + isolation
# ---------------------------------------------------------------------------
def _sources_dir(big_git_repo: Path) -> Path:
"""The module's dedicated ``BOR_SOURCES_DIR`` (the checkout home) —
ONE definition for the app fixture and the ``checkout_dir`` helper
fixture, so the two cannot drift."""
return big_git_repo.parent / "checkouts"
@pytest.fixture(scope="module")
def app_server(mock_llm: int, big_git_repo: Path) -> Iterator[str]:
"""The real app under test on a dedicated port: the deterministic
mock LLM directly (no proxy — the CLONE is the timing fixture, the
import is two files), the fixture repo as the env-fallback git
source, its own ``BOR_SOURCES_DIR`` (the checkout home)."""
if USE_REAL_LLM:
pytest.skip(
"mock-only suite — the timing fixture is the real clone, not the "
"LLM import (E2E_REAL_LLM unsupported)"
)
env = dict(os.environ)
env.pop("DEBUGPY", None)
env["BOR_ENVIRONMENT"] = "e2e"
env["BOR_STATIC_DIR"] = str(REPO / "frontend")
env["BOR_LLM_BASE_URL"] = f"http://127.0.0.1:{MOCK_PORT}/v1"
# Mock-calibrated threshold (conftest pattern) — keeps the suite's
# deterministic gate behavior; production default stays 0.62.
env["BOR_RELEVANCE_THRESHOLD"] = "0.30"
env.setdefault(
"BOR_DATABASE_URL",
"postgresql+psycopg://reese:reese@localhost:5432/brain_of_reese",
)
# Phase 16: admin auth must be set or create_app() refuses to boot.
env["BOR_ADMIN_PASSWORD"] = ADMIN_PASSWORD
env["BOR_SESSION_SECRET"] = SESSION_SECRET
# The sync's subject — one real local repo with the long-clone history.
env["BOR_GIT_SOURCES"] = f"file://{big_git_repo}"
env["BOR_SOURCES_DIR"] = str(_sources_dir(big_git_repo))
proc = subprocess.Popen(
[sys.executable, "-m", "uvicorn", "app.main:app",
"--host", "127.0.0.1", "--port", str(APP_PORT), "--log-level", "warning"],
cwd=REPO,
env=env,
)
try:
_wait_http(f"{APP_URL}/api/health")
yield APP_URL
finally:
proc.terminate()
try:
proc.wait(timeout=10)
except subprocess.TimeoutExpired:
proc.kill()
@pytest.fixture(scope="module")
def app_url(app_server: str) -> str:
return app_server
@pytest.fixture(scope="module")
def checkout_dir(app_server: str, big_git_repo: Path) -> Path:
"""Where the run clones to — ``BOR_SOURCES_DIR/<repo_name(url)>``
(the phase-28 rule, resolved with the production helper so this
module cannot drift from it — the same ``_sources_dir`` the app
fixture puts in ``BOR_SOURCES_DIR``). Test 2 deletes it to force a
re-clone."""
assert app_server # the app must be up (its env is what owns the path)
return _sources_dir(big_git_repo) / repo_name(f"file://{big_git_repo}")
def _truncate_all() -> None:
"""Fresh registry + KB (the E2E isolation pattern): a leftover
``git_sources`` row would win over the app's ``BOR_GIT_SOURCES`` env
fallback (``effective_sources`` prefers the DB list)."""
with SessionLocal() as db:
db.execute(
text(
"TRUNCATE chunks, documents, query_log, steering_notes, "
"kb_overview, git_sources, folder_summaries"
)
)
db.commit() # without the commit the TRUNCATE rolls back (the house pattern)
def _wait_sync_settled(app_url: str, timeout_s: float = 180.0) -> None:
"""No run may leak across tests (the run state lives in the app's
memory): wait for the app's sync status to be non-running BEFORE the
truncate. Own admin session (the endpoint is admin-only)."""
with httpx.Client(base_url=app_url, timeout=5.0) as client:
r = client.post("/api/login", json={"password": ADMIN_PASSWORD})
assert r.status_code == 204, r.text
deadline = time.monotonic() + timeout_s
while time.monotonic() < deadline:
r = client.get("/api/sync/status")
assert r.status_code == 200, r.text
if r.json()["state"] != "running":
return
time.sleep(0.2)
raise AssertionError(f"a sync was still running at a test boundary: {app_url}")
@pytest.fixture(autouse=True)
def _clean(app_url: str, db_ready: None) -> Iterator[None]:
"""Per-test KB isolation (the phase-96 pattern): the shared E2E
Postgres is truncated before AND after every test; the pre-wait
keeps a leaked run (the module app is shared) from racing the
truncate."""
_wait_sync_settled(app_url)
_truncate_all()
yield
_truncate_all()
@pytest.fixture(scope="module", autouse=True)
def _wall_guard() -> Iterator[None]:
"""The task's wall-time guard: the module (fixture build ~8 s + two
full clones ~9 s each + page setup) must fit inside 120 s — if it
drifts, cut ``BIG_COMMITS``, not the guard (measured end to end on
the authoring host: ≈ 30 s, so the budget carries ~4× head-room)."""
t0 = time.monotonic()
yield
elapsed = time.monotonic() - t0
assert elapsed < 120.0, (
f"module wall time {elapsed:.1f}s blew the 120 s budget — cut "
"BIG_COMMITS, not the guard"
)
@pytest.fixture()
def page(browser: Browser) -> Iterator[Page]:
"""The conftest's page + the console-error collector: an uncaught JS
exception (pageerror) or a console error that is not the expected
"Failed to load resource" noise fails the owning test at teardown —
a page that keeps updating is only a claim if it stays healthy."""
pg = browser.new_page(viewport={"width": 1280, "height": 800})
errors: list[str] = []
def _on_console(msg: ConsoleMessage) -> None:
if msg.type == "error" and not _CONSOLE_NOISE.search(msg.text):
errors.append(msg.text)
pg.on("console", _on_console)
pg.on("pageerror", lambda err: errors.append(str(err)))
try:
yield pg
finally:
pg.close()
assert not errors, f"console/page errors: {errors}"
# ---------------------------------------------------------------------------
# Helpers
# ---------------------------------------------------------------------------
def _timed_status(page: Page, app_url: str) -> tuple[float, dict[str, Any]]:
"""One ``GET /api/sync/status`` with its wall-clock latency (the
owner's 2 s poll, timed). The cookie rides the browser context (the
``test_sync_cancel`` ``page.request`` shape)."""
t0 = time.monotonic()
r = page.request.get(f"{app_url}/api/sync/status")
elapsed = time.monotonic() - t0
assert r.status == 200, r.text
return elapsed, r.json()
def _assert_served(polls: list[tuple[float, dict[str, Any]]], where: str) -> None:
"""Every probe issued *where* was served inside the 2 s UI budget —
the one number that separates a busy server from a frozen one
(pre-phase-179 the answer was "when git says so")."""
assert polls, f"no status probe landed {where}"
worst = max(elapsed for elapsed, _ in polls)
assert worst < POLL_CEILING_S, (
f"a {GET_STATUS_PATH} probe issued {where} took {worst:.3f}s "
f"(budget {POLL_CEILING_S}s) — the event loop is parked by the "
"clone again; every other request, the UI's poll included, is "
"queued behind the git subprocess"
)
def _watch_git_prelude(
page: Page, app_url: str, *, timeout_s: float = 60.0
) -> tuple[list[tuple[float, dict[str, Any]]], dict[str, Any]]:
"""Poll ``GET /api/sync/status`` on the UI's 2 s cadence through the
run's git prelude (``state=running`` with ``phase`` — and therefore
``current_file`` — still null: the clone/pull has not handed
anything to the import yet).
Returns the probes taken inside the prelude (each with its latency)
and the first probe that LEFT it (the import's first ``phase`` or a
terminal state)."""
deadline = time.monotonic() + timeout_s
in_prelude: list[tuple[float, dict[str, Any]]] = []
while True:
elapsed, body = _timed_status(page, app_url)
if body["state"] == "running" and body["phase"] is None:
in_prelude.append((elapsed, body))
else:
return in_prelude, body
if time.monotonic() >= deadline:
raise AssertionError(
f"the run stayed in the git prelude for {timeout_s}s: {body}"
)
# Keep the UI's rhythm: the 2 s tick counts the answered probe.
time.sleep(max(0.0, UI_POLL_S - elapsed))
def _wait_sync_state(
page: Page, app_url: str, states: set[str], timeout_s: float = 30.0
) -> dict[str, Any]:
"""Poll the status endpoint at ~100 ms until ``state`` is in *states*
(the ``test_sync_cancel`` deterministic-layer helper)."""
deadline = time.monotonic() + timeout_s
body: dict[str, Any] = {}
while time.monotonic() < deadline:
r = page.request.get(f"{app_url}/api/sync/status")
assert r.status == 200, r.text
body = r.json()
if body["state"] in states:
return body
time.sleep(0.1)
raise AssertionError(f"sync did not reach {sorted(states)}: {body}")
def _clone_finished(checkout: Path) -> bool:
"""Has the clone written its worktree yet? git checks out LAST, so
while the sentinel file is absent the clone subprocess is provably
still in flight — the filesystem-side witness of test 2's A2 pin."""
return (checkout / SENTINEL_DOC).is_file()
def _go_top(page: Page) -> None:
"""Back to the catalog's top level (no-op when already there)."""
if not page.locator("#kb-crumb").is_hidden():
page.locator("#kb-crumb a.kb-crumb-link").first.click()
# ---------------------------------------------------------------------------
# 1. The owner's check: a long clone, and the server keeps answering
# ---------------------------------------------------------------------------
def test_status_polls_responsive_during_long_clone(
page: Page, app_url: str, checkout_dir: Path, db_ready: None
) -> None:
"""The owner's TODO item, L3, end to end: a sync whose first action
is a genuinely long ``git clone`` must not freeze the server.
The Sources page (logged-in admin) starts the run with its own
button; while the run sits in the clone prelude the test probes
``GET /api/sync/status`` on the UI's own 2 s cadence, and the page's
own poll loop is watched in parallel (response listener). Contract:
every probe is served in < 1.5 s, the page's poll keeps landing
200s, the UI stays live ("Syncing…", Cancel available, no error
surface), the prelude really lasted (≥ ``MIN_CLONE_WINDOW_S``), and
the run lands ``success`` with the sentinel's real content in the
KB."""
page.set_default_timeout(30_000)
login(page, app_url) # lands on /sources.html (the sync button's home)
btn = page.locator("#sync-btn")
cancel = page.locator("#sync-cancel-btn")
expect(btn).to_be_visible()
expect(btn).to_be_enabled()
expect(page.locator("#sync-label")).to_have_text("Sync sources")
expect(cancel).to_be_hidden() # idle: no cancel affordance
# The fixture starts from NO checkout — this run is a fresh clone.
assert not checkout_dir.exists(), (
f"{checkout_dir} already exists — the first run would pull, not clone"
)
# Watch the PAGE's own 2 s polls (startSyncPolling, SYNC_POLL_MS):
# a frozen loop starves this listener of 200s, a free loop keeps
# hearing them.
page_polls: list[float] = []
def _count_page_poll(resp: Response) -> None:
if resp.url.endswith(GET_STATUS_PATH) and resp.status == 200:
page_polls.append(time.monotonic())
page.on("response", _count_page_poll)
# --- the owner's click ------------------------------------------------
clicked = time.monotonic()
btn.click()
# The 202 enters the running state synchronously: the main button
# disables, the box reveals "Syncing…", the Cancel control reveals
# (enterSyncRunningState, kind "sync").
expect(btn).to_be_disabled()
expect(page.locator("#sync-progress")).to_have_text("Syncing…")
expect(cancel).to_be_visible()
expect(cancel).to_be_enabled()
# --- the probes, inside the real clone --------------------------------
page_polls_at_start = len(page_polls)
prelude, left = _watch_git_prelude(page, app_url)
window = time.monotonic() - clicked
# The fixture pinned itself: the git prelude held the run long
# enough for the probe set to mean something.
assert window >= MIN_CLONE_WINDOW_S, (
f"the clone window was only {window:.1f}s (>= {MIN_CLONE_WINDOW_S}s "
"required) — the probe set proves nothing, retune BIG_COMMITS"
)
assert len(prelude) >= MIN_POLLS_IN_WINDOW, (
f"only {len(prelude)} status probes landed inside the clone window "
f"(>= {MIN_POLLS_IN_WINDOW} required at the UI's {UI_POLL_S}s cadence)"
)
_assert_served(prelude, "inside the real clone")
for _, body in prelude:
# The live run, mid-clone: running, no phase, no file — the
# clone/pull prelude reports nothing to show yet.
assert body["state"] == "running"
assert body["phase"] is None
assert body["current_file"] is None
assert body["files_done"] == 0 and body["files_total"] == 0
# The PAGE kept polling and kept getting answers through the clone.
assert len(page_polls) - page_polls_at_start >= MIN_POLLS_IN_WINDOW, (
f"the Sources page landed only {len(page_polls) - page_polls_at_start} "
"status 200s through the clone — its poll loop was starved"
)
# And it stayed in its live state: no error banner, no modal, the
# neutral running copy, the Cancel control still there.
expect(page.locator("#sync-progress-text")).to_have_text(counts_line("Syncing…"))
expect(btn).to_be_disabled()
expect(cancel).to_be_visible()
expect(page.locator("#sync-error-banner")).to_be_hidden()
assert page.locator(".sync-modal-backdrop").count() == 0
# The prelude ended where it must — the import's first phase, or the
# run's own terminal (the two-file mock import is ~1 s against a 2 s
# poll tick, so the ``import`` phase can be crossed between two
# probes). What may NEVER be the exit is a failure — a run that died
# in the clone is a broken fixture, not a responsive freeze.
assert left["state"] in {"running", "success"}, (
f"the run left the pipeline during the clone: {left}"
)
if left["state"] == "running":
assert left["phase"] == "import", left
assert _clone_finished(checkout_dir), (
"the prelude ended before the clone wrote its worktree — the "
"window the probes measured was not a clone"
)
# --- the success terminal ---------------------------------------------
body = _wait_sync_state(
page, app_url, {"success", "failed", "cancelled"},
timeout_s=RUN_SETTLE_TIMEOUT_MS / 1000,
)
assert body["state"] == "success", body
assert body["error"] is None
# The clone + the two tip files: the run reports a real import.
assert body["files_total"] >= 1 and body["files_done"] == body["files_total"]
assert body["phase"] is None and body["current_file"] is None
# The UI settles to the success shape within one poll tick.
expect(page.locator("#sync-label")).to_have_text(
SYNCED_LABEL, timeout=UI_SETTLE_TIMEOUT_MS
)
expect(btn).to_be_enabled()
expect(cancel).to_be_hidden()
expect(page.locator("#sync-error-banner")).to_be_hidden()
assert page.locator(".sync-modal-backdrop").count() == 0
line = page.locator("#sync-progress-text").inner_text()
assert RESULT_LINE.fullmatch(line), f"unexpected result line: {line!r}"
# The REAL clone's content is in the KB: the sentinel row, with the
# marker the fixture wrote.
with SessionLocal() as db:
sentinel_content = db.execute(
text(
"SELECT content FROM documents WHERE source = :s AND path = :p"
),
{"s": GIT_SOURCE_NAME, "p": SENTINEL_DOC},
).scalar_one()
assert SENTINEL in sentinel_content
# And the catalog shows it (drill source → notes → the sentinel row).
_go_top(page)
page.click(f'#folders-tbody a.folder-link:text-is("{GIT_SOURCE_NAME}")')
page.click('#folders-tbody a.folder-link:text-is("notes")')
expect(page.locator("#docs-tbody tr", has_text=SENTINEL_DOC)).to_have_count(1)
# ---------------------------------------------------------------------------
# 2. Phase 134 under asyncio.to_thread: cancel DURING the clone
# ---------------------------------------------------------------------------
def test_cancel_during_clone_reaches_terminal(
page: Page, app_url: str, checkout_dir: Path, db_ready: None
) -> None:
"""The cancel-during-clone contract under the off-loop scheduling
(decision A2's observable): with the checkout deleted the run
re-clones — a long git phase again — and the UI's Cancel click
round-trips in < 1.5 s. The run settles into the neutral
``cancelled`` terminal WITHOUT waiting for the git worker: the
sentinel worktree is still absent when the terminal lands and while
the abandoned clone keeps writing, every status probe is served in
< 1.5 s. The import never started (no documents for the source), and
the UI settles retry-ready with no error surface."""
page.set_default_timeout(30_000)
# Force a fresh clone for this run (the checkout is the previous
# test's completed one).
shutil.rmtree(checkout_dir, ignore_errors=True)
assert not checkout_dir.exists()
login(page, app_url)
btn = page.locator("#sync-btn")
cancel = page.locator("#sync-cancel-btn")
expect(btn).to_be_enabled()
expect(cancel).to_be_hidden()
btn.click()
expect(btn).to_be_disabled()
expect(cancel).to_be_visible()
# The deterministic layer: the run is IN the git prelude (running,
# no phase) — the cancel must land on the in-flight clone, not on
# the import.
body = _wait_sync_state(page, app_url, {"running"})
assert body["state"] == "running" and body["phase"] is None, body
# The owner's click, timed end to end: click → the browser's
# POST /api/sync/cancel → its response. Pre-phase-179 this request
# was queued behind the clone (task 01: ≈ the full clone).
clicked = time.monotonic()
with page.expect_response(
lambda resp: "/api/sync/cancel" in resp.url, timeout=UI_SETTLE_TIMEOUT_MS
):
cancel.click()
cancel_elapsed = time.monotonic() - clicked
assert cancel_elapsed < POLL_CEILING_S, (
f"the Cancel click round-tripped in {cancel_elapsed:.3f}s — the loop is "
"still parked by the clone, so the UI cannot even ask to stop a sync"
)
expect(cancel).to_be_disabled() # never stale: disabled on the first line
# Keep probing while the ABANDONED git worker is still running (the
# worktree appears only when clone finishes): the loop serves the
# whole HTTP surface while the thread runs to completion, and the
# run lands the cancelled terminal without waiting for it.
probes: list[tuple[float, dict[str, Any]]] = []
while_during_clone = 0
deadline = time.monotonic() + 60.0
terminal: dict[str, Any] | None = None
while time.monotonic() < deadline:
still_cloning = not _clone_finished(checkout_dir)
elapsed, body = _timed_status(page, app_url)
probes.append((elapsed, body))
if still_cloning:
while_during_clone += 1
if body["state"] != "running":
terminal = body
if not still_cloning:
break
time.sleep(0.5)
assert terminal is not None, "the cancelled terminal never landed"
assert terminal["state"] == "cancelled", terminal
# The phase-134 shape: intent, not failure.
assert terminal["error"] is None
assert terminal["detail"] == {}
assert terminal["started_at"] is not None and terminal["finished_at"] is not None
assert terminal["current_file"] is None and terminal["phase"] is None
assert terminal["current_summary"] is None
assert terminal["current_chunk"] == 0 and terminal["chunks_total"] == 0
# The cancel caught the run in the git prelude: no file was ever
# handed to the import, and the abandoned clone's result is never
# consumed (no half-cancelled index).
assert terminal["files_done"] == 0 and terminal["files_total"] == 0
with SessionLocal() as db:
n_docs = db.execute(
text("SELECT count(*) FROM documents WHERE source = :s"),
{"s": GIT_SOURCE_NAME},
).scalar_one()
assert n_docs == 0, n_docs
# A2's observable, pinned: enough probes to be meaningful, every one
# of them served — including the ones issued while the git thread
# was still copying the repo.
assert while_during_clone >= MIN_POLLS_IN_WINDOW, (
f"only {while_during_clone} probes landed while the abandoned clone was "
"still in flight — the cancelled terminal waited for the git worker "
"(or the clone finished before the cancel), so nothing pinned the "
"thread-runs-in-the-background contract"
)
_assert_served(probes, "during/after a cancelled clone")
# The neutral UI settle: "Sync cancelled", retry-ready, no error.
expect(page.locator("#sync-progress-text")).to_have_text(
counts_line("Sync cancelled"), timeout=UI_SETTLE_TIMEOUT_MS
)
expect(page.locator("#sync-label")).to_have_text(
"Sync sources", timeout=UI_SETTLE_TIMEOUT_MS
)
expect(btn).to_be_enabled()
expect(btn).not_to_have_attribute("aria-busy")
expect(cancel).to_be_hidden()
expect(page.locator("#sync-error-banner")).to_be_hidden()
assert page.locator(".sync-modal-backdrop").count() == 0