update validator key cache on startup (#2760)

* update validator key cache on startup

Versions prior to 1.1.0 do not write a validator key cache at all.

Versions from 1.4.0 and upwards require an immutable validator key cache
to verify blocks - normally, block verification fills the cache but that
assumes that at least one block was verified by a version that has the
key cache.

Taken together, this breaks direct upgrades from anything <1.1.0 to
1.4.0.

The fix is simply to refresh fill the cache from an existing state on
startup.

* also log serious block validation failures at info level

beacon_chain/beacon_chain_db.nim

@@ -799,3 +799,15 @@ iterator getAncestorSummaries*(db: BeaconChainDB, root: Eth2Digest):
       newSummaries.add(res)
 
     res.root = res.summary.parent_root
+
+# Test operations used to create broken and/or legacy database
+
+proc putStateV0*(db: BeaconChainDB, key: Eth2Digest, value: BeaconState) =
+  # Writes to KVStore, as done in 1.0.12 and earlier
+  db.v0.backend.putSnappySSZ(subkey(type value, key), value)
+
+proc putBlockV0*(db: BeaconChainDB, value: TrustedSignedBeaconBlock) =
+  # Write to KVStore, as done in 1.0.12 and earlier
+  # In particular, no summary is written here - it should be recreated
+  # automatically
+  db.v0.backend.putSnappySSZ(subkey(SignedBeaconBlock, value.root), value)

beacon_chain/consensus_object_pools/block_clearance.nim

@@ -205,11 +205,15 @@ proc addRawBlockKnownParent(
        onBlockAdded: OnBlockAdded
      ): Result[BlockRef, (ValidationResult, BlockError)] =
   ## Add a block whose parent is known, after performing validity checks
+  logScope:
+    blck = shortLog(signedBlock.message)
+    blockRoot = shortLog(signedBlock.root)
+    signature = shortLog(signedBlock.signature)
 
   if parent.slot >= signedBlock.message.slot:
     # A block whose parent is newer than the block itself is clearly invalid -
     # discard it immediately
-    debug "Invalid block slot",
+    info "Block with invalid parent, dropping",
       parentBlock = shortLog(parent)
 
     return err((ValidationResult.Reject, Invalid))
@@ -225,7 +229,7 @@ proc addRawBlockKnownParent(
     # correct - from their point of view, the head block they have is the
     # latest thing that happened on the chain and they're performing their
     # duty correctly.
-    debug "Unviable block, dropping",
+    info "Unviable block, dropping",
       finalizedHead = shortLog(dag.finalizedHead),
       tail = shortLog(dag.tail)
 
@@ -249,11 +253,15 @@ proc addRawBlockKnownParent(
     # TODO: remove skipBLSValidation
 
     var sigs: seq[SignatureSet]
-    if sigs.collectSignatureSets(
-        signedBlock, dag.db.immutableValidators, dag.clearanceState, cache).isErr():
+    if (let e = sigs.collectSignatureSets(
+        signedBlock, dag.db.immutableValidators, dag.clearanceState, cache); e.isErr()):
+      info "Unable to load signature sets",
+        err = e.error()
+
       # A PublicKey or Signature isn't on the BLS12-381 curve
       return err((ValidationResult.Reject, Invalid))
     if not quarantine.batchVerify(sigs):
+      info "Block signature verification failed"
       return err((ValidationResult.Reject, Invalid))
 
   let sigVerifyTick = Moment.now()

beacon_chain/consensus_object_pools/blockchain_dag.nim

@@ -440,6 +440,10 @@ proc init*(T: type ChainDAGRef,
   # Pruning metadata
   dag.lastPrunePoint = dag.finalizedHead
 
+  # Fill validator key cache in case we're loading an old database that doesn't
+  # have a cache
+  dag.updateValidatorKeys(getStateField(dag.headState, validators).asSeq())
+
   info "Block dag initialized",
     head = shortLog(headRef),
     finalizedHead = shortLog(dag.finalizedHead),

tests/test_block_pool.nim

@@ -12,9 +12,10 @@ import
   unittest2,
   stew/assign2,
   eth/keys,
-  ../beacon_chain/spec/[datatypes, digest, helpers, state_transition, presets],
+  ../beacon_chain/spec/[
+    beaconstate, datatypes, digest, helpers, state_transition, presets],
   ../beacon_chain/beacon_node_types,
-  ../beacon_chain/[beacon_chain_db, ssz],
+  ../beacon_chain/[beacon_chain_db, ssz, extras],
   ../beacon_chain/consensus_object_pools/[
     blockchain_dag, block_quarantine, block_clearance, statedata_helpers],
   ./testutil, ./testdbutil, ./testblockutil
@@ -523,3 +524,39 @@ suite "chain DAG finalization tests" & preset():
       dag2.finalizedHead.blck.root == dag.finalizedHead.blck.root
       dag2.finalizedHead.slot == dag.finalizedHead.slot
       hash_tree_root(dag2.headState) == hash_tree_root(dag.headState)
+
+suite "Old database versions" & preset():
+  setup:
+    let
+      genState = initialize_beacon_state_from_eth1(
+        defaultRuntimePreset,
+        Eth2Digest(),
+        0,
+        makeInitialDeposits(SLOTS_PER_EPOCH.uint64, flags = {skipBlsValidation}),
+        {skipBlsValidation})
+      genBlock = get_initial_beacon_block(genState[])
+      quarantine = QuarantineRef.init(keys.newRng())
+
+  test "pre-1.1.0":
+    # only kvstore, no immutable validator keys
+
+    let db = BeaconChainDB.new(defaultRuntimePreset, "", inMemory = true)
+
+    # preInit a database to a v1.0.12 state
+    db.putStateV0(genBlock.message.state_root, genState[])
+    db.putBlockV0(genBlock)
+    db.putTailBlock(genBlock.root)
+    db.putHeadBlock(genBlock.root)
+    db.putStateRoot(genBlock.root, genState.slot, genBlock.message.state_root)
+    db.putGenesisBlockRoot(genBlock.root)
+
+    var
+      dag = init(ChainDAGRef, defaultRuntimePreset, db)
+      state = newClone(dag.headState.data)
+      cache = StateCache()
+      att0 = makeFullAttestations(state[], dag.tail.root, 0.Slot, cache)
+      b1 = addTestBlock(state[], dag.tail.root, cache, attestations = att0)
+      b1Add = dag.addRawBlock(quarantine, b1, nil)
+
+    check:
+      b1Add.isOk()