IAVL v2 benchmarks from osmosis mainnet testing

[kocubinski]

I briefly shared these benchmarks from osmosis mainnet testing of iavl v2 in an SDK team call this morning. There was some interest in how they were collected, and a request to provide some shareable links or resources for peer review.

Methodology

Versions of code used in this benchmark:

• iavl v2: afbb627
• osmosis fork of cosmos sdk with iavl v2 patched in: cosmos/cosmos-sdk@ec67f4e
• osmosis patched with a --use-iavl-v2 flag: 01builders/osmosis@4849910

Performance of 2 osmosis binaries were compared (one with iavl v0, the other iavl v2) by syncing from block 12,252,638 to block 12,272,529. The state starting point is the snapshot osmosis-1-pruned.20231108.0910.tar.lz4, obtained from quicksync.io around Nov 8 2023.

Prometheus time series metrics and go CPU profiles were collected. A local prometheus instance scraped the remote node running the osmosis binary.

Findings

(TL;DR)

IAVL v2 shows the following performance improvements over v0:

• mean commit time is 10x faster
• mean get time is 5x faster
• boosts block throughput rate by ~2.5x
• epoch block time is roughly halved (mostly due to faster commits)

Prometheus

IAVL v2 metrics showing commit rate, commit, get, set & delete latency:

v2 grafana dashboard snapshot

IAVL v0 metrics showing commit rate, commit, get, set & delete latency:

v0 grafana dashboard snapshot

CPU Profile

From these flame graphs we can see that I/O time is reduced, osmosis does not appear i/o blocked from iavl with v2, other areas are consuming the majority of computation. In particular we notice the leveldb compactions from CometBFT's blockstore, wasmvm CGO calls, and (in epoch blocks) math computations.

IAVL v2:

CPU Profile: bench_aws_cpuprofile_iavlv2_latest_12252638-12272529.out.gz

IAVL v0:

CPU profile: bench_iavlv0_12252638-12272529.out.gz

Reflections

• in the patched SDK, each store key is committed concurrently to each other, but not to the state machine.
• async commit (mentioned in [Epic]: IAVL v2 implementation & QA #851) would further reduce commit latency.
• pruning is done synchronously in v0, the v2 design (async and more efficient) for pruning is in progress and should not impact online process time.
• taking a snapshot (not shown here) decreases v0 throughput to 0.5 blocks/s, so many node operators turn it off. SQLite is multi reader, and so long as the disk and cpu are below their performance ceiling (for osmosis disk is) snapshotting should not slow block speed.
• store V2's SS system is expected to boost read throughput (an approximation of the v0 fast node system is used here)
• we intend to try a different integration next, namely sei, to show that for an application which is more strictly I/O bound the performance benefits from decreased commit/get latency will flow upwards more directly to block processing speed.

[ValarDragon]

Impressive speedups! This is amazing!

Thank you so much for including the pprof's btw, its helped a lot for speeding up / investigating the code!

Though it is a bit unclear to me why we can conclude that Commit is not a bottleneck to the state machine, until async commit lands. Seems to be 900s out of the 2 hour CPU profile IAVL v2 benchmark (which counts time multiple times for each thread doing compute AFAIU). (900s looking at the cacheKV write process, and the IAVL commit process) This is 12% of the profile time!

Also a lot of the CPU time taken from the main Osmosis state machine thread seems very eliminatable / silly stuff! Got a few PR's in that should reduce the 2800s -> 2400s (one requires a state break :( ). The CGO issue for WASM is harder to eliminate though.