Performance regression on the chain tip

[mriccobene]

Many tests (sync-from-scratch, tip-tracking) are failing on the main branch due to poor Erigon performance on the chain tip. Usually, Erigon stays in sync 99/100% of the time. But currently, on many tests, the percentage is below 75%. Also, there are performance warnings in the logs.

See for example the last sync from scratch run

[VBulikov]

mriccobene added Imp1 as Importance

[yperbasis]

Analysis (May 3 mainnet run, 67% in-sync)

Symptom pattern — 19 in-sync windows averaging ~4.5 min each, separated by ~1 min out-of-sync gaps. 48 treating forkChoiceUpdated as asynchronous events during the tip-tracking phase (446 FCUs total). Forkchoice timings sit at flush=150–300ms, commit=150–300ms in steady state but spike to flush=2s commit=2s (peaks flush=9s commit=4s) every 2–4 min.

Mechanism — FcuBackgroundCommit defaults to false (node/ethconfig/config.go:116), so the FCU's flush+commit runs in the foreground inside runForkchoiceFlushCommit. When a Retire Blocks → collate-build → state merge burst contends for disk IO, that fsync chain blows out to seconds; Caplin times out with ExecutionStatusBusy and that's the "out of sync" gap. Cross-referencing the log, the spike sequence is always Retire Blocks (5–7s) → collate-build → state merge done → slow FCU. holding state collation at block snapshot boundary printed 381 times. temp/ grew 3 GB, fd count climbed 16→3206.

Regression timeline — tip-tracking was last green on 2026-03-15 (b129b92a94) and has failed every weekly run since 2026-03-22 (ea6a21dc3a). So the root commit is in that 1-week window.

Top candidates:

• execmodule: extract PipelineExecutor, internalize ForkValidator #19961 / 3248639b5b (Mar 22) — execmodule: extract PipelineExecutor, internalize ForkValidator. Large FCU refactor; runForkchoiceFlushCommit now chains 3 separate MDBX transactions per FCU.
• commitment: enable warmup cache for all paths + add cache miss counters #19952 / 9a77d9e51b (Mar 20) — commitment: enable warmup cache for all paths. Flipped EnableWarmupCache(true) for the isApplyingBlocks path immediately before the first failure.

Later cherry-picks likely compound but aren't the root:

• warmuper: blocking and more  #20819 / bfc30afb89 (Apr 28) — warmuper: made WarmKey blocking instead of drop-on-full.
• enforce block-snapshots cap inside aggregator collation #20900 / 2e50c368f1 (Apr 29) — enforce block-snapshots cap inside aggregator collation.

Current status

Three bisection probes dispatched:

Probe	Commit	Workflow	Run
Suspect (Apr 28)	bfc30afb89	Tip tracking	https://github.com/erigontech/erigon/actions/runs/25674778861
Last-green (Mar 15)	b129b92a94	Tip tracking	https://github.com/erigontech/erigon/actions/runs/25674975157
Suspect cross-check	bfc30afb89	Sync from scratch	https://github.com/erigontech/erigon/actions/runs/25674976642

The two tip-tracking probes serialize on the tip-tracking self-hosted runner; expected wall-clock ~24h for both. Sync-from-scratch runs on a different pool. I'll bisect the Mar 15…Apr 28 window once these come back.

[mriccobene]

The "tip-tracking & migration" test is fragile. It is more convenient to use sync-from-scratch tests like:

• sync-from-scratch (it uses archive mode)
• sync-from-scratch minimal node

It could also be beneficial to compare the main branch with the release branch, where the problem either does not exist or is less impactful.

[yperbasis]

Important: tip-tracking on main is blocked by a testbed infra issue, not by tip performance

Update from running bisection probes — the QA - Tip tracking & migration workflow on main is not actually exercising tip behavior right now. Both my dispatched probes (commits bfc30afb89 and b129b92a94) failed in the stabilization phase in ~42 min, never reaching the part of the workflow that runs the candidate's binary.

The stabilization step runs the reference Erigon binary at /opt/erigon-versions/reference-version/erigon against /opt/erigon-versions/reference-version/datadir to bring the testbed up to head before testing the candidate. That reference binary deterministically fails at mainnet block 24785118:

[WARN] [4/6 Execution] Execution failed block=24785118 txNum=3414988061
  err="invalid block, txnIdx=114, gas used by execution: 20855803,
       in header: 21032903"

