Zebra full lightwalletd sync is significantly slower than zcashd

[teor2345]

Motivation

Currently, a full lightwalletd sync is 37% slower with Zebra than zcashd (7h vs 5h).

Benchmarks

Full Sync Benchmarks

Here are some commands for full sync benchmarks:

Zebra:

time lightwalletd --zcash-conf-path /home/dev/.config/zebra/zebrad-mainnet-lightwalletd-tmp-zcash.conf --data-dir $(mktemp -d) --log-file /dev/stdout --grpc-bind-addr 0.0.0.0:0 --http-bind-addr 0.0.0.0:0 --no-tls-very-insecure 2>&1 | rg --passthru --max-count 1 'Adding block to cache 182[0-9]{4}'

zcashd:

time lightwalletd --zcash-conf-path /home/dev/.zcash/zcash.conf --data-dir $(mktemp -d) --log-file /dev/stdout --grpc-bind-addr 0.0.0.0:0 --http-bind-addr 0.0.0.0:0 --no-tls-very-insecure 2>&1 | rg --passthru --max-count 1 'Adding block to cache 182[0-9]{4}'

Quick Benchmarks

Here are some commands for quick benchmarks:

Zebra:

TODO

zcashd:

TODO

Benchmark Notes

You can change 182[0-9]{4} to the current tip height minus 10,000. (For example, if the current tip height is 1,975,302 use 196[0-9]{4}.)

rg (ripgrep) is a fast grep alternative written in Rust. You can use tee /dev/stderr | grep --max-count=1 instead of rg rg --passthru --max-count 1.

/home/dev/.config/zebra/zebrad-mainnet-lightwalletd-tmp-zcash.conf is set up like it is in the lightwalletd tests:

rpcbind=127.0.0.1
rpcport=(your Zebra RPC port)

TODO

• a benchmark that takes 1-5 minutes (or less!)
• check if older Zebra releases were faster
• use a flamegraph to find out what parts of Zebra are slow

[teor2345]

Some changes that might impact RPC speed:

• change(state): Write non-finalized blocks to the state in a separate thread, to avoid network and RPC hangs #5257
• data compression in rocksdb
• Disable code timers unless a specific zebrad feature is activated #5253
• re-applying the revert in Revert: deserialize stored transactions in a rayon thread #4933

Some previous changes that might have regressed RPC speed:

• Run JSON-RPC queries in multiple threads #5012
• fix(rpc): Isolate RPC queries from the rest of Zebra, to improve performance #4806
• change(state): Write finalized blocks to the state in a separate thread, to avoid network and RPC hangs #5134
• Make StateService requests into concurrent ReadStateService requests #5102

[teor2345]

I tried timing a large block RPC with zebrad and zcashd, and Zebra was significantly faster each time.

$ zcash-rpc-diff 28232 getblock 1825310 1
Querying zebrad main chain at height >=1825334...

real    0m0.045s
user    0m0.003s
sys     0m0.004s

Querying zcashd main chain at height >=1825334...

real    0m0.059s
user    0m0.003s
sys     0m0.003s

$ zcash-rpc-diff 28232 getblock 1825310 0
Querying zebrad main chain at height >=1825334...

real    0m0.024s
user    0m0.012s
sys     0m0.007s

Querying zcashd main chain at height >=1825334...

real    0m0.079s
user    0m0.010s
sys     0m0.007s

This uses the zcash-rpc-diff changes in commit 89f7b38 in PR #5164.

[teor2345]

This performance pattern continues even if I query multiple blocks, exactly the way lightwalletd does:
https://github.com/adityapk00/lightwalletd/blob/master/common/common.go#L266

time for HEIGHT in $(seq 1825310 1825310); do
    zcash-cli -rpcport=28232 getblock $HEIGHT 0 > /dev/null
    zcash-cli -rpcport=28232 getblock $HEIGHT 1 > /dev/null
done

Zebra port:

real    0m0.078s                                                                               
user    0m0.020s                                                                               
sys     0m0.013s

zcashd port:

real    0m0.157s
user    0m0.018s
sys     0m0.014s

[teor2345]

Similarly, using curl shows that zcashd is slower for single block requests.

For example:

time curl --data-binary '{"method":"getblock","params":["1825310",0],"id":1}' -H 'Authorization: Basic (insert hashed password here)' -H 'Content-Type: application/json' http://127.0.0.1:8232/

You can get the hashed RPC password by running nc -l 11111 in one shell, and zcash-cli -rpcport=11111 getinfo in another.

Maybe the slowness only happens with lots of blocks, or with a continually running process.

[teor2345]

The verbose getblock requests took about the same time for Zebra and zcashd, so I made them about 8x faster in Zebra (commit eb1359a in PR #5164).

Let's see if that fixes our performance issue.

$ time curl --data-binary '{"method":"getblock","params":["1825310",1],"id":1}' -H 'Content-Type: application/json' http://127.0.0.1:28232/ > /dev/null

real    0m0.005s
user    0m0.002s
sys     0m0.002s

The previous times were:

real    0m0.042s
user    0m0.002s
sys     0m0.004s

[teor2345]

A full lightwalletd sync takes 3.4 hours now, so that meets our performance goals for the release candidate. (3.4h vs 5h for zcashd.)

$ time lightwalletd-mainnet-tmp | rg --passthru --max-count 1 'Adding block to cache 182[0-9]{4}'
...
{"app":"lightwalletd","level":"info","msg":"Adding block to cache 1820018 000000000085c92f02a5dec63a62d77455a9e631a624b24c50bfc7e733df65d9","time":"2022-09-29T23:22:58+10:00"}


real    204m48.731s
user    52m38.236s
sys     10m22.202s

[daira]

That's awesome! Congratulations!

[oxarbitrage]

Using zebra from this PR i synchronized lightwalletd in 4 hs and 20 mins locally.

[teor2345]

Using zebra from this PR i synchronized lightwalletd in 4 hs and 20 mins locally.

That sounds about right, the exact time depends on your disk speed, CPU, and Rust and OS versions.