Add skew to timestamp current time comparison

Previously timestamp validation would fail if the timestamp was in the
future, now a 3 second window is allowed to occur to account for skew
between consensus nodes.

consensus/enclave/mock/src/lib.rs

@@ -351,7 +351,7 @@ impl ConsensusEnclave for ConsensusServiceMockEnclave {
         };
 
         let timestamp = if block_version.timestamps_are_supported() {
-            parent_block.timestamp + 1
+            inputs.timestamp
         } else {
             0
         };

consensus/service/src/byzantine_ledger/worker.rs

@@ -880,6 +880,12 @@ impl<
             .get_root_tx_out_membership_element()
             .expect("Failed getting root tx out membership element");
 
+        // We use the max timestamp as that should be the closest time to "now".
+        // i.e. it may have taken 100ms to process the block. The last
+        // timestamp, in an ideal system, may be 100ms later than the first
+        // timestamp in the values, but should still be slightly before now.
+        // Using the max timestamp is also called out in the
+        // [Stellar Whitepaper](https://www.stellar.org/papers/stellar-consensus-protocol).
         let timestamp = timestamps.into_iter().max().unwrap_or(0);
 
         // Request the enclave to form the next block.

consensus/service/src/mint_tx_manager/mod.rs

@@ -70,7 +70,7 @@ impl<L: Ledger> MintTxManager for MintTxManagerImpl<L> {
         let latest_block = self.ledger_db.get_latest_block()?;
 
         if let Some(timestamp) = timestamp {
-            timestamp_validator::validate(timestamp, &latest_block)?;
+            timestamp_validator::validate_with_logger(timestamp, &latest_block, &self.logger)?;
         }
 
         // Ensure that we have not seen this transaction before.
@@ -125,7 +125,7 @@ impl<L: Ledger> MintTxManager for MintTxManagerImpl<L> {
         let latest_block = self.ledger_db.get_latest_block()?;
 
         if let Some(timestamp) = timestamp {
-            timestamp_validator::validate(timestamp, &latest_block)?;
+            timestamp_validator::validate_with_logger(timestamp, &latest_block, &self.logger)?;
         }
 
         // Ensure that we have not seen this transaction before.

consensus/service/src/timestamp_validator.rs

@@ -2,15 +2,28 @@
 
 use displaydoc::Display;
 use mc_blockchain_types::Block;
+use mc_common::logger::{log, Logger};
 
 /// Provides logic for validating a timestamp used in consensus
 
 const MAX_TIMESTAMP_AGE: u64 = 30 * 1000; // 30 seconds
 
+/// The maximum allowed skew between the system time and the timestamp. This
+/// allows the system time to be a bit behind the timestamp.
+/// The reason for this is that during consensus multiple nodes will be looking
+/// at the time and those nodes may have skew between their clocks. If the node
+/// with the latest time proposes a value, it's possible that the other nodes
+/// will reject it because the timestamp is in the future.
+///
+/// The 3 seconds is taken from the `signed_at` values from the first 2 million
+/// blocks of the blockchain. Throwing away significant outlier nodes most nodes
+/// were almost always within 3 seconds of each other.
+const ALLOWED_FUTURE_SKEW: u64 = 3 * 1000;
+
 /// Errors related to validating timestamps
 #[derive(Clone, Debug, Display, Eq, PartialEq)]
 pub enum Error {
-    /// The timestamp is in the future now: {0}, timestamp: {1}
+    /// The timestamp is too far in the future now: {0}, timestamp: {1}
     InFuture(u64, u64),
     /** The timestamp is not newer than the last bock. last_bock timestamp: {0},
     timestamp: {1} */
@@ -19,13 +32,24 @@ pub enum Error {
     TooOld(u64, u64),
 }
 
+pub fn validate_with_logger(
+    timestamp: u64,
+    latest_block: &Block,
+    logger: &Logger,
+) -> Result<(), Error> {
+    validate(timestamp, latest_block).map_err(|e| {
+        log::warn!(logger, "Consensus Value timestamp invalid: {e}");
+        e
+    })
+}
+
 pub fn validate(timestamp: u64, latest_block: &Block) -> Result<(), Error> {
     let now = std::time::SystemTime::now()
         .duration_since(std::time::UNIX_EPOCH)
         .expect("Failed to get system time")
         .as_millis() as u64;
 
-    if timestamp > now {
+    if timestamp > (now + ALLOWED_FUTURE_SKEW) {
         return Err(Error::InFuture(now, timestamp));
     }
 
@@ -100,7 +124,7 @@ mod test {
         // network.
         let now = std::time::SystemTime::now();
         let future = now
-            .checked_add(std::time::Duration::from_millis(100))
+            .checked_add(std::time::Duration::from_millis(ALLOWED_FUTURE_SKEW + 100))
             .unwrap()
             .duration_since(std::time::UNIX_EPOCH)
             .unwrap()
@@ -126,6 +150,20 @@ mod test {
         assert_eq!(validate(now, &latest_block), Ok(()));
     }
 
+    #[test]
+    fn timestamp_up_to_allowed_future_skew_succeeds() {
+        let skewed_now = std::time::SystemTime::now()
+            .checked_add(std::time::Duration::from_millis(ALLOWED_FUTURE_SKEW))
+            .unwrap()
+            .duration_since(std::time::UNIX_EPOCH)
+            .unwrap()
+            .as_millis() as u64;
+
+        let latest_block = Block::default();
+
+        assert_eq!(validate(skewed_now, &latest_block), Ok(()));
+    }
+
     #[test]
     fn timestamp_older_than_30_seconds_fails() {
         let now = std::time::SystemTime::now();

consensus/service/src/tx_manager/mod.rs

@@ -232,7 +232,10 @@ impl<E: ConsensusEnclave + Send, UI: UntrustedInterfaces + Send> TxManager
 
         if let Some(context) = context_opt {
             let _timer = counters::VALIDATE_TX_TIME.start_timer();
-            self.untrusted.is_valid(context, timestamp)?;
+            self.untrusted.is_valid(context, timestamp).map_err(|e| {
+                log::warn!(self.logger, "Failed validated tx_hash: {e}");
+                e
+            })?;
             Ok(())
         } else {
             log::warn!(
@@ -280,7 +283,7 @@ impl<E: ConsensusEnclave + Send, UI: UntrustedInterfaces + Send> TxManager
 
         cache_entries
             .into_iter()
-            .map(|(entry, _)| {
+            .map(|(entry, _timestamp)| {
                 // Highest indices proofs must be w.r.t. the current ledger.
                 // Recreating them here is a crude way to ensure that.
                 let highest_index_proofs: Vec<_> = self