Up to 100x perfomance difference for sqlite vs BDB in CreateWallet test #21628

Building master @ 41a8d2b96ff5cbc2efa9b0996f30228d0a625fdb (sqlite):

./autogen.sh
./configure --without-bdb --without-gui --with-sqlite
  with wallet     = yes
    with sqlite   = yes
    with bdb      = no
gmake -j8
src/test/test_bitcoin --run_test=wallet_tests --log_level=all
...
wallet/test/wallet_tests.cpp:696: Entering test case "CreateWallet"
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:734: info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
wallet/test/wallet_tests.cpp:740: info: check rescan_completed has passed
wallet/test/wallet_tests.cpp:741: info: check addtx_count == 2 has passed
wallet/test/wallet_tests.cpp:744: info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp:745: info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp:753: info: check addtx_count == 4 has passed
wallet/test/wallet_tests.cpp:767: info: check rescan_completed has passed
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:772: info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
wallet/test/wallet_tests.cpp:780: info: check addtx_count == 4 has passed
wallet/test/wallet_tests.cpp:783: info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp:784: info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp:696: Leaving test case "CreateWallet"; testing time: 201296644us
wallet/test/wallet_tests.cpp:791: Entering test case "ZapSelectTx"
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:810: info: check wallet->HasWalletSpend(prev_hash) has passed
wallet/test/wallet_tests.cpp:811: info: check wallet->mapWallet.count(block_hash) == 1u has passed
wallet/test/wallet_tests.cpp:814: info: check wallet->ZapSelectTx(vHashIn, vHashOut) == DBErrors::LOAD_OK has passed
wallet/test/wallet_tests.cpp:816: info: check !wallet->HasWalletSpend(prev_hash) has passed
wallet/test/wallet_tests.cpp:817: info: check wallet->mapWallet.count(block_hash) == 0u has passed
wallet/test/wallet_tests.cpp:791: Leaving test case "ZapSelectTx"; testing time: 200866629us

Compare that to running the same tests after building with just bdb:

gmake clean
./configure --without-gui --with-sqlite=no
  with wallet     = yes
    with sqlite   = no
    with bdb      = yes
gmake -j8
src/test/test_bitcoin --run_test=wallet_tests --log_level=all
...
wallet/test/wallet_tests.cpp:696: Entering test case "CreateWallet"
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:734: info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
wallet/test/wallet_tests.cpp:740: info: check rescan_completed has passed
wallet/test/wallet_tests.cpp:741: info: check addtx_count == 2 has passed
wallet/test/wallet_tests.cpp:744: info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp:745: info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp:753: info: check addtx_count == 4 has passed
wallet/test/wallet_tests.cpp:767: info: check rescan_completed has passed
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:772: info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
wallet/test/wallet_tests.cpp:780: info: check addtx_count == 4 has passed
wallet/test/wallet_tests.cpp:783: info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp:784: info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp:696: Leaving test case "CreateWallet"; testing time: 2139054us
wallet/test/wallet_tests.cpp:791: Entering test case "ZapSelectTx"
wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp:810: info: check wallet->HasWalletSpend(prev_hash) has passed
wallet/test/wallet_tests.cpp:811: info: check wallet->mapWallet.count(block_hash) == 1u has passed
wallet/test/wallet_tests.cpp:814: info: check wallet->ZapSelectTx(vHashIn, vHashOut) == DBErrors::LOAD_OK has passed
wallet/test/wallet_tests.cpp:816: info: check !wallet->HasWalletSpend(prev_hash) has passed
wallet/test/wallet_tests.cpp:817: info: check wallet->mapWallet.count(block_hash) == 0u has passed
wallet/test/wallet_tests.cpp:791: Leaving test case "ZapSelectTx"; testing time: 1821042us

In the sqlite case,CreateWallet is taking ~100x longer: 201296644us vs 2139054us. ZapWalletTx is similar: 200866629us vs 1821042us. Full logs here.

I thought this might be some weird macOS behaviour, but I tested on Linux, and am also seeing up to 27x difference. CreateWallet: 27905993us vs 1092394us. ZapWalletTx: 28024310us vs 969432us. Full logs here.

I'm not seeing this on my system.

./autogen.sh && ./configure --with-bdb --without-gui --without-sqlite && make -j31
...
  with wallet     = yes
    with sqlite   = no
    with bdb      = yes
