materialize_tracked re-reads and re-hashes every present file on every pass, ignoring the scan cache

[myobie]

Summary

materialize_tracked reads and hashes EVERY present file on EVERY sync pass. It
never consults the scan cache. On the live Silber daemon this is the largest
single consumer of CPU.

Evidence

I measured the running daemon, PID 11655, version 0.2.0+fff659e.

I sampled the process CPU as a RATE, not as a level. I read the cumulative CPU
time twice over a known interval and divided.

• One 60 second window: 30.2 percent of one core.
• Twelve 10 second windows: mean 32.5 percent, range 19.7 to 50.8 percent.
• A 15 second sample profile, apportioned by top of stack: 35.0 percent.

Three instruments agree. ps %CPU reported 45.9 to 89.4 percent at the same
time, so ps %CPU overstates this load. Do not use it here.

The profile apportions the busy time like this, as a share of one core:

frame	share of one core
blake3_hash_many_neon	14.22%
__getdirentries64	6.30%
__sendmsg	2.69%
__open_nocancel + __open	2.85%
sync::glob::matches_bytes	1.63%
Manifest::normalize_path	0.77%

Content hashing is the largest consumer. The call path is
entry_loop → sync_once → scan_folder → scan_into_node_observed →
materialize_tracked → content_hash.

The cause

materialize_tracked iterates every present path and does this per file:

let existing = std::fs::read(&path);
...
let existing_hash = content_hash(&existing);

The function holds no reference to scan_cache. I checked origin/main and the
function still has none. scan_folder uses the cache; materialize_tracked
bypasses it.

Why it costs so much here

The st2-declarations-default entry syncs 64 files. Those files hold
70,157,702 bytes. Three stale build artifacts hold 69,898,880 of those bytes,
which is 99.6 percent:

23,346,256 B  plans/artifacts/fabric/pr25/f26618d/fabric-aarch64-apple-darwin
23,346,240 B  plans/artifacts/fabric/pr24/0f19107/fabric-aarch64-apple-darwin
23,206,384 B  plans/artifacts/fabric/pr24/5003cfd/fabric-aarch64-apple-darwin

I measured the pass cadence by watching the entry's state.json mtime. The
entry rewrote 64 times in 128 seconds, which is one pass about every 2 seconds.
That matches WATCH_MAX_COALESCE, so a continuous watch event stream drives it.
The mutation is real and external: st2 writes agent status files and appends
pty/*.events.jsonl inside the watched tree.

So fabric re-reads and re-hashes about 70 MB every 2 seconds. It does this
forever, for three binaries that no peer needs.

What this is NOT

This is not manifest decode. Manifest::diff_from took 1 sample. All
serde_json frames together took 12 samples. Issue #52 names "full decode per
pass" as cause 3. The profile does not support that as the live cost on this
daemon.

Suggested fix

Consult the scan cache in materialize_tracked, the same way scan_folder
does. A file whose size and mtime match the cache entry does not need a re-read
and does not need a re-hash.

I want a test that FAILS before the fix. The test should count the read or hash
calls across two passes over an unchanged tree. The count must not scale with
the tree.

Caveats

The profile is ONE 15 second sample. The apportionment above is that one sample.

I predicted blake3 would cost about 1.75 percent of a core, from 70 MB every 2
seconds at 2 GB/s. I measured 14.22 percent. My prediction was wrong by about
8x, so the per-byte cost, the real cadence, or the hashed volume is not what I
assumed. The direction is confirmed and the magnitude is not yet explained.

The st2-bus-default entry also re-reads 14,247 files per pass, holding
12.5 MB. That adds syscall load which I have not separated from the above.

Not actions I will take

The three artifacts live in the st2 catalog. That tree is not mine. I am not
deleting them and I am not editing that tree.

[myobie]

Correction: my 8x gap is resolved, and I had the cadence wrong

I reported that I predicted blake3 at 1.75 percent of a core and measured 14.22.
I said the magnitude was unexplained. It is explained now, and the error was
mine.

I measured the pass cadence from the state.json mtime and got one pass every
2 seconds. That instrument undercounts. state.json is only rewritten when the
content changes, so a pass that finds nothing new leaves no trace in the mtime.

fabric sync ls exposes a full_scans counter. That counter is the correct
instrument, and it counts every pass. Over a 90 second interval:

entry	full_scans	cadence
st2-declarations-default	+175	one every 0.51 s
st2-bus-default	+2	one every 45 s

The declarations entry full-scans about twice per second, not once per 2
seconds. That is 4x more passes than I claimed.

The numbers now agree

The declarations entry re-reads and re-hashes 70,157,702 bytes per pass.

• 70.16 MB x 175 passes / 90 s = 136.4 MB/s re-hashed, sustained.
• The profile puts blake3_hash_many_neon at 14.22 percent of one core.
• 136.4 MB/s / 0.1422 = 959 MB/s effective single-core blake3 throughput.

959 MB/s is an ordinary NEON blake3 figure. My original prediction assumed the
wrong cadence, not a wrong hash rate. The chain is now closed and consistent.

Independent confirmation of which files are hashed

The hot blake3 kernel is the LARGE input path. compress_subtree_wide appears
11,605 times in the stacks and blake3_hash_many_neon 1,374 times. The
single-block path, compress_in_place, appears 8 times.

A blake3 input under 1024 bytes never reaches compress_subtree_wide. The
st2-bus-default entry holds 12.5 MB across 14,247 files, which averages 878
bytes, so it is almost entirely single-block work. The three artifacts are 23 MB
each.

So the kernel mix confirms the byte share independently: the hashing is the
large files.

A bare read of those three files costs 11 ms from the page cache, at 6.5 GB/s.
The cost is hashing, not I/O.

A second defect, which this issue does not cover

The declarations entry full-scans a CONVERGED tree about twice per second.
fabric sync ls reports drift=clean for it.

The trigger is real and external. The st2-bus-default root,
.../catalog/agents, is nested INSIDE the st2-declarations-default root,
.../catalog. st2 writes agent status files and appends pty/*.events.jsonl
under catalog/agents continuously. Every one of those writes wakes the
declarations watcher, and WATCH_DEBOUNCE is 150 ms.

Fixing this issue removes the hashing. It does NOT remove the scan storm. The
directory walk is 6.30 percent of a core and glob matching is 1.63 percent, and
both survive a scan-cache fix because the entry still walks 14,368 files twice a
second.

I will file that separately rather than widen this issue.

Revised expectation for the fix

Consulting the scan cache in materialize_tracked should take blake3 from
14.22 percent of a core to near zero, because 99.6 percent of the hashed bytes
belong to three files that never change.

It should leave the roughly 8 percent of a core spent walking and glob-matching
the tree untouched. That is the other defect.