mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-10-19 20:44:16 +02:00
## Thinking Path > - Paperclip uses pull request CI to check changes before merge. > - The merged CI profiler records a selected full PR suite in Honeycomb. > - A real 48-job profile exposed an export failure after Honeycomb accepted only part of the trace. > - The same run exposed three fixture subprocesses that looked like incomplete test launches, one direct reporter without a launcher marker, and one overlong test name. > - The exporter needs to handle temporary ingest rejection without sending accepted spans again. > - This pull request fixes those cases and documents the trace display limit. > - The benefit is a complete, checkable CI waterfall with test-file timings. ## Linked Issues or Issue Description **What happened?** The first live `profile-ci` run on #16423 completed all 48 jobs, but the post-run exporter stopped when Honeycomb rejected part of a batch. The initial trace had no root span. Its coverage flag also reported four unfinished invocations and one invalid timing record. **Expected behavior** The exporter should pace large uploads, retry only temporarily rejected events, and publish the root after every child is accepted. Completed reporters should count as complete. Long test names should not erase test timing. **Steps to reproduce** 1. Add `profile-ci` to a CI CODEOWNER PR with the merged profiler. 2. Run the full PR suite, as in [run 38732093469](https://github.com/paperclipai/paperclip/actions/runs/38732093469). 3. Inspect the separate [failed exporter run](https://github.com/paperclipai/paperclip/actions/runs/38733393370) and the trace coverage fields. **Paperclip version or commit** `12612b06eb4332844ac4c8770a1fb6c6b7eccbc9` (PR run head, based on merged #16378). ## What Changed - Pace Honeycomb uploads and retry only transiently rejected events from each batch. - Preserve overlong test timings with bounded names and count complete reporter pairs without a launcher record. - Keep nested Vitest fixture runs from inheriting CI profiling and creating false coverage gaps. - Clarify ordinary CI access, large-trace display limits, and export behavior in the operator guide. ## Verification - [Full PR suite](https://github.com/paperclipai/paperclip/actions/runs/38732093469/attempts/1): 48 of 48 jobs succeeded; 10m 29s wall time. The selected jobs used the AWS public PR fleet. The protected exporter used a separate GitHub-hosted runner. - [Clean Honeycomb file waterfall](https://ui.honeycomb.io/paperclip/environments/test/datasets/paperclip-ci/trace?trace_id=01ed0c541b0442e613a030ffb6dc8d9b&trace_start_ts=1792065955&trace_end_ts=1792066584): 48 jobs, 822 steps, 2,622 file spans, and `ci.profile_complete=true`. It was reconstructed from that run's 45 timing artifacts after identifying three nested fixture records. The full trace also recorded 44,497 tests; Honeycomb's chart omits some deep test spans because it displays at most 32,000 spans per trace. - The original exporter stopped after a partially accepted batch. A local replay of that batch succeeded. I used the authorized local test-environment key to complete the original upload and create the file-level view. No key was added to this branch or PR. - `node --test .github/scripts/tests/ci-profile.test.mjs scripts/ci-profile/reporters.test.mjs`: 18 passed. - `pnpm exec vitest run server/src/__tests__/vitest-chat-shards.test.ts`: 1 passed. - `git diff --check`: passed. - The local `pnpm -r typecheck` and profiled fixture rerun could not start: the package-manager shim could not verify the `pnpm@9.15.4` registry signature because its fetches failed. `pnpm test:run` and `pnpm build` were not run locally; hosted CI is pending. - The updated exporter has not yet run from protected `master`; this PR remains draft until CI and review finish. ## Risks - A 48,000-span export now takes about three extra minutes due to pacing. Retry limits still fail a persistently rejected batch and keep the root unpublished. - Honeycomb may retain duplicates from an already partial export. The clean file-level evidence trace uses a separate trace ID. - The API key stays only in the protected `ci-profiling` environment. PR jobs write timing artifacts but never receive it. > For core feature work, check [`ROADMAP.md`](ROADMAP.md) first and discuss it in `#dev` before opening the PR. Feature PRs that overlap with planned core work may need to be redirected — see `CONTRIBUTING.md`. ## Model Used OpenAI Codex, GPT-6 family, with reasoning, code execution, GitHub API, and browser inspection. The runtime does not expose the exact serving model ID or context window size. ## Checklist - [x] I have included a thinking path that traces from project context to this change - [x] I have specified the model used (with version and capability details) - [x] I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work - [x] I have searched GitHub for duplicate or related PRs and linked them above - [x] I have either (a) linked existing issues with `Fixes: #` / `Closes: #` / `Refs: #` OR (b) described the issue in-PR following the relevant issue template - [x] I have not referenced internal/instance-local Paperclip issues or links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip` URLs) - [x] My branch name describes the change (e.g. `docs/...`, `fix/...`) and contains no internal Paperclip ticket id or instance-derived details - [x] I have run tests locally and they pass - [x] I have added or updated tests where applicable - [x] I have updated relevant documentation to reflect my changes - [x] I have considered and documented any risks above - [ ] All Paperclip CI gates are green - [ ] Greptile is 5/5 with no open P2s, recommendations, or follow-ups - [x] I will address all Greptile and reviewer comments before requesting merge --------- Co-authored-by: Paperclip <noreply@paperclip.ing>
180 lines
10 KiB
JavaScript
180 lines
10 KiB
JavaScript
import { createHash } from "node:crypto";
|
|
|
|
const millis = (value) => Date.parse(value);
|
|
const id = (value, size = 16) => createHash("sha256").update(value).digest("hex").slice(0, size);
|
|
const failed = (status) => ["failure", "failed", "timed_out", "timedOut", "cancelled", "interrupted"].includes(status);
|
|
const text = (value) => typeof value === "string" && value.length <= 4096;
|
|
|
|
export function buildTrace(run, jobs, records = []) {
|
|
if (run.status !== "completed" || !jobs.length || jobs.some((job) => job.status !== "completed")) {
|
|
throw new Error("A complete workflow attempt and its full job inventory are required");
|
|
}
|
|
if (jobs.some((job) => job.run_id !== run.id || job.run_attempt !== run.run_attempt)) {
|
|
throw new Error("Job inventory contains another run or attempt");
|
|
}
|
|
const key = `${run.repository.full_name}:${run.id}:${run.run_attempt}`;
|
|
const traceId = id(key, 32);
|
|
const rootId = id(`${key}:root`);
|
|
const start = millis(run.run_attempt === 1 ? run.created_at : run.run_started_at);
|
|
// The attempt jobs API can relabel carried-over successful jobs with the
|
|
// new attempt number. Their completion clocks still precede this attempt.
|
|
const carriedJobs = run.run_attempt > 1 ? jobs.filter((job) => millis(job.completed_at) < start) : [];
|
|
jobs = jobs.filter((job) => !carriedJobs.includes(job));
|
|
if (!jobs.length) throw new Error("No jobs executed in this workflow attempt");
|
|
const end = Math.max(...jobs.map((job) => millis(job.completed_at)).filter(Number.isFinite));
|
|
if (!Number.isFinite(start) || !Number.isFinite(end) || end < start) throw new Error("Invalid run timing");
|
|
const events = [];
|
|
const warnings = [];
|
|
if (carriedJobs.length) warnings.push(`${carriedJobs.length} completed jobs carried over from earlier attempts were excluded`);
|
|
const shared = {
|
|
"service.name": "paperclip-ci",
|
|
"trace.trace_id": traceId,
|
|
"ci.repository": run.repository.full_name,
|
|
"ci.run_id": String(run.id),
|
|
"ci.attempt": run.run_attempt,
|
|
"ci.commit": run.head_sha,
|
|
"ci.branch": run.head_branch,
|
|
"ci.url": run.html_url,
|
|
};
|
|
const span = (spanId, parent, name, from, to, fields) => {
|
|
if (!Number.isFinite(from) || !Number.isFinite(to) || to < from) return;
|
|
events.push({
|
|
time: new Date(from).toISOString(), samplerate: 1,
|
|
data: { ...shared, "trace.span_id": spanId, ...(parent ? { "trace.parent_id": parent } : {}),
|
|
name, duration_ms: to - from, ...fields },
|
|
});
|
|
};
|
|
span(rootId, null, `PR CI #${run.run_number || run.id} · attempt ${run.run_attempt}`, start, end, {
|
|
"ci.kind": "workflow", "ci.status": run.conclusion, error: failed(run.conclusion),
|
|
"ci.job_count": jobs.length,
|
|
"ci.carried_job_count": carriedJobs.length,
|
|
"ci.wall_ms": end - start,
|
|
// A partial rerun intentionally does not re-execute successful jobs.
|
|
"ci.partial_rerun": run.run_attempt > 1,
|
|
});
|
|
const roots = new Map();
|
|
const byName = new Map();
|
|
for (const job of jobs) {
|
|
const jobId = id(`${key}:job:${job.id}`);
|
|
roots.set(job.id, jobId);
|
|
byName.set(job.name.replace(/^ci \/ /, ""), job);
|
|
const created = Math.max(start, millis(job.created_at) || start);
|
|
const started = Math.max(created, millis(job.started_at) || created);
|
|
const completed = Math.max(started, millis(job.completed_at) || started);
|
|
// Include allocation wait in the job container, then distinguish it from
|
|
// execution. Dependency wait may precede job creation; it stays visible as
|
|
// a gap from the workflow start. GitHub does not expose a separate readyAt.
|
|
span(jobId, rootId, job.name, Math.min(created, started), completed, {
|
|
"ci.kind": "job", "ci.job": job.name, "ci.job_id": String(job.id),
|
|
"ci.status": job.conclusion, error: failed(job.conclusion),
|
|
"ci.runner": job.runner_name, "ci.runner_labels": (job.labels || []).join(","),
|
|
"ci.start_offset_ms": started - start,
|
|
"ci.execution_ms": Math.max(0, completed - started),
|
|
"ci.finishes_last": completed === end,
|
|
"ci.job_url": job.html_url,
|
|
});
|
|
if (started > created) span(id(`${jobId}:wait`), jobId, "Waiting for runner / scheduling", created, started, {
|
|
"ci.kind": "wait", "ci.job": job.name,
|
|
});
|
|
for (const step of job.steps || []) {
|
|
const from = millis(step.started_at);
|
|
const to = millis(step.completed_at);
|
|
if (from < start || to > end) continue; // skipped steps may use epoch timestamps
|
|
span(id(`${jobId}:step:${step.number}`), jobId, step.name, from, to, {
|
|
"ci.kind": "step", "ci.job": job.name, "ci.step": step.name,
|
|
"ci.status": step.conclusion, error: failed(step.conclusion),
|
|
});
|
|
}
|
|
}
|
|
|
|
const receipts = new Set();
|
|
const invocations = new Map();
|
|
const valid = [];
|
|
let rejected = 0;
|
|
for (const record of records) {
|
|
const job = byName.get(record?.job);
|
|
if (!job || record.version !== 1 || String(record.runId) !== String(run.id)
|
|
|| String(record.attempt) !== String(run.run_attempt) || !text(record.invocation)) {
|
|
rejected++; continue;
|
|
}
|
|
if (record.kind === "job") { receipts.add(job.id); continue; }
|
|
const invocation = `${job.id}:${record.framework}:${record.invocation}`;
|
|
if (["expected", "start", "end"].includes(record.kind)) {
|
|
const state = invocations.get(invocation) || {};
|
|
state[record.kind] = true;
|
|
invocations.set(invocation, state);
|
|
continue;
|
|
}
|
|
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
|
|
|| record.start + record.duration > millis(job.completed_at) + 1000) {
|
|
rejected++; continue;
|
|
}
|
|
valid.push({ record, job, invocation });
|
|
}
|
|
const recordId = ({ record, invocation }) => id(`${key}:${invocation}:${record.kind}:${record.id}`);
|
|
const files = new Map(valid.filter(({ record }) => record.kind === "file")
|
|
.map((entry) => [`${entry.invocation}:${entry.record.id}`, recordId(entry)]));
|
|
for (const entry of valid) {
|
|
const { record, job, invocation } = entry;
|
|
const jobId = roots.get(job.id);
|
|
// GitHub steps are ordered and have second-precision timestamps. Prefer
|
|
// the latest containing step: rounding may also make a preceding step fit
|
|
// a short file/test. Preserve the runner's own clock.
|
|
const step = job.steps?.findLast((candidate) => record.start >= millis(candidate.started_at)
|
|
&& record.start + record.duration <= millis(candidate.completed_at) + 1000
|
|
&& candidate.conclusion !== "skipped");
|
|
const parent = files.get(`${invocation}:${record.parent}`)
|
|
|| (step ? id(`${jobId}:step:${step.number}`) : jobId);
|
|
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,
|
|
"test.clock": record.clock === "reporter-receipt" ? "reporter-receipt" : "runner",
|
|
...(Number.isFinite(record.collectMs) ? { "test.collect_ms": record.collectMs } : {}),
|
|
...(Number.isFinite(record.setupMs) ? { "test.setup_ms": record.setupMs } : {}),
|
|
});
|
|
}
|
|
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`);
|
|
// 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");
|
|
if (!expectedReceipts.length) warnings.push("Job/step timings only; no test reporter collection steps were present");
|
|
const root = events[0].data;
|
|
const expectedFramework = (name) => {
|
|
if (/General tests|Verify serialized server suites|Verify Paperclip Runner \(vitest/.test(name)) return "vitest";
|
|
if (/e2e shard/.test(name)) return "playwright";
|
|
if (/\/ policy$|Typecheck \+ Release Registry|Verify Paperclip Runner \(static checks/.test(name)) return "node";
|
|
return null;
|
|
};
|
|
const missingTests = jobs.filter((job) => {
|
|
const framework = expectedFramework(job.name);
|
|
return framework && !valid.some((entry) => entry.job.id === job.id && entry.record.framework === framework);
|
|
});
|
|
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.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 };
|
|
}
|
|
|
|
export function traceUrl(team, environment, dataset, trace) {
|
|
const params = new URLSearchParams({
|
|
trace_id: trace.traceId,
|
|
trace_start_ts: String(Math.floor(Date.parse(trace.events[0].time) / 1000)),
|
|
trace_end_ts: String(Math.ceil((Date.parse(trace.events[0].time) + trace.wallMs) / 1000)),
|
|
});
|
|
return `https://ui.honeycomb.io/${encodeURIComponent(team)}/environments/${encodeURIComponent(environment)}/datasets/${encodeURIComponent(dataset)}/trace?${params}`;
|
|
}
|