perf(api): the default resource policy pins two workers, so nothing can show multi-core behaviour

[DecisionNerd]

Summary

ExecutionResourcePolicy::default() (crates/graphforge-api/src/resource_policy.rs:66-82) sets a fixed two-worker facade:

mode: ResourcePolicyMode::Explicit,
tokio_worker_threads: Some(2),
target_partitions: Some(2),
io_concurrency: Some(2),
compute_threads: Some(2),

pinned by defaults_and_bounds_are_stable at write_modes.rs:404. It preserves pre-#337 behaviour. On an 8-core / 16-thread host it is simply wrong, and every default-constructed instance takes two workers whatever the machine has.

Why this is a precondition, not a cleanup

#1456 lists this as work item 4, "independent of everything above; do it now". Under the foundation-first sequencing it is stronger than independent — it is a precondition for #1462 meaning anything.

While the default pins two workers, a serial-fraction instrument measures the facade rather than the engine, and no parallelism work underneath can show up in a ladder rung. The G500 ladder currently runs at 0.85–0.89 effective cores across a 64x edge range on a 16-thread host, and this default is one reason why.

Shape

Derive concurrency from machine parallelism: mode: Automatic with the individual knobs None so each defers to the mode. Keep the explicit path intact for callers that want to pin.

A change of this shape is already written and uncommitted on perf/unpin-compute-drop-rss-growth-gate — it has not been committed or test-run.

Acceptance

• Defaults derive from logical_cpus() rather than a constant; the mode is Automatic.
• Both pinning tests updated to assert the derived value rather than Some(2) — assert the invariant (concurrency follows the machine), not the observation (it equals 2).
• Explicit policies still honoured, and validate() bounds unchanged.
• A ladder rung shows effective cores above 1.0 once observe(storage): nothing measures the serial fraction of ingest, and #1387 budgets against it #1462 can report it, or the reason it does not is understood and recorded.

Caution

Worker count, execution partitions and durable partition layout are three different numbers. Raising this default must not change the recorded UUID splitters or the durable partition count — those are format parameters, not execution choices.

Plan: rev 8, phase 0b. Parent: #1456 (its work item 4).

[DecisionNerd]

Status correction: this is implemented, but it exists only on one machine

When this issue was filed the change was described as "written and uncommitted". It has since been committed as 1287a2f8 perf(api): derive instance concurrency from the machine instead of a fixed pair on branch perf/unpin-compute-drop-rss-growth-gate:

crates/graphforge-api/src/resource_policy.rs | 32 +++++++++++++++++++---------
crates/graphforge-api/src/write_modes.rs     |  8 ++++++-

The default is now mode: Automatic with tokio_worker_threads, target_partitions, io_concurrency and compute_threads all None, deferring to the mode, and defaults_preserve_fixed_two_worker_baseline is rewritten as defaults_derive_concurrency_from_machine_parallelism — asserting the derived value rather than the constant 2.

It is not merged, has no pull request, and the branch is not pushed to origin. git ls-remote --heads origin perf/unpin-compute-drop-rss-growth-gate returns nothing, so this work and the RSS-gate removal (5bbb8a71) exist on the bench host only. Both are ahead of origin/main by two commits total.

What still needs doing

• Push the branch and open a PR; neither commit has been through CI.
• The tests have not been run against this change in-session — cargo test -p graphforge-api at minimum, plus TCK (cargo test -p graphforge-api --test bdd, not graphforge-core).
• Confirm nothing depended on the two-worker default. Worker count, execution partitions and durable partition layout are three different numbers: this must not change the recorded UUID splitters or the durable partition count, which are format parameters rather than execution choices.
• Once merged, this unblocks observe(storage): nothing measures the serial fraction of ingest, and #1387 budgets against it #1462 — a serial-fraction instrument reports the facade rather than the engine while the default pins two workers.

[DecisionNerd]

Do not merge yet: this change makes the S18 rung time out

A/B on one host, quiet, same harness, same certify and generator binaries. The only difference is whether gf carries 1287a2f8.

gf build	direct validate (no cgroup)	S18 rung under benchexec (16 cores, 4 GiB memory cap)
pinned two workers (origin/main)	35.90 s	~55 s, all ten phases passed
with this change (Automatic)	35.12 s	killed at 420 s

