**Phase 194 — final verification pass: all green.**
**Verified (all 5 tasks already complete; nothing re-implemented needed)**
- `app/rag/importer.py`: `_prescan_pending` + `_pending_hash_stmt` (scalar `documents.file_hash`, own session, ONE `asyncio.to_thread` span, REPLACES the stats pre-walk), `on_scan_progress`, `progress` pair = pending position, `0` branch = byte-identical phase-193 walk.
- `app/config.py`/`settings_catalog.py`/`.env.example`: `sync_pending_count=1` + validator; `app/api/sync.py`: `"scan"` phase, `scan_done`/`scan_total` (additive after `files_total`, kept at every terminal), forced/throttled RSS split; `frontend/assets/sources.js`: `fmtSyncPhaseLabel` scan branch first-arm, `fmtSyncLabel` untouched.
**Tests / lint / coverage (exact commands)**
- `uv run pytest --cov=app --cov-report=term-missing` → **4835 passed**, `app/` 99% (7240 stmts / 16 miss), exit 0
- `uv run pytest tests/e2e/test_sync_pending_count.py -v --no-cov` → **8 passed in 150.81s** (phase suite, isolated)
- 14 sync-lineage E2E suites, one pytest process each (`test_sync_remaining_count`, `…_chunk_progress`, `…_progress_box`, `…_peak_memory_visible`, `…_label_mobile`, `…_upload_progress`, `test_archive_upload_sources`, `…_image_progress`, `…_summary_visibility`, `…_status_freshness`, `test_smoke`, `test_fast_path_deferred_content`, `test_sync_session_reset`, `test_sync_git_freeze`) → **all exit 0**
- `uv run ruff check .` → All checks passed; `uv run pyright` → **0 errors**
**Completion criteria** — all met: `N remaining` = predicted change set (E2E arms 1/2/5, first import counts the walk, no-change → no count part); `scan` phase visible + flips to `import`, scan pair reset/kept at terminals (`test_sync_scan_phase.py`); `BOR_SYNC_PENDING_COUNT=0` walk semantics ("7 remaining" arm) + **negative refuses startup naming the field (verified live by importing `app.main`)**; pre-scan off-loop + cancel lands `cancelled` (integration pins); CLI/upload byte-identical (unedited pins green); payload additive (`_PRE_187_STATUS_KEYS | _MEMORY_KEYS | _SCAN_KEYS`); suite green, coverage >90%, lint/types clean.
**Documentation** — 3 fixes: README sync "States" bullet had an **unclosed parenthesis** (pre-existing, 193/194) and the scan-label "total is 0" clause was ambiguous about a `=0` run (it still counts the walk once the import starts); **AGENTS.md rule 17 had a stray `)`** (pre-existing from phase 191). Also verified consistency both directions for all 87 settings ↔ README ↔ `.env.example` ↔ settings catalog, the pages table ↔ `app/main.py` routes, no stale `BOR_` names, and README/AGENTS claims through phase 194.
**Notes/deviations** — no live-infra changes (prod sync knob ships default-on, no deployment touched); no git index/history commands run (all changes left in the working tree for the harness); commit criterion left to the harness as instructed.
**Next pending phase:** none — `.agents/phases/todo/` holds only `194_sync_pending_count`, which is now ready to move to `complete/`.
645 lines
30 KiB
Python
645 lines
30 KiB
Python
"""Integration: phase 179 — the owner's suspicion (``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 (phase 179 task 02,
|
|
``asyncio.to_thread``).** A long ``git clone`` during a sync DID block
|
|
the app's event loop, and while it was blocked the ENTIRE HTTP surface
|
|
was stalled — including ``GET /api/sync/status``, the endpoint the UI
|
|
polls every 2 s, and even the dependency-free ``GET /api/health``. The
|
|
server did not fail; it FROZE — and the UI's status poll, the one
|
|
request that must stay live to watch a long sync, was among the
|
|
victims. Both git steps now run in a worker thread, and the probes
|
|
below are flipped to pin the server staying responsive.
|
|
|
|
**Mechanism (pre-fix, no ``to_thread`` anywhere).** ``POST /api/sync``
|
|
spawns the run with ``asyncio.create_task(_run_sync())``
|
|
(``app/api/sync.py``) — the coroutine runs on the app's SINGLE uvicorn
|
|
event loop. ``_run_sync`` called the per-source git steps as plain
|
|
synchronous calls — ``root = clone_or_pull(...)`` →
|
|
``scripts/git_sync.py::clone_or_pull`` → ``run_git`` →
|
|
``subprocess.run``. There was no ``asyncio.to_thread`` and no
|
|
``create_subprocess_exec`` anywhere in ``app/`` or ``scripts/``, so a
|
|
long clone parked the loop thread itself: no other coroutine —
|
|
including the ASGI dispatch of ANY incoming request, even sync-``def``
|
|
threadpool endpoints like ``/api/health`` — could be scheduled until
|
|
git returned.
|
|
|
|
**Measured PRE-fix (task 01, 3.0 s stubbed clone).** The
|
|
``GET /api/sync/status`` probe issued into the middle of the clone took
|
|
**≈3.0 s** (measured 3.04 s — the full remainder of the git op plus the
|
|
runner's yield-less tail); the ``GET /api/health`` probe in the same
|
|
window took **≈3.0 s** (measured 3.02 s — any endpoint on the loop
|
|
stalls); the trigger's own ``202`` was held ≈ 3.2 s. Idle, the same
|
|
endpoints answer in **milliseconds** (measured ≈ 0.001 s).
|
|
|
|
**Measured POST-fix (task 02, the same 3.0 s stubbed clone, the same
|
|
scenario).** The status probe issued into the middle of the clone took
|
|
**≈ 0.003 s** (0.0031 s), the second poll one second later the same
|
|
(0.0027 s), ``GET /api/health`` **≈ 0.003 s** (0.0033 s), the trigger's
|
|
``202`` **≈ 0.026 s**, and a ``POST /api/sync/cancel`` issued mid-clone
|
|
**≈ 0.004 s** with the ``cancelled`` terminal landing **≈ 0.006 s**
|
|
later — still INSIDE the abandoned clone's sleep, which is the proof
|
|
that the run no longer waits for the git worker while the worker itself
|
|
finishes on its own. The stub records the thread it ran on: pre-fix it
|
|
was the event-loop thread (identical idents), post-fix it is an
|
|
``asyncio`` worker thread (different ident) — asserted, so a git op that
|
|
slides back onto the loop fails this file even on a machine fast enough
|
|
to hide the latency.
|
|
|
|
**What phase 179 does NOT change:** the pipeline sequence, the run's
|
|
terminals (the stubbed run still lands ``success`` with the same
|
|
``detail``), and the phase-134 cooperative-cancel contract — a cancel
|
|
registered while a git op is in flight stops the run at the next
|
|
boundary (or right at the ``to_thread`` await, which is now the
|
|
common case), lands the ``cancelled`` terminal with ``error`` null and
|
|
``detail`` empty, and never resumes the pipeline with the abandoned
|
|
clone's result. Python threads are not interruptible: the git worker
|
|
runs its ``subprocess`` to completion, but the EVENT LOOP is free the
|
|
whole time.
|
|
|
|
**Why phase 194 leaves these git-span pins alone (the D5 sweep).** The
|
|
runner's import here is a stub (``fake_import`` below, which accepts the
|
|
phase-194 ``on_scan_progress`` argument and fires nothing), so no real
|
|
pre-scan runs inside this file's measurement window — the clone window
|
|
this suite pins stays the only off-loop span it measures. The pre-scan's
|
|
OWN loop-responsiveness pin (the same phase-179 pattern: a blocking
|
|
``_file_hash`` over a multi-file fixture while a heartbeat coroutine keeps
|
|
being scheduled, plus the worker-thread identity) lives in
|
|
``tests/integration/test_sync_pending_count.py`` — beside the cancel at
|
|
that span's await (the importer-side twin of this file's
|
|
cancel-during-clone pin) and its app-side twin in
|
|
``tests/integration/test_sync_scan_phase.py``.
|
|
|
|
**TestClient mechanics (why the trigger still rides a side thread).**
|
|
The shared app loop here is anyio's ``BlockingPortal`` thread. Firing
|
|
``POST /api/sync`` from the test thread would make the mid-clone probe
|
|
unfalsifiable — on a regressed (blocking) run the POST itself would be
|
|
held for the whole clone and only return once the git window had
|
|
CLOSED, so a later probe would be served instantly and pass on a frozen
|
|
server. With the trigger on its own thread the MAIN thread is a free
|
|
second client — the UI's 2 s poll — and the probe provably lands
|
|
mid-clone (the stub's ``finished_at is None`` pin). The trigger's own
|
|
latency is asserted too, in the post-fix direction (prompt, not held).
|
|
|
|
**The repro is deterministic and in-process:**
|
|
``app.api.sync.clone_or_pull`` / ``app.api.sync.file_commit_dates`` (the
|
|
module-level names imported in ``app/api/sync.py`` — patching the
|
|
``scripts.git_sync`` originals would NOT affect the runner) are
|
|
monkeypatched with stubs that record a ``time.monotonic()`` start/end,
|
|
the thread they ran on, and ``time.sleep(3.0)`` — the stub is a PLAIN
|
|
SYNC function, exactly like the real ``clone_or_pull``, because the
|
|
point under test is WHERE it runs. The git source rides the env fallback
|
|
(``BOR_GIT_SOURCES=file://<tmp repo>``, a fresh ``Settings`` on the
|
|
resolver's module — the dev ``.env`` never leaks in); the tmp repo is a
|
|
real one-commit git repo (the ``test_sync_cancel._git`` helper shape)
|
|
although the stub never actually clones it.
|
|
|
|
House patterns (``test_sync_api.py``): the ``sync_client`` fixture is a
|
|
**context-managed** ``TestClient`` — one app event loop across requests,
|
|
exactly how the app runs under uvicorn (without the context manager a
|
|
fresh loop per request would cancel the background task); the module
|
|
status/task/cancel-event reset + the ``git_sources`` / ``sources_meta``
|
|
/ ``folder_summaries`` global-state hygiene fixtures around every test;
|
|
the import / overview / folder-summary layers monkeypatched in
|
|
``app.api.sync`` so only the CLONE is the timing fixture.
|
|
"""
|
|
from __future__ import annotations
|
|
|
|
import asyncio
|
|
import subprocess
|
|
import threading
|
|
import time
|
|
from collections.abc import Callable, Iterator, Sequence
|
|
from datetime import datetime
|
|
from pathlib import Path
|
|
from typing import Any
|
|
|
|
import pytest
|
|
from fastapi.testclient import TestClient
|
|
from sqlalchemy import text
|
|
from sqlalchemy.orm import Session
|
|
|
|
from app.api import sync as sync_api
|
|
from app.config import Settings
|
|
from app.db import SessionLocal, db_available
|
|
from app.main import app as fastapi_app
|
|
from app.rag import git_sources as git_sources_resolver
|
|
from app.rag.importer import ImportSummary
|
|
from app.rag.llm import LLMClient
|
|
from tests.conftest import ADMIN_PASSWORD
|
|
|
|
# The timing fixture: a "long clone" of 3.0 s.
|
|
CLONE_SLEEP = 3.0
|
|
# POST-fix ceiling (phase 179 task 02): every request issued into the
|
|
# middle of the 3 s clone must be served in < 1.5 s — the phase's
|
|
# number, deliberately far above a warm-loop round trip (measured in
|
|
# milliseconds) and far below the clone itself, so a git op that slides
|
|
# back onto the event loop (task 01 measured >= 2.5 s of the same 3 s
|
|
# stub, 3.04 s actual) can never pass this pin.
|
|
PROBE_CEILING = 1.5
|
|
# The idle baseline ceiling: the host-slop canary — if the IDLE probe is
|
|
# slow, the host is too loaded to time anything and this suite's numbers
|
|
# mean nothing.
|
|
IDLE_CEILING = 1.0
|
|
|
|
|
|
@pytest.fixture(autouse=True)
|
|
def _fresh_sync_state() -> Iterator[None]:
|
|
"""House pattern (test_sync_api): the module-level status object +
|
|
task + cancel event are process-global — reset them around every
|
|
test (before AND after) so no terminal state / stale cancel bleeds."""
|
|
sync_api._status = sync_api.SyncStatus()
|
|
sync_api._task = None
|
|
sync_api._cancel_event = asyncio.Event()
|
|
yield
|
|
sync_api._status = sync_api.SyncStatus()
|
|
sync_api._task = None
|
|
sync_api._cancel_event = asyncio.Event()
|
|
|
|
|
|
@pytest.fixture(autouse=True)
|
|
def clean_git_sources(db: Session) -> Iterator[None]:
|
|
"""The env fallback only applies while the ``git_sources`` table is
|
|
EMPTY — truncate it around every test so ``BOR_GIT_SOURCES`` is
|
|
deterministically the origin of the run's single row."""
|
|
db.execute(text("TRUNCATE git_sources"))
|
|
db.commit()
|
|
yield
|
|
db.execute(text("TRUNCATE git_sources"))
|
|
db.commit()
|
|
|
|
|
|
@pytest.fixture(autouse=True)
|
|
def _reset_sources_version() -> Iterator[None]:
|
|
"""The fake import reports a CHANGED KB (added=1), so the runner's
|
|
phase-53 bump fires through its own short-lived ``SessionLocal`` —
|
|
pin the counter to the migration-0010 seed (0) around every test."""
|
|
if not db_available():
|
|
pytest.skip("Postgres not reachable — run `podman compose up -d db` first")
|
|
session = SessionLocal()
|
|
try:
|
|
session.execute(text("UPDATE sources_meta SET version = 0 WHERE id = 1"))
|
|
session.commit()
|
|
yield
|
|
finally:
|
|
session.execute(text("UPDATE sources_meta SET version = 0 WHERE id = 1"))
|
|
session.commit()
|
|
session.close()
|
|
|
|
|
|
@pytest.fixture(autouse=True)
|
|
def _clean_folder_summaries(db: Session) -> Iterator[None]:
|
|
"""``folder_summaries`` is global state the sync touches (the fake
|
|
generator never writes here, but the changed-KB branch runs through
|
|
the runner's own session) — truncate around every test."""
|
|
db.execute(text("TRUNCATE folder_summaries"))
|
|
db.commit()
|
|
yield
|
|
db.execute(text("TRUNCATE folder_summaries"))
|
|
db.commit()
|
|
|
|
|
|
@pytest.fixture()
|
|
def sync_client() -> Iterator[TestClient]:
|
|
"""Context-managed TestClient — one app event loop across requests
|
|
(the background task must survive between the POST and the probes;
|
|
this is precisely what makes the probes measure the loop's state —
|
|
starved pre-phase-179, free post-phase-179)."""
|
|
with TestClient(fastapi_app) as client:
|
|
yield client
|
|
|
|
|
|
def _settings(sources_dir: str) -> Settings:
|
|
"""Fresh settings (no .env file); the checkout root lands in tmp."""
|
|
return Settings(_env_file=None, sources_dir=sources_dir) # pyright: ignore[reportCallIssue]
|
|
|
|
|
|
def _stub_env(monkeypatch: pytest.MonkeyPatch, git_sources: str) -> None:
|
|
"""The resolver's env fallback, driven by a fresh ``Settings`` (the
|
|
dev ``.env`` never leaks in — the test_sync_api pattern)."""
|
|
monkeypatch.setattr(
|
|
git_sources_resolver,
|
|
"get_settings",
|
|
lambda: Settings(_env_file=None, git_sources=git_sources), # pyright: ignore[reportCallIssue]
|
|
)
|
|
|
|
|
|
def _login(client: TestClient) -> None:
|
|
r = client.post("/api/login", json={"password": ADMIN_PASSWORD})
|
|
assert r.status_code == 204, f"admin login failed: {r.status_code} {r.text}"
|
|
|
|
|
|
def _poll(client: TestClient, want: str, timeout: float = 15.0) -> dict:
|
|
"""Poll ``GET /api/sync/status`` until ``state == want`` (terminal).
|
|
Any other state before the deadline fails loudly. The default
|
|
timeout is generous so a wait never races the stub's tail; the
|
|
cancel test passes a SHORT one on purpose — the ``cancelled``
|
|
terminal must land while the abandoned clone is still sleeping
|
|
(phase 179: the run no longer waits for the git worker)."""
|
|
deadline = time.monotonic() + timeout
|
|
while time.monotonic() < deadline:
|
|
body = client.get("/api/sync/status").json()
|
|
if body["state"] == want:
|
|
return body
|
|
assert body["state"] == "running", (
|
|
f"unexpected state {body['state']!r} while waiting for {want!r}: {body}"
|
|
)
|
|
time.sleep(0.05)
|
|
raise AssertionError(f"sync did not reach {want!r} within {timeout}s")
|
|
|
|
|
|
def _git(cwd: Path, *args: str) -> None:
|
|
"""Run git in *cwd*; a non-zero exit fails the fixture loudly
|
|
(the ``tests/e2e/test_sync_cancel.py`` 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 _make_repo(tmp_path: Path) -> Path:
|
|
"""A real one-commit git repo — the env-fallback source the runner
|
|
resolves. The stub NEVER clones it (content is irrelevant); it exists
|
|
so ``repo_name`` / ``clone_url_for`` resolve a real ``file://`` URL."""
|
|
repo = tmp_path / "freeze_repo.git"
|
|
(repo / "notes").mkdir(parents=True)
|
|
(repo / "notes" / "seed.md").write_text("# Seed\nfreeze-fixture content\n", encoding="utf-8")
|
|
_git(repo, "init", "-q")
|
|
_git(repo, "add", "-A")
|
|
_git(
|
|
repo,
|
|
"-c", "user.email=e@x", "-c", "user.name=t",
|
|
"-c", "commit.gpgsign=false", # the fixture commit never signs
|
|
"commit", "-qm", "init",
|
|
)
|
|
return repo
|
|
|
|
|
|
class _SlowClone:
|
|
"""The timing fixture: sync stubs for ``clone_or_pull`` /
|
|
``file_commit_dates`` (PLAIN SYNC functions — like the real ones,
|
|
so the only variable is WHERE the runner calls them: ON the loop
|
|
pre-phase-179, in a worker thread after the fix).
|
|
``clone_or_pull`` signals entry (``started``), records the
|
|
monotonic window, sleeps the simulated clone, and returns the tmp
|
|
repo's ``Path``; ``file_commit_dates`` answers ``{}``."""
|
|
|
|
def __init__(self, repo: Path, sleep: float = CLONE_SLEEP) -> None:
|
|
self.repo = repo
|
|
self.sleep = sleep
|
|
self.started = threading.Event()
|
|
self.started_at: float | None = None
|
|
self.finished_at: float | None = None
|
|
self.calls: list[tuple[str, Path, str | None]] = []
|
|
# Which thread the git op ran on, versus which thread awaited it
|
|
# (``loop_thread_ident``, filled by the fake ``check_models``
|
|
# that runs on the app's loop). PRE-fix the two were THE SAME
|
|
# thread — that identity IS the freeze; phase 179 makes them
|
|
# differ (the git op lands in a ``to_thread`` worker).
|
|
self.thread_ident: int | None = None
|
|
self.thread_name: str | None = None
|
|
self.loop_thread_ident: int | None = None
|
|
|
|
def clone_or_pull(self, url: str, dest: Path | str, branch: str | None = None) -> Path:
|
|
self.calls.append((url, Path(dest), branch))
|
|
self.thread_ident = threading.get_ident()
|
|
self.thread_name = threading.current_thread().name
|
|
self.started_at = time.monotonic()
|
|
self.started.set()
|
|
# THE (simulated) LONG CLONE: a blocking git op — exactly what
|
|
# ``run_git``'s ``subprocess.run`` does. PRE-fix it held the
|
|
# event loop thread and nothing else got scheduled until it
|
|
# returned; phase 179 runs it in a worker thread.
|
|
time.sleep(self.sleep)
|
|
self.finished_at = time.monotonic()
|
|
return self.repo
|
|
|
|
def file_commit_dates(self, root: Path | str) -> dict[str, datetime]:
|
|
return {}
|
|
|
|
|
|
class _FakeImport:
|
|
"""Canned changed-KB import (no files touched): records the runner's
|
|
wiring, returns ``added=1`` so the run takes the overview +
|
|
incremental-summaries branches and lands ``success``."""
|
|
|
|
def __init__(self) -> None:
|
|
self.sources: list[list[Path]] = []
|
|
self.doc_dates_maps: list[dict[str, dict[str, datetime]]] = []
|
|
self.prune_flags: list[bool] = []
|
|
|
|
async def __call__(
|
|
self,
|
|
sources: list[Path],
|
|
llm: LLMClient,
|
|
*,
|
|
prune: bool = False,
|
|
limit: int | None = None,
|
|
session: Session | None = None,
|
|
progress: Callable[[str, str, int, int], None] | None = None,
|
|
on_chunk_progress: Callable[[int, int], None] | None = None,
|
|
on_image_progress: Callable[[int, int], None] | None = None,
|
|
on_scan_progress: Callable[[int, int], None] | None = None, # phase 194
|
|
ignore_by_root: dict[str, list[str]] | None = None,
|
|
include_hidden_by_root: dict[str, bool] | None = None,
|
|
doc_dates_by_root: dict[str, dict[str, datetime]] | None = None,
|
|
) -> ImportSummary:
|
|
self.sources.append(list(sources))
|
|
self.prune_flags.append(prune)
|
|
self.doc_dates_maps.append(doc_dates_by_root or {})
|
|
return ImportSummary(files=1, added=1, updated=0, unchanged=0, pruned=0)
|
|
|
|
|
|
class _FakeOverview:
|
|
async def __call__(self, llm: LLMClient, session: Session | None = None) -> bool:
|
|
return True
|
|
|
|
|
|
class _FakeFolderSummaries:
|
|
async def __call__(
|
|
self,
|
|
db: Session,
|
|
llm: LLMClient,
|
|
*,
|
|
skip: bool = False,
|
|
only_missing: bool = False,
|
|
changed_docs: Sequence[tuple[str, str]] | None = None,
|
|
on_progress: Callable[[int, int, str, str], None] | None = None,
|
|
) -> dict[str, int]:
|
|
return {"generated": 0, "failed": 0, "pruned": 0}
|
|
|
|
|
|
def _install(
|
|
monkeypatch: pytest.MonkeyPatch, tmp_path: Path
|
|
) -> tuple[Path, _SlowClone, _FakeImport]:
|
|
"""Wire one stubbed sync run: env-fallback git source, tmp sources
|
|
root, stubbed probe + import + overview + summaries, and the
|
|
3 s-blocking clone stub on the ``app.api.sync`` module names."""
|
|
repo = _make_repo(tmp_path)
|
|
_stub_env(monkeypatch, f"file://{repo}")
|
|
monkeypatch.setattr(
|
|
sync_api, "get_settings", lambda: _settings(sources_dir=str(tmp_path / "bor"))
|
|
)
|
|
slow = _SlowClone(repo)
|
|
# Patch the module-level names imported at app/api/sync.py L233 —
|
|
# the runner calls THESE, not the scripts.git_sync originals.
|
|
monkeypatch.setattr(sync_api, "clone_or_pull", slow.clone_or_pull)
|
|
monkeypatch.setattr(sync_api, "file_commit_dates", slow.file_commit_dates)
|
|
|
|
async def fake_check_models(llm: LLMClient) -> None:
|
|
# No network — the clone is the only timing fixture. AND: this
|
|
# coroutine runs ON the app's event loop (``_run_sync`` awaits it
|
|
# there), so it is where the loop's OWN thread identity is
|
|
# recorded — the pin that the git op no longer shares it.
|
|
slow.loop_thread_ident = threading.get_ident()
|
|
|
|
monkeypatch.setattr(sync_api, "check_models", fake_check_models)
|
|
fake_import = _FakeImport()
|
|
monkeypatch.setattr(sync_api, "import_sources", fake_import)
|
|
monkeypatch.setattr(sync_api, "regenerate_overview", _FakeOverview())
|
|
monkeypatch.setattr(sync_api, "generate_folder_summaries", _FakeFolderSummaries())
|
|
return repo, slow, fake_import
|
|
|
|
|
|
def _trigger_from_side_thread(client: TestClient) -> tuple[threading.Thread, dict[str, Any]]:
|
|
"""Fire ``POST /api/sync`` from a SIDE thread and return immediately.
|
|
|
|
Why not POST from the test thread: it makes the mid-clone probe
|
|
unfalsifiable. If the git op ever slides back onto the event loop
|
|
(the regression this suite exists to catch), a test-thread POST is
|
|
held for the whole clone and only returns once the git window has
|
|
CLOSED — a probe issued after it would be served instantly and the
|
|
latency assertion would pass on a frozen server. With the trigger on
|
|
its own thread the MAIN thread is a free second client — the UI's 2 s
|
|
status poll — and the probe provably lands mid-clone (the stub's own
|
|
``finished_at is None`` pin below). The trigger's ``202`` is asserted
|
|
too, in the post-fix direction: phase 179 task 01 measured it held
|
|
for ≈ the full clone (its response dispatch rode the frozen loop);
|
|
it must now come back promptly."""
|
|
result: dict[str, Any] = {}
|
|
|
|
def _fire() -> None:
|
|
t0 = time.monotonic()
|
|
r = client.post("/api/sync")
|
|
result["status"] = r.status_code
|
|
result["elapsed"] = time.monotonic() - t0
|
|
|
|
thread = threading.Thread(target=_fire, name="sync-trigger", daemon=True)
|
|
thread.start()
|
|
return thread, result
|
|
|
|
|
|
# --- anonymous gating (house 403 pins) -------------------------------------
|
|
|
|
|
|
def test_anonymous_gets_403_on_sync_surface(client: TestClient) -> None:
|
|
"""The probes run as admin; the anonymous 403s on the two endpoints
|
|
they exercise stay pinned (router ``require_admin``)."""
|
|
assert client.get("/api/sync/status").status_code == 403
|
|
assert client.post("/api/sync").status_code == 403
|
|
|
|
|
|
# --- the mid-clone responsiveness probes (phase 179) ------------------------
|
|
|
|
|
|
def test_long_git_clone_no_longer_freezes_the_event_loop(
|
|
sync_client: TestClient, monkeypatch: pytest.MonkeyPatch, db: Session, tmp_path: Path
|
|
) -> None:
|
|
"""THE contract (phase 179 task 02 — the flip of task 01's repro).
|
|
With the git ops off the loop, the same scenario answers:
|
|
|
|
S0 (baseline) — idle, ``GET /api/sync/status`` answers in ms.
|
|
S1 (PRIMARY, the flip) — the status probe issued into the middle of
|
|
the 3 s stubbed clone — the exact request the UI's 2 s poll is —
|
|
is served in < 1.5 s (measured in ms) and reports the LIVE run
|
|
(``state=running``, ``phase``/``current_file`` null: the
|
|
clone/pull prelude). The stub's own recording proves the probe
|
|
landed INSIDE the clone window (``finished_at`` still None when
|
|
the response came back), so this is loop-freeness, not a clone
|
|
that finished early.
|
|
S2 — the git op ran on a DIFFERENT thread than the one that awaited
|
|
it (pre-fix: the same thread — that identity is the freeze).
|
|
S3 — a second poll ~1 s later (the UI's cadence) is answered just as
|
|
fast while the same clone is still running.
|
|
S4 — the trigger's own ``202`` is released promptly (task 01
|
|
measured it held for ≈ the whole clone; its response dispatch no
|
|
longer rides a parked loop).
|
|
|
|
The run still completes ``success`` with the same detail as before —
|
|
phase 179 changed scheduling, not behavior — and the fixture is left
|
|
clean for the next test."""
|
|
repo, slow, fake_import = _install(monkeypatch, tmp_path)
|
|
_login(sync_client)
|
|
|
|
# S0: idle, the status endpoint answers in milliseconds (this is
|
|
# the endpoint that must stay live to watch a sync — phase 32).
|
|
t0 = time.monotonic()
|
|
r = sync_client.get("/api/sync/status")
|
|
idle_elapsed = time.monotonic() - t0
|
|
assert r.status_code == 200 and r.json()["state"] == "idle"
|
|
assert idle_elapsed < IDLE_CEILING, f"idle status took {idle_elapsed:.3f}s — host too slow?"
|
|
|
|
thread, posted = _trigger_from_side_thread(sync_client)
|
|
# Give the trigger request a head start onto the loop, then wait
|
|
# (bounded) for the run to enter the blocking clone stub.
|
|
time.sleep(0.2)
|
|
assert slow.started.wait(10.0), "the run never reached the clone step"
|
|
|
|
# S1 — THE PROBE (PRIMARY): issued into the middle of the stubbed
|
|
# clone. PRE-fix (task 01) this request could not even be
|
|
# DISPATCHED — it returned only once the clone was done (≈ 3.0 s).
|
|
# Post-fix the clone occupies a to_thread worker, so the loop
|
|
# answers it in milliseconds.
|
|
t0 = time.monotonic()
|
|
probe = sync_client.get("/api/sync/status")
|
|
probe_elapsed = time.monotonic() - t0
|
|
assert probe.status_code == 200
|
|
body_live = probe.json()
|
|
assert body_live["state"] == "running"
|
|
# The clone/pull prelude reports no file and no phase (phase 64/98).
|
|
assert body_live["current_file"] is None
|
|
assert body_live["phase"] is None
|
|
assert probe_elapsed < PROBE_CEILING, (
|
|
f"status probe took {probe_elapsed:.3f}s during a {CLONE_SLEEP}s clone — "
|
|
f"the event loop is still being parked by the git op "
|
|
f"(expected < {PROBE_CEILING}s; pre-phase-179 it took >= 2.5s)"
|
|
)
|
|
|
|
# The probe landed INSIDE the git op, not after it: the stub had
|
|
# entered and had NOT exited when the response came back. Without
|
|
# this pin a too-fast fixture could fake the post-fix numbers.
|
|
assert slow.started_at is not None
|
|
assert slow.finished_at is None, (
|
|
"the status probe did not land inside the clone window — the "
|
|
"latency above measured an idle server, not a cloning one"
|
|
)
|
|
|
|
# S2: the git op does NOT run on the thread that awaited it. PRE-fix
|
|
# ``clone_or_pull`` executed on the event loop thread itself (the
|
|
# two idents matched) — that shared thread is exactly what froze.
|
|
assert slow.thread_ident is not None and slow.loop_thread_ident is not None
|
|
assert slow.thread_ident != slow.loop_thread_ident, (
|
|
f"the git op ran on the event loop thread ({slow.thread_name}) — "
|
|
"it must run in an asyncio.to_thread worker"
|
|
)
|
|
|
|
# S3: the UI's 2 s poll cadence keeps working THROUGH the clone —
|
|
# another poll ~1 s in, same fast answer, same live run.
|
|
time.sleep(1.0)
|
|
t0 = time.monotonic()
|
|
second = sync_client.get("/api/sync/status")
|
|
second_elapsed = time.monotonic() - t0
|
|
assert second.status_code == 200 and second.json()["state"] == "running"
|
|
assert second_elapsed < PROBE_CEILING, (
|
|
f"second status poll took {second_elapsed:.3f}s during the clone"
|
|
)
|
|
assert slow.finished_at is None, "the clone ended before the second poll"
|
|
|
|
# S4: the trigger's own 202 is released promptly now (task 01:
|
|
# held for ≈ the whole clone by the frozen loop).
|
|
thread.join(timeout=15.0)
|
|
assert not thread.is_alive(), "the trigger POST never returned"
|
|
assert posted["status"] == 202
|
|
assert posted["elapsed"] < PROBE_CEILING, (
|
|
f"trigger POST returned in {posted['elapsed']:.3f}s — its response "
|
|
f"dispatch is still queued behind the git op"
|
|
)
|
|
|
|
# Fixture cleanliness + the run's health: the stub returns, so the
|
|
# run completes success — the SAME terminal as before the fix
|
|
# (phase 179 moved scheduling only, it changed no behavior).
|
|
# (The terminal lands on whichever branch the stubbed root yields:
|
|
# the canned added=1 import → success with the overview + summary
|
|
# branches and the phase-53 bump.)
|
|
body = _poll(sync_client, "success")
|
|
assert body["error"] is None
|
|
assert body["detail"]["overview"] is True
|
|
assert body["detail"]["sources_version"] == 1
|
|
|
|
# The stub ran exactly once, on the env-resolved row (bare URL,
|
|
# branch None) into BOR_SOURCES_DIR/<repo-name>/.
|
|
assert slow.calls == [(f"file://{repo}", tmp_path / "bor" / "freeze_repo", None)]
|
|
assert fake_import.sources == [[repo]]
|
|
assert fake_import.prune_flags == [True]
|
|
# The runner fed the per-root date map from the stubbed git layer.
|
|
assert fake_import.doc_dates_maps == [{str(repo): {}}]
|
|
|
|
|
|
def test_health_stays_responsive_during_a_long_clone(
|
|
sync_client: TestClient, monkeypatch: pytest.MonkeyPatch, db: Session, tmp_path: Path
|
|
) -> None:
|
|
"""The blast radius, flipped (phase 179 task 02): task 01 found the
|
|
freeze covered the WHOLE HTTP surface — even ``GET /api/health``
|
|
(dependency-free, no admin, plain threadpool handler) took ≈ the
|
|
full clone. Post-fix that endpoint answers in < 1.5 s (measured in
|
|
ms) while the same 3 s clone is still in flight (the stub's
|
|
``finished_at`` pin), and the run still lands ``success``."""
|
|
_, slow, _ = _install(monkeypatch, tmp_path)
|
|
_login(sync_client)
|
|
thread, _posted = _trigger_from_side_thread(sync_client)
|
|
time.sleep(0.2)
|
|
# Enter the clone window through the stub's own signal (the probe
|
|
# below must be the request that lands inside the window, not a
|
|
# warm-up call).
|
|
assert slow.started.wait(10.0), "the run never reached the clone step"
|
|
|
|
t0 = time.monotonic()
|
|
r = sync_client.get("/api/health")
|
|
elapsed = time.monotonic() - t0
|
|
assert r.status_code == 200
|
|
assert elapsed < PROBE_CEILING, (
|
|
f"health probe took {elapsed:.3f}s during a {CLONE_SLEEP}s clone — "
|
|
f"the loop is still parked by the git op (expected < {PROBE_CEILING}s)"
|
|
)
|
|
assert slow.finished_at is None, "the health probe did not land inside the clone"
|
|
thread.join(timeout=15.0)
|
|
_poll(sync_client, "success")
|
|
|
|
|
|
def test_cancel_during_a_clone_lands_cancelled_with_a_free_loop(
|
|
sync_client: TestClient, monkeypatch: pytest.MonkeyPatch, db: Session, tmp_path: Path
|
|
) -> None:
|
|
"""Phase 134's cooperative cancel, re-pinned under ``to_thread``
|
|
(phase 179 task 02): a cancel registered mid-clone lands the
|
|
``cancelled`` TERMINAL without waiting for the git worker.
|
|
|
|
``POST /api/sync/cancel`` is answered promptly (202, < 1.5 s), the
|
|
run's await on the git worker is interrupted so the terminal lands
|
|
well BEFORE the abandoned clone's 3 s sleep would have ended (the
|
|
2 s poll deadline below is inside that sleep), and the terminal
|
|
keeps the phase-134 shape — ``error`` null, ``detail`` empty, no
|
|
error copy for the UI. What does NOT change: the git worker itself
|
|
is not interruptible, it finishes on its own — and the import that
|
|
would have consumed its result never runs (no half-cancelled
|
|
index)."""
|
|
_, slow, fake_import = _install(monkeypatch, tmp_path)
|
|
_login(sync_client)
|
|
thread, _posted = _trigger_from_side_thread(sync_client)
|
|
time.sleep(0.2)
|
|
assert slow.started.wait(10.0), "the run never reached the clone step"
|
|
|
|
t0 = time.monotonic()
|
|
r = sync_client.post("/api/sync/cancel")
|
|
cancel_elapsed = time.monotonic() - t0
|
|
assert r.status_code == 202, f"cancel not accepted: {r.status_code} {r.text}"
|
|
assert cancel_elapsed < PROBE_CEILING, (
|
|
f"the cancel request itself took {cancel_elapsed:.3f}s — the loop is "
|
|
"still parked by the git op, so the UI cannot even ask to stop a sync"
|
|
)
|
|
|
|
# The terminal lands inside the still-running clone sleep (< 3 s of
|
|
# it remains here): the loop is free and the run was unblocked at
|
|
# its await, it did not have to wait for the git worker.
|
|
body = _poll(sync_client, "cancelled", timeout=2.0)
|
|
assert body["error"] is None
|
|
assert body["detail"] == {}
|
|
assert slow.finished_at is None, (
|
|
"the cancelled terminal waited for the git worker — the run is "
|
|
"still parked behind the blocking subprocess"
|
|
)
|
|
|
|
# And the abandoned clone's import never ran: the run stopped at the
|
|
# cancel, it did not resume the pipeline with a late result.
|
|
assert fake_import.sources == []
|
|
thread.join(timeout=15.0)
|