search-lag.ts · Source

search-lag.tstests/e2e/utils/search-lag.tsraw ← utils20,371 B← Back to the app
1/**
2 * AI Software Factory — E2E index-lag helpers (TASK-0100 req 1 + Backend
3 * Changes + Security).
4 *
5 * These are API / worker-surface helpers (the lag SLAs are measured without a
6 * browser; only `measureCreateLagViaSearchUi` drives the real UI, and
7 * `runSearchIndexBurst` publishes directly to the worker's Redis input stream)
8 * so the lag SLA can be measured deterministically against the REAL pipeline:
9 *
10 *   page write → API publishes `factory:events` → worker stream consumer →
11 *   OpenSearch upsert → query-time permission filter → POST /api/v1/search.
12 *
13 *   - `waitUntilSearchable`   create-side lag (t0 → first hit, 2 s polls, < 30 s)
14 *   - `waitUntilUnsearchable` delete-side  lag (t0 → last hit,  2 s polls, < 30 s)
15 *   - `assertNeverSearchable` permission negative (never visible in a window)
16 *   - `getSearchIndexLag`     the worker's `search-index:lag` metric (worker
17 *                             health server `/health/search-index:lag`)
18 *   - `runSearchIndexBurst`   1k-event burst → worker drains the backlog
19 *   - `measureCreateLagViaSearchUi` UI-side create lag (page via UI → found in
20 *                             the search dialog → exact-page URL)
21 *   - `setPagePrivateDirectDb`the one field no public API sets (Page.isPrivate)
22 *
23 * All lag helpers resolve the measured `lagMs` and the number of 2 s poll
24 * rounds, so a caller can log the curve / attach it to the completion note.
25 */
26import { PrismaClient } from "@prisma/client";
27import { expect, type APIRequestContext, type Locator, type Page } from "@playwright/test";
28 
29/** Index-lag SLA (spec req 1): create + delete must be < 30 s. */
30export const SEARCH_LAG_TIMEOUT_MS = 30_000;
31/** Spec-mandated poll cadence for POST /api/v1/search. */
32export const SEARCH_POLL_INTERVAL_MS = 2_000;
33/**
34 * TASK-0100 S5: the search dialog DEBOUNCES its input (SEARCH_DEBOUNCE_MS =
35 * 225 ms) and then runs the query + suggest fetches, so a result row renders
36 * ≈ 400 ms AFTER `input.fill(...)`. A one-shot `row.isVisible()` immediately
37 * after the fill therefore sees the pre-debounce state (no rows yet) even
38 * when the page IS already searchable (the API finds it in < 2 s) — the
39 * helpers must bound-wait for the row within each poll round.
40 */
41export const SEARCH_ROW_RENDER_WINDOW_MS = 2_500;
42 
43/**
44 * Bounded wait for a search-result row to render (dialog debounce + fetch +
45 * paint). Returns true when the row becomes visible within the window.
46 * Shared by the create-lag UI poll and the click-through re-open so both
47 * honour the dialog's debounce instead of racing it.
48 */
49export async function waitForSearchRow(row: Locator, windowMs: number = SEARCH_ROW_RENDER_WINDOW_MS): Promise<boolean> {
50  try {
51    await expect(row.first()).toBeVisible({ timeout: windowMs });
52    return true;
53  } catch {
54    return false;
55  }
56}
57 
58/**
59 * Plain sleep. `APIRequestContext` has NO `waitForTimeout` (that is a Page /
60 * Locator method) — the polling helpers are browser-free on purpose (they run
61 * against the API/worker surface), so they sleep on `setTimeout`.
62 */
63const sleep = (ms: number): Promise<void> => new Promise((r) => setTimeout(r, ms));
64 
65/** Worker health server port (docs/development/development-guide.md). */
66export const WORKER_HEALTH_URL = process.env.WORKER_HEALTH_URL ?? "http://localhost:4003";
67 
68export interface LagResult {
69  /** Milliseconds from the caller's t0 to the terminal observation. */
70  lagMs: number;
71  /** How many 2 s poll rounds ran before the terminal observation. */
72  polls: number;
73  /** Server-side `tookMs` of the terminal query (cross-check, optional). */
74  tookMs?: number;
75}
76 
77interface SearchEnvelope {
78  data?: { id?: string; docId?: string; url?: string; title?: string; snippet?: string }[];
79  nextCursor?: string | null;
80  tookMs?: number;
81}
82 
83export interface SearchResponse {
84  status: number;
85  rows: SearchEnvelope["data"];
86  tookMs?: number;
87  /** True when the API answered `SEARCH_UNAVAILABLE` (fail-closed). */
88  unavailable?: boolean;
89}
90 
91/**
92 * One POST /api/v1/search (the live TASK-0097 contract: `{ q }` body,
93 * envelope `{ data, nextCursor, tookMs }`).
94 *
95 * "Unavailable" is detected by the `SEARCH_UNAVAILABLE` ERROR CODE, not the
96 * HTTP status: the API's `mapSharedError` propagates the upstream OpenSearch
97 * status (503 when OS is down, but e.g. 400 while the index alias still has
98 * no backing index, 429 on throttling — all fail-closed `SEARCH_UNAVAILABLE`).
99 * Unavailable responses return empty rows + `unavailable: true` — the
100 * polling helpers treat them as "not yet" and keep going to the SLA deadline
101 * (a persistent unavailability then surfaces as the SLA timeout).
102 */
103export async function search(ctx: APIRequestContext, q: string, limit = 10): Promise<SearchResponse> {
104  const res = await ctx.post("/api/v1/search", { data: { q, limit } });
105  if (res.status() !== 200) {
106    const text = await res.text();
107    let code: unknown;
108    try {
109      code = (JSON.parse(text) as { error?: { code?: unknown } }).error?.code;
110    } catch {
111      code = undefined; // non-JSON error body — treat as a hard failure below
112    }
113    if (code === "SEARCH_UNAVAILABLE") return { status: res.status(), rows: [], tookMs: 0, unavailable: true };
114    throw new Error(`search: POST /api/v1/search "${q}" → ${res.status}: ${text.slice(0, 300)}`);
115  }
116  const body = (await res.json()) as SearchEnvelope;
117  return { status: 200, rows: body.data ?? [], tookMs: body.tookMs };
118}
119 
120/**
121 * Does the result set contain the doc? The search `q` is a globally unique
122 * token (a uuid), so a substring match across the serialized rows cannot
123 * false-positive on unrelated docs.
124 */
125function rowsContain(rows: SearchResponse["rows"], q: string): boolean {
126  return (rows ?? []).some((r) => JSON.stringify(r).includes(q));
127}
128 
129/**
130 * Create-side lag (spec req 1 a–d): poll POST /api/v1/search every 2 s from
131 * `t0`, PASS when `q` appears, FAIL after the SLA. Returns the measured lag.
132 */
133export async function waitUntilSearchable(
134  ctx: APIRequestContext,
135  q: string,
136  t0: number,
137  opts: { timeoutMs?: number; intervalMs?: number } = {},
138): Promise<LagResult> {
139  const timeoutMs = opts.timeoutMs ?? SEARCH_LAG_TIMEOUT_MS;
140  const intervalMs = opts.intervalMs ?? SEARCH_POLL_INTERVAL_MS;
141  const deadline = Date.now() + timeoutMs;
142  let polls = 0;
143  let lastStatus = 0;
144  // eslint-disable-next-line no-constant-condition
145  while (true) {
146    polls += 1;
147    const { status, rows, tookMs } = await search(ctx, q).catch(() => ({
148      status: 0,
149      rows: [] as SearchResponse["rows"],
150      tookMs: 0,
151      unavailable: true,
152    }));
153    lastStatus = status;
154    if (rowsContain(rows, q)) {
155      return { lagMs: Date.now() - t0, polls, tookMs };
156    }
157    if (Date.now() >= deadline) {
158      throw new Error(
159        `index lag (create): "${q}" not searchable within ${timeoutMs} ms after ${polls} polls ` +
160          `(last search status ${lastStatus})`,
161      );
162    }
163    await sleep(intervalMs);
164  }
165}
166 
167/**
168 * Delete-side lag (spec req 1 / Tests): the doc was visible; poll until it is
169 * gone (the worker removes the doc on `page.deleted`). Returns the measured
170 * lag from the deletion t0.
171 */
172export async function waitUntilUnsearchable(
173  ctx: APIRequestContext,
174  q: string,
175  t0: number,
176  opts: { timeoutMs?: number; intervalMs?: number } = {},
177): Promise<LagResult> {
178  const timeoutMs = opts.timeoutMs ?? SEARCH_LAG_TIMEOUT_MS;
179  const intervalMs = opts.intervalMs ?? SEARCH_POLL_INTERVAL_MS;
180  const deadline = Date.now() + timeoutMs;
181  let polls = 0;
182  // eslint-disable-next-line no-constant-condition
183  while (true) {
184    polls += 1;
185    const { rows } = await search(ctx, q).catch(() => ({ rows: [] as SearchResponse["rows"] }));
186    if (!rowsContain(rows, q)) {
187      return { lagMs: Date.now() - t0, polls };
188    }
189    if (Date.now() >= deadline) {
190      throw new Error(
191        `index lag (delete): "${q}" still searchable ${timeoutMs} ms after deletion ` +
192          `(the worker must remove the doc on page.deleted)`,
193      );
194    }
195    await sleep(intervalMs);
196  }
197}
198 
199/**
200 * Permission negative (spec Security): a doc that must NEVER be visible to
201 * this viewer — e.g. another member's PRIVATE page — is polled for the whole
202 * window and must return ZERO rows the entire time. Fails the moment the doc
203 * appears.
204 */
205export async function assertNeverSearchable(
206  ctx: APIRequestContext,
207  q: string,
208  opts: { durationMs?: number; intervalMs?: number; description?: string } = {},
209): Promise<{ polls: number }> {
210  const durationMs = opts.durationMs ?? SEARCH_LAG_TIMEOUT_MS;
211  const intervalMs = opts.intervalMs ?? SEARCH_POLL_INTERVAL_MS;
212  const deadline = Date.now() + durationMs;
213  let polls = 0;
214  // eslint-disable-next-line no-constant-condition
215  while (true) {
216    polls += 1;
217    const { rows } = await search(ctx, q).catch(() => ({ rows: [] as SearchResponse["rows"] }));
218    if (rowsContain(rows, q)) {
219      throw new Error(
220        `${opts.description ?? "permission negative"}: "${q}" WAS visible after ${polls} poll(s) — ` +
221          `it must never be found`,
222      );
223    }
224    if (Date.now() >= deadline) break;
225    await sleep(intervalMs);
226  }
227  return { polls };
228}
229 
230// ---------------------------------------------------------------------------
231// UI-side create lag (spec req 1, test 1: "create page (UI) → searchable < 30 s")
232// ---------------------------------------------------------------------------
233 
234export interface CreateLagViaUiOptions {
235  /** Fired once the new page's id is known (read from the post-create URL). */
236  onCreated?: (pageId: string) => void;
237  /** SLA deadline (default 30 s). */
238  timeoutMs?: number;
239}
240 
241/**
242 * Create-side index lag measured through the REAL search UI (spec req 1 /
243 * Tests test 1). Drives the actual browser surface so the event path is the
244 * genuine one (page.created + the page.updated title write → `factory:events`
245 * → worker → OpenSearch):
246 *
247 *   1. navigate to the workspace (`/w/{id}` — the API resolves by id; the
248 *      search dialog scopes by the resolved workspace object, not the param)
249 *   2. click the sidebar "New page" button (aria-label="New page")
250 *   3. type the globally-unique `token` into the title input (aria-label="Page
251 *      title") and blur it so the optimistic title mutation flushes
252 *   4. open the ⌘K dialog, type `token`, and poll (2 s) until a `search-result`
253 *      row containing `token` is visible
254 *
255 * Returns the measured lag (t0 → first visible result row) and fires
256 * `onCreated(pageId)` once the sidebar's `router.push(/page/{id})` has made the
257 * id readable from the URL. The search dialog is CLOSED again before returning
258 * so a caller can re-open it deterministically (the button toggles).
259 */
260export async function measureCreateLagViaSearchUi(
261  page: Page,
262  workspaceId: string,
263  token: string,
264  opts: CreateLagViaUiOptions = {},
265): Promise<LagResult> {
266  const timeoutMs = opts.timeoutMs ?? SEARCH_LAG_TIMEOUT_MS;
267  const intervalMs = SEARCH_POLL_INTERVAL_MS;
268 
269  await page.goto(`/w/${workspaceId}`);
270  const newPageBtn = page.getByRole("button", { name: "New page" });
271  await expect(newPageBtn, 'the sidebar "New page" button').toBeVisible({ timeout: 15_000 });
272 
273  const t0 = Date.now();
274  await newPageBtn.click();
275 
276  // The sidebar creates the page (title "") and router.push's to /page/{id}.
277  const title = page.getByRole("textbox", { name: "Page title" });
278  await expect(title, 'the "Page title" input').toBeVisible({ timeout: 15_000 });
279  await title.click();
280  await title.fill(token);
281  await title.press("Tab"); // blur → flush the optimistic title mutation
282 
283  // The sidebar pushed /w/{slugOrId}/page/{id} — the id is the last segment.
284  const pageId = new URL(page.url()).pathname.split("/").filter(Boolean).pop() ?? "";
285  if (pageId) opts.onCreated?.(pageId);
286 
287  const deadline = t0 + timeoutMs;
288  let polls = 0;
289  const dialog = page.getByTestId("search-dialog");
290  const input = page.getByTestId("search-input");
291  const row = page.getByTestId("search-result").filter({ hasText: token });
292  // eslint-disable-next-line no-constant-condition
293  for (;;) {
294    polls += 1;
295    await page.getByTestId("search-button").click();
296    await expect(dialog).toBeVisible();
297    await input.fill(token);
298    // Bounded wait: the dialog debounces the fill (225 ms) + fetches, so a
299    // one-shot isVisible() always saw the pre-debounce state.
300    const visible = await waitForSearchRow(row);
301    if (visible) {
302      await page.keyboard.press("Escape"); // leave the dialog closed for the caller
303      return { lagMs: Date.now() - t0, polls };
304    }
305    await page.keyboard.press("Escape");
306    if (Date.now() >= deadline) {
307      throw new Error(
308        `measureCreateLagViaSearchUi: "${token}" not found in the search UI within ` +
309          `${timeoutMs} ms after ${polls} polls`,
310      );
311    }
312    await sleep(intervalMs);
313  }
314}
315 
316// ---------------------------------------------------------------------------
317// Worker consumer-lag metric (search-index:lag) — the burst assertion
318// ---------------------------------------------------------------------------
319 
320export interface SearchIndexLag {
321  metric: "search-index:lag";
322  /** False when the endpoint is missing / the worker predates TASK-0100. */
323  available: boolean;
324  /** Delivered to the group but not ACKed (in-flight / redelivery). */
325  pending: number;
326  /** Stream entries not yet delivered to the group (tail − last-delivered). */
327  lagEntries: number;
328  /** pending + lagEntries — the backlog the burst assertion drains. */
329  backlog: number;
330}
331 
332/**
333 * Read `GET /health/search-index:lag` from the worker health server.
334 * Resolves `{ available: false, ... }` (never throws) when the worker does not
335 * expose the metric — callers skip the assertion instead of failing the run.
336 */
337export async function getSearchIndexLag(): Promise<SearchIndexLag> {
338  const fallback: SearchIndexLag = {
339    metric: "search-index:lag",
340    available: false,
341    pending: 0,
342    lagEntries: 0,
343    backlog: 0
344  };
345  try {
346    const res = await fetch(`${WORKER_HEALTH_URL}/health/search-index:lag`, {
347      signal: AbortSignal.timeout(5_000)
348    });
349    if (res.status !== 200) return fallback;
350    const body = (await res.json()) as Partial<SearchIndexLag>;
351    if (typeof body.available !== "boolean") return fallback;
352    return {
353      metric: "search-index:lag",
354      available: body.available,
355      pending: body.pending ?? 0,
356      lagEntries: body.lagEntries ?? 0,
357      backlog: body.backlog ?? 0
358    };
359  } catch {
360    return fallback;
361  }
362}
363 
364export interface BurstResult {
365  /** Number of events published to the stream. */
366  published: number;
367  /** Wall-clock ms to XADD the whole burst. */
368  burstMs: number;
369  /** Wall-clock ms from burst start to backlog === 0 (the drain). */
370  drainMs: number;
371  /** Per-interval backlog samples (tMs from burst start; -1 = unavailable). */
372  samples: { tMs: number; backlog: number }[];
373}
374 
375/**
376 * Burst assertion (spec Backend Changes: "verify the worker consumes a 1k-event
377 * burst without backlog growth > 30 s — assert in the lag suite via the
378 * consumer-lag metric `search-index:lag`").
379 *
380 * The events are published DIRECTLY to the worker's input stream
381 * (`factory:events`) as real `page.updated` envelopes referencing `pageIds` —
382 * each one makes the worker run a genuine re-index (DB read + OpenSearch
383 * upsert), so this is real indexing load, not a no-op. Publishing to the
384 * stream (rather than through the public API) is deliberate: the API's
385 * per-user rate limit (100/min) makes a true 1k-event burst infeasible via
386 * HTTP, while the stream is the worker's actual input and exactly what the
387 * `search-index:lag` metric observes. `pageIds` must be REAL pages (created
388 * via the API first) so the events take the index path, not the
389 * missing-source (poison) path.
390 *
391 * The assertion: after XADD-ing `count` events, the worker's backlog
392 * (`pending + lagEntries` from `/health/search-index:lag`) must reach 0
393 * within the SLA (default 30 s). Throws with the backlog curve on failure.
394 */
395export async function runSearchIndexBurst(opts: {
396  /** Redis DSN (CI e2e job env / local dev .env; default redis://localhost:6379). */
397  redisUrl?: string;
398  /** Real page ids to cycle the `page.updated` events over. */
399  pageIds: string[];
400  workspaceId: string;
401  /** Burst size (spec: 1000). */
402  count?: number;
403  timeoutMs?: number;
404  intervalMs?: number;
405}): Promise<BurstResult> {
406  const { redisUrl, pageIds, workspaceId } = opts;
407  const count = opts.count ?? 1_000;
408  const timeoutMs = opts.timeoutMs ?? SEARCH_LAG_TIMEOUT_MS;
409  const intervalMs = opts.intervalMs ?? SEARCH_POLL_INTERVAL_MS;
410  if (pageIds.length === 0) throw new Error("runSearchIndexBurst: pageIds must be non-empty");
411 
412  // Lazy import so the rest of the helper (used by the non-burst tests) loads
413  // without a Redis dependency at module-eval time.
414  const { default: Redis } = await import("ioredis");
415  const redis = new Redis(redisUrl ?? process.env.REDIS_URL ?? "redis://localhost:6379", {
416    maxRetriesPerRequest: 2,
417    lazyConnect: true
418  });
419 
420  const t0 = Date.now();
421  let burstMs = 0;
422  try {
423    await redis.connect().catch(() => {
424      throw new Error(
425        `runSearchIndexBurst: cannot connect to Redis (${redisUrl ?? process.env.REDIS_URL ?? "redis://localhost:6379"}) ` +
426          `— the burst assertion needs the worker's Redis`,
427      );
428    });
429    const STREAM = "factory:events";
430    // One pipeline, `count` XADDs (fast — a single round-trip).
431    const pipe = redis.pipeline();
432    for (let i = 0; i < count; i += 1) {
433      const pageId = pageIds[i % pageIds.length];
434      const payload = JSON.stringify({ workspaceId, pageId, fields: ["title"] });
435      pipe.xadd(STREAM, "*", "event", "page.updated", "payload", payload, "ts", new Date().toISOString());
436    }
437    const started = Date.now();
438    await pipe.exec();
439    burstMs = Date.now() - started;
440  } finally {
441    redis.disconnect();
442  }
443 
444  // Drain: poll the worker's lag metric until the backlog is 0.
445  const samples: BurstResult["samples"] = [];
446  // eslint-disable-next-line no-constant-condition
447  while (true) {
448    const lag = await getSearchIndexLag();
449    samples.push({ tMs: Date.now() - t0, backlog: lag.available ? lag.backlog : -1 });
450    if (lag.available && lag.backlog === 0) {
451      return { published: count, burstMs, drainMs: Date.now() - t0, samples };
452    }
453    if (Date.now() - t0 >= timeoutMs) {
454      const curve = samples.map((s) => `${s.tMs}ms:${s.backlog}`).join(" ");
455      throw new Error(
456        `worker backlog did not drain within ${timeoutMs} ms after a ${count}-event burst ` +
457          `(search-index:lag samples tMs:backlog = ${curve}; -1 = endpoint unavailable)`,
458      );
459    }
460    await new Promise((r) => setTimeout(r, intervalMs));
461  }
462}
463 
464// ---------------------------------------------------------------------------
465// Private-page seam (TASK-0100 Security negative)
466// ---------------------------------------------------------------------------
467 
468/**
469 * Direct-DB write for the ONE field no public API sets: `Page.isPrivate`
470 * (UpdatePageDto has no privacy field — recorded quirk; the Phase-9 privacy UI
471 * is the intended surface). The spec's negative test needs a private page
472 * owned by one member that another member must NEVER find; only a source-row
473 * write produces the correct `isPrivate` grant snapshot (the worker stamps it
474 * from the row at index time; an API `page.updated` right after re-stamps it).
475 *
476 * Requires `DATABASE_URL` (CI e2e job env / local dev .env).
477 */
478export async function setPagePrivateDirectDb(pageId: string, isPrivate: boolean): Promise<boolean> {
479  const dsn = process.env.DATABASE_URL;
480  if (!dsn) {
481    throw new Error(
482      "setPagePrivateDirectDb: DATABASE_URL is not set — the private-page " +
483        "negative test needs the DB DSN (CI e2e job sets it; local dev .env).",
484    );
485  }
486  const prisma = new PrismaClient({ datasources: { db: { url: dsn } } });
487  try {
488    const updated = await prisma.page.update({
489      where: { id: pageId },
490      data: { isPrivate },
491      select: { isPrivate: true }
492    });
493    expect(updated.isPrivate, `setPagePrivateDirectDb(${pageId}): DB write`).toBe(isPrivate);
494    return updated.isPrivate;
495  } finally {
496    await prisma.$disconnect();
497  }
498}
499