fix(mcp,relayer): stop restore looping on an empty page, and measure the write path

[harrymove-ctrl]

Follow-up to #912, from running the field report's own cases against dev with the published @mysten-incubation/memwal-mcp@0.0.13-dev.6.

Three changes. None alters any tool's contract.

1. memwal_restore told an agent to loop on an empty namespace

Observed live:

total=0  restored=0  skipped=0  failed=0  truncated=true
⚠️ More blobs remain to restore — increase limit and call again.

Nothing had been seen that said blobs remain, and the advice next to total=0 reads as a contradiction.

Two things produce it and only the second is wrong:

• truncated is honest. restore_is_truncated (routes/admin.rs) ORs in source_capped, the sidecar's candidate cap across all of an owner's namespaces. Blobs elsewhere can saturate it while this namespace's page is empty, and below limit < 20 raising the limit genuinely does grow discovery. The doc comment there already anticipates the shape — "including empty namespaces at limit=100" — but only the limit=100 arm was handled.
• The wording is not. formatRestoreResult had no branch for an empty page, and the WALM-480 transient check could never catch one: its guard is skipped + failed < total, which at total = 0 is 0 < 0. Every empty page fell through to the raise-limit arm.

An empty page now says what is known: no blobs found here, the owner-wide cap was reached so this namespace may not have been looked at, and — below the cap — raising the limit widens the search, with the note that a limit already at the cap means the namespace is almost certainly empty and the name is worth checking. A non-truncated empty page just says there is nothing to restore.

The existing WALM-431 test is kept with its intent preserved: the action (raise the limit) was always right and still fires. What it no longer asserts is More blobs remain, which was the false half. Its comment records why, so this does not read as loosening a test for green.

2. The write path had no instrumentation at all

A memwal_remember on a healthy dev takes 33–67s, matching the report's "19s to 1m1s". Locating that time took a wall clock and a log scrape, because the path holding nearly all of it is the one write path nothing measures.

advance_durable_upload had zero observe_external calls while the same file has thirteen elsewhere. The walrus_upload histogram covers only the legacy route, and a tracked job always takes the durable one (remember_job_id is always Some), so it never fires for a real write.

Worse, two numbers that look like write cost are not:

metric	what it actually is
walrus_query_blob_storage_leases 10.94s	the periodic expiry sweep, not the write path
sui_grpc/GetObject 0.31s	delegate-key auth, before the 202

Everything in /metrics accounts for about 4s of a ~58s write.

One remember makes five sequential POSTs to /walrus/upload-step-v3. Aggregating them would answer "the upload was slow", which was never in doubt. Each hop now gets its own series:

walrus_upload_step_encode
walrus_upload_step_register_prepare
walrus_upload_step_register_execute
walrus_upload_step_upload
walrus_upload_step_certify
walrus_upload_step_other

Transport failures record too, matching set_metadata_batch next door, and go through record_sidecar_failure. The label set is closed on purpose — the phase comes from caller-supplied JSON, so a malformed step collapses to one bucket rather than minting a series per input, and a test pins that.

What the numbers look like

A log scrape of one 36.4s write:

hop	cost
encode	2.8s
register_prepare	4.1s
register_execute	5.9s
upload (Walrus relay)	6.9s
certify	5.2s
metadata/transfer	8.5s

So the Walrus write itself is ~7s; the rest is round trips and on-chain ordering. That is one sample, from one environment, read out of stderr. This metric is what turns it into something anyone can query, per environment, over time.

3. The last leg was blind too

The ~8.5s between certified and done is the transfer plus the vector insert. Only walrus_set_metadata_batch (~3s) was measured; the rest could only be recovered by diffing log timestamps. insert_vector now reports through observe_db, adding a dimension to the existing memwal_db_query_duration_seconds family rather than a new one.

The optimisation that looked cheapest, and why it is not in this PR

The job reaches certified at ~27s of a ~36s write and the blob is durable on Walrus there. So "return the tool call at certified, let metadata/transfer finish in the background" looks like ~8.5s, around 23%, for almost nothing.

It is not. insert_vector_and_mark_remember_done does both things its name says, in order:

insert_vector(...).await          // indexes the memory
UPDATE remember_jobs SET status = 'done' ...

done means findable, not merely stored. Until that insert commits, the blob is on Walrus and paid for but memwal_recall cannot see it. Returning early would make memwal_remember answer "Saved" for a memory the very next memwal_recall misses — the same class of defect as the report's §1b, where the tool's answer did not match what the store held. Not worth 8.5s.

I had ranked that change low-risk before reading this code. That ranking was wrong.

What else is deliberately not here

The standalone encode hop looks redundant (the next call re-encodes and its response already carries resumeStep: encoded), and three happy-path reads exist only to return a negative answer. Both are plausible wins.

Neither should be cut on a single stderr sample. They sit inside a durable, resumable, money-spending state machine, and the negative-answer reads are exactly the shape of an idempotency guard for crash-resume. Two diagnoses in this investigation were confidently wrong before measurement corrected them. Land the metric, read one real deployment, then cut with per-hop numbers instead of one log scrape.

Also worth setting expectations: ~12–20s of a testnet write is structural — three ordered on-chain transactions plus a relay write that has to store bytes. Even with every avoidable hop removed, memwal_remember will not reach the "a few seconds" the report expects without an architectural change.

Tests

cargo test -p memwal-server → lib 469 passed (3 new), bin 700 passed (3 new). The 21 and 47 failures in those suites are the pre-existing sandbox PermissionDenied in tests that bind local sockets — unchanged, and none in a file this PR touches.

Sidecar suite → 81 passed, restore.test.ts 12 of them (4 new). tsc --noEmit clean.