🤖 tests: record in-page perf milestones for workspace open

tests/e2e/scenarios/perf.workspaceOpen.spec.ts

@@ -1,6 +1,11 @@
 import { electronTest as test, electronExpect as expect } from "../electronTest";
 import { getXumE2EEnv } from "../env";
 import { parseHistoryProfilesFromEnv, seedWorkspaceHistoryProfile } from "../utils/historyFixture";
+import {
+  readPageMilestones,
+  startPageMilestones,
+  type PageMilestones,
+} from "../utils/pageMilestones";
 import {
   readReactProfileSnapshot,
   resetReactProfileSamples,
@@ -33,12 +38,18 @@ test.describe("workspace open performance profiling", () => {
       await resetReactProfileSamples(page);
 
       const runLabel = `workspace-open-${profile}`;
+      let milestones: PageMilestones | undefined;
       const chromeProfile = await withChromeProfiles(page, { label: runLabel }, async () => {
+        await startPageMilestones(page);
         await ui.projects.openFirstWorkspace();
         await expect(page.getByTestId("message-window")).toHaveAttribute("data-loaded", "true", {
           timeout: 20_000,
         });
+        milestones = await readPageMilestones(page);
       });
+      if (!milestones) {
+        throw new Error("Page milestones were not captured");
+      }
 
       const reactProfileSnapshot = await readReactProfileSnapshot(page);
       if (!reactProfileSnapshot) {
@@ -51,9 +62,12 @@ test.describe("workspace open performance profiling", () => {
         chromeProfile,
         reactProfile: reactProfileSnapshot,
         historyProfile: historySummary,
+        milestones,
       });
 
       expect(chromeProfile.wallTimeMs).toBeGreaterThan(0);
+      // The assertion above saw data-loaded, so the in-page observer must have too.
+      expect(milestones.fullyLoadedMs).not.toBeNull();
       expect(chromeProfile.cpuProfile).not.toBeNull();
       const interestingRenderPaths = [
         "chat-pane",

tests/e2e/utils/pageMilestones.ts

@@ -0,0 +1,126 @@
+import type { Page } from "@playwright/test";
+
+/**
+ * In-page milestone timing for perf scenarios.
+ *
+ * Why (#4441): Playwright's `expect(...).toHave*` assertions poll with backoff
+ * (+100/+250/+500/+1000 ms). Wall time measured when an assertion passes is therefore
+ * quantized, and it jumps whenever a milestone moves later. After #4293 made `data-loaded`
+ * wait for the full tail-first reveal, the gap between the real flip and the passing poll
+ * grew from ~27 ms to ~423 ms, and it read as a regression. These timestamps come from
+ * the page's own clock at the DOM change instead.
+ */
+export interface PageMilestones {
+  /** ms from start until the first transcript row exists ("useful content ready"). */
+  firstMessageMs: number | null;
+  /** ms from start until the message window reports data-loaded="true" ("fully revealed"). */
+  fullyLoadedMs: number | null;
+  /** Longest main-thread task after start, in ms. 0 when no task exceeded the 50 ms long-task floor. */
+  longestTaskMs: number;
+}
+
+const STATE_KEY = "__xumPerfMilestones";
+const FIRST_MESSAGE_SELECTOR = '[data-testid="message-window"] [data-testid="chat-message"]';
+const FULLY_LOADED_SELECTOR = '[data-testid="message-window"][data-loaded="true"]';
+
+interface MilestoneState extends PageMilestones {
+  stop: () => void;
+}
+
+/** Start recording milestones. Call immediately before the action being measured. */
+export async function startPageMilestones(page: Page): Promise<void> {
+  await page.evaluate(
+    ({ stateKey, firstSelector, loadedSelector }) => {
+      const host = window as unknown as Record<string, MilestoneState | undefined>;
+      if (host[stateKey]) {
+        throw new Error("Page milestones already started; call readPageMilestones first");
+      }
+      // A milestone that is already true at start would record 0 and silently measure nothing.
+      if (document.querySelector(loadedSelector)) {
+        throw new Error("Message window is already loaded; the milestone would be meaningless");
+      }
+
+      const t0 = performance.now();
+      const state: MilestoneState = {
+        firstMessageMs: null,
+        fullyLoadedMs: null,
+        longestTaskMs: 0,
+        stop: () => undefined,
+      };
+
+      // MutationObserver callbacks run as a microtask after the DOM change, in the same task,
+      // so the timestamp is not quantized by any polling interval.
+      const mutationObserver = new MutationObserver(() => {
+        const elapsed = performance.now() - t0;
+        if (state.firstMessageMs === null && document.querySelector(firstSelector)) {
+          state.firstMessageMs = elapsed;
+        }
+        if (state.fullyLoadedMs === null && document.querySelector(loadedSelector)) {
+          state.fullyLoadedMs = elapsed;
+        }
+        if (state.firstMessageMs !== null && state.fullyLoadedMs !== null) {
+          mutationObserver.disconnect();
+        }
+      });
+      mutationObserver.observe(document.body, {
+        subtree: true,
+        childList: true,
+        attributes: true,
+        attributeFilter: ["data-loaded"],
+      });
+
+      const recordLongTasks = (entries: PerformanceEntryList) => {
+        for (const entry of entries) {
+          state.longestTaskMs = Math.max(state.longestTaskMs, entry.duration);
+        }
+      };
+      const longTaskObserver = new PerformanceObserver((list) =>
+        recordLongTasks(list.getEntries())
+      );
+      longTaskObserver.observe({ type: "longtask" });
+
+      state.stop = () => {
+        mutationObserver.disconnect();
+        // Long-task entries are delivered asynchronously; drain the queue so the last
+        // task before the read is not missed.
+        recordLongTasks(longTaskObserver.takeRecords());
+        longTaskObserver.disconnect();
+      };
+      host[stateKey] = state;
+    },
+    {
+      stateKey: STATE_KEY,
+      firstSelector: FIRST_MESSAGE_SELECTOR,
+      loadedSelector: FULLY_LOADED_SELECTOR,
+    }
+  );
+}
+
+/** Stop recording and return the milestones. */
+export async function readPageMilestones(page: Page): Promise<PageMilestones> {
+  const milestones = await page.evaluate((stateKey) => {
+    const host = window as unknown as Record<string, MilestoneState | undefined>;
+    const state = host[stateKey];
+    if (!state) {
+      throw new Error("Page milestones were not started");
+    }
+    state.stop();
+    delete host[stateKey];
+    return {
+      firstMessageMs: state.firstMessageMs,
+      fullyLoadedMs: state.fullyLoadedMs,
+      longestTaskMs: state.longestTaskMs,
+    };
+  }, STATE_KEY);
+
+  if (
+    milestones.firstMessageMs !== null &&
+    milestones.fullyLoadedMs !== null &&
+    milestones.firstMessageMs > milestones.fullyLoadedMs
+  ) {
+    throw new Error(
+      `Impossible milestone order: first message at ${milestones.firstMessageMs} ms after full load at ${milestones.fullyLoadedMs} ms`
+    );
+  }
+  return milestones;
+}

tests/e2e/utils/perfProfile.ts

@@ -2,6 +2,7 @@ import fsPromises from "fs/promises";
 import path from "path";
 import { type Page, type TestInfo } from "@playwright/test";
 import type { CDPSession } from "playwright";
+import type { PageMilestones } from "./pageMilestones";
 
 const PERF_ARTIFACTS_ROOT = path.resolve(__dirname, "..", "..", "..", "artifacts", "perf");
 const DEFAULT_TRACE_CATEGORIES = [
@@ -277,6 +278,8 @@ export async function writePerfArtifacts(args: {
   chromeProfile: ChromeProfileCapture;
   reactProfile: unknown;
   historyProfile: unknown;
+  /** In-page milestone timings, for scenarios that record them (see pageMilestones.ts). */
+  milestones?: PageMilestones;
 }): Promise<string> {
   const timestamp = new Date().toISOString().replace(/[.:]/g, "-");
   const runDirName = `${sanitizeForPath(args.runLabel)}-${timestamp}`;
@@ -308,6 +311,8 @@ export async function writePerfArtifacts(args: {
       retry: args.testInfo.retry,
     },
     historyProfile: args.historyProfile,
+    // Additive field: schemaVersion stays 1 because existing readers ignore unknown keys.
+    ...(args.milestones ? { milestones: args.milestones } : {}),
     chromeProfile: {
       label: args.chromeProfile.label,
       startedAt: args.chromeProfile.startedAt,