Erigon Cycle takes ~19h

[mariel-sendblocks]

Hey,
i have an erigon node (v2.57.3) for polygon chain. My problem is that a full cycle is taking about ~19h.
I started the node from a snapshot. in the first few cycles (1-5) a cycle took about ~30h-60h.

My machine's spec - aws ec2 with 8 CPU, 64GB RAM, 10TB gpt3 SSD 16000 IOPS and 1000 thoughput.

The command I used to start my node : erigon --chain=bor-mainnet --datadir=/erigon-home --bor.heimdall=<some address> --private.api.addr=0.0.0.0:9090 --port=30303 --http --http.api=web3,eth,net,engine,debug,trace --ws --db.size.limit=10TB --db.pagesize=16K --batchSize=512mb --prof --pprof.addr=0.0.0.0 --pprof.port=6061

The 19h cycle is divided in the following manner (~) :

• Execution - ~3h
• HashState - ~3.5
• Intermediatehashes - ~6h
• CallTraces - 1h
• StorageHistoryIndex - 2h
• LogIndex - 3h

After a restart, the execution process in the first few hundreds of blocks ~19 blk/s but then decreased to 3-5 blk/s :

[INFO] [01-30|13:08:57.537] [txpool] stat                            pending=7849 baseFee=0 queued=27521 alloc=3.5GB sys=8.1GB
[INFO] [01-30|13:09:01.247] [7/15 Execution] Executed blocks         number=52892102 blk/s=18.0 tx/s=1691.7 Mgas/s=265.1 gasState=0.00 batch=9.5MB alloc=3.9GB sys=8.1GB
[INFO] [01-30|13:09:21.241] [7/15 Execution] Executed blocks         number=52892472 blk/s=18.5 tx/s=1817.4 Mgas/s=272.2 gasState=0.01 batch=19.2MB alloc=5.7GB sys=8.1GB
[INFO] [01-30|13:09:41.271] [7/15 Execution] Executed blocks         number=52892822 blk/s=17.5 tx/s=1709.4 Mgas/s=267.6 gasState=0.01 batch=29.2MB alloc=4.9GB sys=8.1GB
[INFO] [01-30|13:09:57.551] Got new checkpoint from heimdall         start=52922534 end=52923045 rootHash=0xd52a9fbc1b2821a0770e57ec59ef8448aedac712cc6936cd78389cb63d355086
[WARN] [01-30|13:09:57.551] Failed to whitelist checkpoint           err="missing blocks"
[WARN] [01-30|13:09:57.551] unable to handle whitelist checkpoint    err="missing blocks"
[INFO] [01-30|13:10:01.233] [7/15 Execution] Executed blocks         number=52893200 blk/s=18.9 tx/s=1785.9 Mgas/s=274.5 gasState=0.02 batch=39.7MB alloc=4.0GB sys=8.1GB
[INFO] [01-30|13:10:21.261] [7/15 Execution] Executed blocks         number=52893565 blk/s=18.2 tx/s=1797.7 Mgas/s=280.2 gasState=0.02 batch=49.7MB alloc=3.2GB sys=8.1GB
[INFO] [01-30|13:10:41.239] [7/15 Execution] Executed blocks         number=52893952 blk/s=19.4 tx/s=1847.7 Mgas/s=285.5 gasState=0.03 batch=61.5MB alloc=5.2GB sys=8.1GB
[INFO] [01-30|13:11:01.261] [7/15 Execution] Executed blocks         number=52894323 blk/s=18.5 tx/s=1813.3 Mgas/s=278.9 gasState=0.04 batch=72.1MB alloc=4.2GB sys=8.1GB
[INFO] [01-30|13:11:21.254] [7/15 Execution] Executed blocks         number=52894710 blk/s=19.4 tx/s=1731.7 Mgas/s=286.8 gasState=0.04 batch=83.2MB alloc=3.3GB sys=8.1GB
.....
After 7m:
...
[INFO] [01-30|13:18:21.278] [7/15 Execution] Executed blocks         number=52901683 blk/s=3.2 tx/s=253.5 Mgas/s=46.7 gasState=0.13 batch=279.0MB alloc=4.1GB sys=8.3GB
[INFO] [01-30|13:18:41.460] [7/15 Execution] Executed blocks         number=52901766 blk/s=4.1 tx/s=377.2 Mgas/s=77.4 gasState=0.14 batch=281.6MB alloc=4.9GB sys=8.3GB
[INFO] [01-30|13:19:01.330] [7/15 Execution] Executed blocks         number=52901866 blk/s=5.0 tx/s=374.3 Mgas/s=71.5 gasState=0.14 batch=284.0MB alloc=5.6GB sys=8.3GB
[INFO] [01-30|13:19:21.323] [7/15 Execution] Executed blocks         number=52901945 blk/s=4.0 tx/s=282.7 Mgas/s=65.5 gasState=0.14 batch=285.9MB alloc=6.2GB sys=8.3GB
[INFO] [01-30|13:19:41.686] [7/15 Execution] Executed blocks         number=52902018 blk/s=3.6 tx/s=331.6 Mgas/s=65.4 gasState=0.14 batch=288.0MB alloc=3.6GB sys=8.3GB

I checked also io stats with iostat during Execution stage:

iostat -xth 10 myDevice
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
                       5.8%    0.0%    1.9%   12.1%    0.0%   80.2%

     r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz Device
 1754.60      6.9M     0.00   0.0%    0.57     4.0k myDevice

     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz Device
   15.10      1.2M     0.20   1.3%    1.16    81.7k myDevice

     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz Device
    0.00      0.0k     0.00   0.0%    0.00     0.0k myDevice

     f/s f_await  aqu-sz  %util Device
    0.00    0.00    1.01 100.0% myDevice

I didnt see in aws' metrics that the volume reaches its limit:

• The Average queue length is ~1.2 most of the time.
• Average read latency - 0.5 ms/op
• Average write latency - 0.8 ms/op

Used also pprof to get more details about cpu and heap usage (profile of 60s).

memory top inuse space :

cpu top:

Memory & cpu usage :

top - 16:06:04 up 61 days, 19:56,  4 users,  load average: 1.59, 1.62, 1.63
MiB Mem :  63139.0 total,    409.6 free,  15906.0 used,  46823.5 buff/cache
MiB Swap:      0.0 total,      0.0 free,      0.0 used.  46593.0 avail Mem

     PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
  21130 10001     20   0   14.8t  53.3g  43.0g S    44.5       86.4     89:27.34 erigon

Appreciate if you can share your insights and any suggestion to improve the node's performance..

[taratorio]

#9147 (comment)