It then retries in a loop for ~30 min, balloons to ~120 GB RSS, and gets OOM-killed (exit code: -9). The candidate binary built on our branch is never invoked.

This is not new — the same failure killed last week's scheduled main tip-tracking run on May 10 in 45m23s, exact same step. So the tip-tracking failures on main referenced in this issue are not measuring tip performance — they're being blocked before the test starts.

release/3.4 tip-tracking is healthy: the workflow's reference-dir logic resolves release/X.Y branches to /opt/erigon-versions/reference-version-X.(Y-1)/datadir (so release/3.4 uses reference-version-3.3), and that path works correctly — recent runs pass consistently.

Implication for this issue

The QA report conflates two distinct failures:

1. Sync-from-scratch — genuine performance regression in our code (the 67% in-sync metric in the May 3 run is real and is what the analysis above addresses).
2. Tip-tracking on main — blocked by a broken reference binary on the QA runner, not by tip performance.

I'll continue bisection using sync-from-scratch (chiado already passed at bfc30afb89; mainnet probes are in flight). Tip-tracking on main will need the reference binary at /opt/erigon-versions/reference-version/ rebuilt against the current mainnet state before it can produce a useful signal. /cc QA team.

[yperbasis]

Local profiling on mainnet + head-to-head with release/3.4

