Merge pull request #2694 from Evanfeenstra/public-scid-utils
[rust-lightning] / lightning-transaction-sync / src / esplora.rs
index 807ef8075005c13ba12a29d99a393aea72328ac3..eb52faf33648cfb173985b13c29ecb9d754fdb87 100644 (file)
@@ -2,7 +2,7 @@ use crate::error::{TxSyncError, InternalError};
 use crate::common::{SyncState, FilterQueue, ConfirmedTx};
 
 use lightning::util::logger::Logger;
-use lightning::{log_error, log_given_level, log_info, log_internal, log_debug, log_trace};
+use lightning::{log_error, log_debug, log_trace};
 use lightning::chain::WatchedOutput;
 use lightning::chain::{Confirm, Filter};
 
@@ -89,7 +89,11 @@ where
                #[cfg(feature = "async-interface")]
                let mut sync_state = self.sync_state.lock().await;
 
-               log_info!(self.logger, "Starting transaction sync.");
+               log_trace!(self.logger, "Starting transaction sync.");
+               #[cfg(feature = "time")]
+               let start_time = std::time::Instant::now();
+               let mut num_confirmed = 0;
+               let mut num_unconfirmed = 0;
 
                let mut tip_hash = maybe_await!(self.client.get_tip_hash())?;
 
@@ -110,17 +114,40 @@ where
                                                Ok(unconfirmed_txs) => {
                                                        // Double-check the tip hash. If it changed, a reorg happened since
                                                        // we started syncing and we need to restart last-minute.
-                                                       let check_tip_hash = maybe_await!(self.client.get_tip_hash())?;
-                                                       if check_tip_hash != tip_hash {
-                                                               tip_hash = check_tip_hash;
-                                                               continue;
+                                                       match maybe_await!(self.client.get_tip_hash()) {
+                                                               Ok(check_tip_hash) => {
+                                                                       if check_tip_hash != tip_hash {
+                                                                               tip_hash = check_tip_hash;
+
+                                                                               log_debug!(self.logger, "Encountered inconsistency during transaction sync, restarting.");
+                                                                               sync_state.pending_sync = true;
+                                                                               continue;
+                                                                       }
+                                                                       num_unconfirmed += unconfirmed_txs.len();
+                                                                       sync_state.sync_unconfirmed_transactions(
+                                                                               &confirmables,
+                                                                               unconfirmed_txs
+                                                                       );
+                                                               }
+                                                               Err(err) => {
+                                                                       // (Semi-)permanent failure, retry later.
+                                                                       log_error!(self.logger,
+                                                                               "Failed during transaction sync, aborting. Synced so far: {} confirmed, {} unconfirmed.",
+                                                                               num_confirmed,
+                                                                               num_unconfirmed
+                                                                               );
+                                                                       sync_state.pending_sync = true;
+                                                                       return Err(TxSyncError::from(err));
+                                                               }
                                                        }
-
-                                                       self.sync_unconfirmed_transactions(&mut sync_state, &confirmables, unconfirmed_txs);
                                                },
                                                Err(err) => {
                                                        // (Semi-)permanent failure, retry later.
-                                                       log_error!(self.logger, "Failed during transaction sync, aborting.");
+                                                       log_error!(self.logger,
+                                                               "Failed during transaction sync, aborting. Synced so far: {} confirmed, {} unconfirmed.",
+                                                               num_confirmed,
+                                                               num_unconfirmed
+                                                       );
                                                        sync_state.pending_sync = true;
                                                        return Err(TxSyncError::from(err));
                                                }
@@ -136,6 +163,11 @@ where
                                                }
                                                Err(err) => {
                                                        // (Semi-)permanent failure, retry later.
+                                                       log_error!(self.logger,
+                                                               "Failed during transaction sync, aborting. Synced so far: {} confirmed, {} unconfirmed.",
+                                                               num_confirmed,
+                                                               num_unconfirmed
+                                                       );
                                                        sync_state.pending_sync = true;
                                                        return Err(TxSyncError::from(err));
                                                }
