frame-benchmark: `commit_db()` and storage root recalculation costs leak into the measured benchmark time

[sigurpol]

The pallet_staking_async benchmarks show a ~75-115x regression in execution time (from ~40µs to
~3-5ms) for several extrinsics e.g. see here.

This is not a real runtime regression but rather a benchmarking artifact caused by the interaction between the genesis state and the benchmark setup.

The genesis configuration in genesis_config_presets.rs pre-populates a large number of stakers for testing purposes:

"staking": {
    "validatorCount": 600,
    "devStakers": Some((2_000, 25_000)),  // 2,000 validators + 25,000 nominators = 27,000 stakers
},

(similar for e.g. Westend AH with 1k validators and 25k nominators).

Many benchmarks call clear_validators_and_nominators() in their setup phase to ensure a clean state. While this happens in "setup" (before timing starts), the benchmark framework's commit_db() and storage root recalculation costs leak into the measured benchmark time when clearing 27,000 storage entries.

Affected Benchmarks

All benchmarks that call clear_validators_and_nominators() are affected:

Benchmark	Before	After	Change
force_apply_min_commission	42.8 µs	4,886 µs	+11,318%
rebond	64.4 µs	5,126 µs	+7,858%
chill	44.5 µs	5,043 µs	+11,232%
chill_other	46.1 µs	5,043 µs	+10,839%
unbond	64.0 µs	5,254 µs	+8,109%
bond_extra	91.4 µs	5,255 µs	+5,649%
reap_stash	60.9 µs	5,033 µs	+8,164%
force_unstake	61.1 µs	5,054 µs	+8,172%
withdraw_unbonded_kill	65.0 µs	5,156 µs	+7,832%
nominate	82.7 µs	5,107 µs	+6,076%
process_offence_queue	76.4 µs	4,951 µs	+6,381%

Tested approaches

Verification

Disable proof recording

• ❌ --disable-proof-recording alone - does not fix the issue

Genesis build none

• ✅ --genesis-builder none - fixes the issue, benchmarks return to µs range

Force a sleep at the end of commit_db

See #10802 (comment)

No luck, still ms

Force a dummy read at the end of commit_db

No luck, still ms

Force storage root recalculation at the end of commit_db

	fn commit_db(&mut self) {
		self.commit();
		let _ = self.storage_root(sp_runtime::StateVersion::V1);
	}

no luck, still ms

Force commit db at the end of clear_validators_and_nominators

if we just want to unlock staking very quickly, the easiest seems just adding

frame_benchmarking::benchmarking::commit_db();

at the end of the infamous clear_validators_and_nominators(). Then we can open a SDK issue and work in background to fix the real problem of expensive root calculation leaking into benchmark timing.

Tested and works just fine for e.g. force_apply_min_commission and process_offence_queue.

NOTE: note that in the benchmark framework we are calling already commit_db() when calling Recording.start() here which then executes this

Rework staking benchmarks to avoid massive bulk deletion if not needed

An example showing the validity of this approach here where we just remove a clear_validators_and_nominators() from one benchmark and that's enough to go down from ms to microsec).
Related issue: #10813 -> I believe we should both fix the problem in the framework and improve staking setup

Steps to reproduce

Steps to reproduce:

1. build WAH runtime

cargo build --release  -p asset-hub-westend-runtime --features try-runtime,runtime-benchmarks

2. run benchmark test of one of the affected extrinsics e.g.

frame-omni-bencher v1 benchmark pallet --runtime ./target/release/wbuild/asset-hub-westend-runtime/asset_hub_westend_
runtime.compact.compressed.wasm --pallet pallet_staking_async --extrinsic "force_apply_min_commission" --steps 50 --repeat 20

Expected result:

• execution time in few µs (simple exstrinsic with 2 storage read, 1 storage write!!!)
  Actual result:
• execution time in few ms

[kianenigma]

seems like storage operations, especially when doing bulk deletions like clear_prefix, return early while in the background they are already busy and consume io/cpu resources? @cheme does this ring any bell for you?

[sigurpol]

Test shows the following:

• commit_db() after clear at the end of the massive bulk deletion work (at the end of the infamous clear_validators_and_nominators()) meaning it doesn't leak into benchmark timing
• commit_db() only in recording.start() (default behavior we have in benchmark framework when calling Recording.start() here

  polkadot-sdk/substrate/frame/support/procedural/src/benchmark.rs

  Lines 1121 to 1122 in e000a5c

  	recording.start();
  	#post_call

  ->

  polkadot-sdk/substrate/frame/support/procedural/src/benchmark.rs

  Lines 777 to 779 in e000a5c

  	// Commit the externalities to the database, flushing the DB cache.
  	// This will enable worst case scenario for reading from the database.
  	#krate::benchmarking::commit_db();

  doesn't

I would imagine the overlay state to be the same when commit_db() runs (27k deletions + few inserts) in the two cases and the trie computation should be identical.

The difference is what happens between the large commit and the benchmark:

• With early commit: 27k deletions committed → setup → benchmark -> all good
• With late commit: setup → 27k deletions committed → benchmark -> massive bulk deletion leaks into benchmark results

Might be not related to trie operations, maybe some side effects due to host memory, allocator, caches, don't know what.

Inside instance() (lines 1102-1131):

  1108-1114: prepare params
  1117-1119: #setup_stmts      ← clear_validators_and_nominators() runs HERE
                                 (27k deletions marked in overlay)
  1120:      #pre_call          ← encode the extrinsic
  1121:      recording.start()  ← calls on_before_start which calls commit_db()
                                 (27k deletions processed HERE)
             TIMING STARTS
  1122:      #post_call         ← actual benchmark extrinsic executes
  1123:      recording.stop()
             TIMING STOPS

[sigurpol]

This works

				// benchmark setup code
				#(
					#setup_stmts
					#krate::benchmarking::commit_db();
				)*

this (the one I tried before) doesn't

  #(
      #setup_stmts
  )*
  #krate::benchmarking::commit_db();

which is still not clear to me exactly why but seems that committing after each setup statement isolate the expensive helps

[sigurpol]

An attempt to fix it -> #10802