Files
openclaw/test/scripts/ci-run-timings.test.ts
Peter Steinberger 72e42eed48 improve(ci): reduce main gating delays and add timing trends (#122441)
* ci: stop publishing warm dependency snapshots

Amp-Thread-ID: https://ampcode.com/threads/T-019ff3db-c467-70ad-8ed3-81f2ba94b0c0

* ci: isolate the high-variance source test shard

Amp-Thread-ID: https://ampcode.com/threads/T-019ff3db-c467-70ad-8ed3-81f2ba94b0c0

* ci: guarantee rebuilt dependency snapshot publication

Amp-Thread-ID: https://ampcode.com/threads/T-019ff3db-c467-70ad-8ed3-81f2ba94b0c0

* ci: add balanced main timing trends

Amp-Thread-ID: https://ampcode.com/threads/T-019ff3db-c467-70ad-8ed3-81f2ba94b0c0

* fix(ci): fall back when Crabbox CLI is unavailable

Amp-Thread-ID: https://ampcode.com/threads/T-019ff3db-c467-70ad-8ed3-81f2ba94b0c0

* Revert "fix(ci): fall back when Crabbox CLI is unavailable"

This reverts commit 0583ac8a9d.

---------

Co-authored-by: Amp <amp@ampcode.com>
2026-08-11 22:26:39 -07:00

495 lines
17 KiB
TypeScript

// Ci Run Timings tests cover ci run timings script behavior.
import { spawnSync } from "node:child_process";
import { chmodSync, mkdtempSync, readFileSync, rmSync, writeFileSync } from "node:fs";
import { tmpdir } from "node:os";
import path from "node:path";
import { fileURLToPath } from "node:url";
import { describe, expect, it } from "vitest";
import {
collectRunJobsFromPages,
isRetryableGhJsonErrorMessage,
parseRunTimingArgs,
selectLatestMainPushCiRun,
summarizePnpmStoreWarmupBarrier,
summarizeRunTimings,
} from "../../scripts/ci-run-timings.mjs";
describe("scripts/ci-run-timings.mjs", () => {
it("separates start delay from job duration without mislabeling dependency wait", () => {
const summary = summarizeRunTimings(
{
conclusion: "success",
createdAt: "2026-04-22T10:00:00Z",
jobs: [
{
completedAt: "2026-04-22T10:01:20Z",
conclusion: "success",
name: "slow",
startedAt: "2026-04-22T10:00:20Z",
status: "completed",
},
{
completedAt: "2026-04-22T10:01:00Z",
conclusion: "success",
name: "queued",
startedAt: "2026-04-22T10:00:50Z",
status: "completed",
},
{
completedAt: "2026-04-22T10:00:01Z",
conclusion: "skipped",
name: "matrix.check_name",
startedAt: "2026-04-22T10:00:01Z",
status: "completed",
},
],
status: "completed",
updatedAt: "2026-04-22T10:01:30Z",
},
2,
);
expect(summary.wallSeconds).toBe(90);
expect(summary.byDuration.map((job) => [job.name, job.durationSeconds])).toEqual([
["slow", 60],
["queued", 10],
]);
expect(summary.byStartDelay.map((job) => [job.name, job.startDelaySeconds])).toEqual([
["queued", 50],
["slow", 20],
]);
});
it("rejects empty CI job payloads instead of printing empty timing evidence", () => {
expect(() =>
summarizeRunTimings({
conclusion: "success",
createdAt: "2026-04-22T10:00:00Z",
jobs: [],
status: "completed",
updatedAt: "2026-04-22T10:01:30Z",
}),
).toThrow("CI run timing summary requires at least one job");
});
it("selects the push CI run for the current main SHA", () => {
expect(
selectLatestMainPushCiRun(
[
{
databaseId: 3,
event: "issue_comment",
headSha: "current",
},
{
databaseId: 2,
event: "push",
headSha: "older",
},
{
databaseId: 1,
event: "push",
headSha: "current",
},
],
"current",
),
).toEqual({
databaseId: 1,
event: "push",
headSha: "current",
});
});
it("normalizes paginated GitHub Actions job payloads", () => {
expect(
collectRunJobsFromPages([
{
jobs: [
{
completed_at: "2026-06-01T13:26:16Z",
conclusion: "success",
id: 101,
name: "preflight",
started_at: "2026-06-01T13:25:16Z",
status: "completed",
},
],
},
{
jobs: [
{
completedAt: "2026-06-01T13:28:00Z",
conclusion: "failure",
databaseId: 102,
name: "ci-timings-summary",
startedAt: "2026-06-01T13:27:00Z",
status: "completed",
},
],
},
]),
).toEqual([
{
completedAt: "2026-06-01T13:26:16Z",
conclusion: "success",
createdAt: null,
databaseId: 101,
labels: [],
name: "preflight",
runnerGroupName: null,
runnerName: null,
startedAt: "2026-06-01T13:25:16Z",
status: "completed",
},
{
completedAt: "2026-06-01T13:28:00Z",
conclusion: "failure",
createdAt: null,
databaseId: 102,
labels: [],
name: "ci-timings-summary",
runnerGroupName: null,
runnerName: null,
startedAt: "2026-06-01T13:27:00Z",
status: "completed",
},
]);
});
it("retries transient GitHub API failures while preserving auth failures", () => {
for (const message of [
"gh: API secondary rate limit exceeded (HTTP 403)",
"gh: HTTP 429: too many requests",
"Command failed: gh api repos/openclaw/openclaw/actions/runs/1/jobs\nHTTP 502",
"read ECONNRESET",
]) {
expect(isRetryableGhJsonErrorMessage(message)).toBe(true);
}
expect(
isRetryableGhJsonErrorMessage("gh: Resource not accessible by integration (HTTP 403)"),
).toBe(false);
});
it("summarizes the pnpm store warmup fanout barrier", () => {
expect(
summarizePnpmStoreWarmupBarrier({
conclusion: "success",
createdAt: "2026-05-28T23:03:01Z",
jobs: [
{
completedAt: "2026-05-28T23:04:05Z",
conclusion: "success",
name: "preflight",
startedAt: "2026-05-28T23:03:55Z",
status: "completed",
},
{
completedAt: "2026-05-28T23:04:27Z",
conclusion: "success",
name: "pnpm-store-warmup",
startedAt: "2026-05-28T23:04:07Z",
status: "completed",
},
{
completedAt: "2026-05-28T23:06:26Z",
conclusion: "success",
name: "checks-fast-bundled-protocol",
startedAt: "2026-05-28T23:04:29Z",
status: "completed",
},
{
completedAt: "2026-05-28T23:04:28Z",
conclusion: "skipped",
name: "check-docs",
startedAt: "2026-05-28T23:04:28Z",
status: "completed",
},
{
completedAt: "2026-05-28T23:04:35Z",
conclusion: "success",
name: "security-fast",
startedAt: "2026-05-28T23:03:55Z",
status: "completed",
},
{
completedAt: "2026-05-28T23:05:30Z",
conclusion: "success",
name: "checks-node-compat-node22",
startedAt: "2026-05-28T23:04:30Z",
status: "completed",
},
],
status: "completed",
updatedAt: "2026-05-28T23:07:33Z",
}),
).toEqual({
activePostWarmupJobCount: 1,
firstPostWarmupStartDelaySeconds: 2,
postWarmupP95StartDelaySeconds: 2,
postWarmupStartedWithinWindow: 1,
preflightToWarmupCompleteSeconds: 22,
preflightToWarmupStartSeconds: 2,
warmupDurationSeconds: 20,
warmupResult: "completed/success",
windowSeconds: 5,
});
});
it("falls back to the newest push CI run when the exact SHA has not appeared yet", () => {
expect(
selectLatestMainPushCiRun(
[
{
databaseId: 4,
event: "issue_comment",
headSha: "current",
},
{
databaseId: 3,
event: "push",
headSha: "previous",
},
],
"current",
),
).toEqual({
databaseId: 3,
event: "push",
headSha: "previous",
});
});
it("ignores pnpm passthrough sentinels when parsing monitor args", () => {
expect(parseRunTimingArgs(["--latest-main", "--", "--limit", "3"])).toEqual({
compareHours: 12,
detailRuns: 100,
explicitRunId: undefined,
json: false,
limit: 3,
outputPath: null,
recentLimit: null,
trendHours: null,
useLatestMain: true,
});
});
it("parses strict positive integer monitor limits", () => {
expect(parseRunTimingArgs(["123456", "--limit=7"])).toEqual({
compareHours: 12,
detailRuns: 100,
explicitRunId: "123456",
json: false,
limit: 7,
outputPath: null,
recentLimit: null,
trendHours: null,
useLatestMain: false,
});
expect(parseRunTimingArgs(["--recent", "4"]).recentLimit).toBe(4);
});
it("parses bounded trend comparison and JSON report options", () => {
expect(
parseRunTimingArgs([
"--trend-hours=72",
"--compare-hours",
"12",
"--detail-runs=80",
"--json",
"--output",
"ci-trend.json",
]),
).toEqual({
compareHours: 12,
detailRuns: 80,
explicitRunId: undefined,
json: true,
limit: 15,
outputPath: "ci-trend.json",
recentLimit: null,
trendHours: 72,
useLatestMain: false,
});
});
it("rejects malformed monitor limits instead of falling back", () => {
for (const args of [
["--limit", "3jobs"],
["--limit", "0"],
["--limit=1e3"],
["--recent", "recent"],
["--recent", "0"],
["--trend-hours", "0"],
["--compare-hours", "1.5"],
["--detail-runs", "all"],
]) {
expect(() => parseRunTimingArgs(args)).toThrow("must be a positive integer");
}
});
it("rejects missing monitor limits instead of treating flags as values", () => {
for (const args of [
["--limit"],
["--limit", "--recent", "4"],
["--limit", "-h"],
["--recent"],
["--recent", "-h"],
["--trend-hours"],
["--compare-hours", "--json"],
["--detail-runs"],
["--output="],
]) {
expect(() => parseRunTimingArgs(args)).toThrow("requires a value");
}
});
it("rejects unknown monitor flags and duplicate run ids", () => {
expect(() => parseRunTimingArgs(["--run-id", "123456"])).toThrow(
"Unknown CI run timing option: --run-id",
);
expect(() => parseRunTimingArgs(["123456", "789012"])).toThrow(
"Unexpected CI run id argument: 789012",
);
});
it("rejects ambiguous monitor modes and incomplete comparison windows", () => {
expect(() => parseRunTimingArgs(["--recent", "3", "--latest-main"])).toThrow(
"--recent cannot be combined",
);
expect(() => parseRunTimingArgs(["123456", "--latest-main"])).toThrow(
"A run id cannot be combined",
);
expect(() => parseRunTimingArgs(["--trend-hours", "72", "--recent", "3"])).toThrow(
"--trend-hours cannot be combined",
);
expect(() => parseRunTimingArgs(["--trend-hours", "23"])).toThrow("must cover at least two");
expect(() => parseRunTimingArgs(["--json"])).toThrow("require --trend-hours");
});
it("balances trend samples, keeps reruns attempt-specific, and counts API retries", () => {
const fixtureDir = mkdtempSync(path.join(tmpdir(), "openclaw-ci-timings-"));
const fakeGhPath = path.join(fixtureDir, "gh");
const reportPath = path.join(fixtureDir, "reports", "trend.json");
const retryMarkerPath = path.join(fixtureDir, "retried");
const repositoryRoot = path.resolve(path.dirname(fileURLToPath(import.meta.url)), "../..");
const fixtureNowMs = Date.now();
writeFileSync(
fakeGhPath,
`#!/usr/bin/env node
const { existsSync, writeFileSync } = require("node:fs");
const args = process.argv.slice(2);
const endpoint = args.find((arg) => arg.startsWith("repos/")) ?? "";
const now = Number(process.env.FIXTURE_NOW_MS);
const iso = (offsetMs) => new Date(now + offsetMs).toISOString();
if (endpoint.includes("actions/workflows/ci.yml/runs?")) {
console.log(JSON.stringify({ workflow_runs: [
{ id: 101, status: "completed", conclusion: "success", created_at: iso(-60 * 60_000), updated_at: iso(-50 * 60_000), head_sha: "latest", run_attempt: 1, html_url: "https://example.test/101" },
{ id: 104, status: "completed", conclusion: "success", created_at: iso(-90 * 60_000), updated_at: iso(-80 * 60_000), head_sha: "latest-unsampled", run_attempt: 1, html_url: "https://example.test/104" },
{ id: 102, status: "completed", conclusion: "cancelled", created_at: iso(-2 * 60 * 60_000), updated_at: iso(-119 * 60_000), head_sha: "cancelled", run_attempt: 1, html_url: "https://example.test/102" },
{ id: 106, status: "completed", conclusion: "timed_out", created_at: iso(-3 * 60 * 60_000), updated_at: iso(-2 * 60 * 60_000 - 50 * 60_000), head_sha: "timed-out", run_attempt: 1, html_url: "https://example.test/106" },
{ id: 103, status: "completed", conclusion: "success", created_at: iso(-13 * 60 * 60_000), updated_at: iso(-12 * 60 * 60_000 - 50 * 60_000), head_sha: "prior-rerun", run_attempt: 2, html_url: "https://example.test/103" }
] }));
} else if (endpoint.includes("actions/runs/101/attempts/1/jobs?")) {
if (!existsSync(process.env.FIXTURE_RETRY_MARKER)) {
writeFileSync(process.env.FIXTURE_RETRY_MARKER, "retried\\n");
console.error("HTTP 502: fixture transient failure");
process.exit(1);
}
const runStart = now - 60 * 60_000;
const at = (seconds) => new Date(runStart + seconds * 1000).toISOString();
console.log(JSON.stringify({ total_count: 4, jobs: [
{ id: 1, name: "preflight", status: "completed", conclusion: "success", created_at: at(10), started_at: at(20), completed_at: at(60), labels: ["blacksmith-4vcpu-ubuntu-2404"], runner_name: "blacksmith-test", runner_group_name: "blacksmith" },
{ id: 2, name: "checks-node-compact-large-1", status: "completed", conclusion: "success", created_at: at(60), started_at: at(65), completed_at: at(500), labels: ["blacksmith-8vcpu-ubuntu-2404"], runner_name: "blacksmith-test", runner_group_name: "blacksmith" },
{ id: 3, name: "openclaw/ci-gate", status: "completed", conclusion: "success", created_at: at(500), started_at: at(501), completed_at: at(510), labels: ["ubuntu-24.04"], runner_name: "GitHub Actions", runner_group_name: "GitHub Actions" },
{ id: 4, name: "matrix.synthetic", status: "completed", conclusion: "success", created_at: at(510), started_at: at(511), completed_at: at(520), labels: ["ubuntu-24.04"], runner_name: "GitHub Actions", runner_group_name: "GitHub Actions" }
] }));
} else if (endpoint.includes("actions/runs/103/attempts/2/jobs?")) {
const runStart = now - 12 * 60 * 60_000 - 55 * 60_000;
const at = (seconds) => new Date(runStart + seconds * 1000).toISOString();
console.log(JSON.stringify({ total_count: 2, jobs: [
{ id: 5, name: "preflight", status: "completed", conclusion: "success", created_at: at(10), started_at: at(18), completed_at: at(58), labels: ["blacksmith-4vcpu-ubuntu-2404"], runner_name: "blacksmith-test", runner_group_name: "blacksmith" },
{ id: 6, name: "checks-node-compact-large-1", status: "completed", conclusion: "success", created_at: at(58), started_at: at(62), completed_at: at(470), labels: ["blacksmith-8vcpu-ubuntu-2404"], runner_name: "blacksmith-test", runner_group_name: "blacksmith" }
] }));
} else {
console.error("unexpected gh invocation", args.join(" "));
process.exit(2);
}
`,
);
chmodSync(fakeGhPath, 0o755);
try {
const result = spawnSync(
process.execPath,
[
"scripts/ci-run-timings.mjs",
"--trend-hours",
"24",
"--compare-hours",
"12",
"--detail-runs",
"2",
"--json",
"--output",
reportPath,
],
{
cwd: repositoryRoot,
encoding: "utf8",
env: {
...process.env,
FIXTURE_NOW_MS: String(fixtureNowMs),
FIXTURE_RETRY_MARKER: retryMarkerPath,
OPENCLAW_GH_BIN: fakeGhPath,
},
},
);
expect(result.status, result.stderr).toBe(0);
const report = JSON.parse(result.stdout);
expect(JSON.parse(readFileSync(reportPath, "utf8"))).toEqual(report);
expect(report.apiRequests).toEqual({ jobs: 3, runList: 1, total: 4 });
expect(report.sampling).toEqual({
detailedSuccessfulRuns: 2,
eligibleSuccessfulRuns: 3,
});
expect(report.cohorts.comparison.outcomes).toMatchObject({
cancelled: 1,
cancellationRate: 0.25,
nonCancelledPassRate: 2 / 3,
success: 2,
timedOut: 1,
total: 4,
});
expect(report.cohorts.prior.runMetrics.successfulWallSeconds.p50).toBeNull();
expect(report.cohorts.prior.runMetrics.workflowAdmissionSeconds.p50).toBeNull();
expect(report.cohorts.prior.samples.detailedSuccessfulRuns).toBe(1);
expect(report.cohorts.prior.jobMetrics.executionSeconds.count).toBe(2);
expect(report.cohorts.comparison.jobMetrics.runnerQueueSeconds).toMatchObject({
count: 2,
max: 10,
p95: 10,
});
expect(report.cohorts.comparison.jobMetrics.dependencyGatedSeconds.p95).toBe(50);
expect(report.cohorts.comparison.runMetrics.workflowAdmissionSeconds.p95).toBe(10);
expect(report.cohorts.comparison.criticalOwners).toEqual([
{ name: "checks-node-compact-large-1", runs: 1 },
]);
expect(
report.jobs.find((job: { name: string }) => job.name === "checks-node-compact-large-1"),
).toMatchObject({
comparison: { executionSeconds: { count: 1 } },
prior: { executionSeconds: { count: 1 } },
});
expect(report.runs[0].jobTimings.map((job: { name: string }) => job.name)).toEqual([
"preflight",
"checks-node-compact-large-1",
]);
} finally {
rmSync(fixtureDir, { force: true, recursive: true });
}
});
});