From 81f89c054cb11858ecf7d7d5ab4de4698ada3dc3 Mon Sep 17 00:00:00 2001
From: Paul Hauner <paul@paulhauner.com>
Date: Tue, 26 Nov 2019 09:09:26 +1100
Subject: [PATCH] Improve eth1 logging

---
 beacon_node/beacon_chain/src/eth1_chain.rs | 15 ++++++++++++---
 beacon_node/eth1/src/block_cache.rs        |  5 +++++
 beacon_node/eth1/src/service.rs            |  5 +++++
 beacon_node/src/config.rs                  |  2 +-
 4 files changed, 23 insertions(+), 4 deletions(-)

diff --git a/beacon_node/beacon_chain/src/eth1_chain.rs b/beacon_node/beacon_chain/src/eth1_chain.rs
index 6359a5cd93..5429ac32c7 100644
--- a/beacon_node/beacon_chain/src/eth1_chain.rs
+++ b/beacon_node/beacon_chain/src/eth1_chain.rs
@@ -4,7 +4,7 @@ use exit_future::Exit;
 use futures::Future;
 use integer_sqrt::IntegerSquareRoot;
 use rand::prelude::*;
-use slog::{crit, Logger};
+use slog::{crit, trace, Logger};
 use std::collections::HashMap;
 use std::iter::DoubleEndedIterator;
 use std::iter::FromIterator;
@@ -33,7 +33,7 @@ pub enum Error {
     /// voting period.
     UnableToGetPreviousStateRoot(BeaconStateError),
     /// The state required to find the previous eth1 block was not found in the store.
-    PreviousStateNotInDB,
+    PreviousStateNotInDB(Hash256),
     /// There was an error accessing an object in the database.
     StoreError(StoreError),
     /// The eth1 head block at the start of the eth1 voting period is unknown.
@@ -212,11 +212,20 @@ impl<T: EthSpec, S: Store> Eth1ChainBackend<T> for CachingEth1Backend<T, S> {
                 crit!(
                     self.log,
                     "Unable to find eth1 data sets";
+                    "earliest_cached_block" => self.core.earliest_block_timestamp(),
+                    "genesis_time" => state.genesis_time,
                     "outcome" => "casting random eth1 vote"
                 );
                 return Ok(random_eth1_data());
             };
 
+        trace!(
+            self.log,
+            "Found eth1 data sets";
+            "all_eth1_data" => all_eth1_data.len(),
+            "new_eth1_data" => new_eth1_data.len(),
+        );
+
         let valid_votes = collect_valid_votes(state, new_eth1_data, all_eth1_data);
 
         let eth1_data = if let Some(eth1_data) = find_winning_vote(valid_votes) {
@@ -307,7 +316,7 @@ fn eth1_block_hash_at_start_of_voting_period<T: EthSpec, S: Store>(
             .get::<BeaconState<T>>(&prev_state_root)
             .map_err(|e| Error::StoreError(e))?
             .map(|state| state.eth1_data.block_hash)
-            .ok_or_else(|| Error::PreviousStateNotInDB)
+            .ok_or_else(|| Error::PreviousStateNotInDB(*prev_state_root))
     }
 }
 
diff --git a/beacon_node/eth1/src/block_cache.rs b/beacon_node/eth1/src/block_cache.rs
index 1a6464ca76..3975f40563 100644
--- a/beacon_node/eth1/src/block_cache.rs
+++ b/beacon_node/eth1/src/block_cache.rs
@@ -54,6 +54,11 @@ impl BlockCache {
         self.blocks.is_empty()
     }
 
+    /// Returns the timestamp of the earliest block in the cache (if any).
+    pub fn earliest_block_timestamp(&self) -> Option<u64> {
+        self.blocks.first().map(|block| block.timestamp)
+    }
+
     /// Returns the highest block number stored.
     pub fn highest_block_number(&self) -> Option<u64> {
         self.blocks.last().map(|block| block.number)
diff --git a/beacon_node/eth1/src/service.rs b/beacon_node/eth1/src/service.rs
index 51f6877cdd..580727c374 100644
--- a/beacon_node/eth1/src/service.rs
+++ b/beacon_node/eth1/src/service.rs
@@ -168,6 +168,11 @@ impl Service {
         *(self.inner.block_cache.write()) = BlockCache::default();
     }
 
+    /// Returns the timestamp of the earliest block in the cache (if any).
+    pub fn earliest_block_timestamp(&self) -> Option<u64> {
+        self.inner.block_cache.read().earliest_block_timestamp()
+    }
+
     /// Returns the number of currently cached blocks.
     pub fn block_cache_len(&self) -> usize {
         self.blocks().read().len()
diff --git a/beacon_node/src/config.rs b/beacon_node/src/config.rs
index 63d0871740..1f81653d88 100644
--- a/beacon_node/src/config.rs
+++ b/beacon_node/src/config.rs
@@ -283,7 +283,7 @@ fn process_testnet_subcommand(
             // Note: these constants _should_ only be used during genesis to determine the genesis
             // time. This allows the testnet to start shortly after the time + validator count
             // conditions are satisfied, not 1-2 days.
-            spec.seconds_per_day = 1800;
+            spec.seconds_per_day = 60;
 
             client_config.eth1.follow_distance = 16;
             client_config.dummy_eth1_backend = false;