[Performace] eth_getTransactionReceipt concurrent performance 10x slower than eth_getTransactionByHash

[TangMonk]

System information

Erigon version: 2.59.3

OS & Version: Linux

Chain/Network: Mainnet

CPU: AMD EPYC 7763, 64 Core, 128 Thread

Memory: 256 GB DDR4

Disk: 15TB, NVEM 4.0

Erigon.toml config file:

datadir = "/home/david/erigon_archive/"
port = 30304
"authrpc.port" = 8557
"authrpc.addr" = "0.0.0.0"
"authrpc.vhosts" = "*"
"authrpc.jwtsecret" = "/home/david/ethereum/consensus2/jwt.hex"
"db.size.limit"="8TB"
"torrent.download.rate"="1024MB"
"maxpeers"=500
metrics = true
"torrent.port" = 42071
"private.api.addr" = "127.0.0.1:9091"
chain = "mainnet"
http = true
ws = true
"http.addr" = "0.0.0.0"
"http.api" = ["eth", "debug", "net", "trace", "web3", "erigon", "admin", "txpool", "ots"]
"http.corsdomain" = "*"
"http.port" = 7546

I am using wrk to do http concurrent test:

eth_getTransactionReceipt performace

$ wrk -t125 -c125 -d30s -s eth_getTransactionReceipt.lua http://localhost:7546

eth_getTransactionReceipt.lua file:

wrk.method = "POST"
wrk.body   = '{"jsonrpc":"2.0","method":"eth_getTransactionReceipt","params":["0x4e47c43b82a302aa574ad7b61cf54cc72ad1e548e016dc1e3c17ee8b75a20198"],"id":1}'
wrk.headers["Content-Type"] = "application/json"

result:

Running 30s test @ http://localhost:7546
  125 threads and 125 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    21.34ms   28.40ms 533.12ms   97.96%
    Req/Sec    54.79      9.08   252.00     92.12%
  203675 requests in 30.10s, 0.92GB read
Requests/sec:   6766.57
Transfer/sec:     31.40MB

eth_getTransactionByHash performace

$ wrk -t125 -c125 -d30s -s eth_getTransactionByHash.lua http://localhost:7546

eth_getTransactionByHash.lua file:

wrk.method = "POST"
wrk.body   = '{"jsonrpc":"2.0", "method":"eth_getTransactionByHash", "params":["0x4e47c43b82a302aa574ad7b61cf54cc72ad1e548e016dc1e3c17ee8b75a20198"], "id":1}'
wrk.headers["Content-Type"] = "application/json"

result:

Running 30s test @ http://localhost:7546
  125 threads and 125 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.82ms    1.85ms 155.09ms   98.32%
    Req/Sec   580.47     78.17     4.18k    95.17%
  2171851 requests in 30.10s, 2.64GB read
Requests/sec:  72164.60
Transfer/sec:     89.74MB

Summarize

eth_getTransactionByHash is 72164.60/s
eth_getTransactionReceipt is 6766.57/s

eth_getTransactionReceipt is slower than geth

[AskAlexSharov]

@TangMonk what if increase —db.read.comcurrency ?

[TangMonk]

@TangMonk* what if increase —db.read.comcurrency ?

"db.read.concurrency" = 1000
"rpc.batch.concurrency" = 100

Same result

And concurrent rpc requests become slower and slower over time

[AskAlexSharov]

@TangMonk add --pprof --pprof.port=6062 --pprof.addr=0.0.0.0 to erigon. then drop here picture:

go tool pprof -png 'http://0.0.0.0:6062/debug/pprof/profile?seconds=20' > cpu.png

(while you making stress-test)

[AskAlexSharov]

my guess:
we don't have bc.txLookupCache and you calling us with same request - and likely your request is hitting that cache in geth. (if call different txHashes likely you will see similar speed).

bc.txLookupCache - mostly exists because calculation of txIndex is expensive (in geth and erigon): need read whole block and calc all txs hashes.
But this cache is reorgs-unfriendly (each re-org does purge this cache) because txn with same hash may appear in different blocks (with different txnIndex) - after reorg.

[TangMonk]

@TangMonk* add --pprof --pprof.port=6062 --pprof.addr=0.0.0.0 to erigon. then drop here picture:

go tool pprof -png 'http://0.0.0.0:6062/debug/pprof/profile?seconds=20' > cpu.png

(while you making stress-test)

pprof.erigon_2.59.3.samples.cpu.003.pb.gz

[AskAlexSharov]

@TangMonk aha, your picture shows another bottleneck. But this one easy to fix (because receipts LRU is re-orgs-friendly). Here you go: #10112

Let's switch to this PR and generate one new picture.

[TangMonk]

Wow, It works!

I am opting to use rpcdaemon for testing purposes due to its quicker startup time compared to Erigon, the picture might same

pprof.rpcdaemon.samples.cpu.001.pb.gz

$ wrk -t125 -c125 -d30s -s eth_getTransactionReceipt.lua http://localhost:7547

Running 30s test @ http://localhost:7547
  125 threads and 125 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.79ms    2.33ms 143.48ms   97.03%
    Req/Sec   637.71     81.08     2.92k    90.16%
  2386185 requests in 30.10s, 10.78GB read
Requests/sec:  79279.72
Transfer/sec:    366.78MB

So the problem is eth_getTransactionReceipt not cached in LRU but eth_getTransactionByHash cached?

[AskAlexSharov]

@TangMonk FYI: usually people using RPCDaemon because it allow them restart it without restarting erigon, and having different --db.read.concurrency. PageCache - is shared (and surviving app restart).

FYI: I made small-LRU's a bit bigger when RPCDaemon started as separated process: https://github.com/ledgerwatch/erigon/pull/10112/files#diff-d1cd07f6985dbe9ab561409b63d2f19c9c20adb266c21cb3c38d1e0833575778R137

About "So the problem is eth_getTransactionReceipt not cached in LRU but eth_getTransactionByHash cached?":

There are 3 small LRU-caches in Gets RPC:

• blocks: get block by block hash)
• receipts: get receipts by block hash
• txnLookup: get txn by txn hash

We have only for blocks. I just added for receipts. (eth_getTransactionByHash doesn't read receipts)

Thing is:

• OS's PageCache - it's already an LRU. But blocs and receipts are very big and complex objecs -> slow deserialization (you can see Decode on this picture [Performace] eth_getTransactionReceipt concurrent performance 10x slower than eth_getTransactionByHash #10099 (comment) ).
• When people reading much historical data - small LRU-caches get evicted. But probably they are useful for burst-similar-load handling.

About txnLookup cache:

• we will think about it later. It require good eviction policy (geth does purge this cache at each re-org) and 1 transaction deserialization is less costly. So, maybe we don't need it.