OffchainLabs / eth-pos-devnet

MIT License
103 stars 124 forks source link

Slot is higher than the finalized slot / Additional validators in devnet #33

Closed bilaljawed closed 10 months ago

bilaljawed commented 10 months ago

I need some expert opinion from someone who has run multiple nodes in devnet, @nisdas if you could help...

Currently I am able to run 2 nodes side by side Node 1: Geth + Beacon + Interop validators

Then I deposit 32 ETH (test tokens) to deposit contract to make a new validator

After 16-17 hours the validator shows up in the beacon api, i run second node using checkpoint sync and this happens, it seems that it syncs until the new validator came up then it stops


2023-08-30 11:50:28 time="2023-08-30 07:50:28" level=info msg="Processing block batch of size 21 starting from  0xc445761d... 29807/31997 - estimated time remaining 34m45s" blocksPerSecond=1.1 peers=1 prefix=initial-sync
2023-08-30 11:50:29 time="2023-08-30 07:50:29" level=warning msg="Recovering state summary" prefix=db root=0x86b6ce6bead4
2023-08-30 11:50:29 time="2023-08-30 07:50:29" level=warning msg="Skip processing batched blocks" error="could not process block in batch: missing state summary for checkpoint root" prefix=initial-sync
2023-08-30 11:50:29 time="2023-08-30 07:50:29" level=debug msg="Searching for non-skipped slot" headEpoch=14902 prefix=initial-sync start=30253 targetEpoch=14903
2023-08-30 11:50:29 time="2023-08-30 07:50:29" level=debug msg="Requesting blocks" capacity=3 count=2 peer=16Uiu2HAmCzfRuM8s6H4CfY6j5PyNFJqq82ysK5n7xT4iYVJS6viH prefix=initial-sync score="[0.0%, raw: 0.00,  blocks: 0/640]" start=30254 step=1
2023-08-30 11:50:30 time="2023-08-30 07:50:30" level=debug msg="Can not trigger event" epoch=14935 error="slot is higher than the finalized slot" event=tick highestExpectedSlot=29808 noRequiredPeersErrRetries=0 prefix=initial-sync start=29870
2023-08-30 11:50:30 time="2023-08-30 07:50:30" level=debug msg="Can not trigger event" epoch=14967 error="slot is higher than the finalized slot" event=tick highestExpectedSlot=29808 noRequiredPeersErrRetries=0 prefix=initial-sync start=29934
2023-08-30 11:50:30 time="2023-08-30 07:50:30" level=debug msg="Can not trigger event" epoch=14999 error="slot is higher than the finalized slot" event=tick highestExpectedSlot=29808 noRequiredPeersErrRetries=0 prefix=initial-sync start=29998
2023-08-30 11:50:30 time="2023-08-30 07:50:30" level=debug msg="Can not trigger event" epoch=15031 error="slot is higher than the finalized slot" event=tick highestExpectedSlot=29808 noRequiredPeersErrRetries=0 prefix=initial-sync start=30062
2023-08-30 11:50:30 time="2023-08-30 07:50:30" level=debug msg="Can not trigger event" epoch=15063 error="slot is higher than the finalized slot" event=tick highestExpectedSlot=29808 noRequiredPeersErrRetries=0 prefix=initial-sync start=30126
2023-08-30 11:50:30 time="2023-08-30 07:50:30" level=debug msg="Can not trigger event" epoch=15095 error="slot is higher than the finalized slot" event=tick highestExpectedSlot=29808 noRequiredPeersErrRetries=0 prefix=initial-sync start=30190
2023-08-30 11:50:30 time="2023-08-30 07:50:30" level=debug msg="Requesting blocks" capacity=2 count=64 peer=16Uiu2HAmCzfRuM8s6H4CfY6j5PyNFJqq82ysK5n7xT4iYVJS6viH prefix=initial-sync score="[0.0%, raw: 0.00,  blocks: 0/640]" start=29806 step=1
2023-08-30 11:50:30 time="2023-08-30 07:50:30" level=debug msg="Slowing down for rate limit" peer=16Uiu2HAmCzfRuM8s6H4CfY6j5PyNFJqq82ysK5n7xT4iYVJS6viH prefix=initial-sync
2023-08-30 11:50:30 time="2023-08-30 07:50:30" level=debug msg="Can not trigger event" epoch=15127 error="slot is higher than the finalized slot" event=tick highestExpectedSlot=29808 noRequiredPeersErrRetries=0 prefix=initial-sync start=30254

