feat(rpc): trace requests and responses

crates/json-rpc/Cargo.toml

@@ -16,3 +16,4 @@ alloy-primitives = { workspace = true, features = ["std", "serde"] }
 serde.workspace = true
 serde_json = { workspace = true, features = ["std", "raw_value"] }
 thiserror.workspace = true
+tracing.workspace = true

crates/json-rpc/src/lib.rs

@@ -82,6 +82,12 @@
 #![deny(unused_must_use, rust_2018_idioms)]
 #![cfg_attr(docsrs, feature(doc_cfg, doc_auto_cfg))]
 
+#[macro_use]
+extern crate tracing;
+
+use serde::{de::DeserializeOwned, Serialize};
+use std::fmt::Debug;
+
 mod common;
 pub use common::Id;
 
@@ -108,15 +114,13 @@ pub use result::{
     transform_response, transform_result, try_deserialize_ok, BorrowedRpcResult, RpcResult,
 };
 
-use serde::{de::DeserializeOwned, Serialize};
-
 /// An object that can be used as a JSON-RPC parameter.
 ///
 /// This marker trait is blanket-implemented for every qualifying type. It is
 /// used to indicate that a type can be used as a JSON-RPC parameter.
-pub trait RpcParam: Serialize + Clone + Send + Sync + Unpin {}
+pub trait RpcParam: Serialize + Clone + Debug + Send + Sync + Unpin {}
 
-impl<T> RpcParam for T where T: Serialize + Clone + Send + Sync + Unpin {}
+impl<T> RpcParam for T where T: Serialize + Clone + Debug + Send + Sync + Unpin {}
 
 /// An object that can be used as a JSON-RPC return value.
 ///
@@ -128,9 +132,9 @@ impl<T> RpcParam for T where T: Serialize + Clone + Send + Sync + Unpin {}
 /// We add the `'static` lifetime bound to indicate that the type can't borrow.
 /// This is a simplification that makes it easier to use the types in client
 /// code. It is not suitable for use in server code.
-pub trait RpcReturn: DeserializeOwned + Send + Sync + Unpin + 'static {}
+pub trait RpcReturn: DeserializeOwned + Debug + Send + Sync + Unpin + 'static {}
 
-impl<T> RpcReturn for T where T: DeserializeOwned + Send + Sync + Unpin + 'static {}
+impl<T> RpcReturn for T where T: DeserializeOwned + Debug + Send + Sync + Unpin + 'static {}
 
 /// An object that can be used as a JSON-RPC parameter and return value.
 ///

crates/json-rpc/src/result.rs

@@ -62,6 +62,10 @@ where
     ErrResp: RpcReturn,
 {
     let json = result?;
-    let text = json.borrow().get();
-    serde_json::from_str(text).map_err(|err| RpcError::deser_err(err, text))
+    let json = json.borrow().get();
+    trace!(ty=%std::any::type_name::<T>(), json, "deserializing response");
+    serde_json::from_str(json)
+        .inspect(|response| trace!(?response, "deserialized response"))
+        .inspect_err(|err| trace!(?err, "failed to deserialize response"))
+        .map_err(|err| RpcError::deser_err(err, json))
 }

crates/rpc-client/src/call.rs

@@ -71,7 +71,6 @@ where
         mut self: Pin<&mut Self>,
         cx: &mut task::Context<'_>,
     ) -> task::Poll<<Self as Future>::Output> {
-        trace!("Polling prepared");
         let fut = {
             let CallStateProj::Prepared { connection, request } = self.as_mut().project() else {
                 unreachable!("Called poll_prepared in incorrect state")
@@ -81,11 +80,18 @@ where
                 self.set(CallState::Complete);
                 return Ready(RpcResult::Err(e));
             }
-            let request = request.take().expect("no request").serialize();
 
+            let request = request.take().expect("no request");
+            debug!(method=%request.meta.method, id=%request.meta.id, "sending request");
+            trace!(params_ty=%std::any::type_name::<Params>(), ?request, "full request");
+            let request = request.serialize();
             match request {
-                Ok(request) => connection.call(request.into()),
+                Ok(request) => {
+                    trace!(request=%request.serialized(), "serialized request");
+                    connection.call(request.into())
+                }
                 Err(err) => {
+                    trace!(?err, "failed to serialize request");
                     self.set(CallState::Complete);
                     return Ready(RpcResult::Err(TransportError::ser_err(err)));
                 }
@@ -102,7 +108,6 @@ where
         mut self: Pin<&mut Self>,
         cx: &mut task::Context<'_>,
     ) -> task::Poll<<Self as Future>::Output> {
-        trace!("Polling awaiting");
         let CallStateProj::AwaitingResponse { fut } = self.as_mut().project() else {
             unreachable!("Called poll_awaiting in incorrect state")
         };
@@ -122,7 +127,6 @@ where
 {
     type Output = TransportResult<Box<RawValue>>;
 
-    #[instrument(skip(self, cx))]
     fn poll(mut self: Pin<&mut Self>, cx: &mut task::Context<'_>) -> task::Poll<Self::Output> {
         if matches!(*self.as_mut(), CallState::Prepared { .. }) {
             return self.poll_prepared(cx);
@@ -284,7 +288,7 @@ where
     type Output = TransportResult<Resp>;
 
     fn poll(self: Pin<&mut Self>, cx: &mut task::Context<'_>) -> task::Poll<Self::Output> {
-        trace!(?self.state, "Polling RpcCall");
+        trace!(?self.state, "polling RpcCall");
         self.project().state.poll(cx).map(try_deserialize_ok)
     }
 }