Block Validation Rule Performance

[ajlopez]

Informal run of long synchronization againts RSK testnet, produced these logs describing the process of a block

2019-11-02-17:37:40.402 TRACE [blocksyncservice]  Trying to add to blockchain
2019-11-02-17:37:40.402 TRACE [blocksyncservice]  Trying to add block 137713 52667b
2019-11-02-17:37:40.402 TRACE [blockchain]  Try connect block hash: 52667b, number: 137713
2019-11-02-17:37:40.402 TRACE [blockchain]  Start try connect
2019-11-02-17:37:40.402 TRACE [blockchain]  get current state
2019-11-02-17:37:40.402 DEBUG [blockvalidator]  Validating block 52667b 137713
2019-11-02-17:37:40.402 DEBUG [blockvalidator]  Validating block 52667b 137713
2019-11-02-17:37:40.402 DEBUG [blockvalidator]  Validating header 5de60c 137711
2019-11-02-17:37:40.402 DEBUG [blockvalidator]  Rule passed co.rsk.validators.ProofOfWorkRule
2019-11-02-17:37:40.433 DEBUG [blockvalidator]  Rule passed co.rsk.validators.ForkDetectionDataRule
2019-11-02-17:37:40.433 DEBUG [blockvalidator]  Rule passed co.rsk.validators.BlockTimeStampValidationRule
2019-11-02-17:37:40.433 DEBUG [blockvalidator]  Rule passed co.rsk.validators.ValidGasUsedRule
2019-11-02-17:37:40.433 DEBUG [blockvalidator]  Validating header parent 5de60c 137711
2019-11-02-17:37:40.433 DEBUG [blockvalidator]  Rule passed co.rsk.validators.PrevMinGasPriceRule
2019-11-02-17:37:40.433 DEBUG [blockvalidator]  Rule passed co.rsk.validators.BlockParentNumberRule
2019-11-02-17:37:40.433 DEBUG [blockvalidator]  Rule passed co.rsk.validators.BlockTimeStampValidationRule
2019-11-02-17:37:40.433 DEBUG [blockvalidator]  Rule passed co.rsk.validators.BlockDifficultyRule
2019-11-02-17:37:40.433 DEBUG [blockvalidator]  Rule passed co.rsk.validators.BlockParentGasLimitRule
2019-11-02-17:37:40.433 TRACE [blockchain]  execute start

Notice that many log items have the SAME timestamp. Except the process of ForkDetectionDataRule, with a duration of 0.03 seconds (in this machine, context, etc)

This rule is executed ten times if the block has TEN uncles. And when the validation is run twice, it is executed TWENTY times, yielding 0.6 seconds only in block validation. In many circunstance, the rest of the block is executed under 0.1 seconds (involving storage, execution of transactions, receipts, etc), so the time employed by this rule seems excesive.

Recommendations:

• Maybe the rule could be executed only 1 of n blocks
• Maybe it is not needed to apply to the block uncles
• Consider optimizations

[SergioDemianLerner]

Having 10 uncles is not the average case, but I totally agree this must be addressed.

[SergioDemianLerner]

Make sure the delay is reproducible (to discard cases where it is due to coarse clock granularity)

[SergioDemianLerner]

As far as I remember, this issue is solved very easily re-using the cache created by ForkDetectionDataRule. Since the issue is very old, I will check again the code.

[SergioDemianLerner]

There are 3 problems:

1) The first problem is that for each uncle, a new class ConsensusValidationMainchainViewImpl is created and the block headers are pulled from the block store again and again. What is needed is to have a single ConsensusValidationMainchainView object that is created when a block needs to be processed, containing N headers from the current block. Here N = REQUIRED_NUMBER_OF_BLOCKS_FOR_FORK_DETECTION_CALCULATION + uncleListLimit Currently this is N = 449+10 = 559.

The ForkDetectionDataCalculator class method buildCommitToParentsVector() should receive an offset (between 0 and 10) so that it can access the data at the correct place

2) The second problem is that ConsensusValidationMainchainView does not cache the Nonce LSB, but the RSK block header. Each time the nonce LSB is required, the bitcoin block is created, and double-hashed. The ConsensusValidationMainchainView should contain at each position two fields: the block header and the cached nonce LSB.

3) Most of the items in the ConsensusValidationMainchainView are unused, because the fork detection mechanism only looks for blocks whose height is == 0 (mod 64). (64 is the CPV_JUMP_FACTOR). Therefore most of the headers that are read into the view are never accessed. It would be faster just to load the block headers (by number, not by hash) at positions i*64 for i = 0.. (559/64+1).