From 25e5a2661d1d8907c834c88c8019e9601cd5935d Mon Sep 17 00:00:00 2001 From: cliffhall Date: Tue, 20 Oct 2026 01:27:54 -0400 Subject: [PATCH 1/4] feat(cli): add --load mode for load-testing a tool `--load` drives one tool with concurrent, sustained tools/call traffic over the connection the CLI already sets up (transport, headers, OAuth), then prints a latency / error-rate summary in place of the single result. Bounds: --load-concurrency (default 10), --load-duration (default 10s when --load-requests is unset), --load-requests, and --load-rate (even spacing). The summary separates isError results (toolErrors) from calls that threw (errors), groups thrown messages (first ten kinds, rest as "(other)"), and reports nearest-rank latency percentiles and throughput. The engine lives in core/cli/handlers/load-test.ts so mcpdo can reuse it later; only the one-shot CLI exposes it for now. Closes #2439 Co-Authored-By: Claude Opus 5.5 (1M context) Signed-off-by: cliffhall --- clients/cli/README.md | 70 +++- clients/cli/__tests__/load-test.test.ts | 525 ++++++++++++++++++++++++ clients/cli/src/cli.ts | 95 +++++ core/cli/handlers/load-test.ts | 321 +++++++++++++++ 4 files changed, 1010 insertions(+), 1 deletion(-) create mode 100644 clients/cli/__tests__/load-test.test.ts create mode 100644 core/cli/handlers/load-test.ts diff --git a/clients/cli/README.md b/clients/cli/README.md index db48f91e2..efda7034d 100644 --- a/clients/cli/README.md +++ b/clients/cli/README.md @@ -153,6 +153,11 @@ Options that specify the MCP server (catalog/config file, ad-hoc command/URL, en | `-q`, `--quiet` | Print only the result payload on stdout, or the error envelope on stderr on failure. Drops status lines, warnings, advisory summaries and a stdio server's own stderr; OAuth prompts a human must answer still print. See [Quiet output](#quiet-output---quiet). | | `--output ` | Write the result to a file **instead of** stdout. The parent directory must exist; an existing file is replaced. See [Saving a result to a file](#saving-a-result-to-a-file---output). | | `--output-format ` | Encoding of the `--output` file. `json` (default) is the whole result, pretty-printed. `raw` is the result's text, or the decoded bytes of its single image/audio/blob block; `tools/call` and `resources/read` only. | +| `--load` | Load-test one tool: call it repeatedly and concurrently, then print a latency / error-rate summary in place of a result. Requires `--method tools/call --tool-name `. See [Load testing a tool](#load-testing-a-tool---load). | +| `--load-concurrency ` | With `--load`: the most calls in flight at once (positive integer; default `10`). | +| `--load-duration ` | With `--load`: stop starting calls after this many seconds; calls already in flight still finish. Default `10` when `--load-requests` is not set. | +| `--load-requests ` | With `--load`: stop after starting this many calls. With `--load-duration` too, whichever is reached first ends the run. | +| `--load-rate ` | With `--load`: start at most this many calls per second across all workers, spaced evenly (default: unlimited). | | `--relogin` | Delete stored OAuth for this server URL from the shared store before connect; interactive login still only runs if the server requires auth. Requires an HTTP/SSE URL (rejected for stdio). Conflicts with `--stored-auth-only` / `--use-stored-auth` / `--wait-for-auth` / catalog short-circuits. | | `--no-revoke` | With `--relogin`, skip the [RFC 7009](https://datatracker.ietf.org/doc/html/rfc7009) revocation request that would otherwise end the grant at the authorization server when the local state is deleted. The per-server `oauth.revokeOnClear` setting is the persistent form of the same opt-out; either one is enough to skip it. See [Revoking on `--relogin`](#revoking-on---relogin). | | `--stored-auth-only` | **CI / non-interactive safe:** never start interactive OAuth / step-up (and never auto-open a browser); use the shared store if present, otherwise fail immediately with `auth_required`. Prefer this over a bare pipe/CI run that would otherwise attempt interactive login. | @@ -285,7 +290,70 @@ The flag is `--output-format` rather than a new `--format` value because `--form Exit codes are unchanged: a `tools/call` that returns `isError:true` is still written and still exits `5`. A file that cannot be written (missing directory, no permission) exits `1` with envelope code `output_write_failed`. -`--output` is rejected where there is no single result to write — `--app-info`, `--verify`, `--list-stored-auth`, `--print-handoff`, and `servers/list` / `servers/show` — and `--output-format` is rejected without `--output`, rather than either being silently ignored. +`--output` is rejected where there is no single result to write — `--app-info`, `--load`, `--verify`, `--list-stored-auth`, `--print-handoff`, and `servers/list` / `servers/show` — and `--output-format` is rejected without `--output`, rather than either being silently ignored. + +#### Load testing a tool (`--load`) + +`--load` points the Inspector's own connection — transport, headers, OAuth and +all — at one tool and keeps calling it, so seeing how a server behaves under +concurrent or sustained traffic does not mean rewriting that setup in a +separate script ([#2439](https://github.com/modelcontextprotocol/inspector/issues/2439)). + +```bash +# 20 calls in flight for 30 seconds +mcp-inspector --cli --method tools/call --tool-name search \ + --tool-arg query=mcp --load --load-concurrency 20 --load-duration 30 + +# exactly 500 calls, started at no more than 50 per second +mcp-inspector --cli --method tools/call --tool-name search \ + --tool-arg query=mcp --load --load-requests 500 --load-rate 50 +``` + +Every call sends the same arguments and `_meta`. When the run ends, one summary +is printed on stdout (wrapped in `{ "result": … }` with `--format json`): + +```json +{ + "tool": "search", + "concurrency": 20, + "durationMs": 30000, + "requests": 41210, + "ok": 41187, + "toolErrors": 0, + "errors": 23, + "errorRate": 0.0006, + "elapsedMs": 30012.4, + "throughput": 1373.12, + "latencyMs": { "min": 2.1, "mean": 14.5, "p50": 12.9, "p90": 22.4, "p99": 61.3, "max": 30004.8 }, + "errorMessages": [{ "message": "Request timed out", "count": 23 }] +} +``` + +- **`toolErrors`** counts results carrying `isError: true` — the tool ran and + reported a failure. **`errors`** counts calls that never produced a result: + protocol errors, request timeouts, a dropped connection. `errorRate` is both + together over `requests`, rounded to four places. +- **`errorMessages`** groups the thrown messages by frequency. The first ten + distinct messages are kept; any further ones are counted under `(other)`. +- **Latency** is per call, client-side, in milliseconds, with nearest-rank + percentiles. It includes everything the Inspector does around the request, + which is negligible next to a network round trip but not next to a + sub-millisecond stdio echo. +- **Bounds.** `--load-duration` stops *starting* calls; anything in flight is + allowed to finish, so `elapsedMs` can exceed the window by up to one call. + With `--load-rate`, a call whose slot falls past the window is never started. + +**All calls share one connection**, so this measures how a server copes with +concurrent requests on a single session — not with many sessions. A slow call +is bounded by the server's request timeout (`requestTimeout` in the +catalog/config file). + +The tool is looked up once before the clock starts, so a missing tool fails +the run with exit `5` (`tool_not_found`) instead of reporting a 100% error +rate. Otherwise a completed run exits `0` whatever its error rate — the summary +is the result. `--load` is rejected with any other method and with +`--app-info`, `--output` and `--output-format`, and each `--load-*` flag is +rejected without `--load`. #### Schema portability (`--strict`) diff --git a/clients/cli/__tests__/load-test.test.ts b/clients/cli/__tests__/load-test.test.ts new file mode 100644 index 000000000..b59b03cb3 --- /dev/null +++ b/clients/cli/__tests__/load-test.test.ts @@ -0,0 +1,525 @@ +import { describe, it, expect } from "vitest"; +import { runCli } from "./helpers/cli-runner.js"; +import { + expectCliSuccess, + expectCliFailure, + expectValidJson, +} from "./helpers/assertions.js"; +import { + getTestMcpServerCommand, + createTestServerHttp, + createTestServerInfo, + createSimpleTaskTool, + getCrashableTestMcpServerCommand, + CRASH_SERVER_TOOL_NAME, +} from "@modelcontextprotocol/inspector-test-server"; +import { + DEFAULT_LOAD_CONCURRENCY, + DEFAULT_LOAD_DURATION_MS, + MAX_ERROR_KINDS, + OTHER_ERRORS, + percentile, + positiveIntegerParser, + positiveNumberParser, + resolveLoadOptions, + runLoad, + summarizeLatency, + type LoadCallOutcome, + type LoadClock, +} from "@inspector/core/cli/handlers/load-test.js"; + +/** + * A clock that only moves when told to. `sleep` advances it by the requested + * amount, so a rate-limited run completes instantly while still observing + * the schedule it would keep in real time. + */ +function fakeClock(): LoadClock & { advance: (ms: number) => void } { + let t = 1000; + return { + now: () => t, + sleep: async (ms) => { + t += ms; + }, + advance: (ms) => { + t += ms; + }, + }; +} + +describe("load-test engine", () => { + describe("percentile / summarizeLatency", () => { + it("uses nearest-rank percentiles", () => { + const sorted = Array.from({ length: 100 }, (_, i) => i + 1); + expect(percentile(sorted, 50)).toBe(50); + expect(percentile(sorted, 90)).toBe(90); + expect(percentile(sorted, 99)).toBe(99); + expect(percentile([7], 99)).toBe(7); + expect(percentile([1, 2, 3], 0)).toBe(1); + }); + + it("summarizes unsorted samples and returns null for none", () => { + expect(summarizeLatency([])).toBeNull(); + expect(summarizeLatency([3, 1, 2])).toEqual({ + min: 1, + mean: 2, + p50: 2, + p90: 3, + p99: 3, + max: 3, + }); + }); + }); + + describe("flag parsers", () => { + it("accepts only plain positive integers for integer flags", () => { + const parse = positiveIntegerParser("--load-requests"); + expect(parse(" 25 ")).toBe(25); + for (const bad of ["0", "-1", "1.5", "1e3", "0x10", "", "abc"]) { + expect(() => parse(bad)).toThrow( + "--load-requests must be a positive integer.", + ); + } + }); + + it("accepts positive finite numbers for number flags", () => { + const parse = positiveNumberParser("--load-rate"); + expect(parse("2.5")).toBe(2.5); + for (const bad of ["0", "-1", "", " ", "Infinity", "abc"]) { + expect(() => parse(bad)).toThrow( + "--load-rate must be a positive number.", + ); + } + }); + }); + + describe("resolveLoadOptions", () => { + it("defaults to the default concurrency over the default window", () => { + expect(resolveLoadOptions({})).toEqual({ + concurrency: DEFAULT_LOAD_CONCURRENCY, + durationMs: DEFAULT_LOAD_DURATION_MS, + }); + }); + + it("drops the default window when a request count bounds the run", () => { + expect(resolveLoadOptions({ requests: 5, concurrency: 2 })).toEqual({ + concurrency: 2, + requests: 5, + }); + }); + + it("keeps both bounds and the rate when all are given", () => { + expect( + resolveLoadOptions({ durationSec: 1.5, requests: 5, rate: 3 }), + ).toEqual({ + concurrency: DEFAULT_LOAD_CONCURRENCY, + durationMs: 1500, + requests: 5, + rate: 3, + }); + }); + }); + + describe("runLoad", () => { + it("starts exactly the request count and never exceeds concurrency", async () => { + let inFlight = 0; + let peak = 0; + const call = async (): Promise => { + inFlight++; + peak = Math.max(peak, inFlight); + await new Promise((r) => setTimeout(r, 1)); + inFlight--; + return "ok"; + }; + const summary = await runLoad(call, { concurrency: 4, requests: 23 }); + expect(summary.requests).toBe(23); + expect(summary.ok).toBe(23); + expect(summary.requestLimit).toBe(23); + expect(peak).toBe(4); + expect(summary.errorRate).toBe(0); + expect(summary.latencyMs).not.toBeNull(); + expect(summary.throughput).toBeGreaterThan(0); + }); + + it("classifies ok, tool errors and thrown errors", async () => { + let n = 0; + const call = async (): Promise => { + const i = n++; + if (i % 4 === 1) return "tool_error"; + if (i % 4 === 2) throw new Error("boom"); + // A non-Error rejection is still counted, by its string form. + if (i % 4 === 3) throw "raw"; + return "ok"; + }; + const summary = await runLoad( + call, + { concurrency: 1, requests: 8 }, + fakeClock(), + ); + expect(summary).toMatchObject({ + requests: 8, + ok: 2, + toolErrors: 2, + errors: 4, + errorRate: 0.75, + errorMessages: [ + { message: "boom", count: 2 }, + { message: "raw", count: 2 }, + ], + }); + }); + + it("keeps a rare error visible in the error rate", async () => { + let n = 0; + const call = async (): Promise => + n++ === 0 ? "tool_error" : "ok"; + const summary = await runLoad( + call, + { concurrency: 1, requests: 3000 }, + fakeClock(), + ); + expect(summary.errorRate).toBe(0.0003); + }); + + it("folds error kinds past the cap into one (other) entry", async () => { + let n = 0; + const call = async (): Promise => { + throw new Error(`request ${n++} failed`); + }; + const summary = await runLoad( + call, + { concurrency: 1, requests: MAX_ERROR_KINDS + 3 }, + fakeClock(), + ); + expect(summary.errorMessages).toHaveLength(MAX_ERROR_KINDS + 1); + expect(summary.errorMessages.at(-1)).toEqual({ + message: OTHER_ERRORS, + count: 3, + }); + }); + + it("stops starting calls at the deadline and lets in-flight ones finish", async () => { + const clock = fakeClock(); + const call = async (): Promise => { + clock.advance(100); + return "ok"; + }; + const summary = await runLoad( + call, + { concurrency: 1, durationMs: 1000 }, + clock, + ); + // Calls start at 0, 100, …, 900ms; the one started at 900 ends at 1000. + expect(summary.requests).toBe(10); + expect(summary.durationMs).toBe(1000); + expect(summary.elapsedMs).toBe(1000); + expect(summary.throughput).toBe(10); + expect(summary.latencyMs).toMatchObject({ min: 100, max: 100 }); + }); + + it("spaces starts evenly at the rate and never sleeps past the window", async () => { + const clock = fakeClock(); + const starts: number[] = []; + const call = async (): Promise => { + starts.push(clock.now()); + return "ok"; + }; + const summary = await runLoad( + call, + { concurrency: 1, durationMs: 1000, rate: 4 }, + clock, + ); + expect(starts.map((t) => t - 1000)).toEqual([0, 250, 500, 750]); + expect(summary.rate).toBe(4); + expect(summary.requests).toBe(4); + }); + + it("does not sleep for a slot whose time has already passed", async () => { + const clock = fakeClock(); + const call = async (): Promise => { + clock.advance(500); + return "ok"; + }; + const summary = await runLoad( + call, + { concurrency: 1, requests: 3, rate: 10 }, + clock, + ); + // Each call outlasts its 100ms slot, so the schedule never holds one back. + expect(summary.elapsedMs).toBe(1500); + }); + + it("reports an empty run without dividing by zero", async () => { + const summary = await runLoad( + async () => "ok", + { concurrency: 2, durationMs: 0 }, + fakeClock(), + ); + expect(summary).toMatchObject({ + requests: 0, + errorRate: 0, + throughput: 0, + latencyMs: null, + errorMessages: [], + }); + }); + }); +}); + +describe("--load (CLI)", () => { + const { command, args } = getTestMcpServerCommand(); + const echoLoad = [ + command, + ...args, + "--cli", + "--method", + "tools/call", + "--tool-name", + "echo", + "--tool-arg", + "message=hi", + ]; + + it("prints a summary of the requested number of calls", async () => { + const result = await runCli([ + ...echoLoad, + "--load", + "--load-requests", + "30", + "--load-concurrency", + "5", + ]); + expectCliSuccess(result); + const json = expectValidJson(result); + expect(json).toMatchObject({ + tool: "echo", + concurrency: 5, + requestLimit: 30, + requests: 30, + ok: 30, + toolErrors: 0, + errors: 0, + errorRate: 0, + }); + expect(json.durationMs).toBeUndefined(); + expect(json.latencyMs.p99).toBeGreaterThanOrEqual(json.latencyMs.p50); + }); + + it("wraps the summary in the result envelope with --format json", async () => { + const result = await runCli([ + ...echoLoad, + "--load", + "--load-duration", + "0.2", + "--load-rate", + "20", + "--format", + "json", + ]); + expectCliSuccess(result); + const { result: summary } = expectValidJson(result); + expect(summary).toMatchObject({ tool: "echo", durationMs: 200, rate: 20 }); + expect(summary.requests).toBeGreaterThan(0); + expect(summary.requests).toBeLessThanOrEqual(4); + }); + + it("fails before loading when the tool does not exist", async () => { + const result = await runCli([ + command, + ...args, + "--cli", + "--method", + "tools/call", + "--tool-name", + "no_such_tool", + "--load", + "--load-requests", + "3", + ]); + expect(result.exitCode).toBe(5); + expect(result.stderr).toContain("Tool 'no_such_tool' not found on server."); + }); + + it("requires a tool name", async () => { + const result = await runCli([ + command, + ...args, + "--cli", + "--method", + "tools/call", + "--load", + ]); + expectCliFailure(result); + expect(result.stderr).toContain("--load requires --tool-name."); + }); + + it.each([ + [ + ["--method", "tools/list", "--load"], + "--load requires --method tools/call.", + ], + [ + ["--method", "tools/call", "--tool-name", "echo", "--load", "--app-info"], + "--load cannot be combined with --app-info.", + ], + [ + [ + "--method", + "tools/call", + "--tool-name", + "echo", + "--load", + "--output", + "out.json", + ], + "--load cannot be combined with --output or --output-format", + ], + [ + [ + "--method", + "tools/call", + "--tool-name", + "echo", + "--load-concurrency", + "2", + ], + "--load-concurrency requires --load.", + ], + [ + ["--method", "tools/call", "--tool-name", "echo", "--load-duration", "1"], + "--load-duration requires --load.", + ], + [ + ["--method", "tools/call", "--tool-name", "echo", "--load-requests", "1"], + "--load-requests requires --load.", + ], + [ + ["--method", "tools/call", "--tool-name", "echo", "--load-rate", "1"], + "--load-rate requires --load.", + ], + [ + ["--method", "tools/call", "--load", "--load-concurrency", "0"], + "--load-concurrency must be a positive integer.", + ], + ])("rejects %j", async (flags, message) => { + const result = await runCli([command, ...args, "--cli", ...flags]); + expect(result.exitCode).toBe(1); + expect(result.stderr).toContain(message); + }); + + it("counts a result carrying isError as a tool error", async () => { + let n = 0; + const server = createTestServerHttp({ + serverInfo: createTestServerInfo("load-mixed", "1.0.0"), + tools: [ + { + name: "flaky", + description: "Succeeds and fails in turn", + inputSchema: {}, + // The SDK answers a throwing handler with `isError: true`. + handler: async () => { + if (n++ % 2 === 1) throw new Error("flaky refused"); + return { content: [{ type: "text", text: "flaky" }] }; + }, + }, + ], + }); + try { + await server.start(); + const result = await runCli([ + server.url, + "--cli", + "--transport", + "http", + "--method", + "tools/call", + "--tool-name", + "flaky", + "--load", + "--load-requests", + "8", + "--load-concurrency", + "1", + ]); + expectCliSuccess(result); + expect(expectValidJson(result)).toMatchObject({ + requests: 8, + ok: 4, + toolErrors: 4, + errors: 0, + errorRate: 0.5, + errorMessages: [], + }); + } finally { + await server.stop(); + } + }); + + it("counts calls that throw, and keeps going, when the server dies", async () => { + const crashable = getCrashableTestMcpServerCommand(); + const result = await runCli([ + crashable.command, + ...crashable.args, + "--cli", + "--method", + "tools/call", + "--tool-name", + CRASH_SERVER_TOOL_NAME, + "--load", + "--load-requests", + "3", + "--load-concurrency", + "1", + ]); + // The run completed and reported; the failures are in the summary. + expectCliSuccess(result); + const json = expectValidJson(result); + expect(json).toMatchObject({ + requests: 3, + ok: 0, + toolErrors: 0, + errors: 3, + errorRate: 1, + }); + expect( + json.errorMessages.reduce( + (sum: number, e: { count: number }) => sum + e.count, + 0, + ), + ).toBe(3); + }); + + it("loads a taskSupport: required tool through the task path", async () => { + const server = createTestServerHttp({ + serverInfo: createTestServerInfo("load-tasks", "1.0.0"), + tools: [createSimpleTaskTool("simple_task", 10)], + tasks: { list: true, cancel: true }, + logging: true, + }); + try { + await server.start(); + const result = await runCli([ + server.url, + "--cli", + "--transport", + "http", + "--method", + "tools/call", + "--tool-name", + "simple_task", + "--load", + "--load-requests", + "3", + "--load-concurrency", + "3", + ]); + expectCliSuccess(result); + expect(expectValidJson(result)).toMatchObject({ + tool: "simple_task", + requests: 3, + ok: 3, + }); + } finally { + await server.stop(); + } + }); +}); diff --git a/clients/cli/src/cli.ts b/clients/cli/src/cli.ts index c9fa21593..f2a31adcb 100644 --- a/clients/cli/src/cli.ts +++ b/clients/cli/src/cli.ts @@ -57,6 +57,13 @@ import { import { getStateFilePath } from "@inspector/core/auth/node/storage-node.js"; import { SecretFileLockHeldError } from "@inspector/core/auth/node/secret-store.js"; import { consumeMethodOutcome } from "./handlers/consume-outcome.js"; +import { + positiveIntegerParser, + positiveNumberParser, + resolveLoadOptions, + runToolLoad, + type LoadOptions, +} from "@inspector/core/cli/handlers/load-test.js"; import { runMethod } from "@inspector/core/cli/handlers/run-method.js"; import { isOneShotMethod, @@ -137,6 +144,7 @@ async function callMethod( storedAuthOnly: boolean, relogin: boolean, revoke: boolean, + load?: LoadOptions, ): Promise { // Clear after parse-time validation so a bad flag combo never deletes store // entries. Deletes the shared URL-keyed OAuth entry (not "ignore for this run"). @@ -262,6 +270,25 @@ async function callMethod( { storedAuthOnly, autoOpenControl, quiet: args.quiet }, ); + // `--load` (#2439): many calls of one tool, then a single summary, in + // place of the one result a plain `tools/call` prints. + if (load) { + const summary = await withCliAuthRecoveryRetry( + inspectorClient, + serverConfig, + redirectUrlProvider, + callbackUrlConfig, + serverSettings, + () => runToolLoad(inspectorClient, args, load), + { storedAuthOnly, autoOpenControl, quiet: args.quiet }, + ); + await writeFormattedResult( + summary, + args.format === "json" ? "json" : "text", + ); + return; + } + const outcome = await withCliAuthRecoveryRetry( inspectorClient, serverConfig, @@ -789,6 +816,7 @@ type ParseResult = storedAuthOnly?: boolean; relogin?: boolean; revoke?: boolean; + load?: LoadOptions; } // Short-circuit modes (`--list-stored-auth`, `--print-handoff`) do their own // output and need no server connection; runCli returns immediately. @@ -997,6 +1025,30 @@ async function parseArgs(argv?: string[]): Promise { "--require-digests", 'With --verify: exit 9 when a skill advertises no digests (resources: "dynamic"), instead of reporting it as unverifiable and exiting 0.', ) + .option( + "--load", + "Load-test one tool: call it repeatedly and concurrently, then print a latency and error-rate summary instead of a result. Use with --method tools/call --tool-name . Bounded by --load-duration (default 10s) and/or --load-requests.", + ) + .option( + "--load-concurrency ", + "With --load: most calls in flight at once (positive integer; default 10).", + positiveIntegerParser("--load-concurrency"), + ) + .option( + "--load-duration ", + "With --load: stop starting calls after this many seconds; in-flight calls still finish (default 10 when --load-requests is not set).", + positiveNumberParser("--load-duration"), + ) + .option( + "--load-requests ", + "With --load: stop after starting this many calls (positive integer).", + positiveIntegerParser("--load-requests"), + ) + .option( + "--load-rate ", + "With --load: start at most this many calls per second, spread evenly (positive number; default unlimited).", + positiveNumberParser("--load-rate"), + ) .option( "--connect-timeout ", `Connection timeout in ms (default ${DEFAULT_CONNECT_TIMEOUT_MS} for ad-hoc --server-url / target invocations; 0 = no timeout).`, @@ -1185,6 +1237,11 @@ async function parseArgs(argv?: string[]): Promise { waitForAuth?: number; listStoredAuth?: boolean; printHandoff?: boolean; + load?: boolean; + loadConcurrency?: number; + loadDuration?: number; + loadRequests?: number; + loadRate?: number; }; if (options.relogin) { @@ -1272,6 +1329,34 @@ async function parseArgs(argv?: string[]): Promise { throw new Error("--skill-catalog-max-bytes requires --verify."); } + // `--load` (#2439) is checked here for the same reason as `--strict`: the + // short-circuit returns below would otherwise accept it and do nothing. + const loadBounds = [ + ["--load-concurrency", options.loadConcurrency], + ["--load-duration", options.loadDuration], + ["--load-requests", options.loadRequests], + ["--load-rate", options.loadRate], + ] as const; + for (const [flag, value] of loadBounds) { + if (value !== undefined && !options.load) { + throw new Error(`${flag} requires --load.`); + } + } + if (options.load) { + if (options.method !== "tools/call") { + throw new Error("--load requires --method tools/call."); + } + // Each of these shapes a single result; a load run prints a summary. + if (options.appInfo) { + throw new Error("--load cannot be combined with --app-info."); + } + if (options.output !== undefined || options.outputFormat !== undefined) { + throw new Error( + "--load cannot be combined with --output or --output-format; redirect stdout to keep the summary.", + ); + } + } + // `--advertise-apps` is checked here for the same reason: it shapes the // `initialize` handshake, and the short-circuit paths below never open an // MCP connection, so accepting it there would silently ignore it. @@ -1577,6 +1662,14 @@ async function parseArgs(argv?: string[]): Promise { // Commander's `--no-revoke` defaults this to true; only an explicit // `--no-revoke` makes it false. revoke: options.revoke !== false, + ...(options.load && { + load: resolveLoadOptions({ + concurrency: options.loadConcurrency, + durationSec: options.loadDuration, + requests: options.loadRequests, + rate: options.loadRate, + }), + }), }; } @@ -1611,6 +1704,7 @@ async function runParsedCli(argv?: string[]): Promise { storedAuthOnly, relogin, revoke, + load, } = parsed; const clientConfig = await loadRunnerClientConfig({ clientConfigPath }); // A bad --callback-url / MCP_OAUTH_CALLBACK_URL is a *usage* error, but its @@ -1641,5 +1735,6 @@ async function runParsedCli(argv?: string[]): Promise { storedAuthOnly === true, relogin === true, revoke !== false, + load, ); } diff --git a/core/cli/handlers/load-test.ts b/core/cli/handlers/load-test.ts new file mode 100644 index 000000000..95d089ef4 --- /dev/null +++ b/core/cli/handlers/load-test.ts @@ -0,0 +1,321 @@ +import type { Tool } from "@modelcontextprotocol/client"; +import type { InspectorClient } from "../../mcp/index.js"; +import { ManagedToolsState } from "../../mcp/state/index.js"; +import { CliExitCodeError, EXIT_CODES } from "../error-handler.js"; +import type { MethodArgs } from "./method-types.js"; + +/** + * `--load` (#2439): drive one tool with sustained, concurrent `tools/call` + * traffic over the connection the Inspector already set up — transport, OAuth + * and headers included — and report latency and error rate at the end. + * + * Lives in `core/cli/` rather than the CLI client so `mcpdo` can reuse it + * against a daemon connection without a second copy; only the one-shot CLI + * exposes it today. + * + * All calls share ONE connection, so this measures how a server handles + * concurrent requests on a session, not how it handles many sessions. + */ + +/** Bounds for one load run. Validated by the caller before connecting. */ +export type LoadOptions = { + /** Most calls in flight at once. */ + concurrency: number; + /** Stop starting calls after this long. In-flight calls still finish. */ + durationMs?: number; + /** Stop after this many calls have been started. */ + requests?: number; + /** Cap on calls started per second, across all workers. */ + rate?: number; +}; + +/** How one call ended. `tool_error` is a result carrying `isError: true`. */ +export type LoadCallOutcome = "ok" | "tool_error"; + +/** Latency distribution in milliseconds, nearest-rank percentiles. */ +export type LoadLatency = { + min: number; + mean: number; + p50: number; + p90: number; + p99: number; + max: number; +}; + +export type LoadSummary = { + tool?: string; + concurrency: number; + durationMs?: number; + requestLimit?: number; + rate?: number; + /** Calls that completed, in any outcome. */ + requests: number; + ok: number; + /** Calls that returned a result with `isError: true`. */ + toolErrors: number; + /** Calls that threw: protocol errors, timeouts, transport failures. */ + errors: number; + /** `(toolErrors + errors) / requests` to four places; 0 when none completed. */ + errorRate: number; + elapsedMs: number; + /** Completed calls per second of wall clock. */ + throughput: number; + /** `null` when no call completed. */ + latencyMs: LoadLatency | null; + /** Thrown messages by frequency, at most {@link MAX_ERROR_KINDS} of them. */ + errorMessages: { message: string; count: number }[]; +}; + +export const DEFAULT_LOAD_CONCURRENCY = 10; +/** Applied only when neither a duration nor a request count is given. */ +export const DEFAULT_LOAD_DURATION_MS = 10_000; + +/** + * Commander-style parser for a positive integer flag (`--load-concurrency`, + * `--load-requests`). Plain decimal digits only, so `1.5`, `1e3` and `0x10` + * are refused rather than coerced. + */ +export function positiveIntegerParser(flag: string): (value: string) => number { + return (value: string): number => { + const trimmed = value.trim(); + const n = /^\d+$/.test(trimmed) ? Number(trimmed) : NaN; + if (!Number.isSafeInteger(n) || n <= 0) { + throw new Error(`${flag} must be a positive integer.`); + } + return n; + }; +} + +/** Commander-style parser for a positive, finite number flag. */ +export function positiveNumberParser(flag: string): (value: string) => number { + return (value: string): number => { + const n = value.trim() === "" ? NaN : Number(value); + if (!Number.isFinite(n) || n <= 0) { + throw new Error(`${flag} must be a positive number.`); + } + return n; + }; +} + +/** + * Turn the raw flag values into {@link LoadOptions}, applying the defaults: + * {@link DEFAULT_LOAD_CONCURRENCY} workers, and a + * {@link DEFAULT_LOAD_DURATION_MS} window when no request count bounds the + * run instead. Given both, the run stops at whichever is reached first. + */ +export function resolveLoadOptions(flags: { + concurrency?: number; + durationSec?: number; + requests?: number; + rate?: number; +}): LoadOptions { + const durationMs = + flags.durationSec !== undefined + ? flags.durationSec * 1000 + : flags.requests === undefined + ? DEFAULT_LOAD_DURATION_MS + : undefined; + return { + concurrency: flags.concurrency ?? DEFAULT_LOAD_CONCURRENCY, + ...(durationMs !== undefined && { durationMs }), + ...(flags.requests !== undefined && { requests: flags.requests }), + ...(flags.rate !== undefined && { rate: flags.rate }), + }; +} + +/** Distinct error messages kept; the rest fold into one `(other)` entry. */ +export const MAX_ERROR_KINDS = 10; +export const OTHER_ERRORS = "(other)"; + +/** Injected so tests can drive the clock instead of waiting on it. */ +export type LoadClock = { + now: () => number; + sleep: (ms: number) => Promise; +}; + +const realClock: LoadClock = { + now: () => performance.now(), + sleep: (ms) => new Promise((resolve) => setTimeout(resolve, ms)), +}; + +/** Nearest-rank percentile over an ascending-sorted, non-empty array. */ +export function percentile(sorted: number[], p: number): number { + const rank = Math.ceil((p / 100) * sorted.length); + return sorted[Math.min(Math.max(rank, 1), sorted.length) - 1]!; +} + +function round(n: number, places = 2): number { + const scale = 10 ** places; + return Math.round(n * scale) / scale; +} + +export function summarizeLatency(latencies: number[]): LoadLatency | null { + if (latencies.length === 0) return null; + const sorted = [...latencies].sort((a, b) => a - b); + const total = sorted.reduce((sum, n) => sum + n, 0); + return { + min: round(sorted[0]!), + mean: round(total / sorted.length), + p50: round(percentile(sorted, 50)), + p90: round(percentile(sorted, 90)), + p99: round(percentile(sorted, 99)), + max: round(sorted[sorted.length - 1]!), + }; +} + +/** + * Count thrown messages, keeping the first {@link MAX_ERROR_KINDS} distinct + * ones seen. A failing server tends to fail the same way every time, but one + * that embeds a request id in each message would otherwise grow the map by + * one key per call for the whole run. + */ +class ErrorTally { + private readonly counts = new Map(); + private other = 0; + + add(message: string): void { + const count = this.counts.get(message); + if (count !== undefined) this.counts.set(message, count + 1); + else if (this.counts.size < MAX_ERROR_KINDS) this.counts.set(message, 1); + else this.other++; + } + + entries(): { message: string; count: number }[] { + const list = [...this.counts].map(([message, count]) => ({ + message, + count, + })); + list.sort((a, b) => b.count - a.count); + if (this.other > 0) list.push({ message: OTHER_ERRORS, count: this.other }); + return list; + } +} + +/** + * Run `call` under the given bounds and summarize what happened. Workers pull + * slots from a shared counter, so `concurrency` is a hard cap on calls in + * flight and `requests` a hard cap on calls started. With `rate`, slot `i` + * may not start before `i / rate` seconds into the run — an even schedule + * rather than a burst each second. + * + * A slot whose scheduled start falls past the duration is never started, so a + * rate-limited run does not overshoot its window by sleeping into it. + */ +export async function runLoad( + call: () => Promise, + options: LoadOptions, + clock: LoadClock = realClock, +): Promise { + const { concurrency, durationMs, requests, rate } = options; + const latencies: number[] = []; + const tally = new ErrorTally(); + let ok = 0; + let toolErrors = 0; + let errors = 0; + let started = 0; + + const start = clock.now(); + const deadline = durationMs === undefined ? Infinity : start + durationMs; + + const worker = async (): Promise => { + for (;;) { + if (requests !== undefined && started >= requests) return; + if (clock.now() >= deadline) return; + const slot = started++; + if (rate !== undefined) { + const scheduled = start + (slot * 1000) / rate; + if (scheduled >= deadline) return; + const wait = scheduled - clock.now(); + if (wait > 0) await clock.sleep(wait); + } + const t0 = clock.now(); + try { + const outcome = await call(); + if (outcome === "ok") ok++; + else toolErrors++; + } catch (err) { + errors++; + tally.add(err instanceof Error ? err.message : String(err)); + } + latencies.push(clock.now() - t0); + } + }; + + await Promise.all(Array.from({ length: concurrency }, worker)); + + const elapsedMs = clock.now() - start; + const completed = ok + toolErrors + errors; + return { + concurrency, + ...(durationMs !== undefined && { durationMs }), + ...(requests !== undefined && { requestLimit: requests }), + ...(rate !== undefined && { rate }), + requests: completed, + ok, + toolErrors, + errors, + // Four places, so a rare failure under heavy load (23 in 41k) still shows. + errorRate: + completed === 0 ? 0 : round((toolErrors + errors) / completed, 4), + elapsedMs: round(elapsedMs), + throughput: elapsedMs > 0 ? round((completed * 1000) / elapsedMs) : 0, + latencyMs: summarizeLatency(latencies), + errorMessages: tally.entries(), + }; +} + +/** + * Resolve `args.toolName` once, then load it with {@link runLoad}. The tool + * lookup happens before the clock starts, so a missing tool fails the run + * outright (exit 5, as a plain `tools/call` would) instead of being reported + * as a 100% error rate. + */ +export async function runToolLoad( + inspectorClient: InspectorClient, + args: MethodArgs, + options: LoadOptions, + clock?: LoadClock, +): Promise { + if (!args.toolName) { + throw new Error("--load requires --tool-name."); + } + const toolsState = new ManagedToolsState(inspectorClient); + let found: Tool | undefined; + try { + toolsState.setMetadata(args.metadata); + await toolsState.refresh(); + found = toolsState.getTools().find((t) => t.name === args.toolName); + } finally { + toolsState.destroy(); + } + if (!found) { + throw new CliExitCodeError( + EXIT_CODES.TOOL_ERROR, + `Tool '${args.toolName}' not found on server.`, + { code: "tool_not_found" }, + ); + } + const tool = found; + // Same rule as a single `tools/call` (#2649): a tool that requires task + // support can only be called task-augmented. + const useTask = tool.execution?.taskSupport === "required"; + const call = async (): Promise => { + const params = [ + tool, + args.toolArg ?? {}, + args.metadata, + args.toolMeta, + ] as const; + const invocation = useTask + ? await inspectorClient.callToolStream(...params) + : await inspectorClient.callTool(...params); + /* v8 ignore next 3 -- defensive: `ToolCallInvocation.result` is nullable, + but both call paths throw on failure rather than return a null result. */ + if (invocation.result === null) { + throw new Error(invocation.error ?? "Tool call failed"); + } + return invocation.result.isError === true ? "tool_error" : "ok"; + }; + const summary = await runLoad(call, options, clock); + return { tool: tool.name, ...summary }; +} From 9649799a7379e5497bc67988bcadda1b9ee0fb83 Mon Sep 17 00:00:00 2001 From: cliffhall Date: Tue, 20 Oct 2026 01:43:43 -0400 Subject: [PATCH 2/4] fix(cli): drop missed --load-rate slots and recheck the deadline after a wait The rate limiter scheduled slot i at start + i/rate, so a stall (one slow call at concurrency 1) left every missed slot owed and they all started at once afterwards. It now keys off the last slot actually handed out, so a missed slot is dropped and starts stay at least 1/rate apart. The deadline is also checked again after the rate wait, since a timer that wakes late under load would otherwise start a call past --load-duration. --load is now rejected with --list-stored-auth and --print-handoff, which return before the load runs. The README notes that a load run does not prompt for OAuth step-up. The engine tests' fake clock gains a timer queue so concurrent sleepers wake in order, as real timers do. Co-Authored-By: Claude Opus 5.5 (1M context) Signed-off-by: cliffhall --- clients/cli/README.md | 13 ++- clients/cli/__tests__/load-test.test.ts | 103 ++++++++++++++++++++++-- clients/cli/src/cli.ts | 5 ++ core/cli/handlers/load-test.ts | 25 ++++-- 4 files changed, 130 insertions(+), 16 deletions(-) diff --git a/clients/cli/README.md b/clients/cli/README.md index efda7034d..dcd96363b 100644 --- a/clients/cli/README.md +++ b/clients/cli/README.md @@ -341,18 +341,25 @@ is printed on stdout (wrapped in `{ "result": … }` with `--format json`): sub-millisecond stdio echo. - **Bounds.** `--load-duration` stops *starting* calls; anything in flight is allowed to finish, so `elapsedMs` can exceed the window by up to one call. - With `--load-rate`, a call whose slot falls past the window is never started. + With `--load-rate`, starts are at least `1/rate` seconds apart, and a slot + nobody was free to take is dropped rather than made up later — a stall is + never followed by a catch-up burst. A slot that falls past the window is + never started. **All calls share one connection**, so this measures how a server copes with concurrent requests on a single session — not with many sessions. A slow call is bounded by the server's request timeout (`requestTimeout` in the catalog/config file). +A load run does not prompt for OAuth step-up: a tool that needs scopes the +session lacks fails every call, and the challenge shows in `errorMessages`. +Run one plain `tools/call` of the tool first to grant them, then load it. + The tool is looked up once before the clock starts, so a missing tool fails the run with exit `5` (`tool_not_found`) instead of reporting a 100% error rate. Otherwise a completed run exits `0` whatever its error rate — the summary -is the result. `--load` is rejected with any other method and with -`--app-info`, `--output` and `--output-format`, and each `--load-*` flag is +is the result. `--load` is rejected with any other method and with `--app-info`, +`--output`, `--output-format`, `--list-stored-auth` and `--print-handoff`, and each `--load-*` flag is rejected without `--load`. #### Schema portability (`--strict`) diff --git a/clients/cli/__tests__/load-test.test.ts b/clients/cli/__tests__/load-test.test.ts index b59b03cb3..d1955ce7b 100644 --- a/clients/cli/__tests__/load-test.test.ts +++ b/clients/cli/__tests__/load-test.test.ts @@ -29,17 +29,38 @@ import { } from "@inspector/core/cli/handlers/load-test.js"; /** - * A clock that only moves when told to. `sleep` advances it by the requested - * amount, so a rate-limited run completes instantly while still observing - * the schedule it would keep in real time. + * A clock that only moves when told to, with a timer queue: each `sleep` + * wakes at an absolute time, and timers fire one at a time in wake order, + * each on its own macrotask so the woken worker runs (up to its next await) + * before the clock moves again — as real timers behave. A rate-limited run + * therefore completes instantly while keeping the schedule it would in real + * time. */ function fakeClock(): LoadClock & { advance: (ms: number) => void } { let t = 1000; + const timers: { wakeAt: number; resolve: () => void }[] = []; + let pumping = false; + const pump = (): void => { + timers.sort((a, b) => a.wakeAt - b.wakeAt); + const next = timers.shift(); + if (!next) { + pumping = false; + return; + } + t = Math.max(t, next.wakeAt); + next.resolve(); + setImmediate(pump); + }; return { now: () => t, - sleep: async (ms) => { - t += ms; - }, + sleep: (ms) => + new Promise((resolve) => { + timers.push({ wakeAt: t + ms, resolve }); + if (!pumping) { + pumping = true; + setImmediate(pump); + } + }), advance: (ms) => { t += ms; }, @@ -233,6 +254,52 @@ describe("load-test engine", () => { expect(summary.requests).toBe(4); }); + it("drops missed rate slots instead of bursting to catch up", async () => { + const clock = fakeClock(); + const starts: number[] = []; + let n = 0; + const call = async (): Promise => { + starts.push(clock.now() - 1000); + if (n++ === 0) clock.advance(1000); + return "ok"; + }; + await runLoad(call, { concurrency: 1, requests: 5, rate: 10 }, clock); + // The 1s stall forfeits slots 100..900; spacing resumes from 1000. + expect(starts).toEqual([0, 1000, 1100, 1200, 1300]); + }); + + it("keeps concurrent workers spaced at the rate", async () => { + const clock = fakeClock(); + const starts: number[] = []; + const call = async (): Promise => { + starts.push(clock.now() - 1000); + return "ok"; + }; + await runLoad(call, { concurrency: 3, requests: 6, rate: 5 }, clock); + expect([...starts].sort((a, b) => a - b)).toEqual([ + 0, 200, 400, 600, 800, 1000, + ]); + }); + + it("does not start a call when its timer wakes past the deadline", async () => { + const clock = fakeClock(); + // Every timer fires 100ms late. + clock.sleep = async (ms) => clock.advance(ms + 100); + const starts: number[] = []; + const call = async (): Promise => { + starts.push(clock.now() - 1000); + return "ok"; + }; + const summary = await runLoad( + call, + { concurrency: 1, durationMs: 100, rate: 20 }, + clock, + ); + // Slot 50 wakes at 150, past the 100ms window, and is not started. + expect(starts).toEqual([0]); + expect(summary.requests).toBe(1); + }); + it("does not sleep for a slot whose time has already passed", async () => { const clock = fakeClock(); const call = async (): Promise => { @@ -361,6 +428,30 @@ describe("--load (CLI)", () => { ["--method", "tools/call", "--tool-name", "echo", "--load", "--app-info"], "--load cannot be combined with --app-info.", ], + [ + [ + "--method", + "tools/call", + "--tool-name", + "echo", + "--load", + "--list-stored-auth", + ], + "--load cannot be combined with --list-stored-auth or --print-handoff.", + ], + [ + [ + "--method", + "tools/call", + "--tool-name", + "echo", + "--load", + "--print-handoff", + "--server-url", + "http://localhost:1/mcp", + ], + "--load cannot be combined with --list-stored-auth or --print-handoff.", + ], [ [ "--method", diff --git a/clients/cli/src/cli.ts b/clients/cli/src/cli.ts index f2a31adcb..034e38c83 100644 --- a/clients/cli/src/cli.ts +++ b/clients/cli/src/cli.ts @@ -1350,6 +1350,11 @@ async function parseArgs(argv?: string[]): Promise { if (options.appInfo) { throw new Error("--load cannot be combined with --app-info."); } + if (options.listStoredAuth || options.printHandoff) { + throw new Error( + "--load cannot be combined with --list-stored-auth or --print-handoff.", + ); + } if (options.output !== undefined || options.outputFormat !== undefined) { throw new Error( "--load cannot be combined with --output or --output-format; redirect stdout to keep the summary.", diff --git a/core/cli/handlers/load-test.ts b/core/cli/handlers/load-test.ts index 95d089ef4..148cb6d19 100644 --- a/core/cli/handlers/load-test.ts +++ b/core/cli/handlers/load-test.ts @@ -194,12 +194,17 @@ class ErrorTally { /** * Run `call` under the given bounds and summarize what happened. Workers pull * slots from a shared counter, so `concurrency` is a hard cap on calls in - * flight and `requests` a hard cap on calls started. With `rate`, slot `i` - * may not start before `i / rate` seconds into the run — an even schedule - * rather than a burst each second. + * flight and `requests` a hard cap on calls started. With `rate`, starts are + * at least `1 / rate` seconds apart — an even schedule rather than a burst + * each second. * - * A slot whose scheduled start falls past the duration is never started, so a - * rate-limited run does not overshoot its window by sleeping into it. + * The rate limiter keys off the time the last slot was actually handed out, + * not off the run's start: a slot nobody was free to take is dropped rather + * than owed, so a stall (one slow call at concurrency 1) is never followed by + * a catch-up burst against a server that may just be recovering. + * + * A slot scheduled past the duration is never started, and the deadline is + * checked again after the wait, since a timer can wake late under load. */ export async function runLoad( call: () => Promise, @@ -216,17 +221,23 @@ export async function runLoad( const start = clock.now(); const deadline = durationMs === undefined ? Infinity : start + durationMs; + const interval = rate === undefined ? 0 : 1000 / rate; + // Earliest time the next slot may start. Claimed synchronously, so two + // workers can never be handed the same slot. + let nextStart = start; const worker = async (): Promise => { for (;;) { if (requests !== undefined && started >= requests) return; if (clock.now() >= deadline) return; - const slot = started++; + started++; if (rate !== undefined) { - const scheduled = start + (slot * 1000) / rate; + const scheduled = Math.max(nextStart, clock.now()); + nextStart = scheduled + interval; if (scheduled >= deadline) return; const wait = scheduled - clock.now(); if (wait > 0) await clock.sleep(wait); + if (clock.now() >= deadline) return; } const t0 = clock.now(); try { From bc6db3e1e98acbeaf4c597779759e26bb680a949 Mon Sep 17 00:00:00 2001 From: cliffhall Date: Tue, 20 Oct 2026 01:57:09 -0400 Subject: [PATCH 3/4] fix(cli): claim a --load-rate slot only after waking Workers reserved their slot before sleeping, so when the event loop stalled and several timers fired late together, every overdue worker started at once and --load-rate's spacing collapsed. A slot is now claimed only by a worker that is awake at its time, and each wake re-checks the bounds; the rest go back to waiting. Co-Authored-By: Claude Opus 5.5 (1M context) Signed-off-by: cliffhall --- clients/cli/__tests__/load-test.test.ts | 24 +++++++++++- core/cli/handlers/load-test.ts | 51 +++++++++++++++---------- 2 files changed, 53 insertions(+), 22 deletions(-) diff --git a/clients/cli/__tests__/load-test.test.ts b/clients/cli/__tests__/load-test.test.ts index d1955ce7b..3a7c91ab5 100644 --- a/clients/cli/__tests__/load-test.test.ts +++ b/clients/cli/__tests__/load-test.test.ts @@ -36,8 +36,12 @@ import { * therefore completes instantly while keeping the schedule it would in real * time. */ -function fakeClock(): LoadClock & { advance: (ms: number) => void } { +function fakeClock( + options: { lateUntil?: number } = {}, +): LoadClock & { advance: (ms: number) => void } { let t = 1000; + // A stalled event loop: no timer fires before this many ms into the run. + const earliestWake = 1000 + (options.lateUntil ?? 0); const timers: { wakeAt: number; resolve: () => void }[] = []; let pumping = false; const pump = (): void => { @@ -55,7 +59,7 @@ function fakeClock(): LoadClock & { advance: (ms: number) => void } { now: () => t, sleep: (ms) => new Promise((resolve) => { - timers.push({ wakeAt: t + ms, resolve }); + timers.push({ wakeAt: Math.max(t + ms, earliestWake), resolve }); if (!pumping) { pumping = true; setImmediate(pump); @@ -281,6 +285,22 @@ describe("load-test engine", () => { ]); }); + it("keeps the rate when several workers' timers fire late together", async () => { + const clock = fakeClock({ lateUntil: 1000 }); + const starts: number[] = []; + const call = async (): Promise => { + starts.push(clock.now() - 1000); + return "ok"; + }; + await runLoad( + call, + { concurrency: 3, requests: 3, durationMs: 2000, rate: 5 }, + clock, + ); + // Workers 2 and 3 both wake at 1000; only one may start then. + expect(starts).toEqual([0, 1000, 1200]); + }); + it("does not start a call when its timer wakes past the deadline", async () => { const clock = fakeClock(); // Every timer fires 100ms late. diff --git a/core/cli/handlers/load-test.ts b/core/cli/handlers/load-test.ts index 148cb6d19..af35bbf5c 100644 --- a/core/cli/handlers/load-test.ts +++ b/core/cli/handlers/load-test.ts @@ -198,13 +198,11 @@ class ErrorTally { * at least `1 / rate` seconds apart — an even schedule rather than a burst * each second. * - * The rate limiter keys off the time the last slot was actually handed out, - * not off the run's start: a slot nobody was free to take is dropped rather - * than owed, so a stall (one slow call at concurrency 1) is never followed by - * a catch-up burst against a server that may just be recovering. - * - * A slot scheduled past the duration is never started, and the deadline is - * checked again after the wait, since a timer can wake late under load. + * The rate limiter keys off the time the last slot was actually taken, not + * off the run's start: a slot nobody was free to take is dropped rather than + * owed, so a stall — one slow call at concurrency 1, or timers firing late — + * is never followed by a catch-up burst against a server that may just be + * recovering. A slot past the duration is never started. */ export async function runLoad( call: () => Promise, @@ -222,23 +220,36 @@ export async function runLoad( const start = clock.now(); const deadline = durationMs === undefined ? Infinity : start + durationMs; const interval = rate === undefined ? 0 : 1000 / rate; - // Earliest time the next slot may start. Claimed synchronously, so two - // workers can never be handed the same slot. + // Earliest time the next slot may start. let nextStart = start; - const worker = async (): Promise => { + /** + * Wait for a slot and take it, or return false when the run is over. A + * slot is claimed only by a worker that is awake at its time — never + * reserved before a wait — and every wake re-checks the bounds. So if the + * event loop stalls and several workers' timers all fire late at once, the + * first to run takes the slot and the rest go back to waiting, rather than + * starting together. The claim itself is synchronous, so two workers can + * never take the same slot. + */ + const claimSlot = async (): Promise => { for (;;) { - if (requests !== undefined && started >= requests) return; - if (clock.now() >= deadline) return; - started++; - if (rate !== undefined) { - const scheduled = Math.max(nextStart, clock.now()); - nextStart = scheduled + interval; - if (scheduled >= deadline) return; - const wait = scheduled - clock.now(); - if (wait > 0) await clock.sleep(wait); - if (clock.now() >= deadline) return; + if (requests !== undefined && started >= requests) return false; + const now = clock.now(); + if (now >= deadline) return false; + const scheduled = Math.max(nextStart, now); + if (scheduled >= deadline) return false; + if (scheduled <= now) { + started++; + nextStart = now + interval; + return true; } + await clock.sleep(scheduled - now); + } + }; + + const worker = async (): Promise => { + while (await claimSlot()) { const t0 = clock.now(); try { const outcome = await call(); From 4e13034d3a1f6a9b30b3d1aa1c2d683105d14498 Mon Sep 17 00:00:00 2001 From: cliffhall Date: Tue, 20 Oct 2026 02:11:58 -0400 Subject: [PATCH 4/4] fix(cli): one timer per --load-rate slot, and hold the average rate Every idle worker armed a timer for the same next slot and all but one re-armed on waking: 9,900 timers for 100 calls at concurrency 100. Workers now queue on a FIFO turnstile and only the head waits on the clock, which brings that to 99. A claim also reset the schedule from the wake time, so ordinary timer lateness accumulated and the run fell short of the rate (176 of 200 calls in a 1s run at 200/s). A wake that is late by less than one interval now keeps the slot grid; only a slot missed entirely is dropped, so there is still no catch-up burst after a stall. The README notes the ~1ms timer ceiling that limits rates in the high hundreds per second. Co-Authored-By: Claude Opus 5.5 (1M context) Signed-off-by: cliffhall --- clients/cli/README.md | 12 +++-- clients/cli/__tests__/load-test.test.ts | 40 +++++++++++++++-- core/cli/handlers/load-test.ts | 59 ++++++++++++++++--------- 3 files changed, 83 insertions(+), 28 deletions(-) diff --git a/clients/cli/README.md b/clients/cli/README.md index dcd96363b..2d2b11157 100644 --- a/clients/cli/README.md +++ b/clients/cli/README.md @@ -341,10 +341,14 @@ is printed on stdout (wrapped in `{ "result": … }` with `--format json`): sub-millisecond stdio echo. - **Bounds.** `--load-duration` stops *starting* calls; anything in flight is allowed to finish, so `elapsedMs` can exceed the window by up to one call. - With `--load-rate`, starts are at least `1/rate` seconds apart, and a slot - nobody was free to take is dropped rather than made up later — a stall is - never followed by a catch-up burst. A slot that falls past the window is - never started. + With `--load-rate`, starts follow an even `1/rate` grid; a timer that wakes + a little late keeps the grid, so the average rate holds. A slot missed + entirely — every worker busy, or a stalled event loop — is dropped rather + than made up later, so a stall is never followed by a catch-up burst. A + slot that falls past the window is never started. Node's timers resolve to + about a millisecond, so a rate in the high hundreds per second or above is + reached only approximately (1000/s measured ~700 against a local stdio + server); compare `requests` against what you asked for. **All calls share one connection**, so this measures how a server copes with concurrent requests on a single session — not with many sessions. A slow call diff --git a/clients/cli/__tests__/load-test.test.ts b/clients/cli/__tests__/load-test.test.ts index 3a7c91ab5..3d8932bf8 100644 --- a/clients/cli/__tests__/load-test.test.ts +++ b/clients/cli/__tests__/load-test.test.ts @@ -37,13 +37,14 @@ import { * time. */ function fakeClock( - options: { lateUntil?: number } = {}, -): LoadClock & { advance: (ms: number) => void } { + options: { lateUntil?: number; jitter?: number } = {}, +): LoadClock & { advance: (ms: number) => void; sleeps: () => number } { let t = 1000; // A stalled event loop: no timer fires before this many ms into the run. const earliestWake = 1000 + (options.lateUntil ?? 0); const timers: { wakeAt: number; resolve: () => void }[] = []; let pumping = false; + let sleepCount = 0; const pump = (): void => { timers.sort((a, b) => a.wakeAt - b.wakeAt); const next = timers.shift(); @@ -59,7 +60,11 @@ function fakeClock( now: () => t, sleep: (ms) => new Promise((resolve) => { - timers.push({ wakeAt: Math.max(t + ms, earliestWake), resolve }); + sleepCount++; + timers.push({ + wakeAt: Math.max(t + ms + (options.jitter ?? 0), earliestWake), + resolve, + }); if (!pumping) { pumping = true; setImmediate(pump); @@ -68,6 +73,7 @@ function fakeClock( advance: (ms) => { t += ms; }, + sleeps: () => sleepCount, }; } @@ -285,6 +291,34 @@ describe("load-test engine", () => { ]); }); + it("holds the average rate when every timer wakes a little late", async () => { + const clock = fakeClock({ jitter: 30 }); + const starts: number[] = []; + const call = async (): Promise => { + starts.push(clock.now() - 1000); + return "ok"; + }; + await runLoad( + call, + { concurrency: 1, durationMs: 1000, rate: 10 }, + clock, + ); + // 30ms late each time, but on the 100ms grid: ten starts, not eight. + expect(starts).toEqual([0, 130, 230, 330, 430, 530, 630, 730, 830, 930]); + }); + + it("arms one timer per slot however many workers are idle", async () => { + const clock = fakeClock(); + const summary = await runLoad( + async () => "ok", + { concurrency: 100, requests: 100, rate: 1000 }, + clock, + ); + expect(summary.requests).toBe(100); + // Slot 0 starts immediately; each of the other 99 needs one wait. + expect(clock.sleeps()).toBe(99); + }); + it("keeps the rate when several workers' timers fire late together", async () => { const clock = fakeClock({ lateUntil: 1000 }); const starts: number[] = []; diff --git a/core/cli/handlers/load-test.ts b/core/cli/handlers/load-test.ts index af35bbf5c..d02d9c911 100644 --- a/core/cli/handlers/load-test.ts +++ b/core/cli/handlers/load-test.ts @@ -194,9 +194,8 @@ class ErrorTally { /** * Run `call` under the given bounds and summarize what happened. Workers pull * slots from a shared counter, so `concurrency` is a hard cap on calls in - * flight and `requests` a hard cap on calls started. With `rate`, starts are - * at least `1 / rate` seconds apart — an even schedule rather than a burst - * each second. + * flight and `requests` a hard cap on calls started. With `rate`, starts + * follow an even `1 / rate` grid rather than a burst each second. * * The rate limiter keys off the time the last slot was actually taken, not * off the run's start: a slot nobody was free to take is dropped rather than @@ -223,28 +222,46 @@ export async function runLoad( // Earliest time the next slot may start. let nextStart = start; + // FIFO turnstile: workers wanting a slot queue on a promise chain, and only + // the one at the head waits on the clock. Without it, every idle worker + // armed its own timer for the same slot and all but one re-armed on waking + // — at concurrency 100 that is 99 wasted timers per call, enough to make + // the generator the bottleneck at a high --load-rate. + let turnstile: Promise = Promise.resolve(); + /** - * Wait for a slot and take it, or return false when the run is over. A - * slot is claimed only by a worker that is awake at its time — never - * reserved before a wait — and every wake re-checks the bounds. So if the - * event loop stalls and several workers' timers all fire late at once, the - * first to run takes the slot and the rest go back to waiting, rather than - * starting together. The claim itself is synchronous, so two workers can - * never take the same slot. + * Wait for a slot and take it, or return false when the run is over. Only + * the worker at the head of the turnstile is ever waiting on the clock, and + * it claims a slot only once it is awake at that slot's time, re-checking + * the bounds on every wake. So a timer that fires late — a stalled event + * loop — starts one call, never a burst of everything that was due. */ const claimSlot = async (): Promise => { - for (;;) { - if (requests !== undefined && started >= requests) return false; - const now = clock.now(); - if (now >= deadline) return false; - const scheduled = Math.max(nextStart, now); - if (scheduled >= deadline) return false; - if (scheduled <= now) { - started++; - nextStart = now + interval; - return true; + const ahead = turnstile; + let release!: () => void; + turnstile = new Promise((resolve) => (release = resolve)); + await ahead; + try { + for (;;) { + if (requests !== undefined && started >= requests) return false; + const now = clock.now(); + if (now >= deadline) return false; + const scheduled = Math.max(nextStart, now); + if (scheduled >= deadline) return false; + if (scheduled <= now) { + started++; + // A wake that is merely late — timers always are, by a fraction of + // a millisecond — keeps the slot grid, so the average rate holds. + // Only a slot missed entirely (a stall longer than one interval) + // is dropped, and spacing restarts from now: no catch-up burst. + nextStart = + now - nextStart < interval ? nextStart + interval : now + interval; + return true; + } + await clock.sleep(scheduled - now); } - await clock.sleep(scheduled - now); + } finally { + release(); } };