mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-15 18:56:05 +01:00
## Thinking Path
- Cloud durable storage is a major source of failures and slowness on
staging. For example, a staging task failed when saving files after
automatic retries.
- Before measuring or fixing it, we need to see where storage time goes.
Today a saved-workspace restore before the turn appears only inside the
coarse `workspace_environment_realize` phase.
- After the turn, the save's encrypt, put, verify and multipart throttle
backoff have no timing at all. Only `captureMs`, `transferMs`,
`verifyMs`, `uploadMs` and `publishMs` exist, in `saveTiming`.
- Storage retries happen in the SDK and in the multipart uploader,
invisibly.
- This adds the measurement first, so the storage-mode chaos waves
(MinIO behind a fault proxy) can report save and restore p50/p95 and
point at the dominant wait.
## Linked Issues or Issue Description
**What happened?**
Durable-storage saves and restores were opaque in the run log and save
timing. A slow or repeatedly retried storage call could not be told
apart from slow capture, encryption or sandbox work.
**Steps to reproduce**
1. Run a remote task with S3-compatible durable storage, so it saves
after the turn and restores on the next run.
2. Inspect the run log and the `remote_workspace_snapshot` operation's
`saveTiming`. The restore's download, decrypt and verify, and the save's
put, verify and throttle backoff, have no timing.
**Expected behavior**
Each storage step has a duration, and storage request retries and
backoff are counted.
## What Changed
- `server/src/storage/request-stats.ts` (new): an async-local collector
of storage request statistics. Counts only:
- `requests`, `attempts` and `failedRequests`;
- `retryDelayMs` (SDK waits);
- `parts`, `throttled` and `backoffMs` (the multipart uploader's waits).
- `server/src/storage/s3-failure.ts`: `withS3FailureDiagnostics`, which
wraps every S3 send, records each request's SDK `$metadata.attempts` and
`totalRetryDelay`, on success and on failure.
- `server/src/storage/s3-multipart.ts`: records each uploaded part and
each resend wait, flagged throttled when the backend returned 503, 429
or SlowDown.
- `server/src/services/remote-workspace-snapshot-storage.ts`:
- Each step is a `storage.snapshot.*` run phase:
- save: `prior_attempts`, `encrypt`, `digest`, `put`, `verify`;
- restore: `download`, `decrypt`, `verify_plaintext`, `publish`.
- A caller can pass a `timing` record that receives the step durations,
the bytes and the request statistics.
- `server/src/services/remote-workspaces.ts`:
- The save passes a timing record, kept in `saveTiming.storage`.
- The sandbox unpack during a restore is its own phase,
`workspace.snapshot.sandbox_restore`.
- `execution-preparation-timing.ts`: the new phase names.
- `doc/run-log-events.md`: a new "Durable storage timing" section.
Because the restore runs inside run preparation, its steps of 50 ms or
more become `run.performance.span` rows with no extra plumbing. This is
run-log and instance-database data only; there's no Telemetry change.
## Verification
- `server`: `storage-s3-multipart-backoff`, `storage-s3-multipart`,
`storage-s3-multipart-throttle`, `storage-s3-failure-diagnostics`,
`remote-workspace-snapshot-storage` and `execution-preparation-timing`
tests: 86 passed. They include:
- collected stats for a throttled multipart upload: 12 requests, 7
failed, 7 throttled, 35.5 s backoff and 3 parts;
- a save and restore that fill every step duration and the byte count.
- `remote-workspaces.integration.test.ts`: 112 passed. Its `saveTiming`
assertion now includes `storage`.
- Server typecheck: no errors in the touched files.
## Risks
- **Overhead:** one async-local lookup per S3 request, plus timestamps
per snapshot step.
- **Collector scope:** the collector only exists inside a snapshot save
or restore. Other storage callers are unaffected; they record nothing.
- **`saveTiming`** gains a `storage` object. Readers that compare it
exactly (one test, updated) will see the new field.
## Model Used
Claude Opus 5.5 (`claude-opus-5-5`, Anthropic), 1M context window, tool
use and code execution, via Claude Code.
## 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
🤖 Generated with [Claude Code](https://claude.com/claude-code)
---------
Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
27 lines
1.5 KiB
TypeScript
27 lines
1.5 KiB
TypeScript
import { describe, expect, it } from "vitest";
|
|
import { collectStorageRequestStats, newStorageRequestStats, withStorageRequestStats } from "../storage/request-stats.js";
|
|
import { withS3FailureDiagnostics } from "../storage/s3-failure.js";
|
|
|
|
describe("storage request statistics", () => {
|
|
it("adds each request's SDK attempts and retry delay, on success and on failure", async () => {
|
|
const stats = newStorageRequestStats();
|
|
await collectStorageRequestStats(stats, async () => {
|
|
await withS3FailureDiagnostics("get_object", async () => ({ $metadata: { attempts: 3, totalRetryDelay: 1_250 } }));
|
|
await expect(withS3FailureDiagnostics("put_object", async () => {
|
|
throw Object.assign(new Error("Service Unavailable"), { name: "ServiceUnavailable", $metadata: { httpStatusCode: 503, attempts: 4, totalRetryDelay: 2_000 } });
|
|
})).rejects.toThrow("Service Unavailable");
|
|
// A cleanup request sent outside the diagnostics wrapper still counts.
|
|
await withStorageRequestStats(async () => ({ $metadata: { attempts: 1 } }));
|
|
// No metadata: one attempt, no delay.
|
|
await withS3FailureDiagnostics("head_object", async () => ({}));
|
|
});
|
|
expect(stats).toMatchObject({ requests: 4, attempts: 9, retryDelayMs: 3_250, failedRequests: 1 });
|
|
});
|
|
|
|
it("collects nothing outside a collector", async () => {
|
|
const stats = newStorageRequestStats();
|
|
await withS3FailureDiagnostics("get_object", async () => ({ $metadata: { attempts: 2, totalRetryDelay: 10 } }));
|
|
expect(stats.requests).toBe(0);
|
|
});
|
|
});
|