@@ -146,17 +178,33 @@ where
                                        Ok(confirmed_txs) => {
                                                // Double-check the tip hash. If it changed, a reorg happened since
                                                // we started syncing and we need to restart last-minute.
-                                               let check_tip_hash = maybe_await!(self.client.get_tip_hash())?;
-                                               if check_tip_hash != tip_hash {
-                                                       tip_hash = check_tip_hash;
-                                                       continue;
+                                               match maybe_await!(self.client.get_tip_hash()) {
+                                                       Ok(check_tip_hash) => {
+                                                               if check_tip_hash != tip_hash {
+                                                                       tip_hash = check_tip_hash;
+
+                                                                       log_debug!(self.logger,
+                                                                               "Encountered inconsistency during transaction sync, restarting.");
+                                                                       sync_state.pending_sync = true;
+                                                                       continue;
+                                                               }
+                                                               num_confirmed += confirmed_txs.len();
+                                                               sync_state.sync_confirmed_transactions(
+                                                                       &confirmables,
+                                                                       confirmed_txs
+                                                               );
+                                                       }
+                                                       Err(err) => {
+                                                               // (Semi-)permanent failure, retry later.
+                                                               log_error!(self.logger,
+                                                                       "Failed during transaction sync, aborting. Synced so far: {} confirmed, {} unconfirmed.",
+                                                                       num_confirmed,
+                                                                       num_unconfirmed
+                                                               );
+                                                               sync_state.pending_sync = true;
+                                                               return Err(TxSyncError::from(err));
+                                                       }
                                                }
-
-                                               self.sync_confirmed_transactions(
-                                                       &mut sync_state,
-                                                       &confirmables,
-                                                       confirmed_txs,
-                                               );
                                        }
                                        Err(InternalError::Inconsistency) => {
                                                // Immediately restart syncing when we encounter any inconsistencies.
@@ -166,7 +214,11 @@ where
                                        }
                                        Err(err) => {
                                                // (Semi-)permanent failure, retry later.
-                                               log_error!(self.logger, "Failed during transaction sync, aborting.");
+                                               log_error!(self.logger,
+                                                       "Failed during transaction sync, aborting. Synced so far: {} confirmed, {} unconfirmed.",
+                                                       num_confirmed,
+                                                       num_unconfirmed
+                                               );
                                                sync_state.pending_sync = true;
                                                return Err(TxSyncError::from(err));
                                        }
@@ -175,7 +227,12 @@ where
                                sync_state.pending_sync = false;
                        }
                }
-               log_info!(self.logger, "Finished transaction sync.");
+               #[cfg(feature = "time")]
+               log_debug!(self.logger, "Finished transaction sync at tip {} in {}ms: {} confirmed, {} unconfirmed.",
+                               tip_hash, start_time.elapsed().as_millis(), num_confirmed, num_unconfirmed);
+               #[cfg(not(feature = "time"))]
+               log_debug!(self.logger, "Finished transaction sync at tip {}: {} confirmed, {} unconfirmed.",
+                               tip_hash, num_confirmed, num_unconfirmed);
                Ok(())
        }
 
@@ -199,26 +256,6 @@ where
                Ok(())
        }
 
-       fn sync_confirmed_transactions(
-               &self, sync_state: &mut SyncState, confirmables: &Vec<&(dyn Confirm + Sync + Send)>, confirmed_txs: Vec<ConfirmedTx>,
-       ) {
-               for ctx in confirmed_txs {
-                       for c in confirmables {
-                               c.transactions_confirmed(
-                                       &ctx.block_header,
-                                       &[(ctx.pos, &ctx.tx)],
-                                       ctx.block_height,
-                               );
-                       }
-
-                       sync_state.watched_transactions.remove(&ctx.tx.txid());
-
-                       for input in &ctx.tx.input {
-                               sync_state.watched_outputs.remove(&input.previous_output);
-                       }
-               }
-       }
-
        #[maybe_async]
        fn get_confirmed_transactions(
                &self, sync_state: &SyncState,
@@ -286,7 +323,8 @@ where
                                return Err(InternalError::Failed);
                        }
 
-                       let pos = *indexes.get(0).ok_or(InternalError::Failed)? as usize;
+                       // unwrap() safety: len() > 0 is checked above
+                       let pos = *indexes.first().unwrap() as usize;
                        if let Some(tx) = maybe_await!(self.client.get_tx(&txid))? {
                                if let Some(block_height) = known_block_height {
                                        // We can take a shortcut here if a previous call already gave us the height.
@@ -316,11 +354,11 @@ where
                let relevant_txids = confirmables
                        .iter()
                        .flat_map(|c| c.get_relevant_txids())
-                       .collect::<HashSet<(Txid, Option<BlockHash>)>>();
+                       .collect::<HashSet<(Txid, u32, Option<BlockHash>)>>();
 
                let mut unconfirmed_txs = Vec::new();
 
-               for (txid, block_hash_opt) in relevant_txids {
+               for (txid, _conf_height, block_hash_opt) in relevant_txids {
                        if let Some(block_hash) = block_hash_opt {
                                let block_status = maybe_await!(self.client.get_block_status(&block_hash))?;
                                if block_status.in_best_chain {
@@ -337,18 +375,6 @@ where
                Ok(unconfirmed_txs)
        }
 
-       fn sync_unconfirmed_transactions(
-               &self, sync_state: &mut SyncState, confirmables: &Vec<&(dyn Confirm + Sync + Send)>, unconfirmed_txs: Vec<Txid>,
-       ) {
-               for txid in unconfirmed_txs {
-                       for c in confirmables {
-                               c.transaction_unconfirmed(&txid);
-                       }
-
-                       sync_state.watched_transactions.insert(txid);
-               }
-       }
-
        /// Returns a reference to the underlying esplora client.
        pub fn client(&self) -> &EsploraClientType {
                &self.client