feat(cli): report opt-in command timings (#7042)

* feat(cli): report opt-in command timings

* fix(cli): time standalone MCP doctor

* fix(cli): retain timing on doctor errors

* fix(cli): preserve formatted version output with command timings

---------

Co-authored-by: dhruvac29 <dhruvac29@users.noreply.github.com>
Co-authored-by: gensokyo-dev <342580529+gensokyo-dev@users.noreply.github.com>

docs/cli.md

@@ -51,6 +51,15 @@ module page. See
 [JavaScript application workflows](javascript-application-workflows.md) for
 views, feature traces and comparisons that take the same saved Evidence.
 
+Add `--timings` to a command to write one JSON timing record to stderr. For
+example, `rea inspect-elf-notes program --json --timings > result.json` keeps
+stdout as a parseable result and writes
+`{"rea_timings":{"version":1,"command_ms":42}}` to stderr. `command_ms`
+measures CLI command dispatch and result delivery; it is not provider-only or
+analysis-only time. The flag is off by default, and the record omits stages
+that REA did not measure. Root version reporting does not dispatch a command
+and has no command timing record.
+
 ## JSON Lines record output
 
 Use `--format jsonl` to consume row-oriented results one record per line:

scripts/rea.mjs

@@ -68,15 +68,34 @@ if (!(await compiledRuntimeExists(runtimeFiles))) {
   await runMcpHttpEntrypoint(args.slice(1));
 } else if (isMcpDoctorMode) {
   guardClosedStdout();
-  const { runProductionMcpDoctorCli } =
-    await import("../dist/cli-runtime/mcpDoctor.js");
-  const result = await runProductionMcpDoctorCli(doctorArguments, {
-    dispatcherPath: fileURLToPath(import.meta.url),
-    packageRoot,
-    stdoutIsTerminal: process.stdout.isTTY === true,
-  });
-  writeStdout(result.output);
-  process.exitCode = result.exitCode;
+  // Doctor runs outside Incur, so handle its global timing flag here. Keep a
+  // token consumed by --format as a value, even when it looks like a flag.
+  const outputValues = new Set(
+    builtinArguments
+      .splitIncurBuiltinArguments(doctorArguments)
+      .outputValues.map(({ index }) => index),
+  );
+  const doctorCliArguments = doctorArguments.filter(
+    (argument, index) => argument !== "--timings" || outputValues.has(index),
+  );
+  const timingRequested = doctorCliArguments.length !== doctorArguments.length;
+  const started = performance.now();
+  try {
+    const { runProductionMcpDoctorCli } =
+      await import("../dist/cli-runtime/mcpDoctor.js");
+    const result = await runProductionMcpDoctorCli(doctorCliArguments, {
+      dispatcherPath: fileURLToPath(import.meta.url),
+      packageRoot,
+      stdoutIsTerminal: process.stdout.isTTY === true,
+    });
+    writeStdout(result.output);
+    process.exitCode = result.exitCode;
+  } finally {
+    if (timingRequested)
+      process.stderr.write(
+        `${JSON.stringify({ rea_timings: { version: 1, command_ms: Math.round(performance.now() - started) } })}\n`,
+      );
+  }
 } else {
   const {
     cliConfigurationError,

src/cli.ts

@@ -19,7 +19,7 @@ import { registerAnalysisViewCommands } from "./cli/analysisViewCommands.js";
 import { registerBinaryDiagnosticsCommands } from "./cli/binaryDiagnosticsCommands.js";
 import { registerFridaCommands } from "./cli/fridaCommands.js";
 import type { FridaInstrumentationPort } from "./application/frida/FridaInstrumentationPort.js";
-import { Cli } from "incur";
+import { Cli, z } from "incur";
 import {
   adaptCliOutputArgumentsForIncur,
   normalizeCliArguments,
@@ -95,9 +95,15 @@ export const createCli = (
     "cli",
     level?.ok === true ? level.value : "silent",
   );
-  const cli = Cli.create(PRODUCT_IDENTITY.cliBinary, {
+  const timedCli = Cli.create(PRODUCT_IDENTITY.cliBinary, {
     version: PRODUCT_IDENTITY.packageVersion,
     description: "Reverse engineer anything from your terminal or agent.",
+    globals: z.object({
+      timings: z
+        .boolean()
+        .default(false)
+        .describe("Write measured command timing to stderr."),
+    }),
     mcp: {
       command: npxRegistrationCommand().join(" "),
       instructions:
@@ -115,6 +121,23 @@ export const createCli = (
     },
   });
 
+  timedCli.use(async (context, next) => {
+    if (!context.globals.timings) return next();
+    const started = performance.now();
+    try {
+      await next();
+    } finally {
+      // This interval covers CLI command dispatch, including result delivery.
+      // It is not a provider-only or analysis-only measurement.
+      process.stderr.write(
+        `${JSON.stringify({ rea_timings: { version: 1, command_ms: Math.round(performance.now() - started) } })}\n`,
+      );
+    }
+  });
+  // Command registrars do not inspect global options; preserve their existing
+  // type while Incur owns parsing and the middleware owns this added flag.
+  const cli = timedCli as unknown as CliInstance;
+
   registerSetupCommands(cli, logger, environment);
   registerReverseEngineeringCommands(cli, logger, environment);
   registerCutterCommands(cli, logger, environment);
@@ -173,7 +196,10 @@ export const createCli = (
   presentCliArgumentErrors(cli);
   const serveDeclared = excludeDeclaredSensitiveArguments(cli);
   const serve = cli.serve.bind(cli);
-  const complete = createCliCompletions(cli, environment);
+  const complete = createCliCompletions(
+    cli as unknown as Parameters<typeof createCliCompletions>[0],
+    environment,
+  );
   cli.serve = (arguments_ = process.argv.slice(2), options) =>
     complete(arguments_, options ?? {})
       ? Promise.resolve()

src/cliBuiltinArguments.ts

@@ -11,6 +11,7 @@ export const OUTPUT_SWITCHES: ReadonlySet<string> = new Set([
   "--json",
   "--full-output",
   "--token-count",
+  "--timings",
 ]);
 
 /** Valueless flags Incur removes from every position before command parsing. */
@@ -27,6 +28,7 @@ export const INCUR_BUILTIN_FLAGS: ReadonlySet<string> = new Set([
   "--schema",
   "--json",
   "--token-count",
+  "--timings",
 ]);
 
 /** Command tokens and output-flag values as Incur's builtin pass assigns them. */
@@ -42,8 +44,8 @@ export interface IncurBuiltinArgumentSplit {
 
 /**
  * Mirror Incur's builtin pass over normalized arguments without stopping at a
- * rejected value, so callers can still see every later token. REA configures
- * neither a config flag nor global options, which Incur would also remove.
+ * rejected value, so callers can still see every later token. REA's boolean
+ * timing global follows the same valueless pass; no config flag is registered.
  */
 export const splitIncurBuiltinArguments = (
   arguments_: readonly string[],

src/cliOutput.ts

@@ -180,7 +180,11 @@ export const parseCliOutputArguments = (
       const next = arguments_[index + 1];
       if (next === undefined || next.startsWith("-")) rootVersion = true;
       else versionEligible = false;
-    } else if (argument !== "--json" && argument !== "--format")
+    } else if (
+      argument !== "--json" &&
+      argument !== "--format" &&
+      argument !== "--timings"
+    )
       versionEligible = false;
     // Incur scans builtins across `--` and reads spaced value forms, which
     // normalizeCliArguments has produced. Mirror those effective values.

tests/acceptance/cliTimings.test.ts

@@ -0,0 +1,68 @@
+import { writeFile } from "node:fs/promises";
+import { join } from "node:path";
+import { expect } from "vitest";
+
+import { elfNoteFixture } from "../../src/native/elf/ElfNotes.fixture.js";
+import { createTestTempDirectory } from "../fixtures/temporaryDirectory.js";
+import { cliTest } from "../support/cli/cliFixture.js";
+
+const timingRecord = (stderr: string) => {
+  const lines = stderr.trim().split("\n");
+  expect(lines).toHaveLength(1);
+  const record: unknown = JSON.parse(lines[0]!);
+  expect(record).toMatchObject({
+    rea_timings: { version: 1, command_ms: expect.any(Number) },
+  });
+  const duration = (record as { rea_timings: { command_ms: number } })
+    .rea_timings.command_ms;
+  expect(Number.isFinite(duration)).toBe(true);
+  expect(duration).toBeGreaterThanOrEqual(0);
+};
+
+cliTest(
+  "writes opt-in command timing to stderr after success and failure without changing JSON stdout",
+  async ({ cli }) => {
+    const root = await createTestTempDirectory("rea-cli-timings-");
+    const valid = join(root, "program");
+    const invalid = join(root, "truncated");
+    await writeFile(valid, elfNoteFixture({ ownership: "program" }));
+    await writeFile(invalid, Buffer.from("ELF"));
+
+    const defaultRun = await cli.run({
+      arguments: ["inspect-elf-notes", valid, "--json"],
+    });
+    expect(defaultRun.exitCode, defaultRun.stderr).toBe(0);
+    expect(defaultRun.stderr).not.toContain("rea_timings");
+
+    const successful = await cli.run({
+      arguments: ["--timings", "inspect-elf-notes", valid, "--json"],
+    });
+    expect(successful.exitCode, successful.stderr).toBe(0);
+    expect(successful.json).toMatchObject({
+      normalized_result: { coverage: { status: "complete" } },
+    });
+    timingRecord(successful.stderr);
+
+    const failed = await cli.run({
+      arguments: ["inspect-elf-notes", invalid, "--json", "--timings"],
+    });
+    expect(failed.exitCode).toBe(1);
+    expect(failed.json).toMatchObject({ code: "invalid_request" });
+    timingRecord(failed.stderr);
+  },
+);
+
+cliTest(
+  "preserves formatted root version output when timings are requested",
+  async ({ cli }) => {
+    const plain = await cli.run({ arguments: ["--version", "--json"] });
+    const timed = await cli.run({
+      arguments: ["--timings", "--version", "--json"],
+    });
+    expect(plain.exitCode).toBe(0);
+    expect(plain.json).toBeTypeOf("object");
+    expect(timed.exitCode).toBe(0);
+    expect(timed.stdout).toBe(plain.stdout);
+    expect(timed.stderr).toBe("");
+  },
+);

tests/boundary/cli/mcpDoctorHelpCli.test.ts

@@ -117,4 +117,39 @@ describe("MCP doctor help boundary", () => {
     },
     CLI_INTEGRATION_TIMEOUT_MS,
   );
+
+  workspaceCliTest(
+    "reports doctor timing on stderr while preserving JSON output",
+    async ({ cli }) => {
+      const result = await cli.run({
+        arguments: ["mcp", "doctor", "--json", "--timings"],
+      });
+      expect([0, 1]).toContain(result.exitCode);
+      expect(JSON.parse(result.stdout)).toHaveProperty("healthy");
+      const lines = result.stderr.trim().split("\n");
+      expect(lines).toHaveLength(1);
+      const record: unknown = JSON.parse(lines[0]!);
+      expect(record).toMatchObject({
+        rea_timings: { version: 1, command_ms: expect.any(Number) },
+      });
+      const duration = (record as { rea_timings: { command_ms: number } })
+        .rea_timings.command_ms;
+      expect(Number.isFinite(duration)).toBe(true);
+      expect(duration).toBeGreaterThanOrEqual(0);
+    },
+    CLI_INTEGRATION_TIMEOUT_MS,
+  );
+
+  workspaceCliTest(
+    "does not treat a --format value as the timing flag",
+    async ({ cli }) => {
+      const result = await cli.run({
+        arguments: ["mcp", "doctor", "--format", "--timings"],
+      });
+      expect(result.exitCode).toBe(1);
+      expect(result.stdout).toContain("Invalid output format: --timings");
+      expect(result.stderr).toBe("");
+    },
+    CLI_INTEGRATION_TIMEOUT_MS,
+  );
 });