diff --git a/.eslintignore b/.eslintignore index cbea34f25..425ddf293 100644 --- a/.eslintignore +++ b/.eslintignore @@ -45,3 +45,6 @@ e2e-tests/test-results # A verbatim copy of the template's manifest, kept byte-for-byte so `npm run template:baseline` can # write it straight from `git show` rather than a copy plus whatever our tooling would impose on it scripts/merged-template-package.json + +# Captured text and generated datasets for the performance harness +perf/.cache diff --git a/.gitignore b/.gitignore index 4a391479d..da067cee5 100644 --- a/.gitignore +++ b/.gitignore @@ -40,6 +40,10 @@ temp-build # Playwright output e2e-tests/.cdp-* e2e-tests/.dev-* +e2e-tests/.perf-* e2e-tests/.e2e-settings-backup* e2e-tests/playwright-report e2e-tests/test-results + +# Captured text and generated datasets for the performance harness +perf/.cache diff --git a/.prettierignore b/.prettierignore index 53cf3e5e7..01ac2d845 100644 --- a/.prettierignore +++ b/.prettierignore @@ -45,3 +45,6 @@ e2e-tests/test-results # A verbatim copy of the template's manifest, kept byte-for-byte so `npm run template:baseline` can # write it straight from `git show` rather than a copy plus whatever our tooling would impose on it scripts/merged-template-package.json + +# Captured text and generated datasets for the performance harness +perf/.cache diff --git a/AGENTS.md b/AGENTS.md index 9805e188c..51001799d 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -23,6 +23,14 @@ npm test # Run full Jest suite npm run test:coverage # Run with coverage (100% threshold enforced) npm test -- path/to/file.test.ts # Run a single test file npm test -- --testNamePattern="pattern" # Run tests matching name + +# Performance (results land in perf/results/) +npm run perf:capture # Capture the WEB sample's USJ from a launched app into perf/.cache +npm run perf:datasets # Generate the seeded dataset tiers (captures first if needed) +npm run perf:bench # Time the data layer's pure functions in Node +npm run perf:app # Production-build the extension and time it, WebView and extension host, in the app +npm run perf:summary # Render the newest results as markdown tables +npm run perf:shape # Compare analysis shape across tiers and stored projects ``` Only a template merge moves the dependency baseline `npm run lint:dependencies` checks against; refresh it in that same commit with `npm run template:baseline`, which writes both the copy and the `MERGED_TEMPLATE_COMMIT` id recorded beside it in [scripts/check-dependency-scope.cjs](scripts/check-dependency-scope.cjs). [README.md](README.md) has the full procedure. diff --git a/README.md b/README.md index 57f9fbec5..bae694053 100644 --- a/README.md +++ b/README.md @@ -191,34 +191,21 @@ npm run test:coverage # run with coverage report (output to coverage/) ### End-to-end tests -E2E tests use [Playwright](https://playwright.dev/) and live in `e2e-tests/`. They launch Platform.Bible with this extension loaded and verify behavior through the real UI. - -**Prerequisites:** - -- `npm run build` must have been run (`dist/src/main.js` must exist) -- `paranext-core` must have deps installed (e.g., with `npm run core:install`) - -**Smoke tests** (self-contained, good for CI — launches and tears down Platform.Bible automatically): +E2E tests use [Playwright](https://playwright.dev/) and live in `e2e-tests/`. They launch Platform.Bible with this extension loaded and verify behavior through the real UI. Global setup builds the extension first; `paranext-core` must have deps installed (e.g., with `npm run core:install`). ```bash -npm run test:e2e:smoke +npm run test:e2e # smoke tests, then CDP feature tests +npm run test:e2e:smoke # smoke tests only +npm run test:e2e:cdp # CDP feature tests only ``` -**CDP tests** (connect to an already-running app — faster for local development): - -1. Start Platform.Bible with remote debugging enabled: - - ```bash - npm run start:cdp - ``` +Each tier launches its own Platform.Bible instance and tears it down afterward. To iterate against a warm instance, run `npm run start:cdp` first; the CDP tier reuses it and leaves it running. -2. In a second terminal, run the tests: +New feature tests should use `cdp.fixture` and navigate entirely through visible UI. See `e2e-tests/tests/_example/` for a reference template, and [e2e-tests/README.md](e2e-tests/README.md) for the full protocol. - ```bash - npm run test:e2e:cdp - ``` +### Performance -New feature tests should use `cdp.fixture` and navigate entirely through visible UI. See `e2e-tests/tests/_example/` for a reference template. +The performance harness times the data layer in Node and the extension in the app. See [perf/README.md](perf/README.md). ## Publishing diff --git a/e2e-tests/README.md b/e2e-tests/README.md index e9bcfe4d0..c32218321 100644 --- a/e2e-tests/README.md +++ b/e2e-tests/README.md @@ -23,6 +23,10 @@ To reproduce the Linux CI run locally before pushing, run `npm run test:e2e:head - `playwright*.config.ts` — fixture configs - `tests/` — tests, including a smoke test and a test template +## Performance harness + +`playwright-perf.config.ts` and `tests/perf/` measure the extension rather than test it; see [perf/README.md](../perf/README.md). + ## Key differences from `paranext-core/e2e-tests/` These tests are adapted from `paranext-core`'s e2e suite with changes to support testing a side-loaded extension rather than the core platform itself: diff --git a/e2e-tests/global-setup-cdp.ts b/e2e-tests/global-setup-cdp.ts index 6f7b4475f..f05435ee8 100644 --- a/e2e-tests/global-setup-cdp.ts +++ b/e2e-tests/global-setup-cdp.ts @@ -320,7 +320,7 @@ async function cleanUpFailedLaunch( * @throws {Error} If no renderer page appears, tab titles do not resolve, or the extension does not * activate within `timeout`. */ -async function waitForRendererSettled(timeout: number): Promise { +export async function waitForRendererSettled(timeout: number): Promise { const deadline = Date.now() + timeout; const browser = await chromium.connectOverCDP(`http://localhost:${CDP_PORT}`, { timeout: 30_000, diff --git a/e2e-tests/global-setup-perf.ts b/e2e-tests/global-setup-perf.ts new file mode 100644 index 000000000..9a163473c --- /dev/null +++ b/e2e-tests/global-setup-perf.ts @@ -0,0 +1,65 @@ +import type { FullConfig } from '@playwright/test'; +import fs from 'fs'; +import path from 'path'; +import { execSync } from 'child_process'; +import globalSetupCdp, { CDP_PORT } from './global-setup-cdp'; +import { isPortInUse, WEBSOCKET_PORT } from './global-setup'; +import globalTeardownCdp from './global-teardown-cdp'; +import { launchPackagedApp, PACKAGED_APP_PATH, stopPackagedApp } from './perf-app'; + +/** The development host's storage for this extension's projects and drafts. */ +const STORAGE_DIR = path.resolve( + __dirname, + '../../paranext-core/dev-appdata/extensions/interlinearizer/user-data', +); + +/** Where the developer's storage waits out a run. */ +const STORAGE_BACKUP_DIR = `${STORAGE_DIR}.perf-backup`; + +/** Puts back storage a run set aside, discarding what the run stored. */ +function restoreStorage(): void { + if (!fs.existsSync(STORAGE_BACKUP_DIR)) return; + fs.rmSync(STORAGE_DIR, { recursive: true, force: true }); + fs.renameSync(STORAGE_BACKUP_DIR, STORAGE_DIR); +} + +/** + * Launches the app as the CDP tier does, but over empty extension storage, so listing projects + * reads only what the run seeds and the developer's drafts and projects stay untouched. With + * `PERF_APP_PATH` set it builds the extension and launches that packaged app in its own home. + * + * @returns The run's teardown, which stops the app and gives back the storage set aside. + * @throws {Error} If Platform.Bible is already running, since it may own the storage a run sets + * aside. + */ +export default async function globalSetupPerf(config: FullConfig): Promise<() => Promise> { + if ((await isPortInUse(CDP_PORT)) || (await isPortInUse(WEBSOCKET_PORT))) { + throw new Error( + "Platform.Bible is already running. Quit it, or a previous run's app, so the run gets an app and storage of its own.", + ); + } + if (PACKAGED_APP_PATH) { + const buildScript = process.env.E2E_BUILD_SCRIPT ?? 'build:production'; + execSync(`npm run ${buildScript}`, { cwd: path.resolve(__dirname, '..'), stdio: 'inherit' }); + await launchPackagedApp(); + return stopPackagedApp; + } + // A crashed run leaves its backup in place; put it back before setting storage aside again. + restoreStorage(); + fs.mkdirSync(STORAGE_DIR, { recursive: true }); + fs.renameSync(STORAGE_DIR, STORAGE_BACKUP_DIR); + try { + fs.mkdirSync(STORAGE_DIR); + await globalSetupCdp(config); + } catch (error) { + restoreStorage(); + throw error; + } + return async () => { + try { + await globalTeardownCdp(config); + } finally { + restoreStorage(); + } + }; +} diff --git a/e2e-tests/global-setup.ts b/e2e-tests/global-setup.ts index b0a2d6f6a..71106b149 100644 --- a/e2e-tests/global-setup.ts +++ b/e2e-tests/global-setup.ts @@ -191,8 +191,10 @@ export async function bootstrapRendererDevServer(): Promise { // extension the tests were not written against, and the selector mismatches that follow read as // real regressions rather than a build problem. A no-op rebuild costs seconds against a // multi-minute run, so always paying it is cheaper than ever debugging the stale case. - console.log('Building the extension...'); - execSync('npm run build', { cwd: extensionRoot, stdio: 'inherit' }); + // E2E_BUILD_SCRIPT names another build script, such as a production build. + const buildScript = process.env.E2E_BUILD_SCRIPT ?? 'build'; + console.log(`Building the extension (npm run ${buildScript})...`); + execSync(`npm run ${buildScript}`, { cwd: extensionRoot, stdio: 'inherit' }); // Ensure the paranext-core dev main bundle exists const devMainPath = path.join(coreDir, '.erb/dll/main.bundle.dev.js'); diff --git a/e2e-tests/perf-app.ts b/e2e-tests/perf-app.ts new file mode 100644 index 000000000..170970822 --- /dev/null +++ b/e2e-tests/perf-app.ts @@ -0,0 +1,172 @@ +import { chromium } from '@playwright/test'; +import { spawn } from 'child_process'; +import fs from 'fs'; +import os from 'os'; +import path from 'path'; +import { CACHE_DIR } from '../perf/paths'; +import { CDP_PORT, waitForRendererSettled } from './global-setup-cdp'; +import { isPortInUse, waitForPort, WEBSOCKET_PORT } from './global-setup'; +import { E2E_SETTINGS_OVERRIDES } from './fixtures/helpers'; +import { killProcessTree, waitForPidExit } from './process-utils'; + +/** Path to a packaged app's executable; set, it is what the harness launches. */ +export const PACKAGED_APP_PATH = process.env.PERF_APP_PATH; + +/** Home the packaged app runs under, apart from the developer's profile and kept across restarts. */ +export const PERF_HOME_DIR = path.join(CACHE_DIR, 'app-home'); + +/** Display backend the app runs on under Linux, overridable with `PERF_OZONE_PLATFORM`. */ +export const OZONE_PLATFORM = + process.platform === 'linux' ? (process.env.PERF_OZONE_PLATFORM ?? 'x11') : undefined; + +const PID_FILE = path.join(__dirname, '.perf-app.pid'); + +/** Where the launched app's output goes, overwritten by each launch. */ +export const PERF_APP_LOG_FILE = path.join(__dirname, '.perf-app.log'); + +const READY_TIMEOUT = 5 * 60_000; + +const QUIT_TIMEOUT = 60_000; + +/** Prepares the packaged app's home and seeds the settings every e2e launch forces. */ +function seedSettings(): void { + // .NET reports a special folder that does not exist yet as an empty path. Windows resolves + // AppData under USERPROFILE; when it is missing, Electron cannot take its single-instance lock + // and the app quits as if another instance held it. + ['.config', '.local/share', 'AppData/Roaming', 'AppData/Local'].forEach((dir) => + fs.mkdirSync(path.join(PERF_HOME_DIR, dir), { recursive: true }), + ); + const file = path.join(PERF_HOME_DIR, '.platform.bible', 'data', 'settings.json'); + fs.mkdirSync(path.dirname(file), { recursive: true }); + const current: Record = fs.existsSync(file) + ? JSON.parse(fs.readFileSync(file, 'utf-8')) + : {}; + fs.writeFileSync(file, JSON.stringify({ ...current, ...E2E_SETTINGS_OVERRIDES }, undefined, 2)); +} + +/** + * Launches the packaged app with the built extension and remote debugging, then waits until the + * extension is ready. + * + * @returns Milliseconds from spawning the app to its being ready. + * @throws If the app is already running, exits during startup, or is not ready in time. + */ +export async function launchPackagedApp(): Promise { + if (!PACKAGED_APP_PATH) throw new Error('PERF_APP_PATH names no packaged app'); + if ((await isPortInUse(WEBSOCKET_PORT)) || (await isPortInUse(CDP_PORT))) + throw new Error('Platform.Bible is already running'); + seedSettings(); + + // eslint-disable-next-line @typescript-eslint/no-unused-vars + const { ELECTRON_RUN_AS_NODE, ...restEnv } = process.env; + const logFd = fs.openSync(PERF_APP_LOG_FILE, 'w'); + const started = Date.now(); + let app: ReturnType; + try { + app = spawn( + PACKAGED_APP_PATH, + [ + '--extensions', + path.resolve(__dirname, '../dist'), + `--remote-debugging-port=${CDP_PORT}`, + '--window-size', + '1280x960', + ...(process.platform === 'linux' + ? ['--no-sandbox', `--ozone-platform=${OZONE_PLATFORM}`] + : []), + ], + { + env: { + ...restEnv, + HOME: PERF_HOME_DIR, + // Windows takes the home folder from here, and its data provider ignores both variables. + USERPROFILE: PERF_HOME_DIR, + PLATFORM_BIBLE_PROJECT_ROOT_FOLDER: path.join( + PERF_HOME_DIR, + '.platform.bible', + 'projects', + 'Paratext 9 Projects', + ), + // Display authority usually lives in the real home, which the app cannot see. + ...(fs.existsSync(path.join(os.homedir(), '.Xauthority')) && !process.env.XAUTHORITY + ? { XAUTHORITY: path.join(os.homedir(), '.Xauthority') } + : {}), + }, + stdio: ['ignore', logFd, logFd], + detached: true, + }, + ); + } finally { + fs.closeSync(logFd); + } + app.unref(); + if (app.pid) fs.writeFileSync(PID_FILE, String(app.pid)); + + const exited = new Promise((_resolve, reject) => { + app.once('exit', (code, signal) => + reject(new Error(`The packaged app exited during startup (code=${code}, signal=${signal})`)), + ); + app.once('error', reject); + }); + exited.catch(() => {}); + try { + await Promise.race([waitForPort(WEBSOCKET_PORT, READY_TIMEOUT), exited]); + await Promise.race([waitForPort(CDP_PORT, READY_TIMEOUT), exited]); + await Promise.race([waitForRendererSettled(READY_TIMEOUT), exited]); + } catch (error) { + await stopPackagedApp(); + throw error; + } + return Date.now() - started; +} + +/** Asks the app to quit as a user would, so it saves its layout. */ +async function requestQuit(): Promise { + const browser = await chromium.connectOverCDP(`http://localhost:${CDP_PORT}`, { + timeout: 10_000, + }); + try { + const page = browser + .contexts() + .flatMap((context) => context.pages()) + .find((p) => !p.url().startsWith('devtools://')); + // The app may close the connection before the command answers. + await page?.evaluate(() => window.papi.commands.sendCommand('platform.quit')).catch(() => {}); + } finally { + await browser.close().catch(() => {}); + } +} + +function isAlive(pid: number): boolean { + try { + process.kill(pid, 0); + return true; + } catch { + return false; + } +} + +/** Stops the packaged app this harness launched, if it is running. */ +export async function stopPackagedApp(): Promise { + if (!fs.existsSync(PID_FILE)) return; + const pid = Number(fs.readFileSync(PID_FILE, 'utf-8')); + try { + await requestQuit(); + } catch { + // Not reachable over CDP; the kill below still stops it. + } + await waitForPidExit(pid, QUIT_TIMEOUT); + if (isAlive(pid)) { + killProcessTree(pid, 'SIGKILL'); + await waitForPidExit(pid, 10_000); + } + // The next launch needs the websocket port free. + const deadline = Date.now() + QUIT_TIMEOUT; + while (Date.now() < deadline && (await isPortInUse(WEBSOCKET_PORT))) { + // eslint-disable-next-line no-await-in-loop + await new Promise((resolve) => { + setTimeout(resolve, 250); + }); + } + fs.rmSync(PID_FILE, { force: true }); +} diff --git a/e2e-tests/playwright-cdp.config.ts b/e2e-tests/playwright-cdp.config.ts index 48b8d90d8..7a0a73a48 100644 --- a/e2e-tests/playwright-cdp.config.ts +++ b/e2e-tests/playwright-cdp.config.ts @@ -13,7 +13,7 @@ import { defineConfig } from '@playwright/test'; */ export default defineConfig({ testDir: './tests', - testIgnore: ['**/smoke/**', '**/_example/**'], + testIgnore: ['**/smoke/**', '**/_example/**', '**/perf/**'], fullyParallel: false, forbidOnly: !!process.env.CI, // Retries help on the never-reset shared instance only because each test self-heals leftover diff --git a/e2e-tests/playwright-perf.config.ts b/e2e-tests/playwright-perf.config.ts new file mode 100644 index 000000000..80da6dd3c --- /dev/null +++ b/e2e-tests/playwright-perf.config.ts @@ -0,0 +1,23 @@ +import { defineConfig } from '@playwright/test'; + +/** + * Playwright configuration for the performance harness. It launches its own Platform.Bible as the + * CDP feature tier does, over empty extension storage, and never retries a spec: a retried + * measurement would be a different measurement. + */ +export default defineConfig({ + testDir: './tests/perf', + fullyParallel: false, + workers: 1, + retries: 0, + reporter: [['list']], + timeout: 60 * 60_000, + expect: { timeout: 30_000 }, + use: { actionTimeout: 30_000 }, + globalSetup: './global-setup-perf.ts', + outputDir: './test-results/perf', + projects: [ + { name: 'capture', testMatch: /capture-usj\.spec\.ts/ }, + { name: 'app', testMatch: /app-perf\.spec\.ts/ }, + ], +}); diff --git a/e2e-tests/tests/perf/app-perf.spec.ts b/e2e-tests/tests/perf/app-perf.spec.ts new file mode 100644 index 000000000..a71845e17 --- /dev/null +++ b/e2e-tests/tests/perf/app-perf.spec.ts @@ -0,0 +1,439 @@ +import type { Browser, Frame, Page } from '@playwright/test'; +import path from 'path'; +import { readDraftJson, readManifest } from '../../../perf/dataset/store'; +import { TIERS, type TierSpec } from '../../../perf/dataset/tiers'; +import { provenance, writeResults } from '../../../perf/results'; +import { readCaptureMeta } from '../../../perf/usj-cache'; +import { expect, test } from '../../fixtures/cdp.fixture'; +import { waitForAppAndInterlinearizerReady } from '../../fixtures/helpers'; +import { + launchPackagedApp, + OZONE_PLATFORM, + PACKAGED_APP_PATH, + stopPackagedApp, +} from '../../perf-app'; +import type { HostHeap } from './host-inspector'; +import { + clearMeasures, + closeView, + connect, + HOST_CALLS, + hostHeap, + heapUsed, + MAX_WEBSOCKET_PAYLOAD_BYTES, + type Measure, + openView, + PERF_MARKS_KEY, + Samples, + scenarioSamples, + type ScenarioSamples, + sendCommand, + setBook, + setHostPerfMarks, + sourceProjectId, + takeHostEntries, + waitForMeasure, + wireBytes, +} from './view-driver'; + +const RUNS = Number(process.env.PERF_RUNS ?? 10); + +/** Edits made before reading the heap, enough to fill the undo history. */ +const UNDO_FILL_EDITS = 100; + +/** Book the book-switch scenario leaves for before returning, short so its load stays cheap. */ +const AWAY_BOOK = 'JUD'; + +/** Names the saved projects a run seeds, so a later run can recognize them. */ +const SAVED_PROJECT_NAME = /^Perf [a-z-]+ \d+$/; + +/** Tries at picking a menu item before a run gives up on it. */ +const MENU_ATTEMPTS = 3; + +/** The app a run drives; restarting a packaged app replaces its connection. */ +type App = { page: Page; browser?: Browser }; + +function tokenGlossInputs(frame: Frame) { + return frame.locator('input[aria-label^="Gloss for "]:not([aria-label^="Gloss for morpheme"])'); +} + +/** Glosses the `index`th visible word and commits it, as a reader moving on with Tab does. */ +async function editGloss(frame: Frame, index: number, value: string): Promise { + const input = tokenGlossInputs(frame).nth(index); + await input.fill(value); + await input.press('Tab'); +} + +/** Picks `item` from the Project menu, starting over when a re-render closes the menu mid-click. */ +async function openProjectMenuItem( + frame: Frame, + item: RegExp, + attemptsLeft = MENU_ATTEMPTS, +): Promise { + try { + await frame.locator("button[aria-label='Project']").first().click(); + await frame.getByRole('menuitem', { name: item }).first().click({ timeout: 5_000 }); + } catch (error) { + if (attemptsLeft <= 1) throw error; + await frame.page().keyboard.press('Escape'); + await openProjectMenuItem(frame, item, attemptsLeft - 1); + } +} + +/** Turns on timing entries in the WebView and the extension host. */ +async function enableMarks(page: Page): Promise { + await page.evaluate((key) => localStorage.setItem(key, 'true'), PERF_MARKS_KEY); + await setHostPerfMarks(page, true); +} + +/** + * Restarts the packaged app and points `app` at the new instance, with no view open. + * + * @returns Milliseconds until the new instance was ready. + */ +async function restart(app: App): Promise { + await app.browser?.close(); + await stopPackagedApp(); + const startupMs = await launchPackagedApp(); + Object.assign(app, await connect()); + // A view the layout restored would load before a timed open could. + await closeView(app.page); + await enableMarks(app.page); + return startupMs; +} + +/** Stores the tier's draft and saved projects, adding each project's id to `created` as it lands. */ +async function seedTier( + page: Page, + projectId: string, + tier: TierSpec, + draftJson: string, + created: string[], +): Promise { + await sendCommand(page, 'interlinearizer.saveDraft', projectId, draftJson); + const analysisJson = JSON.stringify(JSON.parse(draftJson).analysis); + for (let i = 0; i < tier.savedProjects; i += 1) { + // eslint-disable-next-line no-await-in-loop + const projectJson = await sendCommand( + page, + 'interlinearizer.createProject', + projectId, + ['en'], + undefined, + `Perf ${tier.name} ${i + 1}`, + ); + if (typeof projectJson !== 'string') throw new Error('createProject returned no project'); + const { id } = JSON.parse(projectJson); + created.push(id); + // eslint-disable-next-line no-await-in-loop + await sendCommand(page, 'interlinearizer.saveAnalysis', id, analysisJson, 'null'); + } +} + +/** Deletes saved projects an interrupted run left behind, so the picker lists only this run's. */ +async function deleteLeftoverProjects(page: Page, projectId: string): Promise { + const json = await sendCommand(page, 'interlinearizer.getProjectsForSource', projectId); + if (typeof json !== 'string') return; + const projects: { id: string; name?: string }[] = JSON.parse(json); + await Promise.all( + projects + .filter(({ name }) => name && SAVED_PROJECT_NAME.test(name)) + .map(({ id }) => sendCommand(page, 'interlinearizer.deleteProject', id)), + ); +} + +/** Opens a fresh view on `book` and adds its load, the host's draft fetch included, to `open`. */ +async function measureOpen( + page: Page, + projectId: string, + book: string, + open: ScenarioSamples, +): Promise { + await takeHostEntries(page); + const { frame, openedAt } = await openView(page, projectId, book); + await waitForMeasure(frame, 'book-render', book); + const settled = await waitForMeasure(frame, 'reanchor', book); + open.webView.add(settled); + const frameOrigin = await frame.evaluate(() => performance.timeOrigin); + open.webView.addValue( + 'open-to-interactive', + frameOrigin + Math.max(...settled.map((m) => m.end)) - openedAt, + ); + open.addHostCall(HOST_CALLS.getDraft, await takeHostEntries(page), settled); + await closeView(page); +} + +/** The bytes a measure's detail records, when it records any. */ +function detailBytes(measures: Measure[], name: string): number | undefined { + const detail = measures.find((m) => m.name === name)?.detail; + return detail && + typeof detail === 'object' && + 'bytes' in detail && + typeof detail.bytes === 'number' + ? detail.bytes + : undefined; +} + +/** Fills `result` scenario by scenario, so a failure keeps whatever was already measured. */ +async function measureTier( + app: App, + projectId: string, + tier: TierSpec, + createdProjects: string[], + result: Record, +): Promise { + const manifest = readManifest(tier.name); + const draftJson = readDraftJson(tier.name); + const draftWire = wireBytes(draftJson); + Object.assign(result, { + viewBook: tier.viewBook, + dataset: { counts: manifest.counts, bytes: manifest.bytes }, + wireBytes: { draft: draftWire, projectsForSource: draftWire * tier.savedProjects }, + }); + if (draftWire > MAX_WEBSOCKET_PAYLOAD_BYTES) { + result.skipped = `The draft is ${(draftWire / 1e6).toFixed(1)} MB on the wire, over the websocket's per-message cap; the app cannot load it.`; + return; + } + + await closeView(app.page); + await seedTier(app.page, projectId, tier, draftJson, createdProjects); + + // The first open after each app start. + if (PACKAGED_APP_PATH) { + const cold = scenarioSamples(); + for (let run = 0; run < RUNS; run += 1) { + // eslint-disable-next-line no-await-in-loop + cold.webView.addValue('app-startup', await restart(app)); + // eslint-disable-next-line no-await-in-loop + await measureOpen(app.page, projectId, tier.viewBook, cold); + } + result.cold = cold.summary(); + // The warm scenarios start from a fresh app too, so none inherits the cold runs' heap. + await restart(app); + } + const { page } = app; + + const heapBefore = await heapUsed(page); + let hostBefore: HostHeap | undefined; + let hostSkipped: string | undefined; + try { + hostBefore = await hostHeap(page); + } catch (e) { + hostSkipped = `the extension host's inspector could not force a garbage collection (${e instanceof Error ? e.message : String(e)}).`; + } + const webViewMemory: Record = { heapBeforeOpenBytes: heapBefore }; + const hostMemory: Record = hostBefore + ? { heapBeforeOpenBytes: hostBefore.heapUsed } + : {}; + result.memory = { webView: webViewMemory, host: hostMemory, ...(hostSkipped && { hostSkipped }) }; + /** Records both heaps at `point`, against their readings before the view opened. */ + const recordMemory = async (point: string) => { + webViewMemory[`${point}Bytes`] = (await heapUsed(page)) - heapBefore; + if (!hostBefore) return; + const host = await hostHeap(page); + hostMemory[`${point}Bytes`] = host.heapUsed - hostBefore.heapUsed; + hostMemory[`${point}ExternalBytes`] = host.external - hostBefore.external; + hostMemory[`${point}RssBytes`] = host.rss - hostBefore.rss; + }; + + // A freshly opened WebView in an app that is already running. + const open = scenarioSamples(); + for (let run = 0; run < RUNS; run += 1) { + // eslint-disable-next-line no-await-in-loop + await measureOpen(page, projectId, tier.viewBook, open); + } + result.open = open.summary(); + + // Switching back to the view book in a WebView that already holds the draft. + const { frame } = await openView(page, projectId, tier.viewBook); + await waitForMeasure(frame, 'reanchor', tier.viewBook); + await recordMemory('viewLoaded'); + const switchBook = new Samples(); + for (let run = 0; run < RUNS; run += 1) { + // eslint-disable-next-line no-await-in-loop + await clearMeasures(frame); + // eslint-disable-next-line no-await-in-loop + await setBook(page, AWAY_BOOK); + // eslint-disable-next-line no-await-in-loop + await waitForMeasure(frame, 'reanchor', AWAY_BOOK); + // eslint-disable-next-line no-await-in-loop + await clearMeasures(frame); + // eslint-disable-next-line no-await-in-loop + await setBook(page, tier.viewBook); + // eslint-disable-next-line no-await-in-loop + await waitForMeasure(frame, 'book-render', tier.viewBook); + switchBook.add( + // eslint-disable-next-line no-await-in-loop + await waitForMeasure(frame, 'reanchor', tier.viewBook), + ['usj-fetch', 'tokenize', 'reanchor', 'book-render'], + ); + } + result.switchBook = switchBook.summary(); + + // Edits: one gloss committed, then its debounced autosave round-trip. + const edits = scenarioSamples(); + for (let run = 0; run < RUNS; run += 1) { + // eslint-disable-next-line no-await-in-loop + await clearMeasures(frame); + // eslint-disable-next-line no-await-in-loop + await takeHostEntries(page); + // eslint-disable-next-line no-await-in-loop + await editGloss(frame, run, `perf-${run}`); + // eslint-disable-next-line no-await-in-loop + await waitForMeasure(frame, 'dispatch-render'); + // eslint-disable-next-line no-await-in-loop + const measures = await waitForMeasure(frame, 'autosave'); + edits.webView.add(measures, ['dispatch-render', 'autosave-serialize', 'autosave']); + // eslint-disable-next-line no-await-in-loop + edits.addHostCall(HOST_CALLS.saveDraft, await takeHostEntries(page), measures); + } + result.edit = edits.summary(); + + for (let i = 0; i < UNDO_FILL_EDITS; i += 1) { + // The last edit's autosave lands before the heaps are read, so neither holds a save in flight. + // eslint-disable-next-line no-await-in-loop + if (i === UNDO_FILL_EDITS - 1) await clearMeasures(frame); + // eslint-disable-next-line no-await-in-loop + await editGloss(frame, i % 20, `undo-${i}`); + } + await waitForMeasure(frame, 'autosave'); + await clearMeasures(frame); + await recordMemory('withFullUndoHistory'); + + // Picker: listing the source's saved projects. + const dialog = frame.locator('[data-slot="dialog-content"]'); + const picker = scenarioSamples(); + for (let run = 0; run < RUNS; run += 1) { + // eslint-disable-next-line no-await-in-loop + await clearMeasures(frame); + // eslint-disable-next-line no-await-in-loop + await takeHostEntries(page); + // eslint-disable-next-line no-await-in-loop + await openProjectMenuItem(frame, /Select Interlinear Project/i); + // eslint-disable-next-line no-await-in-loop + const measures = await waitForMeasure(frame, 'projects-fetch'); + picker.webView.add(measures, ['projects-fetch']); + // eslint-disable-next-line no-await-in-loop + picker.addHostCall(HOST_CALLS.getProjectsForSource, await takeHostEntries(page), measures); + // eslint-disable-next-line no-await-in-loop + await frame.getByRole('button', { name: 'Cancel' }).first().click(); + // eslint-disable-next-line no-await-in-loop + await expect(dialog).toHaveCount(0); + } + result.picker = picker.summary(); + await recordMemory('afterPicker'); + + // Save: writing the draft's analysis to the project it was opened from. + await clearMeasures(frame); + await openProjectMenuItem(frame, /Select Interlinear Project/i); + await dialog + .locator('li > button', { hasText: `Perf ${tier.name} 1` }) + .first() + .click(); + // Replacing an edited draft asks first; an unedited one opens straight away. + await frame + .getByTestId('discard-draft-confirm') + .click({ timeout: 5_000 }) + .catch(() => {}); + await expect(dialog).toHaveCount(0, { timeout: 60_000 }); + // Opening the project reseeds the store; a menu opened before that lands is dismissed by it. + await waitForMeasure(frame, 'store-mount'); + const saves = scenarioSamples(); + for (let run = 0; run < RUNS; run += 1) { + // eslint-disable-next-line no-await-in-loop + await clearMeasures(frame); + // eslint-disable-next-line no-await-in-loop + await takeHostEntries(page); + // eslint-disable-next-line no-await-in-loop + await openProjectMenuItem(frame, /^Save(?! As)/); + // eslint-disable-next-line no-await-in-loop + const measures = await waitForMeasure(frame, 'save'); + // A save then persists the draft as clean, and that re-render would close the next run's menu. + // eslint-disable-next-line no-await-in-loop + await waitForMeasure(frame, 'autosave'); + saves.webView.add(measures, ['save']); + const bytes = detailBytes(measures, 'save'); + if (bytes !== undefined) saves.webView.addValue('save-bytes', bytes); + // eslint-disable-next-line no-await-in-loop + saves.addHostCall(HOST_CALLS.saveAnalysis, await takeHostEntries(page), measures); + } + result.save = saves.summary(); + await recordMemory('afterSave'); + + // Concordance: indexing every book of the source, in a fresh WebView each run since a WebView + // keeps the index it built. + const concordance = new Samples(); + for (let run = 0; run < RUNS; run += 1) { + // eslint-disable-next-line no-await-in-loop + await closeView(page); + // eslint-disable-next-line no-await-in-loop + const { frame: view } = await openView(page, projectId, tier.viewBook); + // eslint-disable-next-line no-await-in-loop + await waitForMeasure(view, 'reanchor', tier.viewBook); + // eslint-disable-next-line no-await-in-loop + await clearMeasures(view); + // eslint-disable-next-line no-await-in-loop + await openProjectMenuItem(view, /^Concordance/); + concordance.add( + // eslint-disable-next-line no-await-in-loop + await waitForMeasure(view, 'concordance-entries'), + ['concordance-read', 'concordance-entries'], + ); + } + result.concordance = concordance.summary(); +} + +test('measure the app', async ({ mainPage }) => { + const app: App = { page: mainPage }; + await waitForAppAndInterlinearizerReady(mainPage, { cdp: true }); + const meta = readCaptureMeta(); + const projectId = await sourceProjectId(mainPage); + + const requested = (process.env.PERF_TIERS ?? '').split(',').filter(Boolean); + const tiers = TIERS.filter((t) => requested.length === 0 || requested.includes(t.name)); + await closeView(mainPage); + await deleteLeftoverProjects(mainPage, projectId); + const originalDraft = await sendCommand(mainPage, 'interlinearizer.getDraft', projectId); + await enableMarks(mainPage); + + const createdProjects: string[] = []; + const results: Record> = {}; + try { + await tiers.reduce(async (previous, tier) => { + await previous; + const result: Record = {}; + results[tier.name] = result; + try { + await measureTier(app, projectId, tier, createdProjects, result); + } catch (e) { + result.error = e instanceof Error ? e.message : String(e); + } finally { + // Each tier's picker lists only the projects that tier seeded. + await closeView(app.page); + await Promise.all( + createdProjects + .splice(0) + .map((id) => sendCommand(app.page, 'interlinearizer.deleteProject', id)), + ); + } + console.log(`${tier.name}: ${JSON.stringify(result, undefined, 2)}`); + }, Promise.resolve()); + } finally { + await closeView(app.page); + await app.page.evaluate((key) => localStorage.removeItem(key), PERF_MARKS_KEY); + await setHostPerfMarks(app.page, false); + await sendCommand(app.page, 'interlinearizer.saveDraft', projectId, originalDraft); + } + + const file = writeResults('app', { + ...provenance(meta.coreCommit), + appBuild: app.page.url().startsWith('http://localhost') ? 'dev renderer' : 'packaged', + ...(PACKAGED_APP_PATH && OZONE_PLATFORM ? { display: OZONE_PLATFORM } : {}), + extensionBuild: + process.env.E2E_BUILD_SCRIPT === 'build:production' ? 'production' : 'development', + runs: RUNS, + tiers: results, + }); + console.log(`Wrote ${path.relative(process.cwd(), file)}`); + await app.browser?.close(); +}); diff --git a/e2e-tests/tests/perf/capture-usj.spec.ts b/e2e-tests/tests/perf/capture-usj.spec.ts new file mode 100644 index 000000000..a068b10da --- /dev/null +++ b/e2e-tests/tests/perf/capture-usj.spec.ts @@ -0,0 +1,66 @@ +import { Canon } from '@sillsdev/scripture'; +import { execSync } from 'child_process'; +import path from 'path'; +import { SOURCE_PROJECT_NAME } from '../../../perf/paths'; +import { clearCaptureMeta, writeCapturedBook, writeCaptureMeta } from '../../../perf/usj-cache'; +import { test } from '../../fixtures/cdp.fixture'; +import { waitForAppAndInterlinearizerReady } from '../../fixtures/helpers'; +import { sourceProjectId } from './view-driver'; + +test('capture the source project USJ', async ({ mainPage }) => { + test.setTimeout(10 * 60_000); + await waitForAppAndInterlinearizerReady(mainPage, { cdp: true }); + + const projectId = await sourceProjectId(mainPage); + + const { booksPresent, languageTag } = await mainPage.evaluate(async (id) => { + const base = await window.papi.projectDataProviders.get('platform.base', id); + return { + booksPresent: await base.getSetting('platformScripture.booksPresent'), + languageTag: await base.getSetting('platform.languageTag'), + }; + }, projectId); + if (typeof booksPresent !== 'string' || typeof languageTag !== 'string') + throw new Error(`${SOURCE_PROJECT_NAME} reported no books or language`); + + const listed = [...booksPresent] + .map((flag, index) => (flag === '1' ? Canon.bookNumberToId(index + 1) : undefined)) + .filter((book): book is string => !!book); + + clearCaptureMeta(projectId); + // One book per round-trip keeps each CDP message well under its size limit. + const books: string[] = []; + await listed.reduce(async (previous, book) => { + await previous; + const usj = await mainPage.evaluate( + async ([id, bookCode]) => { + const pdp = await window.papi.projectDataProviders.get('platformScripture.USJ_Book', id); + return pdp.getBookUSJ({ book: bookCode, chapterNum: 1, verseNum: 1 }).catch((e) => { + // A book its settings list but its files lack. + if (String(e?.message ?? e).includes('not found in project')) return undefined; + throw e; + }); + }, + [projectId, book] as const, + ); + if (!usj) { + console.warn(`${SOURCE_PROJECT_NAME} lists ${book} but has no text for it; skipping it`); + return; + } + writeCapturedBook(projectId, book, usj); + books.push(book); + }, Promise.resolve()); + + writeCaptureMeta({ + projectId, + projectName: SOURCE_PROJECT_NAME, + languageTag, + books, + capturedAt: new Date().toISOString(), + coreCommit: execSync('git rev-parse HEAD', { + cwd: path.resolve(__dirname, '../../../../paranext-core'), + }) + .toString() + .trim(), + }); +}); diff --git a/e2e-tests/tests/perf/host-inspector.ts b/e2e-tests/tests/perf/host-inspector.ts new file mode 100644 index 000000000..7fcea17be --- /dev/null +++ b/e2e-tests/tests/perf/host-inspector.ts @@ -0,0 +1,103 @@ +/** Port Node's inspector listens on when a running process is asked to open it. */ +const INSPECTOR_PORT = 9229; + +const INSPECTOR_TIMEOUT_MS = 10_000; + +/** The extension host's memory after a full garbage collection, in bytes. */ +export type HostHeap = { heapUsed: number; external: number; rss: number }; + +type Send = (method: string, params?: Record) => Promise; + +/** Asks Node process `pid` to open its inspector; a no-op once it is open. */ +function openInspector(pid: number): void { + // Node's undeclared counterpart to `kill -USR1`, which also works on Windows. + const debugProcess: unknown = Reflect.get(process, '_debugProcess'); + if (typeof debugProcess !== 'function') + throw new Error("This Node cannot open another process's inspector"); + debugProcess.call(process, pid); +} + +async function inspectorUrl(deadline: number): Promise { + try { + const response = await fetch(`http://127.0.0.1:${INSPECTOR_PORT}/json/list`); + const targets: { webSocketDebuggerUrl?: string }[] = await response.json(); + const url = targets[0]?.webSocketDebuggerUrl; + if (url) return url; + } catch { + // Not listening yet. + } + if (Date.now() > deadline) + throw new Error( + `No inspector opened on port ${INSPECTOR_PORT} within ${INSPECTOR_TIMEOUT_MS} ms`, + ); + await new Promise((resolve) => { + setTimeout(resolve, 100); + }); + return inspectorUrl(deadline); +} + +/** Runs `use` against process `pid`'s inspector, closing the connection after. */ +async function withInspector(pid: number, use: (send: Send) => Promise): Promise { + openInspector(pid); + const socket = new WebSocket(await inspectorUrl(Date.now() + INSPECTOR_TIMEOUT_MS)); + await new Promise((resolve, reject) => { + socket.addEventListener('open', resolve, { once: true }); + socket.addEventListener('error', reject, { once: true }); + }); + const pending = new Map< + number, + { resolve: (result: unknown) => void; reject: (e: Error) => void } + >(); + socket.addEventListener('message', (event) => { + const { id, result, error } = JSON.parse(String(event.data)); + const waiter = pending.get(id); + if (!waiter) return; + pending.delete(id); + if (error) waiter.reject(new Error(`${error.message} (${error.code})`)); + else waiter.resolve(result); + }); + socket.addEventListener('close', () => { + pending.forEach(({ reject }) => reject(new Error('The inspector connection closed'))); + pending.clear(); + }); + let nextId = 0; + const send: Send = (method, params) => + new Promise((resolve, reject) => { + nextId += 1; + pending.set(nextId, { resolve, reject }); + socket.send(JSON.stringify({ id: nextId, method, params })); + }); + try { + return await use(send); + } finally { + socket.close(); + } +} + +/** Evaluates `expression` in the inspected process, returning its JSON-compatible value. */ +async function evaluate(send: Send, expression: string): Promise { + const reply = await send('Runtime.evaluate', { expression, returnByValue: true }); + const value = reply && typeof reply === 'object' && 'result' in reply ? reply.result : undefined; + return value && typeof value === 'object' && 'value' in value ? value.value : undefined; +} + +/** + * Reads the memory of the extension host, process `pid`, right after a full garbage collection. + * + * @throws If the inspector does not open, or the one on {@link INSPECTOR_PORT} belongs to another + * process. + */ +export async function readHostHeap(pid: number): Promise { + return withInspector(pid, async (send) => { + const inspected = await evaluate(send, 'process.pid'); + if (inspected !== pid) + throw new Error( + `The inspector on port ${INSPECTOR_PORT} belongs to process ${inspected}, not the extension host`, + ); + await send('HeapProfiler.collectGarbage'); + const json = await evaluate(send, 'JSON.stringify(process.memoryUsage())'); + if (typeof json !== 'string') throw new Error('The extension host reported no memory usage'); + const { heapUsed, external, rss } = JSON.parse(json); + return { heapUsed, external, rss }; + }); +} diff --git a/e2e-tests/tests/perf/renderer-papi.d.ts b/e2e-tests/tests/perf/renderer-papi.d.ts new file mode 100644 index 000000000..9a558de0f --- /dev/null +++ b/e2e-tests/tests/perf/renderer-papi.d.ts @@ -0,0 +1,37 @@ +/** The slice of the renderer's global `papi` the performance harness drives. */ +interface RendererPapi { + commands: { sendCommand(command: string, ...args: unknown[]): Promise }; + projectLookup: { + getMetadataForAllProjects(): Promise<{ id: string; name?: string }[]>; + }; + projectDataProviders: { + get( + projectInterface: string, + projectId: string, + ): Promise<{ + getSetting(key: string): Promise; + getBookUSJ(verseRef: { + book: string; + chapterNum: number; + verseNum: number; + }): Promise; + }>; + }; + scrollGroups: { + setScrRef( + scrollGroupId: number | undefined, + scrRef: { book: string; chapterNum: number; verseNum: number }, + ): Promise; + }; + webViews: { + openWebView( + webViewType: string, + layout?: unknown, + options?: Record, + ): Promise; + }; +} + +interface Window { + papi: RendererPapi; +} diff --git a/e2e-tests/tests/perf/view-driver.ts b/e2e-tests/tests/perf/view-driver.ts new file mode 100644 index 000000000..3dae23a75 --- /dev/null +++ b/e2e-tests/tests/perf/view-driver.ts @@ -0,0 +1,284 @@ +import { chromium, type Browser, type Frame, type Page } from '@playwright/test'; +import { summarize, type Timing } from '../../../perf/bench/measure'; +import { SOURCE_PROJECT_NAME } from '../../../perf/paths'; +import { expect } from '../../fixtures/cdp.fixture'; +import { CDP_PORT } from '../../global-setup-cdp'; +import { type HostHeap, readHostHeap } from './host-inspector'; + +/** Paranext-core's cap on one websocket message, which every command argument and result crosses. */ +export const MAX_WEBSOCKET_PAYLOAD_BYTES = 100 * 1024 * 1024; + +/** Storage key that asks the WebView for timing entries. */ +export const PERF_MARKS_KEY = 'interlinearizer.perfMarks'; + +export const VIEW_TAB = /^Interlinearizer: WEB/; + +export type Measure = { name: string; duration: number; end: number; detail: unknown }; + +/** A duration the extension host recorded, named without its prefix. */ +export type HostEntry = { name: string; duration: number }; + +/** + * A host command a WebView measure times end to end, and the storage functions whose phases run + * within it. + */ +export type HostCall = { measure: string; command: string; phasePrefixes: string[] }; + +/** The host commands the scenarios time. */ +export const HOST_CALLS = { + getDraft: { measure: 'draft-fetch', command: 'getDraft', phasePrefixes: ['getDraft'] }, + saveDraft: { measure: 'autosave', command: 'saveDraft', phasePrefixes: ['saveDraft'] }, + getProjectsForSource: { + measure: 'projects-fetch', + command: 'getProjectsForSource', + phasePrefixes: ['getProjectsForSource', 'listProjects'], + }, + saveAnalysis: { + measure: 'save', + command: 'saveAnalysis', + phasePrefixes: ['saveAnalysis', 'updateAnalysis'], + }, +} satisfies Record; + +/** Collected durations per measure name, summarized once a scenario's runs are done. */ +export class Samples { + private readonly byName = new Map(); + + add(measures: Measure[], names?: readonly string[]): void { + measures + .filter(({ name }) => !names || names.includes(name)) + .forEach(({ name, duration }) => { + const durations = this.byName.get(name) ?? []; + durations.push(duration); + this.byName.set(name, durations); + }); + } + + addValue(name: string, value: number): void { + this.add([{ name, duration: value, end: 0, detail: undefined }]); + } + + summary(): Record { + return Object.fromEntries([...this.byName].map(([name, values]) => [name, summarize(values)])); + } +} + +/** One scenario's samples, from the WebView and from the extension host. */ +export function scenarioSamples() { + const webView = new Samples(); + const host = new Samples(); + return { + webView, + host, + /** + * Adds the host's time for `call`, named for the WebView measure it serves, with each phase + * summed and the transport the WebView saw beyond it. Adds nothing when the host did not run + * `call` exactly once, since its phases could not then be told apart. + */ + addHostCall(call: HostCall, entries: HostEntry[], measures: Measure[]): void { + const totals = entries.filter(({ name }) => name === call.command); + if (totals.length !== 1) { + console.warn(`Expected one host ${call.command} call, saw ${totals.length}; not sampled`); + return; + } + const [{ duration: hostMs }] = totals; + host.addValue(call.measure, hostMs); + const phases = new Map(); + entries.forEach(({ name, duration }) => { + const [prefix, phase] = name.split(':'); + if (phase && call.phasePrefixes.includes(prefix)) + phases.set(phase, (phases.get(phase) ?? 0) + duration); + }); + phases.forEach((ms, phase) => host.addValue(`${call.measure}:${phase}`, ms)); + const seen = measures.find(({ name }) => name === call.measure); + if (seen) webView.addValue(`${call.measure}:transport`, seen.duration - hostMs); + }, + summary() { + return { webView: webView.summary(), host: host.summary() }; + }, + }; +} + +export type ScenarioSamples = ReturnType; + +/** Size of `json` once it is embedded as a string in a JSON-RPC message. */ +export function wireBytes(json: string): number { + return Buffer.byteLength(JSON.stringify(json)); +} + +export async function sendCommand( + page: Page, + command: string, + ...args: unknown[] +): Promise { + return page.evaluate(([name, params]) => window.papi.commands.sendCommand(name, ...params), [ + command, + args, + ] as const); +} + +export async function setBook(page: Page, book: string): Promise { + await page.evaluate( + (bookCode) => + window.papi.scrollGroups.setScrRef(0, { book: bookCode, chapterNum: 1, verseNum: 1 }), + book, + ); +} + +/** The open WebView's frame, waiting for it to appear. */ +export async function viewFrame(page: Page): Promise { + const iframe = page.locator('iframe[title^="Interlinearizer: WEB"]').first(); + await expect(iframe).toBeAttached({ timeout: 60_000 }); + const frame = await (await iframe.elementHandle())?.contentFrame(); + if (!frame) throw new Error('The Interlinearizer WebView has no frame'); + return frame; +} + +/** + * Opens a view on `book`. + * + * @returns The view's frame, and when the open was requested in epoch milliseconds, comparable with + * any frame's `performance.timeOrigin` plus its timeline. + */ +export async function openView( + page: Page, + projectId: string, + book: string, +): Promise<{ frame: Frame; openedAt: number }> { + await setBook(page, book); + const openedAt = await page.evaluate(async (id) => { + const at = performance.timeOrigin + performance.now(); + await window.papi.webViews.openWebView('interlinearizer.mainWebView', undefined, { + projectId: id, + }); + return at; + }, projectId); + return { frame: await viewFrame(page), openedAt }; +} + +export async function closeView(page: Page): Promise { + const tab = page.locator('.dock-tab', { hasText: VIEW_TAB }); + if ((await tab.count()) === 0) return; + await tab.first().locator('.dock-tab-close-btn').dispatchEvent('click'); + await expect(tab).toHaveCount(0, { timeout: 30_000 }); +} + +/** Every timing entry the WebView has recorded, with its end relative to the frame's start. */ +export async function readMeasures(frame: Frame): Promise { + return frame.evaluate(() => + performance + .getEntriesByType('measure') + .filter((entry) => entry.name.startsWith('ilz:')) + .map((entry) => ({ + name: entry.name.slice('ilz:'.length), + duration: entry.duration, + end: entry.startTime + entry.duration, + detail: 'detail' in entry ? entry.detail : undefined, + })), + ); +} + +export async function clearMeasures(frame: Frame): Promise { + await frame.evaluate(() => { + performance.clearMarks(); + performance.clearMeasures(); + }); +} + +/** + * Waits until the WebView has recorded `name`, for `book` when given, and returns every entry. Only + * entries recorded since the last {@link clearMeasures} count. + */ +export async function waitForMeasure( + frame: Frame, + name: string, + book?: string, +): Promise { + await frame.waitForFunction( + ([entryName, bookCode]) => + performance + .getEntriesByName(entryName, 'measure') + .some( + (entry) => + bookCode === undefined || + ('detail' in entry && + !!entry.detail && + typeof entry.detail === 'object' && + 'book' in entry.detail && + entry.detail.book === bookCode), + ), + [`ilz:${name}`, book] as const, + { timeout: 10 * 60_000, polling: 50 }, + ); + return readMeasures(frame); +} + +/** Bytes of JS heap the renderer holds after a full collection. */ +export async function heapUsed(page: Page): Promise { + const session = await page.context().newCDPSession(page); + try { + await session.send('HeapProfiler.collectGarbage'); + const { usedSize } = await session.send('Runtime.getHeapUsage'); + return usedSize; + } finally { + await session.detach(); + } +} + +/** Turns the extension host's timing entries on or off. */ +export async function setHostPerfMarks(page: Page, on: boolean): Promise { + await sendCommand(page, 'interlinearizer.setPerfMarks', on); +} + +async function readHost(page: Page): Promise<{ entries: HostEntry[]; pid: number }> { + const json = await sendCommand(page, 'interlinearizer.readPerf'); + if (typeof json !== 'string') throw new Error("The host's timing entries are off"); + return JSON.parse(json); +} + +/** Every duration the host recorded since the last call, which clears them. */ +export async function takeHostEntries(page: Page): Promise { + return (await readHost(page)).entries; +} + +/** + * The extension host's memory after a full garbage collection. Clears the host's timing entries. + * + * @throws If the host's inspector cannot be opened to force the collection. + */ +export async function hostHeap(page: Page): Promise { + return readHostHeap((await readHost(page)).pid); +} + +/** The bundled sample project's id, waiting out its install on a profile's first launch. */ +export async function sourceProjectId(page: Page): Promise { + // Polled from here: `waitForFunction` takes an async predicate's pending promise as truthy. + const lookUp = () => + page.evaluate(async (name) => { + const projects = await window.papi.projectLookup.getMetadataForAllProjects(); + return projects.find((project) => project.name === name)?.id; + }, SOURCE_PROJECT_NAME); + await expect + .poll(lookUp, { + message: `No ${SOURCE_PROJECT_NAME} project is installed`, + timeout: 120_000, + intervals: [1_000], + }) + .toEqual(expect.any(String)); + const projectId = await lookUp(); + if (projectId === undefined) throw new Error(`The ${SOURCE_PROJECT_NAME} project went away`); + return projectId; +} + +/** Connects to the running app's renderer over CDP. */ +export async function connect(): Promise<{ browser: Browser; page: Page }> { + const browser = await chromium.connectOverCDP(`http://localhost:${CDP_PORT}`, { + timeout: 30_000, + }); + const page = browser + .contexts() + .flatMap((context) => context.pages()) + .find((p) => !p.url().startsWith('devtools://')); + if (!page) throw new Error('No renderer page found via CDP'); + return { browser, page }; +} diff --git a/package.json b/package.json index e43496187..0574c32a6 100644 --- a/package.json +++ b/package.json @@ -35,6 +35,12 @@ "test:e2e:cdp": "playwright test --config e2e-tests/playwright-cdp.config.ts", "test:e2e:headless": "xvfb-run --auto-servernum --server-args=\"-screen 0 1280x960x24\" npm run test:e2e", "test:e2e:smoke": "playwright test --config e2e-tests/playwright.config.ts --project=smoke", + "perf:capture": "playwright test --config e2e-tests/playwright-perf.config.ts --project=capture", + "perf:datasets": "node --max-old-space-size=8192 -r ts-node/register perf/dataset/cli.ts", + "perf:bench": "cross-env NODE_ENV=production node --expose-gc --max-old-space-size=12288 -r ts-node/register perf/bench/cli.ts", + "perf:app": "cross-env E2E_BUILD_SCRIPT=build:production playwright test --config e2e-tests/playwright-perf.config.ts --project=app", + "perf:summary": "node -r ts-node/register perf/summary/cli.ts", + "perf:shape": "node --max-old-space-size=8192 -r ts-node/register perf/shape/cli.ts", "core:start": "npm --prefix ../paranext-core start", "core:stop": "npm --prefix ../paranext-core stop", "core:reset": "npm run core:stop && node ./scripts/delete-temp-files.cjs --core --ext", diff --git a/perf/README.md b/perf/README.md new file mode 100644 index 000000000..3ba177f04 --- /dev/null +++ b/perf/README.md @@ -0,0 +1,55 @@ +# Performance harness + +Measures the extension rather than tests it: the data layer's pure functions in Node, and the extension running in the app. + +## Commands + +- `npm run perf:capture` captures the WEB sample's USJ into `perf/.cache`. +- `npm run perf:datasets` generates the seeded dataset tiers defined in `perf/dataset/tiers.ts`, capturing first when the cache holds no complete capture. +- `npm run perf:bench` times the data layer's pure functions in Node. +- `npm run perf:app` times the extension in the app. +- `npm run perf:summary` renders the newest results of each kind as markdown tables. +- `npm run perf:shape -- ...` compares the shape of analyses; see [Dataset shape](#dataset-shape). + +`PERF_TIERS` (comma-separated tier names) and `PERF_RUNS` (10 by default) narrow a run. The `large` tier's draft exceeds one websocket message, so only the Node benchmarks can measure it. + +Results land in `perf/results/` as JSON, each recording the machine, its load average, and both commits. + +## Dataset shape + +`perf:shape` prints text-independent measures of an analysis's shape (payload sharing, senses per form, status mix, phrases), so a generated tier can be compared with a real project. + +A dataset is a tier name, or a `draft:` or `project:` key in the development host's extension storage. `PERF_STORAGE_DIR` names another storage directory. + +## Timing in the app + +`perf:app` launches the app as the [CDP end-to-end tier](../e2e-tests/README.md) does, with two differences: + +- Global setup builds the extension for production (`E2E_BUILD_SCRIPT=build:production`). +- The run gets empty extension storage, so listing projects reads only what the run seeds. Your own storage waits in `user-data.perf-backup` beside it and comes back on teardown. + +Quit Platform.Bible first. A perf run refuses to start while any instance holds its ports, since that app may own the storage a run sets aside. + +The timings are `ilz:`-prefixed performance entries. The WebView records them only while the `interlinearizer.perfMarks` localStorage key is `true`, and the extension host only after the `interlinearizer.setPerfMarks` command turns them on; the spec does both. `interlinearizer.readPerf` takes the host's entries, with its process id. + +Each scenario that calls the host reports the host's time for that call beside the WebView's, split into storage read, parse, shard compare, storage write and reply serialize, with transport as the difference. + +Both heaps are read after a forced garbage collection over the DevTools protocol: + +- The WebView's through the app's remote debugging port. +- The host's through the Node inspector the run opens in the host process. It listens on port 9229 until the app quits, so that port must be free. A run that cannot open it records no host heap, and the summary says why. + +## Baseline numbers + +A dev core serves the WebView development React, so baseline numbers need a packaged core: `npm run package` in paranext-core, or on Linux `npx electron-builder build --publish never --linux dir` after its build steps, which skips the snap. + +Set `PERF_APP_PATH` to the packaged executable (`release/build/linux-unpacked/platform-bible` on Linux) and every perf command launches that app instead: + +- Setup builds the extension for production. +- The app runs with its home folder (`HOME`, and `USERPROFILE` on Windows) set to `perf/.cache/app-home`, so it installs WEB into its own profile and never touches yours. +- Teardown asks it to quit. +- `perf:app` also times the first open after each app start, restarting the app before each run. A dev core gets the warm scenarios only. + +On Linux the app runs on X11 unless `PERF_OZONE_PLATFORM` names another backend, such as `wayland` when Xwayland is unavailable; results record it. + +Run on an idle machine, and keep comparing on that same machine. diff --git a/perf/bench/cli.ts b/perf/bench/cli.ts new file mode 100644 index 000000000..6768b089d --- /dev/null +++ b/perf/bench/cli.ts @@ -0,0 +1,193 @@ +/* eslint-disable no-console -- a command-line tool reports to its terminal */ +import type { Book, DraftProject, TextAnalysis } from 'interlinearizer'; +import path from 'path'; +import { tokenizeBook } from '../../src/parsers/papi/bookTokenizer'; +import { extractBookFromUsj } from '../../src/parsers/papi/usjBookExtractor'; +import analysisReducer, { + type AnalysisState, + selectApprovedGloss, + selectCatalogRows, + selectPhraseLinkByTokenRef, + selectPoolIndex, + selectStaleTokenLinks, + writeGloss, +} from '../../src/store/analysisSlice'; +import { createAnalysisStore } from '../../src/store'; +import { mergeAnalyses, splitAnalysisByBook } from '../../src/utils/analysis-book'; +import { + approvedAnalysisByToken, + buildConcordanceEntries, + deriveConcordanceRows, + indexBook, +} from '../../src/utils/concordance'; +import { collatorForTag } from '../../src/utils/language-tags'; +import { reanchorAnalysisToBook } from '../../src/utils/reanchor-analysis'; +import { MAX_UNDO_STEPS } from '../../src/utils/undo-history'; +import { loadBooks, readUsj } from '../books'; +import { readDraftJson, readManifest } from '../dataset/store'; +import { TIERS, type TierSpec } from '../dataset/tiers'; +import { provenance, writeResults } from '../results'; +import { readCaptureMeta } from '../usj-cache'; +import { measure, retainedBytes, type Timing } from './measure'; + +const RUNS = Number(process.env.PERF_RUNS ?? 10); +const WARMUP = 1; + +/** Reads the store through the indexing selectors a mounted view recomputes after a dispatch. */ +function readViewSelectors(state: AnalysisState, book: Book): void { + const tokenRef = book.segments[0].tokens[0].ref; + selectPoolIndex(state); + selectCatalogRows(state, book.bookRef); + selectPhraseLinkByTokenRef(state); + selectStaleTokenLinks(state); + selectApprovedGloss(state, tokenRef); +} + +/** The word tokens of `book`, in document order. */ +function wordsOf(book: Book) { + return book.segments.flatMap((s) => s.tokens.filter((t) => t.type === 'word')); +} + +function benchTier(tier: TierSpec, allBooks: () => Book[]): Record { + const tierName = tier.name; + const meta = readCaptureMeta(); + const manifest = readManifest(tierName); + const viewBookCode = tier.viewBook; + const usj = readUsj(meta, viewBookCode); + const [viewBook] = loadBooks(meta, [viewBookCode]); + const draftJson = readDraftJson(tierName); + const draft: DraftProject = JSON.parse(draftJson); + const { analysis } = draft; + const language = draft.analysisLanguages[0]; + const opts = { runs: RUNS, warmup: WARMUP }; + const noSetup = () => undefined; + const timings: Record = {}; + const time = (name: string, timing: Timing) => { + timings[name] = timing; + console.log(` ${name.padEnd(22)} median ${timing.medianMs} ms, p90 ${timing.p90Ms} ms`); + }; + + console.log( + `${tierName} (view ${viewBookCode}, ${(draftJson.length / 1e6).toFixed(1)} MB draft)`, + ); + + time( + 'load.tokenize', + measure(opts, noSetup, () => tokenizeBook(extractBookFromUsj(usj, meta.languageTag || 'und'))), + ); + time( + 'load.parseDraft', + measure(opts, noSetup, () => JSON.parse(draftJson)), + ); + const now = new Date(0).toISOString(); + time( + 'load.reanchor', + measure(opts, noSetup, () => reanchorAnalysisToBook(analysis, viewBook, now)), + ); + // A fresh copy per run: selectors memoize on the analysis object itself. + time( + 'load.storeMount', + measure( + opts, + () => structuredClone(analysis), + (copy) => { + const store = createAnalysisStore({ + analysis: { analysis: copy, analysisLanguage: language }, + }); + readViewSelectors(store.getState().analysis, viewBook); + }, + ), + ); + + const shards = [...splitAnalysisByBook(analysis).values()].map((shard) => JSON.stringify(shard)); + time( + 'storage.readShards', + measure(opts, noSetup, () => + mergeAnalyses(shards.map((json): TextAnalysis => JSON.parse(json))), + ), + ); + time( + 'storage.writeShards', + measure(opts, noSetup, () => + [...splitAnalysisByBook(analysis).values()].map((shard) => JSON.stringify(shard)), + ), + ); + + // Each run glosses a different word, so no selector can answer from its memo. + const words = wordsOf(viewBook); + const store = createAnalysisStore({ analysis: { analysis, analysisLanguage: language } }); + readViewSelectors(store.getState().analysis, viewBook); + time( + 'edit.dispatch', + measure( + opts, + (i) => words[(i * 97) % words.length], + (token, i) => { + store.dispatch(writeGloss(token.ref, token.surfaceText, `bench-${i}`)); + readViewSelectors(store.getState().analysis, viewBook); + }, + ), + ); + time( + 'edit.serializeDraft', + measure(opts, noSetup, () => + JSON.stringify({ ...draft, analysis: store.getState().analysis.analysis }), + ), + ); + + const books = allBooks(); + const collator = collatorForTag(meta.languageTag || 'und'); + time( + 'concordance.build', + measure(opts, noSetup, () => { + const entries = buildConcordanceEntries(books.map(indexBook), collator); + deriveConcordanceRows( + entries, + approvedAnalysisByToken(analysis.tokenAnalysisLinks), + viewBookCode, + ); + }), + ); + + // The undo history holds a snapshot of the analysis before each of its steps. + const undoBytes = retainedBytes(() => { + let state: AnalysisState = { analysis, analysisLanguage: language }; + const snapshots: AnalysisState[] = []; + for (let i = 0; i < MAX_UNDO_STEPS; i += 1) { + snapshots.push(state); + const token = words[(i * 89) % words.length]; + state = analysisReducer(state, writeGloss(token.ref, token.surfaceText, `undo-${i}`)); + } + return snapshots; + }); + const analysisBytes = retainedBytes(() => JSON.parse(draftJson)); + + return { + viewBook: viewBookCode, + dataset: { counts: manifest.counts, bytes: manifest.bytes }, + timings, + memory: { parsedDraftBytes: analysisBytes, undoHistoryBytes: undoBytes }, + }; +} + +function main(): void { + if (typeof globalThis.gc !== 'function') + console.warn('Run with `node --expose-gc` for stable timings and memory readings.'); + const meta = readCaptureMeta(); + let books: Book[] | undefined; + const allBooks = () => { + books ??= loadBooks(meta, meta.books); + return books; + }; + const requested = process.argv.slice(2); + const tiers = TIERS.filter((t) => requested.length === 0 || requested.includes(t.name)); + + const file = writeResults('bench', { + ...provenance(meta.coreCommit), + runs: RUNS, + tiers: Object.fromEntries(tiers.map((t) => [t.name, benchTier(t, allBooks)])), + }); + console.log(`Wrote ${path.relative(process.cwd(), file)}`); +} + +main(); diff --git a/perf/bench/measure.ts b/perf/bench/measure.ts new file mode 100644 index 000000000..79d4f3571 --- /dev/null +++ b/perf/bench/measure.ts @@ -0,0 +1,69 @@ +import { performance } from 'perf_hooks'; + +/** Timing of one benchmarked operation. */ +export interface Timing { + runs: number; + medianMs: number; + p90Ms: number; + minMs: number; + maxMs: number; +} + +/** + * Runs a full collection when Node was started with `--expose-gc`, so one run's garbage is not + * billed to the next. + */ +export function collectGarbage(): void { + if (typeof globalThis.gc === 'function') globalThis.gc(); +} + +/** The `p`th percentile of ascending `sorted`, by nearest rank. */ +export function percentile(sorted: number[], p: number): number { + return sorted[Math.min(sorted.length - 1, Math.ceil((p / 100) * sorted.length) - 1)]; +} + +const round = (ms: number) => Math.round(ms * 1000) / 1000; + +/** Summarizes durations as the median and p90 the protocol reports. */ +export function summarize(durations: number[]): Timing { + const sorted = [...durations].sort((a, b) => a - b); + return { + runs: sorted.length, + medianMs: round(percentile(sorted, 50)), + p90Ms: round(percentile(sorted, 90)), + minMs: round(sorted[0]), + maxMs: round(sorted[sorted.length - 1]), + }; +} + +/** + * Times `run` after `warmup` unrecorded calls, preparing each call's input untimed with `setup` so + * every run can start from fresh state. + */ +export function measure( + { runs, warmup }: { runs: number; warmup: number }, + setup: (index: number) => T, + run: (input: T, index: number) => unknown, +): Timing { + const durations: number[] = []; + for (let i = 0; i < warmup + runs; i += 1) { + const input = setup(i); + collectGarbage(); + const start = performance.now(); + run(input, i); + const elapsed = performance.now() - start; + if (i >= warmup) durations.push(elapsed); + } + return summarize(durations); +} + +/** Heap bytes `build`'s result keeps alive, measured across forced collections. */ +export function retainedBytes(build: () => unknown): number { + collectGarbage(); + const before = process.memoryUsage().heapUsed; + const kept = build(); + collectGarbage(); + const after = process.memoryUsage().heapUsed; + // Reading `kept` after the second collection keeps it reachable through the measurement. + return kept === undefined ? 0 : after - before; +} diff --git a/perf/books.ts b/perf/books.ts new file mode 100644 index 000000000..3d5d78445 --- /dev/null +++ b/perf/books.ts @@ -0,0 +1,22 @@ +import type { Book } from 'interlinearizer'; +import { tokenizeBook } from '../src/parsers/papi/bookTokenizer'; +import { extractBookFromUsj, type UsjDocument } from '../src/parsers/papi/usjBookExtractor'; +import { readCapturedBook, type UsjCaptureMeta } from './usj-cache'; + +function isUsjDocument(value: unknown): value is UsjDocument { + return !!value && typeof value === 'object' && 'content' in value && Array.isArray(value.content); +} + +/** Reads one captured book's USJ, typed as the extractor expects it. */ +export function readUsj(meta: UsjCaptureMeta, bookCode: string): UsjDocument { + const usj = readCapturedBook(meta.projectId, bookCode); + if (!isUsjDocument(usj)) throw new Error(`Captured ${bookCode} is not USJ`); + return usj; +} + +/** Tokenizes captured books exactly as the WebView does. */ +export function loadBooks(meta: UsjCaptureMeta, bookCodes: readonly string[]): Book[] { + return bookCodes.map((code) => + tokenizeBook(extractBookFromUsj(readUsj(meta, code), meta.languageTag || 'und')), + ); +} diff --git a/perf/dataset/cli.ts b/perf/dataset/cli.ts new file mode 100644 index 000000000..79375f608 --- /dev/null +++ b/perf/dataset/cli.ts @@ -0,0 +1,99 @@ +/* eslint-disable no-console -- a command-line tool reports to its terminal */ +import { execSync } from 'child_process'; +import type { Book, DraftProject, TextAnalysis } from 'interlinearizer'; +import { CURRENT_MODEL_VERSION } from '../../src/types/model-version'; +import { validateTextAnalysis } from '../../src/types/type-guards'; +import { splitAnalysisByBook } from '../../src/utils/analysis-book'; +import { reanchorAnalysisToBook } from '../../src/utils/reanchor-analysis'; +import { loadBooks } from '../books'; +import { hasCompleteCapture, readCaptureMeta } from '../usj-cache'; +import { generateAnalysis } from './generate'; +import { writeDataset, type DatasetManifest } from './store'; +import { DATASET_SEED, TIERS } from './tiers'; + +const ANALYSIS_LANGUAGE = 'en'; + +/** + * Fails unless the analysis is one the app loads without complaint or change: no invariant + * violations, and a re-anchor pass over every book that leaves it as it is. + */ +function assertSteadyState(analysis: TextAnalysis, books: Book[]): void { + const violations = validateTextAnalysis(analysis); + if (violations.length > 0) + throw new Error(`Generated analysis breaks invariants: ${JSON.stringify(violations)}`); + const now = new Date(0).toISOString(); + const moved = books.filter((book) => reanchorAnalysisToBook(analysis, book, now) !== analysis); + if (moved.length > 0) + throw new Error( + `Re-anchoring changes the generated analysis in ${moved.map((b) => b.bookRef)}`, + ); +} + +function countByStatus(statuses: string[]): Record { + const counts: Record = {}; + statuses.forEach((status) => { + counts[status] = (counts[status] ?? 0) + 1; + }); + return counts; +} + +function main(): void { + if (!hasCompleteCapture()) execSync('npm run perf:capture', { stdio: 'inherit' }); + const meta = readCaptureMeta(); + const requested = process.argv.slice(2); + const tiers = requested.length ? TIERS.filter((t) => requested.includes(t.name)) : TIERS; + + tiers.forEach((tier) => { + const started = Date.now(); + const bookCodes = tier.books === 'all' ? meta.books : tier.books; + const books = loadBooks(meta, bookCodes); + const analysis = generateAnalysis(books, tier, { + seed: DATASET_SEED, + analysisLanguage: ANALYSIS_LANGUAGE, + }); + assertSteadyState(analysis, books); + + const draft: DraftProject = { + sourceProjectId: meta.projectId, + modelVersion: CURRENT_MODEL_VERSION, + analysisLanguages: [ANALYSIS_LANGUAGE], + analysis, + dirty: false, + }; + const draftJson = JSON.stringify(draft); + const shardBytes = [...splitAnalysisByBook(analysis).values()].map( + (shard) => JSON.stringify(shard).length, + ); + + const manifest: DatasetManifest = { + tier, + seed: DATASET_SEED, + sourceProjectId: meta.projectId, + coreCommit: meta.coreCommit, + books: bookCodes, + counts: { + segments: books.reduce((n, b) => n + b.segments.length, 0), + wordTokens: books.reduce( + (n, b) => + n + + b.segments.reduce((m, s) => m + s.tokens.filter((t) => t.type === 'word').length, 0), + 0, + ), + tokenAnalyses: analysis.tokenAnalyses.length, + tokenAnalysisLinks: countByStatus(analysis.tokenAnalysisLinks.map((l) => l.status)), + phraseAnalyses: analysis.phraseAnalyses.length, + phraseAnalysisLinks: analysis.phraseAnalysisLinks.length, + segmentAnalyses: analysis.segmentAnalyses.length, + }, + bytes: { draftJson: Buffer.byteLength(draftJson), largestShard: Math.max(0, ...shardBytes) }, + }; + writeDataset(manifest, draftJson); + console.log( + `${tier.name}: ${bookCodes.length} book(s), ${manifest.counts.wordTokens} words, ` + + `${analysis.tokenAnalysisLinks.length} token links, ` + + `${(manifest.bytes.draftJson / 1e6).toFixed(1)} MB draft (${Date.now() - started} ms)`, + ); + }); +} + +main(); diff --git a/perf/dataset/generate.ts b/perf/dataset/generate.ts new file mode 100644 index 000000000..9d6c2ffc5 --- /dev/null +++ b/perf/dataset/generate.ts @@ -0,0 +1,227 @@ +import type { + Book, + MorphemeAnalysis, + PhraseAnalysis, + PhraseAnalysisLink, + Segment, + SegmentAnalysis, + SegmentAnalysisLink, + TextAnalysis, + Token, + TokenAnalysis, + TokenAnalysisLink, + TokenSnapshot, +} from 'interlinearizer'; +import { normalizeSurfaceForm } from '../../src/utils/analysis-identity'; +import { chance, createRng, intBetween, type Rng, uuid } from './rng'; +import type { TierSpec } from './tiers'; + +/** Inputs every generated record depends on besides the tier's shares. */ +export interface GenerateOptions { + seed: number; + analysisLanguage: string; +} + +const EPOCH = Date.parse('2026-01-01T00:00:00.000Z'); + +/** A stale snapshot's spelling, one no token of the text carries. */ +function staleSpelling(surfaceText: string): string { + return `${surfaceText}q`; +} + +/** A gloss of `form`'s given sense, about as long as the word it glosses. */ +function glossOf(form: string, sense: number): string { + const reversed = [...form].reverse().join(''); + return sense === 0 ? reversed : `${reversed}/${sense + 1}`; +} + +/** How many senses `form` has: one for most words, a few for some. */ +function senseCount(seed: number, form: string): number { + const draw = createRng(seed, 'senses', form)(); + if (draw < 0.7) return 1; + return draw < 0.9 ? 2 : 3; +} + +function isWord(token: Token): boolean { + return token.type === 'word'; +} + +function snapshotOf(token: Token): TokenSnapshot { + return { tokenRef: token.ref, surfaceText: token.surfaceText }; +} + +/** + * Builds a draft analysis over `books` shaped by `spec`, the same one every time for a given seed. + * + * Payloads are keyed by content, as the app shares them, so one payload backs its occurrences + * across every book. Stale links are stored already stale, the steady state a past re-anchor + * leaves, so loading a dataset gives the re-anchor pass work without making it write. + */ +export function generateAnalysis( + books: Book[], + spec: TierSpec, + { seed, analysisLanguage }: GenerateOptions, +): TextAnalysis { + const tokenAnalyses = new Map(); + const phraseAnalyses = new Map(); + const tokenAnalysisLinks: TokenAnalysisLink[] = []; + const phraseAnalysisLinks: PhraseAnalysisLink[] = []; + const segmentAnalyses: SegmentAnalysis[] = []; + const segmentAnalysisLinks: SegmentAnalysisLink[] = []; + + let clock = 0; + const nextStamp = (rng: Rng): string => { + clock += intBetween(rng, 1, 90_000); + return new Date(EPOCH + clock).toISOString(); + }; + + const tokenPayload = ( + surfaceText: string, + writingSystem: string, + sense: number, + rng: Rng, + ): TokenAnalysis => { + const form = normalizeSurfaceForm(surfaceText); + const key = `${form}\u0000${sense}`; + const existing = tokenAnalyses.get(key); + if (existing) return existing; + const idRng = createRng(seed, 'token-payload', key); + const stamp = nextStamp(rng); + const payload: TokenAnalysis = { + id: uuid(idRng), + createdAt: stamp, + updatedAt: stamp, + surfaceText, + gloss: { [analysisLanguage]: glossOf(form, sense) }, + }; + if (form.length > 3 && chance(idRng, spec.morphemeShare)) { + const cut = Math.ceil(form.length / 2); + payload.morphemes = [form.slice(0, cut), form.slice(cut)].map( + (part, index): MorphemeAnalysis => ({ + id: uuid(idRng), + form: index === 0 ? part : `-${part}`, + writingSystem, + gloss: { [analysisLanguage]: glossOf(part, 0) }, + }), + ); + } + tokenAnalyses.set(key, payload); + return payload; + }; + + const linkToken = ( + token: Token, + surfaceText: string, + sense: number, + status: TokenAnalysisLink['status'], + rng: Rng, + ) => { + const payload = tokenPayload(surfaceText, token.writingSystem, sense, rng); + const stamp = nextStamp(rng); + tokenAnalysisLinks.push({ + analysisId: payload.id, + createdAt: stamp, + updatedAt: stamp, + status, + token: { tokenRef: token.ref, surfaceText }, + }); + }; + + const linkPhrase = (tokens: Token[], rng: Rng) => { + const snapshots = tokens.map(snapshotOf); + const surfaceText = snapshots.map((s) => s.surfaceText).join(' '); + const key = normalizeSurfaceForm(surfaceText); + let payload = phraseAnalyses.get(key); + if (!payload) { + const stamp = nextStamp(rng); + payload = { + id: uuid(createRng(seed, 'phrase-payload', key)), + createdAt: stamp, + updatedAt: stamp, + surfaceText, + gloss: { [analysisLanguage]: glossOf(key, 0) }, + }; + phraseAnalyses.set(key, payload); + } + const stamp = nextStamp(rng); + phraseAnalysisLinks.push({ + id: uuid(rng), + analysisId: payload.id, + createdAt: stamp, + updatedAt: stamp, + status: 'approved', + tokens: snapshots, + }); + }; + + const translateSegment = (segment: Segment, rng: Rng) => { + const stale = chance(rng, spec.staleShare); + const stamp = nextStamp(rng); + const id = uuid(rng); + segmentAnalyses.push({ + id, + createdAt: stamp, + updatedAt: stamp, + surfaceText: stale ? staleSpelling(segment.baselineText) : segment.baselineText, + freeTranslation: { + [analysisLanguage]: segment.baselineText.split(/\s+/).reverse().join(' '), + }, + }); + segmentAnalysisLinks.push({ + analysisId: id, + segmentId: segment.id, + createdAt: stamp, + updatedAt: stamp, + status: stale ? 'stale' : 'approved', + }); + }; + + books.forEach((book) => { + const rng = createRng(seed, spec.coverage, 'book', book.bookRef); + const inPhrase = new Set(); + const segmentWords = book.segments.map((segment) => segment.tokens.filter(isWord)); + + book.segments.forEach((segment, segmentIndex) => { + if (chance(rng, spec.freeTranslationShare)) translateSegment(segment, rng); + const words = segmentWords[segmentIndex]; + + words.forEach((token, wordIndex) => { + if (!chance(rng, spec.coverage)) return; + const senses = senseCount(seed, normalizeSurfaceForm(token.surfaceText)); + const sense = intBetween(rng, 0, senses - 1); + + if (chance(rng, spec.staleShare)) { + linkToken(token, staleSpelling(token.surfaceText), sense, 'stale', rng); + } else { + linkToken(token, token.surfaceText, sense, 'approved', rng); + if (chance(rng, spec.competingShare)) { + const rival = (sense + 1) % Math.max(2, senses); + const status = chance(rng, 0.5) ? 'suggested' : 'rejected'; + linkToken(token, token.surfaceText, rival, status, rng); + } + } + + if (inPhrase.has(token.ref) || !chance(rng, spec.phraseShare)) return; + const next = book.segments[segmentIndex + 1]; + const nextWords = + next && !next.heading && !segment.heading ? segmentWords[segmentIndex + 1] : []; + const run = + nextWords.length > 0 && chance(rng, spec.crossSegmentPhraseShare) + ? [words[words.length - 1], nextWords[0]] + : words.slice(wordIndex, wordIndex + intBetween(rng, 2, 3)); + if (run.length < 2 || run.some((t) => inPhrase.has(t.ref))) return; + run.forEach((t) => inPhrase.add(t.ref)); + linkPhrase(run, rng); + }); + }); + }); + + return { + segmentAnalyses, + segmentAnalysisLinks, + tokenAnalyses: [...tokenAnalyses.values()], + tokenAnalysisLinks, + phraseAnalyses: [...phraseAnalyses.values()], + phraseAnalysisLinks, + }; +} diff --git a/perf/dataset/rng.ts b/perf/dataset/rng.ts new file mode 100644 index 000000000..9ec683c03 --- /dev/null +++ b/perf/dataset/rng.ts @@ -0,0 +1,47 @@ +/** A seeded source of uniform numbers in `[0, 1)`. */ +export type Rng = () => number; + +/** 32-bit FNV-1a hash of a string. */ +export function hashString(text: string): number { + let hash = 0x811c9dc5; + for (let i = 0; i < text.length; i += 1) { + // eslint-disable-next-line no-bitwise + hash ^= text.charCodeAt(i); + hash = Math.imul(hash, 0x01000193); + } + // eslint-disable-next-line no-bitwise + return hash >>> 0; +} + +/** Mulberry32, seeded from every key given, so equal keys always replay the same sequence. */ +export function createRng(...keys: (string | number)[]): Rng { + let state = hashString(keys.join('\u0000')); + return () => { + /* eslint-disable no-bitwise */ + state = (state + 0x6d2b79f5) >>> 0; + let t = state; + t = Math.imul(t ^ (t >>> 15), t | 1); + t ^= t + Math.imul(t ^ (t >>> 7), t | 61); + return ((t ^ (t >>> 14)) >>> 0) / 4294967296; + /* eslint-enable no-bitwise */ + }; +} + +/** Whether an event of probability `p` happens. */ +export function chance(rng: Rng, p: number): boolean { + return rng() < p; +} + +/** A uniform integer in `[min, max]`. */ +export function intBetween(rng: Rng, min: number, max: number): number { + return min + Math.floor(rng() * (max - min + 1)); +} + +/** A version-4-shaped UUID drawn from `rng`. */ +export function uuid(rng: Rng): string { + const hex = Array.from({ length: 32 }, () => Math.floor(rng() * 16).toString(16)); + hex[12] = '4'; + hex[16] = (8 + Math.floor(rng() * 4)).toString(16); + const s = hex.join(''); + return `${s.slice(0, 8)}-${s.slice(8, 12)}-${s.slice(12, 16)}-${s.slice(16, 20)}-${s.slice(20)}`; +} diff --git a/perf/dataset/store.ts b/perf/dataset/store.ts new file mode 100644 index 000000000..2ea3e1be3 --- /dev/null +++ b/perf/dataset/store.ts @@ -0,0 +1,51 @@ +import fs from 'fs'; +import path from 'path'; +import { DATASETS_DIR } from '../paths'; +import type { TierSpec } from './tiers'; + +/** What a generated dataset holds, recorded beside it so results can be read against its size. */ +export interface DatasetManifest { + tier: TierSpec; + seed: number; + sourceProjectId: string; + /** Paranext-core commit whose USJ the dataset was generated from. */ + coreCommit: string; + books: string[]; + counts: { + segments: number; + wordTokens: number; + tokenAnalyses: number; + tokenAnalysisLinks: Record; + phraseAnalyses: number; + phraseAnalysisLinks: number; + segmentAnalyses: number; + }; + bytes: { + /** The draft as `saveDraft` receives it. */ + draftJson: number; + /** The largest one book's shard of the draft as storage holds it. */ + largestShard: number; + }; +} + +function tierDir(tier: string): string { + return path.join(DATASETS_DIR, tier); +} + +/** Stores a generated tier beside its manifest. */ +export function writeDataset(manifest: DatasetManifest, draftJson: string): void { + const dir = tierDir(manifest.tier.name); + fs.mkdirSync(dir, { recursive: true }); + fs.writeFileSync(path.join(dir, 'draft.json'), draftJson); + fs.writeFileSync(path.join(dir, 'manifest.json'), JSON.stringify(manifest, undefined, 2)); +} + +/** Reads a generated tier's manifest. */ +export function readManifest(tier: string): DatasetManifest { + return JSON.parse(fs.readFileSync(path.join(tierDir(tier), 'manifest.json'), 'utf-8')); +} + +/** The draft exactly as generated, unparsed, so a caller measuring serialization starts from text. */ +export function readDraftJson(tier: string): string { + return fs.readFileSync(path.join(tierDir(tier), 'draft.json'), 'utf-8'); +} diff --git a/perf/dataset/tiers.ts b/perf/dataset/tiers.ts new file mode 100644 index 000000000..e3fe9baca --- /dev/null +++ b/perf/dataset/tiers.ts @@ -0,0 +1,55 @@ +/** The shape of one dataset tier's analysis. Every share is a probability in `[0, 1]`. */ +export interface TierSpec { + name: string; + /** Book codes analyzed, or every captured book. */ + books: string[] | 'all'; + /** Book the view is opened on when measuring loads and edits. */ + viewBook: string; + /** Share of word tokens carrying a gloss, approved or stale. */ + coverage: number; + /** Share of glossed tokens whose gloss is stale. */ + staleShare: number; + /** Share of glossed tokens also carrying a suggested or rejected competitor. */ + competingShare: number; + /** Share of glossed word tokens that start an approved phrase. */ + phraseShare: number; + /** Share of phrases that run on into the next segment. */ + crossSegmentPhraseShare: number; + /** Share of segments carrying a free translation. */ + freeTranslationShare: number; + /** Share of token payloads carrying a morpheme breakdown. */ + morphemeShare: number; + /** Saved projects per source, each holding the draft's analysis. */ + savedProjects: number; +} + +const SHAPE = { + staleShare: 0.03, + competingShare: 0.1, + phraseShare: 0.02, + crossSegmentPhraseShare: 0.1, + freeTranslationShare: 0.3, + morphemeShare: 0.2, + savedProjects: 5, +}; + +/** Sizes run for every metric, so cost can be read as a function of size. */ +export const TIERS: TierSpec[] = [ + { name: 'small', books: ['PHP'], viewBook: 'PHP', coverage: 1, ...SHAPE }, + { name: 'medium', books: ['PSA'], viewBook: 'PSA', coverage: 1, ...SHAPE }, + // Larger than one websocket message can carry, so the app cannot load it. + { name: 'large', books: 'all', viewBook: 'PSA', coverage: 0.5, ...SHAPE }, + // The whole Bible at the coverage whose draft, and the list of its saved projects, each fit one + // message. + { + name: 'large-loadable', + books: 'all', + viewBook: 'PSA', + coverage: 0.3, + ...SHAPE, + savedProjects: 1, + }, +]; + +/** Seed every dataset is generated from. */ +export const DATASET_SEED = 407; diff --git a/perf/paths.ts b/perf/paths.ts new file mode 100644 index 000000000..62622c221 --- /dev/null +++ b/perf/paths.ts @@ -0,0 +1,24 @@ +import path from 'path'; + +/** Root of the performance harness. */ +export const PERF_DIR = __dirname; + +/** Gitignored scratch space for captured text and generated datasets. */ +export const CACHE_DIR = path.join(PERF_DIR, '.cache'); + +/** Captured USJ, one directory per source project. */ +export const USJ_CACHE_DIR = path.join(CACHE_DIR, 'usj'); + +/** Generated datasets, one directory per tier. */ +export const DATASETS_DIR = path.join(CACHE_DIR, 'datasets'); + +/** Committed result files. */ +export const RESULTS_DIR = path.join(PERF_DIR, 'results'); + +/** Short name of the platform's bundled sample project, the text every tier is drawn from. */ +export const SOURCE_PROJECT_NAME = 'WEB'; + +/** Directory holding one project's captured USJ. */ +export function usjDirFor(projectId: string): string { + return path.join(USJ_CACHE_DIR, projectId); +} diff --git a/perf/results.ts b/perf/results.ts new file mode 100644 index 000000000..e110b7456 --- /dev/null +++ b/perf/results.ts @@ -0,0 +1,42 @@ +import { execFileSync } from 'child_process'; +import fs from 'fs'; +import os from 'os'; +import path from 'path'; +import { RESULTS_DIR } from './paths'; + +/** What every result file records about where and on what code it was measured. */ +export function provenance(coreCommit: string) { + const cpus = os.cpus(); + return { + commit: execFileSync('git', ['rev-parse', 'HEAD']).toString().trim(), + // Results written or removed by earlier runs change nothing that is measured. + dirty: + execFileSync('git', ['status', '--porcelain', '--', ':(top)', ':(top,exclude)perf/results']) + .toString() + .trim().length > 0, + coreCommit, + recordedAt: new Date().toISOString(), + machine: { + cpu: cpus[0]?.model, + cores: cpus.length, + memoryGb: Math.round(os.totalmem() / 1e9), + os: `${os.type()} ${os.release()}`, + node: process.version, + loadAverage: os.loadavg(), + }, + }; +} + +/** Writes a result file named for its kind, time, and commit, returning its path. */ +export function writeResults( + kind: string, + results: T, +): string { + fs.mkdirSync(RESULTS_DIR, { recursive: true }); + const file = path.join( + RESULTS_DIR, + `${kind}-${results.recordedAt.slice(0, 19).replace(/:/g, '')}-${results.commit.slice(0, 8)}.json`, + ); + fs.writeFileSync(file, `${JSON.stringify({ kind, ...results }, undefined, 2)}\n`); + return file; +} diff --git a/perf/results/app-2026-10-13T2005-5bfb334e.json b/perf/results/app-2026-10-13T2005-5bfb334e.json new file mode 100644 index 000000000..9045303cd --- /dev/null +++ b/perf/results/app-2026-10-13T2005-5bfb334e.json @@ -0,0 +1,1521 @@ +{ + "kind": "app", + "commit": "5bfb334e0a2bceb5d7e99f635a7d5a5ca810faae", + "dirty": false, + "coreCommit": "0d06e2f782fd98d4469d461ccc52a4c17bd0eed9", + "recordedAt": "2026-10-13T20:05:24.004Z", + "machine": { + "cpu": "12th Gen Intel(R) Core(TM) i7-12700KF", + "cores": 20, + "memoryGb": 34, + "os": "Windows_NT 10.0.26200", + "node": "v25.8.1", + "loadAverage": [0, 0, 0] + }, + "appBuild": "packaged", + "extensionBuild": "production", + "runs": 10, + "tiers": { + "small": { + "viewBook": "PHP", + "dataset": { + "counts": { + "segments": 104, + "wordTokens": 2219, + "tokenAnalyses": 757, + "tokenAnalysisLinks": { + "approved": 2150, + "suggested": 105, + "rejected": 112, + "stale": 69 + }, + "phraseAnalyses": 42, + "phraseAnalysisLinks": 42, + "segmentAnalyses": 25 + }, + "bytes": { + "draftJson": 697387, + "largestShard": 697187 + } + }, + "wireBytes": { + "draft": 785687, + "projectsForSource": 3928435 + }, + "cold": { + "webView": { + "app-startup": { + "runs": 10, + "medianMs": 2194, + "p90Ms": 2214, + "minMs": 2180, + "maxMs": 3006 + }, + "usj-fetch": { + "runs": 10, + "medianMs": 183.4, + "p90Ms": 248.6, + "minMs": 165.6, + "maxMs": 254.9 + }, + "book-render": { + "runs": 10, + "medianMs": 256.6, + "p90Ms": 320.5, + "minMs": 236.1, + "maxMs": 328.3 + }, + "draft-fetch": { + "runs": 10, + "medianMs": 57.5, + "p90Ms": 62.8, + "minMs": 53.4, + "maxMs": 63.1 + }, + "draft-parse": { + "runs": 10, + "medianMs": 1, + "p90Ms": 1.2, + "minMs": 0.9, + "maxMs": 1.2 + }, + "store-mount": { + "runs": 10, + "medianMs": 4.7, + "p90Ms": 5.6, + "minMs": 4.5, + "maxMs": 6.3 + }, + "tokenize": { + "runs": 10, + "medianMs": 6, + "p90Ms": 6.1, + "minMs": 5.9, + "maxMs": 6.1 + }, + "reanchor": { + "runs": 10, + "medianMs": 8.8, + "p90Ms": 9.2, + "minMs": 8.5, + "maxMs": 9.5 + }, + "open-to-interactive": { + "runs": 10, + "medianMs": 541, + "p90Ms": 592.7, + "minMs": 503.5, + "maxMs": 598 + }, + "draft-fetch:transport": { + "runs": 10, + "medianMs": 48.893, + "p90Ms": 53.069, + "minMs": 45.106, + "maxMs": 53.282 + } + }, + "host": { + "draft-fetch": { + "runs": 10, + "medianMs": 8.907, + "p90Ms": 9.731, + "minMs": 8.107, + "maxMs": 12.088 + }, + "draft-fetch:read": { + "runs": 10, + "medianMs": 1.908, + "p90Ms": 2.478, + "minMs": 1.714, + "maxMs": 5.403 + }, + "draft-fetch:parse": { + "runs": 10, + "medianMs": 4.129, + "p90Ms": 4.598, + "minMs": 3.822, + "maxMs": 4.613 + }, + "draft-fetch:compare": { + "runs": 10, + "medianMs": 1.012, + "p90Ms": 1.115, + "minMs": 0.979, + "maxMs": 1.205 + }, + "draft-fetch:serialize": { + "runs": 10, + "medianMs": 0.878, + "p90Ms": 0.95, + "minMs": 0.85, + "maxMs": 1.021 + } + } + }, + "memory": { + "webView": { + "heapBeforeOpenBytes": 17384124, + "viewLoadedBytes": 79232272, + "withFullUndoHistoryBytes": 39964632, + "afterPickerBytes": 40415644, + "afterSaveBytes": 22948660 + }, + "host": { + "heapBeforeOpenBytes": 88367796, + "viewLoadedBytes": 3052160, + "viewLoadedExternalBytes": 40, + "viewLoadedRssBytes": 4239360, + "withFullUndoHistoryBytes": 3135612, + "withFullUndoHistoryExternalBytes": 40, + "withFullUndoHistoryRssBytes": 4321280, + "afterPickerBytes": 4279132, + "afterPickerExternalBytes": 1219904, + "afterPickerRssBytes": 8794112, + "afterSaveBytes": 3963340, + "afterSaveExternalBytes": 1211712, + "afterSaveRssBytes": 8560640 + } + }, + "open": { + "webView": { + "usj-fetch": { + "runs": 10, + "medianMs": 94.7, + "p90Ms": 98.6, + "minMs": 85.7, + "maxMs": 169.7 + }, + "book-render": { + "runs": 10, + "medianMs": 149, + "p90Ms": 176.2, + "minMs": 137.8, + "maxMs": 240.4 + }, + "draft-fetch": { + "runs": 10, + "medianMs": 60.1, + "p90Ms": 66.6, + "minMs": 57.5, + "maxMs": 67.4 + }, + "draft-parse": { + "runs": 10, + "medianMs": 1, + "p90Ms": 1.1, + "minMs": 1, + "maxMs": 1.1 + }, + "store-mount": { + "runs": 10, + "medianMs": 4.7, + "p90Ms": 4.9, + "minMs": 4.3, + "maxMs": 11.8 + }, + "tokenize": { + "runs": 10, + "medianMs": 1.7, + "p90Ms": 2.7, + "minMs": 1.5, + "maxMs": 6 + }, + "reanchor": { + "runs": 10, + "medianMs": 8.3, + "p90Ms": 8.7, + "minMs": 8, + "maxMs": 9 + }, + "open-to-interactive": { + "runs": 10, + "medianMs": 410.1, + "p90Ms": 438.4, + "minMs": 399.4, + "maxMs": 510.1 + }, + "draft-fetch:transport": { + "runs": 10, + "medianMs": 52.975, + "p90Ms": 59.485, + "minMs": 50.871, + "maxMs": 60.583 + } + }, + "host": { + "draft-fetch": { + "runs": 10, + "medianMs": 6.679, + "p90Ms": 7.115, + "minMs": 6.479, + "maxMs": 9.246 + }, + "draft-fetch:read": { + "runs": 10, + "medianMs": 1.543, + "p90Ms": 1.828, + "minMs": 1.395, + "maxMs": 1.912 + }, + "draft-fetch:parse": { + "runs": 10, + "medianMs": 3.023, + "p90Ms": 3.362, + "minMs": 2.828, + "maxMs": 4.747 + }, + "draft-fetch:compare": { + "runs": 10, + "medianMs": 1.036, + "p90Ms": 1.113, + "minMs": 0.99, + "maxMs": 1.135 + }, + "draft-fetch:serialize": { + "runs": 10, + "medianMs": 0.917, + "p90Ms": 0.993, + "minMs": 0.811, + "maxMs": 0.998 + } + } + }, + "switchBook": { + "usj-fetch": { + "runs": 10, + "medianMs": 11, + "p90Ms": 12.1, + "minMs": 9.7, + "maxMs": 12.9 + }, + "book-render": { + "runs": 10, + "medianMs": 49.4, + "p90Ms": 53, + "minMs": 47.1, + "maxMs": 53.3 + }, + "tokenize": { + "runs": 10, + "medianMs": 0.8, + "p90Ms": 1.3, + "minMs": 0.6, + "maxMs": 1.5 + }, + "reanchor": { + "runs": 10, + "medianMs": 5.9, + "p90Ms": 7.5, + "minMs": 5.1, + "maxMs": 7.8 + } + }, + "edit": { + "webView": { + "dispatch-render": { + "runs": 10, + "medianMs": 4.8, + "p90Ms": 6.7, + "minMs": 3.9, + "maxMs": 9 + }, + "autosave-serialize": { + "runs": 10, + "medianMs": 1.8, + "p90Ms": 1.9, + "minMs": 1.7, + "maxMs": 2 + }, + "autosave": { + "runs": 10, + "medianMs": 17.8, + "p90Ms": 29.4, + "minMs": 16.2, + "maxMs": 38.4 + }, + "autosave:transport": { + "runs": 10, + "medianMs": 10.815, + "p90Ms": 14.441, + "minMs": 10.425, + "maxMs": 33.102 + } + }, + "host": { + "autosave": { + "runs": 10, + "medianMs": 6.456, + "p90Ms": 12.975, + "minMs": 5.298, + "maxMs": 14.959 + }, + "autosave:parse": { + "runs": 10, + "medianMs": 0.998, + "p90Ms": 1.12, + "minMs": 0.965, + "maxMs": 1.372 + }, + "autosave:read": { + "runs": 10, + "medianMs": 0.553, + "p90Ms": 1.367, + "minMs": 0.475, + "maxMs": 3.073 + }, + "autosave:compare": { + "runs": 10, + "medianMs": 1.773, + "p90Ms": 2.279, + "minMs": 1.455, + "maxMs": 3.05 + }, + "autosave:write": { + "runs": 10, + "medianMs": 2.42, + "p90Ms": 7.567, + "minMs": 2.179, + "maxMs": 8.958 + } + } + }, + "picker": { + "webView": { + "projects-fetch": { + "runs": 10, + "medianMs": 58.8, + "p90Ms": 61.2, + "minMs": 58, + "maxMs": 61.4 + }, + "projects-fetch:transport": { + "runs": 10, + "medianMs": 43.529, + "p90Ms": 45.758, + "minMs": 35.513, + "maxMs": 46.584 + } + }, + "host": { + "projects-fetch": { + "runs": 10, + "medianMs": 14.969, + "p90Ms": 21.852, + "minMs": 14.242, + "maxMs": 25.687 + }, + "projects-fetch:read": { + "runs": 10, + "medianMs": 3.388, + "p90Ms": 7.028, + "minMs": 3.258, + "maxMs": 9.12 + }, + "projects-fetch:parse": { + "runs": 10, + "medianMs": 10.786, + "p90Ms": 14.23, + "minMs": 10.283, + "maxMs": 15.675 + }, + "projects-fetch:serialize": { + "runs": 10, + "medianMs": 0.57, + "p90Ms": 0.738, + "minMs": 0.531, + "maxMs": 0.762 + } + } + }, + "save": { + "webView": { + "save": { + "runs": 10, + "medianMs": 66, + "p90Ms": 71, + "minMs": 61.6, + "maxMs": 72.2 + }, + "save-bytes": { + "runs": 10, + "medianMs": 697187, + "p90Ms": 697187, + "minMs": 697187, + "maxMs": 697187 + }, + "save:transport": { + "runs": 10, + "medianMs": 57.147, + "p90Ms": 62.678, + "minMs": 52.516, + "maxMs": 63.301 + } + }, + "host": { + "save": { + "runs": 10, + "medianMs": 8.899, + "p90Ms": 10.514, + "minMs": 8.322, + "maxMs": 10.868 + }, + "save:parse": { + "runs": 10, + "medianMs": 4.273, + "p90Ms": 4.817, + "minMs": 3.961, + "maxMs": 5.753 + }, + "save:read": { + "runs": 10, + "medianMs": 1.005, + "p90Ms": 1.015, + "minMs": 0.949, + "maxMs": 1.442 + }, + "save:write": { + "runs": 10, + "medianMs": 2.55, + "p90Ms": 3.032, + "minMs": 2.319, + "maxMs": 3.255 + }, + "save:serialize": { + "runs": 10, + "medianMs": 0.85, + "p90Ms": 0.953, + "minMs": 0.805, + "maxMs": 1.07 + } + } + }, + "concordance": { + "concordance-read": { + "runs": 10, + "medianMs": 1000.7, + "p90Ms": 1057.3, + "minMs": 990.5, + "maxMs": 1060 + }, + "concordance-entries": { + "runs": 10, + "medianMs": 43.1, + "p90Ms": 46.5, + "minMs": 41.4, + "maxMs": 52.9 + } + } + }, + "medium": { + "viewBook": "PSA", + "dataset": { + "counts": { + "segments": 2583, + "wordTokens": 41324, + "tokenAnalyses": 4797, + "tokenAnalysisLinks": { + "approved": 40059, + "suggested": 1963, + "rejected": 1965, + "stale": 1265 + }, + "phraseAnalyses": 756, + "phraseAnalysisLinks": 786, + "segmentAnalyses": 718 + }, + "bytes": { + "draftJson": 11247593, + "largestShard": 11245223 + } + }, + "wireBytes": { + "draft": 12645397, + "projectsForSource": 63226985 + }, + "cold": { + "webView": { + "app-startup": { + "runs": 10, + "medianMs": 2208, + "p90Ms": 4518, + "minMs": 2178, + "maxMs": 4521 + }, + "usj-fetch": { + "runs": 10, + "medianMs": 577.6, + "p90Ms": 619.5, + "minMs": 569.4, + "maxMs": 623.5 + }, + "book-render": { + "runs": 10, + "medianMs": 730.2, + "p90Ms": 768.7, + "minMs": 714.9, + "maxMs": 769.9 + }, + "draft-fetch": { + "runs": 10, + "medianMs": 300.7, + "p90Ms": 329.6, + "minMs": 287.2, + "maxMs": 340.5 + }, + "draft-parse": { + "runs": 10, + "medianMs": 16, + "p90Ms": 16.4, + "minMs": 15.7, + "maxMs": 16.5 + }, + "store-mount": { + "runs": 10, + "medianMs": 18, + "p90Ms": 18.4, + "minMs": 17.9, + "maxMs": 18.7 + }, + "tokenize": { + "runs": 10, + "medianMs": 22.9, + "p90Ms": 23.6, + "minMs": 22.6, + "maxMs": 28.3 + }, + "reanchor": { + "runs": 10, + "medianMs": 127.9, + "p90Ms": 130.7, + "minMs": 121.5, + "maxMs": 133.5 + }, + "open-to-interactive": { + "runs": 10, + "medianMs": 1122.7, + "p90Ms": 1156.9, + "minMs": 1109.2, + "maxMs": 1163.9 + }, + "draft-fetch:transport": { + "runs": 10, + "medianMs": 201.612, + "p90Ms": 216.005, + "minMs": 190.963, + "maxMs": 226.029 + } + }, + "host": { + "draft-fetch": { + "runs": 10, + "medianMs": 98.317, + "p90Ms": 120.63, + "minMs": 96.237, + "maxMs": 124.495 + }, + "draft-fetch:read": { + "runs": 10, + "medianMs": 15.016, + "p90Ms": 34.587, + "minMs": 11.271, + "maxMs": 34.999 + }, + "draft-fetch:parse": { + "runs": 10, + "medianMs": 42.469, + "p90Ms": 43.444, + "minMs": 41.754, + "maxMs": 44.424 + }, + "draft-fetch:compare": { + "runs": 10, + "medianMs": 21.384, + "p90Ms": 23.273, + "minMs": 19.815, + "maxMs": 23.452 + }, + "draft-fetch:serialize": { + "runs": 10, + "medianMs": 20.942, + "p90Ms": 22.453, + "minMs": 18.91, + "maxMs": 22.917 + } + } + }, + "memory": { + "webView": { + "heapBeforeOpenBytes": 17339216, + "viewLoadedBytes": 207537352, + "withFullUndoHistoryBytes": 249602616, + "afterPickerBytes": 250052636, + "afterSaveBytes": 60920628 + }, + "host": { + "heapBeforeOpenBytes": 88401480, + "viewLoadedBytes": 24126288, + "viewLoadedExternalBytes": 40, + "viewLoadedRssBytes": 25378816, + "withFullUndoHistoryBytes": 25446164, + "withFullUndoHistoryExternalBytes": 1203520, + "withFullUndoHistoryRssBytes": 31121408, + "afterPickerBytes": 25090656, + "afterPickerExternalBytes": 1211712, + "afterPickerRssBytes": 31236096, + "afterSaveBytes": 25122096, + "afterSaveExternalBytes": 1211712, + "afterSaveRssBytes": 30765056 + } + }, + "open": { + "webView": { + "usj-fetch": { + "runs": 10, + "medianMs": 478.3, + "p90Ms": 540.6, + "minMs": 436.2, + "maxMs": 590.4 + }, + "book-render": { + "runs": 10, + "medianMs": 611.3, + "p90Ms": 675.2, + "minMs": 570.4, + "maxMs": 742.7 + }, + "draft-fetch": { + "runs": 10, + "medianMs": 304.5, + "p90Ms": 316.7, + "minMs": 292.7, + "maxMs": 319.5 + }, + "draft-parse": { + "runs": 10, + "medianMs": 15.2, + "p90Ms": 22.1, + "minMs": 14.7, + "maxMs": 23.7 + }, + "store-mount": { + "runs": 10, + "medianMs": 17, + "p90Ms": 20.8, + "minMs": 16.6, + "maxMs": 30.5 + }, + "tokenize": { + "runs": 10, + "medianMs": 21.2, + "p90Ms": 24, + "minMs": 19.4, + "maxMs": 27.5 + }, + "reanchor": { + "runs": 10, + "medianMs": 125.4, + "p90Ms": 129.5, + "minMs": 122.4, + "maxMs": 138.8 + }, + "open-to-interactive": { + "runs": 10, + "medianMs": 989.5, + "p90Ms": 1048.3, + "minMs": 946.2, + "maxMs": 1131.2 + }, + "draft-fetch:transport": { + "runs": 10, + "medianMs": 196.371, + "p90Ms": 204.116, + "minMs": 184.235, + "maxMs": 210.673 + } + }, + "host": { + "draft-fetch": { + "runs": 10, + "medianMs": 108.465, + "p90Ms": 115.384, + "minMs": 93.627, + "maxMs": 118.389 + }, + "draft-fetch:read": { + "runs": 10, + "medianMs": 27.759, + "p90Ms": 35.979, + "minMs": 11.091, + "maxMs": 40.114 + }, + "draft-fetch:parse": { + "runs": 10, + "medianMs": 38.194, + "p90Ms": 56.599, + "minMs": 35.339, + "maxMs": 63.611 + }, + "draft-fetch:compare": { + "runs": 10, + "medianMs": 19.185, + "p90Ms": 20.223, + "minMs": 15.727, + "maxMs": 24.526 + }, + "draft-fetch:serialize": { + "runs": 10, + "medianMs": 17.873, + "p90Ms": 20.483, + "minMs": 16.73, + "maxMs": 22.407 + } + } + }, + "switchBook": { + "usj-fetch": { + "runs": 10, + "medianMs": 92.4, + "p90Ms": 112.3, + "minMs": 84.7, + "maxMs": 139 + }, + "book-render": { + "runs": 10, + "medianMs": 176.8, + "p90Ms": 207.1, + "minMs": 167.3, + "maxMs": 219.9 + }, + "tokenize": { + "runs": 10, + "medianMs": 18.2, + "p90Ms": 20.2, + "minMs": 15.8, + "maxMs": 26.7 + }, + "reanchor": { + "runs": 10, + "medianMs": 124.2, + "p90Ms": 128.3, + "minMs": 119.8, + "maxMs": 135.3 + } + }, + "edit": { + "webView": { + "dispatch-render": { + "runs": 10, + "medianMs": 63.5, + "p90Ms": 66.1, + "minMs": 62.2, + "maxMs": 67.8 + }, + "autosave-serialize": { + "runs": 10, + "medianMs": 27.7, + "p90Ms": 28.8, + "minMs": 26.7, + "maxMs": 29.4 + }, + "autosave": { + "runs": 10, + "medianMs": 241.7, + "p90Ms": 256.6, + "minMs": 232.8, + "maxMs": 260.1 + }, + "autosave:transport": { + "runs": 10, + "medianMs": 168.794, + "p90Ms": 185.165, + "minMs": 161.569, + "maxMs": 185.921 + } + }, + "host": { + "autosave": { + "runs": 10, + "medianMs": 72.185, + "p90Ms": 74.038, + "minMs": 71.011, + "maxMs": 74.179 + }, + "autosave:parse": { + "runs": 10, + "medianMs": 21.767, + "p90Ms": 21.904, + "minMs": 19.151, + "maxMs": 22.317 + }, + "autosave:read": { + "runs": 10, + "medianMs": 8.236, + "p90Ms": 10.666, + "minMs": 0.844, + "maxMs": 10.859 + }, + "autosave:compare": { + "runs": 10, + "medianMs": 24.34, + "p90Ms": 24.667, + "minMs": 23.429, + "maxMs": 25.18 + }, + "autosave:write": { + "runs": 10, + "medianMs": 16.976, + "p90Ms": 17.332, + "minMs": 16.265, + "maxMs": 17.751 + } + } + }, + "picker": { + "webView": { + "projects-fetch": { + "runs": 10, + "medianMs": 277.2, + "p90Ms": 290.6, + "minMs": 263.7, + "maxMs": 293.9 + }, + "projects-fetch:transport": { + "runs": 10, + "medianMs": 13.402, + "p90Ms": 14.195, + "minMs": 13.249, + "maxMs": 15.225 + } + }, + "host": { + "projects-fetch": { + "runs": 10, + "medianMs": 263.163, + "p90Ms": 276.671, + "minMs": 249.505, + "maxMs": 280.596 + }, + "projects-fetch:read": { + "runs": 10, + "medianMs": 46.068, + "p90Ms": 57.456, + "minMs": 41.622, + "maxMs": 67.19 + }, + "projects-fetch:parse": { + "runs": 10, + "medianMs": 194.998, + "p90Ms": 210.558, + "minMs": 193.078, + "maxMs": 214.721 + }, + "projects-fetch:serialize": { + "runs": 10, + "medianMs": 9.291, + "p90Ms": 26.925, + "minMs": 8.914, + "maxMs": 28.861 + } + } + }, + "save": { + "webView": { + "save": { + "runs": 10, + "medianMs": 498.5, + "p90Ms": 501.7, + "minMs": 491.7, + "maxMs": 508.8 + }, + "save-bytes": { + "runs": 10, + "medianMs": 11245223, + "p90Ms": 11245223, + "minMs": 11245223, + "maxMs": 11245223 + }, + "save:transport": { + "runs": 10, + "medianMs": 350.385, + "p90Ms": 354.91, + "minMs": 345.424, + "maxMs": 362.247 + } + }, + "host": { + "save": { + "runs": 10, + "medianMs": 146.476, + "p90Ms": 147.709, + "minMs": 144.931, + "maxMs": 150.674 + }, + "save:parse": { + "runs": 10, + "medianMs": 77.361, + "p90Ms": 78.259, + "minMs": 69.783, + "maxMs": 79.305 + }, + "save:read": { + "runs": 10, + "medianMs": 17.268, + "p90Ms": 22.884, + "minMs": 16.389, + "maxMs": 23.283 + }, + "save:write": { + "runs": 10, + "medianMs": 33.283, + "p90Ms": 33.977, + "minMs": 32.595, + "maxMs": 34.035 + }, + "save:serialize": { + "runs": 10, + "medianMs": 17.342, + "p90Ms": 17.556, + "minMs": 16.992, + "maxMs": 17.923 + } + } + }, + "concordance": { + "concordance-read": { + "runs": 10, + "medianMs": 1022.6, + "p90Ms": 1050.2, + "minMs": 986.4, + "maxMs": 1063.6 + }, + "concordance-entries": { + "runs": 10, + "medianMs": 42.1, + "p90Ms": 45.6, + "minMs": 40.2, + "maxMs": 48.5 + } + } + }, + "large": { + "viewBook": "PSA", + "dataset": { + "counts": { + "segments": 37691, + "wordTokens": 905971, + "tokenAnalyses": 20247, + "tokenAnalysisLinks": { + "approved": 438765, + "suggested": 21720, + "stale": 13454, + "rejected": 21885 + }, + "phraseAnalyses": 7633, + "phraseAnalysisLinks": 8687, + "segmentAnalyses": 11278 + }, + "bytes": { + "draftJson": 118832401, + "largestShard": 6013928 + } + }, + "wireBytes": { + "draft": 133323513, + "projectsForSource": 666617565 + }, + "skipped": "The draft is 133.3 MB on the wire, over the websocket's per-message cap; the app cannot load it." + }, + "large-loadable": { + "viewBook": "PSA", + "dataset": { + "counts": { + "segments": 37691, + "wordTokens": 905971, + "tokenAnalyses": 16325, + "tokenAnalysisLinks": { + "approved": 262670, + "stale": 8121, + "suggested": 13072, + "rejected": 13201 + }, + "phraseAnalyses": 4725, + "phraseAnalysisLinks": 5197, + "segmentAnalyses": 11443 + }, + "bytes": { + "draftJson": 74928129, + "largestShard": 3903920 + } + }, + "wireBytes": { + "draft": 83934389, + "projectsForSource": 83934389 + }, + "cold": { + "webView": { + "app-startup": { + "runs": 10, + "medianMs": 2195, + "p90Ms": 2200, + "minMs": 2175, + "maxMs": 2228 + }, + "usj-fetch": { + "runs": 10, + "medianMs": 2492.3, + "p90Ms": 2504.9, + "minMs": 2418.7, + "maxMs": 2510.7 + }, + "book-render": { + "runs": 10, + "medianMs": 2800.5, + "p90Ms": 2811.8, + "minMs": 2724.4, + "maxMs": 2817.9 + }, + "draft-fetch": { + "runs": 10, + "medianMs": 2074.5, + "p90Ms": 2088.7, + "minMs": 2012.8, + "maxMs": 2103.4 + }, + "draft-parse": { + "runs": 10, + "medianMs": 134.7, + "p90Ms": 136.5, + "minMs": 131.3, + "maxMs": 136.9 + }, + "store-mount": { + "runs": 10, + "medianMs": 88.8, + "p90Ms": 90.7, + "minMs": 87.3, + "maxMs": 92.1 + }, + "tokenize": { + "runs": 10, + "medianMs": 23.5, + "p90Ms": 23.8, + "minMs": 23.3, + "maxMs": 23.8 + }, + "reanchor": { + "runs": 10, + "medianMs": 311.9, + "p90Ms": 318.9, + "minMs": 309.8, + "maxMs": 319.7 + }, + "open-to-interactive": { + "runs": 10, + "medianMs": 3376.2, + "p90Ms": 3388.5, + "minMs": 3297.1, + "maxMs": 3396.7 + }, + "draft-fetch:transport": { + "runs": 10, + "medianMs": 1380.587, + "p90Ms": 1396.035, + "minMs": 1295.751, + "maxMs": 1405.287 + } + }, + "host": { + "draft-fetch": { + "runs": 10, + "medianMs": 690.796, + "p90Ms": 717.049, + "minMs": 683.413, + "maxMs": 722.813 + }, + "draft-fetch:read": { + "runs": 10, + "medianMs": 114.954, + "p90Ms": 122.206, + "minMs": 91.593, + "maxMs": 129.275 + }, + "draft-fetch:parse": { + "runs": 10, + "medianMs": 338.836, + "p90Ms": 345.628, + "minMs": 313.893, + "maxMs": 358.398 + }, + "draft-fetch:compare": { + "runs": 10, + "medianMs": 120.602, + "p90Ms": 122.624, + "minMs": 116.186, + "maxMs": 144.098 + }, + "draft-fetch:serialize": { + "runs": 10, + "medianMs": 127.46, + "p90Ms": 129.064, + "minMs": 121.694, + "maxMs": 129.582 + } + } + }, + "memory": { + "webView": { + "heapBeforeOpenBytes": 17365956, + "viewLoadedBytes": 221418000, + "withFullUndoHistoryBytes": 1400577804, + "afterPickerBytes": 1401043284, + "afterSaveBytes": 363751252 + }, + "host": { + "heapBeforeOpenBytes": 88363560, + "viewLoadedBytes": 176871540, + "viewLoadedExternalBytes": 1211712, + "viewLoadedRssBytes": 183025664, + "withFullUndoHistoryBytes": 177013540, + "withFullUndoHistoryExternalBytes": 1211712, + "withFullUndoHistoryRssBytes": 185802752, + "afterPickerBytes": 177031740, + "afterPickerExternalBytes": 1211712, + "afterPickerRssBytes": 186900480, + "afterSaveBytes": 177040980, + "afterSaveExternalBytes": 1211712, + "afterSaveRssBytes": 186703872 + } + }, + "open": { + "webView": { + "usj-fetch": { + "runs": 10, + "medianMs": 2289.4, + "p90Ms": 2377, + "minMs": 327.3, + "maxMs": 2448.6 + }, + "book-render": { + "runs": 10, + "medianMs": 2589.7, + "p90Ms": 2679.4, + "minMs": 2470, + "maxMs": 2755.7 + }, + "draft-fetch": { + "runs": 10, + "medianMs": 2029.8, + "p90Ms": 2056.2, + "minMs": 1956.6, + "maxMs": 2072.7 + }, + "draft-parse": { + "runs": 10, + "medianMs": 143.6, + "p90Ms": 159.8, + "minMs": 133, + "maxMs": 164.6 + }, + "store-mount": { + "runs": 10, + "medianMs": 85.5, + "p90Ms": 315.7, + "minMs": 82, + "maxMs": 324 + }, + "tokenize": { + "runs": 10, + "medianMs": 19.3, + "p90Ms": 25.1, + "minMs": 19.1, + "maxMs": 27.9 + }, + "reanchor": { + "runs": 10, + "medianMs": 351.6, + "p90Ms": 374.9, + "minMs": 317.8, + "maxMs": 375.4 + }, + "open-to-interactive": { + "runs": 10, + "medianMs": 3185.6, + "p90Ms": 3279.1, + "minMs": 3128.7, + "maxMs": 3338.9 + }, + "draft-fetch:transport": { + "runs": 10, + "medianMs": 1337.286, + "p90Ms": 1365.315, + "minMs": 1284.691, + "maxMs": 1398.472 + } + }, + "host": { + "draft-fetch": { + "runs": 10, + "medianMs": 674.228, + "p90Ms": 718.914, + "minMs": 668.502, + "maxMs": 720.631 + }, + "draft-fetch:read": { + "runs": 10, + "medianMs": 104.195, + "p90Ms": 137.731, + "minMs": 86.525, + "maxMs": 140.812 + }, + "draft-fetch:parse": { + "runs": 10, + "medianMs": 340.398, + "p90Ms": 345.145, + "minMs": 305.78, + "maxMs": 347.125 + }, + "draft-fetch:compare": { + "runs": 10, + "medianMs": 116.09, + "p90Ms": 119.63, + "minMs": 113.523, + "maxMs": 120.686 + }, + "draft-fetch:serialize": { + "runs": 10, + "medianMs": 122.673, + "p90Ms": 125.102, + "minMs": 120.76, + "maxMs": 125.283 + } + } + }, + "switchBook": { + "usj-fetch": { + "runs": 10, + "medianMs": 90.8, + "p90Ms": 104.4, + "minMs": 80.6, + "maxMs": 107.5 + }, + "book-render": { + "runs": 10, + "medianMs": 186.2, + "p90Ms": 199.6, + "minMs": 173.8, + "maxMs": 208.8 + }, + "tokenize": { + "runs": 10, + "medianMs": 16.7, + "p90Ms": 20.9, + "minMs": 14.8, + "maxMs": 23 + }, + "reanchor": { + "runs": 10, + "medianMs": 299.3, + "p90Ms": 325.3, + "minMs": 290.3, + "maxMs": 383.9 + } + }, + "edit": { + "webView": { + "dispatch-render": { + "runs": 10, + "medianMs": 414.2, + "p90Ms": 479.8, + "minMs": 333.6, + "maxMs": 479.9 + }, + "autosave-serialize": { + "runs": 10, + "medianMs": 188.7, + "p90Ms": 193.2, + "minMs": 179.5, + "maxMs": 193.9 + }, + "autosave": { + "runs": 10, + "medianMs": 1486.8, + "p90Ms": 1511.4, + "minMs": 1474.7, + "maxMs": 1535 + }, + "autosave:transport": { + "runs": 10, + "medianMs": 1138.353, + "p90Ms": 1158.47, + "minMs": 1102.268, + "maxMs": 1176.002 + } + }, + "host": { + "autosave": { + "runs": 10, + "medianMs": 354.596, + "p90Ms": 359.046, + "minMs": 348.147, + "maxMs": 372.432 + }, + "autosave:parse": { + "runs": 10, + "medianMs": 154.028, + "p90Ms": 158.97, + "minMs": 148.947, + "maxMs": 162.94 + }, + "autosave:read": { + "runs": 10, + "medianMs": 1.561, + "p90Ms": 3.538, + "minMs": 0.725, + "maxMs": 4.91 + }, + "autosave:compare": { + "runs": 10, + "medianMs": 182.81, + "p90Ms": 185.149, + "minMs": 182.568, + "maxMs": 187.086 + }, + "autosave:write": { + "runs": 10, + "medianMs": 6.847, + "p90Ms": 7.271, + "minMs": 6.636, + "maxMs": 7.554 + } + } + }, + "picker": { + "webView": { + "projects-fetch": { + "runs": 10, + "medianMs": 441, + "p90Ms": 444.7, + "minMs": 436.7, + "maxMs": 452.5 + }, + "projects-fetch:transport": { + "runs": 10, + "medianMs": 13.919, + "p90Ms": 14.097, + "minMs": 13.337, + "maxMs": 14.158 + } + }, + "host": { + "projects-fetch": { + "runs": 10, + "medianMs": 427.663, + "p90Ms": 430.759, + "minMs": 422.712, + "maxMs": 438.581 + }, + "projects-fetch:read": { + "runs": 10, + "medianMs": 66.694, + "p90Ms": 73.769, + "minMs": 66.161, + "maxMs": 74.999 + }, + "projects-fetch:parse": { + "runs": 10, + "medianMs": 348.389, + "p90Ms": 351.059, + "minMs": 335.62, + "maxMs": 351.651 + }, + "projects-fetch:serialize": { + "runs": 10, + "medianMs": 12.465, + "p90Ms": 12.658, + "minMs": 12.063, + "maxMs": 13.063 + } + } + }, + "save": { + "webView": { + "save": { + "runs": 10, + "medianMs": 3436.5, + "p90Ms": 3501, + "minMs": 3402.4, + "maxMs": 3502.4 + }, + "save-bytes": { + "runs": 10, + "medianMs": 74884745, + "p90Ms": 74884745, + "minMs": 74884745, + "maxMs": 74884745 + }, + "save:transport": { + "runs": 10, + "medianMs": 2401.497, + "p90Ms": 2468.733, + "minMs": 2380.414, + "maxMs": 2474.525 + } + }, + "host": { + "save": { + "runs": 10, + "medianMs": 1028.603, + "p90Ms": 1033.667, + "minMs": 1015.503, + "maxMs": 1064.786 + }, + "save:parse": { + "runs": 10, + "medianMs": 577.552, + "p90Ms": 583.667, + "minMs": 571.155, + "maxMs": 622.57 + }, + "save:read": { + "runs": 10, + "medianMs": 64.321, + "p90Ms": 66.617, + "minMs": 62.037, + "maxMs": 66.66 + }, + "save:write": { + "runs": 10, + "medianMs": 252.899, + "p90Ms": 255.101, + "minMs": 244.72, + "maxMs": 258.353 + }, + "save:serialize": { + "runs": 10, + "medianMs": 124.118, + "p90Ms": 126.198, + "minMs": 118.596, + "maxMs": 126.369 + } + } + }, + "concordance": { + "concordance-read": { + "runs": 10, + "medianMs": 1090.9, + "p90Ms": 1106.1, + "minMs": 1039.6, + "maxMs": 1149.4 + }, + "concordance-entries": { + "runs": 10, + "medianMs": 44.6, + "p90Ms": 47.3, + "minMs": 42.2, + "maxMs": 47.3 + } + } + } + } +} diff --git a/perf/results/bench-2026-10-13T2005-5bfb334e.json b/perf/results/bench-2026-10-13T2005-5bfb334e.json new file mode 100644 index 000000000..f706fe3f5 --- /dev/null +++ b/perf/results/bench-2026-10-13T2005-5bfb334e.json @@ -0,0 +1,386 @@ +{ + "kind": "bench", + "commit": "5bfb334e0a2bceb5d7e99f635a7d5a5ca810faae", + "dirty": false, + "coreCommit": "0d06e2f782fd98d4469d461ccc52a4c17bd0eed9", + "recordedAt": "2026-10-13T20:05:26.926Z", + "machine": { + "cpu": "12th Gen Intel(R) Core(TM) i7-12700KF", + "cores": 20, + "memoryGb": 34, + "os": "Windows_NT 10.0.26200", + "node": "v25.8.1", + "loadAverage": [0, 0, 0] + }, + "runs": 10, + "tiers": { + "small": { + "viewBook": "PHP", + "dataset": { + "counts": { + "segments": 104, + "wordTokens": 2219, + "tokenAnalyses": 757, + "tokenAnalysisLinks": { + "approved": 2150, + "suggested": 105, + "rejected": 112, + "stale": 69 + }, + "phraseAnalyses": 42, + "phraseAnalysisLinks": 42, + "segmentAnalyses": 25 + }, + "bytes": { + "draftJson": 697387, + "largestShard": 697187 + } + }, + "timings": { + "load.tokenize": { + "runs": 10, + "medianMs": 1.333, + "p90Ms": 1.437, + "minMs": 1.21, + "maxMs": 2.077 + }, + "load.parseDraft": { + "runs": 10, + "medianMs": 1.416, + "p90Ms": 1.509, + "minMs": 1.362, + "maxMs": 1.511 + }, + "load.reanchor": { + "runs": 10, + "medianMs": 7.675, + "p90Ms": 8.477, + "minMs": 7.358, + "maxMs": 8.765 + }, + "load.storeMount": { + "runs": 10, + "medianMs": 3.423, + "p90Ms": 4.177, + "minMs": 3.084, + "maxMs": 4.231 + }, + "storage.readShards": { + "runs": 10, + "medianMs": 1.52, + "p90Ms": 1.613, + "minMs": 1.461, + "maxMs": 1.779 + }, + "storage.writeShards": { + "runs": 10, + "medianMs": 1.472, + "p90Ms": 1.622, + "minMs": 1.193, + "maxMs": 1.628 + }, + "edit.dispatch": { + "runs": 10, + "medianMs": 5.736, + "p90Ms": 6.388, + "minMs": 4.641, + "maxMs": 6.433 + }, + "edit.serializeDraft": { + "runs": 10, + "medianMs": 1.664, + "p90Ms": 1.759, + "minMs": 1.608, + "maxMs": 1.762 + }, + "concordance.build": { + "runs": 10, + "medianMs": 453.368, + "p90Ms": 458.311, + "minMs": 449.536, + "maxMs": 458.705 + } + }, + "memory": { + "parsedDraftBytes": 1142152, + "undoHistoryBytes": 3008832 + } + }, + "medium": { + "viewBook": "PSA", + "dataset": { + "counts": { + "segments": 2583, + "wordTokens": 41324, + "tokenAnalyses": 4797, + "tokenAnalysisLinks": { + "approved": 40059, + "suggested": 1963, + "rejected": 1965, + "stale": 1265 + }, + "phraseAnalyses": 756, + "phraseAnalysisLinks": 786, + "segmentAnalyses": 718 + }, + "bytes": { + "draftJson": 11247593, + "largestShard": 11245223 + } + }, + "timings": { + "load.tokenize": { + "runs": 10, + "medianMs": 26.367, + "p90Ms": 26.597, + "minMs": 26.21, + "maxMs": 26.633 + }, + "load.parseDraft": { + "runs": 10, + "medianMs": 21.092, + "p90Ms": 21.167, + "minMs": 21.016, + "maxMs": 21.227 + }, + "load.reanchor": { + "runs": 10, + "medianMs": 161.282, + "p90Ms": 168.415, + "minMs": 158.495, + "maxMs": 169.362 + }, + "load.storeMount": { + "runs": 10, + "medianMs": 57.238, + "p90Ms": 63.603, + "minMs": 54.989, + "maxMs": 63.607 + }, + "storage.readShards": { + "runs": 10, + "medianMs": 22.3, + "p90Ms": 22.503, + "minMs": 22.152, + "maxMs": 22.537 + }, + "storage.writeShards": { + "runs": 10, + "medianMs": 27.148, + "p90Ms": 27.52, + "minMs": 26.385, + "maxMs": 27.632 + }, + "edit.dispatch": { + "runs": 10, + "medianMs": 91.979, + "p90Ms": 104.009, + "minMs": 89.062, + "maxMs": 120.414 + }, + "edit.serializeDraft": { + "runs": 10, + "medianMs": 25.925, + "p90Ms": 26.321, + "minMs": 25.439, + "maxMs": 26.404 + }, + "concordance.build": { + "runs": 10, + "medianMs": 474.616, + "p90Ms": 481.988, + "minMs": 466.462, + "maxMs": 488.861 + } + }, + "memory": { + "parsedDraftBytes": 17987752, + "undoHistoryBytes": 41949504 + } + }, + "large": { + "viewBook": "PSA", + "dataset": { + "counts": { + "segments": 37691, + "wordTokens": 905971, + "tokenAnalyses": 20247, + "tokenAnalysisLinks": { + "approved": 438765, + "suggested": 21720, + "stale": 13454, + "rejected": 21885 + }, + "phraseAnalyses": 7633, + "phraseAnalysisLinks": 8687, + "segmentAnalyses": 11278 + }, + "bytes": { + "draftJson": 118832401, + "largestShard": 6013928 + } + }, + "timings": { + "load.tokenize": { + "runs": 10, + "medianMs": 27.75, + "p90Ms": 28.142, + "minMs": 27.024, + "maxMs": 28.831 + }, + "load.parseDraft": { + "runs": 10, + "medianMs": 271.055, + "p90Ms": 272.421, + "minMs": 269.263, + "maxMs": 272.424 + }, + "load.reanchor": { + "runs": 10, + "medianMs": 415.253, + "p90Ms": 421.39, + "minMs": 410.341, + "maxMs": 421.734 + }, + "load.storeMount": { + "runs": 10, + "medianMs": 793.552, + "p90Ms": 800.356, + "minMs": 615.725, + "maxMs": 803.135 + }, + "storage.readShards": { + "runs": 10, + "medianMs": 347.901, + "p90Ms": 350.215, + "minMs": 345.728, + "maxMs": 353.878 + }, + "storage.writeShards": { + "runs": 10, + "medianMs": 239.434, + "p90Ms": 240.861, + "minMs": 237.48, + "maxMs": 245.641 + }, + "edit.dispatch": { + "runs": 10, + "medianMs": 1155.556, + "p90Ms": 1158.99, + "minMs": 935.242, + "maxMs": 1168.767 + }, + "edit.serializeDraft": { + "runs": 10, + "medianMs": 254.298, + "p90Ms": 256.243, + "minMs": 252.753, + "maxMs": 258.289 + }, + "concordance.build": { + "runs": 10, + "medianMs": 863.007, + "p90Ms": 874.101, + "minMs": 857.68, + "maxMs": 956.536 + } + }, + "memory": { + "parsedDraftBytes": 188587704, + "undoHistoryBytes": 515438560 + } + }, + "large-loadable": { + "viewBook": "PSA", + "dataset": { + "counts": { + "segments": 37691, + "wordTokens": 905971, + "tokenAnalyses": 16325, + "tokenAnalysisLinks": { + "approved": 262670, + "stale": 8121, + "suggested": 13072, + "rejected": 13201 + }, + "phraseAnalyses": 4725, + "phraseAnalysisLinks": 5197, + "segmentAnalyses": 11443 + }, + "bytes": { + "draftJson": 74928129, + "largestShard": 3903920 + } + }, + "timings": { + "load.tokenize": { + "runs": 10, + "medianMs": 27.92, + "p90Ms": 28.348, + "minMs": 26.921, + "maxMs": 28.604 + }, + "load.parseDraft": { + "runs": 10, + "medianMs": 161.738, + "p90Ms": 163.211, + "minMs": 160.922, + "maxMs": 164.793 + }, + "load.reanchor": { + "runs": 10, + "medianMs": 286.944, + "p90Ms": 301.794, + "minMs": 281.155, + "maxMs": 306.087 + }, + "load.storeMount": { + "runs": 10, + "medianMs": 462.928, + "p90Ms": 491.103, + "minMs": 366.838, + "maxMs": 502.635 + }, + "storage.readShards": { + "runs": 10, + "medianMs": 224.938, + "p90Ms": 225.899, + "minMs": 224.455, + "maxMs": 228.146 + }, + "storage.writeShards": { + "runs": 10, + "medianMs": 152.828, + "p90Ms": 155.071, + "minMs": 150.774, + "maxMs": 156.201 + }, + "edit.dispatch": { + "runs": 10, + "medianMs": 692.639, + "p90Ms": 699.89, + "minMs": 563.2, + "maxMs": 700.104 + }, + "edit.serializeDraft": { + "runs": 10, + "medianMs": 178.454, + "p90Ms": 180.415, + "minMs": 177.472, + "maxMs": 180.568 + }, + "concordance.build": { + "runs": 10, + "medianMs": 670.962, + "p90Ms": 682.625, + "minMs": 668.364, + "maxMs": 719.946 + } + }, + "memory": { + "parsedDraftBytes": 118934440, + "undoHistoryBytes": 340408624 + } + } + } +} diff --git a/perf/shape/cli.ts b/perf/shape/cli.ts new file mode 100644 index 000000000..62e4f0004 --- /dev/null +++ b/perf/shape/cli.ts @@ -0,0 +1,158 @@ +/* eslint-disable no-console -- a command-line tool reports to its terminal */ +import fs from 'fs'; +import type { TextAnalysis } from 'interlinearizer'; +import path from 'path'; +import { draftAnalysisKey, draftKey } from '../../src/services/storageKeys'; +import { isTextAnalysis } from '../../src/types/type-guards'; +import { mergeAnalyses } from '../../src/utils/analysis-book'; +import { normalizeSurfaceForm } from '../../src/utils/analysis-identity'; +import { verseOfTokenRef } from '../../src/utils/reanchor-analysis'; +import { percentile } from '../bench/measure'; +import { readDraftJson } from '../dataset/store'; +import { TIERS } from '../dataset/tiers'; + +/** The development host's extension storage, where real imports and drafts sit. */ +const DEFAULT_STORAGE_DIR = path.resolve( + __dirname, + '../../../paranext-core/dev-appdata/extensions/interlinearizer/user-data', +); + +/** Storage file name for `key`, mirroring core's private `buildUserDataUri`. */ +function storageFile(dir: string, key: string): string { + return path.join(dir, Buffer.from(key).toString('base64url')); +} + +function readStored(dir: string, key: string): unknown { + return JSON.parse(fs.readFileSync(storageFile(dir, key), 'utf-8')); +} + +function asAnalysis(value: unknown, what: string): TextAnalysis { + if (!isTextAnalysis(value)) throw new Error(`${what} is not an analysis`); + return value; +} + +function analysisOf(value: unknown, what: string): TextAnalysis { + if (!value || typeof value !== 'object' || !('analysis' in value)) + throw new Error(`${what} holds no analysis`); + return asAnalysis(value.analysis, what); +} + +/** A stored draft's analysis, merged from the per-book shards its envelope lists. */ +function readStoredDraft(dir: string, sourceProjectId: string): TextAnalysis { + const key = draftKey(sourceProjectId); + const envelope = readStored(dir, key); + const inline = analysisOf(envelope, key); + if (!envelope || typeof envelope !== 'object' || !('analysisBooks' in envelope)) return inline; + const { analysisBooks } = envelope; + if (!Array.isArray(analysisBooks)) throw new Error(`${key} lists no shards`); + return mergeAnalyses([ + inline, + ...analysisBooks.map((book) => { + const shardKey = draftAnalysisKey(sourceProjectId, book); + return asAnalysis(readStored(dir, shardKey), shardKey); + }), + ]); +} + +/** Resolves one argument: a tier name, or a `draft:` / `project:` storage key. */ +function load(arg: string, storageDir: string): TextAnalysis { + if (TIERS.some((tier) => tier.name === arg)) + return analysisOf(JSON.parse(readDraftJson(arg)), arg); + if (arg.startsWith('draft:')) return readStoredDraft(storageDir, arg.slice('draft:'.length)); + if (arg.startsWith('project:')) return analysisOf(readStored(storageDir, arg), arg); + throw new Error(`Unknown dataset ${arg}: expected a tier name, draft: or project:`); +} + +const round = (n: number, places = 3) => Math.round(n * 10 ** places) / 10 ** places; +const share = (part: number, whole: number) => (whole === 0 ? 0 : round(part / whole)); + +function countBy(items: readonly T[], keyOf: (item: T) => string): Map { + const counts = new Map(); + items.forEach((item) => counts.set(keyOf(item), (counts.get(keyOf(item)) ?? 0) + 1)); + return counts; +} + +/** Text-independent measures of an analysis's shape, comparable between synthetic and real data. */ +function shapeOf(analysis: TextAnalysis) { + const links = analysis.tokenAnalysisLinks; + const statuses = Object.fromEntries( + [...countBy(links, (l) => l.status)].map(([status, n]) => [status, share(n, links.length)]), + ); + const linksPerToken = [...countBy(links, (l) => l.token.tokenRef).values()]; + const linksPerPayload = [...countBy(links, (l) => l.analysisId).values()]; + const usedPayloads = new Set(links.map((l) => l.analysisId)); + const used = analysis.tokenAnalyses.filter((a) => usedPayloads.has(a.id)); + const payloadsPerForm = [...countBy(used, (a) => normalizeSurfaceForm(a.surfaceText)).values()]; + const glossLengths = used.flatMap((a) => Object.values(a.gloss ?? {}).map((g) => g.length)); + const phrases = analysis.phraseAnalysisLinks; + const approved = links.filter((l) => l.status === 'approved').length; + const sorted = [...linksPerPayload].sort((a, b) => b - a); + const topPercent = sorted.slice(0, Math.max(1, Math.ceil(sorted.length / 100))); + + return { + tokenLinks: links.length, + tokenPayloads: analysis.tokenAnalyses.length, + statusShare: statuses, + competingTokenShare: share(linksPerToken.filter((n) => n > 1).length, linksPerToken.length), + linksPerPayload: { + mean: round(links.length / Math.max(1, usedPayloads.size), 2), + p95: + linksPerPayload.length === 0 + ? 0 + : percentile( + [...linksPerPayload].sort((a, b) => a - b), + 95, + ), + max: sorted[0] ?? 0, + usedOnceShare: share(linksPerPayload.filter((n) => n === 1).length, linksPerPayload.length), + topPercentLinkShare: share( + topPercent.reduce((n, m) => n + m, 0), + links.length, + ), + }, + payloadsPerForm: { + mean: round(used.length / Math.max(1, payloadsPerForm.length), 2), + multiSenseFormShare: share( + payloadsPerForm.filter((n) => n > 1).length, + payloadsPerForm.length, + ), + }, + morphemeShare: share(used.filter((a) => (a.morphemes?.length ?? 0) > 0).length, used.length), + glossLanguagesPerPayload: round( + used.reduce((n, a) => n + Object.keys(a.gloss ?? {}).length, 0) / Math.max(1, used.length), + 2, + ), + meanGlossLength: round( + glossLengths.reduce((n, m) => n + m, 0) / Math.max(1, glossLengths.length), + 1, + ), + phrasesPerApprovedLink: share(phrases.length, approved), + meanPhraseTokens: round( + phrases.reduce((n, p) => n + p.tokens.length, 0) / Math.max(1, phrases.length), + 2, + ), + crossVersePhraseShare: share( + phrases.filter((p) => new Set(p.tokens.map((t) => verseOfTokenRef(t.tokenRef))).size > 1) + .length, + phrases.length, + ), + segmentTranslationsPerApprovedLink: share(analysis.segmentAnalysisLinks.length, approved), + booklessLinkShare: share( + links.filter((l) => !/^[A-Z0-9]{3} /.test(l.token.tokenRef)).length, + links.length, + ), + }; +} + +function main(): void { + const storageDir = process.env.PERF_STORAGE_DIR ?? DEFAULT_STORAGE_DIR; + const args = process.argv.slice(2); + if (args.length === 0) + throw new Error( + `Name datasets to compare: tier names, or draft: / project: keys in ${storageDir}`, + ); + const shapes = Object.fromEntries(args.map((arg) => [arg, shapeOf(load(arg, storageDir))])); + console.log(JSON.stringify(shapes, undefined, 2)); +} + +main(); diff --git a/perf/summary/cli.ts b/perf/summary/cli.ts new file mode 100644 index 000000000..e0be226bc --- /dev/null +++ b/perf/summary/cli.ts @@ -0,0 +1,338 @@ +/* eslint-disable no-console -- a command-line tool reports to its terminal */ +import fs from 'fs'; +import path from 'path'; +import { RESULTS_DIR } from '../paths'; + +type Json = Record; + +/** A section's rows, each named and holding one cell per tier. */ +type Rows = Map>; + +const isObject = (value: unknown): value is Json => !!value && typeof value === 'object'; + +const isTiming = (value: unknown): value is { medianMs: number; p90Ms: number } => + isObject(value) && typeof value.medianMs === 'number' && typeof value.p90Ms === 'number'; + +/** Sections of a tier's results that describe its input rather than measure it. */ +const DESCRIPTIVE = new Set(['viewBook', 'dataset', 'skipped', 'error']); + +/** Printed ahead of every result measured on the generated datasets. */ +const DATASET_NOTE = + "The datasets gloss WEB's English, which has fewer word forms than a real project's language: about 2.8× the links per token payload of a real Paratext 9 import, so costs that scale with payload count, such as the pool index and catalog rows, read 2–3× low."; + +/** Explains the rows under a call, printed ahead of any report that has them. */ +const HOST_NOTE = + "A call's own row is how long the WebView waited for it. Below it, `↳ host` is the part of that wait the extension host spent working, broken into steps by the `↳ host:` rows, and `↳ transport` is the rest, spent passing the request and reply between the two processes."; + +/** Headings for each kind of result. */ +const KIND_TITLES: Record = { + app: 'In the app (`perf:app`)', + bench: 'Data layer in Node (`perf:bench`)', +}; + +/** What each kind of result measures, printed ahead of its tables. */ +const KIND_INTROS: Record = { + app: 'The extension timed in the running app, driven as a user would drive it.', + bench: "The data layer's functions timed directly in Node, without the app.", +}; + +/** What each section's scenario does, keyed by result kind and section path. */ +const SECTION_DESCRIPTIONS: Record = { + 'app.wireBytes': + 'The size of each payload the WebView receives as one websocket message. A tier whose draft is over the per-message cap cannot load in the app.', + 'app.memory': + 'Heap in use before the view opens, then how far it has grown at each later point. The host heap belongs to the whole platform, not just this extension.', + 'app.cold': "The packaged app restarts before each run, then the view opens on the tier's book.", + 'app.open': + "A new view opens on the tier's book in an app that is already running. Some steps run at the same time, so they do not add up to the total.", + 'app.switchBook': + "With the view open, the book changes to Jude and back; the times are for the return. Book change to rendered includes fetching the book's text.", + 'app.edit': 'One gloss typed and committed with Tab, then the autosave that commit sets off.', + 'app.picker': + 'The Select Interlinear Project dialog opens, listing every saved project for the source.', + 'app.save': 'Save from the Project menu writes the analysis to the project it came from.', + 'app.concordance': + 'The concordance opens in a fresh view, which reads and indexes every book of the source.', + 'bench.timings.load': 'The steps of opening the view on a book.', + 'bench.timings.storage': + 'Splitting the draft into per-book shards to store it, and merging them back.', + 'bench.timings.edit': + "Committing one gloss to the store and rerunning the view's selectors, then serializing the draft to save it.", + 'bench.timings.concordance': + 'Indexing every book of the source and deriving the concordance rows.', + 'bench.memory': 'Heap held by the parsed draft, and by an undo history filled to its limit.', +}; + +/** The memory reading every other one in its section is taken against. */ +const MEMORY_BASELINE = 'heapBeforeOpenBytes'; + +/** Headings for a result's sections, keyed by dotted path; an unlisted section shows its path. */ +const SECTION_LABELS: Record = { + wireBytes: 'Sent over the websocket', + memory: 'Memory', + cold: 'First open after the app starts', + open: 'Open the view in a running app', + switchBook: 'Switch away and back to the book', + edit: 'Edit one gloss', + picker: 'List saved projects in the picker', + save: 'Save the analysis to its project', + concordance: 'Open the concordance', + 'timings.load': 'Load', + 'timings.storage': 'Storage', + 'timings.edit': 'Edit one gloss', + 'timings.concordance': 'Concordance', +}; + +/** Names for measured values, by their key; an unlisted value shows its key. */ +const METRIC_LABELS: Record = { + draft: 'Draft', + projectsForSource: 'Saved projects list', + 'app-startup': 'App startup', + 'usj-fetch': 'Fetch book text', + tokenize: 'Tokenize book', + 'book-render': 'Book change to rendered', + 'draft-fetch': 'Fetch draft', + 'draft-parse': 'Parse draft', + 'store-mount': 'Mount analysis store', + reanchor: 'Reanchor analysis to book', + 'open-to-interactive': 'Total: open to settled', + 'dispatch-render': 'Commit gloss to re-render', + 'autosave-serialize': 'Serialize draft', + autosave: 'Autosave', + 'projects-fetch': 'Fetch saved projects', + save: 'Save', + 'save-bytes': 'Analysis sent', + 'concordance-read': 'Read every book', + 'concordance-entries': 'Build entries', + parseDraft: 'Parse draft', + storeMount: 'Mount analysis store', + readShards: 'Parse and merge shards', + writeShards: 'Split and serialize shards', + dispatch: 'Commit gloss and reselect', + serializeDraft: 'Serialize draft', + build: 'Build entries and rows', + parsedDraftBytes: 'Parsed draft', + undoHistoryBytes: 'Full undo history', +}; + +/** Names for the steps a host call is split into. */ +const PHASE_LABELS: Record = { + read: 'read storage', + parse: 'parse and validate', + compare: 'split and compare shards', + serialize: 'serialize reply', + write: 'write storage', +}; + +/** When the app's memory readings were taken, by the prefix of their key. */ +const MEMORY_POINTS: Record = { + viewLoaded: 'view loaded', + withFullUndoHistory: 'full undo history', + afterPicker: 'after picker', + afterSave: 'after save', +}; + +const isBytes = (name: string) => /bytes/i.test(name); + +const formatNumber = (n: number) => (n >= 100 ? `${Math.round(n)}` : n.toFixed(1)); + +/** A median and p90 in one shared unit, seconds for long timings. */ +function formatTiming(medianMs: number, p90Ms: number): string { + if (p90Ms >= 10_000) return `${formatNumber(medianMs / 1000)} / ${formatNumber(p90Ms / 1000)} s`; + return `${formatNumber(medianMs)} / ${formatNumber(p90Ms)} ms`; +} + +/** Megabytes, signed when `bytes` is a change rather than a total. */ +function formatBytes(bytes: number, isChange = false): string { + const sign = isChange && bytes >= 0 ? '+' : ''; + return `${sign}${(bytes / 1e6).toFixed(1)} MB`; +} + +function formatValue(name: string, value: unknown, isChange = false): string | undefined { + if (isTiming(value)) + return isBytes(name) ? formatBytes(value.medianMs) : formatTiming(value.medianMs, value.p90Ms); + if (typeof value === 'number') + return isBytes(name) ? formatBytes(value, isChange) : String(value); + return undefined; +} + +const metricLabel = (key: string) => METRIC_LABELS[key] ?? key; + +/** + * Rows for a section measured on both sides of the websocket: each WebView call, then its + * transport, then the host's share and that share's steps. + */ +function callRows(webView: Json, host: Json): [string, string | undefined][] { + const calls = [...Object.keys(webView), ...Object.keys(host)].filter((key) => !key.includes(':')); + return [...new Set(calls)].flatMap((call): [string, string | undefined][] => { + const steps = Object.entries(host) + .filter(([key]) => key.startsWith(`${call}:`)) + .map(([key, value]): [string, string | undefined] => { + const step = key.slice(call.length + 1); + return [`↳ host: ${PHASE_LABELS[step] ?? step}`, formatValue(key, value)]; + }); + if (!(call in webView)) return [[`Host: ${metricLabel(call)}`, formatValue(call, host[call])]]; + return [ + [metricLabel(call), formatValue(call, webView[call])], + ['↳ transport', formatValue(call, webView[`${call}:transport`])], + ['↳ host', formatValue(call, host[call])], + ...steps, + ]; + }); +} + +/** + * Rows for the app's heap readings, the WebView's then the host's: each side's heap before the view + * opens, then its change from that at each later point. + */ +function memoryRows(webView: Json, host: Json): [string, string | undefined][] { + const sides: [string, Json][] = [ + ['WebView', webView], + ['Host', host], + ]; + return sides.flatMap(([side, readings]) => + Object.entries(readings).flatMap(([key, value]): [string, string | undefined][] => { + if (key === MEMORY_BASELINE) + return [[`${side} heap before opening`, formatValue(key, value)]]; + const point = MEMORY_POINTS[key.replace(/Bytes$/, '')]; + return point ? [[`${side} heap change, ${point}`, formatValue(key, value, true)]] : []; + }), + ); +} + +/** Adds every measured value of a tier to `sections`, under the section its dotted path names. */ +function addTier(sections: Map, tierName: string, tier: Json, prefix = ''): void { + const add = (section: string, label: string, cell: string | undefined) => { + if (cell === undefined) return; + if (!sections.has(section)) sections.set(section, new Map()); + const rows = sections.get(section); + if (!rows?.has(label)) rows?.set(label, new Map()); + rows?.get(label)?.set(tierName, cell); + }; + Object.entries(tier).forEach(([key, value]) => { + if (!prefix && DESCRIPTIVE.has(key)) return; + const name = prefix + key; + if (isObject(value) && isObject(value.webView) && isObject(value.host)) { + const rows = + key === 'memory' + ? memoryRows(value.webView, value.host) + : callRows(value.webView, value.host); + rows.forEach(([label, cell]) => add(name, label, cell)); + } else if (isObject(value) && !isTiming(value)) { + addTier(sections, tierName, value, `${name}.`); + } else { + // A key may itself be dotted, so the section is everything before the full path's last dot. + const split = name.lastIndexOf('.'); + add( + name.slice(0, Math.max(split, 0)), + metricLabel(name.slice(split + 1)), + formatValue(name, value), + ); + } + }); +} + +/** Tier names joined for a sentence: `a`, `a and b`, `a, b and c`. */ +function listOf(names: string[]): string { + return names.length > 1 + ? `${names.slice(0, -1).join(', ')} and ${names[names.length - 1]}` + : names.join(''); +} + +/** A paragraph for each tier the run skipped or that failed partway. */ +function tierProblems(tiers: Json): string[] { + return Object.entries(tiers).flatMap(([name, tier]) => { + if (!isObject(tier)) return []; + if (typeof tier.skipped === 'string') return [`**${name}** was skipped: ${tier.skipped}`]; + return typeof tier.error === 'string' ? [`**${name}** failed partway: ${tier.error}`] : []; + }); +} + +/** Says, ahead of the memory table, which tiers have no host heap readings and why. */ +function memoryCaveat(tiers: Json): string | undefined { + const skipped = Object.entries(tiers).flatMap(([name, tier]) => + isObject(tier) && isObject(tier.memory) && typeof tier.memory.hostSkipped === 'string' + ? [{ name, reason: tier.memory.hostSkipped }] + : [], + ); + if (!skipped.length) return undefined; + return `No host heap for ${listOf(skipped.map(({ name }) => name))}: ${skipped[0].reason}`; +} + +function report(result: Json): string { + const kind = String(result.kind); + const tiers = isObject(result.tiers) ? result.tiers : {}; + const sections = new Map(); + Object.entries(tiers).forEach(([name, tier]) => { + if (isObject(tier)) addTier(sections, name, tier); + }); + const allRows = [...sections.values()].flatMap((rows) => [...rows.values()]); + const columns = Object.keys(tiers).filter((name) => allRows.some((row) => row.has(name))); + const withHost = [...sections.values()].some((rows) => rows.has('↳ host')); + const machine = isObject(result.machine) ? result.machine : {}; + const load = Array.isArray(machine.loadAverage) ? machine.loadAverage[0] : undefined; + const header = [ + `Measured at \`${String(result.commit).slice(0, 8)}\`${result.dirty ? ' (dirty)' : ''}, core \`${String(result.coreCommit).slice(0, 8)}\``, + `${machine.cpu}, ${machine.cores} threads, ${machine.memoryGb} GB, ${machine.os}, load ${typeof load === 'number' ? load.toFixed(1) : '?'}`, + [ + result.appBuild, + result.display && `${result.display} display`, + result.extensionBuild && `${result.extensionBuild} extension`, + `${result.runs} runs`, + ] + .filter(Boolean) + .join(', '), + ].join('; '); + const intro = [ + KIND_INTROS[kind], + `Each column is a dataset tier. Timings read median / p90 over the ${result.runs} runs.`, + ...(withHost ? [HOST_NOTE] : []), + DATASET_NOTE, + ...tierProblems(tiers), + ].filter(Boolean); + const tables = [...sections].map(([section, rows]) => { + const caveat = kind === 'app' && section === 'memory' ? memoryCaveat(tiers) : undefined; + const description = [SECTION_DESCRIPTIONS[`${kind}.${section}`], caveat] + .filter(Boolean) + .join(' '); + return [ + `### ${SECTION_LABELS[section] ?? (section || 'Other')}`, + ...(description ? ['', description] : []), + '', + `| | ${columns.join(' | ')} |`, + `| --- |${columns.map(() => ' ---: |').join('')}`, + ...[...rows].map( + ([label, cells]) => + `| ${label} | ${columns.map((name) => cells.get(name) ?? '—').join(' | ')} |`, + ), + ].join('\n'); + }); + return [`## ${KIND_TITLES[kind] ?? kind}`, header, ...intro, ...tables].join('\n\n'); +} + +/** The newest result file of each kind, or the files named on the command line. */ +function resultFiles(): string[] { + const named = process.argv.slice(2); + if (named.length) return named; + if (!fs.existsSync(RESULTS_DIR)) throw new Error(`No results in ${RESULTS_DIR}`); + const newest = new Map(); + fs.readdirSync(RESULTS_DIR) + .filter((file) => file.endsWith('.json')) + .forEach((file) => { + const full = path.join(RESULTS_DIR, file); + const { kind, recordedAt } = JSON.parse(fs.readFileSync(full, 'utf-8')); + const current = newest.get(kind); + if (!current || recordedAt > current.recordedAt) newest.set(kind, { file: full, recordedAt }); + }); + return [...newest.values()].map(({ file }) => file); +} + +function main(): void { + console.log( + resultFiles() + .map((file) => report(JSON.parse(fs.readFileSync(file, 'utf-8')))) + .join('\n\n'), + ); +} + +main(); diff --git a/perf/usj-cache.ts b/perf/usj-cache.ts new file mode 100644 index 000000000..79c4071d7 --- /dev/null +++ b/perf/usj-cache.ts @@ -0,0 +1,71 @@ +import fs from 'fs'; +import path from 'path'; +import { USJ_CACHE_DIR, usjDirFor } from './paths'; + +/** What a capture recorded about the project its USJ came from. */ +export interface UsjCaptureMeta { + projectId: string; + projectName: string; + /** The project's `platform.languageTag`, which tokenizing must use to match the app. */ + languageTag: string; + /** Book codes captured, in canonical order. */ + books: string[]; + capturedAt: string; + /** Paranext-core commit the USJ was produced by. */ + coreCommit: string; +} + +const META_FILE = 'meta.json'; + +/** Writes one captured book. */ +export function writeCapturedBook(projectId: string, bookCode: string, usj: unknown): void { + const dir = usjDirFor(projectId); + fs.mkdirSync(dir, { recursive: true }); + fs.writeFileSync(path.join(dir, `${bookCode}.json`), JSON.stringify(usj)); +} + +/** Removes a capture's metadata, marking it incomplete until {@link writeCaptureMeta} runs again. */ +export function clearCaptureMeta(projectId: string): void { + fs.rmSync(path.join(usjDirFor(projectId), META_FILE), { force: true }); +} + +/** Writes a capture's metadata, last, so a capture with metadata is a complete one. */ +export function writeCaptureMeta(meta: UsjCaptureMeta): void { + fs.writeFileSync( + path.join(usjDirFor(meta.projectId), META_FILE), + JSON.stringify(meta, undefined, 2), + ); +} + +function completeCaptureFiles(): string[] { + return fs.existsSync(USJ_CACHE_DIR) + ? fs + .readdirSync(USJ_CACHE_DIR) + .map((dir) => path.join(USJ_CACHE_DIR, dir, META_FILE)) + .filter((file) => fs.existsSync(file)) + : []; +} + +/** Whether the cache holds a complete capture to generate datasets from. */ +export function hasCompleteCapture(): boolean { + return completeCaptureFiles().length > 0; +} + +/** + * Reads the one complete capture in the cache. + * + * @throws If there is no complete capture, or more than one. + */ +export function readCaptureMeta(): UsjCaptureMeta { + const metas = completeCaptureFiles(); + if (metas.length !== 1) + throw new Error( + `Expected one complete USJ capture under ${USJ_CACHE_DIR}, found ${metas.length}. Run \`npm run perf:capture\`.`, + ); + return JSON.parse(fs.readFileSync(metas[0], 'utf-8')); +} + +/** Reads one captured book's USJ. */ +export function readCapturedBook(projectId: string, bookCode: string): unknown { + return JSON.parse(fs.readFileSync(path.join(usjDirFor(projectId), `${bookCode}.json`), 'utf-8')); +} diff --git a/src/__tests__/components/AnalysisStore.test.tsx b/src/__tests__/components/AnalysisStore.test.tsx index 04de237f2..382edd8d7 100644 --- a/src/__tests__/components/AnalysisStore.test.tsx +++ b/src/__tests__/components/AnalysisStore.test.tsx @@ -50,6 +50,14 @@ import { useFreeTranslationsBySegment, } from '../../components/AnalysisStore'; import type { ResolvedTokenAnalysis } from '../../utils/suggestion-engine'; +import { + perfMark, + perfMarksEnabled, + perfMeasure, + perfMeasureFromFirst, +} from '../../utils/perf-marks'; + +jest.mock('../../utils/perf-marks'); /** Builds a minimal `TextAnalysis` with a single approved `TokenAnalysis` for the given token. */ function makeAnalysisWithGloss( @@ -409,21 +417,21 @@ describe('edit locations', () => { }); }); -describe('analysis replacements', () => { - /** Stands in for the draft's feed of replaced analyses, letting a test push one. */ - function makeReplacementFeed() { - let listener: ((analysis: TextAnalysis) => void) | undefined; - const unsubscribe = jest.fn(); - return { - subscribe: (next: (analysis: TextAnalysis) => void) => { - listener = next; - return unsubscribe; - }, - replace: (analysis: TextAnalysis) => listener?.(analysis), - unsubscribe, - }; - } +/** Stands in for the draft's feed of replaced analyses, letting a test push one. */ +function makeReplacementFeed() { + let listener: ((analysis: TextAnalysis) => void) | undefined; + const unsubscribe = jest.fn(); + return { + subscribe: (next: (analysis: TextAnalysis) => void) => { + listener = next; + return unsubscribe; + }, + replace: (analysis: TextAnalysis) => listener?.(analysis), + unsubscribe, + }; +} +describe('analysis replacements', () => { it('follows an analysis the draft replaces', () => { const feed = makeReplacementFeed(); const { result } = renderStoreHook(() => useAnalysis(), { @@ -458,6 +466,67 @@ describe('analysis replacements', () => { }); }); +describe('performance marks', () => { + it('times the store’s first commit from its creation', () => { + renderStoreHook(() => useAnalysis()); + + expect(perfMark).toHaveBeenCalledWith('store-create'); + expect(perfMeasure).toHaveBeenCalledWith('store-mount', 'store-create'); + }); + + it('times a dispatched change to the analysis to the commit rendering it', () => { + jest.mocked(perfMarksEnabled).mockReturnValue(true); + const { result } = renderStoreHook(() => useGlossDispatch()); + + act(() => result.current('tok-1', 'word', 'hi')); + + expect(perfMeasureFromFirst).toHaveBeenCalledWith('dispatch-render', 'dispatch'); + }); + + it('times changes rendered by one commit once', () => { + jest.mocked(perfMarksEnabled).mockReturnValue(true); + const { result } = renderStoreHook(() => useGlossDispatch()); + + act(() => { + result.current('tok-1', 'word', 'hi'); + result.current('tok-2', 'word', 'there'); + }); + + expect(perfMeasureFromFirst).toHaveBeenCalledTimes(1); + }); + + it('times a change that restores the seeded analysis', () => { + jest.mocked(perfMarksEnabled).mockReturnValue(true); + const seeded = makeAnalysisWithGloss('tok-1', 'seeded'); + const feed = makeReplacementFeed(); + const { result } = renderStoreHook(() => useGlossDispatch(), { + initialAnalysis: seeded, + subscribeToReplacements: feed.subscribe, + }); + act(() => result.current('tok-1', 'word', 'edited')); + + act(() => feed.replace(seeded)); + + expect(perfMeasureFromFirst).toHaveBeenCalledTimes(2); + }); + + it('does not time the store’s first render as a change', () => { + jest.mocked(perfMarksEnabled).mockReturnValue(true); + + renderStoreHook(() => useAnalysis()); + + expect(perfMeasureFromFirst).not.toHaveBeenCalled(); + }); + + it('times no change while marks are off', () => { + const { result } = renderStoreHook(() => useGlossDispatch()); + + act(() => result.current('tok-1', 'word', 'hi')); + + expect(perfMeasureFromFirst).not.toHaveBeenCalled(); + }); +}); + describe('useGlossDispatch', () => { it('replaces the existing approved analysis on subsequent writes for the same token', () => { const { result } = renderStoreHook(() => ({ diff --git a/src/__tests__/main.test.ts b/src/__tests__/main.test.ts index 7ef7f86a3..163cea8d8 100644 --- a/src/__tests__/main.test.ts +++ b/src/__tests__/main.test.ts @@ -4,11 +4,13 @@ import type { OpenWebViewOptions, SavedWebViewDefinition, WebViewDefinition } fr import papiBackendMock from '@papi/backend'; import { activate, deactivate } from '@main'; import type { InterlinearizerOpenOptions } from '@main'; +import * as hostPerf from '../services/hostPerf'; import * as projectStorage from '../services/projectStorage'; import * as pt9ImportService from '../services/pt9ImportService'; import { emptyAnalysis, emptyDraft } from '../types/empty-factories'; import { createTestActivationContext, makeStubProject } from './test-helpers'; +jest.mock('../services/hostPerf'); jest.mock('../services/projectStorage'); jest.mock('../services/pt9ImportService'); @@ -1236,6 +1238,41 @@ describe('main', () => { }); }); + describe('interlinearizer.setPerfMarks command', () => { + it("turns the host's timing entries on or off as asked", async () => { + const handler = await activateAndGetHandler<(enabled: boolean) => Promise>( + 'interlinearizer.setPerfMarks', + ); + + await handler(true); + + expect(hostPerf.setHostPerfMarks).toHaveBeenCalledWith(true); + }); + }); + + describe('interlinearizer.readPerf command', () => { + const mockReadHostPerf = jest.mocked(hostPerf.readHostPerf); + + it("returns the host's reading as JSON", async () => { + const reading = { entries: [{ name: 'getDraft', duration: 12, detail: undefined }], pid: 42 }; + mockReadHostPerf.mockReturnValue(reading); + const handler = await activateAndGetHandler<() => Promise>( + 'interlinearizer.readPerf', + ); + + await expect(handler()).resolves.toBe(JSON.stringify(reading)); + }); + + it("returns nothing while the host's timing entries are off", async () => { + mockReadHostPerf.mockReturnValue(undefined); + const handler = await activateAndGetHandler<() => Promise>( + 'interlinearizer.readPerf', + ); + + await expect(handler()).resolves.toBeUndefined(); + }); + }); + describe('interlinearizer.saveDraft command', () => { const mockSaveDraft = jest.mocked(projectStorage.saveDraft); const stubDraft = { ...emptyDraft('src-project'), analysisLanguages: ['en'], dirty: true }; diff --git a/src/__tests__/services/hostPerf.test.ts b/src/__tests__/services/hostPerf.test.ts new file mode 100644 index 000000000..ccf0d42ab --- /dev/null +++ b/src/__tests__/services/hostPerf.test.ts @@ -0,0 +1,41 @@ +/// + +import { readHostPerf, setHostPerfMarks } from '../../services/hostPerf'; +import { perfMarksEnabled, setPerfMarksEnabled, takePerfEntries } from '../../utils/perf-marks'; + +jest.mock('../../utils/perf-marks'); + +const entries = [{ name: 'getDraft', duration: 12, detail: undefined }]; + +beforeEach(() => { + jest.mocked(takePerfEntries).mockReturnValue(entries); +}); + +describe('setHostPerfMarks', () => { + it("switches the host's timing entries as asked", () => { + setHostPerfMarks(true); + + expect(setPerfMarksEnabled).toHaveBeenCalledWith(true); + }); + + it('discards the entries the host already holds', () => { + setHostPerfMarks(false); + + expect(takePerfEntries).toHaveBeenCalled(); + }); +}); + +describe('readHostPerf', () => { + it('reads nothing while timing entries are off', () => { + jest.mocked(perfMarksEnabled).mockReturnValue(false); + + expect(readHostPerf()).toBeUndefined(); + expect(takePerfEntries).not.toHaveBeenCalled(); + }); + + it("takes the recorded entries with the host's process id", () => { + jest.mocked(perfMarksEnabled).mockReturnValue(true); + + expect(readHostPerf()).toEqual({ entries, pid: process.pid }); + }); +}); diff --git a/src/__tests__/services/projectStorage.test.ts b/src/__tests__/services/projectStorage.test.ts index 51b58bd76..ea73c71fb 100644 --- a/src/__tests__/services/projectStorage.test.ts +++ b/src/__tests__/services/projectStorage.test.ts @@ -1126,6 +1126,21 @@ describe('projectStorage', () => { ); }); + it('skips a project whose record cannot be read and logs the error', async () => { + __mockReadUserData + .mockResolvedValueOnce(JSON.stringify(['broken', 'abc'])) + .mockRejectedValueOnce(new Error('permission denied')) + .mockResolvedValueOnce(JSON.stringify(makeStubProject('abc'))); + + const result = await listProjects(token); + + expect(result.map((p) => p.id)).toEqual(['abc']); + expect(__mockLogger.error).toHaveBeenCalledWith( + expect.stringContaining('broken'), + expect.objectContaining({ message: 'permission denied' }), + ); + }); + it('skips a project written by a newer build rather than failing the whole list', async () => { const fromNewerBuild = { ...makeStubProject('future-proj'), diff --git a/src/__tests__/services/storageKeys.test.ts b/src/__tests__/services/storageKeys.test.ts new file mode 100644 index 000000000..0991102b2 --- /dev/null +++ b/src/__tests__/services/storageKeys.test.ts @@ -0,0 +1,32 @@ +/// + +import { + draftAnalysisKey, + draftJournalKey, + draftKey, + projectKey, +} from '../../services/storageKeys'; + +describe('projectKey', () => { + it('keys a project by its id', () => { + expect(projectKey('abc')).toBe('project:abc'); + }); +}); + +describe('draftKey', () => { + it('keys a draft by its source project', () => { + expect(draftKey('src-1')).toBe('draft:src-1'); + }); +}); + +describe('draftAnalysisKey', () => { + it("keys one book's analysis shard under its draft", () => { + expect(draftAnalysisKey('src-1', 'GEN')).toBe('draft:src-1:analysis:GEN'); + }); +}); + +describe('draftJournalKey', () => { + it("keys a draft's shard journal under its draft", () => { + expect(draftJournalKey('src-1')).toBe('draft:src-1:shards'); + }); +}); diff --git a/src/__tests__/store/index.test.ts b/src/__tests__/store/index.test.ts new file mode 100644 index 000000000..fad714dd0 --- /dev/null +++ b/src/__tests__/store/index.test.ts @@ -0,0 +1,36 @@ +/// + +import { createAnalysisStore } from '../../store'; +import { setAnalysisLanguage, writeGloss } from '../../store/analysisSlice'; +import { perfMark, perfMarksEnabled } from '../../utils/perf-marks'; + +jest.mock('../../utils/perf-marks'); + +describe('createAnalysisStore', () => { + it('marks when a dispatch that changes the analysis began', () => { + jest.mocked(perfMarksEnabled).mockReturnValue(true); + jest.spyOn(performance, 'now').mockReturnValue(40); + const store = createAnalysisStore(); + + store.dispatch(writeGloss('tok-1', 'word', 'hi')); + + expect(perfMark).toHaveBeenCalledWith('dispatch', undefined, 40); + }); + + it('marks no dispatch that leaves the analysis unchanged', () => { + jest.mocked(perfMarksEnabled).mockReturnValue(true); + const store = createAnalysisStore(); + + store.dispatch(setAnalysisLanguage('fr')); + + expect(perfMark).not.toHaveBeenCalled(); + }); + + it('marks nothing while marks are off', () => { + const store = createAnalysisStore(); + + store.dispatch(writeGloss('tok-1', 'word', 'hi')); + + expect(perfMark).not.toHaveBeenCalled(); + }); +}); diff --git a/src/__tests__/utils/analysis-book.test.ts b/src/__tests__/utils/analysis-book.test.ts index 781ba5642..cdbf73db0 100644 --- a/src/__tests__/utils/analysis-book.test.ts +++ b/src/__tests__/utils/analysis-book.test.ts @@ -10,6 +10,7 @@ import type { import { BOOKLESS_PARTITION, bookOfRef, + mergeAnalyses, removeBookFromAnalysis, removeBookFromSegmentation, splitAnalysisByBook, @@ -240,6 +241,61 @@ describe('splitAnalysisByBook', () => { }); }); +describe('mergeAnalyses', () => { + const genesis: TextAnalysis = { + tokenAnalyses: [mkTokenAnalysis('ta-gen'), mkTokenAnalysis('shared')], + tokenAnalysisLinks: [mkTokenLink('ta-gen', 'GEN 1:1:0'), mkTokenLink('shared', 'GEN 1:1:3')], + segmentAnalyses: [mkSegmentAnalysis('sa-gen')], + segmentAnalysisLinks: [mkSegmentLink('sa-gen', 'GEN 1:1')], + phraseAnalyses: [{ ...FIXTURE_STAMPS, id: 'pa-gen', surfaceText: 'in the' }], + phraseAnalysisLinks: [makePhraseLink('pa-gen', ['GEN 1:1:0', 'GEN 1:1:3'])], + }; + const exodus: TextAnalysis = { + tokenAnalyses: [mkTokenAnalysis('shared')], + tokenAnalysisLinks: [mkTokenLink('shared', 'EXO 1:1:0')], + segmentAnalyses: [mkSegmentAnalysis('sa-exo')], + segmentAnalysisLinks: [mkSegmentLink('sa-exo', 'EXO 1:1')], + phraseAnalyses: [], + phraseAnalysisLinks: [], + }; + + it('concatenates every partition’s links in partition order', () => { + const merged = mergeAnalyses([genesis, exodus]); + + expect(merged.tokenAnalysisLinks).toEqual([ + ...genesis.tokenAnalysisLinks, + ...exodus.tokenAnalysisLinks, + ]); + expect(merged.segmentAnalysisLinks).toEqual([ + ...genesis.segmentAnalysisLinks, + ...exodus.segmentAnalysisLinks, + ]); + expect(merged.phraseAnalysisLinks).toEqual(genesis.phraseAnalysisLinks); + }); + + it('keeps every payload whose id no earlier partition carried', () => { + const merged = mergeAnalyses([genesis, exodus]); + + expect(merged.segmentAnalyses).toEqual([ + mkSegmentAnalysis('sa-gen'), + mkSegmentAnalysis('sa-exo'), + ]); + expect(merged.phraseAnalyses).toEqual(genesis.phraseAnalyses); + }); + + it('carries a payload two partitions both hold once', () => { + const merged = mergeAnalyses([genesis, exodus]); + + expect(merged.tokenAnalyses).toEqual([mkTokenAnalysis('ta-gen'), mkTokenAnalysis('shared')]); + }); + + it('rebuilds the analysis splitAnalysisByBook partitioned', () => { + const whole = mergeAnalyses([genesis, exodus]); + + expect(mergeAnalyses([...splitAnalysisByBook(whole).values()])).toEqual(whole); + }); +}); + describe('removeBookFromAnalysis', () => { /** * Builds a {@link TextAnalysis} spanning two books (GEN and EXO) with: diff --git a/src/__tests__/utils/perf-marks.test.ts b/src/__tests__/utils/perf-marks.test.ts new file mode 100644 index 000000000..8da488b91 --- /dev/null +++ b/src/__tests__/utils/perf-marks.test.ts @@ -0,0 +1,398 @@ +/// + +type PerfMarks = typeof import('../../utils/perf-marks'); + +type Entry = { + name: string; + entryType: string; + startTime: number; + duration?: number; + detail?: unknown; +}; + +let entries: Entry[]; +let clock: number; + +/** Loads a fresh copy of the module, as a new window would, with the storage key as given. */ +function loadPerfMarks(flag?: string): PerfMarks { + if (flag === undefined) localStorage.removeItem('interlinearizer.perfMarks'); + else localStorage.setItem('interlinearizer.perfMarks', flag); + let loaded: PerfMarks | undefined; + jest.isolateModules(() => { + loaded = jest.requireActual('../../utils/perf-marks'); + }); + if (!loaded) throw new Error('perf-marks did not load'); + return loaded; +} + +beforeEach(() => { + entries = []; + clock = 100; + Object.assign(performance, { + now: jest.fn(() => clock), + mark: jest.fn((name: string, options?: { detail?: unknown }) => { + entries.push({ name, entryType: 'mark', startTime: clock, detail: options?.detail }); + }), + measure: jest.fn(), + getEntriesByName: jest.fn((name: string, type: string) => + entries.filter((e) => e.name === name && e.entryType === type), + ), + getEntriesByType: jest.fn((type: string) => entries.filter((e) => e.entryType === type)), + clearMeasures: jest.fn(), + clearMarks: jest.fn(), + }); +}); + +afterEach(() => { + localStorage.clear(); +}); + +describe('perfMarksEnabled', () => { + it('is off when the storage key is absent', () => { + expect(loadPerfMarks().perfMarksEnabled()).toBe(false); + }); + + it('is on when the storage key is "true"', () => { + expect(loadPerfMarks('true').perfMarksEnabled()).toBe(true); + }); + + it('is off when the storage key holds anything else', () => { + expect(loadPerfMarks('yes').perfMarksEnabled()).toBe(false); + }); + + it('is off when storage cannot be read', () => { + jest.spyOn(Storage.prototype, 'getItem').mockImplementation(() => { + throw new DOMException('denied', 'SecurityError'); + }); + + expect(loadPerfMarks('true').perfMarksEnabled()).toBe(false); + }); + + it('keeps its first answer for the life of the window', () => { + const perfMarks = loadPerfMarks('true'); + perfMarks.perfMarksEnabled(); + localStorage.removeItem('interlinearizer.perfMarks'); + + expect(perfMarks.perfMarksEnabled()).toBe(true); + }); +}); + +describe('setPerfMarksEnabled', () => { + it('turns entries on where storage leaves them off', () => { + const perfMarks = loadPerfMarks(); + + perfMarks.setPerfMarksEnabled(true); + + expect(perfMarks.perfMarksEnabled()).toBe(true); + }); + + it('turns entries off where storage turns them on', () => { + const perfMarks = loadPerfMarks('true'); + + perfMarks.setPerfMarksEnabled(false); + + expect(perfMarks.perfMarksEnabled()).toBe(false); + }); +}); + +describe('takePerfEntries', () => { + it("returns this extension's measures without their prefix", () => { + entries.push( + { name: 'ilz:getDraft', entryType: 'measure', startTime: 0, duration: 12, detail: 7 }, + { name: 'other:render', entryType: 'measure', startTime: 0, duration: 3, detail: 0 }, + ); + + expect(loadPerfMarks().takePerfEntries()).toEqual([ + { name: 'getDraft', duration: 12, detail: 7 }, + ]); + }); + + it('carries no detail from an entry that has none', () => { + entries.push({ name: 'ilz:getDraft', entryType: 'measure', startTime: 0, duration: 12 }); + + expect(loadPerfMarks().takePerfEntries()).toEqual([ + { name: 'getDraft', duration: 12, detail: undefined }, + ]); + }); + + it('clears its own entries from the timeline, once per name', () => { + entries.push( + { name: 'ilz:getDraft', entryType: 'measure', startTime: 0, duration: 12 }, + { name: 'ilz:getDraft', entryType: 'measure', startTime: 20, duration: 9 }, + { name: 'ilz:dispatch', entryType: 'mark', startTime: 5 }, + ); + + loadPerfMarks().takePerfEntries(); + + expect(performance.clearMeasures).toHaveBeenCalledTimes(1); + expect(performance.clearMeasures).toHaveBeenCalledWith('ilz:getDraft'); + expect(performance.clearMarks).toHaveBeenCalledWith('ilz:dispatch'); + }); + + it('leaves entries other code recorded on the timeline', () => { + entries.push( + { name: 'other:render', entryType: 'measure', startTime: 0, duration: 3 }, + { name: 'other:start', entryType: 'mark', startTime: 0 }, + ); + + loadPerfMarks().takePerfEntries(); + + expect(performance.clearMeasures).not.toHaveBeenCalled(); + expect(performance.clearMarks).not.toHaveBeenCalled(); + }); +}); + +describe('perfMark', () => { + it('records a prefixed mark carrying its detail when marks are on', () => { + loadPerfMarks('true').perfMark('book-change', { book: 'GEN' }); + + expect(performance.mark).toHaveBeenCalledWith('ilz:book-change', { detail: { book: 'GEN' } }); + }); + + it('records the mark at the start time given', () => { + loadPerfMarks('true').perfMark('dispatch', undefined, 40); + + expect(performance.mark).toHaveBeenCalledWith('ilz:dispatch', { + detail: undefined, + startTime: 40, + }); + }); + + it('records nothing when marks are off', () => { + loadPerfMarks().perfMark('book-change'); + + expect(performance.mark).not.toHaveBeenCalled(); + }); +}); + +describe('perfMeasure', () => { + it('times from the latest start mark, carrying its detail', () => { + const perfMarks = loadPerfMarks('true'); + perfMarks.perfMark('book-change', { book: 'GEN' }); + clock = 150; + perfMarks.perfMark('book-change', { book: 'EXO' }); + + perfMarks.perfMeasure('book-render', 'book-change'); + + expect(performance.measure).toHaveBeenCalledWith('ilz:book-render', { + start: 150, + detail: { book: 'EXO' }, + }); + }); + + it('carries no detail from a start entry that has none', () => { + const perfMarks = loadPerfMarks('true'); + entries.push({ name: 'ilz:dispatch', entryType: 'mark', startTime: 10 }); + + perfMarks.perfMeasure('dispatch-render', 'dispatch'); + + expect(performance.measure).toHaveBeenCalledWith('ilz:dispatch-render', { + start: 10, + detail: undefined, + }); + }); + + it('records nothing when no start mark was made', () => { + loadPerfMarks('true').perfMeasure('book-render', 'book-change'); + + expect(performance.measure).not.toHaveBeenCalled(); + }); + + it('records nothing when marks are off', () => { + entries.push({ name: 'ilz:book-change', entryType: 'mark', startTime: 10 }); + + loadPerfMarks().perfMeasure('book-render', 'book-change'); + + expect(performance.measure).not.toHaveBeenCalled(); + }); +}); + +describe('perfMeasureFromFirst', () => { + it('times from the earliest pending start mark', () => { + entries.push( + { name: 'ilz:dispatch', entryType: 'mark', startTime: 10 }, + { name: 'ilz:dispatch', entryType: 'mark', startTime: 60 }, + ); + + loadPerfMarks('true').perfMeasureFromFirst('dispatch-render', 'dispatch'); + + expect(performance.measure).toHaveBeenCalledWith('ilz:dispatch-render', { start: 10 }); + }); + + it('consumes the pending start marks', () => { + entries.push({ name: 'ilz:dispatch', entryType: 'mark', startTime: 10 }); + + loadPerfMarks('true').perfMeasureFromFirst('dispatch-render', 'dispatch'); + + expect(performance.clearMarks).toHaveBeenCalledWith('ilz:dispatch'); + }); + + it('records nothing when no start mark is pending', () => { + loadPerfMarks('true').perfMeasureFromFirst('dispatch-render', 'dispatch'); + + expect(performance.measure).not.toHaveBeenCalled(); + }); + + it('records nothing when marks are off', () => { + entries.push({ name: 'ilz:dispatch', entryType: 'mark', startTime: 10 }); + + loadPerfMarks().perfMeasureFromFirst('dispatch-render', 'dispatch'); + + expect(performance.measure).not.toHaveBeenCalled(); + }); +}); + +describe('perfTime', () => { + it('returns what the work returns and records how long it took', () => { + const result = loadPerfMarks('true').perfTime( + 'tokenize', + () => { + clock = 130; + return 'tokens'; + }, + { book: 'GEN' }, + ); + + expect(result).toBe('tokens'); + expect(performance.measure).toHaveBeenCalledWith('ilz:tokenize', { + start: 100, + detail: { book: 'GEN' }, + }); + }); + + it('records the time even when the work throws', () => { + const perfMarks = loadPerfMarks('true'); + + expect(() => + perfMarks.perfTime('tokenize', () => { + throw new Error('bad USJ'); + }), + ).toThrow('bad USJ'); + expect(performance.measure).toHaveBeenCalledTimes(1); + }); + + it('only runs the work when marks are off', () => { + const work = jest.fn(() => 'tokens'); + + expect(loadPerfMarks().perfTime('tokenize', work)).toBe('tokens'); + expect(work).toHaveBeenCalledTimes(1); + expect(performance.measure).not.toHaveBeenCalled(); + }); +}); + +describe('perfTimeAsync', () => { + it('resolves as the work does, timing from before the work started', async () => { + const timed = loadPerfMarks('true').perfTimeAsync( + 'getDraft', + () => { + clock = 120; + return Promise.resolve('draft'); + }, + { bytes: 5 }, + ); + + await expect(timed).resolves.toBe('draft'); + expect(performance.measure).toHaveBeenCalledWith('ilz:getDraft', { + start: 100, + detail: { bytes: 5 }, + }); + }); + + it('records the time even when the work rejects', async () => { + const timed = loadPerfMarks('true').perfTimeAsync('getDraft', () => + Promise.reject(new Error('disk full')), + ); + + await expect(timed).rejects.toThrow('disk full'); + expect(performance.measure).toHaveBeenCalledTimes(1); + }); + + it('only runs the work when marks are off', async () => { + const work = jest.fn(() => Promise.resolve('draft')); + + await expect(loadPerfMarks().perfTimeAsync('getDraft', work)).resolves.toBe('draft'); + expect(work).toHaveBeenCalledTimes(1); + expect(performance.measure).not.toHaveBeenCalled(); + }); +}); + +describe('perfTimeAsyncExcluding', () => { + it('records the span less the nested measures recorded within it', async () => { + const timed = loadPerfMarks('true').perfTimeAsyncExcluding( + 'getDraft:read', + 'getDraft:parse', + () => { + entries.push( + { name: 'ilz:getDraft:parse', entryType: 'measure', startTime: 110, duration: 20 }, + { name: 'ilz:getDraft:parse', entryType: 'measure', startTime: 150, duration: 10 }, + ); + return Promise.resolve('shards'); + }, + ); + clock = 180; + + await expect(timed).resolves.toBe('shards'); + expect(performance.measure).toHaveBeenCalledWith('ilz:getDraft:read', { + start: 100, + duration: 50, + }); + }); + + it('counts no nested measure recorded outside the span', async () => { + entries.push({ name: 'ilz:getDraft:parse', entryType: 'measure', startTime: 40, duration: 20 }); + const timed = loadPerfMarks('true').perfTimeAsyncExcluding( + 'getDraft:read', + 'getDraft:parse', + () => Promise.resolve('shards'), + ); + clock = 180; + + await timed; + + expect(performance.measure).toHaveBeenCalledWith('ilz:getDraft:read', { + start: 100, + duration: 80, + }); + }); + + it('only runs the work when marks are off', async () => { + const work = jest.fn(() => Promise.resolve('shards')); + + await expect( + loadPerfMarks().perfTimeAsyncExcluding('getDraft:read', 'getDraft:parse', work), + ).resolves.toBe('shards'); + expect(work).toHaveBeenCalledTimes(1); + expect(performance.measure).not.toHaveBeenCalled(); + }); +}); + +describe('perfTrack', () => { + it('resolves as the promise it was given does, recording when it settled', async () => { + const tracked = loadPerfMarks('true').perfTrack('autosave', Promise.resolve('saved'), { + bytes: 12, + }); + + await expect(tracked).resolves.toBe('saved'); + expect(performance.measure).toHaveBeenCalledWith('ilz:autosave', { + start: 100, + detail: { bytes: 12 }, + }); + }); + + it('records when the promise rejects', async () => { + const pending = Promise.reject(new Error('offline')); + + await expect(loadPerfMarks('true').perfTrack('autosave', pending)).rejects.toThrow('offline'); + expect(performance.measure).toHaveBeenCalledTimes(1); + }); + + it('hands back the promise it was given, recording nothing, when marks are off', async () => { + const pending = Promise.resolve('saved'); + + const tracked = loadPerfMarks().perfTrack('autosave', pending); + await tracked; + + expect(tracked).toBe(pending); + expect(performance.measure).not.toHaveBeenCalled(); + }); +}); diff --git a/src/components/AnalysisStore.tsx b/src/components/AnalysisStore.tsx index 7bf22b20a..c54aff1b0 100644 --- a/src/components/AnalysisStore.tsx +++ b/src/components/AnalysisStore.tsx @@ -18,6 +18,7 @@ import { import type { ReactNode } from 'react'; import { Provider as ReduxProvider, useDispatch, useSelector, useStore } from 'react-redux'; import { createAnalysisStore, type AnalysisDispatch, type AnalysisRootState } from '../store'; +import { perfMark, perfMarksEnabled, perfMeasure, perfMeasureFromFirst } from '../utils/perf-marks'; import analysisReducer, { approveAnalysisForToken, confirmAnalysisMorphemes, @@ -177,6 +178,7 @@ export function AnalysisStoreProvider({ // Lazy initialization: useRef(createStore()) would create and discard a store on every render const storeRef = useRef | undefined>(undefined); if (!storeRef.current) { + perfMark('store-create'); storeRef.current = createAnalysisStore({ analysis: { analysis: initialAnalysis ?? emptyAnalysis(), analysisLanguage }, }); @@ -193,6 +195,9 @@ export function AnalysisStoreProvider({ store.dispatch(setAnalysisLanguage(analysisLanguage)); }, [store, analysisLanguage]); + // Runs after the subtree's first commit, which is when the store's first readers have rendered. + useLayoutEffect(() => perfMeasure('store-mount', 'store-create'), []); + // Use refs so the dispatch callback never needs to re-create when parent re-renders const onSaveRef = useRef(onSave); onSaveRef.current = onSave; @@ -244,10 +249,22 @@ export function AnalysisStoreProvider({ return ( {children} + {perfMarksEnabled() && } ); } +/** Times each commit of a changed analysis from the earliest dispatch it renders. */ +function DispatchRenderProbe() { + const analysis = useSelector((state: AnalysisRootState) => state.analysis.analysis); + const mountedRef = useRef(false); + useLayoutEffect(() => { + if (mountedRef.current) perfMeasureFromFirst('dispatch-render', 'dispatch'); + mountedRef.current = true; + }, [analysis]); + return undefined; +} + // #endregion // #region Internal hooks diff --git a/src/components/Interlinearizer.tsx b/src/components/Interlinearizer.tsx index 142baf23a..07c2b3de5 100644 --- a/src/components/Interlinearizer.tsx +++ b/src/components/Interlinearizer.tsx @@ -1,7 +1,7 @@ import type { SerializedVerseRef } from '@sillsdev/scripture'; import type { Book } from 'interlinearizer'; import { TooltipProvider } from 'platform-bible-react'; -import { useCallback, useEffect, useMemo, useState } from 'react'; +import { useCallback, useEffect, useLayoutEffect, useMemo, useState } from 'react'; import type { Dispatch, SetStateAction } from 'react'; import { usePhraseDispatch, usePhraseLinkByIdGetter, usePhraseLinkByIdMap } from './AnalysisStore'; import { @@ -17,6 +17,7 @@ import { useAltHeldAttribute } from '../hooks/useAltHeldAttribute'; import type { PhraseMode } from '../types/phrase-mode'; import { TOOLTIP_DELAY_MS } from './tooltip-delay'; import type { ViewOptions } from '../types/view-options'; +import { perfMeasure } from '../utils/perf-marks'; import { phrasesStraddlingBoundary, splitPhraseAtBoundary } from '../utils/phrase-arc'; import SegmentListView from './SegmentListView'; import UnlinkPhraseConfirm from './modals/UnlinkPhraseConfirm'; @@ -98,6 +99,8 @@ export default function Interlinearizer({ // and `reportSettled` lifts the cross-book curtain once the new book is laid out. const { consumeInternalNav, recenterRequest, reportSettled } = useInterlinearNav(); + useLayoutEffect(() => perfMeasure('book-render', 'book-change'), [book.bookRef]); + useAltHeldAttribute(); // Book-wide lookup indexes. diff --git a/src/components/InterlinearizerLoader.tsx b/src/components/InterlinearizerLoader.tsx index 2e8d52430..43a46026b 100644 --- a/src/components/InterlinearizerLoader.tsx +++ b/src/components/InterlinearizerLoader.tsx @@ -49,6 +49,7 @@ import { splitSegmentBefore, unmergeableVerseStarts, } from '../utils/segmentation'; +import { perfTrack } from '../utils/perf-marks'; import { reanchorDraftToBook } from '../utils/reanchor-draft'; import { isInterlinearProjectSummary, isTextAnalysis, isWordToken } from '../types/type-guards'; import { isPt9ImportReport, isPt9UnreadableFileList } from '../converters/pt9'; @@ -1312,14 +1313,19 @@ function InterlinearizerLoaderInner({ return; } try { - const savedJson = await papi.commands.sendCommand( - 'interlinearizer.saveAnalysis', - activeProject.id, - JSON.stringify(snapshot.analysis), - // Send the draft's boundary state on every Save; `null` clears any stored boundaries so a - // reverted segmentation propagates to the project rather than leaving it stale. - // eslint-disable-next-line no-null/no-null -- "null" is the JSON sentinel that clears boundaries - JSON.stringify(snapshot.segmentation ?? null), + const analysisJson = JSON.stringify(snapshot.analysis); + const savedJson = await perfTrack( + 'save', + papi.commands.sendCommand( + 'interlinearizer.saveAnalysis', + activeProject.id, + analysisJson, + // Send the draft's boundary state on every Save; `null` clears any stored boundaries so a + // reverted segmentation propagates to the project rather than leaving it stale. + // eslint-disable-next-line no-null/no-null -- "null" is the JSON sentinel that clears boundaries + JSON.stringify(snapshot.segmentation ?? null), + ), + { bytes: analysisJson.length }, ); // A successful save returns the saved project JSON; `undefined` means the project no longer // exists, so nothing was persisted — leave the draft dirty rather than marking it clean. diff --git a/src/hooks/useConcordanceIndex.ts b/src/hooks/useConcordanceIndex.ts index e6fff1376..67700e502 100644 --- a/src/hooks/useConcordanceIndex.ts +++ b/src/hooks/useConcordanceIndex.ts @@ -12,6 +12,7 @@ import { type ConcordanceEntry, } from '../utils/concordance'; import { collatorForTag } from '../utils/language-tags'; +import { perfMark, perfMeasure, perfTime } from '../utils/perf-marks'; /** Where reading the project's books has got to. */ export type ConcordanceIndexStatus = 'idle' | 'loading' | 'ready' | 'error'; @@ -114,6 +115,7 @@ export default function useConcordanceIndex({ let isCurrent = true; setStatus('loading'); setProgress({ booksRead: 0, bookCount: 0 }); + perfMark('concordance-start'); (async () => { try { const basePdp = await papi.projectDataProviders.get('platform.base', projectId); @@ -150,6 +152,7 @@ export default function useConcordanceIndex({ setStatus('error'); return; } + perfMeasure('concordance-read', 'concordance-start'); setReadings(read); setStatus('ready'); } catch (e) { @@ -198,7 +201,7 @@ export default function useConcordanceIndex({ if (status !== 'ready' || !readings) return []; const books = new Map(readings); mergedLiveVersions.forEach((index, book) => books.set(book, index)); - return buildConcordanceEntries(books.values(), collator); + return perfTime('concordance-entries', () => buildConcordanceEntries(books.values(), collator)); }, [status, readings, mergedLiveVersions, collator]); return useMemo( diff --git a/src/hooks/useDraftProject.ts b/src/hooks/useDraftProject.ts index fe4df373b..71d39267c 100644 --- a/src/hooks/useDraftProject.ts +++ b/src/hooks/useDraftProject.ts @@ -9,6 +9,7 @@ import { useCallback, useEffect, useRef, useState } from 'react'; import { emptyAnalysis, emptyDraft } from '../types/empty-factories'; import { CURRENT_MODEL_VERSION } from '../types/model-version'; import { removeBookFromAnalysis, removeBookFromSegmentation } from '../utils/analysis-book'; +import { perfTime, perfTrack } from '../utils/perf-marks'; import { isEmptyDelta } from '../utils/segmentation'; import { canRedo as historyCanRedo, @@ -317,9 +318,12 @@ export default function useDraftProject( */ const persist = useCallback( (draft: DraftProject) => { - papi.commands - .sendCommand('interlinearizer.saveDraft', sourceProjectId, JSON.stringify(draft)) - .catch((e) => logger.error('Interlinearizer: failed to save draft', e)); + const json = perfTime('autosave-serialize', () => JSON.stringify(draft)); + perfTrack( + 'autosave', + papi.commands.sendCommand('interlinearizer.saveDraft', sourceProjectId, json), + { bytes: json.length }, + ).catch((e) => logger.error('Interlinearizer: failed to save draft', e)); }, [sourceProjectId], ); @@ -336,8 +340,11 @@ export default function useDraftProject( const load = async () => { let draft: DraftProject; try { - const json = await papi.commands.sendCommand('interlinearizer.getDraft', sourceProjectId); - draft = JSON.parse(json); + const json = await perfTrack( + 'draft-fetch', + papi.commands.sendCommand('interlinearizer.getDraft', sourceProjectId), + ); + draft = perfTime('draft-parse', () => JSON.parse(json), { bytes: json.length }); } catch (e) { logger.error('Interlinearizer: failed to load draft', e); draft = emptyDraft(sourceProjectId); diff --git a/src/hooks/useInterlinearizerBookData.ts b/src/hooks/useInterlinearizerBookData.ts index ca77748ff..5fe9aab0d 100644 --- a/src/hooks/useInterlinearizerBookData.ts +++ b/src/hooks/useInterlinearizerBookData.ts @@ -6,6 +6,7 @@ import { extractBookFromUsj } from 'parsers/papi/usjBookExtractor'; import { tokenizeBook } from 'parsers/papi/bookTokenizer'; import { isPlatformError } from 'platform-bible-utils'; import { useEffect, useMemo, useRef } from 'react'; +import { perfMark, perfMeasure, perfTime } from '../utils/perf-marks'; /** Arguments for the {@link useInterlinearizerBookData} hook. */ export interface UseInterlinearizerBookDataArgs { @@ -47,10 +48,10 @@ export default function useInterlinearizerBookData({ projectId, scrRef, }: Readonly): UseInterlinearizerBookDataResult { - const bookScrRef = useMemo( - () => ({ book: scrRef.book, chapterNum: 1, verseNum: 1 }), - [scrRef.book], - ); + const bookScrRef = useMemo(() => { + perfMark('book-change', { book: scrRef.book }); + return { book: scrRef.book, chapterNum: 1, verseNum: 1 }; + }, [scrRef.book]); const [rawBookResult, , isLoading] = useProjectData( 'platformScripture.USJ_Book', @@ -72,6 +73,7 @@ export default function useInterlinearizerBookData({ if (json === prevJsonRef.current) return stableBookResultRef.current; prevJsonRef.current = json; stableBookResultRef.current = rawBookResult; + perfMeasure('usj-fetch', 'book-change'); return rawBookResult; }, [rawBookResult]); @@ -85,7 +87,10 @@ export default function useInterlinearizerBookData({ if (!bookResult || isPlatformError(bookResult)) return [undefined, undefined]; try { - return [tokenizeBook(extractBookFromUsj(bookResult, writingSystemTag)), undefined]; + const tokenized = perfTime('tokenize', () => + tokenizeBook(extractBookFromUsj(bookResult, writingSystemTag)), + ); + return [tokenized, undefined]; } catch (err) { return [undefined, { message: err instanceof Error ? err.message : String(err), raw: err }]; } diff --git a/src/hooks/useProjectsForSource.ts b/src/hooks/useProjectsForSource.ts index e53280b41..529e1c117 100644 --- a/src/hooks/useProjectsForSource.ts +++ b/src/hooks/useProjectsForSource.ts @@ -2,6 +2,7 @@ import papi, { logger } from '@papi/frontend'; import { useEffect, useState } from 'react'; import type { InterlinearProjectSummary } from '../types/interlinear-project-summary'; import { isInterlinearProjectSummary } from '../types/type-guards'; +import { perfTrack } from '../utils/perf-marks'; import { compareUpdatedAtDescending } from '../utils/project-summary-format'; /** Return value of {@link useProjectsForSource}. */ @@ -34,9 +35,9 @@ export default function useProjectsForSource(sourceProjectId: string): UseProjec const load = async () => { try { - const json = await papi.commands.sendCommand( - 'interlinearizer.getProjectsForSource', - sourceProjectId, + const json = await perfTrack( + 'projects-fetch', + papi.commands.sendCommand('interlinearizer.getProjectsForSource', sourceProjectId), ); if (ignore) return; const parsed: unknown = JSON.parse(json); diff --git a/src/main.ts b/src/main.ts index d9a674dbc..54406bc5f 100644 --- a/src/main.ts +++ b/src/main.ts @@ -11,11 +11,13 @@ import type { SegmentationDelta } from 'interlinearizer'; import { formatReplacementString } from 'platform-bible-utils'; import interlinearizerReact from './interlinearizer.web-view?inline'; import interlinearizerStyles from './interlinearizer.web-view.scss?inline'; +import { readHostPerf, setHostPerfMarks } from './services/hostPerf'; import * as projectStorage from './services/projectStorage'; import * as pt9ImportService from './services/pt9ImportService'; import type { Pt9ImportResult } from './services/pt9ImportService'; import { toProjectSummary } from './types/interlinear-project-summary'; import { isDraftProject, isSegmentationDelta, isTextAnalysis } from './types/type-guards'; +import { perfTime, perfTimeAsync } from './utils/perf-marks'; import { summarizeAnalysis } from './utils/project-analysis-summary'; // #region WebView provider @@ -410,33 +412,39 @@ async function saveInterlinearAnalysis( segmentationJson?: string, ): Promise { try { - const analysis = JSON.parse(analysisJson); - if (!isTextAnalysis(analysis)) { - throw new TypeError('saveInterlinearAnalysis: analysisJson does not conform to TextAnalysis'); - } - // undefined ⇒ leave boundaries unchanged; null ⇒ clear them; an object ⇒ set them. - let segmentation: SegmentationDelta | null | undefined; - if (segmentationJson !== undefined) { - const parsed: unknown = JSON.parse(segmentationJson); - // eslint-disable-next-line no-null/no-null -- JSON.parse('null') yields null, the clear sentinel - if (parsed === null) { - // eslint-disable-next-line no-null/no-null -- explicit "clear boundaries" sentinel from the WebView - segmentation = null; - } else if (isSegmentationDelta(parsed)) { - segmentation = parsed; - } else { + return await perfTimeAsync('saveAnalysis', async () => { + const analysis = perfTime('saveAnalysis:parse', () => JSON.parse(analysisJson)); + if (!isTextAnalysis(analysis)) { throw new TypeError( - 'saveInterlinearAnalysis: segmentationJson does not conform to SegmentationDelta', + 'saveInterlinearAnalysis: analysisJson does not conform to TextAnalysis', ); } - } - const updated = await projectStorage.updateAnalysis( - executionToken, - interlinearProjectId, - analysis, - segmentation, - ); - return updated ? JSON.stringify(updated) : undefined; + // undefined ⇒ leave boundaries unchanged; null ⇒ clear them; an object ⇒ set them. + let segmentation: SegmentationDelta | null | undefined; + if (segmentationJson !== undefined) { + const parsed: unknown = JSON.parse(segmentationJson); + // eslint-disable-next-line no-null/no-null -- JSON.parse('null') yields null, the clear sentinel + if (parsed === null) { + // eslint-disable-next-line no-null/no-null -- explicit "clear boundaries" sentinel from the WebView + segmentation = null; + } else if (isSegmentationDelta(parsed)) { + segmentation = parsed; + } else { + throw new TypeError( + 'saveInterlinearAnalysis: segmentationJson does not conform to SegmentationDelta', + ); + } + } + const updated = await projectStorage.updateAnalysis( + executionToken, + interlinearProjectId, + analysis, + segmentation, + ); + return updated + ? perfTime('saveAnalysis:serialize', () => JSON.stringify(updated)) + : undefined; + }); } catch (e) { logger.error('Interlinearizer: failed to save analysis', e); await papi.notifications @@ -461,8 +469,10 @@ async function saveInterlinearAnalysis( */ async function getInterlinearDraft(sourceProjectId: string): Promise { try { - const draft = await projectStorage.getDraft(executionToken, sourceProjectId); - return JSON.stringify(draft); + return await perfTimeAsync('getDraft', async () => { + const draft = await projectStorage.getDraft(executionToken, sourceProjectId); + return perfTime('getDraft:serialize', () => JSON.stringify(draft)); + }); } catch (e) { logger.error('Interlinearizer: failed to get draft', e); throw e; @@ -482,11 +492,13 @@ async function getInterlinearDraft(sourceProjectId: string): Promise { */ async function saveInterlinearDraft(sourceProjectId: string, draftJson: string): Promise { try { - const draft = JSON.parse(draftJson); - if (!isDraftProject(draft)) { - throw new TypeError('saveInterlinearDraft: draftJson does not conform to DraftProject'); - } - await projectStorage.saveDraft(executionToken, sourceProjectId, draft); + await perfTimeAsync('saveDraft', async () => { + const draft = perfTime('saveDraft:parse', () => JSON.parse(draftJson)); + if (!isDraftProject(draft)) { + throw new TypeError('saveInterlinearDraft: draftJson does not conform to DraftProject'); + } + await projectStorage.saveDraft(executionToken, sourceProjectId, draft); + }); } catch (e) { logger.error('Interlinearizer: failed to save draft', e); await papi.notifications @@ -516,13 +528,17 @@ async function saveInterlinearDraft(sourceProjectId: string, draftJson: string): */ async function getProjectsForSource(sourceProjectId: string): Promise { try { - const projects = await projectStorage.getProjectsForSource(executionToken, sourceProjectId); - return JSON.stringify( - projects.map((project) => ({ - ...toProjectSummary(project), - ...summarizeAnalysis(project.analysis), - })), - ); + return await perfTimeAsync('getProjectsForSource', async () => { + const projects = await projectStorage.getProjectsForSource(executionToken, sourceProjectId); + return perfTime('getProjectsForSource:serialize', () => + JSON.stringify( + projects.map((project) => ({ + ...toProjectSummary(project), + ...summarizeAnalysis(project.analysis), + })), + ), + ); + }); } catch (e) { logger.error('Interlinearizer: failed to list projects for source', e); throw e; @@ -792,6 +808,44 @@ export async function activate(context: ExecutionActivationContext): Promise setHostPerfMarks(enabled), + { + method: { + summary: "Turn the extension host's timing entries on or off for the performance harness", + params: [ + { + name: 'enabled', + required: true, + summary: 'Whether the host records timing entries', + schema: { type: 'boolean' }, + }, + ], + result: { name: 'return value', summary: 'void', schema: { type: 'null' } }, + }, + }, + ); + + const readPerfCommandRegistration = await papi.commands.registerCommand( + 'interlinearizer.readPerf', + async () => { + const reading = readHostPerf(); + return reading && JSON.stringify(reading); + }, + { + method: { + summary: 'Take the timing entries the extension host recorded since the last reading', + params: [], + result: { + name: 'return value', + summary: 'JSON-stringified { entries, pid }, or undefined while timing entries are off', + schema: { type: 'string' }, + }, + }, + }, + ); + const updateProjectMetadataCommandRegistration = await papi.commands.registerCommand( 'interlinearizer.updateProjectMetadata', updateProjectMetadata, @@ -1116,6 +1170,8 @@ export async function activate(context: ExecutionActivationContext): Promise(id: string, fn: () => Promise): Promise { return enqueueSerialized(projectQueues, id, fn); } -/** Returns the storage key for a project by ID. */ -function projectKey(id: string): string { - return `project:${id}`; -} - /** The error rejecting a user write to a Paratext 9 import, whose content only sync replaces. */ function pt9ImportReadOnlyError(id: string): Error { return new Error(`Project ${id} is a Paratext 9 import and is read-only`); } -/** Returns the storage key for a source project's draft. */ -function draftKey(sourceProjectId: string): string { - return `draft:${sourceProjectId}`; -} - -/** Returns the storage key holding one book's slice of a draft's analysis. */ -function draftAnalysisKey(sourceProjectId: string, bookCode: string): string { - return `draft:${sourceProjectId}:analysis:${bookCode}`; -} - -/** Returns the storage key holding a source project's {@link ShardJournal}. */ -function draftJournalKey(sourceProjectId: string): string { - return `draft:${sourceProjectId}:shards`; -} - /** * Names the shards a save is about to strand if it is interrupted, so the next run can find them * without the in-memory tally. Storage cannot enumerate keys, so a shard the manifest does not name @@ -326,19 +308,26 @@ type LoadedShard = { }; /** - * Reads one book's analysis shard, treating a missing or unusable one as empty so a single lost - * book does not fail the whole load. + * Reads the record stored at `key`. * + * @returns `undefined` when `key` has never been written (ENOENT). * @throws If `papi.storage.readUserData` rejects for any non-ENOENT reason. */ -async function readAnalysisShard(token: ExecutionToken, key: string): Promise { - let raw: string; +async function readRecord(token: ExecutionToken, key: string): Promise { try { - raw = await papi.storage.readUserData(token, key); + return await papi.storage.readUserData(token, key); } catch (e) { - if (isNotFound(e)) return { analysis: emptyAnalysis(), state: 'absent' }; + if (isNotFound(e)) return undefined; throw e; } +} + +/** + * Parses one book's analysis shard as read from `key`, treating a missing or unusable one as empty + * so a single lost book does not fail the whole load. + */ +function parseAnalysisShard(raw: string | undefined, key: string): LoadedShard { + if (raw === undefined) return { analysis: emptyAnalysis(), state: 'absent' }; try { const parsed: unknown = JSON.parse(raw); if (!isTextAnalysis(parsed)) { @@ -352,28 +341,6 @@ async function readAnalysisShard(token: ExecutionToken, key: string): Promise(); - const appendPayloads = (payloads: readonly T[], into: T[]) => { - payloads.forEach((payload) => { - if (seenPayloadIds.has(payload.id)) return; - seenPayloadIds.add(payload.id); - into.push(payload); - }); - }; - partitions.forEach((partition) => { - merged.tokenAnalysisLinks.push(...partition.tokenAnalysisLinks); - merged.segmentAnalysisLinks.push(...partition.segmentAnalysisLinks); - merged.phraseAnalysisLinks.push(...partition.phraseAnalysisLinks); - appendPayloads(partition.tokenAnalyses, merged.tokenAnalyses); - appendPayloads(partition.segmentAnalyses, merged.segmentAnalyses); - appendPayloads(partition.phraseAnalyses, merged.phraseAnalyses); - }); - return merged; -} - /** * Returns true when `e` is a file-not-found error (ENOENT) from the Node.js file system, which is * what `papi.storage.readUserData` throws when the requested key has never been written. @@ -825,26 +792,30 @@ export async function getProject( token: ExecutionToken, id: string, ): Promise { - try { - const stored: StoredProject = JSON.parse( - await papi.storage.readUserData(token, projectKey(id)), + const raw = await readRecord(token, projectKey(id)); + return raw === undefined ? undefined : parseProject(raw, id); +} + +/** + * Parses project `id`'s stored record as {@link getProject} describes. + * + * @throws {SyntaxError} If `raw` is not valid JSON. + * @throws {Error} If the stored record's `modelVersion` is higher than this build's. + */ +function parseProject(raw: string, id: string): InterlinearProject { + const stored: StoredProject = JSON.parse(raw); + assertSupportedModelVersion(stored, `project ${id}`); + if (!stored.createdAt) + logger.warn( + `Interlinearizer: project ${id} was stored without a creation time; dating it by the read time`, ); - assertSupportedModelVersion(stored, `project ${id}`); - if (!stored.createdAt) - logger.warn( - `Interlinearizer: project ${id} was stored without a creation time; dating it by the read time`, - ); - const createdAt = stored.createdAt ?? new Date().toISOString(); - reportAnalysisViolations(stored.analysis, `project ${id} on load`); - return { - ...stored, - createdAt, - updatedAt: stored.updatedAt ?? createdAt, - }; - } catch (e) { - if (isNotFound(e)) return undefined; - throw e; - } + const createdAt = stored.createdAt ?? new Date().toISOString(); + reportAnalysisViolations(stored.analysis, `project ${id} on load`); + return { + ...stored, + createdAt, + updatedAt: stored.updatedAt ?? createdAt, + }; } /** @@ -858,16 +829,25 @@ export async function getProject( * @throws If `papi.storage.readUserData` rejects for any non-ENOENT reason when reading the index. */ export async function listProjects(token: ExecutionToken): Promise { - const ids = await readIds(token); - const projects = await Promise.all( - ids.map(async (id) => { - try { - return await getProject(token, id); - } catch (e) { - logger.error(`Interlinearizer: failed to read project ${id}:`, e); - return undefined; - } - }), + const projects = await perfTimeAsyncExcluding( + 'listProjects:read', + 'listProjects:parse', + async () => { + const ids = await readIds(token); + return Promise.all( + ids.map(async (id) => { + try { + const raw = await readRecord(token, projectKey(id)); + return raw === undefined + ? undefined + : perfTime('listProjects:parse', () => parseProject(raw, id)); + } catch (e) { + logger.error(`Interlinearizer: failed to read project ${id}:`, e); + return undefined; + } + }), + ); + }, ); return projects.filter((p): p is InterlinearProject => p !== undefined); } @@ -912,10 +892,13 @@ export async function updateAnalysis( segmentation?: SegmentationDelta | null, ): Promise { return enqueueProjectOp(id, async () => { - const project = await getProject(token, id); - if (!project) return undefined; + const raw = await perfTimeAsync('updateAnalysis:read', () => readRecord(token, projectKey(id))); + if (raw === undefined) return undefined; + const project = perfTime('updateAnalysis:parse', () => parseProject(raw, id)); if (project.pt9Import) throw pt9ImportReadOnlyError(id); - reportAnalysisViolations(analysis, `project ${id} on save`); + perfTime('updateAnalysis:parse', () => + reportAnalysisViolations(analysis, `project ${id} on save`), + ); const updated: InterlinearProject = { ...project, modelVersion: CURRENT_MODEL_VERSION, @@ -925,7 +908,9 @@ export async function updateAnalysis( // eslint-disable-next-line no-null/no-null -- null is the explicit "clear stored boundaries" sentinel if (segmentation === null) delete updated.segmentation; else if (segmentation !== undefined) updated.segmentation = segmentation; - await papi.storage.writeUserData(token, projectKey(id), JSON.stringify(updated)); + await perfTimeAsync('updateAnalysis:write', () => + papi.storage.writeUserData(token, projectKey(id), JSON.stringify(updated)), + ); return updated; }); } @@ -1058,41 +1043,57 @@ export async function getDraft( sourceProjectId: string, ): Promise { return enqueueSerialized(draftQueues, sourceProjectId, async () => { - try { - const parsed: unknown = JSON.parse( - await papi.storage.readUserData(token, draftKey(sourceProjectId)), - ); - // Refuse a newer build's draft before validating it: a later shape need not satisfy this - // build's guard, and failing validation is what resets the draft to empty. - assertSupportedModelVersion(parsed, `draft for source project ${sourceProjectId}`); - if (!isDraftProject(parsed) || parsed.sourceProjectId !== sourceProjectId) { - logger.warn('Interlinearizer: stored draft failed validation; resetting to empty draft'); - return emptyDraft(sourceProjectId); - } - const { analysisBooks, ...draft } = withoutShardManifest(parsed); - const describeDraft = `draft for source project ${sourceProjectId} on load`; - // A draft with no manifest carries its analysis inline, with no shards to read. - if (!analysisBooks) { - reportAnalysisViolations(draft.analysis, describeDraft); - return draft; - } - // A save interrupted before its envelope landed leaves shards this manifest never came to - // name. A journaled book whose shard never landed reads as missing and drops back out below. - const { adding } = await readShardJournal(token, sourceProjectId); - const orphaned = adding.filter((bookCode) => !analysisBooks.includes(bookCode)); - const booksToRead = [...analysisBooks, ...orphaned]; - const shards = await Promise.all( - booksToRead.map((bookCode) => - readAnalysisShard(token, draftAnalysisKey(sourceProjectId, bookCode)), - ), - ); - // Record what each shard holds so the next save can tell which books actually changed. An - // unusable shard's empty stand-in is not what is on disk, so it is recorded apart. A journaled - // book is dropped only when its shard is gone: dropping one still in storage would strand it, - // with neither the manifest nor the journal left to name it. - const loadedByBook = booksToRead - .map((bookCode, i) => ({ bookCode, ...shards[i] })) - .filter(({ bookCode, state }) => state !== 'absent' || !orphaned.includes(bookCode)); + const raw = await perfTimeAsync('getDraft:read', () => + readRecord(token, draftKey(sourceProjectId)), + ); + if (raw === undefined) return emptyDraft(sourceProjectId); + const parsed: unknown = perfTime('getDraft:parse', () => JSON.parse(raw)); + // Refuse a newer build's draft before validating it: a later shape need not satisfy this + // build's guard, and failing validation is what resets the draft to empty. + assertSupportedModelVersion(parsed, `draft for source project ${sourceProjectId}`); + if (!isDraftProject(parsed) || parsed.sourceProjectId !== sourceProjectId) { + logger.warn('Interlinearizer: stored draft failed validation; resetting to empty draft'); + return emptyDraft(sourceProjectId); + } + const { analysisBooks, ...draft } = withoutShardManifest(parsed); + const describeDraft = `draft for source project ${sourceProjectId} on load`; + // A draft with no manifest carries its analysis inline, with no shards to read. + if (!analysisBooks) { + perfTime('getDraft:parse', () => reportAnalysisViolations(draft.analysis, describeDraft)); + return draft; + } + const keyOf = (bookCode: string) => draftAnalysisKey(sourceProjectId, bookCode); + // A save interrupted before its envelope landed leaves shards this manifest never came to + // name. A journaled book whose shard never landed reads as missing and drops back out below. + const { booksToRead, orphaned, shards } = await perfTimeAsyncExcluding( + 'getDraft:read', + 'getDraft:parse', + async () => { + const { adding } = await readShardJournal(token, sourceProjectId); + const orphanedBooks = adding.filter((bookCode) => !analysisBooks.includes(bookCode)); + const books = [...analysisBooks, ...orphanedBooks]; + return { + booksToRead: books, + orphaned: orphanedBooks, + shards: await Promise.all( + books.map(async (bookCode) => { + const shardRaw = await readRecord(token, keyOf(bookCode)); + return perfTime('getDraft:parse', () => + parseAnalysisShard(shardRaw, keyOf(bookCode)), + ); + }), + ), + }; + }, + ); + // Record what each shard holds so the next save can tell which books actually changed. An + // unusable shard's empty stand-in is not what is on disk, so it is recorded apart. A journaled + // book is dropped only when its shard is gone: dropping one still in storage would strand it, + // with neither the manifest nor the journal left to name it. + const loadedByBook = booksToRead + .map((bookCode, i) => ({ bookCode, ...shards[i] })) + .filter(({ bookCode, state }) => state !== 'absent' || !orphaned.includes(bookCode)); + perfTime('getDraft:compare', () => shardContentsBySource.set( sourceProjectId, new Map( @@ -1100,22 +1101,21 @@ export async function getDraft( .filter(({ state }) => state === 'loaded') .map(({ bookCode, analysis }) => [bookCode, JSON.stringify(analysis)]), ), - ); - unreadableShardsBySource.set( - sourceProjectId, - new Set( - loadedByBook.filter(({ state }) => state !== 'loaded').map(({ bookCode }) => bookCode), - ), - ); - // Checked once merged: a link and its payload can sit in different shards, so a violation is - // only real of the whole. + ), + ); + unreadableShardsBySource.set( + sourceProjectId, + new Set( + loadedByBook.filter(({ state }) => state !== 'loaded').map(({ bookCode }) => bookCode), + ), + ); + return perfTime('getDraft:parse', () => { + // Checked once merged: a link and its payload can sit in different shards, so a violation + // is only real of the whole. const analysis = mergeAnalyses(shards.map((shard) => shard.analysis)); reportAnalysisViolations(analysis, describeDraft); return { ...draft, analysis }; - } catch (e) { - if (isNotFound(e)) return emptyDraft(sourceProjectId); - throw e; - } + }); }); } @@ -1190,15 +1190,19 @@ export async function saveDraft( ): Promise { // Invariant violations go unreported here: this runs on every edit, so one would log per keystroke. await enqueueSerialized(draftQueues, sourceProjectId, async () => { - const storedBooks = await assertStoredDraftIsWritable(token, sourceProjectId); - const byBook = splitAnalysisByBook(draft.analysis); + const storedBooks = await perfTimeAsync('saveDraft:read', () => + assertStoredDraftIsWritable(token, sourceProjectId), + ); + const byBook = perfTime('saveDraft:compare', () => splitAnalysisByBook(draft.analysis)); const written = getOrCreateEntry(shardContentsBySource, sourceProjectId, () => new Map()); const unreadable = getOrCreateEntry(unreadableShardsBySource, sourceProjectId, () => new Set()); // Books this save no longer carries, less those held back because the load could not read them. // A save whose draft was never loaded here has only the stored manifest or the journal to name // earlier shards. A journaled addition whose shard never landed deletes as a no-op. - const journaled = await readShardJournal(token, sourceProjectId); + const journaled = await perfTimeAsync('saveDraft:read', () => + readShardJournal(token, sourceProjectId), + ); const knownShards = new Set([ ...written.keys(), ...storedBooks, @@ -1213,23 +1217,33 @@ export async function saveDraft( // Name every shard this save could strand before writing any of it. A book the stored manifest // already names needs no entry: it survives an interruption by that manifest alone. const stranded = [...byBook.keys()].filter((bookCode) => !storedBooks.includes(bookCode)); - await writeShardJournal(token, sourceProjectId, { adding: stranded, removing: wiped }); + await perfTimeAsync('saveDraft:write', () => + writeShardJournal(token, sourceProjectId, { adding: stranded, removing: wiped }), + ); - await settleAll( - [...byBook].map(async ([bookCode, partition]) => { + const shards = perfTime('saveDraft:compare', () => + [...byBook].map(([bookCode, partition]) => { const json = JSON.stringify(partition); - if (written.get(bookCode) !== json) { - await papi.storage.writeUserData( - token, - draftAnalysisKey(sourceProjectId, bookCode), - json, - ); - } - written.set(bookCode, json); - // This save rewrote the book, so a later wipe must be free to delete the shard it restored. - unreadable.delete(bookCode); + return { bookCode, json, changed: written.get(bookCode) !== json }; }), ); + await perfTimeAsync('saveDraft:write', () => + settleAll( + shards.map(async ({ bookCode, json, changed }) => { + if (changed) { + await papi.storage.writeUserData( + token, + draftAnalysisKey(sourceProjectId, bookCode), + json, + ); + } + written.set(bookCode, json); + // This save rewrote the book, so a later wipe must be free to delete the shard it + // restored. + unreadable.delete(bookCode); + }), + ), + ); const envelope: StoredDraft = { ...draft, @@ -1237,26 +1251,30 @@ export async function saveDraft( analysis: emptyAnalysis(), analysisBooks: [...byBook.keys(), ...held], }; - await papi.storage.writeUserData(token, draftKey(sourceProjectId), JSON.stringify(envelope)); + await perfTimeAsync('saveDraft:write', () => + papi.storage.writeUserData(token, draftKey(sourceProjectId), JSON.stringify(envelope)), + ); // A wiped book would otherwise leave its shard orphaned. Deleting only once the envelope has // stopped naming the book keeps a failure here from stranding the manifest on a missing shard. const undeleted: string[] = []; - const deletions = await Promise.allSettled( - wiped.map(async (bookCode) => { - try { - await papi.storage.deleteUserData(token, draftAnalysisKey(sourceProjectId, bookCode)); - } catch (e) { - if (!isNotFound(e)) { - // Kept in the journal so a later save retries the deletion even across a restart. - undeleted.push(bookCode); - throw e; + const deletions = await perfTimeAsync('saveDraft:write', () => + Promise.allSettled( + wiped.map(async (bookCode) => { + try { + await papi.storage.deleteUserData(token, draftAnalysisKey(sourceProjectId, bookCode)); + } catch (e) { + if (!isNotFound(e)) { + // Kept in the journal so a later save retries the deletion even across a restart. + undeleted.push(bookCode); + throw e; + } } - } - // Dropped only once the shard is gone, so a later save in this process retries a failed - // deletion. - written.delete(bookCode); - }), + // Dropped only once the shard is gone, so a later save in this process retries a failed + // deletion. + written.delete(bookCode); + }), + ), ); // With the envelope naming every shard this save added, only a failed deletion is still owed. @@ -1264,7 +1282,9 @@ export async function saveDraft( // next save retries the journal either way. const failed = deletions.find((outcome) => outcome.status === 'rejected'); try { - await writeShardJournal(token, sourceProjectId, { adding: [], removing: undeleted }); + await perfTimeAsync('saveDraft:write', () => + writeShardJournal(token, sourceProjectId, { adding: [], removing: undeleted }), + ); } catch (e) { if (!failed) throw e; logger.warn(`Interlinearizer: could not update the shard journal for ${sourceProjectId}:`, e); diff --git a/src/services/storageKeys.ts b/src/services/storageKeys.ts new file mode 100644 index 000000000..1b9433a0b --- /dev/null +++ b/src/services/storageKeys.ts @@ -0,0 +1,19 @@ +/** Returns the storage key for a project by ID. */ +export function projectKey(id: string): string { + return `project:${id}`; +} + +/** Returns the storage key for a source project's draft. */ +export function draftKey(sourceProjectId: string): string { + return `draft:${sourceProjectId}`; +} + +/** Returns the storage key holding one book's slice of a draft's analysis. */ +export function draftAnalysisKey(sourceProjectId: string, bookCode: string): string { + return `draft:${sourceProjectId}:analysis:${bookCode}`; +} + +/** Returns the storage key naming the shards an interrupted save of a draft may have stranded. */ +export function draftJournalKey(sourceProjectId: string): string { + return `draft:${sourceProjectId}:shards`; +} diff --git a/src/store/index.ts b/src/store/index.ts index cb3b76277..31d08ab38 100644 --- a/src/store/index.ts +++ b/src/store/index.ts @@ -1,6 +1,20 @@ -import { configureStore } from '@reduxjs/toolkit'; +import { configureStore, type Middleware } from '@reduxjs/toolkit'; +import { perfMark, perfMarksEnabled } from '../utils/perf-marks'; import analysisReducer, { type AnalysisState } from './analysisSlice'; +/** Marks when each dispatch that changes the analysis began, so the render it causes can be timed. */ +const markDispatches: Middleware = + ({ getState }) => + (next) => + (action) => { + if (!perfMarksEnabled()) return next(action); + const before = getState().analysis.analysis; + const startTime = performance.now(); + const result = next(action); + if (getState().analysis.analysis !== before) perfMark('dispatch', undefined, startTime); + return result; + }; + /** * Creates a Redux store scoped to a single analysis provider instance, optionally seeded from that * provider's props. Keeping the store local rather than global means each WebView, or nested @@ -10,6 +24,7 @@ export function createAnalysisStore(preloadedState?: { analysis: AnalysisState } return configureStore({ reducer: { analysis: analysisReducer }, preloadedState, + middleware: (getDefaultMiddleware) => getDefaultMiddleware().concat(markDispatches), }); } diff --git a/src/types/interlinearizer.d.ts b/src/types/interlinearizer.d.ts index b0255dae0..e148034a8 100644 --- a/src/types/interlinearizer.d.ts +++ b/src/types/interlinearizer.d.ts @@ -234,6 +234,20 @@ declare module 'papi-shared-types' { */ 'interlinearizer.saveDraft': (sourceProjectId: string, draftJson: string) => Promise; + /** + * Turns the extension host's timing entries on or off, discarding any it holds. Off until + * turned on. + */ + 'interlinearizer.setPerfMarks': (enabled: boolean) => Promise; + + /** + * Takes the timing entries the extension host recorded since the last reading. + * + * @returns A JSON string of `{ entries, pid }`, `pid` being the host's process id, or + * `undefined` while the host's timing entries are off. + */ + 'interlinearizer.readPerf': () => Promise; + /** * Updates the metadata of an existing interlinearizer project. * diff --git a/src/utils/analysis-book.ts b/src/utils/analysis-book.ts index 15c6dc384..ac7c19d9b 100644 --- a/src/utils/analysis-book.ts +++ b/src/utils/analysis-book.ts @@ -73,6 +73,28 @@ export function splitAnalysisByBook(analysis: TextAnalysis): Map(); + const appendPayloads = (payloads: readonly T[], into: T[]) => { + payloads.forEach((payload) => { + if (seenPayloadIds.has(payload.id)) return; + seenPayloadIds.add(payload.id); + into.push(payload); + }); + }; + partitions.forEach((partition) => { + merged.tokenAnalysisLinks.push(...partition.tokenAnalysisLinks); + merged.segmentAnalysisLinks.push(...partition.segmentAnalysisLinks); + merged.phraseAnalysisLinks.push(...partition.phraseAnalysisLinks); + appendPayloads(partition.tokenAnalyses, merged.tokenAnalyses); + appendPayloads(partition.segmentAnalyses, merged.segmentAnalyses); + appendPayloads(partition.phraseAnalyses, merged.phraseAnalyses); + }); + return merged; +} + /** Appends the payload each link resolves to, once per distinct id; unresolved links are skipped. */ function collectPayloads( links: readonly { analysisId: string }[], diff --git a/src/utils/perf-marks.ts b/src/utils/perf-marks.ts new file mode 100644 index 000000000..bab6860ca --- /dev/null +++ b/src/utils/perf-marks.ts @@ -0,0 +1,131 @@ +/** + * Storage key that turns timing entries on when set to `'true'`; absent, every function here is a + * no-op. + */ +export const PERF_MARKS_STORAGE_KEY = 'interlinearizer.perfMarks'; + +/** Prefix of every entry this extension puts on the performance timeline. */ +export const PERF_ENTRY_PREFIX = 'ilz:'; + +let enabled: boolean | undefined; + +/** Whether this window records timing entries, decided once per window. */ +export function perfMarksEnabled(): boolean { + if (enabled === undefined) { + try { + enabled = globalThis.localStorage?.getItem(PERF_MARKS_STORAGE_KEY) === 'true'; + } catch { + // A frame denied storage has no way to turn them on. + enabled = false; + } + } + return enabled; +} + +/** Turns timing entries on or off for this realm, overriding the storage key. */ +export function setPerfMarksEnabled(on: boolean): void { + enabled = on; +} + +/** A recorded duration, named without {@link PERF_ENTRY_PREFIX}. */ +export interface PerfEntry { + name: string; + duration: number; + detail: unknown; +} + +/** + * Returns every duration this extension has recorded and removes its entries from the timeline, + * leaving entries other code shares the timeline with. + */ +export function takePerfEntries(): PerfEntry[] { + const ours = (type: string) => + performance.getEntriesByType(type).filter((entry) => entry.name.startsWith(PERF_ENTRY_PREFIX)); + const measures = ours('measure'); + new Set(measures.map((entry) => entry.name)).forEach((name) => performance.clearMeasures(name)); + new Set(ours('mark').map((entry) => entry.name)).forEach((name) => performance.clearMarks(name)); + return measures.map((entry) => ({ + name: entry.name.slice(PERF_ENTRY_PREFIX.length), + duration: entry.duration, + detail: 'detail' in entry ? entry.detail : undefined, + })); +} + +/** Records a point on the timeline, at `startTime` when given, that a later measure can time from. */ +export function perfMark(name: string, detail?: unknown, startTime?: number): void { + if (perfMarksEnabled()) performance.mark(PERF_ENTRY_PREFIX + name, { detail, startTime }); +} + +/** + * Records the time since the latest `startMark` as `name`, carrying that mark's detail. Records + * nothing when no such mark was made. + */ +export function perfMeasure(name: string, startMark: string): void { + if (!perfMarksEnabled()) return; + const start = performance.getEntriesByName(PERF_ENTRY_PREFIX + startMark, 'mark').at(-1); + if (!start) return; + performance.measure(PERF_ENTRY_PREFIX + name, { + start: start.startTime, + detail: 'detail' in start ? start.detail : undefined, + }); +} + +/** + * Records the time since the earliest pending `startMark` as `name`, consuming every pending one. + * Records nothing when none is pending. + */ +export function perfMeasureFromFirst(name: string, startMark: string): void { + if (!perfMarksEnabled()) return; + const start = performance.getEntriesByName(PERF_ENTRY_PREFIX + startMark, 'mark')[0]; + if (!start) return; + performance.measure(PERF_ENTRY_PREFIX + name, { start: start.startTime }); + performance.clearMarks(PERF_ENTRY_PREFIX + startMark); +} + +/** Runs `work`, recording how long it took as `name`. */ +export function perfTime(name: string, work: () => T, detail?: unknown): T { + if (!perfMarksEnabled()) return work(); + const start = performance.now(); + try { + return work(); + } finally { + performance.measure(PERF_ENTRY_PREFIX + name, { start, detail }); + } +} + +/** Runs `work`, recording how long it took to settle as `name`, its synchronous start included. */ +export function perfTimeAsync( + name: string, + work: () => Promise, + detail?: unknown, +): Promise { + if (!perfMarksEnabled()) return work(); + const start = performance.now(); + return work().finally(() => performance.measure(PERF_ENTRY_PREFIX + name, { start, detail })); +} + +/** + * Runs `work`, recording as `name` how long it took to settle less the `nested` measures recorded + * within it, so work that interleaves with the timed work is not counted twice. + */ +export function perfTimeAsyncExcluding( + name: string, + nested: string, + work: () => Promise, +): Promise { + if (!perfMarksEnabled()) return work(); + const start = performance.now(); + return work().finally(() => { + const end = performance.now(); + const overlapped = performance + .getEntriesByName(PERF_ENTRY_PREFIX + nested, 'measure') + .filter((entry) => entry.startTime >= start && entry.startTime + entry.duration <= end) + .reduce((total, entry) => total + entry.duration, 0); + performance.measure(PERF_ENTRY_PREFIX + name, { start, duration: end - start - overlapped }); + }); +} + +/** Settles as `pending` does, once it has recorded how long `pending` took to settle as `name`. */ +export function perfTrack(name: string, pending: Promise, detail?: unknown): Promise { + return perfTimeAsync(name, () => pending, detail); +} diff --git a/src/utils/reanchor-draft.ts b/src/utils/reanchor-draft.ts index b1cbab251..b4a90290a 100644 --- a/src/utils/reanchor-draft.ts +++ b/src/utils/reanchor-draft.ts @@ -1,6 +1,7 @@ import type { Book } from 'interlinearizer'; import type { DraftContent } from '../hooks/useDraftProject'; import { resegmentBook } from '../parsers/papi/resegmentBook'; +import { perfTime } from './perf-marks'; import { reanchorAnalysisToBook } from './reanchor-analysis'; import { reanchorSegmentation } from './segmentation'; import type { BookPass } from './undo-history'; @@ -9,14 +10,17 @@ import type { BookPass } from './undo-history'; export function reanchorDraftToBook(verseBook: Book): BookPass { return (content) => { const segmentation = reanchorSegmentation(verseBook, content.segmentation); - return { - analysis: reanchorAnalysisToBook( - content.analysis, - resegmentBook(verseBook, segmentation), - new Date().toISOString(), - content.segmentation?.addedStarts, - ), - segmentation, - }; + const analysis = perfTime( + 'reanchor', + () => + reanchorAnalysisToBook( + content.analysis, + resegmentBook(verseBook, segmentation), + new Date().toISOString(), + content.segmentation?.addedStarts, + ), + { book: verseBook.bookRef }, + ); + return { analysis, segmentation }; }; } diff --git a/tsconfig.lint.json b/tsconfig.lint.json index d20496cb3..f6a6a2542 100644 --- a/tsconfig.lint.json +++ b/tsconfig.lint.json @@ -3,5 +3,5 @@ "compilerOptions": { "allowJs": true }, - "include": [".*.js", "*.js", "*.ts", "e2e-tests", "lib", "scripts", "src", "webpack"] + "include": [".*.js", "*.js", "*.ts", "e2e-tests", "lib", "perf", "scripts", "src", "webpack"] }