The cargo registry cache misses on every run for a large workspace — and the restore failure is invisible

[debuggingfuture]

#118 made the cargo registry cacheable by teaching CacheService a base outside the checkout. On a large Rust consumer it still misses every run — the full cargo fetch --locked download runs each time, ~1.0 GB and ~40s, and the log is byte-identical run to run.

Evidence

The install's exec logs are identical across a dozen consecutive executions (exec-5.ndjson, 41,299 B of Downloaded <crate> lines). composeRestoreOr runs onMiss only on a miss or a restore error, so one of the two is happening on every attempt — and it has been happening since #118 deployed, which rules out "the first run pays and the rest hit".

The suspicion, stated as a suspicion

The archive is 113.9 MB for that repo (registry/cache 113 MB + registry/index 44 MB, gzipped). The restore path does:

await box.writeFile(TARBALL_PATH, archive.body);

— streaming a 114 MB body from R2 into the container through the Worker, against a 128 MB isolate memory budget. That is close enough to the ceiling to be worth ruling in or out before anything else, and it would explain why a smaller consumer's node_modules cache works while this one does not.

Not confirmed: restore catches its own failure into CacheError and composeRestoreOr treats it as a miss, so the failure is invisible from the consumer side. The first fix is to make it visible — log the restore error at warn with its phase and size, so the next run says which of the two it is instead of leaving it to be inferred.

Why it matters more than 40 seconds