...
src/test/test_bitcoin -t wallet_tests/CreateWallet -t wallet_tests/ZapSelectTx --log_level=all
...
wallet/test/wallet_tests.cpp(696): Entering test case "CreateWallet"
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(734): info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
wallet/test/wallet_tests.cpp(740): info: check rescan_completed has passed
wallet/test/wallet_tests.cpp(741): info: check addtx_count == 2 has passed
wallet/test/wallet_tests.cpp(744): info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp(745): info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp(753): info: check addtx_count == 4 has passed
wallet/test/wallet_tests.cpp(767): info: check rescan_completed has passed
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(772): info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
wallet/test/wallet_tests.cpp(780): info: check addtx_count == 4 has passed
wallet/test/wallet_tests.cpp(783): info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp(784): info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp(696): Leaving test case "CreateWallet"; testing time: 990347us
wallet/test/wallet_tests.cpp(791): Entering test case "ZapSelectTx"
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(810): info: check wallet->HasWalletSpend(prev_hash) has passed
wallet/test/wallet_tests.cpp(811): info: check wallet->mapWallet.count(block_hash) == 1u has passed
wallet/test/wallet_tests.cpp(814): info: check wallet->ZapSelectTx(vHashIn, vHashOut) == DBErrors::LOAD_OK has passed
wallet/test/wallet_tests.cpp(816): info: check !wallet->HasWalletSpend(prev_hash) has passed
wallet/test/wallet_tests.cpp(817): info: check wallet->mapWallet.count(block_hash) == 0u has passed
wallet/test/wallet_tests.cpp(791): Leaving test case "ZapSelectTx"; testing time: 882547us
wallet/test/wallet_tests.cpp(38): Leaving test suite "wallet_tests"; testing time: 1873052us

./autogen.sh && ./configure --without-bdb --without-gui --with-sqlite && make -j31
...
  with wallet     = yes
    with sqlite   = yes
    with bdb      = no
...
src/test/test_bitcoin -t wallet_tests/CreateWallet -t wallet_tests/ZapSelectTx --log_level=all
...
wallet/test/wallet_tests.cpp(696): Entering test case "CreateWallet"
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(734): info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
wallet/test/wallet_tests.cpp(740): info: check rescan_completed has passed
wallet/test/wallet_tests.cpp(741): info: check addtx_count == 2 has passed
wallet/test/wallet_tests.cpp(744): info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp(745): info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp(753): info: check addtx_count == 4 has passed
wallet/test/wallet_tests.cpp(767): info: check rescan_completed has passed
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(772): info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
wallet/test/wallet_tests.cpp(780): info: check addtx_count == 4 has passed
wallet/test/wallet_tests.cpp(783): info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp(784): info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
wallet/test/wallet_tests.cpp(696): Leaving test case "CreateWallet"; testing time: 1006674us
wallet/test/wallet_tests.cpp(791): Entering test case "ZapSelectTx"
wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
wallet/test/wallet_tests.cpp(810): info: check wallet->HasWalletSpend(prev_hash) has passed
wallet/test/wallet_tests.cpp(811): info: check wallet->mapWallet.count(block_hash) == 1u has passed
wallet/test/wallet_tests.cpp(814): info: check wallet->ZapSelectTx(vHashIn, vHashOut) == DBErrors::LOAD_OK has passed
wallet/test/wallet_tests.cpp(816): info: check !wallet->HasWalletSpend(prev_hash) has passed
wallet/test/wallet_tests.cpp(817): info: check wallet->mapWallet.count(block_hash) == 0u has passed
wallet/test/wallet_tests.cpp(791): Leaving test case "ZapSelectTx"; testing time: 934239us

Tested on macOS 11.2.3 with Sqlite 3.34.1 via homebrew (though the wallet log says Using SQLite Version 3.34.0).

With sqlite the CreateWallet test seems to just freeze, though eventually it finished. 867 seconds. No notable CPU / memory / disk use.

I am able to replicate this now. The issue is with disk I/O. When I have the unit tests use my hard drive (vs the ramdisk for my /tmp), I see slowdown.

With sqlite:

wallet/test/wallet_tests.cpp(696): Leaving test case "CreateWallet"; testing time: 1124026946us

With BDB:

wallet/test/wallet_tests.cpp(696): Leaving test case "CreateWallet"; testing time: 3407781us

Presumably we are using sqlite sub-optimally and it is doing a lot more writes than BDB.