So then i tried to run the validator only using the rpc url of 1st beacon node and the validator is activated but cannot sign blocks, waiting for the last 2 hours but nothing, the validator balance is going down constantly..


time="2023-08-30 07:59:20" level=info msg="Submitted new sync contribution and proof" aggregatorIndex=5 bitsCount=39 blockRoot=0x985019af4ac9 prefix=validator slot=32263 slotStartTime=2023-08-30 07:59:19 +0000 UTC subcommitteeIndex=3 timeSinceSlotStart=1.995344044s
time="2023-08-30 07:59:21" level=error msg="Could not get sync committee contribution" error="rpc error: code = DeadlineExceeded desc = context deadline exceeded" prefix=validator
time="2023-08-30 07:59:21" level=info msg="Submitted new attestations" AggregatorIndices=[5] AttesterIndices=[5] BeaconBlockRoot=0x985019af4ac9 CommitteeIndex=0 Slot=32263 SourceEpoch=14912 SourceRoot=0x58586d8e7e98 TargetEpoch=16131 TargetRoot=0x7177948e4020 prefix=validator
time="2023-08-30 07:59:21" level=error msg="Could not report validator's rewards/penalties" error="rpc error: code = DeadlineExceeded desc = context deadline exceeded" prefix=validator
time="2023-08-30 07:59:21" level=info msg="Attestation schedule" attesterDutiesAtSlot=1 prefix=validator pubKeys=[0xac2026628af2] slot=32264 slotInEpoch=0 totalAttestersInEpoch=1
time="2023-08-30 07:59:21" level=info msg="Submitted new sync message" blockRoot=0x985019af4ac9 prefix=validator slot=32264 slotStartTime=2023-08-30 07:59:21 +0000 UTC timeSinceSlotStart=670.49099ms validatorIndex=5
time="2023-08-30 07:59:22" level=info msg="Submitted new attestations" AggregatorIndices=[5] AttesterIndices=[5] BeaconBlockRoot=0x985019af4ac9 CommitteeIndex=0 Slot=32264 SourceEpoch=14912 SourceRoot=0x58586d8e7e98 TargetEpoch=16132 TargetRoot=0x985019af4ac9 prefix=validator
time="2023-08-30 07:59:23" level=info msg="Submitted new sync message" blockRoot=0x985019af4ac9 prefix=validator slot=32265 slotStartTime=2023-08-30 07:59:23 +0000 UTC timeSinceSlotStart=670.258032ms validatorIndex=5
time="2023-08-30 07:59:23" level=info msg="Previous epoch voting summary" correctlyVotedHead=false correctlyVotedSource=false correctlyVotedTarget=false epoch=16131 inactivityScore=1866 newBalance=27.524663114 oldBalance=27.528994013 percentChange="-0.01573%" percentChangeSinceStart="-5.81242%" prefix=validator pubKey=0xac2026628af2 startBalance=29.223241541
time="2023-08-30 07:59:25" level=info msg="Proposal schedule" prefix=validator pubKey=0xac2026628af2 slot=32266
time="2023-08-30 07:59:25" level=info msg="Attestation schedule" attesterDutiesAtSlot=1 prefix=validator pubKeys=[0xac2026628af2] slot=32267 slotInEpoch=1 timeTillDuty=2s totalAttestersInEpoch=1
time="2023-08-30 07:59:25" level=info msg="Submitted new block" blockRoot=0xe78a8bad8e9d fork=capella gasUtilized=0 graffiti="" numAttestations=1 numDeposits=0 parentHash=0x831af61fee40 payloadHash=0x563519f22fc7 prefix=validator pubKey=0xac2026628af2 slot=32266 txCount=0 withdrawalCount=0
time="2023-08-30 07:59:25" level=info msg="Submitted new sync message" blockRoot=0xe78a8bad8e9d prefix=validator slot=32266 slotStartTime=2023-08-30 07:59:25 +0000 UTC timeSinceSlotStart=670.260854ms validatorIndex=5
time="2023-08-30 07:59:27" level=info msg="Submitted new sync message" blockRoot=0xe78a8bad8e9d prefix=validator slot=32267 slotStartTime=2023-08-30 07:59:27 +0000 UTC timeSinceSlotStart=670.265734ms validatorIndex=5
time="2023-08-30 07:59:28" level=info msg="Submitted new attestations" AggregatorIndices=[5] AttesterIndices=[5] BeaconBlockRoot=0xe78a8bad8e9d CommitteeIndex=0 Slot=32267 SourceEpoch=14912 SourceRoot=0x58586d8e7e98 TargetEpoch=16133 TargetRoot=0xe78a8bad8e9d prefix=validator
time="2023-08-30 07:59:28" level=info msg="Previous epoch voting summary" correctlyVotedHead=false correctlyVotedSource=false correctlyVotedTarget=true epoch=16132 inactivityScore=1865 newBalance=27.523649442 oldBalance=27.524902494 percentChange="-0.00455%" percentChangeSinceStart="-5.81589%" prefix=validator pubKey=0xac2026628af2 startBalance=29.223241541
time="2023-08-30 07:59:28" level=info msg="Previous epoch aggregated voting summary" attestationInclusionPct="100%" averageInactivityScore=1865 correctlyVotedHeadPct="0%" correctlyVotedSourcePct="0%" correctlyVotedTargetPct="100%" epoch=16132 prefix=validator
time="2023-08-30 07:59:28" level=info msg="Vote summary since launch" attestationsInclusionPct="100%" correctlyVotedHeadPct="61%" correctlyVotedSourcePct="61%" correctlyVotedTargetPct="100%" numberOfEpochs=783 pctChangeCombinedBalance="-5.81160%" prefix=validator
time="2023-08-30 07:59:29" level=info msg="Attestation schedule" attesterDutiesAtSlot=1 prefix=validator pubKeys=[0xac2026628af2] slot=32269 slotInEpoch=1 timeTillDuty=2s totalAttestersInEpoch=1
time="2023-08-30 07:59:29" level=info msg="Proposal schedule" prefix=validator pubKey=0xac2026628af2 slot=32269 timeTillDuty=2s
time="2023-08-30 07:59:29" level=info msg="Submitted new sync message" blockRoot=0xe78a8bad8e9d prefix=validator slot=32268 slotStartTime=2023-08-30 07:59:29 +0000 UTC timeSinceSlotStart=671.261723ms validatorIndex=5
time="2023-08-30 07:59:31" level=info msg="Submitted new block" blockRoot=0xdc900cca9b95 fork=capella gasUtilized=0 graffiti="" numAttestations=1 numDeposits=0 parentHash=0x563519f22fc7 payloadHash=0xbc8f79cf84bd prefix=validator pubKey=0xac2026628af2 slot=32269 txCount=0 withdrawalCount=0

Appreciate your help @nisdas

nisdas commented 10 months ago

This is the real error here:

2023-08-30 11:50:29 time="2023-08-30 07:50:29" level=warning msg="Skip processing batched blocks" error="could not process block in batch: missing state summary for checkpoint root" prefix=initial-sync

It can't sync here because of an issue with the checkpoint, maybe you can start pasting all the flags you have used for the second node in order to run it.

bilaljawed commented 10 months ago

Thanks will update when i have more tests on this