feat: Compiler-Enforced Logging of All Miner Transaction Outcomes

src/chainstate/stacks/db/blocks.rs

@@ -14,6 +14,7 @@
 // You should have received a copy of the GNU General Public License
 // along with this program.  If not, see <http://www.gnu.org/licenses/>.
 
+use chainstate::stacks::events::*;
 use std::cmp;
 use std::collections::{HashMap, HashSet};
 use std::convert::From;
@@ -3876,16 +3877,26 @@ impl StacksChainState {
         for microblock in microblocks.iter() {
             debug!("Process microblock {}", &microblock.block_hash());
             for tx in microblock.txs.iter() {
-                let (tx_fee, mut tx_receipt) =
-                    StacksChainState::process_transaction(clarity_tx, tx, false)
-                        .map_err(|e| (e, microblock.block_hash()))?;
-
-                tx_receipt.microblock_header = Some(microblock.header.clone());
-                fees = fees.checked_add(tx_fee as u128).expect("Fee overflow");
-                burns = burns
-                    .checked_add(tx_receipt.stx_burned as u128)
-                    .expect("Burns overflow");
-                receipts.push(tx_receipt);
+                match StacksChainState::process_transaction(clarity_tx, tx, false) {
+                    TransactionResult::Success(TransactionSuccess {
+                        tx: _,
+                        fee,
+                        mut receipt,
+                    }) => {
+                        receipt.microblock_header = Some(microblock.header.clone());
+                        fees = fees.checked_add(fee as u128).expect("Fee overflow");
+                        burns = burns
+                            .checked_add(receipt.stx_burned as u128)
+                            .expect("Burns overflow");
+                        receipts.push(receipt);
+                    }
+                    TransactionResult::Skipped(TransactionSkipped { tx: _, reason: _ }) => {
+                        continue;
+                    }
+                    TransactionResult::Error(TransactionError { tx: _, error }) => {
+                        return Err((error, microblock.block_hash()));
+                    }
+                }
             }
         }
         Ok((fees, burns, receipts))
@@ -4029,13 +4040,26 @@ impl StacksChainState {
         let mut burns = 0u128;
         let mut receipts = vec![];
         for tx in block.txs.iter() {
-            let (tx_fee, tx_receipt) =
-                StacksChainState::process_transaction(clarity_tx, tx, false)?;
-            fees = fees.checked_add(tx_fee as u128).expect("Fee overflow");
-            burns = burns
-                .checked_add(tx_receipt.stx_burned as u128)
-                .expect("Burns overflow");
-            receipts.push(tx_receipt);
+            //            let (tx_fee, tx_receipt) =
+            match StacksChainState::process_transaction(clarity_tx, tx, false) {
+                TransactionResult::Success(TransactionSuccess {
+                    tx: _,
+                    fee,
+                    receipt,
+                }) => {
+                    fees = fees.checked_add(fee as u128).expect("Fee overflow");
+                    burns = burns
+                        .checked_add(receipt.stx_burned as u128)
+                        .expect("Burns overflow");
+                    receipts.push(receipt);
+                }
+                TransactionResult::Skipped(TransactionSkipped { tx: _, reason: _ }) => {
+                    continue;
+                }
+                TransactionResult::Error(TransactionError { tx: _, error }) => {
+                    return Err(error);
+                }
+            }
         }
         Ok((fees, burns, receipts))
     }

src/chainstate/stacks/db/mod.rs

@@ -89,6 +89,7 @@ pub mod accounts;
 pub mod blocks;
 pub mod contracts;
 pub mod headers;
+pub mod queryable_logging;
 pub mod transactions;
 pub mod unconfirmed;
 

src/chainstate/stacks/db/queryable_logging.rs

@@ -0,0 +1,42 @@
+//! The methods in this file implement a "queryable" form for logging the outcomes of transactions.
+//!
+//! Each processed transaction should be logged if it succeeds, logged if it fails with an error,
+//! and should be logged each time it is skipped.
+//!
+//! This way, when debugging a miner, we can run a standard query, and see what happened to the
+//! transaction.
+//!
+use chainstate::stacks::Error;
+/// Logs a queryable message for the case where `txid` has succeeded.
+use chainstate::stacks::StacksTransaction;
+
+/// Returns a prefix for a "queryable logging" statement. This is the "queryable" part, which is to
+/// say that the prefix will be the same no matter what the outcome is, so that a fixed regex will
+/// match this part for any transaction.
+///
+/// Format looks like this:
+/// "Transaction outcome 491493d01fc8c0f21f0891ad7c378bfb9c7b83142524f3320ea609e6b5cffa90: "
+fn create_transaction_key(tx: &StacksTransaction) -> String {
+    format!("Transaction outcome {}:", &tx.txid())
+}
+
+/// Logs a queryable message for the case where `txid` has succeeded.
+pub fn log_transaction_success(tx: &StacksTransaction) {
+    info!("{} successfully processed.", create_transaction_key(tx));
+}
+
+/// Logs a queryable message for the case where `txid` has failed
+/// with error `err`.
+pub fn log_transaction_error(tx: &StacksTransaction, err: &Error) {
+    warn!("{} failed with error: {}", create_transaction_key(tx), err);
+}
+
+/// Logs a queryable message for the case where `tx` has been skipped
+/// for reason `reason`.
+pub fn log_transaction_skipped(tx: &StacksTransaction, reason: String) {
+    info!(
+        "{} skipped for reason: {}",
+        create_transaction_key(tx),
+        reason
+    );
+}

src/chainstate/stacks/db/transactions.rs

@@ -24,6 +24,7 @@ use std::path::{Path, PathBuf};
 
 use chainstate::burn::db::sortdb::*;
 use chainstate::stacks::db::*;
+use chainstate::stacks::events::TransactionResult;
 use chainstate::stacks::Error;
 use chainstate::stacks::*;
 use clarity_vm::clarity::{
@@ -1122,8 +1123,10 @@ impl StacksChainState {
         }
     }
 
-    /// Process a transaction.  Return the fee and the transaction receipt
-    pub fn process_transaction(
+    /// This method implements the contract of `process_transaction`, and
+    /// exists as an intermediate step so that its output can be captured and
+    /// logged.
+    fn process_transaction_internal(
         clarity_block: &mut ClarityTx,
         tx: &StacksTransaction,
         quiet: bool,
@@ -1161,6 +1164,28 @@ impl StacksChainState {
 
         Ok((fee, tx_receipt))
     }
+
+    /// Process the transaction `tx`, and add it to the underlying connection in `clarity_block`.
+    ///
+    /// Steps include:
+    /// - check nonces
+    /// - process payload
+    /// - update nonces
+    /// - commit the transaction to `clarity_block`
+    pub fn process_transaction(
+        clarity_block: &mut ClarityTx,
+        tx: &StacksTransaction,
+        quiet: bool,
+    ) -> TransactionResult {
+        let result = StacksChainState::process_transaction_internal(clarity_block, tx, quiet);
+
+        // Note: `process_transaction_internal` does not have the option to
+        // "skip", only succeed for fail.
+        match result {
+            Ok((fee, receipt)) => TransactionResult::success(tx, fee, receipt),
+            Err(err) => TransactionResult::error(tx, err),
+        }
+    }
 }
 
 #[cfg(test)]
@@ -1471,13 +1496,14 @@ pub mod test {
 
             let res = StacksChainState::process_transaction(&mut conn, &signed_tx, false);
             assert!(res.is_err());
+            let error = res.unwrap_err();
 
-            match res {
-                Err(Error::InvalidStacksTransaction(msg, false)) => {
+            match error {
+                Error::InvalidStacksTransaction(msg, false) => {
                     assert!(msg.contains(&err_frag), "{}", err_frag);
                 }
                 _ => {
-                    eprintln!("bad error: {:?}", &res);
+                    eprintln!("bad error: {:?}", &error);
                     eprintln!("Expected '{}'", &err_frag);
                     assert!(false);
                 }

src/chainstate/stacks/events.rs

@@ -17,6 +17,8 @@
 use crate::types::chainstate::StacksAddress;
 use crate::{codec::StacksMessageCodec, types::chainstate::StacksMicroblockHeader};
 use burnchains::Txid;
+use chainstate::stacks::db::queryable_logging::*;
+use chainstate::stacks::Error;
 use chainstate::stacks::StacksTransaction;
 use vm::analysis::ContractAnalysis;
 use vm::costs::ExecutionCost;
@@ -63,6 +65,128 @@ pub struct StacksTransactionReceipt {
     pub microblock_header: Option<StacksMicroblockHeader>,
 }
 
+/// Represents a successful transaction. This transaction should be added to the block.
+#[derive(Debug, Clone, PartialEq)]
+pub struct TransactionSuccess {
+    pub tx: StacksTransaction,
+    // The fee that was charged to the user for doing this transaction.
+    pub fee: u64,
+    pub receipt: StacksTransactionReceipt,
+}
+
+/// Represents a failed transaction. Something concreteley went wrong.
+#[derive(Debug)]
+pub struct TransactionError {
+    pub tx: StacksTransaction,
+    // Note: This should be an `Error` when checked in.
+    pub error: Error,
+}
+
+/// Represents a transaction that was skipped, but might succeed later.
+#[derive(Debug, Clone, PartialEq)]
+pub struct TransactionSkipped {
+    pub tx: StacksTransaction,
+    pub reason: String,
+}
+
+/// `TransactionResult` represents the outcome of transaction processing.
+/// We use this enum to involve the compiler in forcing us to always clearly
+/// indicate the outcome of a transaction.
+///
+/// There are currently three outcomes for a transaction:
+/// 1) succeed
+/// 2) fail
+/// 3) be skipped for now, to be tried again later
+#[derive(Debug)]
+pub enum TransactionResult {
+    // Transaction has already succeeded.
+    Success(TransactionSuccess),
+    // Transaction failed. It is inherently flawed and will not succeed later either.
+    Error(TransactionError),
+    // Transaction wasn't ready to be be processed, but might succeed later.
+    Skipped(TransactionSkipped),
+}
+
+impl TransactionResult {
+    // Creates a `TransactionResult` backed by `TransactionSuccess`.
+    //
+    // This method logs "transaction success" as a side effect.
+    pub fn success(
+        transaction: &StacksTransaction,
+        fee: u64,
+        receipt: StacksTransactionReceipt,
+    ) -> TransactionResult {
+        log_transaction_success(transaction);
+        TransactionResult::Success(TransactionSuccess {
+            tx: transaction.clone(),
+            fee: fee,
+            receipt: receipt,
+        })
+    }
+
+    // Creates a `TransactionResult` backed by `TransactionError`.
+    //
+    // This method logs "transaction error" as a side effect.
+    pub fn error(transaction: &StacksTransaction, error: Error) -> TransactionResult {
+        log_transaction_error(transaction, &error);
+        TransactionResult::Error(TransactionError {
+            tx: transaction.clone(),
+            error: error,
+        })
+    }
+
+    // Creates a `TransactionResult` backed by `TransactionSkipped`.
+    //
+    // This method logs "transaction skipped" as a side effect.
+    pub fn skipped(transaction: &StacksTransaction, reason: String) -> TransactionResult {
+        log_transaction_skipped(transaction, reason.clone());
+        TransactionResult::Skipped(TransactionSkipped {
+            tx: transaction.clone(),
+            reason: reason,
+        })
+    }
+
+    /// Returns true iff this enum is backed by `TransactionSuccess`.
+    pub fn is_ok(&self) -> bool {
+        match &self {
+            TransactionResult::Success(_) => true,
+            _ => false,
+        }
+    }
+
+    /// Returns a TransactionSuccess result as a pair of 1) fee and 2) receipt.
+    ///
+    /// Otherwise crashes.
+    pub fn unwrap(self) -> (u64, StacksTransactionReceipt) {
+        match self {
+            TransactionResult::Success(TransactionSuccess {
+                tx: _,
+                fee,
+                receipt,
+            }) => (fee, receipt),
+            _ => panic!("Tried to `unwrap` a non-success result."),
+        }
+    }
+
+    /// Returns true iff this enum is backed by `Error`.
+    pub fn is_err(&self) -> bool {
+        match &self {
+            TransactionResult::Error(_) => true,
+            _ => false,
+        }
+    }
+
+    /// Returns an Error result as an Error.
+    ///
+    /// Otherwise crashes.
+    pub fn unwrap_err(self) -> Error {
+        match self {
+            TransactionResult::Error(TransactionError { tx: _, error }) => error,
+            _ => panic!("Tried to `unwrap_error` a non-error result."),
+        }
+    }
+}
+
 #[derive(Debug, Clone, PartialEq)]
 pub enum StacksTransactionEvent {
     SmartContractEvent(SmartContractEventData),