From 0ee482356fbf58aae4b7a512dcfff472eca6bca4 Mon Sep 17 00:00:00 2001 From: Shawn Date: Fri, 4 Oct 2024 09:21:46 +0800 Subject: [PATCH 1/5] Added timing probes. --- zilliqa/src/consensus.rs | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/zilliqa/src/consensus.rs b/zilliqa/src/consensus.rs index 5a54cab26..3f80d7446 100644 --- a/zilliqa/src/consensus.rs +++ b/zilliqa/src/consensus.rs @@ -2617,6 +2617,8 @@ impl Consensus { transactions: Vec, committee: &[NodePublicKeyRaw], ) -> Result<()> { + let len = transactions.len(); + let start = std::time::Instant::now(); debug!("Executing block: {:?}", block.header.hash); let parent = self @@ -2627,8 +2629,10 @@ impl Consensus { trace!("applying {} transactions to state", transactions.len()); } + let now = std::time::Instant::now(); let transactions: Result> = transactions.into_iter().map(|tx| tx.verify()).collect(); let mut transactions = transactions?; + info!("{} ELAPSED_VER {:?}", len, now.elapsed()); let transaction_hashes = transactions .iter() @@ -2638,6 +2642,7 @@ impl Consensus { // We re-inject any missing Intershard transactions (or really, any missing // transactions) from our mempool. If any txs are unavailable either in the // message or locally, the proposal cannot be applied + let now = std::time::Instant::now(); for (idx, tx_hash) in block.transactions.iter().enumerate() { if transactions.get(idx).is_some_and(|tx| tx.hash == *tx_hash) { // all good @@ -2649,6 +2654,7 @@ impl Consensus { transactions.insert(idx, local_tx); } } + info!("{} ELAPSED_INS {:?}", len, now.elapsed()); self.apply_rewards(committee, &parent, block.view(), &block.header.qc.cosigned)?; @@ -2666,6 +2672,7 @@ impl Consensus { let mut receipts_trie = eth_trie::EthTrie::new(Arc::new(MemoryDB::new(true))); let mut transactions_trie = eth_trie::EthTrie::new(Arc::new(MemoryDB::new(true))); + let now = std::time::Instant::now(); for (tx_index, txn) in transactions.into_iter().enumerate() { self.new_transaction(txn.clone())?; let tx_hash = txn.hash; @@ -2702,6 +2709,7 @@ impl Consensus { info!(?receipt, "applied transaction {:?}", receipt); block_receipts.push((receipt, tx_index)); } + info!("{} ELAPSED_APP {:?}", len, now.elapsed()); if cumulative_gas_used != block.gas_used() { warn!("Cumulative gas used by executing all transactions: {cumulative_gas_used} is different that the one provided in the block: {}", block.gas_used()); @@ -2741,6 +2749,7 @@ impl Consensus { )); } + let now = std::time::Instant::now(); for (receipt, tx_index) in &mut block_receipts { receipt.block_hash = block.hash(); // Avoid cloning the receipt if there are no subscriptions to send it to. @@ -2748,6 +2757,7 @@ impl Consensus { let _ = self.receipts.send((receipt.clone(), *tx_index)); } } + info!("{} ELAPSED_RCT {:?}", len, now.elapsed()); // Important - only add blocks we are going to execute because they can potentially // overwrite the mapping of block height to block, which there should only be one of. @@ -2761,16 +2771,18 @@ impl Consensus { // closure has to be move to take ownership of block_receipts let db = &self.db; self.db.with_sqlite_tx(move |sqlite_tx| { + let now = std::time::Instant::now(); for (receipt, _) in block_receipts { db.insert_transaction_receipt_with_db_tx(sqlite_tx, receipt)?; } + info!("{} ELAPSED_SQL {:?}", len, now.elapsed()); Ok(()) })?; } // Tell the block store to request more blocks if it can. self.block_store.request_missing_blocks()?; - + info!("{} ELAPSED_EXE {:?}", len, start.elapsed()); Ok(()) } From 4cbe8afdda91ba0c9419018d0aa564cc050a7926 Mon Sep 17 00:00:00 2001 From: Shawn Date: Fri, 4 Oct 2024 10:22:01 +0800 Subject: [PATCH 2/5] Reduced recover_signer() call when assembling the list of txns in execute_block(). Makes it up to 1,500x faster. --- zilliqa/src/consensus.rs | 39 ++++++++++++++++++++------------------- 1 file changed, 20 insertions(+), 19 deletions(-) diff --git a/zilliqa/src/consensus.rs b/zilliqa/src/consensus.rs index 3f80d7446..3a1401b79 100644 --- a/zilliqa/src/consensus.rs +++ b/zilliqa/src/consensus.rs @@ -2629,33 +2629,34 @@ impl Consensus { trace!("applying {} transactions to state", transactions.len()); } - let now = std::time::Instant::now(); - let transactions: Result> = transactions.into_iter().map(|tx| tx.verify()).collect(); - let mut transactions = transactions?; - info!("{} ELAPSED_VER {:?}", len, now.elapsed()); - - let transaction_hashes = transactions - .iter() - .map(|tx| format!("{:?}", tx.hash)) - .join(","); + let mut verified_txns = Vec::new(); // We re-inject any missing Intershard transactions (or really, any missing // transactions) from our mempool. If any txs are unavailable either in the // message or locally, the proposal cannot be applied let now = std::time::Instant::now(); for (idx, tx_hash) in block.transactions.iter().enumerate() { - if transactions.get(idx).is_some_and(|tx| tx.hash == *tx_hash) { - // all good - } else { - let Some(local_tx) = self.transaction_pool.pop_transaction(*tx_hash) else { - warn!("Proposal {} at view {} referenced a transaction {} that was neither included in the broadcast nor found locally - cannot apply block", block.hash(), block.view(), tx_hash); - return Ok(()); - }; - transactions.insert(idx, local_tx); - } + // Attempt to insert verified txns from pool. + if let Some(local_tx) = self.transaction_pool.pop_transaction(*tx_hash) { + verified_txns.insert(idx, local_tx); + continue; + }; + // And recover missing txns from block + if let Some(block_tx) = transactions.get(idx) { + verified_txns.insert(idx, block_tx.clone().verify()?); + continue; + }; + + warn!("Proposal {} at view {} referenced a transaction {} that was neither included in the broadcast nor found locally - cannot apply block", block.hash(), block.view(), tx_hash); + return Ok(()); } info!("{} ELAPSED_INS {:?}", len, now.elapsed()); + let transaction_hashes = verified_txns + .iter() + .map(|tx| format!("{:?}", tx.hash)) + .join(","); + self.apply_rewards(committee, &parent, block.view(), &block.header.qc.cosigned)?; // ZIP-9: Sink gas to zero account @@ -2673,7 +2674,7 @@ impl Consensus { let mut transactions_trie = eth_trie::EthTrie::new(Arc::new(MemoryDB::new(true))); let now = std::time::Instant::now(); - for (tx_index, txn) in transactions.into_iter().enumerate() { + for (tx_index, txn) in verified_txns.into_iter().enumerate() { self.new_transaction(txn.clone())?; let tx_hash = txn.hash; let mut inspector = TouchedAddressInspector::default(); From 125a18ec1212bd87f53b5fcfdc8f1d736ceba86a Mon Sep 17 00:00:00 2001 From: Shawn Date: Fri, 4 Oct 2024 11:12:35 +0800 Subject: [PATCH 3/5] Made it more idiomatic. --- zilliqa/src/consensus.rs | 30 +++++++++++++++++------------- 1 file changed, 17 insertions(+), 13 deletions(-) diff --git a/zilliqa/src/consensus.rs b/zilliqa/src/consensus.rs index 3a1401b79..f3f86c35a 100644 --- a/zilliqa/src/consensus.rs +++ b/zilliqa/src/consensus.rs @@ -2632,24 +2632,28 @@ impl Consensus { let mut verified_txns = Vec::new(); // We re-inject any missing Intershard transactions (or really, any missing - // transactions) from our mempool. If any txs are unavailable either in the + // transactions) from our mempool. If any txs are unavailable in both the // message or locally, the proposal cannot be applied let now = std::time::Instant::now(); for (idx, tx_hash) in block.transactions.iter().enumerate() { - // Attempt to insert verified txns from pool. - if let Some(local_tx) = self.transaction_pool.pop_transaction(*tx_hash) { - verified_txns.insert(idx, local_tx); - continue; - }; - // And recover missing txns from block - if let Some(block_tx) = transactions.get(idx) { - verified_txns.insert(idx, block_tx.clone().verify()?); - continue; + // Prefer to insert verified txn from pool. This is faster. + let txn = match self.transaction_pool.pop_transaction(*tx_hash) { + Some(txn) if txn.hash == *tx_hash => txn, + _ => match transactions + .get(idx) + .and_then(|sig_tx| sig_tx.clone().verify().ok()) + { + // Otherwise, recover txn from proposal. This is slower. + Some(txn) if txn.hash == *tx_hash => txn, + _ => { + warn!("Proposal {} at view {} referenced a transaction {} that was neither included in the broadcast nor found locally - cannot apply block", block.hash(), block.view(), tx_hash); + return Ok(()); + } + }, }; - - warn!("Proposal {} at view {} referenced a transaction {} that was neither included in the broadcast nor found locally - cannot apply block", block.hash(), block.view(), tx_hash); - return Ok(()); + verified_txns.insert(idx, txn); } + info!("{} ELAPSED_INS {:?}", len, now.elapsed()); let transaction_hashes = verified_txns From d388eb829d207b6a51b4824ac836523c060324f2 Mon Sep 17 00:00:00 2001 From: Shawn Date: Fri, 4 Oct 2024 14:42:39 +0800 Subject: [PATCH 4/5] Removed logging/probes. --- zilliqa/src/consensus.rs | 12 ------------ 1 file changed, 12 deletions(-) diff --git a/zilliqa/src/consensus.rs b/zilliqa/src/consensus.rs index f3f86c35a..20021e3f6 100644 --- a/zilliqa/src/consensus.rs +++ b/zilliqa/src/consensus.rs @@ -2617,8 +2617,6 @@ impl Consensus { transactions: Vec, committee: &[NodePublicKeyRaw], ) -> Result<()> { - let len = transactions.len(); - let start = std::time::Instant::now(); debug!("Executing block: {:?}", block.header.hash); let parent = self @@ -2634,7 +2632,6 @@ impl Consensus { // We re-inject any missing Intershard transactions (or really, any missing // transactions) from our mempool. If any txs are unavailable in both the // message or locally, the proposal cannot be applied - let now = std::time::Instant::now(); for (idx, tx_hash) in block.transactions.iter().enumerate() { // Prefer to insert verified txn from pool. This is faster. let txn = match self.transaction_pool.pop_transaction(*tx_hash) { @@ -2654,8 +2651,6 @@ impl Consensus { verified_txns.insert(idx, txn); } - info!("{} ELAPSED_INS {:?}", len, now.elapsed()); - let transaction_hashes = verified_txns .iter() .map(|tx| format!("{:?}", tx.hash)) @@ -2677,7 +2672,6 @@ impl Consensus { let mut receipts_trie = eth_trie::EthTrie::new(Arc::new(MemoryDB::new(true))); let mut transactions_trie = eth_trie::EthTrie::new(Arc::new(MemoryDB::new(true))); - let now = std::time::Instant::now(); for (tx_index, txn) in verified_txns.into_iter().enumerate() { self.new_transaction(txn.clone())?; let tx_hash = txn.hash; @@ -2714,7 +2708,6 @@ impl Consensus { info!(?receipt, "applied transaction {:?}", receipt); block_receipts.push((receipt, tx_index)); } - info!("{} ELAPSED_APP {:?}", len, now.elapsed()); if cumulative_gas_used != block.gas_used() { warn!("Cumulative gas used by executing all transactions: {cumulative_gas_used} is different that the one provided in the block: {}", block.gas_used()); @@ -2754,7 +2747,6 @@ impl Consensus { )); } - let now = std::time::Instant::now(); for (receipt, tx_index) in &mut block_receipts { receipt.block_hash = block.hash(); // Avoid cloning the receipt if there are no subscriptions to send it to. @@ -2762,7 +2754,6 @@ impl Consensus { let _ = self.receipts.send((receipt.clone(), *tx_index)); } } - info!("{} ELAPSED_RCT {:?}", len, now.elapsed()); // Important - only add blocks we are going to execute because they can potentially // overwrite the mapping of block height to block, which there should only be one of. @@ -2776,18 +2767,15 @@ impl Consensus { // closure has to be move to take ownership of block_receipts let db = &self.db; self.db.with_sqlite_tx(move |sqlite_tx| { - let now = std::time::Instant::now(); for (receipt, _) in block_receipts { db.insert_transaction_receipt_with_db_tx(sqlite_tx, receipt)?; } - info!("{} ELAPSED_SQL {:?}", len, now.elapsed()); Ok(()) })?; } // Tell the block store to request more blocks if it can. self.block_store.request_missing_blocks()?; - info!("{} ELAPSED_EXE {:?}", len, start.elapsed()); Ok(()) } From 0ec617f9a198f5e8fb660b6233218c9864ce62de Mon Sep 17 00:00:00 2001 From: Shawn Date: Mon, 7 Oct 2024 09:21:26 +0800 Subject: [PATCH 5/5] Fixed review comments. --- zilliqa/src/consensus.rs | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/zilliqa/src/consensus.rs b/zilliqa/src/consensus.rs index 20021e3f6..1568fec8a 100644 --- a/zilliqa/src/consensus.rs +++ b/zilliqa/src/consensus.rs @@ -2635,10 +2635,11 @@ impl Consensus { for (idx, tx_hash) in block.transactions.iter().enumerate() { // Prefer to insert verified txn from pool. This is faster. let txn = match self.transaction_pool.pop_transaction(*tx_hash) { - Some(txn) if txn.hash == *tx_hash => txn, + Some(txn) => txn, _ => match transactions .get(idx) - .and_then(|sig_tx| sig_tx.clone().verify().ok()) + .map(|sig_tx| sig_tx.clone().verify()) + .transpose()? { // Otherwise, recover txn from proposal. This is slower. Some(txn) if txn.hash == *tx_hash => txn, @@ -2648,7 +2649,7 @@ impl Consensus { } }, }; - verified_txns.insert(idx, txn); + verified_txns.push(txn); } let transaction_hashes = verified_txns