Ran the patched yperbasis/issue21008 build on a mainnet minimal node and compared steady-state tip behaviour against release/3.4 on the same chaindata, same NVMe, same hardware. (To get r34 to boot against a main-touched datadir, opened #21282 to restore JSON wire-format compatibility for chain.Config.ChainID / TerminalTotalDifficulty.)

Steady-state FCU latency at live mainnet tip

Both runs at live tip, neither overlapping a snapshot retire/collate/merge burst. Disk idle in both windows.

stat	main (53 samples)	release/3.4 (39 samples)	Δ
min	144 ms	53 ms	−63 %
p50	229 ms	149 ms	−35 %
p90	319 ms	210 ms	−34 %
p99	384 ms	225 ms	−41 %
mean	239 ms	150 ms	−37 %

main's median FCU is ~80 ms slower than 3.4's, with a noticeably wider tail. Even without observing a multi-second burst spike (the dramatic events described in the original report), the baseline per-FCU latency moved up by ~35–40 %.

Mechanism — confirmed by the FCU goroutine stack

Compared runForkchoiceCommit on r34 vs runForkchoiceFlushCommit on main, and traced what each enters from updateForkChoice. Two structurally different shapes:

release/3.4 — FCU body does one flush+commit only

updateForkChoice(...)
└── writeForkChoiceHashes / TruncateCanonicalChain
└── runForkchoiceCommit
    ├── sd.Flush(tx)
    └── tx.Commit()            // single MDBX commit = single fsync

TxLookup / Senders / BlockHashes / Finish run in a separate background StageLoop (execution/stagedsync/stageloop/stageloop.go:62) on its own cadence — decoupled from the FCU response.

main — FCU body routes through the full stagedsync pipeline

updateForkChoice(...)
└── pipelineExecutor.RunLoop                       // forkchoice.go:505
    ├── sync.Run(sd, tx, ...)                       // executor.go RunLoop body
    │   ├── BlockHashes
    │   ├── Senders
    │   ├── Execution
    │   ├── TxLookup            ← writes txhash→block index per FCU
    │   └── Finish
    └── sync.RunPrune(...)
└── runForkchoiceFlushCommit
    ├── sd.Flush(rwTx)
    └── rwTx.Commit()                                // MDBX commit = fsync

Caught the FCU goroutine inside SpawnTxLookup → ETL.Transform → tx.Hash() during a profile snapshot — confirming the lookup-index write pass really does run per-FCU on main.

Why it costs more

5-min fgprof at tip showed 88 % of the FCU commit wall-time is parked inside mdbx_txn_commit_ex (4.42 s wall vs 0.33 s CPU over 25 FCUs). The commit isn't CPU-bound, it's fsync-bound. main's commit has more dirty pages to durably write because TxLookup / Senders ran into the same tx before the commit. r34's commit has only SharedDomains.Flush output.

Burst amplification

Under quiet disk this just costs +80 ms median. When a retire/collate/merge burst hits the same NVMe (#20900 enforcing the block-snapshots cap, plus the normal background merge writes), per-FCU fsync stretches into seconds. Pre-#19961 the StageLoop ran independently of FCU and a burst stretched the StageLoop's cadence without blocking the FCU response. Post-#19961, every per-slot FCU response is downstream of TxLookup's MDBX writes, so a burst-stalled MDBX directly stalls the FCU and Caplin times out → treating forkChoiceUpdated as asynchronous / ExecutionStatusBusy → the out-of-sync windows you originally documented.

Likely root cause

#19961 (3248639b5b, Mar 21) — "execmodule: extract PipelineExecutor, internalize ForkValidator". The PR description says "no functional changes". Structurally true — the call graph was just reorganised. But moving TxLookup / Senders / Finish from the background StageLoop into the synchronous FCU path via PipelineExecutor.RunLoop is a behaviour change: the work happens at the same total rate, but now on the critical path of every FCU response.

Matches the original timeline: tip-tracking last green b129b92a94 (Mar 15), failed every run since ea6a21dc3a (Mar 22) — #19961 lands inside that window.

Raw data + profiles

Captured locally during the session (CPU/fgprof/heap/goroutine/block/mutex for both main and r34, plus FCU-timing logs). Happy to attach the pprof files if useful for further inspection.

Suggested next steps

1. Move TxLookup / Senders / Finish out of the FCU critical path back to a background loop equivalent to release/3.4's StageLoop. Keeps PR execmodule: extract PipelineExecutor, internalize ForkValidator #19961's nice consolidation of the executor type but undoes the synchronous-per-FCU staging that the rename quietly introduced.

2. Alternatively, try --fcu.background.commit=true (the flag already exists at node/ethconfig/config.go:116; gated off because rawdb + Coherent cache need wiring). That decouples the FCU response from the MDBX fsync, masking both the +80 ms steady-state cost and the burst spikes.

3. The background-merge contention story is real but secondary — even with the disk idle, the per-FCU baseline regressed. Throttling merges (db/state: add optional throttle to MergeLoop to reduce disk I/O pressure #20486) helps the spike side but won't recover the +80 ms baseline.

4. The bisection probes you have running on sync-from-scratch will independently confirm or rule out execmodule: extract PipelineExecutor, internalize ForkValidator #19961 — looking forward to those results.

[yperbasis]

Tip-spike captures from the last 9 hours — refined picture

Caught 4 spike events at live mainnet tip (one prune, three aggregations) while leaving the trigger script running. None reproduced the multi-second `flush=Xs commit=Ys` pattern from the original QA report, but they all hit the same code path and the data lets us bound the magnitude on a fast NVMe.

Burst events and their FCU impact

time	event	duration	concurrent FCU commits
23:55:39	`Background Prune`	1.0 s	next FCU commit=304ms (baseline ~220ms)
02:47:49	`[snapshots] aggregated step=9027`	11.32 s	291ms, 321ms, 158ms
03:16:16	`Background Prune`	1.0 s	not captured in detail
06:17:12	`[snapshots] aggregated step=9028`	10.61 s	peaks 479ms, 569ms, 467ms; sustained 300-500ms for ~2 min

So on this hardware (NVMe with plenty of bandwidth) the FCU commit only elevates ~2-3× over baseline during a single-step aggregation, not the multi-second `flush=9s commit=4s` the May 3 QA report described. Peak observed: 569ms.

Where the merge work goes — confirmed CPU-bound, not disk-bound

CPU profile during the 11.32-s aggregation (06:17, similar profile to the others):

cum %	function
82 %	`AggregatorRoTx.mergeFiles → DomainRoTx.mergeFiles`
62 %	`DomainRoTx.commitmentValTransformDomain → BranchData.ReplacePlainKeys`
52 %	`findShortenedKey → BtIndex.Get → BpsTree.Get`

iostat during the burst: 145 MB/s wMB/s, 4.5 % disk util. The disk is not saturated. The merge is CPU-bound in `commitmentValTransformDomain` — re-pointing every plain-key reference in the new merged commitment branch to the offsets in the merged storage/account files via per-key B-tree searches.

So the dominant per-burst cost on our hardware is CPU spent in `findShortenedKey → BtIndex.Get`, not disk fsync amplification. fsync amplification is real but modest at ~+100 ms because the disk has headroom; on the QA testbed (slower disk), the same merge produces fewer MB/s of headroom and fsync stretches harder, which matches the multi-second peaks they reported.

Practical implication

The "FCU foreground commit" framing (from the earlier analysis on this issue) is correct as a mechanism — the FCU commit fsyncs while merge writes are in flight — but its magnitude on any specific hardware is determined by how saturated that hardware's write queue gets. On a hardware-rich workstation, it's ~+100ms. On the QA testbed, it's multi-second.

The CPU side of `commitmentValTransformDomain` is the more universal lever: every box runs the same code on the same merge ranges, so a CPU optimization there cuts the burst duration everywhere. If the burst is shorter, the FCU has a smaller window in which to overlap.

Two complementary fix surfaces:

• CPU: cache the merged-file `BtIndex.Get` calls in `findShortenedKey` — same merged file is searched for every branch's plain-key references, so identical full keys recur (hot contracts: USDC, Uniswap routers, etc.) and would hit the cache. Trying this now.
• Latency-isolation: `FcuBackgroundCommit=true` (already exists, gated on `node/ethconfig/config.go:116` work). Removes FCU's exposure to fsync queue entirely on any hardware.

All raw profile data (CPU/fgprof/goroutine/iostat/heap snapshots per spike) saved locally under `tmp/profiles/spike-*`.

[AskAlexSharov]

commitmentValTransformDomain - this func used only for Commitment.Domain references (Artem working on releasing files to disable it)

[yperbasis]

Bisection complete: regression introduced by #20035

The mainnet tip performance regression was introduced by 082697d2a0 "caplin: unified Engine API client for standalone mode" (#20035), merged 2026-03-25.

Evidence

Bisection narrowed to adjacent commits on the same day:

Commit	Date (UTC)	Mainnet in-sync %	Source
19f44b15cd (parent)	2026-03-25 21:28	100% ✓	run 26167188026
082697d2a0 (#20035)	2026-03-25 22:38	3% ✗	run 26167198192

Parent is a 45-line addition to cmd/integration (zero runtime impact); child is a 3698-LOC, 35-file change. The regression appears at exactly this commit.

Bisection path with all data points (QA - Sync from scratch (minimal node), mainnet):

Commit	Date	in-sync%	Run time
b129b92a94	Mar 15	100% ✓	3h08m
9dd5317623	Mar 18	100% ✓	4h01m
9a77d9e51b	Mar 20 23:26	100% ✓	4h47m
b772ea8f6a	Mar 21	100% ✓	—
3248639b5b	Mar 21 17:40	100% ✓	—
26e6f5bdb4	Mar 24	100% ✓	6h54m
6b7412525e	Mar 26 00:55	100% ✓	7h08m
19f44b15cd	Mar 25 21:28	100% ✓	7h26m
082697d2a0	Mar 25 22:38	3% ✗	6h44m
7a25711a03	Mar 26 13:40	2% ✗	6h35m
ec45be4827	Apr 1	3% ✗	5h35m
9f5504aabb	Apr 11	2% ✗	5h02m
bfc30afb89	Apr 28	66% ✗	3h07m

(The Apr 11 peak severity gradually mitigates by Apr 28 — some commit in 9f5504aabb..bfc30afb89 partially fixes the regression. Worth identifying but not the root cause.)

Why this commit is suspect

#20035's stated goal is to add a standalone-mode HTTP/JWT Engine API client for Caplin. It should not have affected embedded mode. But the diff also touches the embedded-mode fork choice path:

• cl/phase1/forkchoice/forkchoice.go (+25)
• cl/phase1/forkchoice/get_head.go (22 changed)
• cl/phase1/forkchoice/on_block.go (10 changed)
• cl/phase1/forkchoice/utils.go (31 changed)
• cl/phase1/stages/clstages.go (+70)
• cl/phase1/stages/forkchoice.go (8 changed)
• execution/engineapi/engine_server.go (16 changed)

The PR description even calls out: "Fork choice fixes: Caplin's GetHead() now returns the justified/finalized checkpoints needed by forkchoiceUpdated, fixing standalone mode FCU calls" — exactly the path that's slow in our day-1 analysis.

The symptom (slow flush=2s commit=2s Forkchoice timings every few minutes) is consistent with extra work or contention introduced into the embedded-mode FCU path by changes that were intended only for standalone mode.

Next

Investigating the diff for the specific embedded-mode side effect. Once root cause is identified, will propose a targeted fix or revert of the embedded-mode portion.

cc @mh0lt (PR #20035 author for context on the embedded-mode changes)