mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-10-08 00:54:38 +02:00
## Thinking Path > - Paperclip is the control plane for running AI-agent companies, so long-running remote work needs to stay observable to human operators. > - Cloud / sandbox agents are an active roadmap area, and their workspace sync path is part of the runtime substrate every remote coding run depends on. > - In the sandbox and SSH execution-target flows, Paperclip logged that sync had started, then often went silent for the full transfer window. > - That made large remote syncs feel stalled and also hid a real performance problem in the command-managed sandbox upload path. > - The first part of this pull request threads a throttled progress-reporting surface through the adapter execution-target stack so sync and restore work can emit meaningful updates. > - The second part fixes the command-managed sandbox transport itself: it removes the old serial 32KB append bottleneck, but also falls back away from the single-stream path when a provider-backed sandbox runner cannot surface mid-flight stdin progress. > - The result is that sandbox and SSH transfers are both faster and more observable, including the live Daytona-style sandbox case that previously only emitted `0%` and `100%`. ## Linked Issues or Issue Description No public GitHub issue exists for this bug, so it is described inline below following the bug report template. ### What happened - Remote sandbox and SSH workspace syncs could spend a long time transferring data while only logging a start line (`Syncing workspace and runtime assets to sandbox environment`) and, at best, a terminal line. - In the command-managed sandbox path, the original upload implementation also paid a large performance cost by appending base64 data in many small sequential remote writes (thousands of serial 32KB round-trips on a large workspace). - After the initial transport rewrite, live provider-backed sandbox runs still only emitted `0%` and `100%` because the single-stream stdin RPC buffered progress until completion. ### Expected behavior - Long-running sandbox and SSH syncs should periodically report how much of the transfer is complete (a percentage and/or MB transferred) so an operator can tell the run is healthy and making progress rather than stuck. - The main sandbox upload path should not be artificially slow. - A transfer that fails partway should leave an explicit failure marker in the log rather than a dangling intermediate percentage. ### Steps to reproduce 1. Run an agent against a sandbox (command-managed) or SSH (remote-managed) execution target with a non-trivial workspace. 2. Watch the run log during the workspace/runtime asset sync phase. 3. Observe that the log shows the sync start line and then stays silent for the full transfer (live provider-backed sandbox runs only show `0%` then `100%`). ### Paperclip version or commit - Branch `PAPA-825-provide-status-updates-when-syncing-sandboxes` off `master`. ### Deployment mode - Self-hosted / local instance using sandbox (command-managed) and SSH (remote-managed) execution targets, including provider-backed sandbox runners. ## What Changed - Added shared throttled runtime progress reporting and threaded `onProgress` through the adapter execution-target surface and adapter `execute.ts` entrypoints. - Added sync and restore progress reporting for the command-managed sandbox path and the SSH/remote-managed path, including git import/export progress where totals are known. - Reworked command-managed sandbox transfer behavior so uploads use the faster single-stream path when appropriate, but fall back to chunked progress-emitting writes when the runner cannot expose mid-stream stdin progress. - Marked provider-backed environment sandbox runners as not supporting single-stream stdin progress so live sandbox runs emit meaningful intermediate updates instead of only `0%` and `100%`. - Emit an explicit terminal failure marker (`failed at NN% (x/y MB)`) when an SSH/tar transfer rejects, so a failed sync no longer leaves a dangling intermediate percentage in the log. - Run the SSH sync/restore size estimate (local directory walk / remote `du` probe) concurrently with the transfer instead of awaiting it before opening the pipe, so progress instrumentation no longer adds startup latency proportional to workspace file count. - Added and extended focused regression coverage for runtime progress throttling and the new failure marker, command-managed sandbox transfers, sandbox orchestration, SSH transfer progress, and environment execution-target wiring. ## Verification - `pnpm exec vitest run packages/adapter-utils/src/runtime-progress.test.ts packages/adapter-utils/src/ssh-fixture.test.ts packages/adapter-utils/src/command-managed-runtime.test.ts packages/adapter-utils/src/sandbox-managed-runtime.test.ts` - `pnpm exec vitest run packages/adapter-utils/src/command-managed-runtime.test.ts server/src/__tests__/environment-execution-target.test.ts` - `npx tsc --noEmit` for `packages/adapter-utils` ## Risks - The provider-backed sandbox fallback now prefers chunked command-managed writes when progress hooks are active, so small-to-medium uploads may trade some raw throughput for observable intermediate progress on runtimes that cannot surface true mid-stream stdin progress. - Progress percentages on tar-based transfers still depend on estimates in some cases, so operators may briefly see MB-only lines before the estimate resolves, then near-final clamping before the terminal `100%` line. - This PR changes shared execution-target behavior used by multiple adapters, so regressions would most likely appear in remote runtime setup/teardown flows rather than in a single adapter. ## Model Used - Initial implementation: OpenAI GPT-5.4 via Codex local agent (`codex_local`), high reasoning mode. - Observability follow-ups (failure marker, concurrent size estimate, added tests): Claude Opus 4.8 via Claude Code (`claude_local`). ## 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] I have run tests locally and they pass - [x] I have added or updated tests where applicable - [ ] If this change affects the UI, I have included before/after screenshots - [ ] 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 - [ ] I will address all Greptile and reviewer comments before requesting merge --------- Co-authored-by: Paperclip <noreply@paperclip.ing>
282 lines
8.2 KiB
TypeScript
282 lines
8.2 KiB
TypeScript
import { describe, expect, it } from "vitest";
|
|
import { createRuntimeProgressReporter } from "./runtime-progress.js";
|
|
|
|
const MB = 1024 * 1024;
|
|
|
|
function makeClock(start = 0) {
|
|
let value = start;
|
|
return {
|
|
now: () => value,
|
|
advance: (ms: number) => {
|
|
value += ms;
|
|
},
|
|
};
|
|
}
|
|
|
|
describe("createRuntimeProgressReporter", () => {
|
|
it("formats the message with phase, label, direction, target, percent and MB", async () => {
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Syncing",
|
|
label: "workspace",
|
|
direction: "to",
|
|
target: "sandbox",
|
|
});
|
|
|
|
await reporter.report(12.6 * MB, 31.4 * MB);
|
|
|
|
expect(lines).toEqual(["[paperclip] Syncing workspace to sandbox: 40% (12.6/31.4 MB)\n"]);
|
|
});
|
|
|
|
it("omits the label when none is provided (e.g. git history)", async () => {
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Importing git history",
|
|
direction: "to",
|
|
target: "ssh",
|
|
});
|
|
|
|
await reporter.report(4 * MB, 4 * MB);
|
|
|
|
expect(lines).toEqual(["[paperclip] Importing git history to ssh: 100% (4.0/4.0 MB)\n"]);
|
|
});
|
|
|
|
it("suppresses intermediate emits that neither cross a step nor exceed the interval", async () => {
|
|
const clock = makeClock();
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Syncing",
|
|
label: "workspace",
|
|
direction: "to",
|
|
target: "sandbox",
|
|
now: clock.now,
|
|
});
|
|
|
|
// First report always emits (step 0 crossed).
|
|
await reporter.report(1 * MB, 100 * MB); // 1%
|
|
// Still within the same 10% step and under 2s -> suppressed.
|
|
await reporter.report(2 * MB, 100 * MB); // 2%
|
|
await reporter.report(5 * MB, 100 * MB); // 5%
|
|
|
|
expect(lines).toHaveLength(1);
|
|
expect(lines[0]).toBe("[paperclip] Syncing workspace to sandbox: 1% (1.0/100.0 MB)\n");
|
|
});
|
|
|
|
it("emits when the percentage crosses a 10% step", async () => {
|
|
const clock = makeClock();
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Syncing",
|
|
label: "workspace",
|
|
direction: "to",
|
|
target: "sandbox",
|
|
now: clock.now,
|
|
});
|
|
|
|
await reporter.report(1 * MB, 100 * MB); // 1% -> emit (step 0)
|
|
await reporter.report(15 * MB, 100 * MB); // 15% -> crosses into step 1 -> emit
|
|
|
|
expect(lines).toHaveLength(2);
|
|
expect(lines[1]).toBe("[paperclip] Syncing workspace to sandbox: 15% (15.0/100.0 MB)\n");
|
|
});
|
|
|
|
it("emits on the time threshold even without a step crossing", async () => {
|
|
const clock = makeClock();
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Syncing",
|
|
label: "workspace",
|
|
direction: "to",
|
|
target: "sandbox",
|
|
now: clock.now,
|
|
});
|
|
|
|
await reporter.report(1 * MB, 100 * MB); // emit
|
|
await reporter.report(2 * MB, 100 * MB); // suppressed (same step, no time elapsed)
|
|
clock.advance(2000);
|
|
await reporter.report(3 * MB, 100 * MB); // 3% same step, but 2s elapsed -> emit
|
|
|
|
expect(lines).toHaveLength(2);
|
|
expect(lines[1]).toBe("[paperclip] Syncing workspace to sandbox: 3% (3.0/100.0 MB)\n");
|
|
});
|
|
|
|
it("always emits the terminal 100% line via report reaching the total", async () => {
|
|
const clock = makeClock();
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Restoring",
|
|
label: "workspace",
|
|
direction: "from",
|
|
target: "sandbox",
|
|
now: clock.now,
|
|
});
|
|
|
|
await reporter.report(1 * MB, 100 * MB); // emit
|
|
await reporter.report(100 * MB, 100 * MB); // terminal -> always emit
|
|
|
|
expect(lines[lines.length - 1]).toBe(
|
|
"[paperclip] Restoring workspace from sandbox: 100% (100.0/100.0 MB)\n",
|
|
);
|
|
});
|
|
|
|
it("complete() emits the terminal 100% line even when intermediate emits were throttled", async () => {
|
|
const clock = makeClock();
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Syncing",
|
|
label: "workspace",
|
|
direction: "to",
|
|
target: "sandbox",
|
|
now: clock.now,
|
|
});
|
|
|
|
await reporter.report(1 * MB, 100 * MB); // emit
|
|
await reporter.report(5 * MB, 100 * MB); // suppressed
|
|
await reporter.complete();
|
|
|
|
expect(lines[lines.length - 1]).toBe(
|
|
"[paperclip] Syncing workspace to sandbox: 100% (100.0/100.0 MB)\n",
|
|
);
|
|
});
|
|
|
|
it("complete() is idempotent and does not double-emit after a terminal report", async () => {
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Syncing",
|
|
label: "workspace",
|
|
direction: "to",
|
|
target: "sandbox",
|
|
});
|
|
|
|
await reporter.report(100 * MB, 100 * MB); // terminal
|
|
await reporter.complete();
|
|
await reporter.complete();
|
|
|
|
expect(lines).toHaveLength(1);
|
|
});
|
|
|
|
it("reports MB-only (no percent) when the total is unknown, plus a completion line", async () => {
|
|
const clock = makeClock();
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Restoring",
|
|
label: "workspace",
|
|
direction: "from",
|
|
target: "ssh",
|
|
now: clock.now,
|
|
});
|
|
|
|
await reporter.report(2 * MB, null); // first emit
|
|
await reporter.report(4 * MB, null); // suppressed (no time elapsed)
|
|
clock.advance(2000);
|
|
await reporter.report(8 * MB, null); // time elapsed -> emit
|
|
await reporter.complete();
|
|
|
|
expect(lines).toEqual([
|
|
"[paperclip] Restoring workspace from ssh: 2.0 MB\n",
|
|
"[paperclip] Restoring workspace from ssh: 8.0 MB\n",
|
|
"[paperclip] Restoring workspace from ssh: 8.0 MB\n",
|
|
]);
|
|
});
|
|
|
|
it("fail() emits a terminal failure marker with the last percent instead of a dangling line", async () => {
|
|
const clock = makeClock();
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Syncing",
|
|
label: "workspace",
|
|
direction: "to",
|
|
target: "ssh",
|
|
now: clock.now,
|
|
});
|
|
|
|
await reporter.report(40 * MB, 100 * MB); // emit at 40%
|
|
await reporter.fail();
|
|
|
|
expect(lines).toEqual([
|
|
"[paperclip] Syncing workspace to ssh: 40% (40.0/100.0 MB)\n",
|
|
"[paperclip] Syncing workspace to ssh: failed at 40% (40.0/100.0 MB)\n",
|
|
]);
|
|
});
|
|
|
|
it("fail() falls back to an MB marker when the total is unknown", async () => {
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Restoring",
|
|
direction: "from",
|
|
target: "ssh",
|
|
});
|
|
|
|
await reporter.report(3 * MB, null);
|
|
await reporter.fail();
|
|
|
|
expect(lines.at(-1)).toBe("[paperclip] Restoring from ssh: failed after 3.0 MB\n");
|
|
});
|
|
|
|
it("fail() is suppressed after a terminal completion and complete() after a failure", async () => {
|
|
const lines: string[] = [];
|
|
const reporter = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
lines.push(line);
|
|
},
|
|
phase: "Syncing",
|
|
label: "workspace",
|
|
direction: "to",
|
|
target: "ssh",
|
|
});
|
|
|
|
await reporter.report(100 * MB, 100 * MB); // terminal complete
|
|
await reporter.fail(); // suppressed — already completed
|
|
expect(lines).toHaveLength(1);
|
|
|
|
const failLines: string[] = [];
|
|
const failed = createRuntimeProgressReporter({
|
|
sink: (line) => {
|
|
failLines.push(line);
|
|
},
|
|
phase: "Syncing",
|
|
label: "workspace",
|
|
direction: "to",
|
|
target: "ssh",
|
|
});
|
|
await failed.report(20 * MB, 100 * MB);
|
|
await failed.fail();
|
|
await failed.complete(); // suppressed — already failed
|
|
expect(failLines).toHaveLength(2);
|
|
expect(failLines.at(-1)).toContain("failed at 20%");
|
|
});
|
|
});
|