Better logging when mining own transactions. (#9363)

Cargo.lock

@@ -669,7 +669,7 @@ dependencies = [
  "rlp 0.2.1 (git+https://github.com/paritytech/parity-common)",
  "rustc-hex 1.0.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "trace-time 0.1.0",
- "transaction-pool 1.12.3",
+ "transaction-pool 1.13.1",
  "url 1.5.1 (registry+https://github.com/rust-lang/crates.io-index)",
 ]
 
@@ -2171,7 +2171,7 @@ dependencies = [
  "tempdir 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)",
  "tiny-keccak 1.4.2 (registry+https://github.com/rust-lang/crates.io-index)",
  "tokio-timer 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)",
- "transaction-pool 1.12.3",
+ "transaction-pool 1.13.1",
  "transient-hashmap 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "vm 0.1.0",
 ]
@@ -3330,7 +3330,7 @@ dependencies = [
 
 [[package]]
 name = "transaction-pool"
-version = "1.12.3"
+version = "1.13.1"
 dependencies = [
  "error-chain 0.12.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "ethereum-types 0.3.2 (registry+https://github.com/rust-lang/crates.io-index)",

ethcore/service/src/service.rs

@@ -95,6 +95,7 @@ impl ClientService {
 		let pruning = config.pruning;
 		let client = Client::new(config, &spec, blockchain_db.clone(), miner.clone(), io_service.channel())?;
 		miner.set_io_channel(io_service.channel());
+		miner.set_in_chain_checker(&client.clone());
 
 		let snapshot_params = SnapServiceParams {
 			engine: spec.engine.clone(),

ethcore/src/miner/miner.rs

@@ -43,7 +43,7 @@ use using_queue::{UsingQueue, GetAction};
 use account_provider::{AccountProvider, SignError as AccountError};
 use block::{ClosedBlock, IsBlock, Block, SealedBlock};
 use client::{
-	BlockChain, ChainInfo, CallContract, BlockProducer, SealedBlockImporter, Nonce
+	BlockChain, ChainInfo, CallContract, BlockProducer, SealedBlockImporter, Nonce, TransactionInfo, TransactionId
 };
 use client::{BlockId, ClientIoMessage};
 use executive::contract_address;
@@ -296,6 +296,19 @@ impl Miner {
 		*self.io_channel.write() = Some(io_channel);
 	}
 
+	/// Sets in-blockchain checker for transactions.
+	pub fn set_in_chain_checker<C>(&self, chain: &Arc<C>) where
+		C: TransactionInfo + Send + Sync + 'static,
+	{
+		let client = Arc::downgrade(chain);
+		self.transaction_queue.set_in_chain_checker(move |hash| {
+			match client.upgrade() {
+				Some(info) => info.transaction_block(TransactionId::Hash(*hash)).is_some(),
+				None => false,
+			}
+		});
+	}
+
 	/// Clear all pending block states
 	pub fn clear(&self) {
 		self.sealing.lock().queue.reset();

miner/src/pool/listener.rs

@@ -107,8 +107,8 @@ impl txpool::Listener<Transaction> for Logger {
 		debug!(target: "txqueue", "[{:?}] Canceled by the user.", tx.hash());
 	}
 
-	fn mined(&mut self, tx: &Arc<Transaction>) {
-		debug!(target: "txqueue", "[{:?}] Mined.", tx.hash());
+	fn culled(&mut self, tx: &Arc<Transaction>) {
+		debug!(target: "txqueue", "[{:?}] Culled or mined.", tx.hash());
 	}
 }
 

miner/src/pool/local_transactions.rs

@@ -16,7 +16,7 @@
 
 //! Local Transactions List.
 
-use std::sync::Arc;
+use std::{fmt, sync::Arc};
 
 use ethereum_types::H256;
 use linked_hash_map::LinkedHashMap;
@@ -32,6 +32,8 @@ pub enum Status {
 	Pending(Arc<Transaction>),
 	/// Transaction is already mined.
 	Mined(Arc<Transaction>),
+	/// Transaction didn't get into any block, but some other tx with the same nonce got.
+	Culled(Arc<Transaction>),
 	/// Transaction is dropped because of limit
 	Dropped(Arc<Transaction>),
 	/// Replaced because of higher gas price of another transaction.
@@ -60,11 +62,22 @@ impl Status {
 }
 
 /// Keeps track of local transactions that are in the queue or were mined/dropped recently.
-#[derive(Debug)]
 pub struct LocalTransactionsList {
 	max_old: usize,
 	transactions: LinkedHashMap<H256, Status>,
 	pending: usize,
+	in_chain: Option<Box<Fn(&H256) -> bool + Send + Sync>>,
+}
+
+impl fmt::Debug for LocalTransactionsList {
+	fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result {
+		fmt.debug_struct("LocalTransactionsList")
+			.field("max_old", &self.max_old)
+			.field("transactions", &self.transactions)
+			.field("pending", &self.pending)
+			.field("in_chain", &self.in_chain.is_some())
+			.finish()
+	}
 }
 
 impl Default for LocalTransactionsList {
@@ -80,9 +93,20 @@ impl LocalTransactionsList {
 			max_old,
 			transactions: Default::default(),
 			pending: 0,
+			in_chain: None,
 		}
 	}
 
+	/// Set blockchain checker.
+	///
+	/// The function should return true if transaction is included in chain.
+	pub fn set_in_chain_checker<F, T>(&mut self, checker: T) where
+		T: Into<Option<F>>,
+		F: Fn(&H256) -> bool + Send + Sync + 'static
+	{
+		self.in_chain = checker.into().map(|f| Box::new(f) as _);
+	}
+
 	/// Returns true if the transaction is already in local transactions.
 	pub fn contains(&self, hash: &H256) -> bool {
 		self.transactions.contains_key(hash)
@@ -190,14 +214,20 @@ impl txpool::Listener<Transaction> for LocalTransactionsList {
 		self.clear_old();
 	}
 
-	/// The transaction has been mined.
-	fn mined(&mut self, tx: &Arc<Transaction>) {
+	fn culled(&mut self, tx: &Arc<Transaction>) {
 		if !tx.priority().is_local() {
 			return;
 		}
 
-		info!(target: "own_tx", "Transaction mined (hash {:?})", tx.hash());
-		self.insert(*tx.hash(), Status::Mined(tx.clone()));
+		let is_in_chain = self.in_chain.as_ref().map(|checker| checker(tx.hash())).unwrap_or(false);
+		if is_in_chain {
+			info!(target: "own_tx", "Transaction mined (hash {:?})", tx.hash());
+			self.insert(*tx.hash(), Status::Mined(tx.clone()));
+			return;
+		}
+
+		info!(target: "own_tx", "Transaction culled (hash {:?})", tx.hash());
+		self.insert(*tx.hash(), Status::Culled(tx.clone()));
 	}
 }
 
@@ -229,6 +259,26 @@ mod tests {
 		assert_eq!(statuses, vec![Status::Pending(tx1), Status::Pending(tx2)]);
 	}
 
+	#[test]
+	fn should_use_in_chain_checker_if_present() {
+		// given
+		let mut list = LocalTransactionsList::default();
+		let tx1 = new_tx(10);
+		let tx2 = new_tx(20);
+		list.culled(&tx1);
+		list.culled(&tx2);
+		let statuses = list.all_transactions().values().cloned().collect::<Vec<Status>>();
+		assert_eq!(statuses, vec![Status::Culled(tx1.clone()), Status::Culled(tx2.clone())]);
+
+		// when
+		list.set_in_chain_checker(|_: &_| true);
+		list.culled(&tx1);
+
+		// then
+		let statuses = list.all_transactions().values().cloned().collect::<Vec<Status>>();
+		assert_eq!(statuses, vec![Status::Culled(tx2), Status::Mined(tx1)]);
+	}
+
 	#[test]
 	fn should_clear_old_transactions() {
 		// given

miner/src/pool/queue.rs

@@ -229,6 +229,13 @@ impl TransactionQueue {
 		*self.options.write() = options;
 	}
 
+	/// Sets the in-chain transaction checker for pool listener.
+	pub fn set_in_chain_checker<F>(&self, f: F) where
+		F: Fn(&H256) -> bool + Send + Sync + 'static
+	{
+		self.pool.write().listener_mut().0.set_in_chain_checker(f)
+	}
+
 	/// Import a set of transactions to the pool.
 	///
 	/// Given blockchain and state access (Client)

rpc/src/v1/types/transaction.rs

@@ -82,8 +82,10 @@ pub enum LocalTransactionStatus {
 	Pending,
 	/// Transaction is in future part of the queue
 	Future,
-	/// Transaction is already mined.
+	/// Transaction was mined.
 	Mined(Transaction),
+	/// Transaction was removed from the queue, but not mined.
+	Culled(Transaction),
 	/// Transaction was dropped because of limit.
 	Dropped(Transaction),
 	/// Transaction was replaced by transaction with higher gas price.
@@ -104,7 +106,7 @@ impl Serialize for LocalTransactionStatus {
 
 		let elems = match *self {
 			Pending | Future => 1,
-			Mined(..) | Dropped(..) | Invalid(..) | Canceled(..) => 2,
+			Mined(..) | Culled(..) | Dropped(..) | Invalid(..) | Canceled(..) => 2,
 			Rejected(..) => 3,
 			Replaced(..) => 4,
 		};
@@ -120,6 +122,10 @@ impl Serialize for LocalTransactionStatus {
 				struc.serialize_field(status, "mined")?;
 				struc.serialize_field(transaction, tx)?;
 			},
+			Culled(ref tx) => {
+				struc.serialize_field(status, "culled")?;
+				struc.serialize_field(transaction, tx)?;
+			},
 			Dropped(ref tx) => {
 				struc.serialize_field(status, "dropped")?;
 				struc.serialize_field(transaction, tx)?;
@@ -257,6 +263,7 @@ impl LocalTransactionStatus {
 		match s {
 			Pending(_) => LocalTransactionStatus::Pending,
 			Mined(tx) => LocalTransactionStatus::Mined(convert(tx)),
+			Culled(tx) => LocalTransactionStatus::Culled(convert(tx)),
 			Dropped(tx) => LocalTransactionStatus::Dropped(convert(tx)),
 			Rejected(tx, reason) => LocalTransactionStatus::Rejected(convert(tx), reason),
 			Invalid(tx) => LocalTransactionStatus::Invalid(convert(tx)),

transaction-pool/Cargo.toml

@@ -1,7 +1,7 @@
 [package]
 description = "Generic transaction pool."
 name = "transaction-pool"
-version = "1.12.3"
+version = "1.13.1"
 license = "GPL-3.0"
 authors = ["Parity Technologies <admin@parity.io>"]
 

transaction-pool/src/listener.rs

@@ -40,8 +40,8 @@ pub trait Listener<T> {
 	/// The transaction has been canceled.
 	fn canceled(&mut self, _tx: &Arc<T>) {}
 
-	/// The transaction has been mined.
-	fn mined(&mut self, _tx: &Arc<T>) {}
+	/// The transaction has been culled from the pool.
+	fn culled(&mut self, _tx: &Arc<T>) {}
 }
 
 /// A no-op implementation of `Listener`.
@@ -78,8 +78,8 @@ impl<T, A, B> Listener<T> for (A, B) where
 		self.1.canceled(tx);
 	}
 
-	fn mined(&mut self, tx: &Arc<T>) {
-		self.0.mined(tx);
-		self.1.mined(tx);
+	fn culled(&mut self, tx: &Arc<T>) {
+		self.0.culled(tx);
+		self.1.culled(tx);
 	}
 }

transaction-pool/src/pool.rs

@@ -370,7 +370,7 @@ impl<T, S, L> Pool<T, S, L> where
 				let len = removed.len();
 				for tx in removed {
 					self.finalize_remove(tx.hash());
-					self.listener.mined(&tx);
+					self.listener.culled(&tx);
 				}
 				len
 			},

transaction-pool/src/tests/mod.rs

@@ -648,8 +648,8 @@ mod listener {
 			self.0.borrow_mut().push("canceled".into());
 		}
 
-		fn mined(&mut self, _tx: &SharedTransaction) {
-			self.0.borrow_mut().push("mined".into());
+		fn culled(&mut self, _tx: &SharedTransaction) {
+			self.0.borrow_mut().push("culled".into());
 		}
 	}
 
@@ -743,6 +743,6 @@ mod listener {
 		txq.cull(None, NonceReady::new(3));
 
 		// then
-		assert_eq!(*results.borrow(), &["added", "added", "mined", "mined"]);
+		assert_eq!(*results.borrow(), &["added", "added", "culled", "culled"]);
 	}
 }