Performance stats: Trezor Suite & electrs 0.9.6 via Tor on Odroid HC1

I'll share some performance stats of using Trezor Suite with electrs 0.9.6 as a custom Bitcoin backend over Tor. It works, but the sync time when opening the wallet is not great. Sharing it here so we eventually identify some potential for improvement.

electrs Platform Details:

Odroid HC1 (2 GB RAM) 1 TB SSD Debian buster (32-bit armhf) Bitcoin Core v22.0.0 (txindex = 1)

Trezor Suite Details:

Version: 22.3.2 Route all Suite traffic over Tor: on Labeling: off

Trezor Suite is a HD wallet which queries multiple accounts at once for P2PKH, P2SH-P2WPKH, P2WPKH and P2TR addresses (at least 40 addresses per type and account). So in theory even for an empty wallet, there are at least 4 40 = 160 addresses (scripthashes) to check when opening the wallet. For some reason Trezor Suite also checks the second account for BIP84 addresses, even if the first one is empty. So in reality there are at least 5 40 = 200 addresses to check when opening a wallet.

Here are the sync times for a wallet using a "warm" electrs cache. I assume the cache is "warm" when you start the electrs daemon, open the wallet and let it sync, close the wallet and repeat. (Is there a way to get the cache hits/misses via Prometheus metrics? I haven't discovered any.)

Empty Wallet

Total sync time:

23 sec (on average. measured multiple times.)

Number of calls:

blockchain.scripthash.get_history for unsubscribed scripthash : 400 (Each scripthash seems to be called twice throughout the sync, not sure if this is a bug?) blockchain.scripthash.get_balance for unsubscribed scripthash: 0 blockchain.scripthash.listunspent for unsubscribed scripthash : 0

Non-Empty Wallet (with 3 accounts containing ~50 transactions in total)

Total sync time:

2:15 min (on average. measured multiple times.)

Number of calls:

blockchain.scripthash.get_history for unsubscribed scripthash : 670 (Each scripthash seems to be called twice throughout the sync, not sure if this is a bug?) blockchain.scripthash.get_balance for unsubscribed scripthash: 13 blockchain.scripthash.listunspent for unsubscribed scripthash : 13

Observations:

RAM and CPU of the Odroid HC1 don't seem to be the bottleneck, neither is "saturated" during the test of a "personal" single user case.
Tor doesn't seem to have a significant impact, as the sync time is almost identical when connecting to electrs directly within the same subnet.
I guess sync time could easily be halved if Trezor Suite wouldn't query the history (get_history) twice for each scripthash. This is reproducible and happens every time you open a wallet. Looks like bug in Trezor Suite.
Not sure how significant the impact of "unsubscribed scripthash" is and how much it would improve the overall sync time if this was optimised. (see https://github.com/trezor/trezor-suite/issues/5267)
The get_history metrics (see below) look like there could be an issue?

Prometheus stats for `get_history`, `get_balance` and `listunspent`

Empty Wallet

$ curl -s localhost:4224 | grep get_history
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.000001"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.000002"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.000005"} 155
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.00001"} 194
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.00002"} 200
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.00005"} 200
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.0001"} 200
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.0002"} 287
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.0005"} 341
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.001"} 429
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.002"} 476
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.005"} 487
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.01"} 488
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.02"} 488
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.05"} 553
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.1"} 594
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.2"} 600
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.5"} 600
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="1"} 600
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="2"} 600
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="5"} 600
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="10"} 600
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="20"} 600
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="50"} 600
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="100"} 600
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="+Inf"} 600
rpc_duration_sum{method="blockchain.scripthash.get_history"} 6.564694910000004
rpc_duration_count{method="blockchain.scripthash.get_history"} 600

Non-Empty Wallet

$ curl -s localhost:4224 | grep get_history
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.000001"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.000002"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.000005"} 243
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.00001"} 310
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.00002"} 325
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.00005"} 334
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.0001"} 334
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.0002"} 439
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.0005"} 524
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.001"} 562
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.002"} 639
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.005"} 706
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.01"} 719
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.02"} 722
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.05"} 938
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.1"} 978
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.2"} 998
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="0.5"} 1003
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="1"} 1003
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="2"} 1004
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="5"} 1005
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="10"} 1005
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="20"} 1005
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="50"} 1005
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="100"} 1005
rpc_duration_bucket{method="blockchain.scripthash.get_history",le="+Inf"} 1005
rpc_duration_sum{method="blockchain.scripthash.get_history"} 19.760434207999936
rpc_duration_count{method="blockchain.scripthash.get_history"} 1005

$ curl -s localhost:4224 | grep get_balance
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.000001"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.000002"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.000005"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.00001"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.00002"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.00005"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.0001"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.0002"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.0005"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.001"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.002"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.005"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.01"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.02"} 0
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.05"} 1
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.1"} 4
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.2"} 11
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="0.5"} 12
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="1"} 13
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="2"} 13
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="5"} 13
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="10"} 13
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="20"} 13
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="50"} 13
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="100"} 13
rpc_duration_bucket{method="blockchain.scripthash.get_balance",le="+Inf"} 13
rpc_duration_sum{method="blockchain.scripthash.get_balance"} 2.440490418
rpc_duration_count{method="blockchain.scripthash.get_balance"} 13

$ curl -s localhost:4224 | grep listunspent
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.000001"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.000002"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.000005"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.00001"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.00002"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.00005"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.0001"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.0002"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.0005"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.001"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.002"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.005"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.01"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.02"} 0
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.05"} 1
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.1"} 6
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.2"} 9
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="0.5"} 12
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="1"} 13
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="2"} 13
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="5"} 13
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="10"} 13
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="20"} 13
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="50"} 13
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="100"} 13
rpc_duration_bucket{method="blockchain.scripthash.listunspent",le="+Inf"} 13
rpc_duration_sum{method="blockchain.scripthash.listunspent"} 2.552133667
rpc_duration_count{method="blockchain.scripthash.listunspent"} 13

romanz / electrs