Rocksdb version bump is causing issues with secondary access

[steviez]

Problem

#4210 bumped the rust-rocksdb version from 0.22.0 to 0.23.0 (which implicitly bumped the underlying rocksdb tag).

I observed an issue with the following setup:

• agave-validator is running with Primary access (validator ALWAYS has Primary access for R+W)
• agave-ledger-tool command is executed to access blockstore with Secondary access

The issue I'm observing is that Blockstore::open() is not returning in agave-ledger-tool. Something that takes 10-20 seconds on a MNB blockstore is taking multiple minutes before I kill it. I bisected and confirmed that the version bump is what introduced this regression.

Proposed Solution

1. For now, I am going to revert the version bump so that the tip of master doesn't have this bug
2. Debug what changed from 0.22.0 to 0.23.0 (including the delta in the actual rocksdb). The process is either hung or taking way too long, so building with debug symbols (cargo build --profile release-with-debug) and attaching gdb to agave-ledger-tool should be fairly illuminating

[cpubot]

Hey @steviez, here's what I found.

Running agave-ledger-tool with the updated version of rust-rocksdb against a ledger built on the previous version appears to run some kind of manifest rebuild. It appears that, as of RocksDb 9.0, it defaults to format_version=6 in BlockBasedTableOptions, which may be responsible for the rebuild. But there may also be some other internal structural change that necessitates this as well -- I don't know enough about the internals of RocksDb to know for sure.

I experienced the same long running Blockstore::open() the first time I ran the ledger tool with the new version. I ran this with strace to see if it was actually doing something or just hanging. What I found was a ton of newfstatat on non-existent files.

newfstatat(AT_FDCWD, "/home/sol/ledger/rocksdb/2286471.sst", 0x7ffe4c2344c8, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sol/ledger/rocksdb/2286473.sst", 0x7ffe4c2344c8, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sol/ledger/rocksdb/2286477.sst", 0x7ffe4c2344c8, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sol/ledger/rocksdb/2286474.sst", 0x7ffe4c2344c8, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sol/ledger/rocksdb/2286475.sst", ...

This makes me think it is some kind of manifest / index rebuild.

After this, I rebuilt and restarted the validator with the updated version of rust-rocksdb and re-ran agve-ledger-tool. I observed the same behavior where it iteratively checks for existence of sst files. This time I let it run for a while, until the process eventually came back and reported some output. After this happened, subsequent runs of agave-ledger-tool sees Blockstore::open() return promptly.

In summary, I believe there is a one time manifest / index rebuild that happens when upgrading versions. After this has completed, it opens as normal (slightly faster actually).

[steviez]

Thanks for digging into this @cpubot!

This time I let it run for a while, until the process eventually came back and reported some output

Do you recall about how long this took ?

In summary, I believe there is a one time manifest / index rebuild that happens when upgrading versions. After this has completed, it opens as normal (slightly faster actually).

Additionally, do you know if we'd run into the same one-time-cost calling Blockstore::open() from agave-validator when the Blockstore is opened with Primary access. Given your findings, I'm inclined to think Primary vs. Secondary is not relevant but I'm still curious

[cpubot]

Re-ran the experiment, this time running agave validator with updated version of rust-rocksdb first before running ledger tool.

Agave validator start up:

• Immediately after rebuild with new version of rust-rocksdb: LoadingLedger: 3min 24s
• Restart after initial start with new version: LoadingLedger: 1 min 45s

After letting the validator run through its start-up phase the first time, ledger tool returns as normal.

So, looks like we eat this one-time-cost either way, but doing it via primary access seems faster.

[steviez]

I chatted with @cpubot; he mentioned that restarting the validator with new version happened shortly after the node had initially started with no rocksdb (ie fresh start). Thus, the ledger wasn't very "full" in comparison to what --limit-ledger-size would dicate.

So, I retried the experiment on my machine. The node had previously been running for tip of v2.2 (rust-rocksdb = 0.22.0) ~24 hours with --enable-rpc-transaction-metadata and logs would indicate it was just about "full" in comparison to the default 200M shred limit:

[2025-04-17T17:30:54.966367372Z INFO  solana_ledger::blockstore_cleanup_service] Looking for Blockstore data to cleanup, latest root: 334104114
[2025-04-17T17:30:55.225518212Z INFO  solana_ledger::blockstore_cleanup_service] Blockstore has 197327349 alive shreds in slots [333878545, 334104190], mean of 874 shreds per slot

After restart with rust-rocksdb = 0.23.0, I saw the following from agave-validator logs:

[2025-04-17T17:33:26.823950504Z INFO  solana_ledger::blockstore] Opening blockstore at "/home/sol/ledger/rocksdb"
[2025-04-17T17:33:34.417618586Z INFO  solana_ledger::blockstore] Opening blockstore done; blockstore open took 7.6s

Things went pretty quick; I then ran with ledger-tool and saw things take longer but not the multiple minutes I had previously seen:

[2025-04-17T17:35:53.862824025Z INFO  solana_ledger::blockstore_db] Opening Rocks with secondary (read only) access at: "/home/sol/ledger/rocksdb/solana-secondary". This secondary access could temporarily degrade other accesses, such as by agave-validator
[2025-04-17T17:36:27.273940886Z INFO  solana_ledger::blockstore] Opening blockstore done; blockstore open took 33.4s

And after that initial run, the open time drops to single digit seconds as expected.

Thus, I have been unable to recreate the problem I previously observed where ledger-tool wasn't returning after multiple minutes. I initially found the issue on a warehouse node that was struggling; I thought I reproduced the issue on my dev box but I'm not questioning that. The warehouse node struggling (being behind + having larger ledger) could have contributed to what i observed.

Going to poke around a little more but this is seemingly non-reproducible. If that is still the case, I'll close the issue & merge the upgrade PR