test(e2e): capture rebuild-hermes phase timings for perf comparison

test/e2e/live/rebuild-hermes-progress.ts

@@ -6,6 +6,7 @@ import os from "node:os";
 
 import { REPO_ROOT } from "../fixtures/paths.ts";
 import type { ShellProbeOutputEvent } from "../fixtures/shell-probe.ts";
+import type { RebuildHermesTimeline, RebuildHermesTimingPhase } from "./rebuild-hermes-timing.ts";
 
 interface RebuildHermesResourceSnapshot {
   freeMemoryBytes: number;
@@ -32,6 +33,7 @@ export interface RebuildHermesProgress {
   onOutput: (event: ShellProbeOutputEvent) => void;
   phase: (label: string) => void;
   stop: () => void;
+  timeline: () => RebuildHermesTimeline;
 }
 
 const DEFAULT_HEARTBEAT_INTERVAL_MS = 60_000;
@@ -80,10 +82,17 @@ export function startRebuildHermesProgress(
   const clearTimer = options.clearTimer ?? ((timer) => clearInterval(timer as NodeJS.Timeout));
   const logLine = options.logLine ?? ((line) => process.stdout.write(`${line}\n`));
   const sampleResources = options.sampleResources ?? defaultResourceSnapshot;
+  const overallStartedAt = now();
+  const completedPhases: RebuildHermesTimingPhase[] = [];
   let phaseLabel = initialPhase;
-  let phaseStartedAt = now();
+  let phaseStartedAt = overallStartedAt;
   let lastOutputAt: number | null = null;
   let stopped = false;
+  let stoppedAt = overallStartedAt;
+
+  const completeActivePhase = (completedAt = now()) => {
+    completedPhases.push({ label: phaseLabel, elapsedMs: completedAt - phaseStartedAt });
+  };
 
   const logBestEffort = (state: "started" | "running" | "finished") => {
     try {
@@ -115,6 +124,7 @@ export function startRebuildHermesProgress(
     phase(label) {
       if (stopped) return;
       logBestEffort("finished");
+      completeActivePhase();
       phaseLabel = label;
       phaseStartedAt = now();
       lastOutputAt = null;
@@ -123,8 +133,17 @@ export function startRebuildHermesProgress(
     stop() {
       if (stopped) return;
       stopped = true;
+      stoppedAt = now();
+      completeActivePhase(stoppedAt);
       clearTimer(timer);
       logBestEffort("finished");
     },
+    timeline() {
+      const current = now();
+      const phases = stopped
+        ? [...completedPhases]
+        : [...completedPhases, { label: phaseLabel, elapsedMs: current - phaseStartedAt }];
+      return { phases, totalMs: (stopped ? stoppedAt : current) - overallStartedAt };
+    },
   };
 }

test/e2e/live/rebuild-hermes-timing.ts

@@ -0,0 +1,99 @@
+// SPDX-FileCopyrightText: Copyright (c) 2026 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
+// SPDX-License-Identifier: Apache-2.0
+
+import os from "node:os";
+
+export interface RebuildHermesTimingPhase {
+  label: string;
+  elapsedMs: number;
+}
+
+export interface RebuildHermesTimeline {
+  phases: readonly RebuildHermesTimingPhase[];
+  totalMs: number;
+}
+
+export interface RebuildHermesRunnerClass {
+  platform: string;
+  arch: string;
+  cpuCount: number;
+  cpuModel: string;
+  totalMemoryBytes: number;
+}
+
+export type RebuildHermesLane = "normal" | "stale-base";
+
+export interface RebuildHermesTimingSummary {
+  schema: 1;
+  lane: RebuildHermesLane;
+  runnerClass: RebuildHermesRunnerClass;
+  phases: RebuildHermesTimingPhase[];
+  totalMs: number;
+  capturedAtIso: string;
+}
+
+interface RunnerClassSample {
+  platform: string;
+  arch: string;
+  cpus: ReadonlyArray<{ model: string }>;
+  totalMemoryBytes: number;
+}
+
+function defaultRunnerClassSample(): RunnerClassSample {
+  return {
+    platform: os.platform(),
+    arch: os.arch(),
+    cpus: os.cpus().map((cpu) => ({ model: cpu.model })),
+    totalMemoryBytes: os.totalmem(),
+  };
+}
+
+/**
+ * Fingerprint the runner so before/after timings can be confirmed to come from
+ * the same runner class before any comparison. The comparison itself lives with
+ * whoever reads the artifacts; this only records the identifying fields.
+ */
+export function describeRunnerClass(
+  sample: () => RunnerClassSample = defaultRunnerClassSample,
+): RebuildHermesRunnerClass {
+  const snapshot = sample();
+  return {
+    platform: snapshot.platform,
+    arch: snapshot.arch,
+    cpuCount: snapshot.cpus.length,
+    cpuModel: snapshot.cpus[0]?.model.trim() || "unknown",
+    totalMemoryBytes: snapshot.totalMemoryBytes,
+  };
+}
+
+function normalizeMs(value: number): number {
+  return Number.isFinite(value) && value > 0 ? Math.round(value) : 0;
+}
+
+export interface BuildRebuildHermesTimingSummaryInput {
+  lane: RebuildHermesLane;
+  timeline: RebuildHermesTimeline;
+  runnerClass: RebuildHermesRunnerClass;
+  capturedAtIso: string;
+}
+
+/**
+ * Shape the recorded timeline into the stable timing artifact. Durations are
+ * normalized to non-negative whole milliseconds so repeated runs on the same
+ * runner class stay directly comparable.
+ */
+export function buildRebuildHermesTimingSummary(
+  input: BuildRebuildHermesTimingSummaryInput,
+): RebuildHermesTimingSummary {
+  return {
+    schema: 1,
+    lane: input.lane,
+    runnerClass: input.runnerClass,
+    phases: input.timeline.phases.map((phase) => ({
+      label: phase.label,
+      elapsedMs: normalizeMs(phase.elapsedMs),
+    })),
+    totalMs: normalizeMs(input.timeline.totalMs),
+    capturedAtIso: input.capturedAtIso,
+  };
+}

test/e2e/live/rebuild-hermes.test.ts

@@ -30,6 +30,7 @@ import {
   requireRebuildHermesInitialImageTag,
 } from "./rebuild-hermes-image-state.ts";
 import { startRebuildHermesProgress } from "./rebuild-hermes-progress.ts";
+import { buildRebuildHermesTimingSummary, describeRunnerClass } from "./rebuild-hermes-timing.ts";
 
 // The migrated scope is the legacy non-interactive shell regression: install.sh,
 // Docker base-image builds, OpenShell provider/sandbox commands, direct Hermes
@@ -950,5 +951,19 @@ test(STALE_BASE_REBUILD
     backupRoot: sandboxBackupRoot,
     leaks,
   });
+
+  // Capture per-phase and total wall time tagged with the runner class so
+  // before/after comparisons for #7144 stay on the same runner class. Written
+  // before the final gate so the timing artifact survives an assertion failure.
+  await artifacts.writeJson(
+    "rebuild-hermes-timing.json",
+    buildRebuildHermesTimingSummary({
+      lane: STALE_BASE_REBUILD ? "stale-base" : "normal",
+      timeline: progress.timeline(),
+      runnerClass: describeRunnerClass(),
+      capturedAtIso: new Date().toISOString(),
+    }),
+  );
+
   expect(leaks, "backup files must not contain credential-shaped values").toEqual([]);
 });

test/e2e/support/rebuild-hermes-timing.test.ts

@@ -0,0 +1,139 @@
+// SPDX-FileCopyrightText: Copyright (c) 2026 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
+// SPDX-License-Identifier: Apache-2.0
+
+import { describe, expect, it } from "vitest";
+import {
+  type RebuildHermesProgressOptions,
+  startRebuildHermesProgress,
+} from "../live/rebuild-hermes-progress.ts";
+import {
+  buildRebuildHermesTimingSummary,
+  describeRunnerClass,
+} from "../live/rebuild-hermes-timing.ts";
+
+function timelineHarness() {
+  const state = { clockMs: 1_000 };
+  const options: RebuildHermesProgressOptions = {
+    now: () => state.clockMs,
+    setTimer: () => ({ unref() {} }),
+    clearTimer: () => {},
+    logLine: () => {},
+    sampleResources: () => ({
+      freeMemoryBytes: 0,
+      processRssBytes: 0,
+      totalMemoryBytes: 0,
+      workspaceFreeBytes: 0,
+      loadAverage1m: 0,
+    }),
+  };
+  return { options, state };
+}
+
+describe("Hermes rebuild timing timeline", () => {
+  it("records each completed phase and closes the in-flight phase on snapshot", () => {
+    const { options, state } = timelineHarness();
+    const progress = startRebuildHermesProgress("setup", options);
+
+    state.clockMs = 4_000;
+    progress.phase("phase 6 nemoclaw rebuild");
+    state.clockMs = 9_000;
+
+    expect(progress.timeline()).toEqual({
+      phases: [
+        { label: "setup", elapsedMs: 3_000 },
+        { label: "phase 6 nemoclaw rebuild", elapsedMs: 5_000 },
+      ],
+      totalMs: 8_000,
+    });
+  });
+
+  it("freezes the timeline at stop and ignores post-stop transitions", () => {
+    const { options, state } = timelineHarness();
+    const progress = startRebuildHermesProgress("phase 7 verification", options);
+
+    state.clockMs = 6_000;
+    progress.stop();
+    state.clockMs = 60_000;
+    progress.phase("after stop");
+
+    expect(progress.timeline()).toEqual({
+      phases: [{ label: "phase 7 verification", elapsedMs: 5_000 }],
+      totalMs: 5_000,
+    });
+  });
+
+  it("uses the same stop timestamp for the final phase and total", () => {
+    const { options } = timelineHarness();
+    let clockMs = 1_000;
+    options.now = () => {
+      const current = clockMs;
+      clockMs += 1_000;
+      return current;
+    };
+    const progress = startRebuildHermesProgress("phase 7 verification", options);
+
+    progress.stop();
+
+    expect(progress.timeline()).toEqual({
+      phases: [{ label: "phase 7 verification", elapsedMs: 2_000 }],
+      totalMs: 2_000,
+    });
+  });
+});
+
+describe("Hermes rebuild timing summary", () => {
+  const runnerClass = describeRunnerClass(() => ({
+    platform: "linux",
+    arch: "x64",
+    cpus: [{ model: "  Model A  " }, { model: "Model A" }],
+    totalMemoryBytes: 16 * 1024 ** 3,
+  }));
+
+  it("derives a runner-class fingerprint from the sampled host", () => {
+    expect(runnerClass).toEqual({
+      platform: "linux",
+      arch: "x64",
+      cpuCount: 2,
+      cpuModel: "Model A",
+      totalMemoryBytes: 16 * 1024 ** 3,
+    });
+  });
+
+  it("labels the lane and normalizes durations to whole non-negative ms", () => {
+    const summary = buildRebuildHermesTimingSummary({
+      lane: "stale-base",
+      runnerClass,
+      capturedAtIso: "2026-07-18T00:00:00.000Z",
+      timeline: {
+        phases: [
+          { label: "setup", elapsedMs: 1_499.6 },
+          { label: "phase 6 nemoclaw rebuild", elapsedMs: -5 },
+        ],
+        totalMs: 12_345.4,
+      },
+    });
+
+    expect(summary).toEqual({
+      schema: 1,
+      lane: "stale-base",
+      runnerClass,
+      phases: [
+        { label: "setup", elapsedMs: 1_500 },
+        { label: "phase 6 nemoclaw rebuild", elapsedMs: 0 },
+      ],
+      totalMs: 12_345,
+      capturedAtIso: "2026-07-18T00:00:00.000Z",
+    });
+  });
+
+  it("falls back to a placeholder model when no CPU is reported", () => {
+    expect(
+      describeRunnerClass(() => ({
+        platform: "linux",
+        arch: "arm64",
+        cpus: [],
+        totalMemoryBytes: 0,
+      })).cpuModel,
+    ).toBe("unknown");
+  });
+});