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

issue fanquake openend this issue on April 7, 2021
  1. fanquake commented at 6:04 am on April 7, 2021: member

    Building master @ 41a8d2b96ff5cbc2efa9b0996f30228d0a625fdb (sqlite):

     0./autogen.sh
 1./configure --without-bdb --without-gui --with-sqlite
 2  with wallet     = yes
 3    with sqlite   = yes
 4    with bdb      = no
 5gmake -j8
 6src/test/test_bitcoin --run_test=wallet_tests --log_level=all
 7...
 8wallet/test/wallet_tests.cpp:696: Entering test case "CreateWallet"
 9wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
10wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
11wallet/test/wallet_tests.cpp:734: info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
12wallet/test/wallet_tests.cpp:740: info: check rescan_completed has passed
13wallet/test/wallet_tests.cpp:741: info: check addtx_count == 2 has passed
14wallet/test/wallet_tests.cpp:744: info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
15wallet/test/wallet_tests.cpp:745: info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
16wallet/test/wallet_tests.cpp:753: info: check addtx_count == 4 has passed
17wallet/test/wallet_tests.cpp:767: info: check rescan_completed has passed
18wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
19wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
20wallet/test/wallet_tests.cpp:772: info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
21wallet/test/wallet_tests.cpp:780: info: check addtx_count == 4 has passed
22wallet/test/wallet_tests.cpp:783: info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
23wallet/test/wallet_tests.cpp:784: info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
24wallet/test/wallet_tests.cpp:696: Leaving test case "CreateWallet"; testing time: 201296644us
25wallet/test/wallet_tests.cpp:791: Entering test case "ZapSelectTx"
26wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
27wallet/test/wallet_tests.cpp:810: info: check wallet->HasWalletSpend(prev_hash) has passed
28wallet/test/wallet_tests.cpp:811: info: check wallet->mapWallet.count(block_hash) == 1u has passed
29wallet/test/wallet_tests.cpp:814: info: check wallet->ZapSelectTx(vHashIn, vHashOut) == DBErrors::LOAD_OK has passed
30wallet/test/wallet_tests.cpp:816: info: check !wallet->HasWalletSpend(prev_hash) has passed
31wallet/test/wallet_tests.cpp:817: info: check wallet->mapWallet.count(block_hash) == 0u has passed
32wallet/test/wallet_tests.cpp:791: Leaving test case "ZapSelectTx"; testing time: 200866629us

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

     0gmake clean
 1./configure --without-gui --with-sqlite=no
 2  with wallet     = yes
 3    with sqlite   = no
 4    with bdb      = yes
 5gmake -j8
 6src/test/test_bitcoin --run_test=wallet_tests --log_level=all
 7...
 8wallet/test/wallet_tests.cpp:696: Entering test case "CreateWallet"
 9wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
10wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
11wallet/test/wallet_tests.cpp:734: info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
12wallet/test/wallet_tests.cpp:740: info: check rescan_completed has passed
13wallet/test/wallet_tests.cpp:741: info: check addtx_count == 2 has passed
14wallet/test/wallet_tests.cpp:744: info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
15wallet/test/wallet_tests.cpp:745: info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
16wallet/test/wallet_tests.cpp:753: info: check addtx_count == 4 has passed
17wallet/test/wallet_tests.cpp:767: info: check rescan_completed has passed
18wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
19wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
20wallet/test/wallet_tests.cpp:772: info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
21wallet/test/wallet_tests.cpp:780: info: check addtx_count == 4 has passed
22wallet/test/wallet_tests.cpp:783: info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
23wallet/test/wallet_tests.cpp:784: info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
24wallet/test/wallet_tests.cpp:696: Leaving test case "CreateWallet"; testing time: 2139054us
25wallet/test/wallet_tests.cpp:791: Entering test case "ZapSelectTx"
26wallet/test/wallet_tests.cpp:69: info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
27wallet/test/wallet_tests.cpp:810: info: check wallet->HasWalletSpend(prev_hash) has passed
28wallet/test/wallet_tests.cpp:811: info: check wallet->mapWallet.count(block_hash) == 1u has passed
29wallet/test/wallet_tests.cpp:814: info: check wallet->ZapSelectTx(vHashIn, vHashOut) == DBErrors::LOAD_OK has passed
30wallet/test/wallet_tests.cpp:816: info: check !wallet->HasWalletSpend(prev_hash) has passed
31wallet/test/wallet_tests.cpp:817: info: check wallet->mapWallet.count(block_hash) == 0u has passed
32wallet/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.

  2. fanquake added the label Wallet on Apr 7, 2021
  3. fanquake added the label Tests on Apr 7, 2021
  4. achow101 commented at 6:52 pm on April 7, 2021: member

    I’m not seeing this on my system.

     0./autogen.sh && ./configure --with-bdb --without-gui --without-sqlite && make -j31
 1...
 2  with wallet     = yes
 3    with sqlite   = no
 4    with bdb      = yes
 5...
 6src/test/test_bitcoin -t wallet_tests/CreateWallet -t wallet_tests/ZapSelectTx --log_level=all
 7...
 8wallet/test/wallet_tests.cpp(696): Entering test case "CreateWallet"
 9wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
10wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
11wallet/test/wallet_tests.cpp(734): info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
12wallet/test/wallet_tests.cpp(740): info: check rescan_completed has passed
13wallet/test/wallet_tests.cpp(741): info: check addtx_count == 2 has passed
14wallet/test/wallet_tests.cpp(744): info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
15wallet/test/wallet_tests.cpp(745): info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
16wallet/test/wallet_tests.cpp(753): info: check addtx_count == 4 has passed
17wallet/test/wallet_tests.cpp(767): info: check rescan_completed has passed
18wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
19wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
20wallet/test/wallet_tests.cpp(772): info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
21wallet/test/wallet_tests.cpp(780): info: check addtx_count == 4 has passed
22wallet/test/wallet_tests.cpp(783): info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
23wallet/test/wallet_tests.cpp(784): info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
24wallet/test/wallet_tests.cpp(696): Leaving test case "CreateWallet"; testing time: 990347us
25wallet/test/wallet_tests.cpp(791): Entering test case "ZapSelectTx"
26wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
27wallet/test/wallet_tests.cpp(810): info: check wallet->HasWalletSpend(prev_hash) has passed
28wallet/test/wallet_tests.cpp(811): info: check wallet->mapWallet.count(block_hash) == 1u has passed
29wallet/test/wallet_tests.cpp(814): info: check wallet->ZapSelectTx(vHashIn, vHashOut) == DBErrors::LOAD_OK has passed
30wallet/test/wallet_tests.cpp(816): info: check !wallet->HasWalletSpend(prev_hash) has passed
31wallet/test/wallet_tests.cpp(817): info: check wallet->mapWallet.count(block_hash) == 0u has passed
32wallet/test/wallet_tests.cpp(791): Leaving test case "ZapSelectTx"; testing time: 882547us
33wallet/test/wallet_tests.cpp(38): Leaving test suite "wallet_tests"; testing time: 1873052us

     0./autogen.sh && ./configure --without-bdb --without-gui --with-sqlite && make -j31
 1...
 2  with wallet     = yes
 3    with sqlite   = yes
 4    with bdb      = no
 5...
 6src/test/test_bitcoin -t wallet_tests/CreateWallet -t wallet_tests/ZapSelectTx --log_level=all
 7...
 8wallet/test/wallet_tests.cpp(696): Entering test case "CreateWallet"
 9wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
10wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
11wallet/test/wallet_tests.cpp(734): info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
12wallet/test/wallet_tests.cpp(740): info: check rescan_completed has passed
13wallet/test/wallet_tests.cpp(741): info: check addtx_count == 2 has passed
14wallet/test/wallet_tests.cpp(744): info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
15wallet/test/wallet_tests.cpp(745): info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
16wallet/test/wallet_tests.cpp(753): info: check addtx_count == 4 has passed
17wallet/test/wallet_tests.cpp(767): info: check rescan_completed has passed
18wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
19wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
20wallet/test/wallet_tests.cpp(772): info: check m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error) has passed
21wallet/test/wallet_tests.cpp(780): info: check addtx_count == 4 has passed
22wallet/test/wallet_tests.cpp(783): info: check wallet->mapWallet.count(block_tx.GetHash()) == 1U has passed
23wallet/test/wallet_tests.cpp(784): info: check wallet->mapWallet.count(mempool_tx.GetHash()) == 1U has passed
24wallet/test/wallet_tests.cpp(696): Leaving test case "CreateWallet"; testing time: 1006674us
25wallet/test/wallet_tests.cpp(791): Entering test case "ZapSelectTx"
26wallet/test/wallet_tests.cpp(69): info: check SignTransaction(mtx, &keystore, coins, SIGHASH_ALL, input_errors) has passed
27wallet/test/wallet_tests.cpp(810): info: check wallet->HasWalletSpend(prev_hash) has passed
28wallet/test/wallet_tests.cpp(811): info: check wallet->mapWallet.count(block_hash) == 1u has passed
29wallet/test/wallet_tests.cpp(814): info: check wallet->ZapSelectTx(vHashIn, vHashOut) == DBErrors::LOAD_OK has passed
30wallet/test/wallet_tests.cpp(816): info: check !wallet->HasWalletSpend(prev_hash) has passed
31wallet/test/wallet_tests.cpp(817): info: check wallet->mapWallet.count(block_hash) == 0u has passed
32wallet/test/wallet_tests.cpp(791): Leaving test case "ZapSelectTx"; testing time: 934239us
  5. Sjors commented at 7:21 pm on April 7, 2021: member

    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.

  6. achow101 commented at 8:50 pm on April 7, 2021: member

    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:

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

    With BDB:

    0wallet/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.

  7. MarcoFalke closed this on Apr 13, 2021
  8. sidhujag referenced this in commit c0ef5fd1e1 on Apr 13, 2021
  9. DrahtBot locked this on Aug 18, 2022


fanquake achow101 Sjors

Labels
Wallet Tests

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-10-04 22:12 UTC
This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me