phase: 87_big_read_progress
All criteria verified — no defects found, nothing to fix. Final report: **Phase 87 — big read progress: final verification pass (all tasks already complete in `complete/`)** - Verified implementation vs. overview: `TOOL_LINE_ELAPSED_AFTER_MS = 5_000`, single live `armToolLineClock` site, settle on thinking/retry/delta, `stopToolLineClock` in `setUiState`, visible `.typing-elapsed` (aria kept byte-identical), CSS AA pairing — all match design; `app/` byte-identical (0 changes) - **Tests/lint (exact outcomes):** - `uv run pytest --cov=app --cov-report=term` → 1732 passed, coverage **99%** (>90% ✓) - `uv run pytest tests/e2e/test_big_read_progress.py -v --no-cov` → **4 passed** (ticking suffix, visible hint, settle, no-timer restore) - `test_thinking_display.py` → 5 passed · `test_agent_document_tools.py` → 4 passed · `test_smoke.py` → 3 passed (all isolated) - 3 pinned frontend suites + new unit pins → 62 passed · `uv run ruff check . && uv run pyright` → clean, 0 errors - **Completion criteria:** E2E pins 1–4 ✓ · guard/state-machine byte-identical ✓ (diff is additive only) · diff scope limited to `app.js`, `styles.css`, 2 new test files, phase files; nothing in `app/` ✓ - **Notable:** no deviations; commit + `00_phase.md` move left to the harness per executor rules (task files already in `complete/`) - **Next pending phase:** none — `todo/` contains only this phase (87 is the last)
This commit is contained in:
@@ -0,0 +1,695 @@
|
||||
"""Phase 87 E2E (Playwright, mock-only): progress indication during a
|
||||
deterministic big-read gap.
|
||||
|
||||
Source: ``TODO.md`` L5 — "Need indication that prompt processing is
|
||||
happening during a big read, it can look frozen."
|
||||
Run in isolation (DB must be up: ``podman compose up -d db``):
|
||||
|
||||
uv run pytest tests/e2e/test_big_read_progress.py -v --no-cov
|
||||
|
||||
MOCK-ONLY suite: ``E2E_REAL_LLM=1`` is not supported (the tests skip)
|
||||
— the deterministic gaps this story pins need the mock's "use your
|
||||
tools" marker flow (``tests/e2e/mock_llm.py``) behind the phase-64
|
||||
delay-injecting reverse proxy (``tests/e2e/slow_llm.py``).
|
||||
|
||||
**Mechanism** — the mock's deterministic single-read tool flow, with
|
||||
every inter-frame gap made deterministic at ≥6 s by the slow proxy
|
||||
(``SLOW_LLM_DELAY_S = 6.0`` — this suite passes its OWN value: the
|
||||
phase-64 default 0.15 is far below the 5 s tool-line threshold):
|
||||
|
||||
NOTE the prelude: the chat flow's QUESTION EMBEDDING also travels
|
||||
through the proxy (one 6 s sleep) before the agent loop starts, so
|
||||
the wall-clock timeline of one turn is:
|
||||
|
||||
1. t≈12 s — the first SSE ``tool`` frame ("🔎 Listing documents"): the
|
||||
6 s embedding sleep + request 1's 6 s sleep (``tools`` offered, no
|
||||
tool results yet — streams ONLY the ``ls`` ``tool_calls`` delta,
|
||||
id ``call_0``) + the mock's ~0.2 s tool-call stream;
|
||||
2. t≈19 s — the second ``tool`` frame ("📄 Reading
|
||||
Deployments/example-record-file.json"): request 2's 6 s sleep (a
|
||||
``tool``-role catalog result → streams a ``read`` ``tool_calls``
|
||||
delta on the JOINED combined ``source/path`` of the FIRST catalog
|
||||
line, id ``call_1``);
|
||||
3. t≈25 s — the content answer ``Read <source/path>. <first 80 chars
|
||||
of the read document's content>``: request 3's 6 s sleep (a
|
||||
``tool``-role read result) → the first answer ``delta``.
|
||||
|
||||
So each post-tool-frame gap (≈6.3 s — the 6 s sleep + the short
|
||||
tool-call stream) is PAST the 5 s tool-line threshold
|
||||
(``TOOL_LINE_ELAPSED_AFTER_MS = 5_000``), and the 10 s pre-token
|
||||
typing hint (the existing ``startThinkingClock`` gate, ticking from
|
||||
t≈0) is visible throughout both post-tool gaps — everything before the
|
||||
answer's first delta (the whole turn runs ≈25 s + overhead, acceptable
|
||||
for an isolated story suite). The four tests pin: (1) the latest tool
|
||||
line's ticking "(Ns)" suffix, (2) the typing indicator's visible "Ns"
|
||||
hint (+ the kept aria channel), (3) BOTH settling the instant the
|
||||
answer arrives, (4) a RELOAD restoring the tool lines with NO timer
|
||||
(A6 — the restore path never arms the clock).
|
||||
|
||||
**Aria-channel note (test 2):** the tool-frame branch overwrites the
|
||||
typing bubble's ``aria-label`` with its status copy ("… is listing
|
||||
documents" at ≈12 s, "… is reading …" at ≈19 s); the 1 s thinking
|
||||
clock RE-SETS it to "… is still thinking (Ns)" on every tick (the same
|
||||
task that writes the visible span) — so the two channels read
|
||||
"still thinking" SIMULTANEOUSLY right after each tick, and test 2
|
||||
polls until they align (the deterministic same-moment pin).
|
||||
|
||||
**KB fixture** — byte-identical to the phase-37 suite
|
||||
(``tests/e2e/test_agent_document_tools.py``): ``Homelab/aws-route53.md``
|
||||
carries one chunk embedded with the mock's own bag-of-words vector —
|
||||
the marker question (phase 37's exact question, which carries the
|
||||
trigger phrase) cosines ≈0.69 against it, well past the E2E 0.30
|
||||
threshold, so the turn is grounded and the HIGH prompt carries the
|
||||
``<tools>`` section; ``Deployments/example-record-file.json`` is
|
||||
indexed WITHOUT chunks, and its ``(source, path)`` sorts FIRST in the
|
||||
catalog (``Deployments`` < ``Homelab``) — exactly the line the mock's
|
||||
second request reads, so the answer is byte-stable.
|
||||
|
||||
Test → story mapping (Playwright Mapping Rule):
|
||||
1. ``test_tool_line_shows_ticking_elapsed``
|
||||
2. ``test_typing_indicator_shows_visible_elapsed``
|
||||
3. ``test_indicators_settle_when_the_answer_arrives``
|
||||
4. ``test_restored_turn_has_no_timer``
|
||||
"""
|
||||
from __future__ import annotations
|
||||
|
||||
import hashlib
|
||||
import json
|
||||
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
|
||||
|
||||
import httpx
|
||||
import pytest
|
||||
from playwright.sync_api import Page, expect
|
||||
from sqlalchemy import text
|
||||
from sqlalchemy.orm import Session
|
||||
|
||||
from app.config import Settings as _Settings
|
||||
from app.db import SessionLocal
|
||||
from app.models import Chunk, Document
|
||||
from e2e.auth_helpers import login
|
||||
from e2e.conftest import (
|
||||
ADMIN_PASSWORD,
|
||||
MOCK_PORT,
|
||||
SESSION_SECRET,
|
||||
USE_REAL_LLM,
|
||||
_wait_http,
|
||||
)
|
||||
from tests.e2e.mock_llm import embed_text
|
||||
|
||||
REPO = Path(__file__).resolve().parents[2]
|
||||
|
||||
# Phase 79 (task 04, full inventory): the conftest session app owns its
|
||||
# port in a combined run — this module app binds its own port instead
|
||||
# (a same-port second uvicorn dies on bind and would drive the wrong
|
||||
# server). Env-overridable.
|
||||
APP_PORT = int(os.environ.get("E2E_APP_PORT_BIGREAD", "8128"))
|
||||
APP_URL = f"http://127.0.0.1:{APP_PORT}"
|
||||
|
||||
#: This suite's slow-LLM proxy port (the conftest's mock LLM stays on
|
||||
#: MOCK_PORT; the phase-64 suite owns 8902, so the ports follow the
|
||||
#: same allocation rule: one port pair per module app).
|
||||
SLOW_PORT = int(os.environ.get("E2E_SLOW_LLM_PORT_BIGREAD", "8903"))
|
||||
SLOW_URL = f"http://127.0.0.1:{SLOW_PORT}"
|
||||
|
||||
#: Per-LLM-request delay on the proxy — this suite's timing fixture.
|
||||
#: 6.0 s puts every inter-frame gap past the 5 s tool-line threshold
|
||||
#: and keeps the whole turn pre-token until the first delta (the 10 s
|
||||
#: typing hint ticks across the prelude AND both post-tool gaps); the
|
||||
#: whole turn then runs ≈25 s + overhead — acceptable for an isolated
|
||||
#: story suite (the phase-64 suite has the same shape, at 0.15 s).
|
||||
SLOW_DELAY_S = "6.0"
|
||||
|
||||
# --------------------------------------------------------------------------
|
||||
# KB fixture — byte-identical to the phase-37 suite (see the module
|
||||
# docstring)
|
||||
# --------------------------------------------------------------------------
|
||||
|
||||
SEED_SOURCE = "Homelab"
|
||||
SEED_PATH = "aws-route53.md"
|
||||
|
||||
READ_SOURCE = "Deployments"
|
||||
READ_PATH = "example-record-file.json"
|
||||
READ_SP = f"{READ_SOURCE}/{READ_PATH}"
|
||||
|
||||
#: The retrievable document: references the JSON file "for the exact JSON
|
||||
#: shape of reeselink.json" but never includes it. The repeated
|
||||
#: record-file lines carry the marker question's key tokens (aws,
|
||||
#: route53, hosted, zone, reeselink, json, exact, shape) — verified
|
||||
#: ≈0.69 cosine against the mock's embeddings (E2E threshold 0.30) plus
|
||||
#: FTS hits, so the turn is solidly grounded (HIGH prompt → <tools>).
|
||||
ROUTE53_CONTENT = (
|
||||
"# AWS Route 53 Notes\n\n"
|
||||
"## Record file\n\n"
|
||||
+ (
|
||||
"The aws route53 hosted zone for reeselink keeps every record in "
|
||||
"reseelink.json — the exact JSON shape of reeselink.json is "
|
||||
"documented in example-record-file.json.\n"
|
||||
)
|
||||
* 10
|
||||
+ "\n## Sync job\n\n"
|
||||
"A cron job pushes reeselink.json to the aws route53 hosted zone "
|
||||
"every fifteen minutes; the diff is applied through the route53 api.\n"
|
||||
)
|
||||
|
||||
#: The referenced document: the exact JSON shape. Its FIRST line is longer
|
||||
#: than 80 chars, so the mock's first-80-chars quote is newline-free (the
|
||||
#: rendered-text assertions below match it verbatim). Pinned by the
|
||||
#: assert below (phase 37's pin, kept).
|
||||
RECORD_FILE_CONTENT = (
|
||||
'{ "version": 3, "comment": "ReeseLink hosted zone records — the exact '
|
||||
'JSON shape of reeselink.json",\n'
|
||||
' "hosted_zone_id": "Z0RESEELINK01",\n'
|
||||
' "record_sets": [\n'
|
||||
' { "name": "www.reeselink.example", "type": "A", "ttl": 300,\n'
|
||||
' "resource_records": [ { "value": "10.0.0.20" } ] },\n'
|
||||
' { "name": "api.reeselink.example", "type": "CNAME", "ttl": 300,\n'
|
||||
' "resource_records": [ { "value": "www.reeselink.example" } ] }\n'
|
||||
" ]\n"
|
||||
"}\n"
|
||||
)
|
||||
assert "\n" not in RECORD_FILE_CONTENT[:80] # the quote must stay one line
|
||||
|
||||
#: Phase 37's exact marker question — carries the mock trigger phrase
|
||||
#: "use your tools" (case-insensitive ``TOOLS_TRIGGER``) and is grounded
|
||||
#: against the byte-identical seed above, so the deterministic single-
|
||||
#: read tool flow runs.
|
||||
MARKER_QUESTION = (
|
||||
"Use your tools: what is the exact JSON shape of reeselink.json "
|
||||
"for my aws route53 hosted zone?"
|
||||
)
|
||||
|
||||
#: The mock's deterministic answer for the single-read flow (the
|
||||
#: phase-37 shapes, kept): "Read <source/path>. <first 80 chars>".
|
||||
ANSWER_PREFIX = f"Read {READ_SP}."
|
||||
ANSWER_QUOTE = RECORD_FILE_CONTENT[:80]
|
||||
|
||||
# --------------------------------------------------------------------------
|
||||
# Timeouts — every wait carries ≥2× headroom on its expected duration
|
||||
# (the flakiness discipline: the timing assertions themselves are
|
||||
# strictly-increasing, never exact-value)
|
||||
# --------------------------------------------------------------------------
|
||||
|
||||
#: The first ``tool`` frame lands at ≈12.4 s (the 6 s embedding sleep
|
||||
#: + request 1's 6 s proxy sleep + the mock's short tool-call stream)
|
||||
#: — 1.6× headroom.
|
||||
TOOL_LINE_TIMEOUT_MS = 20_000
|
||||
#: The "(Ns)" suffix appears 5 s after the line's OWN arm (1 s tick
|
||||
#: granularity) — the task's generous 12 s, measured from the line's
|
||||
#: appearance: 2.4× the threshold.
|
||||
SUFFIX_TIMEOUT_MS = 12_000
|
||||
#: The visible typing hint first ticks at 10 s from submit, but this
|
||||
#: suite only starts checking it AFTER the first tool line (≈12.4 s)
|
||||
#: — the first tick where the visible hint and the aria channel align
|
||||
#: is ≈13 s (the next tick after the ls frame's aria overwrite), and
|
||||
#: the indicator is removed at the first delta (≈25 s): 20 s from the
|
||||
#: check start cannot flake.
|
||||
TYPING_HINT_TIMEOUT_MS = 20_000
|
||||
#: The answer settles at ≈19 s from submit; every settle wait here starts
|
||||
#: ≥12 s in — 30 s keeps ≥2× headroom on the remaining window.
|
||||
SETTLE_TIMEOUT_MS = 30_000
|
||||
#: The restore is a synchronous boot re-render — 15 s is ample.
|
||||
RESTORE_TIMEOUT_MS = 15_000
|
||||
|
||||
#: The tool-line suffix format: parenthesized "(Ns)" (the task's pin).
|
||||
ELAPSED_PAT = r"\((\d+)s\)"
|
||||
#: The typing hint format: bare "Ns" (task 01's pin).
|
||||
TYPING_ELAPSED_PAT = r"(\d+)s"
|
||||
#: The two-sample spacing the task pins (≥1.5 s apart).
|
||||
SAMPLE_GAP_S = 1.5
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Fixtures (the phase-64 pattern — module app behind the slow proxy; the
|
||||
# conftest already spawns the mock LLM)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
@pytest.fixture(autouse=True)
|
||||
def _mock_only() -> None:
|
||||
"""The deterministic gaps need the mock's marker flow — skip
|
||||
(rather than fail) when pointed at the real LLM."""
|
||||
if USE_REAL_LLM:
|
||||
pytest.skip(
|
||||
"mock-only suite: the deterministic big-read gap needs the "
|
||||
"mock's 'use your tools' flow behind the slow proxy"
|
||||
)
|
||||
|
||||
|
||||
def _wait_slow_http(url: str, delay_s: float, timeout: float = 60.0) -> None:
|
||||
"""Readiness probe for the slow proxy — the conftest's
|
||||
``_wait_http`` pattern with one adaptation forced by THIS suite's
|
||||
delay: the house helper gives each probe attempt a 2.0 s client
|
||||
timeout, but a request to this proxy takes ≥ ``SLOW_LLM_DELAY_S``
|
||||
(6.0 s — it sleeps per request), so with the house helper NO probe
|
||||
request ever completes and the 40 s deadline expires (the phase-64
|
||||
suite never hit this: its 0.15 s delay is under 2 s). Each attempt
|
||||
here gets ``delay + 5 s``; the deadline loop, 0.5 s cadence, and
|
||||
failure behavior are the conftest pattern verbatim."""
|
||||
deadline = time.monotonic() + timeout
|
||||
last_err = "unknown"
|
||||
while time.monotonic() < deadline:
|
||||
try:
|
||||
httpx.get(url, timeout=delay_s + 5.0)
|
||||
return
|
||||
except Exception as e: # noqa: BLE001 — retry until deadline
|
||||
last_err = str(e)
|
||||
time.sleep(0.5)
|
||||
raise RuntimeError(f"server at {url} did not come up: {last_err}")
|
||||
|
||||
|
||||
@pytest.fixture(scope="module")
|
||||
def slow_llm(mock_llm: int) -> Iterator[int]:
|
||||
"""The delay-injecting reverse proxy in front of the mock LLM
|
||||
(``tests/e2e/slow_llm.py``) — this suite's timing fixture: the
|
||||
per-request ``SLOW_DELAY_S`` makes every inter-frame gap
|
||||
deterministic (see the module docstring). Mirrors the phase-64
|
||||
fixture (process handling unchanged; only the readiness probe
|
||||
adapts — see ``_wait_slow_http``)."""
|
||||
env = dict(os.environ)
|
||||
env.pop("DEBUGPY", None)
|
||||
env["SLOW_LLM_DELAY_S"] = SLOW_DELAY_S
|
||||
env["E2E_MOCK_PORT"] = str(MOCK_PORT)
|
||||
proc = subprocess.Popen(
|
||||
[sys.executable, "-m", "uvicorn", "tests.e2e.slow_llm:app",
|
||||
"--host", "127.0.0.1", "--port", str(SLOW_PORT), "--log-level", "warning"],
|
||||
cwd=REPO,
|
||||
env=env,
|
||||
)
|
||||
try:
|
||||
_wait_slow_http(f"{SLOW_URL}/v1/models", float(SLOW_DELAY_S))
|
||||
yield SLOW_PORT
|
||||
finally:
|
||||
proc.terminate()
|
||||
try:
|
||||
proc.wait(timeout=10)
|
||||
except subprocess.TimeoutExpired:
|
||||
proc.kill()
|
||||
|
||||
|
||||
@pytest.fixture(scope="module")
|
||||
def app_server(mock_llm: int, slow_llm: int) -> Iterator[str]:
|
||||
"""The real app under test — the conftest's session-app env shape
|
||||
(including the phase-61/62 leak guards) with one swap: the LLM base
|
||||
URL is the SLOW PROXY in front of the mock (the timing fixture)."""
|
||||
env = dict(os.environ)
|
||||
env.pop("DEBUGPY", None)
|
||||
env["BOR_ENVIRONMENT"] = "e2e"
|
||||
env["BOR_STATIC_DIR"] = str(REPO / "frontend")
|
||||
env["BOR_LLM_BASE_URL"] = (
|
||||
"https://aipi.reeseapps.com/v1"
|
||||
if USE_REAL_LLM
|
||||
else f"{SLOW_URL}/v1"
|
||||
)
|
||||
# The E2E mock's token-overlap embeddings have their own score
|
||||
# distribution (phase 09) — the mock-calibrated threshold so the
|
||||
# marker question stays grounded (conftest pattern).
|
||||
env["BOR_RELEVANCE_THRESHOLD"] = "0.30"
|
||||
# Phase 67: instant retry waits (no retry fires in this suite — the
|
||||
# conftest env shape, kept).
|
||||
env["BOR_LLM_RETRY_DELAY"] = "0"
|
||||
env["BOR_LLM_RETRIES"] = str(_Settings.model_fields["llm_retries"].default)
|
||||
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
|
||||
# Phase 61/62 leak guards (the conftest pattern): force the code
|
||||
# defaults so an operator's local (gitignored) ``.env`` cannot leak
|
||||
# into the app under test.
|
||||
env["BOR_DOCS_REPO"] = ""
|
||||
env["BOR_SUGGESTIONS"] = json.dumps(
|
||||
_Settings.model_fields["suggestions"].default
|
||||
)
|
||||
env["BOR_INPUT_PLACEHOLDER"] = _Settings.model_fields["input_placeholder"].default
|
||||
env["BOR_FOOTER_TEXT"] = _Settings.model_fields["footer_text"].default
|
||||
env["BOR_THEME"] = _Settings.model_fields["theme"].default
|
||||
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
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# DB seeding (phase-37's TRUNCATE-then-seed pattern)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def _seed(db: Session) -> None:
|
||||
"""The phase-37 two-document pair, byte-identical (see the module
|
||||
docstring)."""
|
||||
md = Document(
|
||||
source=SEED_SOURCE,
|
||||
path=SEED_PATH,
|
||||
full_path=f"/tmp/{SEED_PATH}",
|
||||
title="AWS Route 53 Notes",
|
||||
content=ROUTE53_CONTENT,
|
||||
content_hash=hashlib.sha256(ROUTE53_CONTENT.encode()).hexdigest(),
|
||||
indexed_at=datetime.now(UTC),
|
||||
)
|
||||
db.add(md)
|
||||
db.flush()
|
||||
# One chunk carrying the mock's own embedding → genuine token
|
||||
# overlap between the marker question and this document.
|
||||
db.add(
|
||||
Chunk(
|
||||
document_id=md.id,
|
||||
position=0,
|
||||
content=ROUTE53_CONTENT,
|
||||
embedding=embed_text(ROUTE53_CONTENT),
|
||||
)
|
||||
)
|
||||
# The referenced JSON: indexed, catalogued, readable — but NO chunks,
|
||||
# so retrieval never puts it in context; its (source, path) sorts
|
||||
# FIRST in the catalog — the line the mock reads.
|
||||
db.add(
|
||||
Document(
|
||||
source=READ_SOURCE,
|
||||
path=READ_PATH,
|
||||
full_path=f"/tmp/{READ_PATH}",
|
||||
title="Example Record File",
|
||||
content=RECORD_FILE_CONTENT,
|
||||
content_hash=hashlib.sha256(RECORD_FILE_CONTENT.encode()).hexdigest(),
|
||||
indexed_at=datetime.now(UTC),
|
||||
)
|
||||
)
|
||||
|
||||
|
||||
def _reset_db(seed: Callable[[Session], None] | None = None) -> None:
|
||||
"""Truncate the KB (plus the prompt-shaping tables and the
|
||||
phase-55 auto-save rows), then re-seed — the E2E isolation
|
||||
pattern (phase 37; ``saved_chats`` added since phase 55, when
|
||||
every send auto-saves — a leftover row would pollute the
|
||||
saved-chats suites on the shared DB)."""
|
||||
with SessionLocal() as db:
|
||||
db.execute(
|
||||
text(
|
||||
"TRUNCATE chunks, documents, query_log, "
|
||||
"steering_notes, kb_overview, saved_chats"
|
||||
)
|
||||
)
|
||||
db.commit()
|
||||
if seed is not None:
|
||||
seed(db)
|
||||
db.commit()
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Page helpers
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def _submit_tools_turn(page: Page, app_url: str) -> None:
|
||||
"""Type the marker trigger and submit, then wait for the FIRST
|
||||
``.tool-call`` line (the "Listing documents" line — the mock flow's
|
||||
first call) to appear in ``#messages``.
|
||||
|
||||
Auth: phase 37's agent-tools E2E logs in as admin — mirrored
|
||||
exactly (the mock flow + proxy are identical either way; the
|
||||
house pattern for this flow wins)."""
|
||||
login(page, app_url, next="/")
|
||||
page.fill("#message-input", MARKER_QUESTION)
|
||||
page.click("#send-btn")
|
||||
# The user bubble lands synchronously with the submit handler.
|
||||
expect(page.locator(".msg.user .bubble").last).to_contain_text(MARKER_QUESTION)
|
||||
# The first tool frame lands at ≈6 s (the proxy's per-request
|
||||
# sleep) — generous timeout (≥2× headroom).
|
||||
expect(page.locator("#messages .tool-call").first).to_be_visible(
|
||||
timeout=TOOL_LINE_TIMEOUT_MS
|
||||
)
|
||||
|
||||
|
||||
def _elapsed_value(raw: str | None, pattern: str) -> int:
|
||||
"""Parse the integer seconds out of one indicator text sample
|
||||
(fail loud when the sample does not carry the pinned shape)."""
|
||||
match = re.search(pattern, raw or "")
|
||||
assert match is not None, f"no value matching {pattern} in {raw!r}"
|
||||
return int(match.group(1))
|
||||
|
||||
|
||||
def _sample_twice(page: Page, selector: str, pattern: str) -> tuple[int, int]:
|
||||
"""Two text samples of the FIRST element matching *selector*,
|
||||
≥``SAMPLE_GAP_S`` (1.5 s) apart — the "the clock ticks while the
|
||||
gap holds" check. The strictly-increasing assert stays in the
|
||||
test."""
|
||||
first = page.locator(selector).first
|
||||
v1 = _elapsed_value(first.text_content(), pattern)
|
||||
page.wait_for_timeout(int(SAMPLE_GAP_S * 1000))
|
||||
v2 = _elapsed_value(first.text_content(), pattern)
|
||||
return v1, v2
|
||||
|
||||
|
||||
def _wait_visible_hint_and_aria(page: Page, min_value: int, timeout_ms: int) -> int:
|
||||
"""Poll until BOTH: the typing indicator's visible hint value is
|
||||
≥ *min_value* AND the bubble's ``aria-label`` carries "still
|
||||
thinking" — and return that value.
|
||||
|
||||
Why the combined poll (the deterministic same-moment pin): the
|
||||
tool-frame branch overwrites the bubble's ``aria-label`` with its
|
||||
status copy ("… is listing documents" when the ls frame lands at
|
||||
≈12 s, "… is reading …" at ≈19 s), while the 1 s thinking clock
|
||||
re-sets it to "… is still thinking (Ns)" on EVERY tick — the same
|
||||
task that writes the visible ``.typing-elapsed`` span (app.js
|
||||
``startThinkingClock``: the ``setAttribute`` precedes the span
|
||||
write in one JS task). The two channels therefore read "still
|
||||
thinking" simultaneously right after each tick, and a check that
|
||||
starts in a tool-frame's overwrite window (this suite checks only
|
||||
after the first tool line) must wait for the next tick — exactly
|
||||
the house polling-until pattern (cf. the phase-44 flake fix for
|
||||
transient windows)."""
|
||||
deadline = time.monotonic() + timeout_ms / 1000
|
||||
last: tuple[int | None, str] = (None, "")
|
||||
while time.monotonic() < deadline:
|
||||
el = page.locator("#typing-indicator .typing-elapsed")
|
||||
if el.count() >= 1:
|
||||
value = _elapsed_value(el.first.text_content(), TYPING_ELAPSED_PAT)
|
||||
aria = (
|
||||
page.locator("#typing-indicator .bubble").get_attribute("aria-label")
|
||||
or ""
|
||||
)
|
||||
last = (value, aria)
|
||||
if value >= min_value and "still thinking" in aria:
|
||||
return value
|
||||
time.sleep(0.25)
|
||||
raise AssertionError(
|
||||
f"the visible hint (≥{min_value}s) and the 'still thinking' aria "
|
||||
f"never aligned (last: value={last[0]} aria={last[1]!r})"
|
||||
)
|
||||
|
||||
|
||||
def _wait_settled(page: Page) -> None:
|
||||
"""The turn is complete: answer text in the bubble, button
|
||||
recovered (the phase-37/48 pattern — the in-flight button is the
|
||||
enabled Stop control, so the label assertion carries the settle
|
||||
wait with an explicit timeout)."""
|
||||
expect(page.locator(".msg.brain .bubble").last).not_to_have_text(
|
||||
"", timeout=SETTLE_TIMEOUT_MS
|
||||
)
|
||||
expect(page.locator("#send-btn")).to_be_enabled(timeout=SETTLE_TIMEOUT_MS)
|
||||
expect(page.locator("#send-label")).to_have_text("Send", timeout=SETTLE_TIMEOUT_MS)
|
||||
|
||||
|
||||
#: The FIRST tool line's suffix, pinned to the line ("first .tool-call
|
||||
#: child of the .tool-calls container" — the "Listing documents" line;
|
||||
#: the read frame's second line arms its OWN clock 5 s later and is
|
||||
#: never the target here).
|
||||
FIRST_LINE_SUFFIX = "#messages .tool-calls .tool-call:first-child .tool-elapsed"
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# 1. The latest tool line grows a ticking "(Ns)" suffix during the gap
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_tool_line_shows_ticking_elapsed(
|
||||
page: Page, app_url: str, mock_llm: int, db_ready: None
|
||||
) -> None:
|
||||
"""The owner's "it can look frozen" (sighted channel): after 5 s of
|
||||
frame silence the latest tool line shows a ticking "(Ns)" suffix.
|
||||
The first line's ("Listing documents") suffix is sampled twice ≥1.5
|
||||
s apart: the second value is STRICTLY greater — the clock ticks
|
||||
while the gap holds (the next frame is ≥6 s away, past the 5 s
|
||||
threshold). The turn is still in flight at both samples: the button
|
||||
is the enabled "Stop" control (the phase-48 contract)."""
|
||||
page.set_default_timeout(30_000)
|
||||
_reset_db(_seed)
|
||||
_submit_tools_turn(page, app_url)
|
||||
|
||||
# The suffix appears 5 s after the line's own arm (1 s tick
|
||||
# granularity) — the generous 12 s timeout keeps this unflaky.
|
||||
expect(page.locator(FIRST_LINE_SUFFIX)).to_be_visible(timeout=SUFFIX_TIMEOUT_MS)
|
||||
|
||||
v1, v2 = _sample_twice(page, FIRST_LINE_SUFFIX, ELAPSED_PAT)
|
||||
assert v2 > v1, f"the tool-line suffix did not tick: ({v1}s) -> ({v2}s)"
|
||||
|
||||
# Still in flight (a cheap invariant): the enabled Stop control.
|
||||
expect(page.locator("#send-btn")).to_be_enabled()
|
||||
expect(page.locator("#send-label")).to_have_text("Stop")
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# 2. The typing indicator shows the visible "Ns" hint (kept aria channel)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_typing_indicator_shows_visible_elapsed(
|
||||
page: Page, app_url: str, mock_llm: int, db_ready: None
|
||||
) -> None:
|
||||
"""The 10 s pre-token clock promoted from aria-only to sighted
|
||||
users: during the post-tool-frame gap (no thinking/delta frame has
|
||||
arrived in the mock flow) the typing indicator shows a VISIBLE
|
||||
ticking "Ns" hint. Poll until the visible value (≥10 — the gate)
|
||||
and the bubble's aria-label (the kept "still thinking" sentence —
|
||||
the screen-reader channel the unit pins protect) read together at
|
||||
the same moment; a second value sample ≥1.5 s later is strictly
|
||||
greater (the clock ticks while the gap holds — the next frame is
|
||||
≥6 s away)."""
|
||||
page.set_default_timeout(30_000)
|
||||
_reset_db(_seed)
|
||||
_submit_tools_turn(page, app_url)
|
||||
|
||||
# The hint first ticks at 10 s from submit (1 s granularity), but
|
||||
# the check starts after the first tool line (≈12.4 s) — the ls
|
||||
# frame has just overwritten the bubble's aria-label with its
|
||||
# status copy, so wait for the NEXT tick, where the visible value
|
||||
# and the aria channel align (same JS task — see the helper).
|
||||
v1 = _wait_visible_hint_and_aria(page, 10, TYPING_HINT_TIMEOUT_MS)
|
||||
assert v1 >= 10, f"the hint appeared below the 10 s gate: {v1}s"
|
||||
|
||||
# The clock ticks while the gap holds: ≥1.5 s later the value is
|
||||
# strictly greater (the read frame is ≥6 s away; the first delta
|
||||
# — which removes the whole indicator — is ≈25 s from submit).
|
||||
page.wait_for_timeout(int(SAMPLE_GAP_S * 1000))
|
||||
v2 = _elapsed_value(
|
||||
page.locator("#typing-indicator .typing-elapsed").first.text_content(),
|
||||
TYPING_ELAPSED_PAT,
|
||||
)
|
||||
assert v2 > v1, f"the typing hint did not tick: {v1}s -> {v2}s"
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# 3. On the answer's arrival BOTH indications settle (no stale timers)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_indicators_settle_when_the_answer_arrives(
|
||||
page: Page, app_url: str, mock_llm: int, db_ready: None
|
||||
) -> None:
|
||||
"""Settle contract: once the answer arrives the ``#typing-indicator``
|
||||
is removed (the state machine owns it) and NO ``.tool-elapsed``
|
||||
element exists anywhere in ``#messages`` (the delta frame's
|
||||
settle removed them — both lines' worth); 1.5 s later still none
|
||||
(the turn is over — the transition stopped the clock, no
|
||||
re-appearance). The tool lines themselves remain, byte-identical
|
||||
text — the permanent record (phase 37's pin), and the answer bubble
|
||||
is complete."""
|
||||
page.set_default_timeout(30_000)
|
||||
_reset_db(_seed)
|
||||
_submit_tools_turn(page, app_url)
|
||||
|
||||
# First the ticking state (the test-1 wait, reused)…
|
||||
expect(page.locator(FIRST_LINE_SUFFIX)).to_be_visible(timeout=SUFFIX_TIMEOUT_MS)
|
||||
|
||||
# …then the answer arrives (≈25 s from submit — see the module
|
||||
# docstring's timeline) and settles.
|
||||
_wait_settled(page)
|
||||
|
||||
# Both indications are gone — the typing indicator removed by the
|
||||
# first delta's setUiState(streaming), the suffixes by the delta
|
||||
# frame's settle (the settle contract).
|
||||
expect(page.locator("#typing-indicator")).to_have_count(0)
|
||||
expect(page.locator("#messages .tool-elapsed")).to_have_count(0)
|
||||
|
||||
# No re-appearance 1.5 s later — the turn is over, the clock is
|
||||
# stopped (settle cleared the interval, the transition nulled the
|
||||
# wrap — no residue).
|
||||
page.wait_for_timeout(int(SAMPLE_GAP_S * 1000))
|
||||
expect(page.locator("#messages .tool-elapsed")).to_have_count(0)
|
||||
expect(page.locator("#typing-indicator")).to_have_count(0)
|
||||
|
||||
# The tool lines remain — the permanent record, both present with
|
||||
# their pinned text (phase 37's pattern).
|
||||
lines = page.locator("#messages .tool-call")
|
||||
expect(lines).to_have_count(2)
|
||||
expect(lines.nth(0)).to_contain_text("Listing documents")
|
||||
expect(lines.nth(1)).to_contain_text("Reading ")
|
||||
expect(lines.nth(1)).to_contain_text(READ_SP)
|
||||
|
||||
# The answer bubble is complete (the mock's deterministic quote).
|
||||
bubble = page.locator(".msg.brain .bubble").last
|
||||
expect(bubble).to_contain_text(ANSWER_PREFIX)
|
||||
expect(bubble).to_contain_text(ANSWER_QUOTE)
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# 4. A reload restores the tool lines WITHOUT any timer (A6)
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
|
||||
def test_restored_turn_has_no_timer(
|
||||
page: Page, app_url: str, mock_llm: int, db_ready: None
|
||||
) -> None:
|
||||
"""A6 end-to-end: after the turn completes (the auto-save persisted
|
||||
it — the local ``bor.chat.v1`` record is written synchronously at
|
||||
the save points, so the reload sees the full conversation), a
|
||||
RELOAD in the same context (phase-14 local session) re-renders the
|
||||
persisted tool lines through the SAME ``appendToolLine`` — and they
|
||||
carry NO ``.tool-elapsed`` element (the restore path never arms the
|
||||
clock — the live-only contract), with the page otherwise settled:
|
||||
no ``#typing-indicator``, button "Send", answer intact."""
|
||||
page.set_default_timeout(30_000)
|
||||
_reset_db(_seed)
|
||||
_submit_tools_turn(page, app_url)
|
||||
|
||||
# Let it COMPLETE (answer rendered — the phase-50/55 auto-save
|
||||
# contract).
|
||||
_wait_settled(page)
|
||||
|
||||
# Reload — the same context keeps bor.chat.v1 (the phase-14
|
||||
# restore path).
|
||||
page.reload()
|
||||
expect(page.locator("#empty-state")).to_be_hidden(timeout=RESTORE_TIMEOUT_MS)
|
||||
|
||||
# The persisted record re-renders the tool lines, in saved order
|
||||
# (the phase-37 reload pin, mirrored)…
|
||||
restored = page.locator("#messages .tool-call")
|
||||
expect(restored).to_have_count(2, timeout=RESTORE_TIMEOUT_MS)
|
||||
expect(restored.nth(0)).to_contain_text("Listing documents")
|
||||
expect(restored.nth(1)).to_contain_text("Reading ")
|
||||
expect(restored.nth(1)).to_contain_text(READ_SP)
|
||||
|
||||
# …with NO timer (A6 — the restore never arms the clock) and the
|
||||
# page otherwise settled.
|
||||
expect(page.locator("#messages .tool-elapsed")).to_have_count(0)
|
||||
expect(page.locator("#typing-indicator")).to_have_count(0)
|
||||
expect(page.locator("#send-label")).to_have_text("Send")
|
||||
|
||||
# The answer is intact (phase-14 restore path).
|
||||
bubble = page.locator(".msg.brain .bubble").last
|
||||
expect(bubble).to_contain_text(ANSWER_PREFIX)
|
||||
expect(bubble).to_contain_text(ANSWER_QUOTE)
|
||||
|
||||
Reference in New Issue
Block a user