lightningnetwork / lnd

Lightning Network Daemon ⚡️
MIT License
7.56k stars 2.06k forks source link

`LeaseOutput` is slow with postgres backend #8809

Open yyforyongyu opened 1 month ago

yyforyongyu commented 1 month ago

Issue

SendCoins takes much longer to run with postgres as the db backend, and this itest failure has been shown multiple times,

harness_rpc.go:97: 
            Error Trace:    /home/runner/work/lnd/lnd/lntest/rpc/harness_rpc.go:97
                                        /home/runner/work/lnd/lnd/lntest/rpc/lnd.go:374
                                        /home/runner/work/lnd/lnd/itest/lnd_taproot_test.go:129
                                        /home/runner/work/lnd/lnd/itest/lnd_taproot_test.go:52
                                        /home/runner/work/lnd/lnd/lntest/harness.go:385
                                        /home/runner/work/lnd/lnd/itest/lnd_test.go:139
            Error:          Received unexpected error:
                            rpc error: code = DeadlineExceeded desc = context deadline exceeded
            Messages:       Alice: failed to call SendCoins

Observations

Turns out that when using postgres, leasing outputs take much longer, which is called here when crafting the tx for SendCoins.

Steps to reproduce

Running with make itest icase=sign_psbt/fund_and_sign_psbt backend=btcd,

2024-06-04 03:37:30.353 [INF] RPCS: [sendcoins] addr=2MzusuQmFdFCBgtns6LjnCnQemeAhRftiku, amt=0 BTC, sat/kw=12500, min_confs=0, send_all=true
2024-06-04 03:37:30.353 [DBG] SWPR: [WithCoinSelectLock] entered the lock
2024-06-04 03:37:30.453 [DBG] SWPR: [WithCoinSelectLock] finished fetching UTXOs
2024-06-04 03:37:30.453 [DBG] SWPR: [WithCoinSelectLock] leasing utxo: 65734f6883a0949f4588589fda166b9339bfb77081cf77dad1ee91b5dc78c000:0
...leasing 98 more...
2024-06-04 03:37:31.616 [DBG] SWPR: [WithCoinSelectLock] leasing utxo: 2fb2947606ac7bf141ae364e8ea8d805344f56a319b679efa4380e6839782bf8:0
2024-06-04 03:37:31.626 [DBG] SWPR: [WithCoinSelectLock] exited the lock
2024-06-04 03:37:31.656 [DBG] SWPR: Creating sweep transaction 6c4bc2d7afeecb395d8bf0654065d7f5acb52b1017e5b4a61442bbd1dd3d7207 for 100 inputs...

Running with make itest icase=sign_psbt/fund_and_sign_psbt backend=bitcoind,

2024-06-04 03:46:54.785 [INF] RPCS: [sendcoins] addr=2MzDETUurmNbcnx2mLWtm4tdeARCFUkdQbU, amt=0 BTC, sat/kw=12500, min_confs=0, send_all=true
2024-06-04 03:46:54.786 [DBG] SWPR: [WithCoinSelectLock] entered the lock
2024-06-04 03:46:54.856 [DBG] SWPR: [WithCoinSelectLock] finished fetching UTXOs
2024-06-04 03:46:54.856 [DBG] SWPR: [WithCoinSelectLock] leasing utxo: f4436cede2c43faa7eb16cc2d4577e0825790f685b146eacfbe2a07a1006df00:0
...leasing 98 more...
2024-06-04 03:46:55.960 [DBG] SWPR: [WithCoinSelectLock] leasing utxo: 8dd273ce89622e59cae55a216a33b65d581a0d9ea95a30d74138140f5a0d15ff:0
2024-06-04 03:46:55.970 [DBG] SWPR: [WithCoinSelectLock] exited the lock
2024-06-04 03:46:55.984 [DBG] SWPR: Creating sweep transaction c383561e0096a6099dfe5c9cd57a42a6f393cb7fd281e137e5d989c518db3627 for 100 inputs...

Running with make itest icase=sign_psbt/fund_and_sign_psbt backend=bitcoind dbbackend=postgres,

2024-06-04 03:41:21.576 [INF] RPCS: [sendcoins] addr=2N6HM91LmDZP63ViD5MPirXxLScp3gmK2zf, amt=0 BTC, sat/kw=12500, min_confs=0, send_all=true
2024-06-04 03:41:21.577 [DBG] SWPR: [WithCoinSelectLock] entered the lock
2024-06-04 03:41:23.324 [DBG] SWPR: [WithCoinSelectLock] finished fetching UTXOs
2024-06-04 03:41:23.324 [DBG] SWPR: [WithCoinSelectLock] leasing utxo: 38fecbec097297b3e4b1e2f535e4d4707efc8d5668424f4c14e29805aa771801:0
...leasing 98 more...
2024-06-04 03:42:02.574 [DBG] SWPR: [WithCoinSelectLock] leasing utxo: ad3297020e2b81993d2093ae239894a47ad3f67b243fc2f79c0f1fdf808384fc:0
2024-06-04 03:42:03.284 [DBG] SWPR: [WithCoinSelectLock] exited the lock
2024-06-04 03:42:03.772 [DBG] SWPR: Creating sweep transaction e50f98c1f40080ee20139d095945149a16d3334080658598bf4a5eef8ec90a7f for 100 inputs...

Running with make itest icase=sign_psbt/fund_and_sign_psbt backend=bitcoind dbbackend=postgres nativesql=true,

2024-06-04 03:53:42.474 [INF] RPCS: [sendcoins] addr=2MuaBevMSc9Gxdi4WGAnuEiRXH2pGAcYNaj, amt=0 BTC, sat/kw=12500, min_confs=0, send_all=true
2024-06-04 03:53:42.475 [DBG] SWPR: [WithCoinSelectLock] entered the lock
2024-06-04 03:53:44.029 [DBG] SWPR: [WithCoinSelectLock] finished fetching UTXOs
2024-06-04 03:53:44.029 [DBG] SWPR: [WithCoinSelectLock] leasing utxo: 1deb82f888c58b2c9e86d0f8773537324a5b1fe2ddd2b3d3a243088cb9990000:0
...leasing 98 more...
2024-06-04 03:54:19.937 [DBG] SWPR: [WithCoinSelectLock] leasing utxo: a4304be189a3075d22f5cabc638af956da871b09ae46ffb48a6dd1c143d084fe:0
2024-06-04 03:54:20.671 [DBG] SWPR: [WithCoinSelectLock] exited the lock
2024-06-04 03:54:21.260 [DBG] SWPR: Creating sweep transaction a6d8019cb0cb3f5bb0603bcfc4676b6eef81f88301933e75bd67673650b4e1c5 for 100 inputs...
Roasbeef commented 1 month ago

The implementation here is pretty unglamorous: https://github.com/btcsuite/btcwallet/blob/6fe19a472a627b5f3a6ab2eda9ed7d8809d04f2e/wtxmgr/tx.go#L1184-L1204

Perhaps the culprit is that we'll create 100 distributed transactions for the 100 outpoints, instead of just 1 transaction?