diff --git a/README.md b/README.md index b45f10a7..827b4657 100644 --- a/README.md +++ b/README.md @@ -757,6 +757,30 @@ processes the queued writes. Note that you cannot mix the queued mode with the non-queued mode. If there are any writes queued, a non-stale read or non-async write will throw an error. +The `example/` app has a **Benchmark** page that allows you to compare the +performance of the queued mode with non-queued mode. See +[`example/convex/bench.ts`](./example/convex/bench.ts). + +#### Inspecting the queue + +You can check how much work is still queued, and whether the Batch Worker is +running. + +```ts +const stats = await ctx.runQuery(components.aggregate.inspect.queueStats, { + limit: 128, + includeWorker: true, +}); +``` + +It returns the number of queued `rows` and the `operations` and `bytes` they +hold, the oldest and newest commit timestamps it saw, and the Batch Worker's +state (`"idle"`, `"running"`, `"stopped"`, or `null` if it has never been +pinged). The scan is bounded: it reads up to `limit` rows (default 128, +max 1024) and sets `truncated` when there are more, so the counts are lower +bounds on a deep queue. Pass `includeWorker: false` to skip the worker's state +and save a nested query. + #### Dead-lettered writes If a queued write can't be applied (for example, a `delete` for a key that isn't diff --git a/example/convex/_generated/api.d.ts b/example/convex/_generated/api.d.ts index 37538736..1926c905 100644 --- a/example/convex/_generated/api.d.ts +++ b/example/convex/_generated/api.d.ts @@ -8,12 +8,15 @@ * @module */ +import type * as bench from "../bench.js"; import type * as btree from "../btree.js"; import type * as crons from "../crons.js"; import type * as leaderboard from "../leaderboard.js"; import type * as photos from "../photos.js"; import type * as shuffle from "../shuffle.js"; import type * as stats from "../stats.js"; +import type * as utils_benchMath from "../utils/benchMath.js"; +import type * as utils_benchTypes from "../utils/benchTypes.js"; import type * as utils_resetStatus from "../utils/resetStatus.js"; import type { @@ -23,12 +26,15 @@ import type { } from "convex/server"; declare const fullApi: ApiFromModules<{ + bench: typeof bench; btree: typeof btree; crons: typeof crons; leaderboard: typeof leaderboard; photos: typeof photos; shuffle: typeof shuffle; stats: typeof stats; + "utils/benchMath": typeof utils_benchMath; + "utils/benchTypes": typeof utils_benchTypes; "utils/resetStatus": typeof utils_resetStatus; }>; @@ -65,5 +71,6 @@ export declare const components: { photos: import("@convex-dev/aggregate/_generated/component.js").ComponentApi<"photos">; stats: import("@convex-dev/aggregate/_generated/component.js").ComponentApi<"stats">; btreeAggregate: import("@convex-dev/aggregate/_generated/component.js").ComponentApi<"btreeAggregate">; + benchAggregate: import("@convex-dev/aggregate/_generated/component.js").ComponentApi<"benchAggregate">; migrations: import("@convex-dev/migrations/_generated/component.js").ComponentApi<"migrations">; }; diff --git a/example/convex/bench.test.ts b/example/convex/bench.test.ts new file mode 100644 index 00000000..f578394b --- /dev/null +++ b/example/convex/bench.test.ts @@ -0,0 +1,670 @@ +/// + +import { convexTest } from "convex-test"; +import { afterEach, beforeEach, describe, expect, test, vi } from "vitest"; +import { api, components, internal } from "./_generated/api"; +import { scheduleSlot } from "./bench"; +import schema from "./schema"; +import { register } from "@convex-dev/aggregate/test"; +import type { BenchConfig } from "./utils/benchTypes"; + +const modules = import.meta.glob("./**/*.ts"); + +const eagerConfig: BenchConfig = { + mode: "eager", + scenario: "hot", + totalOps: 100, + opsPerMutation: 10, + fanOut: 5, + shards: 1, + timeoutMs: 60_000, +}; + +describe("bench", () => { + function setupTest() { + const t = convexTest(schema, modules); + register(t, "benchAggregate"); + return t; + } + + let t: ReturnType; + + /** What the aggregate itself holds, read eagerly. Throws while ops are queued. */ + async function aggregateCount(namespace = "hot"): Promise { + const { count } = await t.query( + components.benchAggregate.btree.aggregateBetween, + { namespace }, + ); + return count; + } + + beforeEach(() => { + vi.useFakeTimers(); + t = setupTest(); + }); + + afterEach(async () => { + await t.finishAllScheduledFunctions(vi.runAllTimers); + vi.useRealTimers(); + }); + + test("an eager run completes and every op lands in the aggregate", async () => { + const started = await t.mutation(api.bench.startRun, { + config: eagerConfig, + label: "eager-smoke", + }); + expect(started.ok).toBe(true); + if (!started.ok) return; + + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const run = await t.query(api.bench.getRun, { runId: started.runId }); + expect(run?.status).toBe("done"); + expect(run?.results?.ops.committed).toBe(100); + expect(run?.results?.jobs.failed).toBe(0); + + // The aggregate itself agrees, read eagerly (no queue to block it). + expect(await aggregateCount()).toBe(100); + }); + + test("an eager run is consistent the moment its last write commits", async () => { + // `watch` notices the enqueue finishing on one tick and only stamps the end + // of the drain on the next, so an eager run's recorded end trailed its last + // commit by a tick with nothing happening in between — a flat tail on the + // consistency curve after it had reached zero, and a padded + // time-to-consistency. An eager run has no drain to wait for. + const started = await t.mutation(api.bench.startRun, { + config: eagerConfig, + }); + if (!started.ok) throw new Error("expected the run to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const run = await t.query(api.bench.getRun, { runId: started.runId }); + expect(run?.enqueueEndedAtMs).toBeDefined(); + expect(run?.drainEndedAtMs).toBe(run?.enqueueEndedAtMs); + expect(run?.results?.drain.timeToDrainMs).toBe(0); + expect(run?.results?.drain.resolutionMs).toBe(0); + // The curve closes exactly where the run ends. + const start = run?.enqueueStartedAtMs ?? run?.createdAtMs ?? 0; + expect(run?.results?.consistency?.at(-1)).toEqual({ + elapsedMs: (run?.drainEndedAtMs ?? 0) - start, + outstanding: 0, + queued: 0, + }); + }); + + test("fan-out 1 runs the mutations one after another", async () => { + // Lanes are what bound in-flight work. Without that bound a fan-out-1 run + // reported concurrency.achieved of 114. + const started = await t.mutation(api.bench.startRun, { + config: { ...eagerConfig, fanOut: 1 }, + }); + if (!started.ok) throw new Error("expected the run to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const { lanes, jobs } = await t.run(async (ctx) => ({ + lanes: await ctx.db.query("benchLanes").collect(), + jobs: await ctx.db.query("benchJobs").collect(), + })); + // One lane, and every job in the run went through it. + expect(lanes).toHaveLength(1); + expect(lanes[0].jobsSpawned).toBe(jobs.length); + expect(jobs).toHaveLength(10); // 100 ops / 10 per mutation + + const run = await t.query(api.bench.getRun, { runId: started.runId }); + expect(run?.results?.ops.committed).toBe(100); + + // Everything the scheduler's own clock feeds is degenerate under + // convex-test, which doesn't implement `ctx.meta.getRequestMetadata()`: job + // rows get no `scheduledFnId`, so no job contributes an interval or a + // latency sample. Asserted rather than implied, so implementing the syscall + // fails here loudly instead of quietly changing what these numbers mean. + expect(run?.results?.concurrency.achieved).toBe(0); + expect(run?.results?.latency.jobLatency.count).toBe(0); + expect(run?.results?.latency.jobService.count).toBe(0); + expect(run?.results?.latency.jobQueue.count).toBe(0); + expect(run?.results?.jobs.failed).toBe(0); + }); + + test("deals jobs across one lane per unit of fan-out", async () => { + const started = await t.mutation(api.bench.startRun, { + config: { ...eagerConfig, fanOut: 3 }, + }); + if (!started.ok) throw new Error("expected the run to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const { lanes, jobs } = await t.run(async (ctx) => ({ + lanes: await ctx.db.query("benchLanes").collect(), + jobs: await ctx.db.query("benchJobs").collect(), + })); + expect(lanes).toHaveLength(3); + // Lane L owns seqs L, L+3, L+6, … — the lanes partition the work, so no seq + // runs twice and none is dropped. 10 jobs over 3 lanes is 4/3/3. + expect(lanes.map((l) => l.jobsSpawned).sort()).toEqual([3, 3, 4]); + expect(lanes.reduce((n, l) => n + l.jobsSpawned, 0)).toBe(jobs.length); + expect(new Set(jobs.map((j) => j.seq)).size).toBe(jobs.length); + + const run = await t.query(api.bench.getRun, { runId: started.runId }); + expect(run?.results?.ops.committed).toBe(100); + }); + + test("a run that loses ops reports it instead of reading as done", async () => { + // A job whose transaction can't commit — an eager job at 1000 ops/txn reads + // past the 16 MiB limit walking the B-tree — commits no row and no ops. The + // run used to finish "done" with a fast time and a low op count, and the + // consistency curve was force-closed at zero, drawing a cliff at the end of + // a curve that had been sitting at the unlanded total the whole run. + const started = await t.mutation(api.bench.startRun, { + config: { ...eagerConfig, fanOut: 2 }, + }); + if (!started.ok) throw new Error("expected the run to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + // Drop one job's ops to simulate a job that committed nothing, then + // re-finalize over the same rows. The samples counted that job as it landed, + // so they lose it too — a job that never committed never shows up in one. + // Only the arithmetic is under test here; `finalize` treats an + // already-finished run no differently. + await t.run(async (ctx) => { + const job = await ctx.db.query("benchJobs").first(); + if (!job) throw new Error("expected a job row"); + await ctx.db.patch("benchJobs", job._id, { ops: 0 }); + for (const sample of await ctx.db.query("benchQueueSamples").collect()) { + if (sample.opsCommitted >= job.ops) { + await ctx.db.patch("benchQueueSamples", sample._id, { + opsCommitted: sample.opsCommitted - job.ops, + }); + } + } + }); + await t.mutation(internal.bench.finalize, { runId: started.runId }); + + const run = await t.query(api.bench.getRun, { runId: started.runId }); + expect(run?.status).toBe("failed"); + expect(run?.results?.ops.committed).toBe(90); + expect(run?.results?.ops.failed).toBe(10); + expect(run?.errors?.[0]).toContain("10 of 100 ops never landed"); + // The curve stops where the run stopped rather than being closed at zero. + expect(run?.results?.consistency?.at(-1)?.outstanding).toBe(10); + }); + + test("a finished run stores a consistency curve that reaches zero", async () => { + // Fan-out 1 is the case that exposed the watch loop starving: every job + // insert lands in the tick's read set, so a tick that read the run's jobs + // directly never committed until the writes stopped, and the curve came out + // flat at the total for the whole run. + const started = await t.mutation(api.bench.startRun, { + config: { ...eagerConfig, fanOut: 1 }, + }); + if (!started.ok) throw new Error("expected the run to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const run = await t.query(api.bench.getRun, { runId: started.runId }); + const curve = run?.results?.consistency; + expect(curve?.length).toBeGreaterThan(0); + if (!curve) return; + expect(curve.at(-1)?.outstanding).toBe(0); + // The final point is appended by `finalize` whenever the run reached + // consistency, so a curve that sat flat at the total would still end at + // zero. Some sampled point has to show the decline in progress. + expect( + curve + .slice(0, -1) + .some((p) => p.outstanding > 0 && p.outstanding < eagerConfig.totalOps), + ).toBe(true); + // Committed ops only accumulate and an eager run queues nothing, so the + // curve is monotonic and time runs forwards. + for (let i = 1; i < curve.length; i++) { + expect(curve[i].outstanding).toBeLessThanOrEqual( + curve[i - 1].outstanding, + ); + expect(curve[i].elapsedMs).toBeGreaterThanOrEqual(curve[i - 1].elapsedMs); + } + }); + + test("an eager run records clock-free per-op work metrics", async () => { + const started = await t.mutation(api.bench.startRun, { + config: eagerConfig, + }); + if (!started.ok) throw new Error("expected the run to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const run = await t.query(api.bench.getRun, { runId: started.runId }); + // Each eager insert walks the btree, so it must write more than nothing. + expect(run?.results?.work.documentsWrittenPerOp).toBeGreaterThan(0); + expect(run?.results?.work.documentsReadPerOp).toBeGreaterThan(0); + }); + + test("spreads writes across namespaces in the sharded scenario", async () => { + const started = await t.mutation(api.bench.startRun, { + config: { ...eagerConfig, scenario: "sharded", shards: 4 }, + }); + if (!started.ok) throw new Error("expected the run to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + // Job `seq` writes to `shard-${seq % 4}`, so the 10 jobs of 10 ops land + // 30/30/20/20 — every namespace used, and none of them holding everything. + const counts = await Promise.all( + [0, 1, 2, 3].map((i) => aggregateCount(`shard-${i}`)), + ); + expect(counts).toEqual([30, 30, 20, 20]); + + const run = await t.query(api.bench.getRun, { runId: started.runId }); + expect(run?.results?.ops.committed).toBe(100); + }); + + test("the bursty scenario holds each burst back to its slot", async () => { + const started = await t.mutation(api.bench.startRun, { + config: { + ...eagerConfig, + scenario: "bursty", + bursts: 4, + burstIntervalMs: 5_000, + fanOut: 5, + }, + }); + if (!started.ok) throw new Error("expected the run to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const { run, jobs } = await t.run(async (ctx) => ({ + run: await ctx.db.get("benchRuns", started.runId), + jobs: await ctx.db.query("benchJobs").collect(), + })); + const t0 = run!.enqueueStartedAtMs!; + // 10 write jobs over 4 bursts is 3 per burst, and burst b isn't due until + // b · 5s — including for the lanes that skip a burst entirely, there being + // fewer jobs in a burst than there are lanes. + for (const job of jobs) { + const burst = Math.min(Math.floor(job.seq / 3), 3); + expect(job.startedAtMs - t0).toBeGreaterThanOrEqual(burst * 5_000); + } + // The run really did span the schedule rather than running the whole thing + // at once — without this the loop above would pass on a frozen clock. + const spanMs = Math.max(...jobs.map((j) => j.startedAtMs)) - t0; + expect(spanMs).toBeGreaterThanOrEqual(15_000); + expect(run!.results?.ops.committed).toBe(100); + expect(run!.results?.jobs.failed).toBe(0); + }); + + test("refuses a second run while one is in progress", async () => { + const first = await t.mutation(api.bench.startRun, { config: eagerConfig }); + expect(first.ok).toBe(true); + const second = await t.mutation(api.bench.startRun, { + config: eagerConfig, + }); + expect(second).toMatchObject({ ok: false, reason: "run_in_progress" }); + }); + + test("rejects an invalid config before creating a run", async () => { + const result = await t.mutation(api.bench.startRun, { + config: { ...eagerConfig, scenario: "hot", shards: 8 }, + }); + expect(result).toMatchObject({ ok: false, reason: "invalid_config" }); + expect(await t.query(api.bench.listRuns, {})).toHaveLength(0); + }); + + test("canStart reports a clean slate", async () => { + const status = await t.query(api.bench.canStart); + expect(status.canStart).toBe(true); + expect(status.queue.rows).toBe(0); + }); + + test("resetAll clears runs and the aggregate", async () => { + const started = await t.mutation(api.bench.startRun, { + config: eagerConfig, + }); + if (!started.ok) throw new Error("expected the run to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + expect(await t.mutation(internal.bench.resetAll)).toBe("all_reset"); + expect(await t.query(api.bench.listRuns, {})).toHaveLength(0); + expect(await aggregateCount()).toBe(0); + }); + + test("resetAll reports partial_reset while rows are left to delete", async () => { + // `resetAll` deletes at most 1000 rows per table per call and the cron chain + // re-runs it on "partial_reset", so a table at exactly the batch size has to + // stop and report rather than claim the deployment is clean. + await t.run(async (ctx) => { + const runId = await ctx.db.insert("benchRuns", { + status: "done", + config: eagerConfig, + createdAtMs: 0, + progress: { + opsCommitted: 0, + lastQueueRows: 0, + lastQueueOperations: 0, + lastQueueChangeAtMs: 0, + }, + }); + for (let i = 0; i < 1000; i++) { + await ctx.db.insert("benchQueueSamples", { + runId, + atMs: i, + rows: 0, + operations: 0, + opsCommitted: 0, + bytes: 0, + truncated: false, + }); + } + }); + + expect(await t.mutation(internal.bench.resetAll)).toBe("partial_reset"); + // The samples went, and the run it stopped short of is still there. + const left = await t.run(async (ctx) => ({ + samples: (await ctx.db.query("benchQueueSamples").collect()).length, + runs: (await ctx.db.query("benchRuns").collect()).length, + })); + expect(left).toEqual({ samples: 0, runs: 1 }); + // The next pass has less than a batch to do and finishes the job. + expect(await t.mutation(internal.bench.resetAll)).toBe("all_reset"); + expect(await t.query(api.bench.listRuns, {})).toHaveLength(0); + }); + + test("resetAll reports partial_reset while ops are still queued", async () => { + // `clearAll` throws PENDING_OPERATIONS while the queue is non-empty, so the + // tables are emptied but the aggregate is left for a later pass. + await t.mutation(components.benchAggregate.public.enqueue, { + operation: { type: "insert", key: 1, value: "a", namespace: "hot" }, + }); + + expect(await t.mutation(internal.bench.resetAll)).toBe("partial_reset"); + expect(await t.query(api.bench.listRuns, {})).toHaveLength(0); + + // Once the worker has drained, the same call gets all the way through. + await t.finishAllScheduledFunctions(vi.runAllTimers); + expect(await t.mutation(internal.bench.resetAll)).toBe("all_reset"); + expect(await aggregateCount()).toBe(0); + }); + + test("cancelSuite cancels a pending run and finalize keeps it canceled", async () => { + const started = await t.mutation(api.bench.startSuite, { + config: eagerConfig, + repeats: 2, + }); + if (!started.ok) throw new Error("expected the suite to start"); + + // The run hasn't been prepared yet, so it isn't "enqueuing" and the cancel + // is terminal: status "canceled", with finalize scheduled. + await t.mutation(api.bench.cancelSuite, { suiteId: started.suiteId }); + const [canceled] = await t.query(api.bench.listRuns, {}); + expect(canceled.status).toBe("canceled"); + + await t.finishAllScheduledFunctions(vi.runAllTimers); + const [finalized] = await t.query(api.bench.listRuns, {}); + // Still canceled rather than "failed", and finalize suppresses the "ops + // never landed" complaint: a cancelled run losing its ops isn't a defect. + expect(finalized.status).toBe("canceled"); + expect(finalized.errors).toBeUndefined(); + expect(finalized.results?.ops.committed).toBe(0); + expect(finalized.results?.ops.failed).toBe(100); + }); + + test("cancelSuite leaves a draining queued run to finish its tail", async () => { + const started = await t.mutation(api.bench.startSuite, { + config: { ...eagerConfig, timeoutMs: 60 * 60 * 1000 }, + repeats: 2, + }); + if (!started.ok) throw new Error("expected the suite to start"); + // A suite's first run is the queued one. Drive it into "enqueuing" so the + // cancel hits the branch that can't just stop: enqueued ops can't be + // un-enqueued, so the run goes to "draining" and finalizes only once the + // watcher sees the queue empty. + const [pending] = await t.query(api.bench.listRuns, {}); + expect(pending.config.mode).toBe("async"); + await t.mutation(internal.bench.prepare, { runId: pending._id }); + + await t.mutation(api.bench.cancelSuite, { suiteId: started.suiteId }); + const [draining] = await t.query(api.bench.listRuns, {}); + expect(draining.status).toBe("draining"); + // No finalize was scheduled, so nothing has been written yet. + expect(draining.results).toBeUndefined(); + + await t.finishAllScheduledFunctions(vi.runAllTimers); + const [done] = await t.query(api.bench.listRuns, {}); + expect(done.results).toBeDefined(); + // The suite stays canceled and never starts its remaining runs. + const suites = await t.query(api.bench.listSuites, {}); + expect(suites[0]).toMatchObject({ status: "canceled" }); + expect(await t.query(api.bench.listRuns, {})).toHaveLength(1); + }); + + describe("suites", () => { + test("scheduleSlot alternates the two sides across repeats", () => { + // Q,E,Q,E,Q,E — not Q,Q,Q,E,E,E. Drift over the suite's lifetime then + // lands on both sides equally. + expect([0, 1, 2, 3, 4, 5].map(scheduleSlot)).toEqual([ + { mode: "async", repeatIndex: 0 }, + { mode: "eager", repeatIndex: 0 }, + { mode: "async", repeatIndex: 1 }, + { mode: "eager", repeatIndex: 1 }, + { mode: "async", repeatIndex: 2 }, + { mode: "eager", repeatIndex: 2 }, + ]); + }); + + test("startSuite rejects a repeat count outside the allowed range", async () => { + for (const repeats of [0, -1, 2.5, 11]) { + const result = await t.mutation(api.bench.startSuite, { + config: eagerConfig, + repeats, + }); + expect(result.ok).toBe(false); + if (result.ok) throw new Error("expected a rejection"); + expect(result.reason).toBe("invalid_config"); + } + expect(await t.query(api.bench.listSuites, {})).toHaveLength(0); + }); + + test("startSuite starts exactly one run up front", async () => { + const started = await t.mutation(api.bench.startSuite, { + config: eagerConfig, + repeats: 2, + }); + if (!started.ok) throw new Error("expected the suite to start"); + + const suites = await t.query(api.bench.listSuites, {}); + expect(suites).toHaveLength(1); + // Cursor advanced past the run it just started, and no further. + expect(suites[0]).toMatchObject({ + cursor: 1, + repeats: 2, + status: "running", + }); + const runs = await t.query(api.bench.listRuns, {}); + expect(runs).toHaveLength(1); + // Queued goes first, so the eager side never measures a backlog the + // queued side left behind. + expect(runs[0]).toMatchObject({ + suiteId: started.suiteId, + repeatIndex: 0, + }); + expect(runs[0].config.mode).toBe("async"); + }); + + test("a suite runs every repeat and then marks itself done", async () => { + const started = await t.mutation(api.bench.startSuite, { + // The queued side waits on the batch worker, whose monitor schedules + // itself minutes out, so give the watchdog room. + config: { ...eagerConfig, timeoutMs: 60 * 60 * 1000 }, + repeats: 3, + }); + if (!started.ok) throw new Error("expected the suite to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + // Both sides x 3 repeats. + const suites = await t.query(api.bench.listSuites, {}); + expect(suites[0]).toMatchObject({ status: "done", cursor: 6 }); + const runs = await t.query(api.bench.listRuns, {}); + expect(runs).toHaveLength(6); + expect(runs.every((r) => r.suiteId === started.suiteId)).toBe(true); + expect( + runs.map((r) => r.repeatIndex).sort((a, b) => (a ?? 0) - (b ?? 0)), + ).toEqual([0, 0, 1, 1, 2, 2]); + // Every run produced results, so the dashboard has 3 samples per side. + expect(runs.every((r) => r.results !== undefined)).toBe(true); + }); + + test("the dashboard's per-suite reads: a count and one suite's runs", async () => { + const started = await t.mutation(api.bench.startSuite, { + config: { ...eagerConfig, timeoutMs: 60 * 60 * 1000 }, + repeats: 2, + }); + if (!started.ok) throw new Error("expected the suite to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + // The picker's done/total comes off this count, so the fat run documents + // never have to cross the wire for a suite that isn't on screen. + const [suite] = await t.query(api.bench.listSuites, {}); + expect(suite.doneRuns).toBe(4); + + const runs = await t.query(api.bench.listSuiteRuns, { + suiteId: started.suiteId, + }); + expect(runs.map((r) => [r.config.mode, r.repeatIndex])).toEqual([ + ["async", 0], + ["eager", 0], + ["async", 1], + ["eager", 1], + ]); + expect(await t.query(api.bench.latestRunId)).toBe(runs[3]._id); + }); + + test("startSuite refuses while another run is in flight", async () => { + const first = await t.mutation(api.bench.startRun, { + config: eagerConfig, + }); + if (!first.ok) throw new Error("expected the run to start"); + const second = await t.mutation(api.bench.startSuite, { + config: eagerConfig, + repeats: 2, + }); + expect(second.ok).toBe(false); + if (second.ok) throw new Error("expected a rejection"); + expect(second.reason).toBe("run_in_progress"); + }); + + test("cancelSuite stops the schedule from advancing", async () => { + const started = await t.mutation(api.bench.startSuite, { + config: eagerConfig, + repeats: 3, + }); + if (!started.ok) throw new Error("expected the suite to start"); + await t.mutation(api.bench.cancelSuite, { suiteId: started.suiteId }); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const suites = await t.query(api.bench.listSuites, {}); + expect(suites[0]).toMatchObject({ status: "canceled" }); + // The first run was already in flight; repeats 2 and 3 never started. + expect(await t.query(api.bench.listRuns, {})).toHaveLength(1); + }); + + test("runs both sides, queued batched and eager plain", async () => { + const started = await t.mutation(api.bench.startSuite, { + config: { ...eagerConfig, timeoutMs: 60 * 60 * 1000 }, + repeats: 2, + }); + if (!started.ok) throw new Error("expected the suite to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const suites = await t.query(api.bench.listSuites, {}); + expect(suites[0]).toMatchObject({ status: "done", cursor: 4 }); + + const runs = await t.query(api.bench.listRuns, {}); + expect(runs).toHaveLength(4); + // Alternating, oldest first. + expect( + [...runs] + .sort((a, b) => a.createdAtMs - b.createdAtMs) + .map((r) => [r.config.mode, r.repeatIndex]), + ).toEqual([ + ["async", 0], + ["eager", 0], + ["async", 1], + ["eager", 1], + ]); + // Queued always batches; eager has no enqueue call to make. + for (const run of runs) { + expect(run.config.writeApi).toBe( + run.config.mode === "async" ? "batch" : undefined, + ); + } + expect(runs.every((r) => r.results !== undefined)).toBe(true); + }); + + test("resetAll clears suites along with their runs", async () => { + const started = await t.mutation(api.bench.startSuite, { + config: eagerConfig, + repeats: 2, + }); + if (!started.ok) throw new Error("expected the suite to start"); + await t.finishAllScheduledFunctions(vi.runAllTimers); + + expect(await t.mutation(internal.bench.resetAll)).toBe("all_reset"); + expect(await t.query(api.bench.listSuites, {})).toHaveLength(0); + expect(await t.query(api.bench.listRuns, {})).toHaveLength(0); + }); + }); + + test("an async run enqueues, drains, and reaches the same count", async () => { + const started = await t.mutation(api.bench.startRun, { + config: { + ...eagerConfig, + mode: "async", + // The queued path waits on the batch worker, whose monitor schedules + // itself minutes out. `runAllTimers` jumps virtual time to the last + // timer, so a realistic `timeoutMs` would trip the run's own watchdog + // before it could finish. + timeoutMs: 60 * 60 * 1000, + }, + label: "async-smoke", + }); + expect(started.ok).toBe(true); + if (!started.ok) return; + + // Drains the run's jobs and the aggregate's batch worker alike. + await t.finishAllScheduledFunctions(vi.runAllTimers); + + const run = await t.query(api.bench.getRun, { runId: started.runId }); + expect(run?.status).toBe("done"); + expect(run?.results?.ops.committed).toBe(100); + expect(run?.results?.jobs.failed).toBe(0); + + // The queue is empty once the worker catches up, so an eager read goes + // through and sees every operation. + expect(await aggregateCount()).toBe(100); + }); + + test("a batched queued run lands the same ops for less work per op", async () => { + // `enqueueBatch` hands the component one call per transaction instead of + // `opsPerMutation` of them, and each of those per-op calls re-reads and + // rewrites the row it is appending to. So the batched run must do strictly + // fewer database queries per op — that saving is the reason for the option. + async function runWork(writeApi: "perOp" | "batch") { + const started = await t.mutation(api.bench.startRun, { + config: { + ...eagerConfig, + mode: "async", + writeApi, + timeoutMs: 60 * 60 * 1000, + }, + label: `async-${writeApi}`, + }); + if (!started.ok) throw new Error(`expected the ${writeApi} run to start`); + await t.finishAllScheduledFunctions(vi.runAllTimers); + const run = await t.query(api.bench.getRun, { runId: started.runId }); + expect(run?.status).toBe("done"); + expect(run?.results?.ops.committed).toBe(100); + expect(run?.results?.jobs.failed).toBe(0); + // Same data either way, so the aggregate agrees at the end of each run. + expect(await aggregateCount()).toBe(100); + await t.mutation(internal.bench.resetAll, {}); + return run!.results!.work; + } + + const perOp = await runWork("perOp"); + const batch = await runWork("batch"); + expect(batch.databaseQueriesPerOp).toBeLessThan(perOp.databaseQueriesPerOp); + }); +}); diff --git a/example/convex/bench.ts b/example/convex/bench.ts new file mode 100644 index 00000000..841fa78b --- /dev/null +++ b/example/convex/bench.ts @@ -0,0 +1,1469 @@ +/** + * Benchmark comparing the aggregate's queued ("async") write path against the + * synchronous ("eager") one. + * + * `Date.now()` is frozen for a whole transaction, so no mutation can time + * itself: the run fans out with the scheduler and reads the platform's own + * `_scheduled_functions` timings instead. `getTransactionMetrics()` needs no + * clock at all, which makes documents-and-bytes-per-op the most trustworthy + * number here. + * + * While a queued run is draining, `assertNoPendingOperations` makes every eager + * write, every non-stale read, and even `clear` throw `PENDING_OPERATIONS` on + * this component — hence the dedicated aggregate instance and one run at a time. + */ + +import { DirectAggregate } from "@convex-dev/aggregate"; +import { ConvexError, v } from "convex/values"; +import type { Id } from "./_generated/dataModel"; +import { + internalMutation, + internalQuery, + mutation, + query, + type MutationCtx, + type QueryCtx, +} from "./_generated/server"; +import { components, internal } from "./_generated/api"; +import { resetStatusValidator } from "./utils/resetStatus"; +import { + allShards, + burstDelayMs, + classifyError, + consistencyCurve, + downsample, + histAdd, + histInit, + laneCount, + laneDelayMs, + laneStartDelayMs, + MAX_CURVE_POINTS, + MAX_FAN_OUT, + maxOverlap, + planWriteJob, + summarize, + summarizeError, + totalWriteJobs, + validateConfig, + type Hist, +} from "./utils/benchMath"; +import { + vBenchConfig, + vPendingOperationsStats, + vRunStatus, + vWriteApi, + type BenchConfig, + type BenchMode, + type BenchResults, +} from "./utils/benchTypes"; + +const benchAggregate = new DirectAggregate<{ + Key: number; + Id: string; + Namespace: string; +}>(components.benchAggregate); + +/** The batch worker's default, which `enqueueOperation` doesn't override. */ +const WORKER_MONITOR_LAG_MS = 60_000; + +const SAMPLE_INTERVAL_MS = 250; +const WATCH_INTERVAL_MS = 250; +/** `clear` schedules async node cleanup, so let it settle before writing. */ +const PREPARE_SETTLE_MS = 250; +// Must exceed the worker's monitor lag: a fully idle loop waits for a ping or +// the 60s monitor, so a still queue is not necessarily a stuck one. +const STALL_MS = 2 * WORKER_MONITOR_LAG_MS; +const MAX_TICKS = 20_000; +// Job rows a single pass will read, for `watch` and `finalize` alike. A run with +// more job transactions than this undercounts its committed ops and the watchdog +// ends it on timeoutMs. +const MAX_JOB_ROWS = 8_000; + +/** Upper bound on a suite's repeats, so one suite can't schedule unboundedly. */ +const MAX_REPEATS = 10; +/** The two sides of every comparison, in the order they interleave. */ +const MODES = ["async", "eager"] as const; +/** Run rows one suite can hold, plus slack, as the bound on per-suite reads. */ +const SUITE_RUN_ROWS = MAX_REPEATS * MODES.length + 4; +const SUITE_ADVANCE_RETRY_MS = 1_000; +// Long enough to outlast the worker's monitor lag before giving up on the suite. +const SUITE_ADVANCE_MAX_ATTEMPTS = 120; + +const ACTIVE_STATUSES = [ + "pending", + "preparing", + "enqueuing", + "draining", + "finalizing", +] as const; + +type ScheduledDoc = { + scheduledTime: number; + completedTime?: number; + state: + | { kind: "pending" } + | { kind: "inProgress" } + | { kind: "success" } + | { kind: "failed"; error: string } + | { kind: "canceled" }; +}; + +/** + * Depth of the queued-write backlog. The client deliberately doesn't expose it — + * only something measuring the queue needs it — so the benchmark calls + * `inspect.queueStats` itself. + */ +async function queueStats( + ctx: QueryCtx, + opts: { limit?: number; includeWorker: boolean }, +) { + return await ctx.runQuery(components.benchAggregate.inspect.queueStats, { + limit: opts.limit, + includeWorker: opts.includeWorker, + }); +} + +/** + * The same read from a mutation, off a stale snapshot. That's the only correct + * choice for a poller: a live read would take a read dependency on + * `pendingOperations` and OCC-conflict with the enqueuers it is measuring. + */ +async function staleQueueStats( + ctx: MutationCtx, + opts: { limit?: number; includeWorker: boolean }, +) { + return await ctx.runQuery( + components.benchAggregate.inspect.queueStats, + { limit: opts.limit, includeWorker: opts.includeWorker }, + { useStaleSnapshot: true }, + ); +} + +// ---------------------------------------------------------------- queries + +export const canStart = query({ + args: {}, + returns: v.object({ + canStart: v.boolean(), + reason: v.optional( + v.union(v.literal("run_in_progress"), v.literal("pending_ops")), + ), + activeRunId: v.optional(v.id("benchRuns")), + queue: vPendingOperationsStats, + }), + handler: async (ctx) => { + const queue = await queueStats(ctx, { includeWorker: false }); + const active = await findActiveRun(ctx); + if (active) { + return { + canStart: false, + reason: "run_in_progress" as const, + activeRunId: active._id, + queue, + }; + } + if (queue.rows > 0) { + return { canStart: false, reason: "pending_ops" as const, queue }; + } + return { canStart: true, queue }; + }, +}); + +export const getRun = query({ + args: { runId: v.id("benchRuns") }, + handler: async (ctx, { runId }) => await ctx.db.get("benchRuns", runId), +}); + +export const listRuns = query({ + args: { limit: v.optional(v.number()) }, + handler: async (ctx, { limit }) => + await ctx.db + .query("benchRuns") + .order("desc") + .take(limit ?? 25), +}); + +/** + * The newest run, whichever suite it belongs to — the page's fallback focus when + * nothing is in flight. Only the id: `getRun` fetches the document. + */ +export const latestRunId = query({ + args: {}, + returns: v.union(v.id("benchRuns"), v.null()), + handler: async (ctx) => { + const run = await ctx.db.query("benchRuns").order("desc").first(); + return run?._id ?? null; + }, +}); + +/** The runs of one comparison, oldest first so repeat order reads naturally. */ +export const listSuiteRuns = query({ + args: { suiteId: v.id("benchSuites") }, + handler: async (ctx, { suiteId }) => { + const runs = await ctx.db + .query("benchRuns") + .withIndex("by_suite", (q) => q.eq("suiteId", suiteId)) + .take(SUITE_RUN_ROWS); + return runs.sort((a, b) => a.createdAtMs - b.createdAtMs); + }, +}); + +/** + * Past comparisons, newest first, each with how many of its runs have results. + * + * The count is taken here rather than by shipping the runs to the client: a + * finished run carries a downsampled consistency curve and three histograms with + * their raw buckets, and `watch` patches the active run four times a second, so a + * subscription holding those documents would resend all of them every tick. This + * reads them and returns a number. + */ +export const listSuites = query({ + args: { limit: v.optional(v.number()) }, + handler: async (ctx, { limit }) => { + const suites = await ctx.db + .query("benchSuites") + .order("desc") + .take(limit ?? 10); + return await Promise.all( + suites.map(async (suite) => { + const runs = await ctx.db + .query("benchRuns") + .withIndex("by_suite", (q) => q.eq("suiteId", suite._id)) + .take(SUITE_RUN_ROWS); + return { + ...suite, + doneRuns: runs.filter((run) => run.results !== undefined).length, + }; + }), + ); + }, +}); + +/** + * Operations not yet applied to the aggregate, over time — every run of a + * comparison on one elapsed-time axis. It's the quantity that means the same + * thing in both modes, so the width of a curve is that run's time to + * consistency. All repeats are returned: the family of curves per mode *is* the + * run-to-run spread. + */ +export const getConsistencySeries = query({ + args: { suiteId: v.id("benchSuites") }, + handler: async (ctx, { suiteId }) => { + const suite = await ctx.db.get("benchSuites", suiteId); + if (!suite) return []; + const runs = await ctx.db + .query("benchRuns") + .withIndex("by_suite", (q) => q.eq("suiteId", suiteId)) + .take(SUITE_RUN_ROWS); + + const series = []; + for (const mode of MODES) { + const mine = runs + .filter((r) => r.config.mode === mode) + .sort((a, b) => (a.repeatIndex ?? 0) - (b.repeatIndex ?? 0)); + for (const run of mine) { + const cell = { + mode, + repeatIndex: run.repeatIndex ?? 0, + totalOps: run.config.totalOps, + }; + // A finished run carries the curve `finalize` reconstructed from the + // scheduler's own completion times, which is the accurate one. + if (run.results?.consistency?.length) { + series.push({ ...cell, points: run.results.consistency }); + continue; + } + + // Otherwise build it from the samples as they stand — the in-flight + // path, and the one old runs fall back to. + const startedAt = run.enqueueStartedAtMs ?? run.createdAtMs; + const samples = await ctx.db + .query("benchQueueSamples") + .withIndex("by_run_at", (q) => q.eq("runId", run._id)) + .take(4000); + if (samples.length === 0) continue; + const done = run.status === "done"; + series.push({ + ...cell, + points: downsample( + consistencyCurve({ + totalOps: run.config.totalOps, + startedAtMs: startedAt, + endedAtMs: done + ? (run.drainEndedAtMs ?? run.finishedAtMs) + : undefined, + samples, + }), + MAX_CURVE_POINTS, + ), + }); + } + } + return series; + }, +}); + +// --------------------------------------------------------------- mutations + +export const startRun = mutation({ + args: { config: vBenchConfig, label: v.optional(v.string()) }, + returns: v.union( + v.object({ ok: v.literal(true), runId: v.id("benchRuns") }), + v.object({ + ok: v.literal(false), + reason: v.union( + v.literal("run_in_progress"), + v.literal("pending_ops"), + v.literal("invalid_config"), + ), + detail: v.string(), + }), + ), + handler: async (ctx, { config, label }) => { + const invalid = validateConfig(config); + if (invalid) { + return { + ok: false as const, + reason: "invalid_config" as const, + detail: invalid, + }; + } + const blocked = await startBlocked(ctx); + if (blocked) return blocked; + + const runId = await insertRun(ctx, { config, label }); + return { ok: true as const, runId }; + }, +}); + +/** + * The interleaved schedule a suite walks: queued, eager, queued, eager, so drift + * in the deployment over the suite's lifetime lands on both sides equally rather + * than all on whichever side ran last. + */ +export function scheduleSlot(index: number): { + mode: BenchMode; + repeatIndex: number; +} { + return { + mode: MODES[index % MODES.length], + repeatIndex: Math.floor(index / MODES.length), + }; +} + +/** + * The config one side of the comparison actually runs. Queued always batches, + * because batching is how you would use the queued path — the per-op API re-reads + * and rewrites the row it appends to on every call. + */ +function runConfig(config: BenchConfig, mode: BenchMode): BenchConfig { + return mode === "async" + ? { ...config, mode, writeApi: "batch" } + : { ...config, mode, writeApi: undefined }; +} + +export const startSuite = mutation({ + args: { + config: vBenchConfig, + repeats: v.number(), + }, + returns: v.union( + v.object({ ok: v.literal(true), suiteId: v.id("benchSuites") }), + v.object({ + ok: v.literal(false), + reason: v.union( + v.literal("run_in_progress"), + v.literal("pending_ops"), + v.literal("invalid_config"), + ), + detail: v.string(), + }), + ), + handler: async (ctx, { config, repeats }) => { + const reject = (detail: string) => ({ + ok: false as const, + reason: "invalid_config" as const, + detail, + }); + if (!Number.isInteger(repeats) || repeats < 1 || repeats > MAX_REPEATS) { + return reject(`repeats must be an integer in 1..${MAX_REPEATS}`); + } + // Both sides run the same shape of work, so validating either validates the + // comparison. + for (const mode of MODES) { + const invalid = validateConfig(runConfig(config, mode)); + if (invalid) return reject(invalid); + } + + const blocked = await startBlocked(ctx); + if (blocked) return blocked; + + const suiteId = await ctx.db.insert("benchSuites", { + config, + repeats, + cursor: 0, + status: "running", + createdAtMs: Date.now(), + }); + await startNextSuiteRun(ctx, suiteId); + return { ok: true as const, suiteId }; + }, +}); + +export const cancelSuite = mutation({ + args: { suiteId: v.id("benchSuites") }, + returns: v.null(), + handler: async (ctx, { suiteId }) => { + const suite = await ctx.db.get("benchSuites", suiteId); + if (!suite || suite.status !== "running") return null; + await ctx.db.patch("benchSuites", suiteId, { + status: "canceled", + finishedAtMs: Date.now(), + }); + // Cancel whichever run of the suite is still in flight; the suite being + // "canceled" stops `advanceSuite` from starting the next one. + const runs = await ctx.db + .query("benchRuns") + .withIndex("by_suite", (q) => q.eq("suiteId", suiteId)) + .take(SUITE_RUN_ROWS); + for (const run of runs) { + if ((ACTIVE_STATUSES as readonly string[]).includes(run.status)) { + await cancelRunHandler(ctx, run._id); + } + } + return null; + }, +}); + +/** + * Starts the next run of a suite, or finishes the suite when the schedule is + * exhausted. Reschedules itself while the previous run's queue is still + * draining — `startRun`'s guards apply to suite runs too. + */ +export const advanceSuite = internalMutation({ + args: { suiteId: v.id("benchSuites"), attempt: v.optional(v.number()) }, + returns: v.null(), + handler: async (ctx, { suiteId, attempt = 0 }) => { + const suite = await ctx.db.get("benchSuites", suiteId); + if (!suite || suite.status !== "running") return null; + + if (suite.cursor >= MODES.length * suite.repeats) { + await ctx.db.patch("benchSuites", suiteId, { + status: "done", + finishedAtMs: Date.now(), + }); + return null; + } + + const blocked = await startBlocked(ctx); + if (blocked) { + if (attempt >= SUITE_ADVANCE_MAX_ATTEMPTS) { + await ctx.db.patch("benchSuites", suiteId, { + status: "canceled", + finishedAtMs: Date.now(), + }); + return null; + } + await ctx.scheduler.runAfter( + SUITE_ADVANCE_RETRY_MS, + internal.bench.advanceSuite, + { + suiteId, + attempt: attempt + 1, + }, + ); + return null; + } + + await startNextSuiteRun(ctx, suiteId); + return null; + }, +}); + +async function startNextSuiteRun(ctx: MutationCtx, suiteId: Id<"benchSuites">) { + const suite = await ctx.db.get("benchSuites", suiteId); + if (!suite) return; + const { mode, repeatIndex } = scheduleSlot(suite.cursor); + await insertRun(ctx, { + config: runConfig(suite.config, mode), + label: `${mode === "async" ? "queued" : "eager"} · rep ${repeatIndex + 1}/${suite.repeats}`, + suiteId, + repeatIndex, + }); + await ctx.db.patch("benchSuites", suiteId, { + cursor: Math.min(suite.cursor + 1, MODES.length * suite.repeats), + }); +} + +/** + * Shared by `startRun` and the suite driver. Refuses for BOTH modes: an eager run + * would throw PENDING_OPERATIONS on its first write, and a queued run would be + * measuring someone else's backlog. + */ +async function startBlocked(ctx: MutationCtx) { + const active = await findActiveRun(ctx); + if (active) { + return { + ok: false as const, + reason: "run_in_progress" as const, + detail: `run ${active._id} is ${active.status}`, + }; + } + const queue = await staleQueueStats(ctx, { includeWorker: false }); + if (queue.rows > 0) { + return { + ok: false as const, + reason: "pending_ops" as const, + detail: + `${queue.operations} operation(s) across ${queue.rows} transaction(s) are still queued. ` + + `The worker drains on ping or within ${WORKER_MONITOR_LAG_MS / 1000}s.`, + }; + } + return null; +} + +async function insertRun( + ctx: MutationCtx, + { + config, + label, + suiteId, + repeatIndex, + }: { + config: BenchConfig; + label?: string; + suiteId?: Id<"benchSuites">; + repeatIndex?: number; + }, +): Promise> { + const now = Date.now(); + const runId = await ctx.db.insert("benchRuns", { + label, + suiteId, + repeatIndex, + status: "pending", + config, + createdAtMs: now, + progress: { + opsCommitted: 0, + lastQueueRows: 0, + lastQueueOperations: 0, + lastQueueChangeAtMs: now, + }, + }); + await ctx.scheduler.runAfter(0, internal.bench.prepare, { runId }); + return runId; +} + +async function cancelRunHandler(ctx: MutationCtx, runId: Id<"benchRuns">) { + const run = await ctx.db.get("benchRuns", runId); + if (!run) throw new Error("no such run"); + + // Cancelling the pending job in each lane is enough to stop the run: a lane + // only ever schedules from inside a job, so killing that job ends the chain. + let canceledJobs = 0; + const lanes = await ctx.db + .query("benchLanes") + .withIndex("by_run_lane", (q) => q.eq("runId", runId)) + .take(MAX_FAN_OUT); + for (const lane of lanes) { + const doc = await getScheduled(ctx, lane.scheduledFnId); + if (doc?.state.kind === "pending") { + await ctx.scheduler.cancel( + lane.scheduledFnId as Id<"_scheduled_functions">, + ); + canceledJobs++; + } + } + + // A queued run's tail can't be cancelled: there's no way to un-enqueue ops + // or to force a drain. All we can do is stop scheduling new work and wait. + const status = + run.config.mode === "async" && run.status === "enqueuing" + ? ("draining" as const) + : ("canceled" as const); + await ctx.db.patch("benchRuns", runId, { status }); + if (status === "canceled") { + await ctx.scheduler.runAfter(0, internal.bench.finalize, { runId }); + } + return { canceledJobs, status }; +} + +// ------------------------------------------------------- internal: lifecycle + +export const prepare = internalMutation({ + args: { runId: v.id("benchRuns") }, + returns: v.null(), + handler: async (ctx, { runId }) => { + const run = await ctx.db.get("benchRuns", runId); + if (!run || run.status !== "pending") return null; + await ctx.db.patch("benchRuns", runId, { status: "preparing" }); + + for (const shard of allShards(run.config)) { + await benchAggregate.clear(ctx, { + namespace: shard, + maxNodeSize: run.config.maxNodeSize, + rootLazy: run.config.rootLazy, + }); + } + + await ctx.db.patch("benchRuns", runId, { + status: "enqueuing", + enqueueStartedAtMs: Date.now(), + expectedJobs: totalWriteJobs(run.config), + }); + await ctx.scheduler.runAfter(PREPARE_SETTLE_MS, internal.bench.seedLanes, { + runId, + }); + await ctx.scheduler.runAfter(0, internal.bench.sampleQueue, { + runId, + tick: 0, + }); + await ctx.scheduler.runAfter(WATCH_INTERVAL_MS, internal.bench.watch, { + runId, + tick: 0, + }); + return null; + }, +}); + +/** + * Deals the first job into each lane. Everything after this is scheduled by the + * jobs themselves, one successor per commit, so the number of write transactions + * in flight never exceeds the configured fan-out. + */ +export const seedLanes = internalMutation({ + args: { runId: v.id("benchRuns") }, + returns: v.null(), + handler: async (ctx, { runId }) => { + const run = await ctx.db.get("benchRuns", runId); + if (!run || run.status !== "enqueuing") return null; + const config = run.config; + // Seeding happens PREPARE_SETTLE_MS after t0, and a seed can belong to a + // later burst, so the burst schedule applies here too. + const elapsedMs = Date.now() - (run.enqueueStartedAtMs ?? run.createdAtMs); + + for (let lane = 0; lane < laneCount(config); lane++) { + const job = planWriteJob(config, lane); + if (!job) break; + const scheduledFnId = await ctx.scheduler.runAfter( + Math.max( + laneStartDelayMs(config, lane), + burstDelayMs(config, job.seq, elapsedMs), + ), + internal.bench.writeJob, + { + runId, + lane, + seq: job.seq, + shard: job.shard, + keyBase: job.keyBase, + ops: job.ops, + async: config.mode === "async", + writeApi: config.writeApi ?? "perOp", + }, + ); + await ctx.db.insert("benchLanes", { + runId, + lane, + scheduledFnId, + jobsSpawned: 1, + }); + } + return null; + }, +}); + +export const writeJob = internalMutation({ + args: { + runId: v.id("benchRuns"), + lane: v.number(), + seq: v.number(), + shard: v.string(), + keyBase: v.number(), + ops: v.number(), + async: v.boolean(), + writeApi: vWriteApi, + }, + returns: v.null(), + handler: async ( + ctx, + { runId, lane, seq, shard, keyBase, ops, async, writeApi }, + ) => { + // Null if a reset deleted the run out from under this job. + const plan = await staleRunPlan(ctx, runId); + if (!plan) return null; + const config = plan.config; + + const startedAtMs = Date.now(); + const fnId = await scheduledFnId(ctx); + let ok = true; + let errorCode: string | undefined; + const item = (i: number) => { + const key = keyBase + i; + return { + namespace: shard, + key, + id: `${runId}:${seq}:${i}`, + sumValue: key, + }; + }; + try { + if (async && writeApi === "batch") { + // One component call for the whole transaction, so the queue is appended + // to once instead of `ops` times. There is no eager `insertBatch`, so an + // eager job falls through to the per-op loop whatever `writeApi` says. + await benchAggregate.enqueueBatch( + ctx, + Array.from({ length: ops }, (_, i) => ({ + type: "insert" as const, + ...item(i), + })), + ); + } else { + for (let i = 0; i < ops; i++) { + await benchAggregate.insert( + ctx, + item(i), + // Triggers can't be used here: they don't forward opts, so a + // triggered write is always eager. + { async }, + ); + } + } + } catch (e) { + if (e instanceof ConvexError) { + ok = false; + errorCode = String(e.data?.code ?? "UNKNOWN"); + } else { + throw e; // unexpected — let it surface as a failed scheduled function + } + } + + await ctx.db.insert("benchJobs", { + runId, + seq, + ops: ok ? ops : 0, + scheduledFnId: fnId, + startedAtMs, + metrics: await txnMetrics(ctx), + errorCode, + }); + + // The lane's next job, scheduled in the transaction that finishes this one. + // A ConvexError is a result, not a reason to stop — but an unexpected throw + // rolls this back, leaving the lane's pointer on a failed scheduled function, + // which is how `watch` sees the break. + const next = planWriteJob(config, seq + laneCount(config)); + if (next) { + // Trickle's arrival pacing or the next burst's slot; different scenarios, + // so at most one is non-zero. `startedAtMs` is this transaction's frozen + // clock, which is what `runAfter` is relative to, so the successor lands on + // the grid rather than one service time past it. + const delayMs = Math.max( + laneDelayMs(config), + burstDelayMs(config, next.seq, startedAtMs - plan.enqueueStartedAtMs), + ); + await advanceLane(ctx, runId, lane, () => + ctx.scheduler.runAfter(delayMs, internal.bench.writeJob, { + runId, + lane, + seq: next.seq, + shard: next.shard, + keyBase: next.keyBase, + ops: next.ops, + async, + writeApi, + }), + ); + } + return null; + }, +}); + +export const sampleQueue = internalMutation({ + args: { runId: v.id("benchRuns"), tick: v.number() }, + returns: v.null(), + handler: async (ctx, { runId, tick }) => { + // One stale-snapshot read for the whole sample: `watch` patches the run + // document every tick, so a live sampler would OCC-conflict with it and lose + // whole seconds of samples. See `runSampleState` for why it has to be one. + const state = await ctx.runQuery( + internal.bench.runSampleState, + { runId }, + { useStaleSnapshot: true }, + ); + if (!state) return null; + const active = state.status === "enqueuing" || state.status === "draining"; + if (!active || tick > MAX_TICKS) return null; + + await ctx.db.insert("benchQueueSamples", { + runId, + atMs: Date.now(), + rows: state.queue.rows, + operations: state.queue.operations, + opsCommitted: state.opsCommitted, + bytes: state.queue.bytes, + truncated: state.queue.truncated, + }); + await ctx.scheduler.runAfter( + SAMPLE_INTERVAL_MS, + internal.bench.sampleQueue, + { runId, tick: tick + 1 }, + ); + return null; + }, +}); + +export const scheduledStates = internalQuery({ + args: { ids: v.array(v.string()) }, + returns: v.array( + v.object({ + id: v.string(), + scheduledTime: v.union(v.number(), v.null()), + completedTime: v.union(v.number(), v.null()), + kind: v.union(v.string(), v.null()), + error: v.union(v.string(), v.null()), + }), + ), + handler: async (ctx, { ids }) => { + const docs = await Promise.all( + ids.map((id) => + ctx.db.system.get( + "_scheduled_functions", + id as Id<"_scheduled_functions">, + ), + ), + ); + return docs.map((doc, i) => ({ + id: ids[i], + scheduledTime: doc?.scheduledTime ?? null, + completedTime: doc?.completedTime ?? null, + kind: doc?.state.kind ?? null, + error: doc?.state.kind === "failed" ? doc.state.error : null, + })); + }, +}); + +/** + * Everything one queue sample records, read in a single transaction so it all + * describes the same snapshot. A job's row and the ops it enqueued commit + * together, so any snapshot holds both or neither; the consistency curve's + * `totalOps - opsCommitted + operations` is then exact. Read as two queries the + * committed total could run ahead of the queue by whatever landed in between, + * and the curve dipped and rose with every sample. + */ +export const runSampleState = internalQuery({ + args: { runId: v.id("benchRuns") }, + returns: v.union( + v.object({ + status: vRunStatus, + opsCommitted: v.number(), + queue: v.object({ + rows: v.number(), + operations: v.number(), + bytes: v.number(), + truncated: v.boolean(), + }), + }), + v.null(), + ), + handler: async (ctx, { runId }) => { + const run = await ctx.db.get("benchRuns", runId); + if (!run) return null; + const jobs = await ctx.db + .query("benchJobs") + .withIndex("by_run_seq", (q) => q.eq("runId", runId)) + .take(MAX_JOB_ROWS); + const queue = await ctx.runQuery( + components.benchAggregate.inspect.queueStats, + { limit: 1024, includeWorker: false }, + ); + return { + status: run.status, + opsCommitted: jobs.reduce((total, job) => total + job.ops, 0), + queue: { + rows: queue.rows, + operations: queue.operations, + bytes: queue.bytes, + truncated: queue.truncated, + }, + }; + }, +}); + +export const runPlanSnapshot = internalQuery({ + args: { runId: v.id("benchRuns") }, + returns: v.union( + v.object({ config: vBenchConfig, enqueueStartedAtMs: v.number() }), + v.null(), + ), + handler: async (ctx, { runId }) => { + const run = await ctx.db.get("benchRuns", runId); + if (!run) return null; + return { + config: run.config, + // The run's t0: what the burst schedule and the consistency curve are both + // measured from. + enqueueStartedAtMs: run.enqueueStartedAtMs ?? run.createdAtMs, + }; + }, +}); + +/** + * The run's lane pointers and committed-op total, as a separate query so `watch` + * can take them off a stale snapshot. Reading the job rows in the watch mutation + * itself takes a read dependency on an index range the run appends to for its + * whole enqueue phase, so every tick OCC-conflicts with the jobs it is measuring + * — at fan-out 1 that froze `progress.opsCommitted` near zero for entire runs. + */ +export const runSnapshot = internalQuery({ + args: { runId: v.id("benchRuns") }, + returns: v.object({ + laneFnIds: v.array(v.string()), + opsCommitted: v.number(), + }), + handler: async (ctx, { runId }) => { + const lanes = await ctx.db + .query("benchLanes") + .withIndex("by_run_lane", (q) => q.eq("runId", runId)) + .take(MAX_FAN_OUT); + const jobs = await ctx.db + .query("benchJobs") + .withIndex("by_run_seq", (q) => q.eq("runId", runId)) + .take(MAX_JOB_ROWS); + return { + laneFnIds: lanes.map((lane) => lane.scheduledFnId), + opsCommitted: jobs.reduce((total, job) => total + job.ops, 0), + }; + }, +}); + +export const watch = internalMutation({ + args: { runId: v.id("benchRuns"), tick: v.number() }, + returns: v.null(), + handler: async (ctx, { runId, tick }) => { + const run = await ctx.db.get("benchRuns", runId); + if (!run) return null; + if (run.status !== "enqueuing" && run.status !== "draining") return null; + if (tick > MAX_TICKS) return null; + + const now = Date.now(); + // Everything below comes off a stale snapshot, so the tick's only live read + // is the run document it owns. See `runSnapshot`. + const snapshot = await ctx.runQuery( + internal.bench.runSnapshot, + { runId }, + { useStaleSnapshot: true }, + ); + // One id per lane, not every id the run has scheduled, so this stays a + // handful of reads however long the run is. + const states = await ctx.runQuery( + internal.bench.scheduledStates, + { ids: snapshot.laneFnIds }, + { useStaleSnapshot: true }, + ); + // Pending or running means work in flight. Success means that lane scheduled + // no successor; failed or canceled means its chain is broken. Either way, + // nothing more is coming from it. + const lanesRunning = states.filter( + (s) => s.kind === "pending" || s.kind === "inProgress", + ).length; + + // `watch` needs the worker's status for the drain-complete check below. + const queue = await staleQueueStats(ctx, { + limit: 1024, + includeWorker: true, + }); + const queueChanged = + queue.operations !== run.progress.lastQueueOperations || + queue.rows !== run.progress.lastQueueRows; + + const progress = { + ...run.progress, + opsCommitted: snapshot.opsCommitted, + lastQueueRows: queue.rows, + lastQueueOperations: queue.operations, + lastQueueChangeAtMs: queueChanged + ? now + : run.progress.lastQueueChangeAtMs, + }; + + // Every lane seeded and none still running. Off a stale snapshot, so this can + // be a snapshot age late but never early: a job moves its lane's pointer onto + // its successor in the transaction that schedules it. + const enqueueDone = + snapshot.laneFnIds.length >= laneCount(run.config) && lanesRunning === 0; + + const startedAt = run.enqueueStartedAtMs ?? run.createdAtMs; + const timedOut = now - startedAt > run.config.timeoutMs; + const stalled = + run.status === "draining" && + queue.operations > 0 && + now - progress.lastQueueChangeAtMs > STALL_MS; + if (timedOut || stalled) { + await ctx.db.patch("benchRuns", runId, { + status: "finalizing", + progress, + drainEndedAtMs: now, + errors: [ + ...(run.errors ?? []), + timedOut + ? `run exceeded timeoutMs (${run.config.timeoutMs}ms)` + : `drain stalled: ${queue.operations} ops unchanged for ${STALL_MS}ms`, + ], + }); + await ctx.scheduler.runAfter(0, internal.bench.finalize, { runId }); + return null; + } + + if (run.status === "enqueuing" && enqueueDone) { + await ctx.db.patch("benchRuns", runId, { + status: "draining", + enqueueEndedAtMs: now, + progress, + }); + } else if (run.status === "draining") { + // An empty queue *is* consistency: the worker deletes a pendingOperations + // row in the same transaction that applies its operations. So stamp the + // moment it empties, whatever the worker's status doc says — the wait for + // the worker to park afterwards isn't part of time-to-consistency. + const consistentAt = + run.drainEndedAtMs ?? (queue.rows === 0 ? now : undefined); + if (consistentAt !== undefined && queue.worker !== "running") { + await ctx.db.patch("benchRuns", runId, { + status: "finalizing", + drainEndedAtMs: consistentAt, + workerParkedAtMs: now, + progress, + }); + await ctx.scheduler.runAfter(0, internal.bench.finalize, { runId }); + return null; + } + await ctx.db.patch("benchRuns", runId, { + progress, + drainEndedAtMs: consistentAt, + }); + } else { + await ctx.db.patch("benchRuns", runId, { progress }); + } + + await ctx.scheduler.runAfter(WATCH_INTERVAL_MS, internal.bench.watch, { + runId, + tick: tick + 1, + }); + return null; + }, +}); + +// ------------------------------------------------------- internal: finalize + +type Acc = { + jobLatency: Hist; + jobService: Hist; + jobQueue: Hist; + opsCommitted: number; + jobsTotal: number; + jobsSucceeded: number; + jobsFailed: number; + jobsCanceled: number; + documentsRead: number; + documentsWritten: number; + bytesRead: number; + bytesWritten: number; + databaseQueries: number; + errorPendingOperations: number; + errorOcc: number; + errorLimit: number; + errorOther: number; + errorSamples: string[]; + intervals: Array<{ start: number; end: number }>; +}; + +export const finalize = internalMutation({ + args: { runId: v.id("benchRuns") }, + returns: v.null(), + handler: async (ctx, { runId }) => { + const run = await ctx.db.get("benchRuns", runId); + if (!run) return null; + + const jobs = await ctx.db + .query("benchJobs") + .withIndex("by_run_seq", (q) => q.eq("runId", runId)) + .take(MAX_JOB_ROWS); + + // A committed job records its own scheduled id. The lane pointers cover what + // those can't: a job that threw committed no row at all. + const lanes = await ctx.db + .query("benchLanes") + .withIndex("by_run_lane", (q) => q.eq("runId", runId)) + .take(MAX_FAN_OUT); + const jobIds = jobs.flatMap((job) => + job.scheduledFnId ? [job.scheduledFnId] : [], + ); + const laneIds = lanes + .map((lane) => lane.scheduledFnId) + .filter((id) => !jobIds.includes(id)); + const states = await ctx.runQuery( + internal.bench.scheduledStates, + { ids: [...jobIds, ...laneIds] }, + { useStaleSnapshot: true }, + ); + const byId = new Map(states.map((s) => [s.id, s])); + + const acc: Acc = { + jobLatency: histInit(), + jobService: histInit(), + jobQueue: histInit(), + opsCommitted: 0, + jobsTotal: run.expectedJobs ?? totalWriteJobs(run.config), + jobsSucceeded: 0, + jobsFailed: 0, + jobsCanceled: 0, + documentsRead: 0, + documentsWritten: 0, + bytesRead: 0, + bytesWritten: 0, + databaseQueries: 0, + errorPendingOperations: 0, + errorOcc: 0, + errorLimit: 0, + errorOther: 0, + errorSamples: [], + intervals: [], + }; + + for (const s of states) { + if (s.kind === "success") acc.jobsSucceeded++; + else if (s.kind === "canceled") acc.jobsCanceled++; + else if (s.kind === "failed") { + acc.jobsFailed++; + const cls = classifyError(s.error ?? ""); + if (cls === "pendingOperations") acc.errorPendingOperations++; + else if (cls === "occSuspected") acc.errorOcc++; + else if (cls === "limit") acc.errorLimit++; + else acc.errorOther++; + if (acc.errorSamples.length < 5 && s.error) { + acc.errorSamples.push(summarizeError(s.error)); + } + } + } + + // The scheduler's clock puts the end of the enqueue phase at the last job's + // commit. `watch` stamped it on the tick that noticed, off a stale snapshot, + // which is a tick or two late; taken instead whenever every job has one. + let lastCommitMs: number | undefined = jobs.length > 0 ? 0 : undefined; + for (const job of jobs) { + const sched = job.scheduledFnId ? byId.get(job.scheduledFnId) : undefined; + if (sched?.scheduledTime != null && sched.completedTime != null) { + acc.intervals.push({ + start: sched.scheduledTime, + end: sched.completedTime, + }); + histAdd(acc.jobLatency, sched.completedTime - sched.scheduledTime); + histAdd(acc.jobService, sched.completedTime - job.startedAtMs); + histAdd(acc.jobQueue, job.startedAtMs - sched.scheduledTime); + } + if (lastCommitMs !== undefined) { + lastCommitMs = + sched?.completedTime != null + ? Math.max(lastCommitMs, sched.completedTime) + : undefined; + } + acc.opsCommitted += job.ops; + acc.documentsRead += job.metrics.documentsRead; + acc.documentsWritten += job.metrics.documentsWritten; + acc.bytesRead += job.metrics.bytesRead; + acc.bytesWritten += job.metrics.bytesWritten; + acc.databaseQueries += job.metrics.databaseQueries; + if (job.errorCode === "PENDING_OPERATIONS") acc.errorPendingOperations++; + } + + const samples = await ctx.db + .query("benchQueueSamples") + .withIndex("by_run_at", (q) => q.eq("runId", runId)) + .take(4000); + let peakRows = 0; + let peakOperations = 0; + let peakBytes = 0; + let peakTruncated = false; + for (const s of samples) { + peakRows = Math.max(peakRows, s.rows); + peakOperations = Math.max(peakOperations, s.operations); + peakBytes = Math.max(peakBytes, s.bytes); + if (s.truncated) peakTruncated = true; + } + + const enqueueStart = run.enqueueStartedAtMs ?? run.createdAtMs; + const enqueueEnd = + lastCommitMs ?? run.enqueueEndedAtMs ?? run.drainEndedAtMs ?? Date.now(); + // An eager run queues nothing, so it is consistent the moment its last write + // commits. `watch` still spends a tick in "draining" before it stamps the + // end, and that tick drew a flat tail on the curve past the point it had + // reached zero and padded time-to-consistency by the same amount. + const drainEnd = + run.config.mode === "async" + ? Math.max(run.drainEndedAtMs ?? enqueueEnd, enqueueEnd) + : enqueueEnd; + const enqueueSecs = Math.max(enqueueEnd - enqueueStart, 1) / 1000; + const totalSecs = Math.max(drainEnd - enqueueStart, 1) / 1000; + const timeToDrainMs = Math.max(drainEnd - enqueueEnd, 0); + const ops = Math.max(acc.opsCommitted, 1); + + // Ops that never landed, whatever the reason. This is the check that matters: + // a run can fail without anything in `run.errors`, which only carries the + // watchdog's own complaints. + const opsMissing = Math.max(run.config.totalOps - acc.opsCommitted, 0); + const watchdogErrors = run.errors ?? []; + // Only close the consistency curve at zero when everything actually landed, + // or a run that lost most of its ops draws a cliff at the end of a curve + // that never came down. + const reachedConsistency = + watchdogErrors.length === 0 && + run.status !== "canceled" && + opsMissing === 0; + const jobErrors = + acc.jobsFailed > 0 + ? [ + `${acc.jobsFailed} of ${acc.jobsTotal} jobs failed, ${opsMissing} of ${run.config.totalOps} ops never landed` + + (acc.errorSamples[0] ? `: ${acc.errorSamples[0]}` : ""), + ] + : opsMissing > 0 && run.status !== "canceled" + ? [`${opsMissing} of ${run.config.totalOps} ops never landed`] + : []; + const errors = [...watchdogErrors, ...jobErrors]; + const failed = errors.length > 0; + + const results: BenchResults = { + ops: { + attempted: run.config.totalOps, + committed: acc.opsCommitted, + failed: opsMissing, + }, + jobs: { + total: acc.jobsTotal, + succeeded: acc.jobsSucceeded, + failed: acc.jobsFailed, + canceled: acc.jobsCanceled, + }, + latency: { + jobLatency: summarize(acc.jobLatency), + jobService: summarize(acc.jobService), + jobQueue: summarize(acc.jobQueue), + perOpServiceMs: acc.jobService.sum / ops, + }, + work: { + documentsReadPerOp: acc.documentsRead / ops, + documentsWrittenPerOp: acc.documentsWritten / ops, + bytesReadPerOp: acc.bytesRead / ops, + bytesWrittenPerOp: acc.bytesWritten / ops, + databaseQueriesPerOp: acc.databaseQueries / ops, + }, + throughput: { + enqueueOpsPerSec: acc.opsCommitted / enqueueSecs, + applyOpsPerSec: + run.config.mode === "async" + ? acc.opsCommitted / totalSecs + : undefined, + }, + drain: { + timeToDrainMs, + resolutionMs: run.config.mode === "async" ? WATCH_INTERVAL_MS : 0, + exceededMonitorLag: timeToDrainMs > WORKER_MONITOR_LAG_MS, + workerParkMs: + run.workerParkedAtMs !== undefined + ? Math.max(run.workerParkedAtMs - drainEnd, 0) + : undefined, + }, + queue: { + peakRows, + peakOperations, + peakBytes, + peakTruncated, + samples: samples.length, + }, + concurrency: { + achieved: maxOverlap(acc.intervals), + offered: run.config.fanOut, + }, + consistency: downsample( + consistencyCurve({ + totalOps: run.config.totalOps, + startedAtMs: enqueueStart, + endedAtMs: reachedConsistency ? drainEnd : undefined, + samples, + }), + MAX_CURVE_POINTS, + ), + errors: { + occSuspected: acc.errorOcc, + pendingOperations: acc.errorPendingOperations, + limit: acc.errorLimit, + other: acc.errorOther, + samples: acc.errorSamples, + }, + }; + + await ctx.db.patch("benchRuns", runId, { + status: + run.status === "canceled" ? "canceled" : failed ? "failed" : "done", + // Refined above; the client's time-to-consistency reads these. + enqueueEndedAtMs: enqueueEnd, + drainEndedAtMs: drainEnd, + finishedAtMs: Date.now(), + errors: errors.length > 0 ? errors : undefined, + results, + }); + // A suite's runs are strictly sequential: the next one starts only once this + // one's results are written, so they never contend for the aggregate. + if (run.suiteId) { + await ctx.scheduler.runAfter(0, internal.bench.advanceSuite, { + suiteId: run.suiteId, + }); + } + return null; + }, +}); + +// ------------------------------------------------------------------ helpers + +async function findActiveRun(ctx: { db: QueryCtx["db"] }) { + for (const status of ACTIVE_STATUSES) { + const found = await ctx.db + .query("benchRuns") + .withIndex("by_status", (q) => q.eq("status", status)) + .first(); + if (found) return found; + } + return null; +} + +const ZERO_METRICS = { + documentsRead: 0, + documentsWritten: 0, + bytesRead: 0, + bytesWritten: 0, + databaseQueries: 0, +}; + +/** + * `ctx.meta` is backed by syscalls convex-test doesn't implement, so under test + * these degrade to zeros rather than failing the run. + */ +async function txnMetrics(ctx: MutationCtx): Promise { + try { + const m = await ctx.meta.getTransactionMetrics(); + return { + documentsRead: m.documentsRead.used, + documentsWritten: m.documentsWritten.used, + bytesRead: m.bytesRead.used, + bytesWritten: m.bytesWritten.used, + databaseQueries: m.databaseQueries.used, + }; + } catch { + return ZERO_METRICS; + } +} + +/** + * Moves a lane's pointer onto the job it just scheduled, in the same transaction + * that scheduled it. `watch` reads the pointer as the lane's liveness, so it must + * never name an unscheduled job or miss a scheduled one. + */ +async function advanceLane( + ctx: MutationCtx, + runId: Id<"benchRuns">, + lane: number, + schedule: () => Promise>, +): Promise { + const row = await ctx.db + .query("benchLanes") + .withIndex("by_run_lane", (q) => q.eq("runId", runId).eq("lane", lane)) + .unique(); + // No row means a reset took the lane out from under this job. Stop rather than + // schedule work nothing is tracking, which would leave the run waiting on a + // lane it can't see. + if (!row) return; + await ctx.db.patch("benchLanes", row._id, { + scheduledFnId: await schedule(), + jobsSpawned: row.jobsSpawned + 1, + }); +} + +/** + * The run's config and t0, or null if the run is gone. Jobs need both to schedule + * their successor; off a stale snapshot because reading the run document live + * would put every job in the run on a collision course with `watch`'s patches. + */ +async function staleRunPlan( + ctx: MutationCtx, + runId: Id<"benchRuns">, +): Promise<{ config: BenchConfig; enqueueStartedAtMs: number } | null> { + return await ctx.runQuery( + internal.bench.runPlanSnapshot, + { runId }, + { useStaleSnapshot: true }, + ); +} + +async function scheduledFnId(ctx: MutationCtx): Promise { + try { + return ( + (await ctx.meta.getRequestMetadata()).scheduledFunctionId ?? undefined + ); + } catch { + return undefined; + } +} + +async function getScheduled( + ctx: MutationCtx, + id: string, +): Promise { + return (await ctx.db.system.get( + "_scheduled_functions", + id as Id<"_scheduled_functions">, + )) as ScheduledDoc | null; +} + +// -------------------------------------------------------------------- reset + +export const resetAll = internalMutation({ + args: {}, + returns: resetStatusValidator, + handler: async (ctx): Promise<"all_reset" | "partial_reset"> => { + const batchSize = 1000; + + // Cancel still-pending jobs first, so a reset doesn't leave orphans writing + // into deleted runs. + const lanes = await ctx.db.query("benchLanes").take(batchSize); + for (const lane of lanes) { + const doc = await getScheduled(ctx, lane.scheduledFnId); + if (doc?.state.kind === "pending") { + await ctx.scheduler.cancel( + lane.scheduledFnId as Id<"_scheduled_functions">, + ); + } + } + + for (const table of [ + "benchQueueSamples", + "benchJobs", + "benchLanes", + "benchRuns", + "benchSuites", + ] as const) { + const docs = await ctx.db.query(table).take(batchSize); + for (const doc of docs) await ctx.db.delete(table, doc._id); + if (docs.length === batchSize) return "partial_reset"; + } + + // `clear` throws while ops are queued, so wait for the worker to drain. + // The cron chain re-runs us on "partial_reset". + const queue = await staleQueueStats(ctx, { includeWorker: false }); + if (queue.rows > 0) return "partial_reset"; + + await benchAggregate.clearAll(ctx); + return "all_reset"; + }, +}); diff --git a/example/convex/convex.config.ts b/example/convex/convex.config.ts index e58e9694..140ce0de 100644 --- a/example/convex/convex.config.ts +++ b/example/convex/convex.config.ts @@ -9,6 +9,10 @@ app.use(aggregate, { name: "music" }); app.use(aggregate, { name: "photos" }); app.use(aggregate, { name: "stats" }); app.use(aggregate, { name: "btreeAggregate" }); +// Dedicated instance for the benchmark. It must not be shared: while a queued +// (async) run is draining, `assertNoPendingOperations` makes every eager write, +// every non-stale read, and even `clear` throw on that instance. +app.use(aggregate, { name: "benchAggregate" }); app.use(migrations); diff --git a/example/convex/crons.ts b/example/convex/crons.ts index 454e8fab..dce3d1d6 100644 --- a/example/convex/crons.ts +++ b/example/convex/crons.ts @@ -1,13 +1,49 @@ import { cronJobs } from "convex/server"; +import { v } from "convex/values"; import { api, internal } from "./_generated/api"; import { internalMutation } from "./_generated/server"; +const BENCH_RESET_RETRY_MS = 1_000; +/** + * Bounded like `bench.advanceSuite`, and for the same reason: the drain relies + * on the batch worker's monitor waking it, and a stopped worker never would. + */ +const BENCH_RESET_MAX_ATTEMPTS = 120; + +/** + * Retries `bench.resetAll` until the aggregate's queue drains, since + * `assertNoPendingOperations` makes its `clear` throw while operations are + * pending. Waiting on the worker makes no progress of its own, so this backs + * off between attempts instead of rescheduling immediately. + */ +export const finishBenchReset = internalMutation({ + args: { attempt: v.optional(v.number()) }, + handler: async (ctx, { attempt = 0 }) => { + if ((await ctx.runMutation(internal.bench.resetAll)) !== "partial_reset") { + console.log("Bench reset complete"); + return null; + } + if (attempt >= BENCH_RESET_MAX_ATTEMPTS) { + console.error("Giving up on bench reset; the queue never drained"); + return null; + } + await ctx.scheduler.runAfter( + BENCH_RESET_RETRY_MS, + internal.crons.finishBenchReset, + { attempt: attempt + 1 }, + ); + return null; + }, +}); + export const resetAndSeed = internalMutation({ args: {}, handler: async (ctx) => { console.log("Starting daily data reset..."); - // Reset each module sequentially; bail early and reschedule if any aren't done yet + // Reset each module sequentially; bail early and reschedule if any aren't done yet. + // Every `partial_reset` below means a full delete batch landed, so each + // iteration of the chain makes progress. if ( (await ctx.runMutation(internal.leaderboard.resetAll)) === "partial_reset" ) { @@ -33,6 +69,16 @@ export const resetAndSeed = internalMutation({ return null; } + // Bench goes last and never bails out of this chain: its reset can be stuck + // behind a draining queue, and nothing below touches the bench tables. + if ((await ctx.runMutation(internal.bench.resetAll)) === "partial_reset") { + await ctx.scheduler.runAfter( + BENCH_RESET_RETRY_MS, + internal.crons.finishBenchReset, + { attempt: 1 }, + ); + } + await ctx.runMutation(api.leaderboard.addMockScores, { count: 500 }); // Add some initial photos diff --git a/example/convex/schema.ts b/example/convex/schema.ts index e198b0fa..d0dd9f04 100644 --- a/example/convex/schema.ts +++ b/example/convex/schema.ts @@ -1,5 +1,6 @@ import { defineSchema, defineTable } from "convex/server"; import { v } from "convex/values"; +import { vBenchConfig, vBenchResults, vRunStatus } from "./utils/benchTypes"; export default defineSchema({ leaderboard: defineTable({ @@ -13,4 +14,129 @@ export default defineSchema({ album: v.string(), url: v.string(), }).index("by_album_creation_time", ["album"]), + + // ---- benchmark (see bench.ts) ---- + + // A suite is one comparison: the same config run queued and eager, `repeats` + // times each. Repeats exist so the dashboard can show a median and a spread + // instead of a single sample — one run of a scheduler-driven benchmark is noise. + // + // The two sides aren't stored, because they're never anything else: the queued + // run is this config with `mode: "async"` and batched enqueues, the eager run is + // the same config with `mode: "eager"`. `runConfig` in bench.ts derives both. + benchSuites: defineTable({ + config: vBenchConfig, + repeats: v.number(), + // Next index into the interleaved schedule. See `scheduleSlot` in bench.ts. + cursor: v.number(), + status: v.union( + v.literal("running"), + v.literal("done"), + v.literal("canceled"), + ), + createdAtMs: v.number(), + finishedAtMs: v.optional(v.number()), + }), + + // One row per run. Per-job progress is aggregated into `progress` by the + // single-threaded `watch` loop rather than patched by each job, so the + // dashboard can subscribe to this row without it churning per write. + benchRuns: defineTable({ + label: v.optional(v.string()), + // Set when the run is one cell of a suite. Which side of the comparison it + // is comes from `config.mode`, so it isn't stored separately. + suiteId: v.optional(v.id("benchSuites")), + repeatIndex: v.optional(v.number()), + status: vRunStatus, + config: vBenchConfig, + createdAtMs: v.number(), + enqueueStartedAtMs: v.optional(v.number()), + /** + * When the last write committed. Stamped by `watch` as it notices, then + * replaced by `finalize` with the scheduler's own completion time. + */ + enqueueEndedAtMs: v.optional(v.number()), + /** + * When the queue emptied, which is when the aggregate became consistent — + * the worker applies a batch and deletes its rows in one transaction. For an + * eager run, which queues nothing, `finalize` sets it to `enqueueEndedAtMs`. + */ + drainEndedAtMs: v.optional(v.number()), + /** + * When the component's worker stopped reporting itself as running. Strictly + * after consistency: it's the worker's own wind-down, kept out of the drain + * measurement but recorded so the wait it imposes is visible. + */ + workerParkedAtMs: v.optional(v.number()), + finishedAtMs: v.optional(v.number()), + /** Jobs the run will schedule if nothing fails. See `totalWriteJobs`. */ + expectedJobs: v.optional(v.number()), + progress: v.object({ + opsCommitted: v.number(), + lastQueueRows: v.number(), + lastQueueOperations: v.number(), + lastQueueChangeAtMs: v.number(), + }), + results: v.optional(vBenchResults), + errors: v.optional(v.array(v.string())), + }) + .index("by_status", ["status"]) + .index("by_suite", ["suiteId"]), + + // One append-only row per committed job transaction. Deliberately per-job, + // not per-op: `Date.now()` is frozen per transaction and getTransactionMetrics + // is per-transaction, so a per-op row would carry no extra information at 10x + // the write cost — and those writes would become the thing being measured. + benchJobs: defineTable({ + runId: v.id("benchRuns"), + seq: v.number(), + ops: v.number(), + // Id of this execution's `_scheduled_functions` row. Stored as a string: + // user schemas can't reference system tables. Cast when reading. + scheduledFnId: v.optional(v.string()), + startedAtMs: v.number(), + metrics: v.object({ + documentsRead: v.number(), + documentsWritten: v.number(), + bytesRead: v.number(), + bytesWritten: v.number(), + databaseQueries: v.number(), + }), + errorCode: v.optional(v.string()), + }).index("by_run_seq", ["runId", "seq"]), + + // One row per lane, pointing at the job most recently scheduled in it. + // + // A lane is a serial chain: each job schedules its successor as it commits and + // moves this pointer in the same transaction, so the pointer always names the + // only job that lane can have in flight. Its scheduled state is therefore the + // lane's state — pending or inProgress means running, success means that job + // scheduled no successor and the lane is done, failed or canceled means the + // chain is broken. That's what makes a thrown job observable at all: it + // commits nothing, writes no benchJobs row, and the id of its + // `_scheduled_functions` row is known only to whoever scheduled it. + // + // One row per lane rather than a growing manifest, and only that lane's own + // jobs ever write it, so the bookkeeping costs a patch per job and contends + // with nothing. + benchLanes: defineTable({ + runId: v.id("benchRuns"), + lane: v.number(), + scheduledFnId: v.string(), + jobsSpawned: v.number(), + }).index("by_run_lane", ["runId", "lane"]), + + // Queue-depth timeseries, sampled on a fixed cadence during a run. + benchQueueSamples: defineTable({ + runId: v.id("benchRuns"), + atMs: v.number(), + rows: v.number(), + operations: v.number(), + // Ops committed by the run's jobs, read from the same snapshot as the queue + // figures so the two agree on which enqueues have happened. (Samples from + // before that came from `watch`'s lagging counter instead.) + opsCommitted: v.number(), + bytes: v.number(), + truncated: v.boolean(), + }).index("by_run_at", ["runId", "atMs"]), }); diff --git a/example/convex/utils/benchMath.test.ts b/example/convex/utils/benchMath.test.ts new file mode 100644 index 00000000..db75951e --- /dev/null +++ b/example/convex/utils/benchMath.test.ts @@ -0,0 +1,657 @@ +import { describe, expect, test } from "vitest"; +import { + allShards, + bucketIndex, + bucketLowerBound, + burstDelayMs, + burstOfSeq, + burstStartsMs, + classifyError, + consistencyCurve, + downsample, + HIST_BUCKETS, + histAdd, + histInit, + histQuantile, + laneCount, + laneDelayMs, + laneStartDelayMs, + MAX_SHARDS, + MAX_TOTAL_OPS, + maxOverlap, + planWriteJob, + shardName, + summarize, + summarizeError, + totalWriteJobs, + validateConfig, +} from "./benchMath"; +import type { BenchConfig } from "./benchTypes"; + +const baseConfig: BenchConfig = { + mode: "async", + scenario: "hot", + totalOps: 100, + opsPerMutation: 10, + fanOut: 4, + shards: 1, + timeoutMs: 60_000, +}; + +/** + * Interpolating quantile over a sorted copy, to check the histogram against. + * `histQuantile` interpolates too, so any gap between the two is bucket error + * rather than a difference of definition. + */ +function exactQuantile(values: number[], q: number): number { + const sorted = [...values].sort((a, b) => a - b); + const pos = q * sorted.length - 0.5; + if (pos <= 0) return sorted[0]; + if (pos >= sorted.length - 1) return sorted[sorted.length - 1]; + const lo = Math.floor(pos); + return sorted[lo] + (sorted[lo + 1] - sorted[lo]) * (pos - lo); +} + +describe("histogram", () => { + test("keeps count, sum, min and max exact", () => { + const h = histInit(); + for (const v of [1, 5, 20, 100]) histAdd(h, v); + expect(h.count).toBe(4); + expect(h.sum).toBe(126); + expect(h.min).toBe(1); + expect(h.max).toBe(100); + }); + + test("drops non-finite samples and folds negative ones to zero", () => { + const h = histInit(); + for (const v of [NaN, Infinity, -Infinity]) histAdd(h, v); + expect(h.count).toBe(0); + // `jobQueue` is fed startedAtMs - scheduledTime, which goes negative when the + // two clocks disagree; it counts as a zero-wait sample rather than vanishing. + histAdd(h, -5); + expect(h.count).toBe(1); + expect(h.sum).toBe(0); + expect(h.min).toBe(0); + expect(h.buckets[0]).toBe(1); + }); + + test("puts a value in the bucket its own lower edge names", () => { + // An off-by-one here shifts every quantile by a bucket width (~19%). + expect(bucketLowerBound(0)).toBe(0); + expect(bucketIndex(0)).toBe(0); + expect(bucketIndex(0.5)).toBe(0); + for (const i of [1, 2, 17, 63]) { + expect(bucketIndex(bucketLowerBound(i))).toBe(i); + expect(bucketIndex(bucketLowerBound(i) * (1 - 1e-9))).toBe(i - 1); + } + // The top bucket is a catch-all: its lower edge is ~27.5s, and anything + // slower lands in it rather than off the end of the array. + expect(Math.round(bucketLowerBound(HIST_BUCKETS - 1))).toBe(27_554); + expect(bucketIndex(10 * 60_000)).toBe(HIST_BUCKETS - 1); + }); + + test("quantiles land well inside a bucket width of the exact value", () => { + const values: number[] = []; + for (let i = 0; i < 1000; i++) values.push(1 + (i % 250)); + const h = histInit(); + for (const v of values) histAdd(h, v); + for (const q of [0.5, 0.75, 0.9]) { + const exact = exactQuantile(values, q); + const approx = histQuantile(h, q); + // Measured error is under 1%; a bucket off-by-one would be 11-19%, so this + // budget fails on one rather than absorbing it. + expect(Math.abs(approx - exact) / exact).toBeLessThan(0.05); + } + }); + + test("summarizes an empty histogram without dividing by zero", () => { + expect(summarize(histInit())).toMatchObject({ count: 0, mean: 0, p95: 0 }); + }); +}); + +describe("lane planning", () => { + /** Every write job in seq order, as the lanes would produce them. */ + function allWriteJobs(config: BenchConfig) { + const jobs = []; + for (let seq = 0; ; seq++) { + const job = planWriteJob(config, seq); + if (!job) return jobs; + jobs.push(job); + } + } + + test("covers every op exactly once with unique keys", () => { + const seen = new Set(); + let ops = 0; + for (const job of allWriteJobs(baseConfig)) { + for (let i = 0; i < job.ops; i++) { + const key = job.keyBase + i; + // The jobs' key ranges partition 0..totalOps-1, so a finished run holds + // exactly totalOps distinct keys and its aggregate count is checkable. + expect(seen.has(key)).toBe(false); + seen.add(key); + } + ops += job.ops; + } + expect(ops).toBe(baseConfig.totalOps); + expect(seen.size).toBe(baseConfig.totalOps); + }); + + test("deals the jobs across the lanes without gaps or overlap", () => { + // Lane L runs L, L + lanes, L + 2·lanes, … so the lanes partition the seqs. + const lanes = laneCount(baseConfig); + expect(lanes).toBe(4); + const byLane = Array.from({ length: lanes }, (_, lane) => { + const seqs = []; + for (let seq = lane; planWriteJob(baseConfig, seq); seq += lanes) { + seqs.push(seq); + } + return seqs; + }); + expect(byLane).toEqual([ + [0, 4, 8], + [1, 5, 9], + [2, 6], + [3, 7], + ]); + expect(byLane.flat().sort((a, b) => a - b)).toEqual( + Array.from({ length: totalWriteJobs(baseConfig) }, (_, i) => i), + ); + }); + + test("never opens more lanes than there are jobs", () => { + // Otherwise a lane would be seeded with nothing to run, and the run would + // wait for a job that was never scheduled. + expect(laneCount({ ...baseConfig, totalOps: 20, fanOut: 8 })).toBe(2); + expect(planWriteJob({ ...baseConfig, totalOps: 20 }, 2)).toBeNull(); + }); + + test("runs strictly serially at fan-out 1", () => { + expect(laneCount({ ...baseConfig, fanOut: 1 })).toBe(1); + }); + + test("spreads across shards when sharded", () => { + const config = { ...baseConfig, scenario: "sharded" as const, shards: 4 }; + const shards = new Set(allWriteJobs(config).map((j) => j.shard)); + expect(shards.size).toBe(4); + expect(allShards(config)).toEqual([ + "shard-0", + "shard-1", + "shard-2", + "shard-3", + ]); + expect(shardName(config, 5)).toBe("shard-1"); + }); + + test("names the single namespace consistently when unsharded", () => { + // The namespace name is what the run reads back to check its own totals, so + // planning and reporting have to agree on it. + expect(allShards(baseConfig)).toEqual(["hot"]); + expect(shardName(baseConfig, 3)).toBe("hot"); + }); + + test("trickle spaces a lane's jobs by the arrival rate", () => { + const config: BenchConfig = { + ...baseConfig, + scenario: "trickle", + arrivalRatePerSec: 20, // one job every 50ms + fanOut: 4, + }; + // Four lanes staggered a slot apart, each firing every four slots, is one + // job every 50ms overall. + expect([0, 1, 2, 3].map((l) => laneStartDelayMs(config, l))).toEqual([ + 0, 50, 100, 150, + ]); + expect(laneDelayMs(config)).toBe(200); + }); + + test("does not pace the other scenarios", () => { + expect(laneDelayMs(baseConfig)).toBe(0); + expect(laneStartDelayMs(baseConfig, 3)).toBe(0); + }); + + test("bursty deals the write jobs into contiguous bursts", () => { + const config: BenchConfig = { + ...baseConfig, + scenario: "bursty", + bursts: 4, + burstIntervalMs: 5_000, + }; + // 10 write jobs over 4 bursts: 3, 3, 3, then the remaining 1. + const seqs = allWriteJobs(config).map((j) => burstOfSeq(config, j.seq)); + expect(seqs).toEqual([0, 0, 0, 1, 1, 1, 2, 2, 2, 3]); + expect(burstStartsMs(config)).toEqual([0, 5_000, 10_000, 15_000]); + }); + + test("can leave a trailing burst empty", () => { + // jobsPerBurst is a ceiling, so 5 jobs over 4 bursts is 2/2/1/0: the run + // performs three bursts while still reporting `bursts: 4`. + const config: BenchConfig = { + ...baseConfig, + scenario: "bursty", + totalOps: 50, + opsPerMutation: 10, + bursts: 4, + burstIntervalMs: 5_000, + }; + const seqs = allWriteJobs(config).map((j) => burstOfSeq(config, j.seq)); + expect(seqs).toEqual([0, 0, 1, 1, 2]); + expect(new Set(seqs).has(3)).toBe(false); + }); + + test("bursty holds a job back to its slot but never past it", () => { + const config: BenchConfig = { + ...baseConfig, + scenario: "bursty", + bursts: 4, + burstIntervalMs: 5_000, + }; + // Burst 1 starts seq 3. A lane arriving there early waits out the rest of + // the interval; one arriving late doesn't wait at all — the burst is already + // due, so an overrun spills into the next slot rather than pushing it back. + expect(burstDelayMs(config, 3, 1_200)).toBe(3_800); + expect(burstDelayMs(config, 3, 5_000)).toBe(0); + expect(burstDelayMs(config, 3, 9_000)).toBe(0); + // Still inside burst 0, so nothing is held back. + expect(burstDelayMs(config, 2, 1_200)).toBe(0); + // The last burst's jobs are due at its own slot, not the run's start. + expect(burstDelayMs(config, 9, 0)).toBe(15_000); + }); + + test("does not burst the other scenarios", () => { + expect(burstOfSeq({ ...baseConfig, bursts: 4 }, 9)).toBe(0); + expect( + burstDelayMs({ ...baseConfig, bursts: 4, burstIntervalMs: 5_000 }, 9, 0), + ).toBe(0); + }); + + test("does not overshoot totalOps on the final job", () => { + const config = { ...baseConfig, totalOps: 25, opsPerMutation: 10 }; + const last = allWriteJobs(config).at(-1)!; + expect(last.ops).toBe(5); + }); +}); + +describe("validateConfig", () => { + test("accepts a sane config", () => { + expect(validateConfig(baseConfig)).toBeNull(); + }); + + test("bounds totalOps", () => { + expect(validateConfig({ ...baseConfig, totalOps: 0 })).toMatch(/totalOps/); + expect( + validateConfig({ ...baseConfig, totalOps: MAX_TOTAL_OPS + 1 }), + ).toMatch(/totalOps/); + }); + + test("bounds opsPerMutation below but not above", () => { + expect(validateConfig({ ...baseConfig, opsPerMutation: 0 })).toMatch( + /opsPerMutation/, + ); + expect(validateConfig({ ...baseConfig, opsPerMutation: 2.5 })).toMatch( + /opsPerMutation/, + ); + // Deliberately unbounded above; an over-large job fails as a failed job. + expect( + validateConfig({ ...baseConfig, totalOps: 5_000, opsPerMutation: 5_000 }), + ).toBeNull(); + }); + + test("rejects fractional and non-finite counts", () => { + // A fractional fanOut is the dangerous one: laneCount would be 4.5, so the + // lanes would stride by 4.5, seed one lane too many, overlap key ranges, and + // drive ops.failed negative. + expect(validateConfig({ ...baseConfig, fanOut: 4.5 })).toMatch(/fanOut/); + expect(validateConfig({ ...baseConfig, totalOps: 100.5 })).toMatch( + /totalOps/, + ); + expect( + validateConfig({ ...baseConfig, scenario: "sharded", shards: 2.5 }), + ).toMatch(/shards/); + expect(validateConfig({ ...baseConfig, totalOps: NaN })).toMatch( + /totalOps/, + ); + expect(validateConfig({ ...baseConfig, fanOut: Infinity })).toMatch( + /fanOut/, + ); + expect(validateConfig({ ...baseConfig, timeoutMs: NaN })).toMatch( + /timeoutMs/, + ); + }); + + test("rejects a hot scenario with multiple shards", () => { + expect(validateConfig({ ...baseConfig, shards: 4 })).toMatch(/hot/); + }); + + test("bounds the shard count", () => { + expect(validateConfig({ ...baseConfig, shards: 0 })).toMatch(/shards/); + expect( + validateConfig({ + ...baseConfig, + scenario: "sharded", + shards: MAX_SHARDS + 1, + }), + ).toMatch(/shards/); + }); + + test("requires more than one shard for the sharded scenario", () => { + expect( + validateConfig({ ...baseConfig, scenario: "sharded", shards: 1 }), + ).toMatch(/sharded/); + }); + + test("rejects a fan-out wider than the scheduling limit allows", () => { + expect(validateConfig({ ...baseConfig, fanOut: 500 })).toMatch(/fanOut/); + }); + + test("requires an arrival rate for trickle", () => { + expect(validateConfig({ ...baseConfig, scenario: "trickle" })).toMatch( + /arrivalRatePerSec/, + ); + expect( + validateConfig({ + ...baseConfig, + scenario: "trickle", + arrivalRatePerSec: Infinity, + }), + ).toMatch(/arrivalRatePerSec/); + }); + + test("requires a burst count and interval for bursty", () => { + const bursty = { ...baseConfig, scenario: "bursty" as const }; + expect(validateConfig(bursty)).toMatch(/bursts/); + expect(validateConfig({ ...bursty, bursts: 1 })).toMatch(/bursts/); + expect(validateConfig({ ...bursty, bursts: 2.5 })).toMatch(/bursts/); + expect(validateConfig({ ...bursty, bursts: 4 })).toMatch(/burstIntervalMs/); + expect( + validateConfig({ ...bursty, bursts: 4, burstIntervalMs: 10 }), + ).toMatch(/burstIntervalMs/); + expect( + validateConfig({ ...bursty, bursts: 4, burstIntervalMs: 5_000 }), + ).toBeNull(); + }); + + test("rejects a burst schedule the watchdog would cut short", () => { + // Three bursts 30s apart put the last one at 60s, exactly the timeout. + expect( + validateConfig({ + ...baseConfig, + scenario: "bursty", + bursts: 3, + burstIntervalMs: 30_000, + }), + ).toMatch(/timeoutMs/); + }); +}); + +describe("classifyError", () => { + test("buckets a transaction limit on its own", () => { + // The eager path's ceiling on ops per transaction, not noise: 1000 eager + // inserts read past 16 MiB walking the btree and the job can't commit. + expect( + classifyError( + "Too many bytes read in a single function execution (limit: 16777216 bytes)", + ), + ).toBe("limit"); + expect(classifyError("Too many documents read")).toBe("limit"); + expect( + classifyError("Too many writes in a single function execution"), + ).toBe("limit"); + expect( + classifyError("Function execution exceeded the maximum size of 8MB"), + ).toBe("limit"); + expect(classifyError("Too many reads (limit: 4096)")).toBe("limit"); + }); + + test("recognizes the pending-ops guard the component actually throws", () => { + // The component throws code PENDING_OPERATIONS; there is no PENDING_COMMITS + // anywhere in it, so matching that name counted every guard failure as + // `other` and reported zero. + expect( + classifyError( + 'Uncaught ConvexError: {"code":"PENDING_OPERATIONS","message":"Cannot synchronously read or write to the aggregate while there are async updates enqueued."}', + ), + ).toBe("pendingOperations"); + }); + + test("recognizes a write conflict", () => { + expect( + classifyError("Documents read from or written to...write conflict"), + ).toBe("occSuspected"); + expect( + classifyError("Optimistic concurrency control failed on this mutation"), + ).toBe("occSuspected"); + expect(classifyError("Failed with OCC after 4 attempts")).toBe( + "occSuspected", + ); + }); + + test("does not read an OCC conflict into the word 'occurred'", () => { + expect(classifyError("Uncaught Error: an internal error occurred")).toBe( + "other", + ); + // And a limit error phrased that way still reaches the limit test, which + // runs after the OCC one. + expect( + classifyError("An error occurred: Too many documents read (limit: 4096)"), + ).toBe("limit"); + }); + + test("falls back to other", () => { + expect(classifyError("boom")).toBe("other"); + }); +}); + +describe("summarizeError", () => { + const raw = `Uncaught Error: Uncaught Error: Too many bytes read in a single function execution (limit: 16777216 bytes). Consider using smaller limits in your queries. + at async insertIntoNode (../../src/component/btree.ts:955:6) + at async insertHandler (../../src/component/btree.ts:67:12) +`; + + const advisory = `Uncaught Error: Uncaught Error: Too many bytes read in a single function execution (limit: 16777216 bytes). Consider using smaller limits in your queries, paginating your queries, or using indexed queries with a selective index range expression. See https://docs.convex.dev/production/state/limits for more details. + at async insertIntoNode (../../src/component/btree.ts:955:6) + at async insertHandler (../../src/component/btree.ts:67:12) +`; + + test("keeps the message and the frame that located it", () => { + const summary = summarizeError(raw, 200); + expect(summary).toContain("Too many bytes read"); + expect(summary).toContain("btree.ts:955"); + expect(summary).not.toContain("\n"); + expect(summary.length).toBeLessThanOrEqual(200); + }); + + test("truncates a long message rather than the frame", () => { + // The case the frame's separate budget exists for: a limit error whose advice + // paragraph would otherwise push the part that says *where* off the end. + const summary = summarizeError(advisory, 140); + expect(summary.length).toBeLessThanOrEqual(140); + expect(summary).toContain("Too many bytes read"); + expect(summary).toContain("…"); + expect(summary).not.toContain("paginating"); + // The whole frame survived; only the message paid for the budget. + expect(summary).toMatch( + /\(at async insertIntoNode \(\.\.\/\.\.\/src\/component\/btree\.ts:955:6\)\)$/, + ); + }); + + test("survives a budget too small for either part", () => { + // maxLength - 8 drives the frame's budget below the ellipsis, which the + // clamp has to handle by slicing rather than by producing a longer string. + const summary = summarizeError(advisory, 9); + expect(summary.length).toBeLessThanOrEqual(9); + expect(summarizeError(advisory, 0).length).toBeLessThanOrEqual(3); + }); + + test("survives an error with no stack", () => { + expect(summarizeError("plain failure")).toBe("plain failure"); + expect(summarizeError("")).toBe(""); + }); +}); + +describe("maxOverlap", () => { + test("returns 1 when execution was serial", () => { + expect( + maxOverlap([ + { start: 0, end: 10 }, + { start: 10, end: 20 }, + { start: 20, end: 30 }, + ]), + ).toBe(1); + }); + + test("counts fully concurrent jobs", () => { + expect( + maxOverlap([ + { start: 0, end: 10 }, + { start: 1, end: 9 }, + { start: 2, end: 8 }, + ]), + ).toBe(3); + }); + + test("ignores incomplete intervals", () => { + expect(maxOverlap([{ start: 0, end: NaN }])).toBe(0); + }); +}); + +describe("downsample", () => { + test("keeps short series untouched", () => { + expect(downsample([1, 2, 3], 10)).toEqual([1, 2, 3]); + }); + + test("keeps the first and last point", () => { + const out = downsample( + Array.from({ length: 1000 }, (_, i) => i), + 10, + ); + expect(out).toHaveLength(10); + expect(out[0]).toBe(0); + expect(out.at(-1)).toBe(999); + }); + + test("passes the series through when asked for fewer than two points", () => { + // Fewer than two can't keep both ends, and the stride would divide by zero. + const items = [1, 2, 3, 4]; + expect(downsample(items, 1)).toEqual(items); + expect(downsample(items, 0)).toEqual(items); + }); +}); + +describe("consistencyCurve", () => { + // A queued run: 40 ops accepted over four samples, then a drain. Each sample + // pairs the queue depth with the committed total from the same snapshot. + const queued = { + totalOps: 40, + startedAtMs: 1_000, + samples: [ + { atMs: 1_000, operations: 0, opsCommitted: 0 }, + { atMs: 1_250, operations: 10, opsCommitted: 10 }, + { atMs: 1_500, operations: 20, opsCommitted: 20 }, + { atMs: 1_750, operations: 30, opsCommitted: 30 }, + { atMs: 2_000, operations: 20, opsCommitted: 40 }, + { atMs: 2_250, operations: 0, opsCommitted: 40 }, + ], + }; + + test("reports the queue depth alongside the outstanding total", () => { + // The gap between the two is the work no writer has handed over yet, which + // is what separates "waiting on the writers" from "waiting on the worker". + const points = consistencyCurve(queued); + expect(points.map((p) => p.queued)).toEqual([0, 10, 20, 30, 20, 0]); + }); + + test("holds at the total while the queue absorbs the writes", () => { + const points = consistencyCurve(queued); + // Accepted but unapplied still counts as outstanding, so the curve holds at + // 40 through the enqueue phase and only falls as the worker drains. + expect(points.map((p) => p.outstanding)).toEqual([40, 40, 40, 40, 20, 0]); + expect(points.map((p) => p.elapsedMs)).toEqual([ + 0, 250, 500, 750, 1000, 1250, + ]); + }); + + test("declines through the enqueue phase when nothing queues", () => { + // The same commits with an empty queue: an eager run, which lands each op + // as its transaction commits. + const points = consistencyCurve({ + ...queued, + samples: queued.samples.map((s) => ({ ...s, operations: 0 })), + }); + expect(points.map((p) => p.outstanding)).toEqual([40, 30, 20, 10, 0, 0]); + }); + + test("never rises while the enqueue and the queue are read together", () => { + // Writers and the worker interleaving arbitrarily: every op that leaves + // "not yet asked for" enters the queue in the same snapshot, so the sum + // can only fall. + const samples = [ + { atMs: 0, operations: 0, opsCommitted: 0 }, + { atMs: 1, operations: 7, opsCommitted: 7 }, + { atMs: 2, operations: 3, opsCommitted: 12 }, + { atMs: 3, operations: 15, opsCommitted: 30 }, + { atMs: 4, operations: 2, opsCommitted: 33 }, + { atMs: 5, operations: 9, opsCommitted: 40 }, + { atMs: 6, operations: 0, opsCommitted: 40 }, + ]; + const points = consistencyCurve({ totalOps: 40, startedAtMs: 0, samples }); + const outstanding = points.map((p) => p.outstanding); + expect(outstanding).toEqual([40, 40, 31, 25, 9, 9, 0]); + for (let i = 1; i < outstanding.length; i++) { + expect(outstanding[i]).toBeLessThanOrEqual(outstanding[i - 1]); + } + }); + + test("clamps a sample whose terms fall outside the run", () => { + // A truncated queue read caps `operations` below the real depth, and a job + // retried after committing counts its ops twice: neither may push the curve + // outside [0, totalOps], and the queued line never draws above the curve. + const deep = consistencyCurve({ + totalOps: 40, + startedAtMs: 0, + samples: [{ atMs: 200, operations: 50, opsCommitted: 20 }], + }); + expect(deep[0]).toEqual({ elapsedMs: 200, outstanding: 40, queued: 40 }); + + const over = consistencyCurve({ + totalOps: 40, + startedAtMs: 0, + samples: [{ atMs: 200, operations: 5, opsCommitted: 50 }], + }); + expect(over[0]).toEqual({ elapsedMs: 200, outstanding: 0, queued: 0 }); + }); + + test("closes the curve at the end of the drain", () => { + const points = consistencyCurve({ ...queued, endedAtMs: 2_400 }); + expect(points.at(-1)).toEqual({ + elapsedMs: 1_400, + outstanding: 0, + queued: 0, + }); + }); + + test("ends where the run reached consistency, not where sampling stopped", () => { + // The sampler keeps ticking while the component's worker parks, and those + // samples aren't part of the run's span. Time also has to run forwards: the + // two timestamps come from different scheduled functions, so a sample can + // land after the end was stamped, and a curve doubling back draws a segment + // straight across the chart. + const points = consistencyCurve({ ...queued, endedAtMs: 1_900 }); + expect(points.at(-1)).toEqual({ + elapsedMs: 900, + outstanding: 0, + queued: 0, + }); + const elapsed = points.map((p) => p.elapsedMs); + expect([...elapsed].sort((a, b) => a - b)).toEqual(elapsed); + }); + + test("leaves an unfinished run short of zero", () => { + const points = consistencyCurve({ + totalOps: 40, + startedAtMs: 0, + samples: [{ atMs: 200, operations: 0, opsCommitted: 10 }], + }); + expect(points.at(-1)?.outstanding).toBe(30); + }); +}); diff --git a/example/convex/utils/benchMath.ts b/example/convex/utils/benchMath.ts new file mode 100644 index 00000000..c63d92a5 --- /dev/null +++ b/example/convex/utils/benchMath.ts @@ -0,0 +1,508 @@ +/** + * Pure helpers for the benchmark: histograms, lane and burst planning, config + * validation, error classification, downsampling. No Convex imports, so they're + * unit-testable on their own. + */ + +import type { BenchConfig, HistSummary } from "./benchTypes"; + +// ---- histogram ---- + +// Log-scale buckets from 0.5ms. Bucket 63's lower edge is ~27.5s (the notional +// top edge is 0.5·2^16 = 32.8s) and it is a catch-all for anything slower. +export const HIST_BUCKETS = 64; +const HIST_MIN_MS = 0.5; +const HIST_GROWTH = Math.pow(2, 0.25); // ~19% per bucket + +export type Hist = { + buckets: number[]; + count: number; + sum: number; + min: number; + max: number; +}; + +export function histInit(): Hist { + return { + buckets: new Array(HIST_BUCKETS).fill(0), + count: 0, + sum: 0, + min: Infinity, + max: -Infinity, + }; +} + +/** Bucket a value falls in, clamped to the histogram's range. */ +export function bucketIndex(valueMs: number): number { + if (valueMs <= HIST_MIN_MS) return 0; + const i = Math.floor(Math.log(valueMs / HIST_MIN_MS) / Math.log(HIST_GROWTH)); + return Math.min(Math.max(i, 0), HIST_BUCKETS - 1); +} + +/** Lower edge of a bucket, in ms. Exported for the chart's axis labels. */ +export function bucketLowerBound(i: number): number { + return i <= 0 ? 0 : HIST_MIN_MS * Math.pow(HIST_GROWTH, i); +} + +export function histAdd(h: Hist, valueMs: number): void { + if (!Number.isFinite(valueMs)) return; + // Negative inputs are clock skew between two scheduled functions, not data; + // they fold into bucket 0, which does drag `min` to 0. + const v = Math.max(valueMs, 0); + h.buckets[bucketIndex(v)]++; + h.count++; + h.sum += v; + if (v < h.min) h.min = v; + if (v > h.max) h.max = v; +} + +/** + * Quantile by linear interpolation within the containing bucket. Carries + * bucket-width error (~19%); count, sum, min and max stay exact. + */ +export function histQuantile(h: Hist, q: number): number { + if (h.count === 0) return 0; + const target = q * h.count; + let cumulative = 0; + for (let i = 0; i < h.buckets.length; i++) { + const n = h.buckets[i]; + if (n === 0) continue; + if (cumulative + n >= target) { + const lo = bucketLowerBound(i); + const hi = bucketLowerBound(i + 1); + const within = (target - cumulative) / n; + return Math.min(Math.max(lo + (hi - lo) * within, h.min), h.max); + } + cumulative += n; + } + return h.max; +} + +export function summarize(h: Hist): HistSummary { + if (h.count === 0) { + return { + count: 0, + mean: 0, + p50: 0, + p75: 0, + p90: 0, + p95: 0, + p99: 0, + min: 0, + max: 0, + buckets: h.buckets, + }; + } + return { + count: h.count, + mean: h.sum / h.count, + p50: histQuantile(h, 0.5), + p75: histQuantile(h, 0.75), + p90: histQuantile(h, 0.9), + p95: histQuantile(h, 0.95), + p99: histQuantile(h, 0.99), + min: h.min, + max: h.max, + buckets: h.buckets, + }; +} + +// ---- lane planning ---- + +export const MAX_FAN_OUT = 200; +export const MAX_TOTAL_OPS = 200_000; +export const MAX_SHARDS = 64; + +export type PlannedJob = { + seq: number; + shard: string; + /** First aggregate key this job writes; keys are keyBase..keyBase+ops-1. */ + keyBase: number; + ops: number; +}; + +export function totalWriteJobs(config: BenchConfig): number { + return Math.ceil(config.totalOps / config.opsPerMutation); +} + +/** + * Concurrent serial chains the write jobs are dealt across. Lane L runs seqs + * L, L + lanes, L + 2·lanes, … and each job schedules its own successor when it + * commits, so exactly this many write transactions are ever in flight. Without + * that bound, scheduling jobs without waiting for them put ~114 eager inserts on + * one btree root at fanOut 1 — `concurrency.achieved` reported 114 against 1. + */ +export function laneCount(config: BenchConfig): number { + return Math.max(1, Math.min(config.fanOut, totalWriteJobs(config))); +} + +/** + * Gap between one job in a lane and its successor. Trickle paces via scheduler + * delays because an in-mutation sleep is impossible and Date.now() is frozen; + * `lanes` lanes each firing every `lanes · slot` is the configured arrival rate, + * with service time a floor on it. + */ +export function laneDelayMs(config: BenchConfig): number { + return slotMs(config) * laneCount(config); +} + +/** Stagger applied to lane L when the lanes are seeded. */ +export function laneStartDelayMs(config: BenchConfig, lane: number): number { + return slotMs(config) * lane; +} + +function slotMs(config: BenchConfig): number { + return config.scenario === "trickle" && config.arrivalRatePerSec + ? 1000 / config.arrivalRatePerSec + : 0; +} + +// ---- burst planning ---- + +export const MAX_BURSTS = 32; +// A gap shorter than the queue sampler's cadence wouldn't be visible in the +// samples, so it would read as jitter rather than as a burst. +export const MIN_BURST_INTERVAL_MS = 250; + +/** Bursts the write jobs are dealt into. 1 outside the bursty scenario. */ +export function burstCount(config: BenchConfig): number { + return config.scenario === "bursty" ? Math.max(config.bursts ?? 1, 1) : 1; +} + +/** + * Write jobs in each burst. It's a ceiling, so trailing bursts can come out + * empty: 5 jobs over 4 bursts is 2/2/1/0, a run that performs three bursts while + * reporting `bursts: 4`. + */ +export function jobsPerBurst(config: BenchConfig): number { + return Math.ceil(totalWriteJobs(config) / burstCount(config)); +} + +/** + * The burst write job `seq` belongs to. Bursts are contiguous ranges of seqs, so + * a lane's jobs may straddle a boundary — or skip a burst entirely, when there + * are fewer jobs per burst than lanes. + */ +export function burstOfSeq(config: BenchConfig, seq: number): number { + return Math.min( + Math.floor(seq / jobsPerBurst(config)), + burstCount(config) - 1, + ); +} + +/** + * Ms after the run's t0 at which burst `b` is due to start. A grid anchored to + * the run, not a gap from when the previous burst finished, so both arms of a + * comparison see the identical arrival pattern and drifting lanes realign at the + * next burst. A burst that overruns therefore doesn't push its successor back; + * the consistency chart marks the grid, so an overrun reads as a curve that + * never comes back down between marks. + */ +export function burstStartMs(config: BenchConfig, burst: number): number { + return burst * (config.burstIntervalMs ?? 0); +} + +/** Every burst's due time, for marking the schedule on a chart. */ +export function burstStartsMs(config: BenchConfig): number[] { + return Array.from({ length: burstCount(config) }, (_, b) => + burstStartMs(config, b), + ); +} + +/** + * How long a lane must hold write job `seq` back to put it in its burst's slot, + * given the ms elapsed since the run's t0. Zero once the slot has arrived, so an + * overrunning burst is never delayed further. + */ +export function burstDelayMs( + config: BenchConfig, + seq: number, + elapsedMs: number, +): number { + if (config.scenario !== "bursty") return 0; + return Math.max(burstStartMs(config, burstOfSeq(config, seq)) - elapsedMs, 0); +} + +/** + * Plan write job `seq`, or null once the run has no more. Deterministic in + * (config, seq), so a lane carries no state beyond the seq it is on. The key + * ranges are contiguous and disjoint, so a finished run holds exactly totalOps + * distinct keys. + */ +export function planWriteJob( + config: BenchConfig, + seq: number, +): PlannedJob | null { + if (seq < 0 || seq >= totalWriteJobs(config)) return null; + const opsRemaining = config.totalOps - seq * config.opsPerMutation; + return { + seq, + shard: shardName(config, seq), + keyBase: seq * config.opsPerMutation, + ops: Math.min(config.opsPerMutation, opsRemaining), + }; +} + +export function shardName(config: BenchConfig, i: number): string { + return config.shards <= 1 ? "hot" : `shard-${i % config.shards}`; +} + +export function allShards(config: BenchConfig): string[] { + if (config.shards <= 1) return ["hot"]; + return Array.from({ length: config.shards }, (_, i) => `shard-${i}`); +} + +// ---- config validation ---- + +/** + * The trust boundary for `startRun`, a public mutation. Counts must be whole as + * well as in range: a fractional `fanOut` or `shards` reaches arithmetic that + * assumes integers (lane striding, shard naming, key ranges) and silently yields + * overlapping jobs and negative failure counts instead of an error. + */ +export function validateConfig(config: BenchConfig): string | null { + if ( + !Number.isInteger(config.totalOps) || + config.totalOps < 1 || + config.totalOps > MAX_TOTAL_OPS + ) { + return `totalOps must be a whole number between 1 and ${MAX_TOTAL_OPS}`; + } + // Unbounded above on purpose: where eager stops working is a property of bytes + // and tree depth, not of a count worth freezing here, and an over-large job + // fails visibly. The floor is structural — `totalWriteJobs` divides by this. + if (!Number.isInteger(config.opsPerMutation) || config.opsPerMutation < 1) { + return "opsPerMutation must be a whole number of at least 1"; + } + if ( + !Number.isInteger(config.fanOut) || + config.fanOut < 1 || + config.fanOut > MAX_FAN_OUT + ) { + // Lanes are seeded in one transaction, which can schedule at most 1000 + // functions; stay well under. + return `fanOut must be a whole number between 1 and ${MAX_FAN_OUT}`; + } + if ( + !Number.isInteger(config.shards) || + config.shards < 1 || + config.shards > MAX_SHARDS + ) { + return `shards must be a whole number between 1 and ${MAX_SHARDS}`; + } + if (!Number.isFinite(config.timeoutMs) || config.timeoutMs < 1) { + return "timeoutMs must be a positive number"; + } + if (config.scenario === "hot" && config.shards !== 1) { + return "the hot scenario requires shards === 1"; + } + if (config.scenario === "sharded" && config.shards < 2) { + return "the sharded scenario requires shards >= 2"; + } + if (config.scenario === "trickle") { + if ( + !config.arrivalRatePerSec || + !Number.isFinite(config.arrivalRatePerSec) || + config.arrivalRatePerSec <= 0 + ) { + return "the trickle scenario requires a positive arrivalRatePerSec"; + } + } + if (config.scenario === "bursty") { + if ( + !config.bursts || + !Number.isInteger(config.bursts) || + config.bursts < 2 || + config.bursts > MAX_BURSTS + ) { + return `the bursty scenario requires a whole number of bursts between 2 and ${MAX_BURSTS}`; + } + if ( + !config.burstIntervalMs || + !Number.isFinite(config.burstIntervalMs) || + config.burstIntervalMs < MIN_BURST_INTERVAL_MS + ) { + return `the bursty scenario requires burstIntervalMs of at least ${MIN_BURST_INTERVAL_MS}`; + } + // The watchdog measures from t0, so a schedule that outlasts the timeout + // would be cut off partway through: the last bursts would never run and the + // run would report ops that never landed. + if (burstStartMs(config, config.bursts - 1) >= config.timeoutMs) { + return `the burst schedule (${burstStartMs(config, config.bursts - 1)}ms to the last burst) must fit inside timeoutMs`; + } + } + return null; +} + +// ---- error classification ---- + +export type ErrorClass = + "pendingOperations" | "occSuspected" | "limit" | "other"; + +// Bare "occ" needs word boundaries: "an internal error occurred" contains it, +// and matching that would file most unrelated failures as OCC conflicts. +const OCC_PATTERN = /write conflict|optimistic concurrency|\bocc\b/; + +/** + * Best-effort bucketing of a scheduled function's error string. OCC conflicts the + * platform retries *successfully* are invisible to the app, so this undercounts; + * `jobQueueMs` is the proxy for retry pressure. + * + * `limit` isn't noise, it's the result: an eager job walks the btree once per op, + * so past some transaction size it reads past the 16 MiB limit and can't commit, + * while the queued path just appends a row. + */ +export function classifyError(error: string): ErrorClass { + // The component's guard throws ConvexError({ code: "PENDING_OPERATIONS" }). + if (error.includes("PENDING_OPERATIONS")) return "pendingOperations"; + const lowered = error.toLowerCase(); + if (OCC_PATTERN.test(lowered)) return "occSuspected"; + if ( + lowered.includes("too many bytes") || + lowered.includes("too many documents") || + lowered.includes("too many reads") || + lowered.includes("too many writes") || + lowered.includes("(limit:") || + lowered.includes("exceeded the maximum") + ) { + return "limit"; + } + return "other"; +} + +/** + * The readable part of a scheduled function's error: its message and the first + * frame that located it, the raw string being a full stack trace through the + * client and the component. The frame gets its own budget rather than whatever + * the message leaves over, because platform limit errors carry a paragraph of + * advice that would otherwise push the part saying *where* off the end. + */ +export function summarizeError(error: string, maxLength = 240): string { + const lines = error.split("\n").map((line) => line.trim()); + // Errors that crossed a component boundary arrive with the prefix repeated. + const message = (lines.find((line) => line.length > 0) ?? "").replace( + /^(uncaught error:\s*)+/i, + "", + ); + const frame = lines.find((line) => line.startsWith("at ")); + if (!frame) return clamp(message, maxLength); + const located = `(${clamp(frame, Math.min(96, maxLength - 8))})`; + return `${clamp(message, maxLength - located.length - 1)} ${located}`; +} + +function clamp(text: string, maxLength: number): string { + if (maxLength <= 1) return text.slice(0, Math.max(maxLength, 0)); + return text.length > maxLength ? `${text.slice(0, maxLength - 1)}…` : text; +} + +// ---- misc ---- + +/** + * Max number of jobs whose [scheduledTime, completedTime] intervals overlap. + * If this comes back ~1 the scheduler ran the fan-out serially and any + * contention conclusion from the run is void. + */ +export function maxOverlap( + intervals: Array<{ start: number; end: number }>, +): number { + const events: Array<[number, number]> = []; + for (const { start, end } of intervals) { + if (!Number.isFinite(start) || !Number.isFinite(end)) continue; + events.push([start, 1], [Math.max(end, start), -1]); + } + // Ends before starts at equal timestamps, so touching intervals don't count + // as overlapping. + events.sort((a, b) => a[0] - b[0] || a[1] - b[1]); + let current = 0; + let peak = 0; + for (const [, delta] of events) { + current += delta; + if (current > peak) peak = current; + } + return peak; +} + +// ---- consistency curve ---- + +export type ConsistencyPoint = { + elapsedMs: number; + outstanding: number; + /** + * Of the outstanding operations, the ones sitting in the queue. Zero for an + * eager run; for a queued run the gap to `outstanding` separates "not yet + * asked for" from "asked for, not yet applied". + */ + queued: number; +}; + +/** Points the stored curve is downsampled to; roughly the chart's pixel width. */ +export const MAX_CURVE_POINTS = 300; + +/** + * Operations accepted but not yet applied to the aggregate, at each queue sample. + * + * Each sample's `opsCommitted` and `operations` must come from one snapshot: the + * ops a job enqueued and the row recording that job commit together, so a + * snapshot sees both or neither, and `totalOps - opsCommitted + operations` is + * then exactly "not yet asked for" plus "asked for, not yet applied". Read from + * two snapshots the terms disagree by whatever committed in between and the + * curve wobbles back up after every dip. + * + * `samples` must be sorted by `atMs`. `endedAtMs` is when the run reached + * consistency — it closes the curve and cuts it off there, since the sampler + * goes on ticking while the component's worker parks. Pass it only for a run + * that got there. + */ +export function consistencyCurve({ + totalOps, + startedAtMs, + endedAtMs, + samples, +}: { + totalOps: number; + startedAtMs: number; + endedAtMs?: number; + samples: Array<{ atMs: number; operations: number; opsCommitted: number }>; +}): ConsistencyPoint[] { + const points: ConsistencyPoint[] = []; + for (const sample of samples) { + // Samples after the run reached consistency describe the worker winding + // down, not the run; they'd stretch the curve past the moment it finished, + // which is the one thing its width is supposed to say. + if (endedAtMs !== undefined && sample.atMs > endedAtMs) break; + // A committed op is applied in an eager run and merely accepted in a queued + // one, so the ops sitting in the queue are added back. Clamped to + // [0, totalOps]: a truncated queue read or a job retried after committing + // can put the raw figure outside it. + const outstanding = Math.min( + totalOps, + Math.max(totalOps - sample.opsCommitted + sample.operations, 0), + ); + points.push({ + elapsedMs: Math.max(sample.atMs - startedAtMs, 0), + outstanding, + // Can't exceed the outstanding total it's a part of. + queued: Math.min(sample.operations, outstanding), + }); + } + if (endedAtMs !== undefined) { + const last = points[points.length - 1]?.elapsedMs ?? 0; + points.push({ + elapsedMs: Math.max(endedAtMs - startedAtMs, last), + outstanding: 0, + queued: 0, + }); + } + return points; +} + +/** Evenly strided downsample that always keeps the first and last point. */ +export function downsample(items: T[], maxPoints: number): T[] { + if (items.length <= maxPoints || maxPoints < 2) return items; + const stride = (items.length - 1) / (maxPoints - 1); + const out: T[] = []; + for (let i = 0; i < maxPoints; i++) { + out.push(items[Math.round(i * stride)]); + } + return out; +} diff --git a/example/convex/utils/benchTypes.ts b/example/convex/utils/benchTypes.ts new file mode 100644 index 00000000..7b14064c --- /dev/null +++ b/example/convex/utils/benchTypes.ts @@ -0,0 +1,197 @@ +import { type Infer, v } from "convex/values"; + +const vBenchMode = v.union(v.literal("eager"), v.literal("async")); +export type BenchMode = Infer; + +/** + * How a queued job hands its operations to the component: one `enqueue` call per + * operation, or a single `enqueueBatch` call carrying all of them. + */ +export const vWriteApi = v.union(v.literal("perOp"), v.literal("batch")); + +const vBenchScenario = v.union( + v.literal("hot"), + v.literal("sharded"), + v.literal("trickle"), + v.literal("bursty"), +); + +export const vRunStatus = v.union( + v.literal("pending"), + v.literal("preparing"), + v.literal("enqueuing"), + v.literal("draining"), + v.literal("finalizing"), + v.literal("done"), + v.literal("failed"), + v.literal("canceled"), +); + +export const vBenchConfig = v.object({ + mode: vBenchMode, + scenario: vBenchScenario, + /** Total aggregate operations the run will attempt. */ + totalOps: v.number(), + /** Aggregate writes per job transaction. */ + opsPerMutation: v.number(), + /** + * Which enqueue API a job uses. Queued runs only — there is no eager batch + * API, so an eager job ignores this and always writes per operation. Absent + * means "perOp", so runs recorded before the option existed still read back. + */ + writeApi: v.optional(vWriteApi), + /** + * Concurrent write transactions. The jobs are dealt across this many serial + * lanes, so it's a hard bound on in-flight work: 1 runs them strictly one + * after another. See `laneCount`. + */ + fanOut: v.number(), + /** Namespaces to spread writes across. 1 for the "hot" scenario. */ + shards: v.number(), + /** trickle: arrival rate. */ + arrivalRatePerSec: v.optional(v.number()), + /** + * bursty: how many bursts the writes are dealt into, and how far apart the + * bursts start. See `burstStartMs` for what the interval means. + */ + bursts: v.optional(v.number()), + burstIntervalMs: v.optional(v.number()), + maxNodeSize: v.optional(v.number()), + rootLazy: v.optional(v.boolean()), + /** Watchdog: fail the run if it exceeds this. */ + timeoutMs: v.number(), +}); +export type BenchConfig = Infer; + +const vHistSummary = v.object({ + count: v.number(), + mean: v.number(), + p50: v.number(), + p75: v.number(), + p90: v.number(), + p95: v.number(), + p99: v.number(), + min: v.number(), + max: v.number(), + /** Log-scale bucket counts, for the histogram chart. */ + buckets: v.array(v.number()), +}); +export type HistSummary = Infer; + +export const vBenchResults = v.object({ + ops: v.object({ + attempted: v.number(), + committed: v.number(), + failed: v.number(), + }), + jobs: v.object({ + total: v.number(), + succeeded: v.number(), + failed: v.number(), + canceled: v.number(), + }), + latency: v.object({ + /** completedTime - scheduledTime: queue wait + retries + execution. */ + jobLatency: vHistSummary, + /** completedTime - startedAtMs: the final attempt's execution only. */ + jobService: vHistSummary, + /** startedAtMs - scheduledTime: wait + retry time. OCC-pressure proxy. */ + jobQueue: vHistSummary, + perOpServiceMs: v.number(), + }), + /** Clock-free work per op, from getTransactionMetrics(). */ + work: v.object({ + documentsReadPerOp: v.number(), + documentsWrittenPerOp: v.number(), + bytesReadPerOp: v.number(), + bytesWrittenPerOp: v.number(), + databaseQueriesPerOp: v.number(), + }), + throughput: v.object({ + enqueueOpsPerSec: v.number(), + /** Async only: includes the drain. The number that makes async honest. */ + applyOpsPerSec: v.optional(v.number()), + }), + drain: v.object({ + /** + * Time from the last write being accepted to the queue being empty. For a + * queued run this is a tail, not a phase: the worker applies throughout the + * enqueue, so this is only what was left over at the end. + */ + timeToDrainMs: v.optional(v.number()), + /** + * Sampling resolution of timeToDrainMs. Zero for an eager run, whose end is + * the scheduler's clock rather than a watch tick. + */ + resolutionMs: v.number(), + /** True if the drain took longer than the worker's monitor lag. */ + exceededMonitorLag: v.boolean(), + /** + * Time the component's worker went on reporting itself as running after the + * queue was empty. Not part of time-to-consistency — the data had already + * landed — but the run does wait for it before releasing the aggregate. + */ + workerParkMs: v.optional(v.number()), + }), + queue: v.object({ + peakRows: v.number(), + peakOperations: v.number(), + peakBytes: v.number(), + /** Peaks are lower bounds when true. */ + peakTruncated: v.boolean(), + samples: v.number(), + }), + concurrency: v.object({ + /** Max overlap of [scheduledTime, completedTime] across jobs. */ + achieved: v.number(), + offered: v.number(), + }), + errors: v.object({ + occSuspected: v.number(), + pendingOperations: v.number(), + /** + * Jobs that couldn't commit at all because the transaction hit a platform + * limit — the eager path's ceiling on ops per transaction. Absent on runs + * recorded before the class existed, which counted these as `other`. + */ + limit: v.optional(v.number()), + other: v.number(), + /** One line each: message plus the frame that located it. */ + samples: v.array(v.string()), + }), + /** + * Operations not yet applied to the aggregate, over the run, built at finalize + * time from the queue samples — see `consistencyCurve`. Absent on runs + * recorded before it was stored, which the chart query builds from the + * samples on the fly. + */ + consistency: v.optional( + v.array( + v.object({ + elapsedMs: v.number(), + outstanding: v.number(), + /** + * The part of `outstanding` sitting in the queue. Always written; zero + * for an eager run, which queues nothing. + */ + queued: v.number(), + }), + ), + ), +}); +export type BenchResults = Infer; + +export const vPendingOperationsStats = v.object({ + rows: v.number(), + operations: v.number(), + bytes: v.number(), + truncated: v.boolean(), + oldestCommitTs: v.union(v.int64(), v.null()), + newestObservedCommitTs: v.union(v.int64(), v.null()), + worker: v.union( + v.literal("idle"), + v.literal("running"), + v.literal("stopped"), + v.null(), + ), +}); diff --git a/example/src/App.tsx b/example/src/App.tsx index d3a03d92..18f19928 100644 --- a/example/src/App.tsx +++ b/example/src/App.tsx @@ -4,6 +4,7 @@ import { PhotosPage } from "./pages/photos/PhotosPage"; import { ShufflePage } from "./pages/shuffle/ShufflePage"; import { StatsPage } from "./pages/stats/StatsPage"; import { BTreePage } from "./pages/btree/BTreePage"; +import { BenchPage } from "./pages/bench/BenchPage"; import { useRoute } from "./routes"; import { exhaustiveCheck } from "./utils/utils"; @@ -16,6 +17,7 @@ export default function App() { if (route.name === "shuffle") return ; if (route.name === "stats") return ; if (route.name === "btree") return ; + if (route.name === "bench") return ; if (route.name == false) return ; diff --git a/example/src/common/Navbar.tsx b/example/src/common/Navbar.tsx index 12a387f7..9a19c7a3 100644 --- a/example/src/common/Navbar.tsx +++ b/example/src/common/Navbar.tsx @@ -6,6 +6,7 @@ import { IconArrowsShuffle, IconChartPie, IconBinaryTree, + IconGauge, } from "@tabler/icons-react"; import { routes, useRoute } from "../routes"; @@ -55,6 +56,13 @@ export function Navbar() { onClick={() => routes.btree().push()} c="white" /> + } + active={route.name === "bench"} + onClick={() => routes.bench().push()} + c="white" + /> ); } diff --git a/example/src/common/PageHeader.tsx b/example/src/common/PageHeader.tsx index d19903e1..fbfc8c66 100644 --- a/example/src/common/PageHeader.tsx +++ b/example/src/common/PageHeader.tsx @@ -4,7 +4,7 @@ import { CodeLinkButton } from "./CodeLinkButton"; interface PageHeaderProps { title: string; - description: string; + description?: string; icon: ReactNode; filename: string; } @@ -24,9 +24,11 @@ export function PageHeader({ - - {description} - + {description && ( + + {description} + + )} ); diff --git a/example/src/pages/bench/BenchControls.tsx b/example/src/pages/bench/BenchControls.tsx new file mode 100644 index 00000000..49f63ff0 --- /dev/null +++ b/example/src/pages/bench/BenchControls.tsx @@ -0,0 +1,367 @@ +import { + Button, + Card, + Group, + NumberInput, + Progress, + Select, + Stack, + Text, +} from "@mantine/core"; +import { IconPlayerPlay, IconPlayerStop } from "@tabler/icons-react"; +import { MODE_COLOR } from "./charts/chartTheme"; +import { formatSeconds } from "./charts/scale"; +import { + MAX_BURSTS, + MAX_FAN_OUT, + MAX_SHARDS, + MAX_TOTAL_OPS, + MIN_BURST_INTERVAL_MS, +} from "../../../convex/utils/benchMath"; +import { + MAX_REPEATS, + modeLabel, + phaseLabel, + timeToConsistencyMs, + scenarioMeta, + SCENARIOS, + suiteLabel, + suiteProgress, + type BenchRun, + type BenchScenario, + type BenchSuite, +} from "./benchTypes"; +import type { Id } from "../../../convex/_generated/dataModel"; + +const inputStyles = { + label: { color: "white" }, + input: { backgroundColor: "var(--mantine-color-dark-4)" }, +} as const; + +export type BenchControlsProps = { + config: BenchRun["config"]; + onChange: (config: BenchRun["config"]) => void; + repeats: number; + onRepeatsChange: (repeats: number) => void; + onRun: () => void; + onStop: () => void; + isStarting: boolean; + /** The run in flight, if any. Progress is shown here rather than elsewhere. */ + activeRun: BenchRun | null; + activeSuite: BenchSuite | null; + /** Past comparisons, newest first, named by the parameters that produced them. */ + suites: BenchSuite[]; + selectedSuiteId: Id<"benchSuites"> | null; + onSelectSuite: (suiteId: Id<"benchSuites">) => void; + /** Non-zero means a new comparison will be refused until the worker drains. */ + pendingOps: number; +}; + +/** + * Everything you can change, and everything happening right now, in one strip. + * + * There is no separate monitor: a comparison takes a handful of seconds, so its + * progress belongs beside the button that started it rather than behind a tab + * you have to go and find. When nothing is running the strip is just the + * parameters and a picker for past results. + */ +export function BenchControls({ + config, + onChange, + repeats, + onRepeatsChange, + onRun, + onStop, + isStarting, + activeRun, + activeSuite, + suites, + selectedSuiteId, + onSelectSuite, + pendingOps, +}: BenchControlsProps) { + const meta = scenarioMeta(config.scenario); + const busy = activeSuite !== null; + + const setScenario = (scenario: BenchScenario) => { + const next = scenarioMeta(scenario); + onChange({ + ...config, + scenario, + shards: 1, + arrivalRatePerSec: undefined, + bursts: undefined, + burstIntervalMs: undefined, + ...next.defaults, + }); + }; + + return ( + + + + + { + const { done, total } = suiteProgress(s); + return { + value: s._id, + label: + done === total + ? suiteLabel(s) + : `${suiteLabel(s)} — ${done}/${total}`, + }; + })} + value={selectedSuiteId} + onChange={(value) => + value && onSelectSuite(value as Id<"benchSuites">) + } + allowDeselect={false} + size="sm" + maw={560} + styles={inputStyles} + /> + ) + )} + + {pendingOps > 0 && !busy && ( + + {pendingOps} operation(s) still queued — a comparison will be + refused until the worker drains. An eager write would throw + PENDING_OPERATIONS, and a queued one would measure this backlog. + + )} + + + ); +} + +/** + * What's happening, while it happens: which side is running, its phase, the ops + * it has landed, its elapsed time to consistency, and how far through the suite's + * schedule it is. + */ +function LiveStrip({ + activeRun, + activeSuite, +}: { + activeRun: BenchRun | null; + activeSuite: BenchSuite; +}) { + const { done, total } = suiteProgress(activeSuite); + const totalMs = activeRun ? timeToConsistencyMs(activeRun) : 0; + const committed = activeRun?.progress.opsCommitted ?? 0; + const attempted = activeRun?.config.totalOps ?? 0; + + return ( + + + +
+ + {activeRun ? modeLabel(activeRun.config.mode) : "Starting"} + + + + {activeRun ? phaseLabel(activeRun.status) : "…"} + + + {committed}/{attempted} ops + + + {formatSeconds(totalMs)} + + + run {Math.min(done + 1, total)} of {total} + + + + + ); +} + +function Param({ + label, + value, + min, + max, + step, + onChange, +}: { + label: string; + value: number; + min: number; + /** Omit where there is no ceiling worth enforcing. */ + max?: number; + step?: number; + onChange: (value: number) => void; +}) { + return ( + + { + const parsed = + typeof next === "number" ? next : Number.parseFloat(next); + if (Number.isFinite(parsed)) onChange(parsed); + }} + min={min} + max={max} + step={step} + allowDecimal={false} + size="sm" + styles={inputStyles} + /> + + ); +} diff --git a/example/src/pages/bench/BenchPage.tsx b/example/src/pages/bench/BenchPage.tsx new file mode 100644 index 00000000..be0b54c5 --- /dev/null +++ b/example/src/pages/bench/BenchPage.tsx @@ -0,0 +1,104 @@ +import { Container, Stack } from "@mantine/core"; +import { IconGauge } from "@tabler/icons-react"; +import { useMemo, useState } from "react"; +import { CommonAppShell } from "@/common/CommonAppShell"; +import { PageHeader } from "../../common/PageHeader"; +import type { Id } from "../../../convex/_generated/dataModel"; +import { BenchControls } from "./BenchControls"; +import { ComparisonSection } from "./ComparisonSection"; +import { LatencySection } from "./LatencySection"; +import { ConsistencySection } from "./ConsistencySection"; +import { FailureNotice } from "./FailureNotice"; +import { useBenchRun } from "./useBenchRun"; +import { cellStats } from "./suiteStats"; +import { burstStartsMs } from "../../../convex/utils/benchMath"; +import { + DEFAULT_CONFIG, + DEFAULT_REPEATS, + MODES, + modeLabel, + modeRuns, + type BenchRun, +} from "./benchTypes"; + +export function BenchPage() { + const [config, setConfig] = useState(DEFAULT_CONFIG); + const [repeats, setRepeats] = useState(DEFAULT_REPEATS); + const [selectedSuiteId, setSelectedSuiteId] = + useState | null>(null); + + const { + canStart, + runs, + suites, + run, + consistencySeries, + selectedSuite, + startSuite, + cancelSuite, + isStarting, + } = useBenchRun(selectedSuiteId); + + // Queued first, eager second, everywhere on the page. + const cells = useMemo(() => { + if (!selectedSuite) return []; + return MODES.map((mode) => cellStats(mode, modeRuns(runs, mode))); + }, [selectedSuite, runs]); + + const activeSuite = suites.find((s) => s.status === "running") ?? null; + + return ( + + + + } + filename="bench.ts" + /> + + { + void startSuite(config, repeats).then((result) => { + if (result?.ok) setSelectedSuiteId(result.suiteId); + }); + }} + onStop={() => { + if (activeSuite) void cancelSuite(activeSuite._id); + }} + isStarting={isStarting} + activeRun={run} + activeSuite={activeSuite} + suites={suites} + selectedSuiteId={selectedSuite?._id ?? null} + onSelectSuite={setSelectedSuiteId} + pendingOps={canStart?.queue.operations ?? 0} + /> + + {/* Above the charts: a run that lost work invalidates the numbers + below it. */} + + + ({ + ...s, + label: modeLabel(s.mode), + }))} + cells={cells} + burstMarksMs={ + selectedSuite ? burstStartsMs(selectedSuite.config) : [] + } + /> + + + + + + + + ); +} diff --git a/example/src/pages/bench/ComparisonSection.tsx b/example/src/pages/bench/ComparisonSection.tsx new file mode 100644 index 00000000..f8c38038 --- /dev/null +++ b/example/src/pages/bench/ComparisonSection.tsx @@ -0,0 +1,110 @@ +import { Card, Stack, Text } from "@mantine/core"; +import { + GroupedBarChart, + type BarSeries, + type BarValue, +} from "./charts/GroupedBarChart"; +import { SectionHeading } from "./SectionHeading"; +import { formatMs, formatRate } from "./charts/scale"; +import type { CellStats, Spread } from "./suiteStats"; + +/** + * Each mode against itself. A queued write's latency is the time to accept it + * into the queue and an eager write's is the time to apply it, so p50 queued + * beside p50 eager compares two different events; the same goes for the rate + * writers saw. Grouping by mode puts a mode's percentiles together, where the + * shape of each is what there is to read, and keeps the modes off a shared bar. + * + * Faceted by unit — latency in ms, throughput in ops/s. Never one chart mixing + * them. Bars are medians over the suite's repeats with min–max whiskers. + */ +/** Shared by every facet, so all bars rise from the same baseline. */ +const SERIES_LABEL_WIDTH = 124; + +export function ComparisonSection({ cells }: { cells: CellStats[] }) { + const order = cells.filter((c) => c.n > 0); + if (order.length === 0) return null; + + // One group per mode; the series repeat inside each and take the mode's color. + const byMode = ( + picks: { label: string; pick: (cell: CellStats) => Spread | null }[], + ): BarSeries[] => + picks.map(({ label, pick }) => ({ + label, + color: "transparent", + values: order.map((cell) => toBarValue(pick(cell), cell.color)), + })); + + return ( + + + + + c.label)} + series={byMode([ + { label: "p50", pick: (c) => c.p50 }, + { label: "p95", pick: (c) => c.p95 }, + { label: "p99", pick: (c) => c.p99 }, + ])} + format={formatMs} + /> + + {/* Two observers of one run, not two phases: the rate a writer saw, and + the rate the aggregate actually became consistent at. For queued + writes the gap between them is the whole trade being measured; for + eager writes the two coincide. */} + c.label)} + series={byMode([ + { label: "as seen by writers", pick: (c) => c.enqueueOpsPerSec }, + { label: "to consistency", pick: (c) => c.applyOpsPerSec }, + ])} + format={formatRate} + /> + + + ); +} + +function toBarValue(spread: Spread | null, color: string): BarValue | null { + if (!spread) return null; + return spread.n > 1 + ? { value: spread.median, low: spread.min, high: spread.max, color } + : { value: spread.median, color }; +} + +function Facet({ + title, + groups, + series, + format, +}: { + title: string; + groups: string[]; + series: BarSeries[]; + format: (v: number) => string; +}) { + return ( + + + {title} + + + + ); +} diff --git a/example/src/pages/bench/ConsistencySection.tsx b/example/src/pages/bench/ConsistencySection.tsx new file mode 100644 index 00000000..5cd66227 --- /dev/null +++ b/example/src/pages/bench/ConsistencySection.tsx @@ -0,0 +1,88 @@ +import { Card, Divider, Stack, Text } from "@mantine/core"; +import { ChartLegend, type LegendItem } from "./charts/ChartLegend"; +import { + ConsistencyChart, + type ConsistencySeries, +} from "./charts/ConsistencyChart"; +import { INK, MODE_COLOR } from "./charts/chartTheme"; +import { MODES } from "./benchTypes"; +import { SectionHeading } from "./SectionHeading"; +import { TimeToConsistency } from "./TimeToConsistency"; +import type { CellStats } from "./suiteStats"; + +/** + * The page's main exhibit: operations not yet applied, over time, both modes on + * one axis. It's the one quantity that means the same thing in both modes, so it + * is the one place they are compared directly — the time-to-consistency readout + * beneath it is the width of the curves as a figure. + */ +export function ConsistencySection({ + series, + cells, + burstMarksMs = [], +}: { + series: ConsistencySeries[]; + /** Queued first, eager second. */ + cells: CellStats[]; + /** When the workload's bursts were due, if the scenario has any. */ + burstMarksMs?: number[]; +}) { + const drawable = series.filter((s) => s.points.length > 0); + const hasQueue = drawable.some((s) => s.points.some((p) => p.queued > 0)); + // One entry per mode however many repeats there are — colour is the mode. A + // queued run's dashed queue line is filed under its mode, not as a third + // series. + const legend: LegendItem[] = []; + for (const mode of MODES) { + const group = drawable.filter((s) => s.mode === mode); + if (group.length === 0) continue; + legend.push({ + label: + group.length > 1 + ? `${group[0].label} · ${group.length} runs` + : group[0].label, + color: MODE_COLOR[mode], + shape: "line", + group: mode, + }); + // Only when there's a queue to explain — otherwise the entry names a line + // that never appears. + if (mode === "async" && hasQueue) { + legend.push({ + label: "in queue", + color: MODE_COLOR.async, + shape: "dashedLine", + group: mode, + }); + } + } + if (burstMarksMs.some((t) => t > 0)) { + legend.push({ label: "burst due", color: INK.muted, shape: "dashedLine" }); + } + + return ( + + + 0 ? : undefined} + /> + {drawable.length === 0 ? ( + + {cells.length === 0 + ? "Run a comparison to populate this chart." + : "No samples yet."} + + ) : ( + + )} + {cells.some((cell) => cell.totalMs !== null) && ( + <> + + + + )} + + + ); +} diff --git a/example/src/pages/bench/FailureNotice.tsx b/example/src/pages/bench/FailureNotice.tsx new file mode 100644 index 00000000..cca7a501 --- /dev/null +++ b/example/src/pages/bench/FailureNotice.tsx @@ -0,0 +1,94 @@ +import { Card, Group, Stack, Text } from "@mantine/core"; +import { IconAlertTriangle } from "@tabler/icons-react"; +import { isComplete, modeLabel, type BenchRun } from "./benchTypes"; +import { formatCount } from "./charts/scale"; +import { SectionHeading } from "./SectionHeading"; + +/** + * Runs that didn't land all their operations, and so aren't in any of the numbers + * below. + * + * They are excluded from the medians rather than averaged in: a run that lost work + * measured a smaller workload, not a noisier sample of the configured one. Naming + * them here keeps a suite from quietly reporting fewer repeats than it ran. + */ +export function FailureNotice({ runs }: { runs: BenchRun[] }) { + const failures = runs.flatMap((run) => { + const results = run.results; + if (!results || isComplete(run)) return []; + return [ + { run, results, missing: results.ops.attempted - results.ops.committed }, + ]; + }); + if (failures.length === 0) return null; + + return ( + + + + + + {failures.length === 1 + ? "1 run excluded from the stats below" + : `${failures.length} runs excluded from the stats below`} + + + } + /> + + {failures.map(({ run, results, missing }) => ( + + + + {modeLabel(run.config.mode)} + {run.repeatIndex !== undefined + ? ` · repeat ${run.repeatIndex + 1}` + : ""} + + + {formatCount(missing)} of {formatCount(results.ops.attempted)}{" "} + ops never landed + + + {results.jobs.failed} of {results.jobs.total} jobs failed + {cause(results)} + + + {results.errors.samples[0] && ( + + {results.errors.samples[0]} + + )} + + ))} + + + + ); +} + +/** The dominant error class, named the way the reader can act on it. */ +function cause(results: NonNullable): string { + const { errors } = results; + const limit = errors.limit ?? 0; + if (limit > 0) { + return " · transaction limit exceeded, so the ops per transaction is too high for this mode"; + } + if (errors.pendingOperations > 0) return " · PENDING_OPERATIONS"; + if (errors.occSuspected > 0) return " · write conflicts"; + return ""; +} diff --git a/example/src/pages/bench/LatencySection.tsx b/example/src/pages/bench/LatencySection.tsx new file mode 100644 index 00000000..e02fc165 --- /dev/null +++ b/example/src/pages/bench/LatencySection.tsx @@ -0,0 +1,79 @@ +import { Card, Group, Stack, Text } from "@mantine/core"; +import { LatencyHistogram } from "./charts/LatencyHistogram"; +import { SectionHeading } from "./SectionHeading"; +import { bucketExtent } from "./charts/histBuckets"; +import { formatCount } from "./charts/scale"; +import type { CellStats } from "./suiteStats"; + +/** + * Small multiples over a shared x-domain rather than overlaid — overlapping + * distributions are unreadable, and a shared domain makes the shift between them + * obvious. + * + * Each histogram pools every repeat's buckets, so it shows the shape of the whole + * sample rather than of whichever single run happened to be selected. + */ +export function LatencySection({ cells }: { cells: CellStats[] }) { + const order = cells.filter((c) => c.jobCount > 0); + if (order.length === 0) return null; + + const domain = sharedDomain(order.map((c) => c.buckets)); + + return ( + + + + {order.map((cell) => ( + + +
+ + {cell.label} + + + {formatCount(cell.jobCount)} jobs over {cell.n} run + {cell.n === 1 ? "" : "s"} + + + + + ))} + + + ); +} + +/** Median percentile across repeats — the same numbers the scoreboard quotes. */ +function percentiles(cell: CellStats) { + return [ + { label: "p50", spread: cell.p50 }, + { label: "p95", spread: cell.p95 }, + { label: "p99", spread: cell.p99 }, + ] + .filter((p) => p.spread !== null) + .map((p) => ({ label: p.label, valueMs: p.spread!.median })); +} + +function sharedDomain(bucketSets: number[][]): [number, number] { + let lo = Infinity; + let hi = -Infinity; + for (const buckets of bucketSets) { + const [a, b] = bucketExtent(buckets); + lo = Math.min(lo, a); + hi = Math.max(hi, b); + } + return Number.isFinite(lo) ? [lo, hi] : [0, 1]; +} diff --git a/example/src/pages/bench/SectionHeading.tsx b/example/src/pages/bench/SectionHeading.tsx new file mode 100644 index 00000000..518d8097 --- /dev/null +++ b/example/src/pages/bench/SectionHeading.tsx @@ -0,0 +1,25 @@ +import { Group, Text } from "@mantine/core"; + +/** Section title, with an optional legend or note on the trailing edge. */ +export function SectionHeading({ + title, + right, +}: { + title: string; + right?: React.ReactNode; +}) { + return ( + + + {title} + + {right} + + ); +} diff --git a/example/src/pages/bench/TimeToConsistency.tsx b/example/src/pages/bench/TimeToConsistency.tsx new file mode 100644 index 00000000..8840dfc8 --- /dev/null +++ b/example/src/pages/bench/TimeToConsistency.tsx @@ -0,0 +1,135 @@ +import { Box, Group, Stack, Text, Tooltip } from "@mantine/core"; +import { INK } from "./charts/chartTheme"; +import { formatRatio, formatSeconds } from "./charts/scale"; +import { ratio, rangesOverlap, type CellStats } from "./suiteStats"; + +/** + * The one number that means the same thing in both modes: first write accepted + * to the aggregate being consistent. It's the width of each curve above it, read + * off as a figure — the median over the suite's repeats with the observed range, + * and queued's multiple against eager. + * + * A multiple whose two ranges overlap is struck through rather than quoted — at + * that much run-to-run noise the medians haven't separated, and the honest + * reading is "not resolved at this sample size". + */ +export function TimeToConsistency({ cells }: { cells: CellStats[] }) { + const ready = cells.filter((cell) => cell.totalMs !== null); + if (ready.length === 0) return null; + const baseline = cells[1]?.totalMs ?? null; + const thin = ready.some((cell) => cell.n <= 1); + + return ( + + + + Time to consistency + + + {thin ? "single run — no spread" : "median · min–max"} + + + + {ready.map((cell, i) => { + const spread = cell.totalMs!; + const r = + i === 0 && ready.length > 1 + ? ratio(spread, baseline, "lower") + : null; + return ( + + + + + {cell.label} · n = {cell.n} + + + + {formatSeconds(spread.median)} + + {spread.n > 1 && ( + + {formatSeconds(spread.min)} – {formatSeconds(spread.max)} + + )} + {r !== null && baseline && ( + + )} + + ); + })} + + + ); +} + +/** Queued against eager. Below 1 is a result too; the verb carries direction. */ +function Multiple({ value, resolved }: { value: number; resolved: boolean }) { + const body = ( + + + {formatRatio(value)} + + + {value >= 1 ? "faster than eager" : "slower than eager"} + + + ); + return resolved ? ( + body + ) : ( + + {body} + + ); +} diff --git a/example/src/pages/bench/benchTypes.ts b/example/src/pages/bench/benchTypes.ts new file mode 100644 index 00000000..b8522c0f --- /dev/null +++ b/example/src/pages/bench/benchTypes.ts @@ -0,0 +1,197 @@ +import type { FunctionReturnType } from "convex/server"; +import type { api } from "../../../convex/_generated/api"; + +export type BenchRun = NonNullable>; +export type BenchScenario = BenchRun["config"]["scenario"]; +export type BenchMode = BenchRun["config"]["mode"]; +export type RunStatus = BenchRun["status"]; +export type BenchSuite = FunctionReturnType< + typeof api.bench.listSuites +>[number]; + +/** Config fields that only apply to some scenarios. */ +export type ScenarioField = + "shards" | "arrivalRatePerSec" | "bursts" | "burstIntervalMs"; + +export type ScenarioMeta = { + id: BenchScenario; + label: string; + description: string; + fields: readonly ScenarioField[]; + /** Applied on top of the base config when the scenario is selected. */ + defaults: Partial; +}; + +export const SCENARIOS: readonly ScenarioMeta[] = [ + { + id: "hot", + label: "Hot single namespace", + description: + "Every writer hits one namespace — maximum B-tree contention, the case queued writes exist to fix.", + fields: [], + defaults: { shards: 1 }, + }, + { + id: "sharded", + label: "Sharded namespaces", + description: + "Writers spread over N namespaces, to see how much namespacing alone relieves contention.", + fields: ["shards"], + defaults: { shards: 8 }, + }, + { + id: "trickle", + label: "Sustained trickle", + description: + "A steady arrival rate rather than one burst, to see whether the worker keeps up and how queue depth behaves.", + fields: ["arrivalRatePerSec"], + defaults: { shards: 1, arrivalRatePerSec: 50 }, + }, + { + id: "bursty", + label: "Bursts over time", + description: + "Writes arrive in bursts a fixed interval apart, so the queue fills, drains, and has to wake the worker from idle each time. The marks on the consistency chart are when each burst was due — a curve still up at the next mark is a burst that mode couldn't absorb in time.", + fields: ["bursts", "burstIntervalMs"], + defaults: { shards: 1, bursts: 4, burstIntervalMs: 4_000 }, + }, +] as const; + +export function scenarioMeta(id: BenchScenario): ScenarioMeta { + return SCENARIOS.find((s) => s.id === id) ?? SCENARIOS[0]; +} + +export const DEFAULT_CONFIG: BenchRun["config"] = { + mode: "async", + scenario: "hot", + totalOps: 500, + opsPerMutation: 10, + writeApi: "perOp", + fanOut: 20, + shards: 1, + timeoutMs: 300_000, +}; + +/** + * One run is a single sample of a noisy process, so every number is a median over + * the repeats with its observed range. Three is the smallest count with a spread + * at all, and it keeps a comparison inside a demo's patience. + */ +export const DEFAULT_REPEATS = 3; +export const MAX_REPEATS = 10; + +/** The two sides, in the order they appear everywhere on the page. */ +export const MODES = ["async", "eager"] as const; + +export function modeLabel(mode: BenchMode): string { + return mode === "async" ? "Queued" : "Eager"; +} + +/** + * A run whose numbers describe the workload that was configured. Anything less is + * a different, smaller workload rather than a noisier sample of the same one — an + * eager run that loses nine jobs of ten to the 16 MiB read limit reports the + * latency of the one that committed. The results are checked rather than the + * status alone, so runs recorded before `finalize` learned to fail over lost ops + * are judged the same way. + */ +export function isComplete(run: BenchRun): boolean { + const results = run.results; + if (!results) return false; + return ( + run.status === "done" && + results.jobs.failed === 0 && + results.ops.committed >= results.ops.attempted + ); +} + +/** One side of a comparison, out of a single suite's runs. */ +export function modeRuns(runs: BenchRun[], mode: BenchMode): BenchRun[] { + return runs.filter((r) => r.config.mode === mode); +} + +/** + * How far along a suite is. The done count comes from `listSuites`, so this is + * right for every suite the picker offers rather than only the loaded one. + */ +export function suiteProgress(suite: BenchSuite): { + done: number; + total: number; +} { + return { done: suite.doneRuns, total: MODES.length * suite.repeats }; +} + +/** A past run is identified by what was varied to produce it, not by a name. */ +export function paramsLabel(config: BenchRun["config"]): string { + const parts = [ + scenarioMeta(config.scenario).label, + `${config.totalOps} ops`, + `${config.fanOut}× fan-out`, + `${config.opsPerMutation}/txn`, + ]; + if (config.scenario === "sharded") parts.push(`${config.shards} namespaces`); + if (config.scenario === "trickle") { + parts.push(`${config.arrivalRatePerSec}/s`); + } + if (config.scenario === "bursty") { + parts.push( + `${config.bursts} bursts`, + `${Number(((config.burstIntervalMs ?? 0) / 1000).toFixed(1))}s apart`, + ); + } + return parts.join(" · "); +} + +export function suiteLabel(suite: BenchSuite): string { + return `${paramsLabel(suite.config)} · ${suite.repeats}×`; +} + +export function isInFlight(status: RunStatus): boolean { + return ( + status === "pending" || + status === "preparing" || + status === "enqueuing" || + status === "draining" || + status === "finalizing" + ); +} + +export function phaseLabel(status: RunStatus): string { + switch (status) { + case "pending": + case "preparing": + return "Preparing"; + case "enqueuing": + return "Enqueuing"; + case "draining": + return "Draining"; + case "finalizing": + return "Finalizing"; + case "done": + return "Done"; + case "failed": + return "Failed"; + case "canceled": + return "Canceled"; + } +} + +/** + * The run's one time measurement, in ms: first write accepted to the aggregate + * being consistent. + * + * Deliberately not broken into phases — a queued run's worker applies operations + * the whole time its writers are handing them over, so "enqueue" and "drain" + * aren't stages it passes through. The worker goes on reporting itself as running + * after the queue empties; that wait is outside this span and is kept in + * `results.drain.workerParkMs` for anyone diagnosing it. + */ +export function timeToConsistencyMs(run: BenchRun): number { + const start = run.enqueueStartedAtMs ?? run.createdAtMs; + const now = Date.now(); + const enqueueEnd = + run.enqueueEndedAtMs ?? (isInFlight(run.status) ? now : start); + const consistentAt = + run.drainEndedAtMs ?? (isInFlight(run.status) ? now : enqueueEnd); + return Math.max(consistentAt - start, 0); +} diff --git a/example/src/pages/bench/charts/ChartFrame.tsx b/example/src/pages/bench/charts/ChartFrame.tsx new file mode 100644 index 00000000..a0f1700d --- /dev/null +++ b/example/src/pages/bench/charts/ChartFrame.tsx @@ -0,0 +1,151 @@ +import { Box } from "@mantine/core"; +import { useElementSize } from "@mantine/hooks"; +import type { ReactNode } from "react"; +import { CHART, INK } from "./chartTheme"; +import { linearScale, niceTicks, type Scale } from "./scale"; + +export type FrameRender = (args: { + innerWidth: number; + innerHeight: number; + x: Scale; + y: Scale; +}) => ReactNode; + +export type ChartFrameProps = { + height: number; + xDomain: [number, number]; + yDomain: [number, number]; + /** Accessible description of what the chart shows. */ + ariaLabel: string; + formatX?: (v: number) => string; + formatY?: (v: number) => string; + /** Minimum y tick step. Pass 1 on a count axis to keep ticks integral. */ + yTickMinStep?: number; + children: FrameRender; + /** + * `offsetX` is measured from the left edge of this component's own relatively + * positioned box, so it can be handed straight to `ChartTooltip`'s `left`. + */ + onPointerMove?: (args: { xValue: number; offsetX: number }) => void; + onPointerLeave?: () => void; +}; + +const MARGIN = { top: 12, right: 16, bottom: 26, left: 48 }; +const X_TICKS = 6; +const Y_TICKS = 4; + +/** + * Shared chart chrome: responsive sizing, hairline gridlines, axes, and tick + * labels. Every chart on the page renders through this so the whole page reads + * as one system. + */ +export function ChartFrame({ + height, + xDomain, + yDomain, + ariaLabel, + formatX, + formatY, + yTickMinStep = 0, + children, + onPointerMove, + onPointerLeave, +}: ChartFrameProps) { + const { ref, width } = useElementSize(); + + const innerWidth = Math.max(width - MARGIN.left - MARGIN.right, 0); + const innerHeight = Math.max(height - MARGIN.top - MARGIN.bottom, 0); + const x = linearScale(xDomain, [0, innerWidth]); + const y = linearScale(yDomain, [innerHeight, 0]); + const ready = innerWidth > 0 && innerHeight > 0; + + const xTicks = niceTicks(xDomain[0], xDomain[1], X_TICKS); + const yTicks = niceTicks(yDomain[0], yDomain[1], Y_TICKS, yTickMinStep); + + return ( + // Fixed height even before measurement, so the layout never jumps. + + {ready && ( + { + const rect = event.currentTarget.getBoundingClientRect(); + const offsetX = event.clientX - rect.left; + const clamped = Math.min( + Math.max(offsetX - MARGIN.left, 0), + innerWidth, + ); + const span = xDomain[1] - xDomain[0]; + onPointerMove({ + xValue: + xDomain[0] + + (innerWidth === 0 ? 0 : (clamped / innerWidth) * span), + offsetX, + }); + } + : undefined + } + onPointerLeave={onPointerLeave} + > + + {yTicks.map((tick) => ( + + ))} + + {children({ innerWidth, innerHeight, x, y })} + + + + {yTicks.map((tick) => ( + + {formatY ? formatY(tick) : tick} + + ))} + + {xTicks.map((tick) => ( + + {formatX ? formatX(tick) : tick} + + ))} + + + )} + + ); +} diff --git a/example/src/pages/bench/charts/ChartLegend.tsx b/example/src/pages/bench/charts/ChartLegend.tsx new file mode 100644 index 00000000..c605942e --- /dev/null +++ b/example/src/pages/bench/charts/ChartLegend.tsx @@ -0,0 +1,67 @@ +import { Box, Group, Text } from "@mantine/core"; + +export type LegendItem = { + label: string; + color: string; + /** Lines get a 2px rule; fills get a swatch. */ + shape?: "line" | "dashedLine" | "swatch"; + /** + * Consecutive items sharing a group sit tight together, so a mark that + * belongs to a series — a queued run's dashed queue line — reads as part of + * that series' entry rather than as a third series. + */ + group?: string; +}; + +/** + * Always rendered for two or more series, so identity is never carried by color + * alone. A single-series chart needs none — its title names it. + */ +export function ChartLegend({ items }: { items: LegendItem[] }) { + if (items.length < 2) return null; + const clusters: LegendItem[][] = []; + for (const item of items) { + const last = clusters[clusters.length - 1]; + if (last && item.group !== undefined && last[0].group === item.group) { + last.push(item); + } else { + clusters.push([item]); + } + } + return ( + + {clusters.map((cluster) => ( + + {cluster.map((item) => ( + + + + {item.label} + + + ))} + + ))} + + ); +} + +function Key({ item }: { item: LegendItem }) { + if (item.shape === "line") { + return ; + } + if (item.shape === "dashedLine") { + // Matches the mark: a dashed rule, same hue, so the key reads as the same + // line and not as a second series. + return ( + + ); + } + return ; +} diff --git a/example/src/pages/bench/charts/ChartTooltip.tsx b/example/src/pages/bench/charts/ChartTooltip.tsx new file mode 100644 index 00000000..d682a179 --- /dev/null +++ b/example/src/pages/bench/charts/ChartTooltip.tsx @@ -0,0 +1,67 @@ +import { Box, Group, Paper, Stack, Text } from "@mantine/core"; + +export type TooltipRow = { + label: string; + value: string; + color?: string; +}; + +/** + * Value first and prominent, series name secondary, a colored key beside it. + * Positioned relative to the chart's own `pos="relative"` box. + */ +export function ChartTooltip({ + title, + rows, + left, + top, +}: { + title?: string; + rows: TooltipRow[]; + left: number; + top: number; +}) { + return ( + + + {title && ( + + {title} + + )} + {rows.map((row) => ( + + {row.color && ( + + )} + + {row.value} + + + {row.label} + + + ))} + + + ); +} diff --git a/example/src/pages/bench/charts/ConsistencyChart.tsx b/example/src/pages/bench/charts/ConsistencyChart.tsx new file mode 100644 index 00000000..5bc89c8b --- /dev/null +++ b/example/src/pages/bench/charts/ConsistencyChart.tsx @@ -0,0 +1,230 @@ +import { Box } from "@mantine/core"; +import { useMemo, useState } from "react"; +import { ChartFrame } from "./ChartFrame"; +import { ChartTooltip } from "./ChartTooltip"; +import { INK, MARK, MODE_COLOR } from "./chartTheme"; +import { formatCount, formatSeconds } from "./scale"; +import { MODES, type BenchMode } from "../benchTypes"; +import type { ConsistencyPoint } from "../../../../convex/utils/benchMath"; + +export type ConsistencySeries = { + mode: BenchMode; + label: string; + repeatIndex: number; + points: ConsistencyPoint[]; +}; + +/** + * Operations not yet in the aggregate, over time, both modes on one axis. A + * curve's width is its run's time to consistency and its shape is how the mode + * got there. + * + * One curve per repeat, colored by mode rather than by run: the spread within a + * mode should read as a band, and a hue per run would imply each repeat is its + * own thing to identify rather than one sample of the same thing. A curve stops + * where its run stopped — carried flat to the chart's full width it read as a run + * still going long after it had finished. + * + * The dashed line under a queued curve is the queue itself. The gap between the + * two is work no writer has handed over yet, so together they say whether a + * queued run is waiting on its writers or on the worker. + */ +export function ConsistencyChart({ + series, + marksMs = [], + height = 240, +}: { + series: ConsistencySeries[]; + /** + * Elapsed times to rule off behind the curves — the bursty scenario's burst + * schedule. A curve still up at the next mark is a burst the mode hadn't + * absorbed before the following one arrived. Empty for other scenarios. + */ + marksMs?: number[]; + height?: number; +}) { + const [hover, setHover] = useState<{ t: number; left: number } | null>(null); + + const { xMax, yMax } = useMemo(() => { + let x = 0; + let y = 0; + for (const s of series) { + for (const p of s.points) { + if (p.elapsedMs > x) x = p.elapsedMs; + if (p.outstanding > y) y = p.outstanding; + } + } + return { xMax: x || 1, yMax: y || 1 }; + }, [series]); + + const drawable = useMemo( + () => series.filter((s) => s.points.length > 0), + [series], + ); + if (drawable.length === 0) return null; + + return ( + + formatSeconds(v)} + formatY={(v) => formatCount(v)} + onPointerMove={({ xValue, offsetX }) => + setHover({ t: xValue, left: offsetX }) + } + onPointerLeave={() => setHover(null)} + > + {({ x, y, innerHeight }) => ( + + {/* Only inside the drawn domain — a mark past the end of every run + would stretch the axis to describe a burst that never got + scheduled. */} + {marksMs + .filter((t) => t > 0 && t <= xMax) + .map((t) => ( + + ))} + {drawable.map((s) => { + const end = s.points[s.points.length - 1]; + const inQueue = s.points.some((p) => p.queued > 0); + return ( + + {inQueue && ( + p.queued)} + fill="none" + stroke={MODE_COLOR[s.mode]} + strokeWidth={MARK.lineWidth} + strokeDasharray="4 4" + strokeLinejoin="round" + strokeLinecap="round" + opacity={0.7} + /> + )} + p.outstanding)} + fill="none" + stroke={MODE_COLOR[s.mode]} + strokeWidth={MARK.lineWidth} + strokeLinejoin="round" + strokeLinecap="round" + opacity={0.85} + /> + {/* Hollow when the run ended above zero — that one didn't + finish its work, and a filled dot would read as a clean + landing. */} + + + ); + })} + {hover && ( + + )} + + )} + + + {hover && ( + + )} + + ); +} + +function path( + points: ConsistencyPoint[], + x: (v: number) => number, + y: (v: number) => number, + value: (p: ConsistencyPoint) => number, +): string { + return points + .map((p, i) => `${i === 0 ? "M" : "L"} ${x(p.elapsedMs)} ${y(value(p))}`) + .join(" "); +} + +/** + * One row per mode spanning its repeats — six rows of individual runs is not a + * readout. A mode whose runs had all finished by `t` reads "finished" rather than + * the zero it would otherwise hold. + */ +function modeRows(series: ConsistencySeries[], t: number) { + const rows = []; + for (const mode of MODES) { + const mine = series.filter((s) => s.mode === mode); + if (mine.length === 0) continue; + const live = mine.filter( + (s) => s.points[s.points.length - 1].elapsedMs >= t, + ); + if (live.length === 0) { + rows.push({ + label: mine[0].label, + value: "finished", + color: MODE_COLOR[mode], + }); + continue; + } + const values = live.map((s) => at(s.points, t, (p) => p.outstanding)); + const lo = Math.min(...values); + const hi = Math.max(...values); + const queued = live.map((s) => at(s.points, t, (p) => p.queued)); + const inQueue = Math.max(...queued); + rows.push({ + label: mine[0].label, + value: + (lo === hi + ? formatCount(lo) + : `${formatCount(lo)} – ${formatCount(hi)}`) + + (inQueue > 0 ? ` · ${formatCount(inQueue)} in queue` : ""), + color: MODE_COLOR[mode], + }); + } + return rows; +} + +/** Value of the nearest sample at or before `t`, so the readout never invents one. */ +function at( + points: ConsistencyPoint[], + t: number, + value: (p: ConsistencyPoint) => number, +): number { + let out = points[0] ? value(points[0]) : 0; + for (const p of points) { + if (p.elapsedMs > t) break; + out = value(p); + } + return out; +} diff --git a/example/src/pages/bench/charts/GroupedBarChart.tsx b/example/src/pages/bench/charts/GroupedBarChart.tsx new file mode 100644 index 00000000..08a03ed5 --- /dev/null +++ b/example/src/pages/bench/charts/GroupedBarChart.tsx @@ -0,0 +1,227 @@ +import { Box, Stack, Text } from "@mantine/core"; +import { INK, MARK } from "./chartTheme"; + +export type BarValue = { + value: number; + /** Observed range across repeats. Omitted for a single sample. */ + low?: number; + high?: number; + /** + * Overrides the series color for this bar. For a chart grouped by mode the + * mode is the group, and it's the group that owns the color. + */ + color?: string; +}; + +export type BarSeries = { + label: string; + color: string; + /** One entry per group, aligned with `groups`. */ + values: (BarValue | null)[]; +}; + +export type GroupedBarChartProps = { + groups: string[]; + series: BarSeries[]; + format: (v: number) => string; + ariaLabel: string; + /** + * Width of a label column naming each series beside its bar. Set when color + * doesn't identify the series — the bars within a group share the group's + * color — so a legend couldn't either. Omit for the usual one-color-per-series + * layout, where the legend does that job. + */ + seriesLabelWidth?: number; +}; + +const LABEL_WIDTH = 104; +/** Reserved to the right of the track so a tip label is never clipped. */ +const VALUE_GUTTER = 84; +const GROUP_GAP = 18; + +/** + * Horizontal grouped bars with a direct value label at each tip. Used one facet + * per unit — never one chart mixing ms with ops/s. + * + * The bar length is the median over the suite's repeats; the whisker spans the + * observed min–max. Bars whose whiskers overlap have not separated at this + * sample size, which is exactly what the reader needs to see before quoting a + * difference. + * + * Laid out in HTML rather than a scaled SVG viewBox: percentage widths make the + * bars responsive without stretching the label glyphs, which a `viewBox` plus + * `preserveAspectRatio="none"` does. + */ +export function GroupedBarChart({ + groups, + series, + format, + ariaLabel, + seriesLabelWidth, +}: GroupedBarChartProps) { + const max = Math.max( + ...series.flatMap((s) => + s.values.flatMap((v) => + v ? [v.value, v.high ?? v.value].filter(Number.isFinite) : [], + ), + ), + 0, + ); + + if (max === 0) { + return ( + + No data yet. + + ); + } + + const pct = (v: number) => (v / max) * 100; + + return ( + + {groups.map((group, gi) => ( + + + {group} + + + {series.map((s) => { + const entry = s.values[gi]; + if (!entry || !Number.isFinite(entry.value)) return null; + const barPct = Math.max( + pct(entry.value), + entry.value > 0 ? 0.5 : 0, + ); + const hasRange = + entry.low !== undefined && + entry.high !== undefined && + entry.high > entry.low; + const bar = ( + + + {hasRange && ( + + )} + {/* Always outside the tip, so a short bar can't clip it. */} + + {format(entry.value)} + + + ); + if (seriesLabelWidth === undefined) { + return {bar}; + } + return ( + + {/* Right-aligned, so every label ends at the bar baseline. */} + + {s.label} + + {bar} + + ); + })} + + + ))} + + ); +} + +/** + * Drawn in ink rather than the series color: it's an uncertainty annotation on + * the mark, not a second series, and it has to stay legible on top of the fill. + */ +function Whisker({ lowPct, highPct }: { lowPct: number; highPct: number }) { + const capHeight = Math.round(MARK.barMaxThickness * 0.6); + return ( + + + + + + ); + + function Cap() { + return ( + + ); + } +} diff --git a/example/src/pages/bench/charts/LatencyHistogram.tsx b/example/src/pages/bench/charts/LatencyHistogram.tsx new file mode 100644 index 00000000..47a69aa9 --- /dev/null +++ b/example/src/pages/bench/charts/LatencyHistogram.tsx @@ -0,0 +1,148 @@ +import { Box, Stack, Text } from "@mantine/core"; +import { useState } from "react"; +import { ChartFrame } from "./ChartFrame"; +import { ChartTooltip } from "./ChartTooltip"; +import { INK, MARK } from "./chartTheme"; +import { bucketExtent, bucketPosition } from "./histBuckets"; +import { bucketLowerBound } from "../../../../convex/utils/benchMath"; +import { formatCount, formatMs, verticalBarPath } from "./scale"; + +export type LatencyHistogramProps = { + buckets: number[]; + color: string; + /** Names the series in the accessible label. */ + name: string; + /** Marked with hairline rules and labelled above the plot. */ + percentiles?: { label: string; valueMs: number }[]; + /** Shared across small multiples so two runs are directly comparable. */ + domain?: [number, number]; + height?: number; +}; + +export function LatencyHistogram({ + buckets, + color, + name, + percentiles = [], + domain, + height = 200, +}: LatencyHistogramProps) { + const [hover, setHover] = useState<{ index: number; left: number } | null>( + null, + ); + const [lo, hi] = domain ?? bucketExtent(buckets); + const visible = buckets.slice(lo, hi + 1); + const yMax = Math.max(...visible, 1); + + if (visible.length === 0) return null; + + return ( + + + formatMs(bucketLowerBound(v))} + formatY={(v) => formatCount(v)} + > + {({ x, y, innerHeight }) => { + const slot = x(lo + 1) - x(lo); + const width = Math.min( + Math.max(slot - MARK.surfaceGap, 1), + MARK.barMaxThickness, + ); + return ( + + {visible.map((count, i) => { + if (count === 0) return null; + const index = lo + i; + const left = x(index) + (slot - width) / 2; + return ( + { + // The tooltip is positioned inside the chart's own box, + // so the cursor has to be measured against the svg + // rather than the viewport. + const rect = + event.currentTarget.ownerSVGElement?.getBoundingClientRect(); + setHover({ + index, + left: rect ? event.clientX - rect.left : 0, + }); + }} + onPointerLeave={() => setHover(null)} + /> + ); + })} + + {percentiles.map((p, i) => { + const at = bucketPosition(p.valueMs); + if (at < lo || at > hi + 1) return null; + return ( + + + {/* Staggered down the plot: percentiles sit close together + on a log axis and would otherwise overlap into + unreadable runs like "p95p99". */} + + {p.label} + + + ); + })} + + ); + }} + + + {hover && ( + + )} + + {percentiles.length > 0 && ( + + {percentiles + .map((p) => `${p.label} ${formatMs(p.valueMs)}`) + .join(" · ")} + + )} + + ); +} diff --git a/example/src/pages/bench/charts/chartTheme.ts b/example/src/pages/bench/charts/chartTheme.ts new file mode 100644 index 00000000..bbed6cac --- /dev/null +++ b/example/src/pages/bench/charts/chartTheme.ts @@ -0,0 +1,34 @@ +/** + * Chart tokens for the benchmark page. + * + * Color follows the entity: `async` is always blue and `eager` is always orange, + * in every chart and every table row. Never reassign by rank. + */ + +export const MODE_COLOR = { + async: "#3987e5", + eager: "#d95926", +} as const; + +export const INK = { + primary: "#ffffff", + secondary: "#c3c2b7", + muted: "#898781", +} as const; + +export const CHART = { + /** Hairline gridlines — solid, never dashed. */ + grid: "#2c2c2a", + axis: "#383835", +} as const; + +export const MARK = { + /** Bars never get fatter than this. */ + barMaxThickness: 24, + lineWidth: 2, + /** Gap between adjacent bars, showing the card behind them. */ + surfaceGap: 2, + markerRadius: 4, + /** Rounded at the data end, square at the baseline. */ + barEndRadius: 4, +} as const; diff --git a/example/src/pages/bench/charts/histBuckets.ts b/example/src/pages/bench/charts/histBuckets.ts new file mode 100644 index 00000000..c47e42a9 --- /dev/null +++ b/example/src/pages/bench/charts/histBuckets.ts @@ -0,0 +1,33 @@ +/** + * Frontend-only histogram helpers. The bucket math itself is shared with the + * server in `convex/utils/benchMath.ts` so the axis can't disagree with the data. + */ + +import { + bucketIndex, + bucketLowerBound, +} from "../../../../convex/utils/benchMath"; + +/** + * Fractional bucket position of a latency, for placing a percentile rule between + * bucket edges. `bucketIndex` clamps to the last bucket, so a percentile past the + * histogram's range pins to the end rather than falling outside the domain and + * being dropped. + */ +export function bucketPosition(valueMs: number): number { + const i = bucketIndex(valueMs); + const lo = bucketLowerBound(i); + const hi = bucketLowerBound(i + 1); + if (!(lo > 0) || !(hi > lo) || valueMs <= lo) return i; + return i + Math.min(Math.log(valueMs / lo) / Math.log(hi / lo), 1); +} + +/** Trailing empty buckets carry no information; drop them from the domain. */ +export function bucketExtent(buckets: number[]): [number, number] { + const firstFilled = buckets.findIndex((n) => n > 0); + if (firstFilled < 0) return [0, 0]; + let last = buckets.length - 1; + while (buckets[last] === 0) last--; + const first = Math.max(firstFilled - 1, 0); + return [first, Math.max(last + 1, first + 1)]; +} diff --git a/example/src/pages/bench/charts/scale.ts b/example/src/pages/bench/charts/scale.ts new file mode 100644 index 00000000..a74985c0 --- /dev/null +++ b/example/src/pages/bench/charts/scale.ts @@ -0,0 +1,100 @@ +/** Pure scale/tick helpers. Kept out of .tsx so react-refresh stays happy. */ + +export type Scale = (value: number) => number; + +export function linearScale( + domain: [number, number], + range: [number, number], +): Scale { + const [d0, d1] = domain; + const [r0, r1] = range; + const span = d1 - d0; + if (span === 0) return () => r0; + return (value) => r0 + ((value - d0) / span) * (r1 - r0); +} + +/** + * Ticks at 1/2/5 x 10^n covering the domain. `minStep` floors the step size — + * pass 1 for a count axis, so a domain of [0, 1] yields 0 and 1 rather than + * fractional ticks that collapse to duplicate integer labels. + */ +export function niceTicks( + min: number, + max: number, + count = 5, + minStep = 0, +): number[] { + if (!Number.isFinite(min) || !Number.isFinite(max) || min === max) { + return [min || 0]; + } + const rawStep = (max - min) / Math.max(count, 1); + const magnitude = Math.pow(10, Math.floor(Math.log10(rawStep))); + const normalized = rawStep / magnitude; + const step = Math.max( + (normalized <= 1 ? 1 : normalized <= 2 ? 2 : normalized <= 5 ? 5 : 10) * + magnitude, + minStep, + ); + const start = Math.ceil(min / step) * step; + const ticks: number[] = []; + for (let t = start; t <= max + step * 1e-9; t += step) { + // Guard against float drift producing -0 or 0.30000000000000004. + ticks.push(Math.abs(t) < step * 1e-9 ? 0 : Number(t.toPrecision(12))); + } + return ticks; +} + +export function formatMs(ms: number): string { + if (!Number.isFinite(ms)) return "–"; + if (ms >= 10_000) return `${(ms / 1000).toFixed(1)}s`; + if (ms >= 1000) return `${(ms / 1000).toFixed(2)}s`; + if (ms >= 100) return `${Math.round(ms)}ms`; + if (ms >= 10) return `${ms.toFixed(1)}ms`; + return `${ms.toFixed(2)}ms`; +} + +export function formatCount(n: number): string { + if (!Number.isFinite(n)) return "–"; + if (n >= 1_000_000) return `${(n / 1_000_000).toFixed(1)}M`; + if (n >= 1000) return `${(n / 1000).toFixed(1)}k`; + return `${Math.round(n)}`; +} + +export function formatRate(opsPerSec: number): string { + if (!Number.isFinite(opsPerSec)) return "–"; + return opsPerSec >= 100 ? `${Math.round(opsPerSec)}` : opsPerSec.toFixed(1); +} + +export function formatSeconds(ms: number): string { + if (!Number.isFinite(ms)) return "–"; + return `${(ms / 1000).toFixed(ms < 10_000 ? 2 : 1)}s`; +} + +/** + * Rounded at the data end, square at the baseline — for a bar growing upward + * from y0 to y1 (screen coords, y1 < y0). + */ +export function verticalBarPath( + x: number, + width: number, + yTop: number, + yBase: number, + radius: number, +): string { + const r = Math.max(0, Math.min(radius, width / 2, Math.abs(yBase - yTop))); + return [ + `M ${x} ${yBase}`, + `L ${x} ${yTop + r}`, + `Q ${x} ${yTop} ${x + r} ${yTop}`, + `L ${x + width - r} ${yTop}`, + `Q ${x + width} ${yTop} ${x + width} ${yTop + r}`, + `L ${x + width} ${yBase}`, + "Z", + ].join(" "); +} + +/** Always ≥ 1×: the direction is carried by the verb beside it. */ +export function formatRatio(ratio: number): string { + const r = ratio >= 1 ? ratio : 1 / ratio; + return `${r >= 100 ? Math.round(r) : r.toFixed(1)}×`; +} diff --git a/example/src/pages/bench/suiteStats.test.ts b/example/src/pages/bench/suiteStats.test.ts new file mode 100644 index 00000000..f4452cd7 --- /dev/null +++ b/example/src/pages/bench/suiteStats.test.ts @@ -0,0 +1,239 @@ +import { describe, expect, test } from "vitest"; +import { + cellStats, + median, + rangesOverlap, + ratio, + spreadOf, + type Spread, +} from "./suiteStats"; +import type { BenchRun } from "./benchTypes"; + +/** + * Minimal stand-in for a finished run. Only the fields the aggregation reads are + * populated; the cast keeps the fixture from having to mirror the whole + * generated document type. + */ +function run(opts: { + mode?: "async" | "eager"; + p50?: number; + p95?: number; + p99?: number; + enqueueOpsPerSec?: number; + buckets?: number[]; + count?: number; + enqueueStartedAtMs?: number; + enqueueEndedAtMs?: number; + drainEndedAtMs?: number; + /** Ops that never landed, for the incomplete-run cases. */ + opsMissing?: number; + jobsFailed?: number; + workerParkMs?: number; +}): BenchRun { + const { + mode = "async", + p50 = 100, + p95 = 200, + p99 = 300, + enqueueOpsPerSec = 500, + buckets = [], + count = 10, + enqueueStartedAtMs = 1_000, + enqueueEndedAtMs = 2_000, + drainEndedAtMs = 3_000, + opsMissing = 0, + jobsFailed = 0, + workerParkMs = 0, + } = opts; + return { + status: "done", + config: { mode }, + createdAtMs: enqueueStartedAtMs, + enqueueStartedAtMs, + enqueueEndedAtMs, + drainEndedAtMs, + results: { + ops: { attempted: 100, committed: 100 - opsMissing, failed: opsMissing }, + jobs: { total: 10, succeeded: 10 - jobsFailed, failed: jobsFailed }, + latency: { jobLatency: { p50, p95, p99, count, buckets } }, + drain: { workerParkMs }, + throughput: { enqueueOpsPerSec }, + queue: { peakOperations: 42 }, + }, + } as unknown as BenchRun; +} + +describe("median", () => { + test("picks the middle of an odd-length sample", () => { + expect(median([5, 1, 3])).toBe(3); + }); + + test("averages the two middles of an even-length sample", () => { + expect(median([1, 2, 3, 10])).toBe(2.5); + }); + + test("is NaN with no samples, so callers can't mistake it for zero", () => { + expect(median([])).toBeNaN(); + }); +}); + +describe("spreadOf", () => { + test("reports the median with the observed range", () => { + const spread = spreadOf( + [run({ p50: 100 }), run({ p50: 300 }), run({ p50: 200 })], + (r) => r.results?.latency.jobLatency.p50, + ); + expect(spread).toMatchObject({ median: 200, min: 100, max: 300, n: 3 }); + }); + + test("skips runs missing the metric rather than counting them as zero", () => { + const spread = spreadOf( + [run({ p50: 100 }), { results: undefined } as unknown as BenchRun], + (r) => r.results?.latency.jobLatency.p50, + ); + expect(spread).toMatchObject({ median: 100, min: 100, max: 100, n: 1 }); + }); + + test("is null when nothing contributed", () => { + expect(spreadOf([], (r) => r.results?.latency.jobLatency.p50)).toBeNull(); + }); +}); + +describe("cellStats", () => { + test("pools every repeat's histogram and job count", () => { + const stats = cellStats("async", [ + run({ buckets: [1, 2, 0], count: 3 }), + run({ buckets: [0, 1, 5], count: 6 }), + ]); + expect(stats.buckets).toEqual([1, 3, 5]); + expect(stats.label).toBe("Queued"); + expect(stats.mode).toBe("async"); + expect(stats.color).toBe("#3987e5"); + expect(stats.jobCount).toBe(9); + expect(stats.n).toBe(2); + }); + + test("ignores runs without results, so an in-flight run doesn't skew n", () => { + const stats = cellStats("async", [ + run({ p50: 100 }), + { config: { mode: "async" }, results: undefined } as unknown as BenchRun, + ]); + expect(stats.n).toBe(1); + expect(stats.p50?.median).toBe(100); + }); + + test("leaves out a run that lost ops, and says how many it left out", () => { + // The incomplete run measured a smaller workload, not a noisier sample of + // the same one — a median across both would describe neither. + const stats = cellStats("async", [ + run({ p50: 100 }), + run({ p50: 900, opsMissing: 90, jobsFailed: 9 }), + ]); + expect(stats.n).toBe(1); + expect(stats.p50?.median).toBe(100); + expect(stats.p50?.max).toBe(100); + expect(stats.excluded).toBe(1); + }); + + test("leaves out a run whose jobs failed even if every op landed", () => { + const stats = cellStats("async", [run({ jobsFailed: 2 })]); + expect(stats.n).toBe(0); + expect(stats.p50).toBeNull(); + expect(stats.excluded).toBe(1); + // Nothing pooled either, so the histogram doesn't claim jobs it excluded. + expect(stats.jobCount).toBe(0); + }); + + test("doesn't count an in-flight run as excluded", () => { + // It hasn't lost anything — it just hasn't finished, so there is nothing to + // report about it. + const stats = cellStats("async", [ + run({}), + { config: { mode: "async" }, results: undefined } as unknown as BenchRun, + ]); + expect(stats.n).toBe(1); + expect(stats.excluded).toBe(0); + }); + + test("keeps the worker's parking time out of the run's total", () => { + // The aggregate was already consistent — the run only waits so the next one + // starts against an idle worker. Charging it to the total added six seconds + // to a twenty-five second drain. + const stats = cellStats("async", [ + run({ + enqueueStartedAtMs: 1_000, + enqueueEndedAtMs: 1_400, + drainEndedAtMs: 3_000, + workerParkMs: 6_000, + }), + ]); + expect(stats.totalMs?.median).toBe(2_000); + }); + + test("measures from the first write to consistency", () => { + const stats = cellStats("async", [ + run({ + enqueueStartedAtMs: 1_000, + enqueueEndedAtMs: 1_400, + drainEndedAtMs: 3_000, + }), + ]); + expect(stats.totalMs?.median).toBe(2_000); + }); +}); + +const spread = (median: number, min: number, max: number): Spread => ({ + median, + min, + max, + n: 3, +}); + +describe("rangesOverlap", () => { + test("separated ranges do not overlap", () => { + expect(rangesOverlap(spread(100, 90, 110), spread(500, 480, 520))).toBe( + false, + ); + }); + + test("touching ranges count as overlapping", () => { + expect(rangesOverlap(spread(100, 90, 110), spread(200, 110, 300))).toBe( + true, + ); + }); + + test("a range contained in another overlaps", () => { + expect(rangesOverlap(spread(150, 140, 160), spread(200, 100, 300))).toBe( + true, + ); + }); +}); + +describe("ratio", () => { + test("is greater than 1 when the arm beats the baseline on lower-is-better", () => { + expect( + ratio(spread(100, 90, 110), spread(500, 480, 520), "lower"), + ).toBeCloseTo(5); + }); + + test("is greater than 1 when the arm beats the baseline on higher-is-better", () => { + expect( + ratio(spread(500, 480, 520), spread(100, 90, 110), "higher"), + ).toBeCloseTo(5); + }); + + test("is less than 1 when the baseline wins", () => { + expect( + ratio(spread(500, 480, 520), spread(100, 90, 110), "lower"), + ).toBeCloseTo(0.2); + }); + + test("is null rather than Infinity when a median is zero", () => { + expect(ratio(spread(0, 0, 0), spread(100, 90, 110), "lower")).toBeNull(); + }); + + test("is null when either side has no samples", () => { + expect(ratio(null, spread(100, 90, 110), "lower")).toBeNull(); + expect(ratio(spread(100, 90, 110), null, "lower")).toBeNull(); + }); +}); diff --git a/example/src/pages/bench/suiteStats.ts b/example/src/pages/bench/suiteStats.ts new file mode 100644 index 00000000..8d0d52d9 --- /dev/null +++ b/example/src/pages/bench/suiteStats.ts @@ -0,0 +1,139 @@ +/** + * Aggregation across a suite's repeats. + * + * Median rather than mean, and min–max rather than a standard deviation: with the + * handful of repeats a live demo can afford, one slow run drags a mean around and + * a stddev from 3 points is not meaningful. `n` is always shown, since `n=1` has + * no spread and must not be read as if it did. + */ + +import { MODE_COLOR } from "./charts/chartTheme"; +import { + isComplete, + modeLabel, + timeToConsistencyMs, + type BenchMode, + type BenchRun, +} from "./benchTypes"; + +export type Spread = { + /** Median across repeats — the headline number. */ + median: number; + min: number; + max: number; + /** Number of repeats that contributed. */ + n: number; +}; + +export function median(values: number[]): number { + if (values.length === 0) return NaN; + const sorted = [...values].sort((a, b) => a - b); + const mid = sorted.length >> 1; + return sorted.length % 2 === 1 + ? sorted[mid] + : (sorted[mid - 1] + sorted[mid]) / 2; +} + +export function spreadOf( + runs: BenchRun[], + value: (run: BenchRun) => number | undefined, +): Spread | null { + const values = runs + .map(value) + .filter((v): v is number => v !== undefined && Number.isFinite(v)); + if (values.length === 0) return null; + return { + median: median(values), + min: Math.min(...values), + max: Math.max(...values), + n: values.length, + }; +} + +/** Every metric the comparison views read, computed once per cell. */ +export type CellStats = { + mode: BenchMode; + label: string; + /** Queued is always blue, eager always orange, in every view. */ + color: string; + n: number; + p50: Spread | null; + p95: Spread | null; + p99: Spread | null; + enqueueOpsPerSec: Spread | null; + applyOpsPerSec: Spread | null; + /** First write accepted to consistent. The run's one time measurement. */ + totalMs: Spread | null; + /** Union of the per-run latency histograms, for the distribution chart. */ + buckets: number[]; + /** Total jobs across repeats, so the histogram's count label is honest. */ + jobCount: number; + /** Runs left out because they didn't land all their ops. See `isComplete`. */ + excluded: number; +}; + +/** + * Only complete runs contribute: a run that lost work would pull the medians + * toward a workload nobody asked for. It is counted in `excluded` and reported by + * `FailureNotice` instead. + */ +export function cellStats(mode: BenchMode, runs: BenchRun[]): CellStats { + const done = runs.filter(isComplete); + const buckets: number[] = []; + let jobCount = 0; + for (const run of done) { + const hist = run.results!.latency.jobLatency; + jobCount += hist.count; + hist.buckets.forEach((count, i) => { + buckets[i] = (buckets[i] ?? 0) + count; + }); + } + return { + mode, + label: modeLabel(mode), + color: MODE_COLOR[mode], + n: done.length, + p50: spreadOf(done, (r) => r.results?.latency.jobLatency.p50), + p95: spreadOf(done, (r) => r.results?.latency.jobLatency.p95), + p99: spreadOf(done, (r) => r.results?.latency.jobLatency.p99), + enqueueOpsPerSec: spreadOf( + done, + (r) => r.results?.throughput.enqueueOpsPerSec, + ), + applyOpsPerSec: spreadOf( + done, + (r) => + r.results?.throughput.applyOpsPerSec ?? + r.results?.throughput.enqueueOpsPerSec, + ), + totalMs: spreadOf(done, timeToConsistencyMs), + buckets, + jobCount, + excluded: runs.filter((r) => r.results && !isComplete(r)).length, + }; +} + +/** + * A ratio between medians whose ranges overlap is not a result — the views mark it + * rather than quoting it as one. + */ +export function rangesOverlap(a: Spread, b: Spread): boolean { + return a.min <= b.max && b.min <= a.max; +} + +/** + * The multiple between a mode's median and the baseline's, oriented so the mode + * beating the baseline is > 1. Null when either side is missing or non-positive, + * so callers show a dash instead of a meaningless number. + */ +export function ratio( + arm: Spread | null, + baseline: Spread | null, + better: "lower" | "higher", +): number | null { + if (!arm || !baseline) return null; + const a = arm.median; + const b = baseline.median; + if (!(a > 0) || !(b > 0)) return null; + return better === "lower" ? b / a : a / b; +} diff --git a/example/src/pages/bench/useBenchRun.ts b/example/src/pages/bench/useBenchRun.ts new file mode 100644 index 00000000..c2671dbc --- /dev/null +++ b/example/src/pages/bench/useBenchRun.ts @@ -0,0 +1,105 @@ +import { useMutation, useQuery } from "convex/react"; +import { useCallback, useState } from "react"; +import { api } from "../../../convex/_generated/api"; +import type { Id } from "../../../convex/_generated/dataModel"; +import { useStableQuery } from "../../utils/useStableQuery"; +import { useApiErrorHandler } from "../../utils/errors"; +import type { BenchRun, BenchSuite } from "./benchTypes"; + +// Each suite in this window costs `listSuites` a pass over its run documents to +// count them, so it stays small even though the wire payload no longer scales +// with it. +const SUITE_WINDOW = 3; + +/** + * All Convex wiring for the benchmark page. + * + * The fat run documents — a consistency curve and three histograms each — are + * subscribed to one suite at a time, and never the whole table: `watch` patches + * the active run four times a second, so every document in a live query's read + * set is resent on that cadence. What crosses suites is a count from + * `listSuites` instead. + * + * Note what is *not* subscribed to: nothing counts `benchJobs` rows live. A + * subscription like that would re-run on every job insert, which would both + * scale badly and add load to the very thing being measured. Live progress + * comes off the single-writer `progress` field on the run row. + */ +export function useBenchRun(suiteId: Id<"benchSuites"> | null) { + const onApiError = useApiErrorHandler(); + const [isStarting, setIsStarting] = useState(false); + + const canStart = useQuery(api.bench.canStart); + const latestRunId = useQuery(api.bench.latestRunId); + const suites = useStableQuery(api.bench.listSuites, { limit: SUITE_WINDOW }); + + // Derived, not synced in an effect: follow whatever run is active, else fall + // back to the most recent one. + const effectiveRunId = canStart?.activeRunId ?? latestRunId ?? null; + + const run = useStableQuery( + api.bench.getRun, + effectiveRunId ? { runId: effectiveRunId } : "skip", + ); + // Derived here rather than in the page, so the per-suite queries can follow the + // suite actually on screen: with nothing explicitly picked that's the newest + // one with a finished run. The `doneRuns` count is what makes this answerable + // without any run documents — the runs query is keyed by the answer. + const selectedSuite: BenchSuite | null = suiteId + ? ((suites ?? []).find((s) => s._id === suiteId) ?? null) + : ((suites ?? []).find((s) => s.doneRuns > 0) ?? (suites ?? [])[0] ?? null); + + const runs = useStableQuery( + api.bench.listSuiteRuns, + selectedSuite ? { suiteId: selectedSuite._id } : "skip", + ); + + const consistencySeries = useStableQuery( + api.bench.getConsistencySeries, + selectedSuite ? { suiteId: selectedSuite._id } : "skip", + ); + + const startSuiteMutation = useMutation(api.bench.startSuite); + const cancelSuiteMutation = useMutation(api.bench.cancelSuite); + + const startSuite = useCallback( + async (config: BenchRun["config"], repeats: number) => { + // Latch before awaiting: the suite row doesn't exist until this returns, + // so without it a double-click fires two comparisons. + setIsStarting(true); + try { + return await startSuiteMutation({ config, repeats }); + } catch (error) { + onApiError(error, "startSuite"); + return null; + } finally { + setIsStarting(false); + } + }, + [startSuiteMutation, onApiError], + ); + + const cancelSuite = useCallback( + async (suiteId: Id<"benchSuites">) => { + try { + return await cancelSuiteMutation({ suiteId }); + } catch (error) { + onApiError(error, "cancelSuite"); + return null; + } + }, + [cancelSuiteMutation, onApiError], + ); + + return { + canStart, + runs: runs ?? [], + suites: suites ?? [], + run: run ?? null, + consistencySeries: consistencySeries ?? [], + selectedSuite, + startSuite, + cancelSuite, + isStarting, + }; +} diff --git a/example/src/pages/home/HomePage.tsx b/example/src/pages/home/HomePage.tsx index 6875e959..9239bd9f 100644 --- a/example/src/pages/home/HomePage.tsx +++ b/example/src/pages/home/HomePage.tsx @@ -6,6 +6,7 @@ import { IconArrowsShuffle, IconChartPie, IconBinaryTree, + IconGauge, } from "@tabler/icons-react"; import { routes } from "../../routes"; import { CommonAppShell } from "@/common/CommonAppShell"; @@ -126,6 +127,26 @@ export function HomePage() { + + routes.bench().push()} + className="hover-card" + > + + + + + Benchmark + + + + Queued vs eager writes under contention + + + diff --git a/example/src/routes.ts b/example/src/routes.ts index 5a302b0b..d200ea9c 100644 --- a/example/src/routes.ts +++ b/example/src/routes.ts @@ -7,4 +7,5 @@ export const { RouteProvider, useRoute, routes } = createRouter({ shuffle: defineRoute("/shuffle"), stats: defineRoute("/stats"), btree: defineRoute("/btree"), + bench: defineRoute("/bench"), }); diff --git a/src/component/_generated/component.ts b/src/component/_generated/component.ts index 9e2beebf..fa645b36 100644 --- a/src/component/_generated/component.ts +++ b/src/component/_generated/component.ts @@ -290,6 +290,21 @@ export type ComponentApi = }>, Name >; + queueStats: FunctionReference< + "query", + "internal", + { includeWorker?: boolean; limit?: number }, + { + bytes: number; + newestObservedCommitTs: bigint | null; + oldestCommitTs: bigint | null; + operations: number; + rows: number; + truncated: boolean; + worker: "idle" | "running" | "stopped" | null; + }, + Name + >; }; public: { clear: FunctionReference< diff --git a/src/component/inspect.test.ts b/src/component/inspect.test.ts new file mode 100644 index 00000000..4ce92ead --- /dev/null +++ b/src/component/inspect.test.ts @@ -0,0 +1,161 @@ +import { assert, describe, expect, test } from "vitest"; +import type { TestConvex } from "convex-test"; +import schema, { type Operation } from "./schema.js"; +import { initConvexTest } from "./setup.test.js"; +import { getOrCreateTree } from "./btree.js"; +import { api, internal } from "./_generated/api.js"; +import { enqueueOperations, OPS_WORKER_NAME } from "./worker.js"; + +// Enqueue and return the commitTs of the new row. +async function enqueue( + t: TestConvex, + ...operations: Operation[] +): Promise { + const commitTs = await t.run(async (ctx) => { + await enqueueOperations(ctx, operations); + return ctx.db.vars.commitTs; + }); + assert(typeof commitTs === "bigint"); + return commitTs; +} + +describe("queueStats", () => { + test("reports an empty queue", async () => { + const t = initConvexTest(); + expect( + await t.query(api.inspect.queueStats, { includeWorker: false }), + ).toMatchObject({ + rows: 0, + operations: 0, + truncated: false, + oldestCommitTs: null, + newestObservedCommitTs: null, + }); + }); + + test("counts rows and operations, and tracks the commitTs range", async () => { + const t = initConvexTest(); + const first = await enqueue(t, { type: "insert", key: 1, value: "a" }); + await enqueue( + t, + { type: "insert", key: 2, value: "b" }, + { type: "insert", key: 3, value: "c" }, + ); + const last = await enqueue(t, { type: "delete", key: 1 }); + const stats = await t.query(api.inspect.queueStats, { + includeWorker: false, + }); + expect(stats).toMatchObject({ + rows: 3, + operations: 4, + truncated: false, + oldestCommitTs: first, + newestObservedCommitTs: last, + }); + expect(stats.bytes).toBeGreaterThan(0); + }); + + test("counts down as the worker drains a commit part way", async () => { + // The queue shrinks operation by operation, not just row by row: a commit + // the cycle can't finish keeps its row, holding only what's left to apply. + const t = initConvexTest({ + // A cycle stops once fewer than RESERVE_HEADROOM (100) writes are left, + // and an insert into this tree costs about four, so this budget drains + // roughly two dozen of the 60 operations below. + transactionLimits: { documentsWritten: 200 }, + }); + await t.run(async (ctx) => { + await getOrCreateTree(ctx.db, undefined, 4, false); + }); + await enqueue( + t, + ...Array.from({ length: 60 }, (_, i) => ({ + type: "insert" as const, + key: i, + value: `v${i}`, + })), + ); + const before = await t.query(api.inspect.queueStats, { + includeWorker: false, + }); + expect(before).toMatchObject({ rows: 1, operations: 60 }); + + const batch = await t.query(internal.worker.getBatch, { + name: OPS_WORKER_NAME, + }); + assert(batch.kind === "work"); + await t.mutation(internal.worker.processBatch, { ...batch.batch }); + const after = await t.query(api.inspect.queueStats, { + includeWorker: false, + }); + expect(after.rows).toEqual(1); + expect(60 - after.operations).toBeGreaterThanOrEqual(20); + expect(60 - after.operations).toBeLessThanOrEqual(30); + }); + + test("reports the worker's status, and omits it on request", async () => { + const t = initConvexTest(); + // `includeWorker` defaults to true; before anything enqueues there is no + // worker to report on. + expect(await t.query(api.inspect.queueStats, {})).toMatchObject({ + rows: 0, + worker: null, + }); + await enqueue(t, { type: "insert", key: 1, value: "a" }); + expect(await t.query(api.inspect.queueStats, {})).toMatchObject({ + rows: 1, + worker: "running", + }); + expect( + await t.query(api.inspect.queueStats, { includeWorker: false }), + ).toMatchObject({ rows: 1, worker: null }); + }); + + test("bounds the scan and reports truncation", async () => { + const t = initConvexTest(); + for (let i = 1; i <= 5; i++) { + await enqueue(t, { type: "insert", key: i, value: `v${i}` }); + } + expect( + await t.query(api.inspect.queueStats, { limit: 2, includeWorker: false }), + ).toMatchObject({ rows: 2, operations: 2, truncated: true }); + // A limit that exactly covers the queue is not truncation. + expect( + await t.query(api.inspect.queueStats, { limit: 5, includeWorker: false }), + ).toMatchObject({ rows: 5, operations: 5, truncated: false }); + }); + + test("clamps limit to a whole number in range", async () => { + const t = initConvexTest(); + for (let i = 1; i <= 5; i++) { + await enqueue(t, { type: "insert", key: i, value: `v${i}` }); + } + const rowsFor = async (limit: number) => + (await t.query(api.inspect.queueStats, { limit, includeWorker: false })) + .rows; + expect(await rowsFor(0)).toEqual(1); + expect(await rowsFor(-5)).toEqual(1); + expect(await rowsFor(2.7)).toEqual(2); + // `v.number()` admits these; they must not defeat the cap. + expect(await rowsFor(NaN)).toEqual(5); + expect(await rowsFor(Infinity)).toEqual(5); + }); + + test("stops early when the rows read exceed the byte budget", async () => { + const t = initConvexTest(); + // MAX_BYTES_PER_ENTRY caps a row at 100 KiB, so ~50 of the fattest rows the + // queue can hold overrun the query's 4 MiB read budget. + const value = "x".repeat(100_000); + for (let i = 1; i <= 50; i++) { + await enqueue(t, { type: "insert", key: i, value }); + } + const stats = await t.query(api.inspect.queueStats, { + includeWorker: false, + }); + expect(stats.truncated).toBe(true); + // Neither the queue nor the 128-row default cap ended the scan, and the + // bytes counted crossed the budget: the byte check is what stopped it. + expect(stats.rows).toBeLessThan(50); + expect(stats.bytes).toBeGreaterThanOrEqual(4 * 1024 * 1024); + }); +}); diff --git a/src/component/inspect.ts b/src/component/inspect.ts index 8fe24cb7..5022add6 100644 --- a/src/component/inspect.ts +++ b/src/component/inspect.ts @@ -1,8 +1,10 @@ -import { v } from "convex/values"; +import { getConvexSize, v } from "convex/values"; +import { components } from "./_generated/api.js"; import type { Id } from "./_generated/dataModel.js"; import { type DatabaseReader, query } from "./_generated/server.js"; import { getTree, type Namespace, p } from "./btree.js"; import schema from "./schema.js"; +import { OPS_WORKER_NAME } from "./worker.js"; export const display = query({ args: { namespace: v.optional(v.any()) }, @@ -134,3 +136,107 @@ export const listTreeNodes = query({ return values; }, }); + +// How many queued rows `queueStats` looks at by default, and the most it will +// ever look at. Counting the whole queue is unbounded O(n) document reads, and +// `enqueueOperations` packs rows up to MAX_BYTES_PER_ENTRY (100 KiB), so an +// unbounded count would blow the 16 MiB read limit exactly when the queue is +// deepest — which is when you most want the number. Callers get a bounded count +// plus `truncated`. +const DEFAULT_STATS_LIMIT = 128; +const MAX_STATS_LIMIT = 1024; +// Stop early if the rows read get large, for the same reason getBatch budgets +// its reads — and with the same 4 MiB budget getBatch gives itself. +const STATS_READ_BUDGET_BYTES = 4 * 1024 * 1024; + +/** + * Inspect the async-write queue: how many enqueued operations are still waiting + * to be applied, and whether the background worker is running. + * + * Bounded — it looks at up to `limit` queued rows (default 128, max 1024) and + * sets `truncated` when there are more, so it stays cheap on a deep queue. One + * transaction can hold several rows, so `limit` bounds rows, not transactions. + * When `truncated` is true, `rows`/`operations`/`bytes` are lower bounds and + * `newestObservedCommitTs` is the last row looked at rather than the newest + * queued one, so `newestObservedCommitTs - oldestCommitTs` understates lag. + * + * Deliberately says nothing about how far the worker has drained: the cursor + * lives in the batch worker's high-churn state document, so reading it would + * invalidate this query — and anything subscribed to it — every cycle. + * `operations` already says what's left to do. + * + * Never asserts the queue is empty, unlike the read and write paths that throw + * `PENDING_OPERATIONS`: reading a non-empty queue is the entire point. + */ +export const queueStats = query({ + args: { + limit: v.optional(v.number()), + // Set false to skip the nested batch-worker status query: one fewer nested + // query, and the result stops invalidating when the worker transitions + // between idle and running. + includeWorker: v.optional(v.boolean()), + }, + returns: v.object({ + rows: v.number(), + operations: v.number(), + bytes: v.number(), + truncated: v.boolean(), + oldestCommitTs: v.union(v.int64(), v.null()), + newestObservedCommitTs: v.union(v.int64(), v.null()), + worker: v.union( + v.literal("idle"), + v.literal("running"), + v.literal("stopped"), + v.null(), + ), + }), + handler: async (ctx, { limit, includeWorker }) => { + // `v.number()` admits NaN and Infinity, and a NaN cap would make the row + // check below never fire, so anything non-finite falls back to the default. + const requested = + limit === undefined || !Number.isFinite(limit) + ? DEFAULT_STATS_LIMIT + : Math.floor(limit); + const cap = Math.min(Math.max(requested, 1), MAX_STATS_LIMIT); + let rows = 0; + let operations = 0; + let bytes = 0; + let truncated = false; + let oldestCommitTs: bigint | null = null; + let newestObservedCommitTs: bigint | null = null; + for await (const row of ctx.db + .query("pendingOperations") + .withIndex("by_commitTs")) { + if (rows >= cap || bytes >= STATS_READ_BUDGET_BYTES) { + truncated = true; + break; + } + rows++; + operations += row.operations.length; + bytes += getConvexSize(row); + // A row's commitTs is late-bound: inside its own enqueuing transaction it + // reads back as a placeholder rather than a bigint. A committed row always + // has a real one, but guard anyway (as getBatch does). + const ts = row.commitTs; + if (typeof ts === "bigint") { + if (oldestCommitTs === null) oldestCommitTs = ts; + newestObservedCommitTs = ts; + } + } + const worker = + includeWorker === false + ? null + : await ctx.runQuery(components.batchWorker.lib.status, { + name: OPS_WORKER_NAME, + }); + return { + rows, + operations, + bytes, + truncated, + oldestCommitTs, + newestObservedCommitTs, + worker: worker?.kind ?? null, + }; + }, +}); diff --git a/src/test.ts b/src/test.ts index bf4d4083..3a3e349e 100644 --- a/src/test.ts +++ b/src/test.ts @@ -1,6 +1,7 @@ /// import type { TestConvex } from "convex-test"; import type { GenericSchema, SchemaDefinition } from "convex/server"; +import batchWorker from "@convex-dev/batch-worker/test"; import type { ComponentApi } from "./component/_generated/component.js"; import schema from "./component/schema.js"; const modules = import.meta.glob("./component/**/*.ts"); @@ -16,6 +17,10 @@ export function register( t: TestConvex>, name: string = "aggregate", ) { - return t.registerComponent(name, schema, modules) as unknown as ComponentApi; + const component = t.registerComponent(name, schema, modules); + // The aggregate mounts the batch worker (it drains async writes), so anything + // that reads the queue's status needs it registered too. + batchWorker.register(t, `${name}/batchWorker`); + return component as unknown as ComponentApi; } export default { register, schema, modules };