Add logger

.github/workflows/ build_and_test.yml

@@ -6,6 +6,7 @@ env:
   CARGO_TERM_COLOR: always
   CARGO_TERM_VERBOSE: true
   CARGOFLAGS: --workspace --all-targets --all-features
+  RUST_LOG: trace
 
 jobs:
   debug_mode_build:

CHANGELOG.md

@@ -7,6 +7,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+### Added
+
+- Logging
+  - RPC server binary can output logs
+  - Tests print logs
+
 ## [0.0.7] - 2024-08-15
 
 ### Added

Cargo.toml

@@ -14,6 +14,7 @@ bitcoin-scriptexec = { git = "https://github.com/Bitcoin-Wildlife-Sanctuary/rust
 rusqlite = { version = "0.32.1", features = ["bundled"] }
 rs_merkle = "1.4"
 jsonrpsee = { version = "0.24.3", features = ["server", "client", "macros"], default-features = false }
-tokio = { version = "1.39.2", features = ["full"]}
+tokio = { version = "1.39.3", features = ["full"]}
 tracing = "0.1.40"
+tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }
 tower = "0.4.13"

README.md

@@ -101,6 +101,21 @@ Standard Rust tools are sufficient for testing:
 cargo test
 ```
 
+Additionally, logging level can be set to view crucial information. There are
+multiple levels of logs:
+
+```bash
+RUST_LOG=trace cargo test # Prints every detail
+RUST_LOG=debug cargo test
+RUST_LOG=info cargo test
+RUST_LOG=warn cargo test
+RUST_LOG=error cargo test # Prints only errors
+```
+
+Please check
+[log library's documentation](https://docs.rs/log/latest/log/enum.Level.html)
+for more detail.
+
 ## Documentation
 
 No external documentation is provided. Please read code comments or run:

src/client/mod.rs

@@ -3,7 +3,6 @@
 //! Client crate mocks the `Client` struct in `bitcoincore-rpc`.
 
 use crate::ledger::Ledger;
-use bitcoin::Txid;
 use bitcoincore_rpc::{Auth, RpcApi};
 
 mod rpc_api;
@@ -47,6 +46,7 @@ impl RpcApiWrapper for Client {
     /// Parameters must match `bitcoincore_rpc::Client::new()`. Only the `url`
     /// is used for database identification. Authorization struct is not used
     /// and can be a dummy value.
+    #[tracing::instrument]
     fn new(url: &str, _auth: bitcoincore_rpc::Auth) -> bitcoincore_rpc::Result<Self> {
         Ok(Self {
             ledger: Ledger::new(url),
@@ -56,57 +56,14 @@ impl RpcApiWrapper for Client {
     /// This function will establish a new database connection, while preserving
     /// it's previous state. Meaning it won't clear database. This is helpful
     /// for cloning the `Client` structure.
+    #[tracing::instrument]
     fn new_without_cleanup(url: &str, _auth: Auth) -> bitcoincore_rpc::Result<Self> {
         Ok(Self {
             ledger: Ledger::new_without_cleanup(url),
         })
     }
 }
 
-/// Dumps complete ledger to a string and returns it. This can help identify
-/// bugs as it draws the big picture of the mock blockchain.
-pub fn dump_ledger(rpc: Client, pretty: bool) -> String {
-    dump_ledger_inner(rpc.ledger, pretty)
-}
-/// Parent of `dump_ledger`. This function accepts private `Ledger` struct. This
-/// useful for only crate tests.
-pub fn dump_ledger_inner(ledger: Ledger, pretty: bool) -> String {
-    let mut dump = String::new();
-
-    const DELIMETER: &str = "\n-----\n";
-
-    let transactions = ledger.get_transactions();
-
-    if pretty {
-        dump += DELIMETER;
-        dump += format!("Transactions: {:#?}", transactions).as_str();
-        dump += DELIMETER;
-        dump += format!(
-            "Txids: {:#?}",
-            transactions
-                .iter()
-                .map(|tx| tx.compute_txid())
-                .collect::<Vec<Txid>>()
-        )
-        .as_str();
-        dump += DELIMETER;
-    } else {
-        dump += format!("Transactions: {:?}", transactions).as_str();
-        dump += DELIMETER;
-        dump += format!(
-            "Txids: {:?}",
-            transactions
-                .iter()
-                .map(|tx| tx.compute_txid())
-                .collect::<Vec<Txid>>()
-        )
-        .as_str();
-        dump += DELIMETER;
-    }
-
-    dump
-}
-
 #[cfg(test)]
 mod tests {
     use super::*;

src/client/rpc_api.rs

@@ -19,7 +19,7 @@ use bitcoincore_rpc::{
         GetRawTransactionResultVoutScriptPubKey, GetTransactionResult, GetTransactionResultDetail,
         GetTransactionResultDetailCategory, GetTxOutResult, WalletTxInfo,
     },
-    RpcApi,
+    Error, RpcApi,
 };
 use secp256k1::rand::{self, RngCore};
 
@@ -41,11 +41,14 @@ impl RpcApi for Client {
         cmd: &str,
         args: &[serde_json::Value],
     ) -> bitcoincore_rpc::Result<T> {
-        unimplemented!(
+        let msg = format!(
             "Unimplemented mock RPC cmd: {}, with args: {:?}. Please consider implementing it.",
-            cmd,
-            args
+            cmd, args
         );
+
+        tracing::error!(msg);
+
+        Err(Error::ReturnedError(msg))
     }
 
     fn send_raw_transaction<R: bitcoincore_rpc::RawTx>(
@@ -565,7 +568,12 @@ mod tests {
         // Wallet has funds now. It should not be rejected.
         let txin = TxIn {
             previous_output: OutPoint {
-                txid: rpc.ledger.get_transactions().get(0).unwrap().compute_txid(),
+                txid: rpc
+                    .ledger
+                    ._get_transactions()
+                    .get(0)
+                    .unwrap()
+                    .compute_txid(),
                 vout: 0,
             },
             witness: credential.witness.unwrap(),

src/ledger/address.rs

@@ -23,16 +23,24 @@ pub struct UserCredential {
 }
 
 impl UserCredential {
-    /// Creates a new `UserCredential` with random keys.
+    /// Creates a new `UserCredential` with random keys. Bitcoin address has the
+    /// type of "p2tr".
     pub fn new() -> Self {
         let secp = Secp256k1::new();
 
         let (secret_key, public_key) = secp.generate_keypair(&mut rand::thread_rng());
+        tracing::trace!(
+            "New secret/public key pair: {:?} {:?}",
+            secret_key,
+            public_key
+        );
 
         let keypair = Keypair::from_secret_key(&secp, &secret_key);
         let (x_only_public_key, _parity) = XOnlyPublicKey::from_keypair(&keypair);
+        tracing::trace!("New x-only public key: {:?}", x_only_public_key);
 
         let address = Address::p2tr(&secp, x_only_public_key, None, Network::Regtest);
+        tracing::trace!("New bitcoin address: {:?}", address);
 
         Self {
             secp,
@@ -55,10 +63,12 @@ impl Default for UserCredential {
 impl Ledger {
     /// Generates a random secret/public key pair and creates a new Bicoin
     /// address from them.
+    #[tracing::instrument]
     pub fn generate_credential() -> UserCredential {
         UserCredential::new()
     }
     /// Generates a Bitcoin credentials from a witness program.
+    #[tracing::instrument]
     pub fn generate_credential_from_witness() -> UserCredential {
         let mut credential = Ledger::generate_credential();
 
@@ -90,12 +100,17 @@ impl Ledger {
         let taproot_spend_info = taproot_builder
             .finalize(&credential.secp, credential.x_only_public_key)
             .unwrap();
+        tracing::trace!(
+            "Taproot spend info for the new witness: {:?}",
+            taproot_spend_info
+        );
 
         let witness_program = WitnessProgram::p2tr(
             &credential.secp,
             credential.x_only_public_key,
             taproot_spend_info.merkle_root(),
         );
+        tracing::trace!("New witness program: {:?}", witness_program);
 
         let mut control_block_bytes = Vec::new();
         taproot_spend_info
@@ -107,6 +122,7 @@ impl Ledger {
         let mut witness = Witness::new();
         witness.push(script.to_bytes());
         witness.push(control_block_bytes);
+        tracing::trace!("New witness: {:?}", witness);
 
         credential.witness = Some(witness);
         credential.witness_program = Some(witness_program);

src/ledger/block.rs

@@ -21,13 +21,15 @@ impl Ledger {
     /// # Panics
     ///
     /// Will panic if there was a problem writing data to ledger.
+    #[tracing::instrument]
     pub fn mine_block(&self, address: &Address) -> Result<BlockHash, LedgerError> {
         let mut transactions = self.get_mempool_transactions();
         let coinbase_transaction = self.create_coinbase_transaction(
             address,
             transactions.iter().map(|tx| tx.compute_wtxid()).collect(),
         )?;
         transactions.insert(0, coinbase_transaction.clone());
+        tracing::debug!("Number of transactions in block: {}", transactions.len());
 
         self.add_transaction_unconditionally(coinbase_transaction)?;
 
@@ -56,8 +58,11 @@ impl Ledger {
             }
         };
 
+        tracing::trace!("Transactions in block: {:?}", transactions);
         let txids: Vec<Txid> = transactions.iter().map(|tx| tx.compute_txid()).collect();
+        tracing::trace!("TxIds in block: {:?}", txids);
         let merkle_root = utils::calculate_merkle_root(txids)?;
+        tracing::trace!("Merkle root of the TxIds: {:?}", merkle_root);
 
         Ok(Block {
             header: Header {
@@ -87,16 +92,24 @@ impl Ledger {
 
         let current_block_height = prev_block_height + 1;
         let current_block_time = prev_block_time + (10 * 60);
+        tracing::debug!(
+            "New block's height: {}, time: {}",
+            current_block_height,
+            current_block_time
+        );
 
         let mut hash: Vec<u8> = Vec::new();
-        block.block_hash().consensus_encode(&mut hash).unwrap();
+        let block_hash = block.block_hash();
+        block_hash.consensus_encode(&mut hash).unwrap();
+        tracing::debug!("New block's hash: {}", block_hash);
 
         let mut body: Vec<u8> = Vec::new();
         if let Err(e) = block.consensus_encode(&mut body) {
             return Err(LedgerError::Block(format!("Couldn't encode block: {}", e)));
         };
 
         let coinbase_txid = block.txdata.first().unwrap().compute_txid().to_string();
+        tracing::trace!("New block's coinbase TxId: {}", coinbase_txid);
 
         if let Err(e) = self.database.lock().unwrap().execute(
             "INSERT INTO blocks (height, time, hash, coinbase, body) VALUES (?1, ?2, ?3, ?4, ?5)",
@@ -192,6 +205,23 @@ impl Ledger {
         }
     }
 
+    /// Adds a transactions to the mempool.
+    ///
+    /// # Panics
+    ///
+    /// Will panic if there is a problem with database.
+    pub fn add_mempool_transaction(&self, txid: Txid) -> Result<(), LedgerError> {
+        match self.database.lock().unwrap().execute(
+            "INSERT INTO mempool (txid) VALUES (?1)",
+            params![txid.to_string()],
+        ) {
+            Ok(_) => Ok(()),
+            Err(e) => Err(LedgerError::Transaction(format!(
+                "Couldn't add transaction with txid {} to mempool: {}",
+                txid, e
+            ))),
+        }
+    }
     /// Gets all the transactions that are in the mempool.
     ///
     /// # Panics
@@ -219,24 +249,6 @@ impl Ledger {
             .map(|txid| self.get_transaction(*txid).unwrap())
             .collect::<Vec<Transaction>>()
     }
-    /// Adds a transactions to the mempool.
-    ///
-    /// # Panics
-    ///
-    /// Will panic if there is a problem with database.
-    pub fn add_mempool_transaction(&self, txid: Txid) -> Result<(), LedgerError> {
-        match self.database.lock().unwrap().execute(
-            "INSERT INTO mempool (txid) VALUES (?1)",
-            params![txid.to_string()],
-        ) {
-            Ok(_) => Ok(()),
-            Err(e) => Err(LedgerError::Transaction(format!(
-                "Couldn't add transaction with txid {} to mempool: {}",
-                txid, e
-            ))),
-        }
-    }
-
     /// Gets a mempool transaction, if it's in the mempool.
     ///
     /// # Panics
@@ -299,7 +311,10 @@ impl Ledger {
 
 #[cfg(test)]
 mod tests {
-    use crate::ledger::{self, Ledger, BLOCK_REWARD};
+    use crate::{
+        ledger::{self, Ledger},
+        utils::BLOCK_REWARD,
+    };
     use bitcoin::{Amount, OutPoint, ScriptBuf, Transaction, Txid};
 
     #[test]
@@ -339,7 +354,7 @@ mod tests {
 
         // Because there is no transactions are mined, there should be only a
         // coinbase transaction.
-        let txs = ledger.get_transactions();
+        let txs = ledger._get_transactions();
         let coinbase_tx = txs.first().unwrap();
 
         assert_eq!(

src/ledger/mod.rs

@@ -5,24 +5,22 @@
 //! This crate is designed to be used as immutable, because of the `RpcApi`'s
 //! immutable nature.
 
+use crate::utils;
 use rusqlite::Connection;
 use std::{
     env,
     sync::{Arc, Mutex},
 };
+
 mod address;
 mod block;
 pub(crate) mod errors;
 mod script;
 mod spending_requirements;
 mod transactions;
 
-/// Block reward is fixed to 50 BTC, regardless of which and how many blocks are
-/// generated.
-pub(crate) const BLOCK_REWARD: u64 = 5_000_000_000;
-
 /// Mock Bitcoin ledger.
-#[derive(Clone)]
+#[derive(Clone, Debug)]
 pub struct Ledger {
     /// Database connection.
     database: Arc<Mutex<Connection>>,
@@ -39,8 +37,12 @@ impl Ledger {
     ///
     /// Panics if SQLite connection can't be established and initial query can't
     /// be run.
+    #[tracing::instrument]
     pub fn new(path: &str) -> Self {
         let path = Ledger::get_database_path(path);
+        let _ = utils::initialize_logger();
+
+        tracing::trace!("Creating database at path {path}");
 
         let database = Connection::open(path.clone()).unwrap();