add additional trace logging and remove some unused logging

src/bin/electrs.rs

@@ -2,6 +2,7 @@ extern crate error_chain;
 #[macro_use]
 extern crate log;
 
+
 extern crate electrs;
 
 use error_chain::ChainedError;
@@ -116,26 +117,24 @@ fn run_server(config: Arc<Config>) -> Result<()> {
     let electrum_server = ElectrumRPC::start(Arc::clone(&config), Arc::clone(&query), &metrics);
 
     loop {
+        trace!("signal.wait");
         if let Err(err) = signal.wait(Duration::from_secs(5), true) {
             info!("stopping server: {}", err);
             rest_server.stop();
             // the electrum server is stopped when dropped
             break;
         }
 
-        debug!("checking for new blocks, current_tip={}", tip);
-
+        trace!("calling getbestblockhash my tip={}", tip);
         // Index new blocks
         let current_tip = daemon.getbestblockhash()?;
 
-        debug!("new blockhash from bitcoind={}", current_tip);
-
         if current_tip != tip {
-            debug!("updating index to {}", current_tip);
+            trace!("retrieved NEW blockhash bitcoind new={}", current_tip);
             indexer.update(&daemon)?;
             tip = current_tip;
         } else {
-            debug!("tip unchanged, no update");
+            trace!("tip UNCHANGED")
         }
 
         // Update mempool
@@ -152,9 +151,11 @@ fn run_server(config: Arc<Config>) -> Result<()> {
 }
 
 fn main() {
+
     let config = Arc::new(Config::from_args());
     if let Err(e) = run_server(config) {
         error!("server failed: {}", e.display_chain());
         process::exit(1);
     }
+
 }

src/new_index/mempool.rs

@@ -306,7 +306,7 @@ impl Mempool {
     }
 
     fn add(&mut self, txs: Vec<Transaction>) {
-        let t = Instant::now();
+        //let t = Instant::now();
         self.delta
             .with_label_values(&["add"])
             .observe(txs.len() as f64);
@@ -415,7 +415,7 @@ impl Mempool {
     }
 
     pub fn lookup_txos(&self, outpoints: &BTreeSet<OutPoint>) -> Result<HashMap<OutPoint, TxOut>> {
-        let t = Instant::now();
+        //let t = Instant::now();
         let _timer = self
             .latency
             .with_label_values(&["lookup_txos"])
@@ -505,7 +505,7 @@ impl Mempool {
     }
 
     pub fn update(mempool: &Arc<RwLock<Mempool>>, daemon: &Daemon) -> Result<()> {
-        let t = Instant::now();
+        //let t = Instant::now();
         let _timer = mempool.read().unwrap().latency.with_label_values(&["update"]).start_timer();
 
         // 1. Determine which transactions are no longer in the daemon's mempool and which ones have newly entered it

src/new_index/schema.rs

@@ -1053,14 +1053,14 @@ fn lookup_txos(
     allow_missing: bool,
     num_threads: usize,
 ) -> HashMap<OutPoint, TxOut> {
-    let t = Instant::now();
+    //let t = Instant::now();
     let pool = rayon::ThreadPoolBuilder::new()
         .num_threads(num_threads) // we need to saturate SSD IOPS
         .thread_name(|i| format!("lookup-txo-{}", i))
         .build()
         .unwrap();
     //log_fn_duration("schema::ThreadPoolBuilder", t.elapsed().as_micros());
-    let t2 = Instant::now();
+    //let t2 = Instant::now();
     let res = pool.install(|| {
         outpoints
             .par_iter()
@@ -1082,7 +1082,7 @@ fn lookup_txos(
 }
 
 fn lookup_txo(txstore_db: &DB, outpoint: &OutPoint) -> Option<TxOut> {
-    let t = Instant::now();
+    //let t = Instant::now();
     let res = txstore_db
         .get(&TxOutRow::key(&outpoint))
         .map(|val| deserialize(&val).expect("failed to parse TxOut"));

src/signal.rs

@@ -52,7 +52,10 @@ impl Waiter {
                 }
             }
             Ok(sig) => bail!(ErrorKind::Interrupt(sig)),
-            Err(RecvTimeoutError::Timeout) => Ok(()),
+            Err(RecvTimeoutError::Timeout) => {
+                trace!("timeout");
+                Ok(())
+            }
             Err(RecvTimeoutError::Disconnected) => bail!("signal hook channel disconnected"),
         }
     }