Intra-deploy par-operator parallelism does not deliver speedup — investigation

[elmiringos]

What did you expect to see?

The implementation already looks like it's aiming for parallel execution of par-branches:

• The reducer spawns a separate tokio task per branch (rholang/src/rust/interpreter/reduce.rs:259).
• The runtime is multi-threaded with one worker per CPU core (node/src/main.rs:52, TOKIO_WORKER_THREADS=32 on a 32-core pod — verified at runtime).

Given that setup, a deploy with N par-branches doing identical work would reasonably be expected to scale across cores:

par-branches	per-branch work	expected execution time	expected CPU peak
1	~2.5 s on one core	~2.5 s	~1 core
4	~2.5 s each	~2.5 s	~4 cores
32	~2.5 s each	~2.5 s (slowest branch wins)	toward 32 cores (saturated)

As Kevin clarified, | is declarative — by the language spec it doesn't require concurrent execution, and the implementation is free to choose any strategy. But the runtime is already configured for parallelism end-to-end, so a 32-branch deploy on a 32-core pod should at least attempt to use those cores.

What we measured doesn't match this — see below.

What did you see instead?

Propose time grows linearly with total work, with super-linear overhead at high N. CPU peak stays at 1.5–4.8 cores out of 32 regardless of N. Replay times grow much faster than propose and exceed practical timeouts above N ≥ 8.

Run rholang-par-08-05-26-091918, profile max (32 CPU pod limit):

forks	total iterations	propose ms	s/fork (propose/N/1000)	CPU peak	CPU % limit	replay PHASE	replay/propose
1	5 000	2 560	2.560	n/a	n/a	17 267 ms	6.7×
2	10 000	3 897	1.948	n/a	n/a	233 521 ms	60×
4	20 000	8 472	2.118	n/a	n/a	678 996 ms	80×
8	40 000	26 467	3.308	3 482m	11 %	timed out 900s	>34×
16	80 000	92 816	5.801	3 528m	11 %	timed out 900s	(~5h est)
32	160 000	438 824	13.713	4 829m	15 %	timed out 900s	(~days est)

forks=1 → forks=32 multiplies total work by exactly 32×, but multiplies propose wall-clock by 171×. A truly parallel reducer would have left wall-clock flat (~2.6 s); a perfectly sequential one would multiply by exactly 32× (=~82 s).

CPU "n/a" rows = propose window was shorter than the 15s kubelet sampling tick; CPU was used, just not measured.

Steps to reproduce the bug

1. The smart contract. A single signed deploy whose rholang body is generated programmatically — N par-composed busy!(...) invocations joined by an N-receive for. Each branch performs an identical 5 000-round recursive countdown through rspace. Concrete expansion for forks=4:

new done, stdout(`rho:io:stdout`) in {
  new busy in {
    contract busy(@iters, @id, done) = {
      new loop in {
        contract loop(@n) = {
          if (n <= 0) { done!(id) } else { loop!(n - 1) }
        } |
        loop!(iters)
      }
    } |
    busy!(5000, 0, *done) | busy!(5000, 1, *done) | busy!(5000, 2, *done) | busy!(5000, 3, *done)
  } |
  for (@_ <- done; @_ <- done; @_ <- done; @_ <- done) {
    stdout!(("ParTerm done", 4))
  }
}

Each branch uses its own private loop channel (created via new loop in {…} inside contract busy), so the only shared rspace state across branches is the implicit tuplespace itself.

2. Sweep and measurement loop. For each N ∈ {1, 2, 4, 8, 16, 32} we provision a fresh 3-validator chain (one proposer + two followers, single shard, max-user-deploys-per-block = 1, heartbeat disabled), submit one signed deploy with the contract above, call propose on the proposer, wait for the block to advance on the proposer, then wait for the follower to replay it. Teardown the namespace, then next N. Total runtime ≈ 90 minutes for the full sweep on a 32-core pod.

3. What we recorded per step. Numbers come from two independent sources, both sampled live during each step:

• Propose wall-clock — measured client-side as time.Since(proposeStart) around the propose RPC against the proposer. Cross-checked against the node-side log line Propose timing: mode=sync, propose_core_ms=…, total_ms=… (within ~200 ms RPC overhead).
• CPU peak on the proposer pod — usageNanoCores from the kubelet's /stats/summary API, polled every 15 s; we keep the max sample observed during the propose window. Converted to millicores (/1_000_000).
• Replay PHASE / EVAL on the follower — Prometheus histograms block.replay.phase.user-deploys.time and block.replay.deploy.evaluate.time scraped from :40403/metrics before and after each step.
• Contract completion confirmation — ("ParTerm done", N) appears in validator1's stdout log only after the N-receive for fires, i.e. after all N branches have signalled completion. Verified present for all 6 steps.

4. How we concluded what we concluded. Verdict is derived from propose wall-clock scaling, not replay PHASE (replay PHASE includes rig-replay overhead that is orthogonal to reducer concurrency). If the reducer were honouring | as concurrent execution we would see propose wall-clock stay roughly flat as N grows and CPU peak rise toward 32 cores. Instead propose wall-clock grows ~linearly with N (171× growth at N = 32 for 32× more work) and CPU peak never exceeds 4.8 of 32 cores — across all rows of the sweep, in a consistent pattern.

What version of F1R3FLY Node are you using?

rust-node:0.4.14

What is your environment?

Node:

• Tokio multi-thread runtime, TOKIO_WORKER_THREADS=32 (verified at runtime — env override in pkg/manifest/statefulset.go:182)
• Casper config: heartbeat disabled (F1R3_HEARTBEAT_ENABLED=false), max-user-deploys-per-block = 1, per-deploy phlo limit 100_000_000
• 3 validators (one proposer + two followers) on a single shard, genesis-only, no dynamic bonding
• Bootstrap + 3 validators + 1 observer, all in one k3s namespace per fork-step
• Replay measured on validator2 (follower); propose measured on validator1

Host:

• k3s 1.x, containerd, single-node cluster
• Validator pod resource envelope (max profile):
  • limits.cpu: 32, requests.cpu: 8
  • limits.memory: 64Gi, requests.memory: 16Gi
  • PVC: 800 Gi (local-path)
  • cgroup cpu.max: 3200000 100000 (32-core CFS quota, verified)

[linear]

F1R-157

[spreston8]

This issue has been migrated to F1R3FLY-io/f1r3node-rust#50 as part of the deprecation of this repository. Please continue tracking the work there.