fix(log): Limit RPC failure log length, add details to RPC failure logs (#6754)

* Limit the RPC failure log length

* Add more specific logs for some RPC tests

* Make sure the block hash is always available for logging

zebra-rpc/src/constants.rs

@@ -16,3 +16,6 @@ pub const INVALID_PARAMETERS_ERROR_CODE: ErrorCode = ErrorCode::ServerError(-1);
 /// `lightwalletd` expects error code `-8` when a block is not found:
 /// <https://github.com/adityapk00/lightwalletd/blob/c1bab818a683e4de69cd952317000f9bb2932274/common/common.go#L251-L254>
 pub const MISSING_BLOCK_ERROR_CODE: ErrorCode = ErrorCode::ServerError(-8);
+
+/// When logging parameter data, only log this much data.
+pub const MAX_PARAMS_LOG_LENGTH: usize = 100;

zebra-rpc/src/methods/get_block_template_rpcs.rs

@@ -737,7 +737,7 @@ where
             let block: Block = match block_bytes.zcash_deserialize_into() {
                 Ok(block_bytes) => block_bytes,
                 Err(error) => {
-                    tracing::info!(?error, "submit block failed");
+                    tracing::info!(?error, "submit block failed: block bytes could not be deserialized into a structurally valid block");
 
                     return Ok(submit_block::ErrorResponse::Rejected.into());
                 }
@@ -747,6 +747,7 @@ where
                 .coinbase_height()
                 .map(|height| height.0.to_string())
                 .unwrap_or_else(|| "invalid coinbase height".to_string());
+            let block_hash = block.hash();
 
             let chain_verifier_response = chain_verifier
                 .ready()
@@ -778,8 +779,7 @@ where
                         .downcast::<VerifyChainError>()
                         .map(|boxed_chain_error| *boxed_chain_error);
 
-                    // TODO: add block hash to error?
-                    tracing::info!(?error, ?block_height, "submit block failed");
+                    tracing::info!(?error, ?block_hash, ?block_height, "submit block failed verification");
 
                     error
                 }

zebra-rpc/src/server/rpc_call_compatibility.rs

@@ -12,7 +12,7 @@ use jsonrpc_core::{
     BoxFuture, ErrorCode, Metadata, MethodCall, Notification,
 };
 
-use crate::constants::INVALID_PARAMETERS_ERROR_CODE;
+use crate::constants::{INVALID_PARAMETERS_ERROR_CODE, MAX_PARAMS_LOG_LENGTH};
 
 /// JSON-RPC [`Middleware`] with compatibility workarounds.
 ///
@@ -75,10 +75,22 @@ impl FixRpcResponseMiddleware {
     fn call_description(call: &Call) -> String {
         match call {
             Call::MethodCall(MethodCall { method, params, .. }) => {
-                format!(r#"method = {method:?}, params = {params:?}"#)
+                let mut params = format!("{params:?}");
+                if params.len() >= MAX_PARAMS_LOG_LENGTH {
+                    params.truncate(MAX_PARAMS_LOG_LENGTH);
+                    params.push_str("...");
+                }
+
+                format!(r#"method = {method:?}, params = {params}"#)
             }
             Call::Notification(Notification { method, params, .. }) => {
-                format!(r#"notification = {method:?}, params = {params:?}"#)
+                let mut params = format!("{params:?}");
+                if params.len() >= MAX_PARAMS_LOG_LENGTH {
+                    params.truncate(MAX_PARAMS_LOG_LENGTH);
+                    params.push_str("...");
+                }
+
+                format!(r#"notification = {method:?}, params = {params}"#)
             }
             Call::Invalid { .. } => "invalid request".to_owned(),
         }

zebrad/tests/common/get_block_template_rpcs/submit_block.rs

@@ -75,7 +75,10 @@ pub(crate) async fn run() -> Result<()> {
         let res_text = res.text().await?;
 
         // Test rpc endpoint response
-        assert!(res_text.contains(r#""result":null"#));
+        assert!(
+            res_text.contains(r#""result":null"#),
+            "unexpected response from submitblock RPC, should be null, was: {res_text}"
+        );
     }
 
     zebrad.kill(false)?;