fix(sync): background pin path logs a successful capsule download while storing nothing

[MichaelTaylor3d]

Task

The background pin path logs a successful download for an operation that stored nothing.

Observed on a real two-host EC2 run (run id mvp4-20260824-160219, dig-node v0.145.0 from the
released .deb):

whole-store sync downloaded a capsule ... bytes=134968615

Nothing was stored. The CLI sync trigger path reports the same underlying failure honestly; only
the background path claims success.

Why this is worth a ticket rather than a comment

Diagnosing from logs alone would mislead — and logs are the only surface available on a headless node,
which is exactly where this path runs. An operator reading that line concludes the capsule is resident and
moves on to debug the wrong layer. The e2e lane that found it was chasing an unrelated question and hit
this by comparing two surfaces that disagreed.

It also meets the bar on its own: a shipped surface that asserts a fact the system does not have. That
the fact is "your content downloaded" rather than a balance does not change the class — the honest
alternative was available and the CLI path already emits it.

The two surfaces disagreeing is the tell. One of them is wrong, and it is the one with no human in the
loop.

Context

• Producer: the background pin / whole-store sync path (contrast with the CLI sync trigger path, which
  is correct — copy its shape rather than inventing one).
• The byte count in the message (134968615) is close to but not equal to the capsule that genuinely
  moved in the same session (134,968,945 bytes, byte-exact C→A over mTLS). Worth checking whether the
  logged figure is bytes received being reported as bytes stored — that would explain both the message
  and the discrepancy.

Scope

Make the background path report what actually happened. Prefer the CLI path's existing honest wording over
new wording. If a partial download genuinely occurred, say that — a resumable partial is a real state
(§2.6's temp-file/resume model), and "downloaded" is not how to describe it.

Do not fix this by silencing the log. An operator with no line at all is better off than one with a
false line, but a correct line is better than both.

Evidence

A test asserting the emitted log line for a failed store — not that the failure path is reachable.
Read a passed-count, never an ok. Include the negative: the old wording must fail the new assertion, or
it proves nothing.

Cross-references

Found during: https://github.com/DIG-Network/dig_ecosystem/issues/2191 (the miss-contract e2e leg)
Fleet evidence: run mvp4-20260824-160219

[MichaelTaylor3d]

Diagnosed and located, NOT fixed on this lane — handing off with the exact fix rather than shipping it untested. Lane loop/batch-cache, PR #455.

Root cause, confirmed in the tree. Node::sync_module_from (crates/dig-node-core/src/lib.rs) emits

tracing::info!(store, served_root, bytes = bytes.len(), "whole-store sync downloaded a capsule");

before two things that can each still fail:

1. verify_synced_capsule_is_chain_anchored(...) — the fail-closed chain-anchored gate, which ?-returns.
2. the write itself — create_dir_all, persist_holder_claim, and write_atomic, each of which ?-returns.

So every failure after that line leaves an INFO line claiming a download while nothing reached disk. On a headless node the journal is the only surface this path has, which is what makes it mislead rather than merely mis-word.

Your byte-count hypothesis is confirmed. bytes is the buffer returned by download_capsule / clone_whole_store — bytes received, reported under a name that reads as bytes stored. That is why 134968615 is close to but not equal to the capsule that genuinely moved.

The fix, in two parts:

• Demote the pre-verify line to debug! and rename its field to bytes_received, wording it as received, verifying before storing — it is true at that point and only that.
• Add an info! after CACHE_REFETCH_COUNT.fetch_add(...), immediately before Ok(served_root), with bytes_stored — reaching that point is the one place "stored" is true, since every earlier exit is an Err the caller reports.

Why I am not landing it here. The ticket rightly asks for a test on the emitted log line for a failed store, with the negative (the old wording must fail the new assertion). Making that non-vacuous needs the download to SUCCEED and the verify to FAIL — pointing at an unreachable upstream makes the whole function error before either line, so such a test passes against the OLD code too. That needs a local HTTP upstream fixture serving dig.getCapsule chunks, which does not exist in dig-node-core today and is more than a tail-end addition to this batch.

crates/dig-node-core/src/peer.rs has a ready CaptureBuffer + capture_logs harness (private to its test module) that the eventual test should copy — it captures real emitted records, which is exactly the surface this ticket is about.

Ticket stays open.

[MichaelTaylor3d]

Taken by the standing dig-node backlog-drain lane.

• branch loop/mc-drain, draft PR fix(sync): the background whole-store sync must not log a download it never stored #468
• head 1b1d136

Confirmed the premise against origin/main (95c9592): crates/dig-node-core/src/lib.rs:2515 emits
info!("whole-store sync downloaded a capsule") immediately after the bytes arrive and before
verify_synced_capsule_is_chain_anchored, the provenance marker write, and write_atomic — all three of
which can refuse. sync_module (lib.rs:2404) then collapses that Err to a bare false and logs nothing,
so the only operator-visible record of a store-nothing sync is a success line.

Next action: reword the pre-store line to the fact it actually has (bytes received), add a post-write line
for the fact it does not yet have (capsule stored), and make the background wrapper log the reason it
returned false. Test asserts the emitted records via a scoped capturing subscriber, with the old wording as
the negative control.

[MichaelTaylor3d]

Fixed on loop/mc-drain, head 507afaf, draft PR #468.

The change

• lib.rs:2513 — the pre-store line now states the fact it actually has: "whole-store sync received a
  capsule's bytes; verifying and storing". Three refusals still lie between that point and residency.
• lib.rs after write_atomic — a new info! "whole-store sync stored a capsule", emitted only once
  the bytes are published. Not a silencing fix: the ticket rules that out and a control test enforces it.
• sync_module (lib.rs:2404) — the background wrapper no longer collapses the Err to a bare false
  with no trace. It warn!s "whole-store sync failed" with the reason, in control.rs:1598's own
  wording, so the background and CLI surfaces read alike.

Evidence — the emitted records, not the reachability of the path

Both tests read a scoped capturing subscriber's real output. test result: ok. 2 passed; 0 failed
(count read, not exit status).

Each part was proven load-bearing by reverting only that part, on a committed tree:

reverted	outcome
the pre-store wording alone	1 passed; 1 failed — the failure test goes red
the warn! and the "stored" wording	0 passed; 2 failed — both go red

The fixture makes the download genuinely SUCCEED and the chain disagree (the resolver anchors the store
at a different root), because a wire failure would never reach the log statement at all — that is the
shape actually observed on mvp4-20260824-160219.

Not done here, and stated rather than implied: the full dig-node-core lib run was
1006 passed; 26 failed, and every one of the 26 failed with
Io(Os { code: 112, kind: StorageFull }) from the fixture compiler. The dev machine is at 3.4 GB free
of 1.9 TB. Those failures are unrelated to this diff and are not reproducible until the disk is
reclaimed; CI runs on a clean runner.

[MichaelTaylor3d]

Re-ran the full suite on the reclaimed disk: test result: ok. 1032 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out (503s).

This supersedes the 1006 passed; 26 failed reading recorded above. Every one of those 26 failed with
Io(Os { code: 112, kind: StorageFull }) from the fixture compiler, on a machine at 3.4 GB free — none
of them touched this diff. Recording the clean number rather than leaving the caveated one, since a
reader who finds the earlier comment first would otherwise inherit a false red.