Reproduced twice. The first observation was a --maximum-scale 20 run that sat at 100% CPU for 17 minutes on S18 before I stopped it; the second was a dedicated --rung S18 run that hit a 420 s timeout (exit=124).

What it is not

It is not a slowdown of the work itself. Driven directly, outside benchexec, the whole import sequence is unchanged:

begin 0.10s  register-nodes 0.10s  register-edges 0.40s  validate 35.22s  commit 2.00s

versus 35.90 s for validate on the pinned build. I checked this first, because my initial reading was "this change is a severe regression" and the direct measurement did not support it. It only appears under the ladder.

Likely mechanism, stated as a hypothesis rather than a result

The ladder runs inside a cgroup with cores: 16 and memory_bytes: 4294967296. This change takes tokio_worker_threads, target_partitions, io_concurrency and compute_threads from a fixed 2 to a machine-derived value — about 8 on this host. More concurrent workers means more simultaneous buffers, sort scratch and cache windows against a hard 4 GiB ceiling that the unconstrained direct run never touches.

I have not confirmed that memory is the binding resource — the killed runs left no evidence behind. It could also be thread oversubscription interacting with the cgroup's CPU controller. The reproduction is solid; the explanation is not.

Why CI is green

Nothing in the crate suites, the harness suites, clippy or make pre-push-fast runs an import at S18 scale inside a 4 GiB cgroup. The change is correct by every gate we have, and it still stops the ladder.

