diff --git a/.github/scripts/tests/ci-profile.test.mjs b/.github/scripts/tests/ci-profile.test.mjs index 9492dae5847..b6a931b6e3c 100644 --- a/.github/scripts/tests/ci-profile.test.mjs +++ b/.github/scripts/tests/ci-profile.test.mjs @@ -105,6 +105,21 @@ test("coverage is conservative after failures and does not merge framework invoc assert.equal(trace.events[0].data["ci.reported_invocations"], 1); }); +test("complete reporter pairs count without launcher intent, and long test names remain timed", () => { + const records = [ + record({ kind: "job" }), record({ kind: "job", job: "second" }), + record({ framework: "node", kind: "start" }), record({ framework: "node", kind: "end" }), + record({ kind: "test", id: "long", parent: "file", name: "x".repeat(5000), + file: "a.test.ts", start: Date.parse(at(4)), duration: 100, status: "passed" }), + record({ kind: "file", id: "file", name: "a.test.ts", file: "a.test.ts", + start: Date.parse(at(4)), duration: 100, status: "passed" }), + ]; + const trace = buildTrace({ ...run, conclusion: "success" }, jobs, records); + assert.equal(trace.events[0].data["ci.profile_complete"], true); + assert.equal(trace.events[0].data["ci.test_count"], 1); + assert.equal(trace.events.find((event) => event.data["ci.kind"] === "test").data.name.length, 256); +}); + test("trusted policy commands work with both current and pre-profile checkouts", () => { const source = readFileSync(new URL("../../workflows/pr-trusted.yml", import.meta.url), "utf8"); const block = source.split(" - name: Select compatible Node test command\n")[1].split("\n - name:")[0]; @@ -191,18 +206,30 @@ test("profiling uses only infrastructure CODEOWNERS resolved at trusted master", ]); }); -test("export checks per-event ingestion results, including partial failures", async () => { +test("export paces batches and retries only rejected transient events", async () => { const events = Array.from({ length: 501 }, () => ({ data: {} })); const sizes = []; + const pauses = []; await sendEvents(events, "test-only", "paperclip-ci", async (url, options) => { assert.equal(url, "https://api.honeycomb.io/1/batch/paperclip-ci"); assert.equal(options.redirect, "error"); const size = JSON.parse(options.body).length; sizes.push(size); return { ok: true, json: async () => Array.from({ length: size }, () => ({ status: 202 })) }; - }); - assert.deepEqual(sizes, [500, 1]); - await assert.rejects(sendEvents([events[0]], "test-only", "paperclip-ci", async () => ({ ok: true, json: async () => [{ status: 400 }] })), /every span/); + }, async (ms) => { pauses.push(ms); }); + assert.deepEqual(sizes, [250, 250, 1]); + assert.deepEqual(pauses, [1000, 1000]); + let calls = 0; + const retried = []; + await sendEvents([{ data: { id: 1 } }, { data: { id: 2 } }], "test-only", "paperclip-ci", async (_url, options) => { + const batch = JSON.parse(options.body); + retried.push(batch.map((event) => event.data.id)); + calls += 1; + return { ok: true, json: async () => calls === 1 ? [{ status: 202 }, { status: 429 }] : [{ status: 202 }] }; + }, async (ms) => { pauses.push(ms); }); + assert.deepEqual(retried, [[1, 2], [2]]); + assert.equal(pauses.at(-1), 1000); + await assert.rejects(sendEvents([events[0]], "test-only", "paperclip-ci", async () => ({ ok: true, json: async () => [{ status: 400 }] })), /status 400/); }); test("workflow exporter runs trusted code and keeps keys out of the PR jobs", () => { diff --git a/doc/ci-profiling.md b/doc/ci-profiling.md index d2031d9f7f8..9d836537bd8 100644 --- a/doc/ci-profiling.md +++ b/doc/ci-profiling.md @@ -17,7 +17,8 @@ The PR author, original workflow actor, and rerun actor must all be individual users in the trusted `master` branch's `.github/**` CODEOWNERS rule. GitHub user IDs are resolved from that rule; PR edits to CODEOWNERS cannot grant access. A label on an outside contributor's PR does not enable profiling, even when a -maintainer applies it. Failed identity lookups disable profiling. +maintainer applies it. The PR still runs normal CI and needs no Honeycomb +access. Failed identity lookups disable profiling. Ordinary PRs do not write timing artifacts or export traces. The exporter job is skipped for ordinary run names. Adding another label does not run the CI matrix. @@ -42,6 +43,10 @@ The expandable hierarchy is **workflow → job → step → test filename → te Vitest, Playwright, and Node file rows use repository-relative filenames, also available in `test.file`. Separate files retain their own children even when individual test names repeat across files. +Honeycomb shows only the 32,000 spans closest to the root in a very large trace. +All file rows are near the root, but the chart can omit some individual test +rows. Use **View events** to query all recorded test spans. Test names are +limited to 256 characters in the trace; file paths remain intact. - Compare the jobs that finish last (`ci.finishes_last`) with other overlapping work. A long job that finishes early is not necessarily delaying CI. @@ -79,7 +84,9 @@ artifacts, interrupted reporters, rejected data, and absent test details visible Test launchers write an expected-invocation record before starting each Vitest, Playwright, or Node process. Each reporter must write matching start/end records, so a missing reporter cannot hide behind another successful invocation in the -same job. Compare `ci.expected_invocations` with `ci.reported_invocations`. +same job. Direct package scripts can start a reporter without the launcher; +their start/end pair proves collection. Compare `ci.expected_invocations` with +`ci.reported_invocations`. Failed or cancelled workflows are conservatively incomplete because a failed command can prevent later tests or steps from running. @@ -90,9 +97,10 @@ unambiguous full-suite baseline. GitHub may carry earlier successful jobs into the new attempt's job inventory. Jobs completed before the new attempt started are excluded and counted in `ci.carried_job_count`. -If export fails, inspect **CI profile** and rerun that exporter after fixing the -cause. A partial HTTP export may already have sent some spans; retries use the -same IDs but the Events API does not promise deduplication. Timing artifacts +The exporter sends bounded batches with pauses and retries only events that +Honeycomb rejects temporarily. If export still fails, inspect **CI profile** +before rerunning it. A partial HTTP export may already have sent some spans; +reruns use the same IDs but the Events API does not promise deduplication. Timing artifacts remain available for 14 days. Invalid/oversized artifacts stop export instead of silently truncating the suite. No logs, environment dumps, error messages, stack traces, or credentials are included in the exported field allowlist. @@ -144,4 +152,5 @@ workflow. References: [Honeycomb trace fields](https://docs.honeycomb.io/get-started/best-practices/organizing-data/), [Events API](https://docs.honeycomb.io/api/events/create-events), +[large trace display limit](https://docs.honeycomb.io/troubleshoot/common-issues/data-in-honeycomb/#your-very-large-trace-displays-only-32000-spans), [GitHub workflow_run](https://docs.github.com/en/actions/reference/workflows-and-actions/events-that-trigger-workflows#workflow_run). diff --git a/scripts/ci-profile/export.mjs b/scripts/ci-profile/export.mjs index 48e726b42ed..2e5ab2ba2e5 100644 --- a/scripts/ci-profile/export.mjs +++ b/scripts/ci-profile/export.mjs @@ -14,19 +14,35 @@ const get = (endpoint) => JSON.parse(gh([endpoint]).toString()); const pages = (endpoint, field) => JSON.parse(gh(["--paginate", "--slurp", endpoint]).toString()) .flatMap((page) => field ? page[field] : page); -export async function sendEvents(events, apiKey, dataset, fetcher = fetch) { +export async function sendEvents(events, apiKey, dataset, fetcher = fetch, pause = (ms) => new Promise((resolve) => setTimeout(resolve, ms))) { if (!apiKey) throw new Error("HONEYCOMB_CI_API_KEY is not configured"); - for (let offset = 0; offset < events.length; offset += 500) { - const batch = events.slice(offset, offset + 500); - const response = await fetcher(`https://api.honeycomb.io/1/batch/${encodeURIComponent(dataset)}`, { - method: "POST", headers: { "X-Honeycomb-Team": apiKey, "Content-Type": "application/json" }, - body: JSON.stringify(batch), redirect: "error", signal: AbortSignal.timeout(30_000), - }); - if (!response.ok) throw new Error(`Honeycomb export failed (HTTP ${response.status})`); - const results = await response.json(); - if (!Array.isArray(results) || results.length !== batch.length || results.some((result) => result.status !== 202)) { - throw new Error("Honeycomb did not accept every span in the batch"); + const transient = new Set([429, 500, 502, 503, 504]); + for (let offset = 0; offset < events.length; offset += 250) { + let pending = events.slice(offset, offset + 250); + for (let attempt = 0; pending.length; attempt += 1) { + if (attempt >= 8) throw new Error(`Honeycomb did not accept ${pending.length} spans after retries`); + const response = await fetcher(`https://api.honeycomb.io/1/batch/${encodeURIComponent(dataset)}`, { + method: "POST", headers: { "X-Honeycomb-Team": apiKey, "Content-Type": "application/json" }, + body: JSON.stringify(pending), redirect: "error", signal: AbortSignal.timeout(30_000), + }); + if (!response.ok) { + if (!transient.has(response.status)) throw new Error(`Honeycomb export failed (HTTP ${response.status})`); + await pause(Math.min(30_000, 1000 * 2 ** attempt)); + continue; + } + const results = await response.json(); + if (!Array.isArray(results) || results.length !== pending.length) { + throw new Error("Honeycomb returned an unexpected batch response"); + } + const rejected = results.flatMap((result, index) => result.status === 202 ? [] : [{ event: pending[index], status: result.status }]); + const permanent = rejected.find(({ status }) => !transient.has(status)); + if (permanent) throw new Error(`Honeycomb rejected ${rejected.length} spans (status ${permanent.status})`); + pending = rejected.map(({ event }) => event); + if (pending.length) await pause(Math.min(30_000, 1000 * 2 ** attempt)); } + // The full suite can exceed Honeycomb's burst allowance. Leave capacity + // for the team's other telemetry rather than exhausting it in one export. + if (offset + 250 < events.length) await pause(1000); } } diff --git a/scripts/ci-profile/trace.mjs b/scripts/ci-profile/trace.mjs index 99beeabad04..a36112d6ced 100644 --- a/scripts/ci-profile/trace.mjs +++ b/scripts/ci-profile/trace.mjs @@ -105,7 +105,8 @@ export function buildTrace(run, jobs, records = []) { invocations.set(invocation, state); continue; } - if (!["file", "test"].includes(record.kind) || !text(record.id) || !text(record.name) + if (!["file", "test"].includes(record.kind) || !text(record.id) + || (record.kind === "file" ? !text(record.name) : typeof record.name !== "string") || !text(record.file) || !["vitest", "playwright", "node"].includes(record.framework) || !Number.isFinite(record.start) || !Number.isFinite(record.duration) || record.duration < 0 || record.start < millis(job.started_at) - 1000 @@ -128,7 +129,7 @@ export function buildTrace(run, jobs, records = []) { && candidate.conclusion !== "skipped"); const parent = files.get(`${invocation}:${record.parent}`) || (step ? id(`${jobId}:step:${step.number}`) : jobId); - span(recordId(entry), parent, record.name, record.start, record.start + record.duration, { + span(recordId(entry), parent, record.kind === "test" ? record.name.slice(0, 256) : record.name, record.start, record.start + record.duration, { "ci.kind": record.kind, "ci.job": job.name, "test.framework": record.framework, "test.file": record.file, "test.status": typeof record.status === "string" ? record.status.slice(0, 32) : "unknown", error: failed(record.status), "test.retries": Number.isFinite(record.retries) ? record.retries : 0, @@ -140,7 +141,9 @@ export function buildTrace(run, jobs, records = []) { const expectedReceipts = jobs.filter((job) => job.steps?.some((step) => step.name === "Initialize CI profile")); const missing = expectedReceipts.filter((job) => !receipts.has(job.id)); if (missing.length) warnings.push(`Missing timing artifacts for ${missing.length} jobs`); - const incomplete = [...invocations.values()].filter((value) => !value.expected || !value.start || !value.end).length; + // Some package scripts invoke a reporter without using the launcher. Its + // start/end pair proves collection even when no intent record was written. + const incomplete = [...invocations.values()].filter((value) => !value.start || !value.end).length; if (incomplete) warnings.push(`${incomplete} test invocations did not finish reporting`); if (rejected) warnings.push(`${rejected} invalid timing records ignored`); if (run.conclusion !== "success") warnings.push("Workflow did not succeed; later tests or steps may not have run"); @@ -159,8 +162,8 @@ export function buildTrace(run, jobs, records = []) { if (expectedReceipts.length && missingTests.length) warnings.push(`Missing test detail for ${missingTests.length} test jobs (including jobs that failed before testing)`); root["ci.test_count"] = valid.filter(({ record }) => record.kind === "test").length; root["ci.file_count"] = valid.filter(({ record }) => record.kind === "file").length; - root["ci.expected_invocations"] = [...invocations.values()].filter((value) => value.expected).length; - root["ci.reported_invocations"] = [...invocations.values()].filter((value) => value.expected && value.start && value.end).length; + root["ci.expected_invocations"] = invocations.size; + root["ci.reported_invocations"] = [...invocations.values()].filter((value) => value.start && value.end).length; root["ci.profile_complete"] = warnings.length === 0 && run.run_attempt === 1; root["ci.coverage_warnings"] = warnings.join("; "); return { traceId, events, warnings, wallMs: end - start, jobCount: jobs.length }; diff --git a/server/src/__tests__/vitest-chat-shards.test.ts b/server/src/__tests__/vitest-chat-shards.test.ts index 75de627551f..7c985762211 100644 --- a/server/src/__tests__/vitest-chat-shards.test.ts +++ b/server/src/__tests__/vitest-chat-shards.test.ts @@ -37,7 +37,7 @@ it("runs every active nested/parameterized fixture case exactly once through the const run = (index: number, count: number) => spawnSync(process.execPath, [ path.join(repoRoot, "scripts/run-vitest-stable.mjs"), "--mode", "general", "--group", "general-chat", "--shard-index", String(index), "--shard-count", String(count), - ], { cwd: root, env: { ...process.env, CI: "true" }, encoding: "utf8", timeout: 45_000, maxBuffer: 4 * 1024 * 1024 }); + ], { cwd: root, env: { ...process.env, CI: "true", PAPERCLIP_CI_PROFILE: "false" }, encoding: "utf8", timeout: 45_000, maxBuffer: 4 * 1024 * 1024 }); for (const index of [0, 1]) { const result = run(index, 2); expect(result.error, result.stderr).toBeUndefined();