phase: 186_git_log_streaming_dates
## Final report — phase 186 `git_log_streaming_dates`
**State found:** all three task files were already implemented and in `.agents/phases/complete/186_git_log_streaming_dates/`, so this run was the final verification + documentation pass.
### Verification (all green)
| Gate | Result |
|---|---|
| `pytest --cov=app --cov-report=term-missing` | **4531 passed, exit 0** · coverage `TOTAL 6872 stmts → 99%` (gate >90%) |
| `tests/e2e/test_git_log_stream_dates.py -v --no-cov` (isolation) | **5 passed** |
| `ruff check .` | All checks passed |
| `pyright` | 0 errors |
Implementation shape confirmed against the phase contracts: `_parse_commit_dates(str | Iterable[str])` (existing string pins untouched — only 3 non-test lines removed from `test_git_sync.py`), `stream_git_lines` (`Popen` + daemon stderr drain + per-line stdout + terminate-on-abandon, `run_git`-shaped `GitSyncError`), `file_commit_dates` on the stream with byte-identical dates and the fail-soft funnel unchanged, `async_sync` propagating the `to_thread` errors to the existing `except`. A11 holds: two `subprocess.` sites, both in `scripts/git_sync.py`, both off-loop.
### Documentation-consistency pass
Verified (clean): all ~100 `BOR_*` README defaults against a bare `Settings()` (the local `.env` produced false positives — none real), `.env.example` completeness, every module/route/page/test path referenced, `compose.yaml`/`Containerfile`/`entrypoint.sh` claims, E2E port conventions (8901 / 8123), palette count (17), chip cap (90), token format, payload limits, retrieval battery + audit commands.
Fixed (both files, prose only):
- **Page-naming drift** — README/AGENTS called the sync/catalog page "the Sources page" in 5 places, contradicting the README's own convention (and `frontend/index.html`): the **Sync sources** button and the document catalogue are the **RAG** page (`/sources.html`); "Sources" is `/git-sources.html`. Now `RAG page (/sources.html)` in README:186, 376, 418, 682, 713, 745, 1006, 1057 and AGENTS:19, 38, 183.
- **Phase-186 AST-pin wording** — "fails if a third spawn appears anywhere in `app/` or `scripts/`" overstated it (the pin *enumerates* the spawns, including the non-git Valkey probe in `app/core/caching.py`); rewritten to describe the enumeration.
- Moved `00_phase.md` into `complete/186_git_log_streaming_dates/` (AGENTS rule 2 moves the whole directory); `todo/` now starts at 187.
⚠️ **One mistake to disclose:** while tidying line wraps I ran `git checkout README.md`, which discarded task 03's uncommitted phase-186 README bullet. I restored it verbatim from the full `git diff` captured earlier in this session (plus the two corrections above) and re-verified the section renders as intended — no other README content was uncommitted, and AGENTS.md was untouched by the checkout. A blanket line-length rewrap also reflowed 4 unrelated lines; all four were restored to their exact original text (`git diff` now shows only intended changes).
Nothing was committed or staged — the working tree is left for the harness: modified `scripts/git_sync.py`, `app/api/sync.py`, `app/rag/git_sources.py`, `tests/unit/test_git_sync.py`, `tests/integration/test_git_file_dates.py`, `README.md`, `AGENTS.md`; new `tests/e2e/test_git_log_stream_dates.py`, `.agents/phases/complete/186_git_log_streaming_dates/`, `.agents/reports/186_git_log_streaming_dates/`.
This commit is contained in:
@@ -0,0 +1,831 @@
|
||||
"""Phase 186 (task 03) E2E (Playwright, mock-only): the dates the owner
|
||||
reads come through the STREAMED commit-date walk.
|
||||
|
||||
Phase 186 changed the TRANSPORT of the git date walk, nothing else:
|
||||
``file_commit_dates`` used to buffer ``git log --name-only
|
||||
--format=@@%cI`` as ONE string (346,829 lines / 15 MB for the incident
|
||||
box's litellm checkout) and hand it to a parser that materialised a
|
||||
second copy with ``splitlines()``; it now parses the pipe line by line
|
||||
through ``stream_git_lines`` (the second, documented spawn site beside
|
||||
``run_git``). This module is the owner-visible half of that promise —
|
||||
the phase-106 D2 contract (every document's date is that FILE'S
|
||||
last-commit date) re-pinned through the browser with the streaming walk
|
||||
in place, plus the two neighbours the streaming move could plausibly
|
||||
have broken: the mtime fallback and the phase-106 D1 manual-date lock.
|
||||
|
||||
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_git_log_stream_dates.py -v --no-cov
|
||||
|
||||
**Fixture repo** — a real two-commit ``file://`` repo (the
|
||||
``test_git_source_dates.py`` ``_git``/``_commit`` shape, with
|
||||
``GIT_AUTHOR_DATE``/``GIT_COMMITTER_DATE`` pinned per commit so the
|
||||
dates are exact and stable):
|
||||
|
||||
* commit A @ ``2026-01-05T12:00:00Z`` adds ``notes/old.md`` (never
|
||||
touched again), ``notes/changed.md`` and ``notes/café.md``;
|
||||
* commit B @ ``2026-03-20T12:00:00Z`` modifies ``notes/changed.md``
|
||||
ONLY — the one file whose date distinguishes "last commit" from "the
|
||||
repo tip" and from "when the sync ran";
|
||||
* both dates are MID-DAY (12:00Z) so the local calendar DAY of the
|
||||
instant is the committed day from UTC−12 to UTC+11, and the YEAR is
|
||||
2026 in every timezone on earth — the visible-text assertions only
|
||||
ever compare the two cells against EACH OTHER, every exact assertion
|
||||
rides the ``title`` / API ISO (the house locale-stable idiom, the
|
||||
``test_document_dates.py`` L455 lesson).
|
||||
|
||||
**The uncommitted file — written into the CHECKOUT.** ``notes/untracked.md``
|
||||
is seeded in the app's own checkout (``BOR_SOURCES_DIR/<repo_name(url)>``),
|
||||
NOT in the fixture repository: the sync never re-clones (``clone_or_pull``
|
||||
fetches + ``merge --ff-only`` the existing checkout, and git never touches
|
||||
an untracked file), so a file placed there survives every later sync —
|
||||
exactly the owner's "a file git has never committed" case. Because the
|
||||
first test's sync is the one that creates the checkout, the seed helper
|
||||
creates it first with a real ``git clone`` when it is still missing, so
|
||||
any single test of this module also passes standalone (``-k``). Its mtime
|
||||
is pinned with ``os.utime`` to ``2026-02-14T09:30:00Z`` — between the two
|
||||
commits, so a stored date of ``2026-02-14`` can only be the mtime and can
|
||||
never be confused with a commit date or with the run's own day. The same
|
||||
helper re-pins ``notes/café.md``'s mtime to ``2026-04-11T08:00:00Z``
|
||||
(AFTER both commits) for the quoted-path test; git re-hashes but never
|
||||
rewrites a file whose content matches, so the pin survives every sync.
|
||||
|
||||
**Non-ASCII / ``core.quotepath``-quoted paths — recorded as-is, pinned
|
||||
UNCHANGED (measured on the authoring box, git 2.51, 2026-10-16).** With
|
||||
the default ``core.quotepath=true`` a full-history ``git log
|
||||
--name-only --format=@@%cI`` prints ``notes/café.md`` as the eight-bit-
|
||||
escaped, quote-wrapped line ``"notes/caf\\303\\251.md"``, and the parser
|
||||
(whose grammar phase 186 did NOT touch — only how the bytes arrive) turns
|
||||
it into the key ``'"notes/caf/303/251.md"'``: ``line.split()`` keeps the
|
||||
quotes, ``replace("\\\\", "/")`` turns each octal backslash into a slash,
|
||||
``lstrip("/")`` cannot strip the leading ``"``. That key never matches the
|
||||
importer's ``dates_map.get(rel)``, so a non-ASCII path falls back to its
|
||||
FILE MTIME today — before and after this phase, byte-identically (the
|
||||
streaming site passes the same bytes through, and
|
||||
``test_quoted_nonascii_path_falls_back_exactly_as_before`` pins both
|
||||
halves: the mangled key IN the walk's dict, and the document showing
|
||||
its mtime instead of commit A).
|
||||
Fixing it means changing the parser's quoting semantics (e.g. ``-c
|
||||
core.quotepath=false``, or NUL-separated paths), which is a DATE change
|
||||
for every non-ASCII document already in a KB — out of scope for a
|
||||
transport phase, recorded here for a future one (LOCKED A1: this phase
|
||||
changes how the bytes arrive, never which dates the KB stores).
|
||||
|
||||
Test → contract mapping (five tests):
|
||||
|
||||
1. ``test_document_dates_are_the_last_commit_dates`` — after a real
|
||||
sync of the fixture repo, ``notes/old.md`` carries commit A
|
||||
(``2026-01-05``) and ``notes/changed.md`` carries commit B
|
||||
(``2026-03-20``) — through ``GET /api/docs`` + ``GET
|
||||
/api/documents/content`` (the per-document surface; there is no
|
||||
``GET /api/docs/{id}``), through the RAG table's ``Created`` cell
|
||||
(full ISO on the ``title``, and the two cells' visible text
|
||||
differs), and through the viewer's ``.doc-created`` badge. Neither
|
||||
date is the run's own day, and both differ from the row's
|
||||
``indexed_at`` (which IS the sync/clone day).
|
||||
2. ``test_uncommitted_file_falls_back_to_mtime`` — the file git has
|
||||
never committed is stored at its file mtime (the fail-soft contract
|
||||
reached through the streaming walk, asserted against the same
|
||||
``file_mtime_datetime``/``normalize_doc_date`` the importer uses),
|
||||
and the run reaches ``success`` with no error surface.
|
||||
3. ``test_manual_date_survives_a_resync`` — the D1 lock: set a date in
|
||||
the viewer's editor, re-sync, the manual date is untouched while the
|
||||
OTHER documents keep coming from the stream (``dates_updated=0``,
|
||||
the stream re-derived the same values, and only the manual row is
|
||||
flagged in the DB).
|
||||
4. ``test_resync_is_unchanged_and_dates_hold`` — a second sync with
|
||||
nothing changed reports everything ``unchanged`` (0 added / 0
|
||||
updated / 0 pruned) with a byte-identical date map: the stream
|
||||
re-parses, it does not drift.
|
||||
5. ``test_quoted_nonascii_path_falls_back_exactly_as_before`` — the
|
||||
UNCHANGED non-ASCII behaviour described above (module docstring),
|
||||
pinned through the stream.
|
||||
|
||||
Isolation (the house per-module pattern): a dedicated app port, the
|
||||
deterministic mock LLM (``E2E_REAL_LLM=1`` is SKIPPED — the dates come
|
||||
from git, not from the model), a dedicated ``BOR_SOURCES_DIR`` for the
|
||||
checkout, ``BOR_GIT_SOURCES=file://<fixture repo>`` as the env-fallback
|
||||
source row, and the shared E2E Postgres truncated before AND after every
|
||||
test (with a wait for any in-flight run first — the run state lives in
|
||||
the module app's memory).
|
||||
"""
|
||||
from __future__ import annotations
|
||||
|
||||
import os
|
||||
import re
|
||||
import subprocess
|
||||
import sys
|
||||
import time
|
||||
from collections.abc import Callable, Iterator
|
||||
from datetime import UTC, datetime
|
||||
from pathlib import Path
|
||||
from typing import Any
|
||||
|
||||
import httpx
|
||||
import pytest
|
||||
from playwright.sync_api import Page, expect
|
||||
from sqlalchemy import select, text
|
||||
|
||||
from app.db import SessionLocal
|
||||
from app.models import Document
|
||||
from app.rag.doc_dates import file_mtime_datetime, normalize_doc_date
|
||||
from e2e.auth_helpers import login
|
||||
from e2e.conftest import (
|
||||
ADMIN_PASSWORD,
|
||||
SESSION_SECRET,
|
||||
USE_REAL_LLM,
|
||||
_wait_http,
|
||||
)
|
||||
from scripts.git_sync import file_commit_dates
|
||||
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_git_source_dates`` pattern.
|
||||
APP_PORT = int(os.environ.get("E2E_APP_PORT_STREAMDATES", "8203"))
|
||||
APP_URL = f"http://127.0.0.1:{APP_PORT}"
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Fixture constants (deterministic — see the module docstring)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
#: The fixture repo's directory name — the source name the import records
|
||||
#: (the ``repo_name`` basename rule, phase 28) and the checkout dir name.
|
||||
REPO_NAME = "git-stream-dates"
|
||||
|
||||
OLD_DOC = "notes/old.md"
|
||||
CHANGED_DOC = "notes/changed.md"
|
||||
#: The non-ASCII path, quoted by ``core.quotepath`` in the walk (the
|
||||
#: module docstring's UNCHANGED-behaviour record).
|
||||
QUOTED_DOC = "notes/café.md"
|
||||
#: Never committed — seeded into the CHECKOUT by ``seed_checkout``.
|
||||
UNTRACKED_DOC = "notes/untracked.md"
|
||||
|
||||
#: The two controlled commit dates (both instants, mid-day: the local
|
||||
#: calendar DAY is the committed day for every timezone the CI can run
|
||||
#: in, the YEAR is stable everywhere — the ``test_document_dates.py`` L455
|
||||
#: lesson).
|
||||
COMMIT_A = "2026-01-05T12:00:00Z"
|
||||
COMMIT_B = "2026-03-20T12:00:00Z"
|
||||
|
||||
#: The same instants as stored (``%cI`` → ``datetime.fromisoformat`` →
|
||||
#: ``normalize_doc_date`` → Postgres → ``isoformat()``) — the exact ISO
|
||||
#: the API, the ``Created`` cell ``title`` and the badge ``title`` carry.
|
||||
COMMIT_A_ISO = "2026-01-05T12:00:00+00:00"
|
||||
COMMIT_B_ISO = "2026-03-20T12:00:00+00:00"
|
||||
|
||||
#: The pinned mtimes (``os.utime``, whole seconds — so the stored ISO is
|
||||
#: exact). The untracked file sits BETWEEN the two commits; the quoted
|
||||
#: file AFTER both, so a fallback date can never be mistaken for one of
|
||||
#: the commit dates above.
|
||||
UNTRACKED_MTIME = datetime(2026, 2, 14, 9, 30, tzinfo=UTC)
|
||||
UNTRACKED_MTIME_ISO = "2026-02-14T09:30:00+00:00"
|
||||
QUOTED_MTIME = datetime(2026, 4, 11, 8, 0, tzinfo=UTC)
|
||||
QUOTED_MTIME_ISO = "2026-04-11T08:00:00+00:00"
|
||||
|
||||
#: The owner's correction (the date-editor surface, phase 106 D1/D7).
|
||||
EDITED_ISO = "2021-05-05T00:00:00+00:00"
|
||||
|
||||
#: The walk's key for ``notes/café.md`` under the default
|
||||
#: ``core.quotepath=true`` — the measured, UNCHANGED mangle (module
|
||||
#: docstring): the quotes survive ``split()``, every octal backslash
|
||||
#: becomes a slash, and the leading quote survives ``lstrip("/")``.
|
||||
QUOTED_WALK_KEY = '"notes/caf/303/251.md"'
|
||||
|
||||
#: Every committed file (the checkout before ``seed_checkout`` runs).
|
||||
COMMITTED_DOCS = (OLD_DOC, CHANGED_DOC, QUOTED_DOC)
|
||||
|
||||
#: The untracked file's body (its content is irrelevant — only its
|
||||
#: existence in the working tree and its pinned mtime matter).
|
||||
UNTRACKED_BODY = (
|
||||
"# Not in git\n\nA working-tree file the repository has never committed: its "
|
||||
"only date signal is the file's own mtime.\n"
|
||||
)
|
||||
|
||||
#: "Synced HH:MM" (``sources.js`` ``fmtSyncTime``) and the idle/boot label.
|
||||
SYNCED_LABEL = re.compile(r"Synced \d{1,2}:\d{2}")
|
||||
IDLE_LABEL = re.compile(r"^Sync sources$|^Synced \d{1,2}:\d{2}$")
|
||||
|
||||
#: A real clone + mock import of three/four small markdown files settles
|
||||
#: in ~2 s; the budgets below are ~15× that (no client timeout on the run).
|
||||
RUN_SETTLE_TIMEOUT_S = 90.0
|
||||
UI_SETTLE_TIMEOUT_MS = 20_000
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# The fixture repo (module-scoped — real git, two controlled commits)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def _git(cwd: Path, *args: str, env: dict[str, str] | None = None) -> str:
|
||||
"""Run git in *cwd*; a non-zero exit fails the fixture loudly.
|
||||
|
||||
*env* overrides (``GIT_AUTHOR_DATE`` / ``GIT_COMMITTER_DATE`` — the
|
||||
phase's whole point) ride on top of a copy of ``os.environ`` so the
|
||||
fixture never mutates the test process's environment.
|
||||
"""
|
||||
full_env = dict(os.environ)
|
||||
if env:
|
||||
full_env.update(env)
|
||||
proc = subprocess.run(
|
||||
["git", *args], cwd=cwd, capture_output=True, text=True, env=full_env
|
||||
)
|
||||
if proc.returncode != 0:
|
||||
raise AssertionError(f"git {' '.join(args)} failed: {proc.stderr.strip()}")
|
||||
return proc.stdout
|
||||
|
||||
|
||||
def _commit(cwd: Path, message: str, when: str) -> None:
|
||||
"""``git add -A`` + a commit with BOTH dates pinned to *when*.
|
||||
|
||||
``file_commit_dates`` reads ``%cI`` (the COMMITTER date); the author
|
||||
date is pinned too so the fixture carries one unambiguous date per
|
||||
commit (the ``test_git_source_dates.py`` helper, verbatim in shape).
|
||||
"""
|
||||
_git(cwd, "add", "-A")
|
||||
_git(
|
||||
cwd,
|
||||
"-c", "user.email=e@x", "-c", "user.name=t",
|
||||
"-c", "commit.gpgsign=false", # the fixture commits never sign
|
||||
"commit", "-qm", message,
|
||||
env={"GIT_AUTHOR_DATE": when, "GIT_COMMITTER_DATE": when},
|
||||
)
|
||||
|
||||
|
||||
def _write(root: Path, rel: str, body: str, mtime: datetime | None = None) -> Path:
|
||||
"""Write *body* to ``root/rel`` and optionally pin its mtime."""
|
||||
path = root / rel
|
||||
path.parent.mkdir(parents=True, exist_ok=True)
|
||||
path.write_text(body, encoding="utf-8")
|
||||
if mtime is not None:
|
||||
os.utime(path, (mtime.timestamp(), mtime.timestamp()))
|
||||
return path
|
||||
|
||||
|
||||
@pytest.fixture(scope="module")
|
||||
def stream_repo(tmp_path_factory: pytest.TempPathFactory) -> Path:
|
||||
"""The real two-commit repo the sync clones over ``file://``.
|
||||
|
||||
Commit A (2026-01-05) adds the three committed notes; commit B
|
||||
(2026-03-20) touches ``notes/changed.md`` ONLY — the file whose
|
||||
stored date therefore has to be 2026-03-20 while its sibling stays
|
||||
2026-01-05 (the phase-106 D2 first-sighting-wins contract).
|
||||
"""
|
||||
root = tmp_path_factory.mktemp("bor_git_log_stream")
|
||||
repo = root / REPO_NAME
|
||||
_write(repo, OLD_DOC, "# Old note\n\nWritten once in January, never touched again.\n")
|
||||
_write(repo, CHANGED_DOC, "# Changed note\n\nFirst version (January).\n")
|
||||
_write(repo, QUOTED_DOC, "# Café note\n\nA path with a non-ASCII character.\n")
|
||||
_git(repo, "init", "-q", "-b", "main")
|
||||
_commit(repo, "january notes", COMMIT_A)
|
||||
_write(repo, CHANGED_DOC, "# Changed note\n\nSecond version (March) — the last commit.\n")
|
||||
_commit(repo, "march edit", COMMIT_B)
|
||||
assert (repo / ".git").is_dir()
|
||||
assert _git(repo, "rev-list", "--count", "HEAD").strip() == "2"
|
||||
return repo
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# The app under test (module-scoped env, the test_git_source_dates shape)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def _sources_dir(stream_repo: Path) -> Path:
|
||||
"""The module's dedicated ``BOR_SOURCES_DIR`` — ONE definition for
|
||||
the app fixture and the checkout path, so the two cannot drift."""
|
||||
return stream_repo.parent / "checkouts"
|
||||
|
||||
|
||||
@pytest.fixture(scope="module")
|
||||
def app_server(mock_llm: int, stream_repo: Path) -> Iterator[str]:
|
||||
"""The real app under test: one ``file://`` git source (the
|
||||
env-fallback row) checked out under its own fresh dir."""
|
||||
if USE_REAL_LLM:
|
||||
pytest.skip(
|
||||
"mock-only suite — the dates come from real git and the importer, "
|
||||
"not from a chat answer (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_llm}/v1"
|
||||
# Mock-calibrated threshold (conftest pattern) — no chat turn is sent
|
||||
# here, but the app boots with the same env shape.
|
||||
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 subject: one real local repo, its own checkout home.
|
||||
env["BOR_GIT_SOURCES"] = f"file://{stream_repo}"
|
||||
env["BOR_SOURCES_DIR"] = str(_sources_dir(stream_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(app_server: str, stream_repo: Path) -> Path:
|
||||
"""Where the run clones to — ``BOR_SOURCES_DIR/<repo_name(url)>``,
|
||||
resolved with the PRODUCTION helper so this module cannot drift from
|
||||
the phase-28 rule (the ``test_sync_git_freeze.py`` shape)."""
|
||||
assert app_server # the app must be up — its env is what owns the path
|
||||
return _sources_dir(stream_repo) / repo_name(f"file://{stream_repo}")
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Isolation + the checkout seeding helper
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
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), and every test's
|
||||
sync counts must be its own."""
|
||||
with SessionLocal() as db:
|
||||
db.execute(
|
||||
text(
|
||||
"TRUNCATE chunks, documents, query_log, kb_overview, "
|
||||
"git_sources, sources_meta, folder_summaries"
|
||||
)
|
||||
)
|
||||
db.commit() # without the commit the TRUNCATE rolls back (house pattern)
|
||||
|
||||
|
||||
def _wait_sync_idle(app_url: str, timeout_s: float = RUN_SETTLE_TIMEOUT_S) -> None:
|
||||
"""No run may leak across a test boundary (the run state lives in the
|
||||
module app's memory): wait for a non-running status BEFORE truncating.
|
||||
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:
|
||||
if client.get("/api/sync/status").json()["state"] != "running":
|
||||
return
|
||||
time.sleep(0.25)
|
||||
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, before AND after (the phase-179 pattern)."""
|
||||
_wait_sync_idle(app_url)
|
||||
_truncate_all()
|
||||
yield
|
||||
_truncate_all()
|
||||
|
||||
|
||||
@pytest.fixture(scope="module")
|
||||
def seed_checkout(
|
||||
checkout: Path, stream_repo: Path
|
||||
) -> Callable[[], Path]:
|
||||
"""``seed_checkout()`` → the seeded checkout, ready for a sync.
|
||||
|
||||
Writes ``notes/untracked.md`` into the CHECKOUT (never into the
|
||||
fixture repo — a clone does not carry untracked files, and the sync
|
||||
only ever fetch/ff-merges the existing checkout, so the file
|
||||
survives every later sync), pins its mtime, and re-pins the quoted
|
||||
file's mtime. When the checkout does not exist yet (a single test run
|
||||
with ``-k``, before the app has cloned anything) it is created first
|
||||
with a real ``git clone`` — the same working tree the sync would
|
||||
have produced.
|
||||
"""
|
||||
|
||||
def _seed() -> Path:
|
||||
if not checkout.exists():
|
||||
checkout.parent.mkdir(parents=True, exist_ok=True)
|
||||
_git(checkout.parent, "clone", "-q", f"file://{stream_repo}", str(checkout))
|
||||
_write(checkout, UNTRACKED_DOC, UNTRACKED_BODY, UNTRACKED_MTIME)
|
||||
_write(
|
||||
checkout,
|
||||
QUOTED_DOC,
|
||||
(stream_repo / QUOTED_DOC).read_text(encoding="utf-8"),
|
||||
QUOTED_MTIME,
|
||||
)
|
||||
# The seed is the fixture: a broken checkout fails here, loudly,
|
||||
# instead of turning a date assertion into a mystery.
|
||||
assert (checkout / UNTRACKED_DOC).is_file()
|
||||
assert file_mtime_datetime(checkout / UNTRACKED_DOC) == UNTRACKED_MTIME
|
||||
return checkout
|
||||
|
||||
return _seed
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Helpers
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def _status(page: Page) -> dict[str, Any]:
|
||||
r = page.request.get(f"{APP_URL}/api/sync/status")
|
||||
assert r.status == 200, r.text
|
||||
return r.json()
|
||||
|
||||
|
||||
def _wait_status_terminal(
|
||||
page: Page, timeout_s: float = RUN_SETTLE_TIMEOUT_S
|
||||
) -> dict[str, Any]:
|
||||
"""Poll until the run leaves ``running`` (the deterministic layer
|
||||
under the UI's own 2 s poll)."""
|
||||
deadline = time.monotonic() + timeout_s
|
||||
body: dict[str, Any] = {}
|
||||
while time.monotonic() < deadline:
|
||||
body = _status(page)
|
||||
if body["state"] != "running":
|
||||
return body
|
||||
time.sleep(0.1)
|
||||
raise AssertionError(f"the sync never left `running`: {body}")
|
||||
|
||||
|
||||
def _run_sync(page: Page, expected_line: str | re.Pattern[str]) -> dict[str, Any]:
|
||||
"""The owner's click, end to end: Sources page → "Sync sources" →
|
||||
the live "Syncing…" state → the terminal ``success`` (status API) →
|
||||
the settled UI (retry-ready button, the result counts line, no error
|
||||
surface). Returns the run's ``detail`` counts.
|
||||
|
||||
The caller is already logged in (``login`` lands on /sources.html).
|
||||
"""
|
||||
btn = page.locator("#sync-btn")
|
||||
expect(btn).to_be_visible()
|
||||
expect(btn).to_be_enabled()
|
||||
expect(page.locator("#sync-label")).to_have_text(IDLE_LABEL)
|
||||
|
||||
btn.click()
|
||||
expect(btn).to_be_disabled()
|
||||
expect(page.locator("#sync-label")).to_have_text("Syncing…")
|
||||
|
||||
body = _wait_status_terminal(page)
|
||||
assert body["state"] == "success", body
|
||||
assert body["error"] is None, body
|
||||
|
||||
expect(page.locator("#sync-label")).to_have_text(SYNCED_LABEL, timeout=UI_SETTLE_TIMEOUT_MS)
|
||||
expect(btn).to_be_enabled() # never stale at the terminal state
|
||||
expect(page.locator("#sync-error-banner")).to_be_hidden()
|
||||
expect(page.locator("#sync-progress-text")).to_have_text(
|
||||
expected_line, timeout=UI_SETTLE_TIMEOUT_MS
|
||||
)
|
||||
return dict(body["detail"] or {})
|
||||
|
||||
|
||||
def _docs(page: Page) -> dict[str, dict[str, Any]]:
|
||||
"""``GET /api/docs`` keyed by path (the browser's admin cookie rides)."""
|
||||
r = page.request.get(f"{APP_URL}/api/docs")
|
||||
assert r.status == 200, r.text
|
||||
return {d["path"]: d for d in r.json()["documents"]}
|
||||
|
||||
|
||||
def _content(page: Page, path: str) -> dict[str, Any]:
|
||||
"""``GET /api/documents/content`` — the per-document surface (there is
|
||||
no ``GET /api/docs/{id}``; this is the route the viewer itself uses)."""
|
||||
r = page.request.get(
|
||||
f"{APP_URL}/api/documents/content",
|
||||
params={"source": REPO_NAME, "path": path},
|
||||
)
|
||||
assert r.status == 200, r.text
|
||||
return r.json()
|
||||
|
||||
|
||||
def _date_map(docs: dict[str, dict[str, Any]]) -> dict[str, str]:
|
||||
return {p: d["created_at"] for p, d in docs.items()}
|
||||
|
||||
|
||||
def _drill_to_notes(page: Page, rows: int) -> None:
|
||||
"""Top level → the source → ``notes`` (the two real clicks) — and the
|
||||
file table holds exactly *rows* documents (the whole checkout, the
|
||||
``.git`` directory excluded by the hidden-path rule)."""
|
||||
page.locator("#folders-tbody .folder-link").first.wait_for(state="visible")
|
||||
page.click(f'#folders-tbody a.folder-link:text-is("{REPO_NAME}")')
|
||||
page.click('#folders-tbody a.folder-link:text-is("notes")')
|
||||
expect(page.locator("#docs-tbody tr")).to_have_count(rows)
|
||||
|
||||
|
||||
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()
|
||||
|
||||
|
||||
def _created_cell(page: Page, path: str) -> Any:
|
||||
"""The row's ``Created`` cell (the column between Chunks and Indexed,
|
||||
phase 106 D8)."""
|
||||
row = page.locator("#docs-tbody tr", has_text=path)
|
||||
expect(row).to_have_count(1)
|
||||
return row.locator("td:nth-child(5)")
|
||||
|
||||
|
||||
def _open_doc(page: Page, path: str) -> None:
|
||||
"""Open the same-page viewer modal for one row (phase 26)."""
|
||||
row = page.locator("#docs-tbody tr", has_text=path)
|
||||
expect(row).to_have_count(1)
|
||||
row.locator("td:nth-child(2) a.doc-link").click()
|
||||
expect(page.locator(".doc-modal")).to_be_visible()
|
||||
expect(page.locator("#doc-modal-meta .doc-created")).to_have_count(1)
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# 1. The dates the owner reads ARE the per-file last-commit dates
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_document_dates_are_the_last_commit_dates(
|
||||
page: Page, app_url: str, db_ready: None
|
||||
) -> None:
|
||||
"""THE phase-106 D2 contract through the streaming walk: the file
|
||||
nobody touched again keeps commit A (2026-01-05) and the file commit
|
||||
B modified carries commit B (2026-03-20) — not the sync day, not the
|
||||
clone day, not the repo tip for both. API, table cell and viewer
|
||||
badge all three, with the exact ISO on every ``title``."""
|
||||
page.set_default_timeout(30_000)
|
||||
login(page, app_url) # lands on /sources.html
|
||||
run_day = datetime.now(UTC).date().isoformat()
|
||||
|
||||
detail = _run_sync(page, f"{len(COMMITTED_DOCS)} added")
|
||||
assert detail["added"] == len(COMMITTED_DOCS)
|
||||
assert detail["errors"] == 0
|
||||
|
||||
docs = _docs(page)
|
||||
assert set(docs) == set(COMMITTED_DOCS) # the checkout, nothing else
|
||||
assert docs[OLD_DOC]["created_at"] == COMMIT_A_ISO
|
||||
assert docs[CHANGED_DOC]["created_at"] == COMMIT_B_ISO
|
||||
# The two files' dates DIFFER — a walk that lost the per-file
|
||||
# distinction (a uniform tip/clone date) cannot pass.
|
||||
assert docs[OLD_DOC]["created_at"] != docs[CHANGED_DOC]["created_at"]
|
||||
for path in (OLD_DOC, CHANGED_DOC):
|
||||
created = docs[path]["created_at"]
|
||||
# Not the run's own day, and strictly older than the row's own
|
||||
# ``indexed_at`` (which IS the clone/sync day — the two concepts
|
||||
# do not blur).
|
||||
assert created[:10] != run_day, f"{path} stored the sync day: {created}"
|
||||
assert created < docs[path]["indexed_at"], (path, created, docs[path]["indexed_at"])
|
||||
|
||||
# The per-document surface the viewer itself reads.
|
||||
assert _content(page, OLD_DOC)["created_at"] == COMMIT_A_ISO
|
||||
assert _content(page, CHANGED_DOC)["created_at"] == COMMIT_B_ISO
|
||||
|
||||
# The RAG table: the full ISO on the ``Created`` cell's ``title``,
|
||||
# and the two cells' visible text differs (the owner's "both docs
|
||||
# show the same date" complaint, UI side).
|
||||
_drill_to_notes(page, len(COMMITTED_DOCS))
|
||||
old_cell = _created_cell(page, OLD_DOC)
|
||||
changed_cell = _created_cell(page, CHANGED_DOC)
|
||||
assert old_cell.get_attribute("title", timeout=15_000) == COMMIT_A_ISO
|
||||
assert changed_cell.get_attribute("title", timeout=15_000) == COMMIT_B_ISO
|
||||
old_text = (old_cell.text_content() or "").strip()
|
||||
changed_text = (changed_cell.text_content() or "").strip()
|
||||
assert old_text and changed_text and old_text != changed_text, (
|
||||
f"the two Created cells are identical: {old_text!r}"
|
||||
)
|
||||
|
||||
# The viewer's Created badge (the date at the top of the clicked
|
||||
# document) carries the same raw ISO on its title.
|
||||
_open_doc(page, CHANGED_DOC)
|
||||
badge = page.locator("#doc-modal-meta .doc-created")
|
||||
expect(badge).to_have_text(re.compile(r"^Created \S"))
|
||||
assert badge.get_attribute("title", timeout=15_000) == COMMIT_B_ISO
|
||||
page.keyboard.press("Escape")
|
||||
expect(page.locator(".doc-modal")).to_be_hidden()
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# 2. The file git has never committed: the mtime fallback, through the
|
||||
# streaming walk (the fail-soft contract that must not change)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_uncommitted_file_falls_back_to_mtime(
|
||||
page: Page, app_url: str, seed_checkout: Callable[[], Path], db_ready: None
|
||||
) -> None:
|
||||
"""``notes/untracked.md`` is in the working tree and in NO commit, so
|
||||
the walk has no entry for it and the importer's ``file_mtime_datetime``
|
||||
fallback applies — the stored date equals the file's own mtime
|
||||
(2026-02-14, neither commit's date), the run reaches ``success``, and
|
||||
no error surface appears (a date-less file is not a failure)."""
|
||||
page.set_default_timeout(30_000)
|
||||
checkout_dir = seed_checkout()
|
||||
login(page, app_url)
|
||||
|
||||
detail = _run_sync(page, f"{len(COMMITTED_DOCS) + 1} added")
|
||||
assert detail["added"] == len(COMMITTED_DOCS) + 1
|
||||
assert detail["errors"] == 0
|
||||
|
||||
docs = _docs(page)
|
||||
assert UNTRACKED_DOC in docs
|
||||
# The exact mtime, computed the way the importer computes it (the
|
||||
# D2 fallback through the streaming path — no dict entry, so
|
||||
# ``normalize_doc_date(file mtime)`` is the whole story).
|
||||
on_disk = normalize_doc_date(file_mtime_datetime(checkout_dir / UNTRACKED_DOC))
|
||||
assert on_disk.isoformat() == UNTRACKED_MTIME_ISO
|
||||
assert docs[UNTRACKED_DOC]["created_at"] == UNTRACKED_MTIME_ISO
|
||||
assert docs[UNTRACKED_DOC]["created_at"] not in (COMMIT_A_ISO, COMMIT_B_ISO)
|
||||
|
||||
# The owner-visible half: the table cell and the viewer badge.
|
||||
_drill_to_notes(page, len(COMMITTED_DOCS) + 1)
|
||||
cell = _created_cell(page, UNTRACKED_DOC)
|
||||
assert cell.get_attribute("title", timeout=15_000) == UNTRACKED_MTIME_ISO
|
||||
_open_doc(page, UNTRACKED_DOC)
|
||||
assert page.locator("#doc-modal-meta .doc-created").get_attribute(
|
||||
"title", timeout=15_000
|
||||
) == UNTRACKED_MTIME_ISO
|
||||
page.keyboard.press("Escape")
|
||||
|
||||
# And the run itself stayed clean (the fail-soft contract is about
|
||||
# the RESULT: a date walk with no entry never breaks a sync).
|
||||
body = _status(page)
|
||||
assert body["state"] == "success" and body["error"] is None
|
||||
expect(page.locator("#sync-error-banner")).to_be_hidden()
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# 3. The phase-106 D1 lock: the owner's correction survives a re-sync
|
||||
# while the other documents keep coming from the stream
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_manual_date_survives_a_resync(
|
||||
page: Page, app_url: str, seed_checkout: Callable[[], Path], db_ready: None
|
||||
) -> None:
|
||||
"""Set a date in the viewer's editor → Save (the badge re-renders
|
||||
from the RESPONSE) → re-sync: the manual date is untouched, the
|
||||
``created_at_manual`` flag is the only flag in the source, and the
|
||||
OTHER documents still read their dates off the stream (the run
|
||||
reports no date drift at all — ``dates_updated=0`` with commit B
|
||||
still on ``notes/changed.md``)."""
|
||||
page.set_default_timeout(30_000)
|
||||
seed_checkout()
|
||||
login(page, app_url)
|
||||
_run_sync(page, f"{len(COMMITTED_DOCS) + 1} added")
|
||||
|
||||
# --- SET the correction through the real UI --------------------------
|
||||
_drill_to_notes(page, len(COMMITTED_DOCS) + 1)
|
||||
_open_doc(page, OLD_DOC)
|
||||
edit = page.locator("#doc-modal .doc-date-edit")
|
||||
expect(edit).to_be_visible(timeout=15_000)
|
||||
edit.click()
|
||||
page.fill("#doc-modal .doc-date-input", "2021-05-05")
|
||||
page.click("#doc-modal .doc-date-save")
|
||||
expect(page.locator("#doc-modal .doc-date-status")).to_have_text(
|
||||
f"Date saved for {REPO_NAME}/{OLD_DOC}."
|
||||
)
|
||||
# The badge re-renders from the server's normalized value, never the
|
||||
# raw input string.
|
||||
expect(page.locator("#doc-modal-meta .doc-created")).to_have_attribute(
|
||||
"title", EDITED_ISO
|
||||
)
|
||||
expect(page.locator("#doc-modal .doc-date-editor")).to_have_count(0, timeout=8_000)
|
||||
page.keyboard.press("Escape")
|
||||
expect(page.locator(".doc-modal")).to_be_hidden()
|
||||
assert _docs(page)[OLD_DOC]["created_at"] == EDITED_ISO
|
||||
|
||||
# --- RE-SYNC ---------------------------------------------------------
|
||||
_go_top(page)
|
||||
detail = _run_sync(page, f"0 added · {len(COMMITTED_DOCS) + 1} unchanged")
|
||||
assert detail["added"] == 0 and detail["updated"] == 0
|
||||
assert detail["pruned"] == 0
|
||||
# Nothing moved: the stream re-derived the SAME dates for the sync-managed
|
||||
# rows, and the manual row is skipped entirely (D1) — so a re-sync is a
|
||||
# no-op on the date column, not a re-stamp.
|
||||
assert detail["dates_updated"] == 0, detail
|
||||
|
||||
docs = _docs(page)
|
||||
assert docs[OLD_DOC]["created_at"] == EDITED_ISO # the owner's date SURVIVES
|
||||
# The neighbours keep coming from the stream, unchanged.
|
||||
assert docs[CHANGED_DOC]["created_at"] == COMMIT_B_ISO
|
||||
assert docs[UNTRACKED_DOC]["created_at"] == UNTRACKED_MTIME_ISO
|
||||
|
||||
with SessionLocal() as db:
|
||||
rows = db.execute(
|
||||
select(Document.path, Document.created_at_manual).where(
|
||||
Document.source == REPO_NAME
|
||||
)
|
||||
).all()
|
||||
manual = {path for path, flag in rows if flag}
|
||||
assert manual == {OLD_DOC}, rows
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# 4. An unchanged re-sync: everything ``unchanged``, dates hold exactly
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_resync_is_unchanged_and_dates_hold(
|
||||
page: Page, app_url: str, seed_checkout: Callable[[], Path], db_ready: None
|
||||
) -> None:
|
||||
"""Two syncs, nothing changed in between: the second reports every
|
||||
file ``unchanged`` (0 added / 0 updated / 0 pruned / 0 dates_updated)
|
||||
and the date map is BYTE-identical — the stream re-parses the same
|
||||
``git log`` to the same dict, it does not drift (the phase-186
|
||||
"same dates, cheaper transport" claim, owner-visible)."""
|
||||
page.set_default_timeout(30_000)
|
||||
seed_checkout()
|
||||
login(page, app_url)
|
||||
|
||||
first = _run_sync(page, f"{len(COMMITTED_DOCS) + 1} added")
|
||||
assert first["added"] == len(COMMITTED_DOCS) + 1
|
||||
before = _date_map(_docs(page))
|
||||
assert before[CHANGED_DOC] == COMMIT_B_ISO # the map is meaningful first
|
||||
|
||||
_go_top(page)
|
||||
second = _run_sync(page, f"0 added · {len(COMMITTED_DOCS) + 1} unchanged")
|
||||
assert second["added"] == 0
|
||||
assert second["updated"] == 0
|
||||
assert second["unchanged"] == len(COMMITTED_DOCS) + 1
|
||||
assert second["pruned"] == 0
|
||||
assert second["dates_updated"] == 0, second
|
||||
|
||||
after = _date_map(_docs(page))
|
||||
assert after == before, f"the dates drifted across an unchanged re-sync:\n{before}\n{after}"
|
||||
|
||||
# And the cells agree with the API (the owner reads the table, not
|
||||
# the JSON): every row's title still equals the stored ISO.
|
||||
_drill_to_notes(page, len(COMMITTED_DOCS) + 1)
|
||||
for path in (*COMMITTED_DOCS, UNTRACKED_DOC):
|
||||
assert _created_cell(page, path).get_attribute("title", timeout=15_000) == after[path]
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# 5. The non-ASCII path: the quoted-key behaviour is UNCHANGED by the
|
||||
# streaming move (module docstring's measured record)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_quoted_nonascii_path_falls_back_exactly_as_before(
|
||||
page: Page,
|
||||
app_url: str,
|
||||
seed_checkout: Callable[[], Path],
|
||||
checkout: Path,
|
||||
db_ready: None,
|
||||
) -> None:
|
||||
"""What the walk does TODAY with a ``core.quotepath``-quoted path,
|
||||
pinned as UNCHANGED behaviour (the module docstring carries the
|
||||
measurement): the walk's dict carries the mangled key
|
||||
``'"notes/caf/303/251.md"'`` — never ``notes/café.md`` — so the
|
||||
importer's lookup misses and the document shows its file mtime
|
||||
instead of commit A. The phase-186 change is transport only, so both
|
||||
halves (the mangled key and the mtime result) must be exactly what
|
||||
the buffered walk produced; this is the pin that says so, NOT a
|
||||
statement that the behaviour is correct (fixing the quoting grammar
|
||||
changes stored dates for every non-ASCII document — LOCKED A1,
|
||||
a future phase's call)."""
|
||||
page.set_default_timeout(30_000)
|
||||
checkout_dir = seed_checkout()
|
||||
assert checkout == checkout_dir
|
||||
|
||||
# The walk itself (the deterministic layer): same bytes in, same
|
||||
# mangled keys out, and NO entry for the real path.
|
||||
walk = file_commit_dates(checkout_dir)
|
||||
assert walk[OLD_DOC].isoformat() == COMMIT_A_ISO # the stream still works here
|
||||
assert QUOTED_DOC not in walk, sorted(walk)
|
||||
assert walk[QUOTED_WALK_KEY].isoformat() == COMMIT_A_ISO, sorted(walk)
|
||||
|
||||
login(page, app_url)
|
||||
detail = _run_sync(page, f"{len(COMMITTED_DOCS) + 1} added")
|
||||
assert detail["errors"] == 0
|
||||
|
||||
docs = _docs(page)
|
||||
assert QUOTED_DOC in docs
|
||||
created = docs[QUOTED_DOC]["created_at"]
|
||||
# The importer looked up the REAL path, found nothing, and fell back.
|
||||
assert created != COMMIT_A_ISO, (
|
||||
"the quoted path suddenly resolved to its commit date — the parser's "
|
||||
"quoting grammar changed, which is a DATE change for every non-ASCII "
|
||||
"document already in a KB (LOCKED A1: this phase ships no such change)"
|
||||
)
|
||||
assert created == normalize_doc_date(
|
||||
file_mtime_datetime(checkout_dir / QUOTED_DOC)
|
||||
).isoformat()
|
||||
assert created == QUOTED_MTIME_ISO
|
||||
|
||||
# The run stayed clean and the owner sees the date in both surfaces.
|
||||
body = _status(page)
|
||||
assert body["state"] == "success" and body["error"] is None
|
||||
expect(page.locator("#sync-error-banner")).to_be_hidden()
|
||||
_drill_to_notes(page, len(COMMITTED_DOCS) + 1)
|
||||
assert _created_cell(page, QUOTED_DOC).get_attribute(
|
||||
"title", timeout=15_000
|
||||
) == QUOTED_MTIME_ISO
|
||||
@@ -26,6 +26,17 @@ the VERIFIED checkout behavior (phase 107):
|
||||
``{}`` — a date walk must never break a sync (the importer, task
|
||||
04, falls back to file mtimes).
|
||||
|
||||
Phase 186 adds the two pins for the walk moving off ``run_git`` onto
|
||||
the streaming site :func:`scripts.git_sync.stream_git_lines` (the
|
||||
incident of 2026-10-15: a full-history ``git log`` held as ONE string
|
||||
plus the parser's ``splitlines()`` copy, tens of MB of transient peak
|
||||
per source): ``test_streamed_walk_returns_the_buffered_dates`` proves
|
||||
the streamed dict EQUALS the buffered one on the four cases that
|
||||
matter (commit-1-only file, commit-2-modified file, subdirectory file,
|
||||
never-committed file → the mtime fallback), and
|
||||
``test_file_commit_dates_fail_soft_unchanged`` pins that both fail-soft
|
||||
arms and their exact warning lines survived the move.
|
||||
|
||||
DB-free by design: ``file_commit_dates`` takes a path, no session.
|
||||
Skipped (not failed) on a machine without the git CLI (the
|
||||
``test_doc_drafts_api.py`` guard).
|
||||
@@ -212,12 +223,13 @@ def test_git_error_fails_soft(
|
||||
) -> None:
|
||||
"""(c) a ``GitSyncError`` from the walk (git missing/failed) →
|
||||
``{}`` + a logged warning naming the fallback — the fail-soft
|
||||
contract (pinned)."""
|
||||
contract (pinned). Phase 186 moved the walk off ``run_git`` onto
|
||||
:func:`stream_git_lines`, so that is the site the stub replaces."""
|
||||
|
||||
def boom(argv: list[str], cwd: Path) -> str:
|
||||
raise GitSyncError("git log failed (exit 128): fatal: bad object")
|
||||
|
||||
monkeypatch.setattr("scripts.git_sync.run_git", boom)
|
||||
monkeypatch.setattr("scripts.git_sync.stream_git_lines", boom)
|
||||
with caplog.at_level("WARNING"):
|
||||
assert file_commit_dates(scratch_repo) == {}
|
||||
assert any("file_commit_dates" in record.message for record in caplog.records)
|
||||
@@ -230,12 +242,88 @@ def test_malformed_log_output_fails_soft(
|
||||
read) → ``{}`` (fail-soft) — the walk is all-or-nothing: a
|
||||
partially parsed date map would be worse than none."""
|
||||
monkeypatch.setattr(
|
||||
"scripts.git_sync.run_git",
|
||||
lambda argv, cwd: "@@not-a-date\nb.md\n",
|
||||
"scripts.git_sync.stream_git_lines",
|
||||
lambda argv, cwd: iter(["@@not-a-date", "b.md"]),
|
||||
)
|
||||
assert file_commit_dates(scratch_repo) == {}
|
||||
|
||||
|
||||
# --- phase 186: the streamed walk returns what the buffered one did ---------
|
||||
|
||||
|
||||
def test_streamed_walk_returns_the_buffered_dates(
|
||||
scratch_repo: Path, tmp_path: Path
|
||||
) -> None:
|
||||
"""Phase 186 D4 — DATE PARITY. The same checkout is walked twice:
|
||||
through the shipped streaming path (``file_commit_dates``) and
|
||||
through the pre-phase buffered path (``run_git`` → one ``str`` →
|
||||
``_parse_commit_dates``). The two dicts are EQUAL, and they carry
|
||||
the four cases the phase names:
|
||||
|
||||
(i) a file only in commit 1 (``a.md``) → commit 1's date;
|
||||
(ii) a file modified in commit 2 (``b.md``) → commit 2's date, NOT
|
||||
commit 1's — first-sighting-wins over a newest-first walk;
|
||||
(iii) a file in a subdirectory (``docs/deep.md``) → its own
|
||||
last-commit date, keyed repo-relative with ``/``;
|
||||
(iv) a file in the working tree that git never committed → no entry
|
||||
at all, so the importer's mtime fallback applies (asserted on
|
||||
the LOOKUP here — the resulting date is the importer's
|
||||
contract, tested in ``test_importer_dates.py``)."""
|
||||
dest = tmp_path / "clone"
|
||||
clone_or_pull(str(scratch_repo), dest)
|
||||
(dest / "never-committed.md").write_text("# untracked\n", encoding="utf-8")
|
||||
|
||||
streamed = file_commit_dates(dest)
|
||||
buffered = _parse_commit_dates(
|
||||
run_git(["git", "log", "--name-only", "--format=@@%cI"], cwd=dest)
|
||||
)
|
||||
|
||||
assert streamed == buffered
|
||||
assert streamed["a.md"] == DATE_A # (i) only in commit 1
|
||||
assert streamed["b.md"] == DATE_B # (ii) modified in commit 2
|
||||
assert streamed["docs/deep.md"] == DATE_A # (iii) subdirectory
|
||||
assert "never-committed.md" not in streamed # (iv) mtime fallback
|
||||
assert streamed.get("never-committed.md") is None
|
||||
|
||||
|
||||
def test_file_commit_dates_fail_soft_unchanged(
|
||||
tmp_path: Path, caplog: pytest.LogCaptureFixture
|
||||
) -> None:
|
||||
"""Phase 186 D3: both fail-soft arms and their EXACT warning lines
|
||||
survive the switch to streaming — (a) a checkout that is not a
|
||||
directory (git is never invoked), (b) a directory that is not a
|
||||
repository (the stream raises the ``run_git``-shaped
|
||||
``GitSyncError`` mid-call). Both return ``{}``; neither raises.
|
||||
The wording is byte-pinned because the ops dashboards grep it."""
|
||||
missing = tmp_path / "gone"
|
||||
not_a_dir = tmp_path / "a-file"
|
||||
not_a_dir.write_text("# not a directory\n", encoding="utf-8")
|
||||
plain = tmp_path / "notarepo"
|
||||
plain.mkdir()
|
||||
(plain / "a.md").write_text("# A\n", encoding="utf-8")
|
||||
|
||||
with caplog.at_level("WARNING", logger="scripts.git_sync"):
|
||||
assert file_commit_dates(missing) == {}
|
||||
assert file_commit_dates(not_a_dir) == {}
|
||||
assert file_commit_dates(plain) == {}
|
||||
|
||||
messages = [r.getMessage() for r in caplog.records if r.name == "scripts.git_sync"]
|
||||
assert len(messages) == 3
|
||||
assert messages[0] == (
|
||||
f"file_commit_dates: {missing} is not a directory — no git dates "
|
||||
"(the importer will fall back to file mtimes)"
|
||||
)
|
||||
assert messages[1] == (
|
||||
f"file_commit_dates: {not_a_dir} is not a directory — no git dates "
|
||||
"(the importer will fall back to file mtimes)"
|
||||
)
|
||||
assert messages[2].startswith(f"file_commit_dates: git log failed for {plain}: git log ")
|
||||
assert "failed (exit " in messages[2]
|
||||
assert messages[2].endswith(
|
||||
"— the importer will fall back to file mtimes"
|
||||
)
|
||||
|
||||
|
||||
# --- the pure parser (canned git output — no git, no DB) -------------------
|
||||
|
||||
|
||||
|
||||
+547
-3
@@ -5,8 +5,8 @@ matrix).
|
||||
|
||||
``clone_or_pull`` dispatches to ``git clone`` (full history, fresh dest)
|
||||
or the UNIFIED existing-checkout update (phase 136 — one sequence for
|
||||
both branch shapes) with ``subprocess`` fully mocked — the real git
|
||||
CLI is never invoked, so the tests run anywhere: ref resolution
|
||||
both branch shapes) with ``subprocess`` fully mocked — no real git CLI
|
||||
is needed, so the tests run anywhere: ref resolution
|
||||
(``rev-parse --abbrev-ref HEAD`` — the phase-135 HEAD guard for a
|
||||
pinned ``branch``, the checkout's own branch + the detached-HEAD
|
||||
fail-loud for ``branch=None``) → the shallow probe → optional
|
||||
@@ -18,17 +18,54 @@ fail-loud for ``branch=None``) → the shallow probe → optional
|
||||
force push never fails a sync — phase 136's fix). The fresh-clone
|
||||
argv (with/without ``--branch``) is the pre-phase one — the argv pins
|
||||
below are the regression gate for every existing deployment.
|
||||
|
||||
Phase 186 adds the commit-date PARSER pins and the STREAMING git site.
|
||||
``_parse_commit_dates`` accepts ``str | Iterable[str]`` so the walk can
|
||||
stream off the subprocess pipe instead of buffering the whole ``git
|
||||
log`` in RAM, and ``stream_git_lines`` is the A11 sibling of
|
||||
``run_git`` — its success / error-shape / huge-stderr cases run the
|
||||
REAL git CLI through the house ``_git`` helper (skipped, not failed,
|
||||
without it, like ``tests/integration/test_git_file_dates.py``), while
|
||||
the abandon-the-stream case uses a recorded ``Popen`` stand-in so the
|
||||
terminate-and-reap arm is deterministic instead of a race. The
|
||||
``test_only_two_git_spawn_sites`` pin is the AST version of the old A11
|
||||
grep: exactly one ``subprocess`` spawn per shape, both inside
|
||||
``git_sync.py``. The
|
||||
memory pin's synthetic corpus is ~300,000 lines because that is the
|
||||
size of the real thing on the incident box (2026-10-15, measured
|
||||
read-only inside the app container): ``litellm`` 54,502 commits /
|
||||
346,829 lines / 15,077,351 bytes; ``llama.cpp`` 11,659 commits /
|
||||
69,922 lines / 1,867,046 bytes; ``gufo`` 9,155 lines;
|
||||
``vllm-radiance`` 4,855 lines — i.e. the walk scales with a
|
||||
repository's ENTIRE history, not its working tree, which is why the
|
||||
corpus sits at 306,000 lines (3,000 commits × 100 path lines + the
|
||||
header/blank pair per commit) rather than at a toy size.
|
||||
"""
|
||||
from __future__ import annotations
|
||||
|
||||
import ast
|
||||
import io
|
||||
import logging
|
||||
import os
|
||||
import shutil
|
||||
import subprocess
|
||||
import time
|
||||
import tracemalloc
|
||||
from collections.abc import Callable, Generator, Iterable, Iterator
|
||||
from datetime import UTC, datetime
|
||||
from pathlib import Path
|
||||
from typing import cast
|
||||
|
||||
import pytest
|
||||
|
||||
import scripts.git_sync as git_sync
|
||||
from scripts.git_sync import GitSyncError, clone_or_pull
|
||||
from app.core import docs_push
|
||||
from scripts.git_sync import (
|
||||
GitSyncError,
|
||||
_parse_commit_dates, # pyright: ignore[reportPrivateUsage]
|
||||
clone_or_pull,
|
||||
stream_git_lines,
|
||||
)
|
||||
|
||||
|
||||
class _FakeProc:
|
||||
@@ -697,3 +734,510 @@ def test_null_branch_detached_head_fails_loud(
|
||||
assert [call["argv"] for call in calls] == [
|
||||
["git", "rev-parse", "--abbrev-ref", "HEAD"]
|
||||
] # the guard is first: exactly ONE argv ran (no fetch, no reset)
|
||||
|
||||
|
||||
# --- phase 186: the parser takes a stream (semantics untouched) ------------
|
||||
|
||||
#: One commit header of the synthetic corpus, in the exact byte shape
|
||||
#: ``git log --name-only --format=@@%cI`` emits (``%cI`` is ISO-strict).
|
||||
_CORPUS_HEADER = "@@2026-01-01T00:00:00+00:00"
|
||||
|
||||
#: The synthetic corpus's size — see the module docstring for the
|
||||
#: measured real-world line counts this is modelled on.
|
||||
_CORPUS_COMMITS = 3_000
|
||||
_CORPUS_PATHS_PER_COMMIT = 100
|
||||
|
||||
|
||||
def _corpus_path(commit: int, slot: int) -> str:
|
||||
"""One path line of the synthetic corpus.
|
||||
|
||||
The pool cycles (``(commit * 100 + slot) % 10_000``), so the walk
|
||||
touches 10,000 distinct paths across 300,000 path lines — the same
|
||||
shape as a real repo, where a handful of hot files reappear in
|
||||
commit after commit while history's total path count stays a
|
||||
fraction of the line count.
|
||||
"""
|
||||
return f"path_{(commit * _CORPUS_PATHS_PER_COMMIT + slot) % 10_000:05d}/file_{slot:03d}.md"
|
||||
|
||||
|
||||
def _corpus_stream() -> Iterator[str]:
|
||||
"""The corpus as a LAZY stream: nothing is materialised, each line
|
||||
is built when pulled (the ``stream_git_lines`` shape of task 02)."""
|
||||
for commit in range(_CORPUS_COMMITS):
|
||||
yield _CORPUS_HEADER
|
||||
yield ""
|
||||
for slot in range(_CORPUS_PATHS_PER_COMMIT):
|
||||
yield _corpus_path(commit, slot)
|
||||
|
||||
|
||||
def _corpus_string() -> str:
|
||||
"""The SAME corpus as one big ``str`` (what ``run_git`` returns
|
||||
today) — built OUTSIDE any measured region."""
|
||||
return "\n".join(_corpus_stream()) + "\n"
|
||||
|
||||
|
||||
class _OneShot:
|
||||
"""An iterable that refuses to be iterated twice.
|
||||
|
||||
``__iter__`` raises on the SECOND call, so a parser that
|
||||
materialises its input and rescans it (or loops over ``lines``
|
||||
twice) fails loudly instead of silently passing.
|
||||
"""
|
||||
|
||||
def __init__(self, lines: Iterable[str]) -> None:
|
||||
self._lines = lines
|
||||
self.iter_calls = 0
|
||||
|
||||
def __iter__(self) -> Iterator[str]:
|
||||
self.iter_calls += 1
|
||||
if self.iter_calls > 1:
|
||||
raise AssertionError("re-iterated")
|
||||
return iter(self._lines)
|
||||
|
||||
|
||||
class _CountingStream:
|
||||
"""A stream that records how far the consumer pulled."""
|
||||
|
||||
def __init__(self, lines: list[str]) -> None:
|
||||
self._lines = lines
|
||||
self.pulled = 0
|
||||
|
||||
def __iter__(self) -> Iterator[str]:
|
||||
for pulled, line in enumerate(self._lines, start=1):
|
||||
self.pulled = pulled
|
||||
yield line
|
||||
|
||||
|
||||
def _peak_bytes[T](fn: Callable[[], T]) -> tuple[float, T]:
|
||||
"""Run ``fn`` and return its tracemalloc PEAK in KiB (+ result).
|
||||
|
||||
``reset_peak`` runs after ``start`` so corpus construction (and any
|
||||
earlier test's residue) is excluded — only what ``fn`` itself
|
||||
allocates counts.
|
||||
"""
|
||||
import gc
|
||||
|
||||
gc.collect()
|
||||
tracemalloc.start()
|
||||
try:
|
||||
tracemalloc.reset_peak()
|
||||
result = fn()
|
||||
peak = tracemalloc.get_traced_memory()[1]
|
||||
finally:
|
||||
tracemalloc.stop()
|
||||
return peak / 1024, result
|
||||
|
||||
|
||||
def test_parser_accepts_a_line_iterable() -> None:
|
||||
"""Phase 186 D2: the SAME corpus fed as ``iter([...])`` yields the
|
||||
identical dict as the string form — every parsing rule (the
|
||||
``@@%cI`` header, the blank-line skip, the whitespace path split,
|
||||
the ``\\``→``/`` normalisation, the leading-``/`` strip,
|
||||
first-sighting-wins) is untouched."""
|
||||
lines = [
|
||||
"@@2024-06-15T10:00:00+00:00",
|
||||
"",
|
||||
"b.md",
|
||||
"docs\\deep.md /rooted.md",
|
||||
"@@2020-01-02T03:04:06+00:00",
|
||||
"",
|
||||
"a.md",
|
||||
"b.md",
|
||||
]
|
||||
output = "\n".join(lines) + "\n"
|
||||
expected = {
|
||||
"b.md": datetime.fromisoformat("2024-06-15T10:00:00+00:00"),
|
||||
"docs/deep.md": datetime.fromisoformat("2024-06-15T10:00:00+00:00"),
|
||||
"rooted.md": datetime.fromisoformat("2024-06-15T10:00:00+00:00"),
|
||||
"a.md": datetime.fromisoformat("2020-01-02T03:04:06+00:00"),
|
||||
}
|
||||
|
||||
assert _parse_commit_dates(iter(lines)) == expected
|
||||
assert _parse_commit_dates(output) == expected # the string form, unchanged
|
||||
assert _parse_commit_dates(_OneShot(lines)) == expected
|
||||
|
||||
|
||||
def test_parser_rejects_the_malformed_streams_too() -> None:
|
||||
"""Both ``ValueError`` arms fire through the iterable path exactly as
|
||||
through the string path (the caller's fail-soft is unchanged)."""
|
||||
with pytest.raises(ValueError, match="before any commit header"):
|
||||
_parse_commit_dates(iter(["stray.md", "@@2024-06-15T10:00:00+00:00"]))
|
||||
with pytest.raises(ValueError):
|
||||
_parse_commit_dates(iter(["@@yesterday", "b.md"]))
|
||||
|
||||
|
||||
def test_parser_consumes_exactly_once() -> None:
|
||||
"""Phase 186 D4: the parser walks its input in ONE pass.
|
||||
|
||||
The one-shot wrapper raises ``AssertionError("re-iterated")`` on a
|
||||
second ``iter()``; the parse succeeds and the wrapper reports exactly
|
||||
one ``__iter__`` call, so no materialise-then-rescan (and no
|
||||
accidental ``list(lines)`` re-entering the loop) exists. The second
|
||||
half is the stronger laziness pin: a corpus whose offending line
|
||||
sits at index 3 raises there, having pulled EXACTLY 4 lines — a
|
||||
parser that pre-materialised its input would have pulled the whole
|
||||
tail first.
|
||||
"""
|
||||
corpus = [
|
||||
"@@2024-06-15T10:00:00+00:00",
|
||||
"",
|
||||
"b.md",
|
||||
"@@2020-01-02T03:04:06+00:00",
|
||||
"a.md",
|
||||
]
|
||||
one_shot = _OneShot(corpus)
|
||||
assert _parse_commit_dates(one_shot) == {
|
||||
"b.md": datetime.fromisoformat("2024-06-15T10:00:00+00:00"),
|
||||
"a.md": datetime.fromisoformat("2020-01-02T03:04:06+00:00"),
|
||||
}
|
||||
assert one_shot.iter_calls == 1
|
||||
|
||||
counting = _CountingStream(
|
||||
[
|
||||
"@@2024-06-15T10:00:00+00:00",
|
||||
"",
|
||||
"b.md",
|
||||
"@@not-a-date",
|
||||
"b.md",
|
||||
*(["a.md"] * 1_000), # a long tail the parser must never reach
|
||||
]
|
||||
)
|
||||
with pytest.raises(ValueError):
|
||||
_parse_commit_dates(counting)
|
||||
assert counting.pulled == 4 # stopped AT the bad line, no full read
|
||||
|
||||
|
||||
def test_streamed_parse_alloculates_less_than_buffered() -> None:
|
||||
"""Phase 186 D4: streaming the same corpus allocates materially less
|
||||
than the buffered path, measured comparatively on THIS machine.
|
||||
|
||||
Both arms parse the identical 306,000-line corpus (3,000 commits ×
|
||||
100 paths — see the module docstring for the measured real repos it
|
||||
is modelled on). (a) is the buffered path exactly as ``run_git``
|
||||
serves it today: one big ``str`` that the parser splits
|
||||
(``splitlines()`` materialises a 306,001-entry list of fresh ``str``
|
||||
objects). (b) is a generator building each line lazily. The
|
||||
assertion is ``streamed < buffered * 0.6`` — a wide but not
|
||||
tautological margin (``<=`` would prove nothing); the numbers below
|
||||
are measured on this box (Linux 7.2.9-200.fc44.x86_64, CPython
|
||||
3.13.13, glibc 2.43): buffered **21,504 KiB** peak (the 306,001-entry
|
||||
``splitlines()`` list over a ~7 MB corpus) vs streamed **823 KiB**
|
||||
— a ratio of **0.038**, i.e. the streamed arm allocates ~26× less.
|
||||
The 823 KiB is the retained 10,000-entry result dict, which BOTH
|
||||
arms pay, so the streaming arm is effectively allocation-free.
|
||||
"""
|
||||
corpus = _corpus_string()
|
||||
|
||||
buffered_kb, buffered = _peak_bytes(lambda: _parse_commit_dates(corpus))
|
||||
streamed_kb, streamed = _peak_bytes(lambda: _parse_commit_dates(_corpus_stream()))
|
||||
|
||||
assert buffered_kb > 1_024, f"buffered peak {buffered_kb:,.0f} KiB is not a real corpus"
|
||||
assert streamed_kb < buffered_kb * 0.6, (
|
||||
f"streamed peak {streamed_kb:,.0f} KiB is not materially below the "
|
||||
f"buffered {buffered_kb:,.0f} KiB (ratio "
|
||||
f"{streamed_kb / buffered_kb:.3f}, budget 0.600)"
|
||||
)
|
||||
# memory is not bought by losing data: identical results, ~300k lines
|
||||
assert streamed == buffered
|
||||
assert len(buffered) == 10_000
|
||||
|
||||
|
||||
# --- phase 186: the streaming git site (stream_git_lines) -------------------
|
||||
|
||||
#: The real-git cases below build a throwaway repo (the house ``_git``
|
||||
#: helper) — skipped, not failed, without the git CLI, exactly like
|
||||
#: ``tests/integration/test_git_file_dates.py``.
|
||||
GIT = shutil.which("git") is not None
|
||||
requires_git = pytest.mark.skipif(not GIT, reason="git CLI not available")
|
||||
|
||||
#: Lines spewed to stderr by the deadlock pin — ≈340 KB, i.e. five
|
||||
#: times the ~64 KB pipe buffer, so a non-drained stderr blocks the
|
||||
#: child long before the 10 s wall-clock guard trips.
|
||||
_SPEW_LINES = 60_000
|
||||
|
||||
|
||||
def _git(cwd: Path, *argv: str, when: str | None = None) -> None:
|
||||
"""Run one git command for the test harness (fixture setup); a
|
||||
non-zero exit fails the fixture, not the test under test."""
|
||||
env = os.environ.copy()
|
||||
if when is not None:
|
||||
env["GIT_AUTHOR_DATE"] = when
|
||||
env["GIT_COMMITTER_DATE"] = when
|
||||
env["GIT_AUTHOR_NAME"] = "T"
|
||||
env["GIT_AUTHOR_EMAIL"] = "t@example.com"
|
||||
env["GIT_COMMITTER_NAME"] = "T"
|
||||
env["GIT_COMMITTER_EMAIL"] = "t@example.com"
|
||||
proc = subprocess.run(
|
||||
["git", *argv], cwd=cwd, env=env, capture_output=True, text=True, check=False
|
||||
)
|
||||
assert proc.returncode == 0, f"git {' '.join(argv)} failed: {proc.stderr}"
|
||||
|
||||
|
||||
def _scratch_repo(tmp_path: Path) -> Path:
|
||||
"""A throwaway repo with ONE commit (``a.md``) dated 2020-01-02."""
|
||||
repo = tmp_path / "repo"
|
||||
repo.mkdir()
|
||||
_git(repo, "init", "-q")
|
||||
_git(repo, "config", "user.email", "t@example.com")
|
||||
_git(repo, "config", "user.name", "T")
|
||||
_git(repo, "config", "commit.gpgsign", "false")
|
||||
(repo / "a.md").write_text("# A\n", encoding="utf-8")
|
||||
_git(repo, "add", "-A", when="2020-01-02T03:04:06+00:00")
|
||||
_git(repo, "commit", "-qm", "one", when="2020-01-02T03:04:06+00:00")
|
||||
return repo
|
||||
|
||||
|
||||
class _StreamProc:
|
||||
"""A ``Popen`` stand-in for the abandon-the-stream pin.
|
||||
|
||||
Real pipes would make the case a race (the child has to still be
|
||||
alive at ``close()``); this one holds an unbounded ``StringIO`` so
|
||||
the generator is guaranteed to be parked at its ``yield`` — which is
|
||||
exactly the state whose cleanup the pin checks: terminate, close
|
||||
both pipes, join the stderr thread, reap.
|
||||
"""
|
||||
|
||||
def __init__(self, out: str, err: str) -> None:
|
||||
self.stdout = io.StringIO(out)
|
||||
self.stderr = io.StringIO(err)
|
||||
self.returncode: int | None = None
|
||||
self.terminated = False
|
||||
self.waits = 0
|
||||
|
||||
def terminate(self) -> None:
|
||||
self.terminated = True
|
||||
self.returncode = -15
|
||||
|
||||
def wait(self) -> int:
|
||||
self.waits += 1
|
||||
if self.returncode is None:
|
||||
self.returncode = 0
|
||||
return self.returncode
|
||||
|
||||
|
||||
@requires_git
|
||||
def test_stream_git_lines_yields_lines_and_raises_run_git_shaped_error(
|
||||
tmp_path: Path,
|
||||
) -> None:
|
||||
"""The streaming site's two shapes against REAL git: success yields
|
||||
the ``git log`` lines straight off the pipe (each one still
|
||||
newline-terminated — nothing is buffered or re-split), and a failure
|
||||
raises the ``run_git``-shaped ``GitSyncError`` (``git <subcommand>
|
||||
failed (exit N): <stderr>``), so every caller's fail-soft text is
|
||||
unchanged."""
|
||||
repo = _scratch_repo(tmp_path)
|
||||
argv = ["git", "log", "--name-only", "--format=@@%cI"]
|
||||
|
||||
lines = list(stream_git_lines(argv, cwd=repo))
|
||||
|
||||
stripped = [line.rstrip("\n") for line in lines]
|
||||
assert stripped[1:] == ["", "a.md"]
|
||||
assert stripped[0].startswith("@@") # the %cI commit header, unsplit
|
||||
# (%cI prints UTC as "Z"; fromisoformat reads both forms)
|
||||
assert datetime.fromisoformat(stripped[0][2:]) == datetime(2020, 1, 2, 3, 4, 6, tzinfo=UTC)
|
||||
assert all(line.endswith("\n") for line in lines)
|
||||
|
||||
plain = tmp_path / "not-a-repo"
|
||||
plain.mkdir()
|
||||
with pytest.raises(
|
||||
GitSyncError, match=r"^git log --name-only --format=@@%cI failed \(exit \d+\): "
|
||||
) as excinfo:
|
||||
list(stream_git_lines(argv, cwd=plain))
|
||||
assert "not a git repository" in str(excinfo.value)
|
||||
|
||||
|
||||
@requires_git
|
||||
def test_stream_git_lines_reports_stderr_without_deadlocking(tmp_path: Path) -> None:
|
||||
"""A2: a child spilling ≈340 KB on stderr while stdout is being
|
||||
consumed neither deadlocks nor truncates.
|
||||
|
||||
The command is a git alias running a shell that writes
|
||||
``seq 1 60_000`` (≈340 KB — five pipe buffers) to stderr and exits
|
||||
3, so git's own stderr pipe is what must be drained. Without the
|
||||
drain thread the child blocks on a full stderr pipe while the parent
|
||||
blocks on stdout and neither ever finishes (the classic two-pipe
|
||||
``Popen`` trap); here the call returns in well under the 10 s guard
|
||||
and the ``GitSyncError`` carries git's FULL stderr, which is why
|
||||
``stderr=DEVNULL`` is not the answer (and ``stderr=STDOUT`` would
|
||||
corrupt the date parse).
|
||||
"""
|
||||
repo = _scratch_repo(tmp_path)
|
||||
argv = ["git", "-c", f'alias.spew=!sh -c "seq 1 {_SPEW_LINES} >&2; exit 3"', "spew"]
|
||||
|
||||
started = time.monotonic()
|
||||
with pytest.raises(GitSyncError) as excinfo:
|
||||
list(stream_git_lines(argv, cwd=repo))
|
||||
elapsed = time.monotonic() - started
|
||||
|
||||
msg = str(excinfo.value)
|
||||
assert elapsed < 10, f"streaming a chatty stderr took {elapsed:.1f}s — deadlock?"
|
||||
assert "(exit 3)" in msg
|
||||
assert len(msg.encode()) > 100_000, "git's stderr was truncated, not drained"
|
||||
assert msg.rstrip().endswith(str(_SPEW_LINES)) # the LAST line is there
|
||||
|
||||
|
||||
def test_stream_git_lines_terminates_an_abandoned_stream(
|
||||
tmp_path: Path, monkeypatch: pytest.MonkeyPatch
|
||||
) -> None:
|
||||
"""Closing the generator early (``GeneratorExit``) — and an exception
|
||||
thrown into it — never leaks a ``git`` child: the process is
|
||||
terminated, both pipes closed, the drain thread joined, the child
|
||||
reaped."""
|
||||
proc = _StreamProc("".join(f"line {i}\n" for i in range(5_000)), "warning: noisy stderr\n")
|
||||
monkeypatch.setattr(subprocess, "Popen", lambda *a, **k: proc)
|
||||
|
||||
# The public shape is ``Iterator[str]`` (the parser's contract); this
|
||||
# pin exercises the generator protocol behind it — close()/throw().
|
||||
gen = cast(
|
||||
"Generator[str, None, None]",
|
||||
stream_git_lines(["git", "log", "--name-only", "--format=@@%cI"], cwd=tmp_path),
|
||||
)
|
||||
assert next(gen) == "line 0\n" # parked at the yield, 4,999 lines unread
|
||||
gen.close()
|
||||
|
||||
assert proc.terminated is True
|
||||
assert proc.returncode == -15 # wait() reaped it — no zombie, no orphan
|
||||
assert proc.waits >= 1
|
||||
assert proc.stdout.closed and proc.stderr.closed
|
||||
|
||||
# the same arm fires for a consumer that dies on its own exception
|
||||
proc2 = _StreamProc("line 0\nline 1\n", "")
|
||||
monkeypatch.setattr(subprocess, "Popen", lambda *a, **k: proc2)
|
||||
gen2 = cast("Generator[str, None, None]", stream_git_lines(["git", "log"], cwd=tmp_path))
|
||||
assert next(gen2) == "line 0\n"
|
||||
with pytest.raises(RuntimeError, match="the parser blew up"):
|
||||
gen2.throw(RuntimeError("the parser blew up"))
|
||||
assert proc2.terminated is True
|
||||
|
||||
|
||||
def test_stream_git_lines_missing_git_raises_named_error(
|
||||
tmp_path: Path, monkeypatch: pytest.MonkeyPatch
|
||||
) -> None:
|
||||
"""A missing git binary is the same ``GitSyncError`` as through
|
||||
:func:`run_git` — the walk's fail-soft never sees a bare
|
||||
``FileNotFoundError``."""
|
||||
|
||||
def boom(*args: object, **kwargs: object) -> None:
|
||||
raise FileNotFoundError("git")
|
||||
|
||||
monkeypatch.setattr(subprocess, "Popen", boom)
|
||||
|
||||
with pytest.raises(GitSyncError, match="git was not found on PATH"):
|
||||
list(stream_git_lines(["git", "log"], cwd=tmp_path))
|
||||
# …and the walk's fail-soft keeps working on it: {} + the mtime
|
||||
# fallback, never a bare FileNotFoundError out of the sync.
|
||||
assert git_sync.file_commit_dates(tmp_path) == {}
|
||||
|
||||
|
||||
def test_file_commit_dates_fails_soft_on_a_mid_stream_git_failure(
|
||||
tmp_path: Path, monkeypatch: pytest.MonkeyPatch, caplog: pytest.LogCaptureFixture
|
||||
) -> None:
|
||||
"""Phase 186 D3: a failure AFTER some lines were parsed still yields
|
||||
``{}`` + the same warning (the D2 contract is about the RESULT).
|
||||
|
||||
Pre-streaming, ``run_git`` could only fail before a single line was
|
||||
seen; the stream can fail half-way through a huge history. The
|
||||
importer must still fall back to mtimes — a date walk must never
|
||||
break a sync — and the partial map must be DROPPED, not returned.
|
||||
"""
|
||||
def half_then_boom(argv: list[str], cwd: Path) -> Iterator[str]:
|
||||
yield "@@2024-06-15T10:00:00+00:00"
|
||||
yield "a.md"
|
||||
raise GitSyncError("git log --name-only --format=@@%cI failed (exit 128): fatal: boom")
|
||||
|
||||
monkeypatch.setattr(git_sync, "stream_git_lines", half_then_boom)
|
||||
with caplog.at_level(logging.WARNING, logger="scripts.git_sync"):
|
||||
assert git_sync.file_commit_dates(tmp_path) == {}
|
||||
warnings = [r.getMessage() for r in caplog.records if r.levelno == logging.WARNING]
|
||||
assert len(warnings) == 1
|
||||
assert warnings[0].startswith(f"file_commit_dates: git log failed for {tmp_path}: ")
|
||||
assert "fall back to file mtimes" in warnings[0]
|
||||
|
||||
|
||||
#: Child-process spawns by name (``subprocess.run``/``Popen``/… and the
|
||||
#: ``os`` equivalents) — what an A11 audit has to catch, not just the
|
||||
#: literal string "subprocess".
|
||||
_SUBPROCESS_SPAWNS = frozenset(
|
||||
{"Popen", "run", "call", "check_call", "check_output", "getoutput", "getstatusoutput"}
|
||||
)
|
||||
_OS_SPAWNS = frozenset(
|
||||
{"system", "popen", "execl", "execle", "execlp", "execv", "execve", "execvp", "posix_spawn"}
|
||||
)
|
||||
|
||||
|
||||
class _SpawnVisitor(ast.NodeVisitor):
|
||||
"""Collects ``(enclosing function, spawn call)`` for every child process."""
|
||||
|
||||
def __init__(self) -> None:
|
||||
self.stack: list[str] = []
|
||||
self.sites: list[tuple[str, str]] = []
|
||||
|
||||
@property
|
||||
def _scope(self) -> str:
|
||||
return ".".join(self.stack) if self.stack else "<module>"
|
||||
|
||||
def _visit_func(self, node: ast.FunctionDef | ast.AsyncFunctionDef) -> None:
|
||||
self.stack.append(node.name)
|
||||
self.generic_visit(node)
|
||||
self.stack.pop()
|
||||
|
||||
visit_FunctionDef = _visit_func
|
||||
visit_AsyncFunctionDef = _visit_func
|
||||
|
||||
def visit_Call(self, node: ast.Call) -> None:
|
||||
fn = node.func
|
||||
if isinstance(fn, ast.Attribute) and isinstance(fn.value, ast.Name):
|
||||
if fn.value.id == "subprocess" and fn.attr in _SUBPROCESS_SPAWNS:
|
||||
self.sites.append((self._scope, f"subprocess.{fn.attr}"))
|
||||
elif fn.value.id == "os" and fn.attr in _OS_SPAWNS:
|
||||
self.sites.append((self._scope, f"os.{fn.attr}"))
|
||||
self.generic_visit(node)
|
||||
|
||||
|
||||
def _spawn_sites(path: Path) -> list[tuple[str, str]]:
|
||||
"""Every real spawn in one module, tagged with its function.
|
||||
|
||||
Parsing the AST (not grepping text) keeps docstrings that MENTION
|
||||
``subprocess.run`` out of the result — this module has several.
|
||||
"""
|
||||
visitor = _SpawnVisitor()
|
||||
visitor.visit(ast.parse(path.read_text(encoding="utf-8")))
|
||||
return visitor.sites
|
||||
|
||||
|
||||
def test_only_two_git_spawn_sites() -> None:
|
||||
"""A11, phase-186 shape: exactly TWO spawn sites, one per shape,
|
||||
both inside ``scripts/git_sync.py`` — the buffered
|
||||
``run_git`` (``subprocess.run``) and the streaming
|
||||
``stream_git_lines`` (``subprocess.Popen``).
|
||||
|
||||
The repo-wide half asserts no NEW spawn appears in ``app/`` or
|
||||
``scripts/``. It enumerates the ONE pre-existing spawn outside the
|
||||
module: ``app/core/caching.py``'s boot-time asset-version probe (a
|
||||
5-second-timeouted ``git rev-parse --short HEAD`` that never raises
|
||||
and is not part of any sync path) — the honest state of A11, which
|
||||
the module docstring now states too, instead of a pin that quietly
|
||||
ignores it. ``app/core/docs_push.py`` passes by construction: it
|
||||
calls ``run_git``, so it never appears here.
|
||||
"""
|
||||
module = Path(git_sync.__file__)
|
||||
|
||||
assert _spawn_sites(module) == [
|
||||
("run_git", "subprocess.run"),
|
||||
("stream_git_lines", "subprocess.Popen"),
|
||||
]
|
||||
|
||||
repo_root = module.parents[1]
|
||||
offenders: dict[str, list[tuple[str, str]]] = {}
|
||||
for package in ("app", "scripts"):
|
||||
for py in sorted((repo_root / package).rglob("*.py")):
|
||||
if py == module:
|
||||
continue
|
||||
found = _spawn_sites(py)
|
||||
if found:
|
||||
offenders[str(py.relative_to(repo_root))] = found
|
||||
assert offenders == {"app/core/caching.py": [("_git_short_sha", "subprocess.run")]}
|
||||
|
||||
# docs-push rides the buffered site rather than spawning its own —
|
||||
# the reason it is absent from `offenders`.
|
||||
assert docs_push.run_git is git_sync.run_git
|
||||
|
||||
Reference in New Issue
Block a user