Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

"Performance warning: 4.3 s execution time for eth_getBlockByNumber" warning on indexer node after exhausting all RSS on instance. #1981

Open
oleksandrSydorenkoJ opened this issue Sep 9, 2024 · 2 comments
Assignees
Labels
Milestone

Comments

@oleksandrSydorenkoJ
Copy link

oleksandrSydorenkoJ commented Sep 9, 2024

Describe the bug
The indexer node continuously catches up with new blocks, and on slower instances, this prolonged process slows Skaled's JSON-RPC server.

Preconditions
Whitelisted IP for Instance with 4GB RSS, 2 cores
The long-turn load tests of token transfer with 100k gas usage

Versions:
skalenetwork/schain:3.19.1

To Reproduce

  1. Run indexer node from 0 block
  2. Send eth_getBlockByNumber("latest") in a loop
  3. Run load tests on the core nodes (at least 300 transactions token transfers per block)
  4. Wait for 6 days
  5. Send eth_getBlockByNumber on the indexer endpoint

Expected behavior
The "eth_getBlockByNumber" call should be processed in less than 1 second

Actual state
After exhausting all RSS on the instance (4GB), Skaled's JSON-RPC server is slow down and throws the "Performance warning" logs.
Indexer node is behind core node by 30k blocks

2024-09-09 11:15:59.099509   Performance warning: 1.545505 seconds execution time for eth_getBlockByNumber call with id=1 when called from origin http://127.0.0.1:39738 through server with index=0
2024-09-09 11:15:59.099912   SWT:4449:BFT:4513
2024-09-09 11:15:59.099934   TQBYTES:CTQ:0:FTQ:0:TQSIZE:CTQ:0:FTQ:0
[2024-09-09 11:15:59.102] [8:main] [info] 1496491:BLOCK_COMMITED: PRPSR:13:BID: 1496492:ROOT:12390051706433997174657264043132457667126472190155056832213590207262755263903:HASH:af0d112e:BLOCK_TXS:160:DMSG:0:TPRPS:413:MPRPS:0:RPRPS:0:TXS:157075:TXLS:413:MGS:0:INSTS:0:BPS:0:HDRS:2:SOCK:1:FDS:3955:PRT:0:BTA:110329256:BSA:0:TPS:0:LWT:0:LRT:0:LWC:46930:LRC:46536:STAMP:1725827128.756
2024-09-09 11:15:59.239174   Block sealed #1496492 (#2c3b1289…)
2024-09-09 11:15:59.239223   Block stats:BN:1496491:BTS:1725827127:TXS:480:HDRS:12:LOGS:8284:SENGS:1:TXRS:8244:BLCKS:3:ACCS:199:BQS:1:BDS:59:TSS:0:UTX:0:VTX:0:CMM:9100111:KDS:31
2024-09-09 11:15:59.239902   Block 1496492 DB usage is 222753. Piece DB usage is 226853169 bytes
2024-09-09 11:16:05.126912   Performance warning: 4.059041 seconds execution time for eth_getBlockByNumber call with id=741 when called from origin http://1.1.1.1:53160 through server with index=0
2024-09-09 11:16:05.657774   Performance warning: 6.267574 seconds execution time for eth_blockNumber call with id=1 when called from origin http://127.0.0.1:39758 through server with index=0
2024-09-09 11:16:05.659372   SWT:6491:BFT:6559
2024-09-09 11:16:05.659403   TQBYTES:CTQ:0:FTQ:0:TQSIZE:CTQ:0:FTQ:0
[2024-09-09 11:16:05.662] [8:main] [info] 1496492:BLOCK_COMMITED: PRPSR:14:BID: 1496493:ROOT:12390051706433997174657264043132457667126472190155056832213590207262755263903:HASH:38830abc:BLOCK_TXS:822:DMSG:0:TPRPS:413:MPRPS:0:RPRPS:0:TXS:157075:TXLS:413:MGS:0:INSTS:0:BPS:0:HDRS:2:SOCK:1:FDS:3955:PRT:0:BTA:110322204:BSA:0:TPS:0:LWT:0:LRT:0:LWC:46933:LRC:46541:STAMP:1725827129.931
2024-09-09 11:16:06.885109   Block sealed #1496493 (#6ef73046…)
2024-09-09 11:16:06.885167   Block stats:BN:1496492:BTS:1725827128:TXS:2466:HDRS:12:LOGS:9768:SENGS:1:TXRS:9728:BLCKS:3:ACCS:199:BQS:1:BDS:60:TSS:0:UTX:0:VTX:0:CMM:9302742:KDS:31
2024-09-09 11:16:06.888417   Block 1496493 DB usage is 1141508. Piece DB usage is 227994677 bytes
2024-09-09 11:16:11.314201   SWT:5582:BFT:5654
...
2024-09-09 11:16:21.307435   Block stats:BN:1496495:BTS:1725827134:TXS:1014:HDRS:12:LOGS:10257:SENGS:1:TXRS:10217:BLCKS:3:ACCS:199:BQS:1:BDS:62:TSS:0:UTX:0:VTX:0:CMM:10846313:KDS:31
2024-09-09 11:16:23.294857   Performance warning: 1.449030 seconds execution time for eth_getBlockByNumber call with id=747 when called from origin http://1.1.1.1:53160 through server with index=0
2024-09-09 11:16:23.294870   Block 1496496 DB usage is 469724. Piece DB usage is 229347372 bytes
2024-09-09 11:16:27.806283   Performance warning: 4.369296 seconds execution time for eth_getBlockByNumber call with id=748 when called from origin http://1.1.1.1:53160 through server with index=0

@oleksandrSydorenkoJ
Copy link
Author

> eth.syncing
{
  currentBlock: 1497073,
  healedBytecodeBytes: 0,
  healedBytecodes: 0,
  healedTrienodeBytes: 0,
  healedTrienodes: 0,
  healingBytecode: 0,
  healingTrienodes: 0,
  highestBlock: 1523128,
  startingBlock: 1497001,
  syncedAccountBytes: 0,
  syncedAccounts: 0,
  syncedBytecodeBytes: 0,
  syncedBytecodes: 0,
  syncedStorage: 0,
  syncedStorageBytes: 0,
  txIndexFinishedBlocks: 0,
  txIndexRemainingBlocks: 0
}

@DmytroNazarenko DmytroNazarenko added this to the SKALE 3.2 milestone Sep 9, 2024
@PolinaKiporenko
Copy link
Contributor

Could be fixed by #1545

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
Status: No status
Development

No branches or pull requests

4 participants