This is the third fail-closed surface this work has found that only a real rung exercises, after the certify validator (#1462) and the evidence schema. A green PR touching concurrency defaults should be rung-tested before it merges, and that is now cheap: --rung S18 is about a minute on a quiet host.

Suggested next step

Before merging, re-run --rung S18 with this commit and capture the peak RSS, or raise the rung's memory limit temporarily to see whether it completes. If memory is the binding resource, this change needs a memory-aware bound on the derived worker count rather than a plain logical_cpus() derivation — which is also what #1387's own 4 GiB budget decision implies, since it says to budget per shard rather than treat 4 GiB as a target.

The change is still right in principle: a two-worker facade cannot show multi-core behaviour whatever the engine does (#1462 depends on this landing). It needs a bound, not reverting.

[DecisionNerd]

Diagnosed: this exposes a livelock, not a resource limit

Correcting my previous comment. I hypothesised the 4 GiB cgroup cap was the binding resource. It is not. Caught the hung S18 rung in the act:

VmRSS: 183 MB                      <- nowhere near the 4 GiB cap
Threads: 17
voluntary_ctxt_switches: 602       <- in 100 seconds
read_bytes: 242 MB  write_bytes: 510 MB

    TID   %CPU STAT WCHAN
2166093    0.3 SNl  futex_do_wait   <- main thread, waiting
2166096..  0.0 SNl  futex_do_wait   <- 15 more, all waiting
2166106   99.8 RNl  -               <- ONE thread, running, no wchan

Sampled utime + stime ten seconds apart: exactly 1000 ticks, precisely one full core, continuously.

One thread spins indefinitely while all sixteen others block on futexes. That is a livelock, not a deadlock — a deadlock parks every thread at 0% CPU. And it is not memory: RSS is 183 MB against a 4096 MB ceiling.

It is non-deterministic

Driven directly outside benchexec with the same derived worker count, the identical import completes in 35.12 s. Under benchexec it hangs. Same binary, same data, same host. So this is timing-dependent — a race that the direct run wins and the containerised run loses, not a property of the worker count alone.

That also means the direct measurement I used to exonerate this change was luck, and a green CI run proves nothing here. A concurrency default cannot be validated by a single passing execution.

What this means for the change

The change is not wrong. It raises tokio_worker_threads, target_partitions, io_concurrency and compute_threads from a fixed 2 to about 8, and that exposes a pre-existing race in the ingest path that a two-worker facade has been hiding.

Two consequences worth separating:

1. This PR should not merge until the race is found. Landing it turns an intermittent hang loose on every default-configured ingest, and the ladder is where it will show up first.
2. The race is the more important finding. It is in code that runs today; the facade merely makes it improbable. epic(storage): stop maintaining a hand-rolled dataflow engine; reuse Arrow/DataFusion where determinism and durability allow #1456 argues the hand-rolled dataflow machinery is where the defects live, and this is that argument with a reproduction attached.

Reproducing it

--rung S18 under benchexec, gf built with 1287a2f8

Hung in 2 of 2 attempts (17 minutes before I stopped the first; 420 s timeout on the second; a third reproduced within 100 s and was inspected above). The pinned build passes the same rung in ~55 s, and S18/S19/S20 all pass on it.

The spinning thread's stack would name the loop. gdb -p <pid> -batch -ex "thread apply all bt" on a live hang is the next step, and the hang reproduces inside two minutes, so it is cheap to catch.

[DecisionNerd]

Correcting myself again: it is not a livelock. It is pathological parquet re-decompression.

I called this a livelock because one thread sat at 100% CPU while sixteen blocked on futexes. A profile of the running thread shows it is doing real work, not spinning on a lock. perf record on the thread in R state, 12 s, 2377 samples:

45.92%  ZSTD_decompressSequences_bmi2      tokio-rt-worker
15.12%  core::hash::BuildHasher::hash_one
 6.34%  core::iter::Map::fold
 5.41%  core::hash::sip::Hasher::write
 1.72%  core::slice::sort::unstable::quicksort
 1.59%  ZSTD_buildFSETable_body
 1.14%  arrow_array::BooleanArray::from_trusted_len_iter
 0.75%  parquet::encodings::rle::RleDecoder::get_batch_with_dict
 0.25%  parquet::column::reader::GenericColumnReader::skip_records
 0.17%  parquet::arrow::ParquetRecordBatchReader::next
 0.13%  parquet::arrow::array_reader::builder::ArrayReaderBuilder::build_reader

Zstd decompression of parquet, plus SipHash hashing, on a tokio worker — continuously, for minutes, where the pinned build completes the whole S18 rung in ~55 s. The other threads are blocked because everything is serialised behind this one.

Hypothesis, and why I think it, stated as a hypothesis

ArrayReaderBuilder::build_reader and GenericColumnReader::skip_records are both in the profile. Building a reader is setup, and skip_records is seeking; neither belongs in the steady state of a single linear scan. Their presence alongside 46% zstd decompression is the signature of readers being constructed repeatedly and each skipping forward through the file, re-decompressing to reach its offset — linear work per batch, quadratic overall.

Raising target_partitions from 2 to 8 would multiply exactly that. It is consistent with every observation: one worker saturated, the rest idle, 242 MB read but 510 MB written, and a 20x+ blowup that does not appear when the same binary runs the same import outside the container.

I cannot prove causality from this profile. The release build has no frame pointers, so the call graph is too shallow to name the caller. What is established: the thread is doing parquet decode work, not waiting, and the volume is pathological.

Corrections to my earlier comments on this PR

Three, and they are worth stating plainly because each was confidently wrong:

1. "Severe regression" — the direct measurement showed no difference (35.12 s vs 35.90 s).
2. "The 4 GiB cgroup cap is the binding resource" — RSS was 183 MB. Not memory.
3. "Livelock" — the thread is running real code, not spinning on a futex.

What has held throughout: the S18 rung hangs with this change and passes without it, reproduced 4 of 4 times, and S18/S19/S20 all pass on the pinned build.

Suggested next step

Rebuild with debug = true in the release profile (or force-frame-pointers), reproduce, and re-profile. The call graph will then name the caller of build_reader, which is where the repeated scan originates. The hang reproduces inside two minutes, so this is a short loop.

The change should still land eventually — a two-worker facade cannot show multi-core behaviour, and #1462 depends on it. It should land after whatever this is, because the defect it exposes is in code that runs today.

[DecisionNerd]

Located: it is the one-hop query, not ingest

A frame-pointer build resolves the call graph completely. This is the whole of the hot path, 2410 samples over 12 s on the one running thread:

<graphforge_exec::demand::RssProbeStream as Stream>::poll_next
  graphforge_exec::expand_exec::expand_single_hop_chunk
    |--43.63%-- graphforge_storage::catalog::filtered_parquet::read_edges_filtered_projected_from_inventory
    |             read_required_edge_filtered
    |               read_parquet_filtered_u64_attempt
    |                 |--29.91%-- StructArrayReader::skip_records
    |                 |             |--15.88%-- array_reader::skip_records -> ZSTDCodec::decompress
    |                 |              --13.95%-- array_reader::skip_records -> ZSTD decompress
    |                  --13.72%-- ArrowReaderBuilder::build -> ZSTD decompress
     --1.93%--  read_nodes_filtered_projected_observed

expand_single_hop_chunk is a query, not ingest. The S18 rung runs ten phases and query is one of them; that is where it hangs.

This explains the observation I could not reconcile

I reported that driving the import directly showed no difference — 35.12 s with this change against 35.90 s without — and used that to argue the change was not a regression. That measurement ran begin, register-parquet, validate and commit. It never ran a query. The rung does. So the direct comparison was measuring a path this defect does not touch, and my conclusion from it was worthless.

What the defect is

read_parquet_filtered_u64_attempt spends 43.6% of the thread in two places that should not be hot:

• skip_records (29.9%), each call decompressing zstd to seek forward.
• ArrowReaderBuilder::build (13.7%), also decompressing — building a reader is setup, and setup is not a steady-state cost.

That is the signature of readers being constructed repeatedly and each seeking forward through compressed data. Raising target_partitions from 2 to 8 multiplies it, which is why the pinned build completes the rung in ~55 s and this one does not finish in 400 s.

Why this matters beyond this PR

The defect is in code that runs today. The two-worker default keeps the multiplier small enough to hide it. Two open issues are already circling it without naming it:

• perf(query): persist the adjacency CSR at publish instead of rebuilding it in every process #1446 — the adjacency CSR is rebuilt per process, ~16 s of CPU at S20 on a hop query.
• observe(storage): read_path_scan attributes 579 KB of a 6.4 GB hop query; the adjacency rebuild bypasses the counters #1449 — read_path_scan attributes 579 KB of a hop query that costs 6.4 GB of reads, because the rebuild bypasses the counters.

This profile is the same query path, and it says the cost is repeated seeking and reader construction over zstd-compressed parquet. A filtered read that decompresses in order to skip is doing the decompression twice: once to find the rows, once to read them.

Status of this PR

Still should not merge as it stands, but the reason has changed: it is not an ingest regression, it is a query-path defect that this change amplifies. Fixing the query path is the prerequisite, and it is worth doing regardless of this PR, since it is on the critical path for #1388 as well.

Reproduction: --rung S18 under benchexec with gf built from 1287a2f8. Hung 5 of 5 attempts; the frame-pointer build reproduces within 110 s and profiles cleanly.

[DecisionNerd]

Tested: #1453 removes the hang that blocks #1466

I posted this as a hypothesis. It now has a measurement.

build	S18 rung under benchexec
#1466 alone	hung, 5 of 5 attempts — >400 s, one thread spinning in expand_single_hop_chunk
#1466 + #1453	work completes in 37.6 s

37.6 s is ordinary S18 territory; the hang was unbounded. Taking the hop query off filtered parquet removes the cost that #1466's target_partitions increase was multiplying, exactly as the profile predicted.

Suggested merge order: #1453 before #1466.

Two honest caveats

The combined run does not pass. It completes the work and then fails evidence_invalid at ingest. The receipt key sets are identical to a passing run — no missing or extra fields — so it is a value-level rejection rather than a shape change. I have not chased it.

And it may be my mess rather than #1453's. This was a local merge across three worktrees carrying my own in-flight fixes, and I tripped over that twice while testing: first a certify/gf binary mismatch, then finding that perf/1464-chain-split forked from observe/1462-wire-ingest-phases before I committed the certify validator fix on it. Neither was a defect in #1453.

The timing result is robust to that — 37.6 s versus >400 s is not a subtle difference and does not depend on which certify binary validated it. The evidence_invalid is not robust to it, and should be reproduced from clean branches before anyone treats it as a property of #1453.

Reproduction

# hangs, 5/5
--rung S18, gf built from 1287a2f8

# completes in 37.6s
--rung S18, gf built from 1287a2f8 merged with origin/fix/adjacency-csr-persist

Both on a quiet host, benchexec, same generator and data.