Testnet stability (#451)

* Change reduced tree for adding weightless node

* Add more comments for reduced tree fork choice

* Small refactor on reduced tree for readability

* Move test_harness forking logic into itself

* Add new `AncestorIter` trait to store

* Add unfinished tests to fork choice

* Make `beacon_state.genesis_block_root` public

* Add failing lmd_ghost fork choice tests

* Extend fork_choice tests, create failing test

* Implement Debug for generic ReducedTree

* Add lazy_static to fork choice tests

* Add verify_integrity fn to reduced tree

* Fix bugs in reduced tree

* Ensure all reduced tree tests verify integrity

* Slightly alter reduce tree test params

* Add (failing) reduced tree test

* Fix bug in fork choice

Iter ancestors was not working well with skip slots

* Put maximum depth for common ancestor search

Ensures that we don't search back past the finalized root.

* Add basic finalization tests for reduced tree

* Change fork choice to use beacon_block_root

Previously it was using target_root, which was wrong

* Change reduced tree for adding weightless node

* Add more comments for reduced tree fork choice

* Small refactor on reduced tree for readability

* Move test_harness forking logic into itself

* Add new `AncestorIter` trait to store

* Add unfinished tests to fork choice

* Make `beacon_state.genesis_block_root` public

* Add failing lmd_ghost fork choice tests

* Extend fork_choice tests, create failing test

* Implement Debug for generic ReducedTree

* Add lazy_static to fork choice tests

* Add verify_integrity fn to reduced tree

* Fix bugs in reduced tree

* Ensure all reduced tree tests verify integrity

* Slightly alter reduce tree test params

* Add (failing) reduced tree test

* Fix bug in fork choice

Iter ancestors was not working well with skip slots

* Put maximum depth for common ancestor search

Ensures that we don't search back past the finalized root.

* Add basic finalization tests for reduced tree

* Add network dir CLI flag

* Simplify "NewSlot" log message

* Rename network-dir CLI flag

* Change fork choice to use beacon_block_root

Previously it was using target_root, which was wrong

* Update db dir size for metrics

* Change slog to use `FullFormat` logging

* Update some comments and log formatting

* Add prom gauge for best block root

* Only add known target blocks to fork choice

* Add finalized and justified root prom metrics

* Add CLI flag for setting log level

* Add logger to beacon chain

* Add debug-level CLI flag to validator

* Allow block processing if fork choice fails

* Create warn log when there's low libp2p peer count

* Minor change to logging

* Make ancestor iter return option

* Disable fork choice test when !debug_assertions

* Fix type, removed code fragment

* Tidy some borrow-checker evading

* Lower reduced tree random test iterations

beacon_node/beacon_chain/src/beacon_chain.rs

@@ -8,6 +8,7 @@ use log::trace;
 use operation_pool::DepositInsertStatus;
 use operation_pool::{OperationPool, PersistedOperationPool};
 use parking_lot::{RwLock, RwLockReadGuard};
+use slog::{error, info, warn, Logger};
 use slot_clock::SlotClock;
 use state_processing::per_block_processing::errors::{
     AttestationValidationError, AttesterSlashingValidationError, DepositValidationError,
@@ -83,6 +84,8 @@ pub struct BeaconChain<T: BeaconChainTypes> {
     pub fork_choice: ForkChoice<T>,
     /// Stores metrics about this `BeaconChain`.
     pub metrics: Metrics,
+    /// Logging to CLI, etc.
+    log: Logger,
 }
 
 impl<T: BeaconChainTypes> BeaconChain<T> {
@@ -93,6 +96,7 @@ impl<T: BeaconChainTypes> BeaconChain<T> {
         mut genesis_state: BeaconState<T::EthSpec>,
         genesis_block: BeaconBlock,
         spec: ChainSpec,
+        log: Logger,
     ) -> Result<Self, Error> {
         genesis_state.build_all_caches(&spec)?;
 
@@ -123,6 +127,7 @@ impl<T: BeaconChainTypes> BeaconChain<T> {
             fork_choice: ForkChoice::new(store.clone(), &genesis_block, genesis_block_root),
             metrics: Metrics::new()?,
             store,
+            log,
         })
     }
 
@@ -130,6 +135,7 @@ impl<T: BeaconChainTypes> BeaconChain<T> {
     pub fn from_store(
         store: Arc<T::Store>,
         spec: ChainSpec,
+        log: Logger,
     ) -> Result<Option<BeaconChain<T>>, Error> {
         let key = Hash256::from_slice(&BEACON_CHAIN_DB_KEY.as_bytes());
         let p: PersistedBeaconChain<T> = match store.get(&key) {
@@ -159,6 +165,7 @@ impl<T: BeaconChainTypes> BeaconChain<T> {
             genesis_block_root: p.genesis_block_root,
             metrics: Metrics::new()?,
             store,
+            log,
         }))
     }
 
@@ -646,13 +653,27 @@ impl<T: BeaconChainTypes> BeaconChain<T> {
         self.store.put(&state_root, &state)?;
 
         // Register the new block with the fork choice service.
-        self.fork_choice.process_block(&state, &block, block_root)?;
+        if let Err(e) = self.fork_choice.process_block(&state, &block, block_root) {
+            error!(
+                self.log,
+                "fork choice failed to process_block";
+                "error" => format!("{:?}", e),
+                "block_root" =>  format!("{}", block_root),
+                "block_slot" => format!("{}", block.slot)
+            )
+        }
 
         // Execute the fork choice algorithm, enthroning a new head if discovered.
         //
         // Note: in the future we may choose to run fork-choice less often, potentially based upon
         // some heuristic around number of attestations seen for the block.
-        self.fork_choice()?;
+        if let Err(e) = self.fork_choice() {
+            error!(
+                self.log,
+                "fork choice failed to find head";
+                "error" => format!("{:?}", e)
+            )
+        };
 
         self.metrics.block_processing_successes.inc();
         self.metrics
@@ -780,9 +801,27 @@ impl<T: BeaconChainTypes> BeaconChain<T> {
                 .get(&beacon_state_root)?
                 .ok_or_else(|| Error::MissingBeaconState(beacon_state_root))?;
 
+            let previous_slot = self.head().beacon_block.slot;
+            let new_slot = beacon_block.slot;
+
             // If we switched to a new chain (instead of building atop the present chain).
             if self.head().beacon_block_root != beacon_block.previous_block_root {
                 self.metrics.fork_choice_reorg_count.inc();
+                warn!(
+                    self.log,
+                    "Beacon chain re-org";
+                    "previous_slot" => previous_slot,
+                    "new_slot" => new_slot
+                );
+            } else {
+                info!(
+                    self.log,
+                    "new head block";
+                    "justified_root" => format!("{}", beacon_state.current_justified_root),
+                    "finalized_root" => format!("{}", beacon_state.finalized_root),
+                    "root" => format!("{}", beacon_block_root),
+                    "slot" => new_slot,
+                );
             };
 
             let old_finalized_epoch = self.head().beacon_state.finalized_epoch;

beacon_node/beacon_chain/src/fork_choice.rs

@@ -18,6 +18,7 @@ pub enum Error {
 
 pub struct ForkChoice<T: BeaconChainTypes> {
     backend: T::LmdGhost,
+    store: Arc<T::Store>,
     /// Used for resolving the `0x00..00` alias back to genesis.
     ///
     /// Does not necessarily need to be the _actual_ genesis, it suffices to be the finalized root
@@ -36,6 +37,7 @@ impl<T: BeaconChainTypes> ForkChoice<T> {
         genesis_block_root: Hash256,
     ) -> Self {
         Self {
+            store: store.clone(),
             backend: T::LmdGhost::new(store, genesis_block, genesis_block_root),
             genesis_block_root,
         }
@@ -125,13 +127,6 @@ impl<T: BeaconChainTypes> ForkChoice<T> {
         state: &BeaconState<T::EthSpec>,
         attestation: &Attestation,
     ) -> Result<()> {
-        let validator_indices = get_attesting_indices_unsorted(
-            state,
-            &attestation.data,
-            &attestation.aggregation_bitfield,
-        )?;
-        let block_slot = state.get_attestation_slot(&attestation.data)?;
-
         let block_hash = attestation.data.beacon_block_root;
 
         // Ignore any attestations to the zero hash.
@@ -147,7 +142,22 @@ impl<T: BeaconChainTypes> ForkChoice<T> {
         // (1) becomes weird once we hit finality and fork choice drops the genesis block. (2) is
         // fine because votes to the genesis block are not useful; all validators implicitly attest
         // to genesis just by being present in the chain.
-        if block_hash != Hash256::zero() {
+        //
+        // Additionally, don't add any block hash to fork choice unless we have imported the block.
+        if block_hash != Hash256::zero()
+            && self
+                .store
+                .exists::<BeaconBlock>(&block_hash)
+                .unwrap_or(false)
+        {
+            let validator_indices = get_attesting_indices_unsorted(
+                state,
+                &attestation.data,
+                &attestation.aggregation_bitfield,
+            )?;
+
+            let block_slot = state.get_attestation_slot(&attestation.data)?;
+
             for validator_index in validator_indices {
                 self.backend
                     .process_attestation(validator_index, block_hash, block_slot)?;

beacon_node/beacon_chain/src/test_utils.rs

@@ -1,5 +1,6 @@
 use crate::{BeaconChain, BeaconChainTypes, BlockProcessingOutcome};
 use lmd_ghost::LmdGhost;
+use sloggers::{null::NullLoggerBuilder, Build};
 use slot_clock::SlotClock;
 use slot_clock::TestingSlotClock;
 use state_processing::per_slot_processing;
@@ -94,6 +95,9 @@ where
         let mut genesis_block = BeaconBlock::empty(&spec);
         genesis_block.state_root = Hash256::from_slice(&genesis_state.tree_hash_root());
 
+        let builder = NullLoggerBuilder;
+        let log = builder.build().expect("logger should build");
+
         // Slot clock
         let slot_clock = TestingSlotClock::new(
             spec.genesis_slot,
@@ -107,6 +111,7 @@ where
             genesis_state,
             genesis_block,
             spec.clone(),
+            log,
         )
         .expect("Terminate if beacon chain generation fails");