It is 40s and 1 GB today, on a run that shares one container. The moment stages get their own containers (#131), the same download is paid N times.

[debuggingfuture]

Correction: the failure is logged, it is just not reachable from the consumer's side

I wrote above that "the restore failure is caught into a CacheError and treated as a miss, so it is invisible" and proposed logging as the first fix. That is wrong — composeRestoreOr already logs both swallows, and has since #120:

restore(opts).pipe(
  Effect.catchAll((e) => Effect.as(Effect.logWarning(e.message), false)),
  …
  save(opts).pipe(Effect.catchAll((e) => Effect.logWarning(e.message))),

and cache-r2.test.ts pins both ("a swallowed save failure is logged, not discarded silently", "a swallowed restore failure is logged too").

So the diagnosis is available; it lands in the dispatcher's logs, which a consumer reading its own PR checks cannot see. The /v1/executions/<id> record carries steps and log files, and neither includes the Worker-side logWarning output.

What would actually close this

Either of:

1. Surface it in the execution record. The install runs inside the checkout step; a cache miss with a reason belongs on that step's metadata, where /v1/executions/<id> already exposes stepOpts.* and would need no new endpoint.
2. Read it dispatcher-side and answer the question directly — wrangler tail during a consumer's run, or the Workers Logs UI, filtered to cache restore. That is a one-off diagnostic rather than a fix, but it settles the 128 MB hypothesis in one run instead of by inference.

The measurement stands: 113.9 MB archive, a full ~1.0 GB cargo fetch on every run since #118 deployed, log byte-identical run to run.

[debuggingfuture]

Measured: this is now the thing blocking parallel stages, and it is worse than "40s a run"

#135 made stageConcurrency > 1 possible. Turned on for five stages on a large Rust consumer, the run does not finish in roughly its longest stage. It stalls.

^	Stage	Alone (sequential)	Five in parallel
1	ts	70s	still running at 1038s
2	formal	24s	still running at 1038s
3	features	533s	still running at 1038s
4	connectors	254s	still running at 1038s
5	workspace	666s	982s (its own gate time 880s)

A 24-second stage that has not finished in seventeen minutes is not CPU contention. The execution's log inventory says what it is: seven cargo fetch --locked logs, each 41,299 bytes — the same full ~1.0 GB registry download, seven times, in one run. Five stages plus rebuilds, each paying the miss.

workspace's own numbers show the compute side is fine under contention: 880s against 666s alone, memory peak 2.1 GiB of 11.9 GiB. The stall is bandwidth, and it is entirely this cache.

Consequence

Isolated stages are reverted to sequential on that consumer until this is fixed. The ordering is now unambiguous:

1. This issue. One registry restore per container instead of one full download.
2. Then turn stageConcurrency back on and get the wall clock the routing fix made possible.

Doing them in the other order buys N× the bytes for a slower run, which is what the measurement above is.

The suspicion from the original report stands and is worth ruling in or out first: the archive is 113.9 MB, the restore path buffers it through a Worker isolate with a 128 MB budget, and composeRestoreOr swallows the failure into a miss. One wrangler tail during a consumer run settles it.

[debuggingfuture]

Root cause: the restore passes a stream to a method that throws unconditionally

Not the 128 MB isolate budget I suspected above — that guess was wrong, and size has nothing to do with it. cache-r2.ts:94 does:

await box.writeFile(TARBALL_PATH, archive.body);   // archive.body is a ReadableStream

and the SDK (@cloudflare/sandbox@0.10.1) dispatches on the argument type:

async writeFile(path, content, options = {}) {
  const session = options.sessionId ?? await this.ensureDefaultSession();
  if (content instanceof ReadableStream) return this.client.files.writeFileStream(path, content, session);
  return this.client.files.writeFile(path, content, session, { encoding: options.encoding });
}

writeFileStream(_path, _content, _sessionId) {
  throw new Error("writeFileStream requires the rpc transport. Set SANDBOX_TRANSPORT=rpc.");
}

writeFileStream has no implementation on this transport — it is a bare throw. SANDBOX_TRANSPORT is set nowhere in this repo, so the default applies and every restore raises. composeRestoreOr catches it into a miss, logs a warning into the dispatcher's own logs where no consumer can see it, and runs the full install.

So the cache has missed on every run since #118 deployed, deterministically, for a reason that has nothing to do with the archive, the key, or R2. Its own doc comment on readFileStream (#88) warned about exactly this class on the read side; the write side has the same split and it was not checked.

Three ways out, and the one worth taking

^	Fix	Cost
1	SANDBOX_TRANSPORT=rpc	One config line, unknown blast radius: it changes the transport for every sandbox operation, not just this one
2	Buffer the archive and pass a string, as the SDK's error advises	A 114 MB archive is ~152 MB base64 in a 128 MB isolate — this is where the size objection actually bites
3	Never move the bytes through the Worker. Serve the archive from the tokened artifact endpoint and have the container pull it: curl -fsSL '<signed>' | tar xz -C <base>	The container already has curl; the save path already streams out rather than buffering; and it removes the isolate from the data path entirely

(3) is the shape the save side already has, and the only one whose cost does not grow with the archive.

Why it is worth doing now rather than later

Measured on a large Rust consumer: five isolated stages produced seven cargo fetch --locked logs of 41,299 bytes each — the same ~1.0 GB download, seven times, in one run — and stalled a 24-second stage past seventeen minutes. Sequentially it is ~40s and 1.0 GB a run, which is why it read as a nuisance for so long. It is the thing standing between stageConcurrency and the wall-clock win #135 made available.

[debuggingfuture]

Two more things found while reading the SDK, both of which change the options table above.

SANDBOX_TRANSPORT is a Worker env var read in the Sandbox DO's constructor, not a per-call option:

const transportEnv = envObj?.SANDBOX_TRANSPORT;
if (transportEnv === "websocket" || transportEnv === "rpc") this.transport = transportEnv;

So option 1 is genuinely one line in wrangler.jsonc — and genuinely switches the transport for every sandbox operation on a dispatcher serving several repos, not just the cache restore. Cheap to try, not cheap to be wrong about.

The SDK already ships the container-side R2 path option 3 describes. It carries BACKUP_BUCKET, CLOUDFLARE_ACCOUNT_ID, R2_ACCESS_KEY_ID, R2_SECRET_ACCESS_KEY, and createBackup / restoreBackup — and its restore streams the archive straight into the container, falling back to base64 only when the R2 object has no body stream:

await this.client.files.writeFileStream(archivePath, body, backupSession);
} else {
  const archiveBuffer = await archiveObject.arrayBuffer();
  const base64Content = Buffer.from(archiveBuffer).toString("base64");

Worth evaluating before hand-rolling a curl | tar xz: if createBackup/restoreBackup do the right thing on the deployed transport, the cache becomes a call rather than a mechanism to maintain — and the credentials plumbing already has a home. (Note the fallback there is the same base64 buffering option 2 rules out on size, so this needs checking on a 114 MB archive rather than assuming.)

[debuggingfuture]

Final number from that parallel run, which is worse than "stalled":

formal — a 24-second stage — ran for 2037s and then FAILED. connectors, features and ts were still running at 2088s. Only workspace completed (982s), and it did so first, because it is the one stage whose work dwarfs its own install.

An 85× degradation on the cheapest stage in the gate. Five containers each pulling ~1.0 GB does not slow the run down proportionally — it starves the stages that have nothing else to do, and they die on their ceilings having accomplished nothing.

So the cost of this cache miss is not the ~40s a sequential run pays. It is that concurrency, the single largest remaining win in the gate's wall clock, is unusable while it stands.

[debuggingfuture]

Settling the numbers I posted above as lower bounds — two stages died, not one:

^	Stage	Sequential	Five in parallel
1	formal	24s	failed at 2037s
2	ts	70s	failed at 2337s
3	connectors	254s	still running at 2392s
4	features	533s	still running at 2392s
5	workspace	666s	982s — the only one that finished, and it finished first

Two of five dying on their ceilings having accomplished nothing is starvation, not contention. The stages that lose are precisely the ones with the least work of their own to do — they are pure install, and the install is the thing that misses.

[debuggingfuture]

Fixed. The cache hits on rpc.

First run of a consumer with sandbox.transport:<repo> = rpc (#140), compared against the same repo's previous run:

^	Log inventory	Before (http)	After (rpc)
1	lockfile probes + sha256sum Cargo.lock	53 / 56 / 49 / 157 B	present, twice
2	cargo fetch --locked	41,299 B	absent
3	checkout step	45–299s	65s

The absence is positive evidence, not a gap: detectTool's probes and the lockfile hash only run inside installCached, so the install path executed — and did not fetch. That is composeRestoreOr taking the hit branch and skipping onMiss for the first time since #118.

What this confirms

The diagnosis holds exactly: writeFile(path, ReadableStream) → writeFileStream → a bare throw off rpc, caught into a miss. Nothing to do with the 113.9 MB archive, the key, or R2 — the same restore, unchanged, works the moment the transport can stream.

For other consumers

sandbox.transport:<owner>/<repo> = rpc per repo, or SANDBOX_TRANSPORT=rpc as a Worker var once enough repos have proved it. Worth knowing before flipping the var: setTransport persists to each container's DO storage and the SDK prefers a stored transport over the env default on cold start, so the two mechanisms do not fight but a pinned container keeps its pin.

The obvious follow-up is whether http should remain the default at all, given the streaming file APIs simply do not exist there and the SDK calls rpc its primary client.