From db379919f26a16740c110cc95a047920eeb6cb62 Mon Sep 17 00:00:00 2001 From: DaniPopes <57450786+DaniPopes@users.noreply.github.com> Date: Wed, 10 Apr 2024 16:23:44 +0200 Subject: [PATCH] feat(rpc): trace requests and responses --- crates/json-rpc/Cargo.toml | 1 + crates/json-rpc/src/lib.rs | 16 ++++++++++------ crates/json-rpc/src/result.rs | 8 ++++++-- crates/rpc-client/src/call.rs | 16 ++++++++++------ 4 files changed, 27 insertions(+), 14 deletions(-) diff --git a/crates/json-rpc/Cargo.toml b/crates/json-rpc/Cargo.toml index b2ef00318b1..a6ceb6e5e5f 100644 --- a/crates/json-rpc/Cargo.toml +++ b/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 diff --git a/crates/json-rpc/src/lib.rs b/crates/json-rpc/src/lib.rs index 21eb3255c98..c6b576d04e4 100644 --- a/crates/json-rpc/src/lib.rs +++ b/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 RpcParam for T where T: Serialize + Clone + Send + Sync + Unpin {} +impl 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 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 RpcReturn for T where T: DeserializeOwned + Send + Sync + Unpin + 'static {} +impl 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. /// diff --git a/crates/json-rpc/src/result.rs b/crates/json-rpc/src/result.rs index aa513494768..e3ed1c303ff 100644 --- a/crates/json-rpc/src/result.rs +++ b/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::(), 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)) } diff --git a/crates/rpc-client/src/call.rs b/crates/rpc-client/src/call.rs index 6afef99e67a..327a473fe00 100644 --- a/crates/rpc-client/src/call.rs +++ b/crates/rpc-client/src/call.rs @@ -71,7 +71,6 @@ where mut self: Pin<&mut Self>, cx: &mut task::Context<'_>, ) -> task::Poll<::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::(), ?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<::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>; - #[instrument(skip(self, cx))] fn poll(mut self: Pin<&mut Self>, cx: &mut task::Context<'_>) -> task::Poll { if matches!(*self.as_mut(), CallState::Prepared { .. }) { return self.poll_prepared(cx); @@ -284,7 +288,7 @@ where type Output = TransportResult; fn poll(self: Pin<&mut Self>, cx: &mut task::Context<'_>) -> task::Poll { - trace!(?self.state, "Polling RpcCall"); + trace!(?self.state, "polling RpcCall"); self.project().state.poll(cx).map(try_deserialize_ok) } }