From c3e7d749ede971e72665834bd5f4427c53248a3b Mon Sep 17 00:00:00 2001 From: teor Date: Sat, 22 Jul 2023 06:35:56 +1000 Subject: [PATCH] fix(log): Limit verbose RPC responses in logs (#7258) * Truncate verbose RPC responses in test logs * Downgrade verbose block template state log to debug --- zebra-chain/src/transaction/serialize.rs | 11 ++++- .../types/get_block_template.rs | 41 ++++++++++++++++++- zebra-state/src/service.rs | 2 +- .../get_block_template.rs | 10 ++++- 4 files changed, 60 insertions(+), 4 deletions(-) diff --git a/zebra-chain/src/transaction/serialize.rs b/zebra-chain/src/transaction/serialize.rs index e083921b..dd8a8c2e 100644 --- a/zebra-chain/src/transaction/serialize.rs +++ b/zebra-chain/src/transaction/serialize.rs @@ -1023,8 +1023,17 @@ impl fmt::Display for SerializedTransaction { impl fmt::Debug for SerializedTransaction { fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + // A transaction with a lot of transfers can be extremely long in logs. + let mut data_truncated = hex::encode(&self.bytes); + if data_truncated.len() > 1003 { + let end = data_truncated.len() - 500; + // Replace the middle bytes with "...", but leave 500 bytes on either side. + // The data is hex, so this replacement won't panic. + data_truncated.replace_range(500..=end, "..."); + } + f.debug_tuple("SerializedTransaction") - .field(&hex::encode(&self.bytes)) + .field(&data_truncated) .finish() } } diff --git a/zebra-rpc/src/methods/get_block_template_rpcs/types/get_block_template.rs b/zebra-rpc/src/methods/get_block_template_rpcs/types/get_block_template.rs index df85939e..617b8008 100644 --- a/zebra-rpc/src/methods/get_block_template_rpcs/types/get_block_template.rs +++ b/zebra-rpc/src/methods/get_block_template_rpcs/types/get_block_template.rs @@ -1,6 +1,8 @@ //! The `GetBlockTempate` type is the output of the `getblocktemplate` RPC method in the //! default 'template' mode. See [`ProposalResponse`] for the output in 'proposal' mode. +use std::fmt; + use zebra_chain::{ amount, block::{ChainHistoryBlockTxAuthCommitmentHash, MAX_BLOCK_BYTES, ZCASH_BLOCK_VERSION}, @@ -34,7 +36,7 @@ pub use parameters::{GetBlockTemplateCapability, GetBlockTemplateRequestMode, Js pub use proposal::{proposal_block_from_template, ProposalResponse}; /// A serialized `getblocktemplate` RPC response in template mode. -#[derive(Clone, Debug, Eq, PartialEq, serde::Serialize, serde::Deserialize)] +#[derive(Clone, Eq, PartialEq, serde::Serialize, serde::Deserialize)] pub struct GetBlockTemplate { /// The getblocktemplate RPC capabilities supported by Zebra. /// @@ -167,6 +169,43 @@ pub struct GetBlockTemplate { pub submit_old: Option, } +impl fmt::Debug for GetBlockTemplate { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + // A block with a lot of transactions can be extremely long in logs. + let mut transactions_truncated = self.transactions.clone(); + if self.transactions.len() > 4 { + // Remove transaction 3 onwards, but leave the last transaction + let end = self.transactions.len() - 2; + transactions_truncated.splice(3..=end, Vec::new()); + } + + f.debug_struct("GetBlockTemplate") + .field("capabilities", &self.capabilities) + .field("version", &self.version) + .field("previous_block_hash", &self.previous_block_hash) + .field("block_commitments_hash", &self.block_commitments_hash) + .field("light_client_root_hash", &self.light_client_root_hash) + .field("final_sapling_root_hash", &self.final_sapling_root_hash) + .field("default_roots", &self.default_roots) + .field("transaction_count", &self.transactions.len()) + .field("transactions", &transactions_truncated) + .field("coinbase_txn", &self.coinbase_txn) + .field("long_poll_id", &self.long_poll_id) + .field("target", &self.target) + .field("min_time", &self.min_time) + .field("mutable", &self.mutable) + .field("nonce_range", &self.nonce_range) + .field("sigop_limit", &self.sigop_limit) + .field("size_limit", &self.size_limit) + .field("cur_time", &self.cur_time) + .field("bits", &self.bits) + .field("height", &self.height) + .field("max_time", &self.max_time) + .field("submit_old", &self.submit_old) + .finish() + } +} + impl GetBlockTemplate { /// Returns a `Vec` of capabilities supported by the `getblocktemplate` RPC pub fn capabilities() -> Vec { diff --git a/zebra-state/src/service.rs b/zebra-state/src/service.rs index d2a8eb23..5340ef14 100644 --- a/zebra-state/src/service.rs +++ b/zebra-state/src/service.rs @@ -1751,7 +1751,7 @@ impl Service for ReadStateService { tokio::task::spawn_blocking(move || { span.in_scope(move || { - tracing::info!("attempting to validate and commit block proposal onto a cloned non-finalized state"); + tracing::debug!("attempting to validate and commit block proposal onto a cloned non-finalized state"); let mut latest_non_finalized_state = state.latest_non_finalized_state(); // The previous block of a valid proposal must be on the best chain tip. diff --git a/zebrad/tests/common/get_block_template_rpcs/get_block_template.rs b/zebrad/tests/common/get_block_template_rpcs/get_block_template.rs index 81a8ad49..e6bd3d3d 100644 --- a/zebrad/tests/common/get_block_template_rpcs/get_block_template.rs +++ b/zebrad/tests/common/get_block_template_rpcs/get_block_template.rs @@ -106,7 +106,15 @@ pub(crate) async fn run() -> Result<()> { .await?; let is_response_success = getblocktemplate_response.status().is_success(); - let response_text = getblocktemplate_response.text().await?; + + let mut response_text = getblocktemplate_response.text().await?; + // This string can be extremely long in logs. + if response_text.len() > 1003 { + let end = response_text.len() - 500; + // Replace the middle bytes with "...", but leave 500 bytes on either side. + // The response text is ascii, so this replacement won't panic. + response_text.replace_range(500..=end, "..."); + } tracing::info!( response_text,