Structured logs for relayer logic

relayer/src/chain/cosmos.rs

@@ -1054,7 +1054,8 @@ impl ChainEndpoint for CosmosSdkChain {
  ) -> Result<Vec<IbcEvent>, Error> {
  crate::time!("send_messages_and_wait_commit");
 
- let _span = span!(Level::DEBUG, "send_w", id = %tracked_msgs).entered();
+ let _span =
+ span!(Level::DEBUG, "send_tx_commit", id = %tracked_msgs.tracking_id()).entered();
 
  let proto_msgs = tracked_msgs.messages();
 
@@ -1111,7 +1112,7 @@ impl ChainEndpoint for CosmosSdkChain {
  ) -> Result<Vec<Response>, Error> {
  crate::time!("send_messages_and_wait_check_tx");
 
- let span = span!(Level::DEBUG, "send", id = %tracked_msgs);
+ let span = span!(Level::DEBUG, "send_tx_check", id = %tracked_msgs.tracking_id());
  let _enter = span.enter();
 
  let proto_msgs = tracked_msgs.messages();

relayer/src/chain/tx.rs

@@ -1,5 +1,3 @@
-use core::fmt;
-
 use prost_types::Any;
 
 /// A wrapper over a vector of proto-encoded messages
@@ -15,33 +13,31 @@ pub struct TrackedMsgs {
 }
 
 impl TrackedMsgs {
- pub fn new(msgs: Vec<Any>, tid: &str) -> Self {
+ pub fn new(msgs: Vec<Any>, tid: impl Into<String>) -> Self {
  Self {
  msgs,
  tracking_id: tid.into(),
  }
  }
 
- pub fn messages(&self) -> &Vec<Any> {
- &self.msgs
- }
-
- pub fn new_single(msg: Any, tid: &str) -> Self {
+ pub fn new_single(msg: Any, tid: impl Into<String>) -> Self {
  Self {
  msgs: vec![msg],
  tracking_id: tid.into(),
  }
  }
+
+ pub fn messages(&self) -> &Vec<Any> {
+ &self.msgs
+ }
+
+ pub fn tracking_id(&self) -> &str {
+ &self.tracking_id
+ }
 }
 
 impl From<TrackedMsgs> for Vec<Any> {
  fn from(tm: TrackedMsgs) -> Vec<Any> {
  tm.msgs
  }
 }
-
-impl fmt::Display for TrackedMsgs {
- fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
- write!(f, "{}; len={}", self.tracking_id, self.msgs.len())
- }
-}

relayer/src/channel.rs

@@ -704,7 +704,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Channel<ChainA, ChainB> {
  pub fn build_chan_open_init_and_send(&self) -> Result<IbcEvent, ChannelError> {
  let dst_msgs = self.build_chan_open_init()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create channel");
+ let tm = TrackedMsgs::new(dst_msgs, "create channel with ChannelOpenInit");
 
  let events = self
  .dst_chain()
@@ -870,7 +870,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Channel<ChainA, ChainB> {
  pub fn build_chan_open_try_and_send(&self) -> Result<IbcEvent, ChannelError> {
  let dst_msgs = self.build_chan_open_try()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create channel");
+ let tm = TrackedMsgs::new(dst_msgs, "create channel with ChannelOpenTry");
 
  let events = self
  .dst_chain()
@@ -957,7 +957,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Channel<ChainA, ChainB> {
  ) -> Result<IbcEvent, ChannelError> {
  let dst_msgs = channel.build_chan_open_ack()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create channel");
+ let tm = TrackedMsgs::new(dst_msgs, "create channel with ChannelOpenAck");
 
  let events = channel
  .dst_chain()
@@ -1055,7 +1055,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Channel<ChainA, ChainB> {
  ) -> Result<IbcEvent, ChannelError> {
  let dst_msgs = channel.build_chan_open_confirm()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create channel");
+ let tm = TrackedMsgs::new(dst_msgs, "create channel with ChannelOpenConfirm");
  let events = channel
  .dst_chain()
  .send_messages_and_wait_commit(tm)
@@ -1119,7 +1119,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Channel<ChainA, ChainB> {
  pub fn build_chan_close_init_and_send(&self) -> Result<IbcEvent, ChannelError> {
  let dst_msgs = self.build_chan_close_init()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create channel");
+ let tm = TrackedMsgs::new(dst_msgs, "create channel with ChannelCloseInit");
 
  let events = self
  .dst_chain()
@@ -1200,7 +1200,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Channel<ChainA, ChainB> {
  pub fn build_chan_close_confirm_and_send(&self) -> Result<IbcEvent, ChannelError> {
  let dst_msgs = self.build_chan_close_confirm()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create channel");
+ let tm = TrackedMsgs::new(dst_msgs, "create channel with ChannelCloseConfirm");
 
  let events = self
  .dst_chain()

relayer/src/connection.rs

@@ -768,7 +768,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Connection<ChainA, ChainB> {
  pub fn build_conn_init_and_send(&self) -> Result<IbcEvent, ConnectionError> {
  let dst_msgs = self.build_conn_init()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create connection");
+ let tm = TrackedMsgs::new(dst_msgs, "create connection with ConnectionOpenInit");
 
  let events = self
  .dst_chain()
@@ -828,7 +828,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Connection<ChainA, ChainB> {
  .map_err(|e| ConnectionError::chain_query(self.dst_chain().id(), e))?;
  let client_msgs = self.build_update_client_on_src(src_client_target_height)?;
 
- let tm = TrackedMsgs::new(client_msgs, "create connection");
+ let tm = TrackedMsgs::new(client_msgs, "update client on source for ConnectionOpenTry");
  self.src_chain()
  .send_messages_and_wait_commit(tm)
  .map_err(|e| ConnectionError::submit(self.src_chain().id(), e))?;
@@ -899,7 +899,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Connection<ChainA, ChainB> {
  pub fn build_conn_try_and_send(&self) -> Result<IbcEvent, ConnectionError> {
  let dst_msgs = self.build_conn_try()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create connection");
+ let tm = TrackedMsgs::new(dst_msgs, "create connection with ConnectionOpenTry");
 
  let events = self
  .dst_chain()
@@ -949,7 +949,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Connection<ChainA, ChainB> {
  .map_err(|e| ConnectionError::chain_query(self.dst_chain().id(), e))?;
  let client_msgs = self.build_update_client_on_src(src_client_target_height)?;
 
- let tm = TrackedMsgs::new(client_msgs, "create connection");
+ let tm = TrackedMsgs::new(client_msgs, "update client on source for ConnectionOpenAck");
 
  self.src_chain()
  .send_messages_and_wait_commit(tm)
@@ -995,7 +995,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Connection<ChainA, ChainB> {
  pub fn build_conn_ack_and_send(&self) -> Result<IbcEvent, ConnectionError> {
  let dst_msgs = self.build_conn_ack()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create connection");
+ let tm = TrackedMsgs::new(dst_msgs, "create connection with ConnectionOpenAck");
 
  let events = self
  .dst_chain()
@@ -1074,7 +1074,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> Connection<ChainA, ChainB> {
  pub fn build_conn_confirm_and_send(&self) -> Result<IbcEvent, ConnectionError> {
  let dst_msgs = self.build_conn_confirm()?;
 
- let tm = TrackedMsgs::new(dst_msgs, "create connection");
+ let tm = TrackedMsgs::new(dst_msgs, "create connection with ConnectionOpenConfirm");
 
  let events = self
  .dst_chain()

relayer/src/link/operational_data.rs

@@ -1,3 +1,4 @@
+use alloc::borrow::Cow;
 use core::fmt;
 use core::iter;
 use std::time::Instant;
@@ -45,14 +46,10 @@ impl TrackedEvents {
  &self.list
  }
 
- pub fn tracking_id(&self) -> &String {
+ pub fn tracking_id(&self) -> &str {
  &self.tracking_id
  }
 
- pub fn len(&self) -> usize {
- self.list.len()
- }
-
  pub fn set_height(&mut self, height: Height) {
  for event in self.list.iter_mut() {
  event.set_height(height);
@@ -99,25 +96,40 @@ pub struct OperationalData {
 }
 
 impl OperationalData {
- pub fn new(proofs_height: Height, target: OperationalDataTarget, tn: &str) -> Self {
+ pub fn new(
+ proofs_height: Height,
+ target: OperationalDataTarget,
+ tracking_id: impl Into<String>,
+ ) -> Self {
  OperationalData {
  proofs_height,
  batch: vec![],
  target,
  scheduled_time: Instant::now(),
- tracking_id: tn.to_string(),
+ tracking_id: tracking_id.into(),
  }
  }
 
  pub fn push(&mut self, msg: TransitMessage) {
  self.batch.push(msg)
  }
 
- pub fn events(&self) -> TrackedEvents {
- let list = self.batch.iter().map(|gm| gm.event.clone()).collect();
+ /// Returns displayable information on the operation's data.
+ pub fn info(&self) -> OperationalInfo<'_> {
+ OperationalInfo {
+ tracking_id: Cow::Borrowed(&self.tracking_id),
+ target: self.target,
+ proofs_height: self.proofs_height,
+ batch_len: self.batch.len(),
+ }
+ }
+
+ /// Transforms `self` into the list of events accompanied with the tracking ID.
+ pub fn into_events(self) -> TrackedEvents {
+ let list = self.batch.into_iter().map(|gm| gm.event).collect();
  TrackedEvents {
  list,
- tracking_id: self.tracking_id.clone(),
+ tracking_id: self.tracking_id,
  }
  }
 
@@ -163,7 +175,7 @@ impl OperationalData {
  let tm = TrackedMsgs::new(msgs, &self.tracking_id);
 
  info!(
- "[{}] assembled batch of {} msgs",
+ "[{}] assembled batch of {} message(s)",
  relay_path,
  tm.messages().len()
  );
@@ -172,15 +184,47 @@ impl OperationalData {
  }
 }
 
-impl fmt::Display for OperationalData {
+/// A lightweight informational data structure that can be extracted
+/// out of [`OperationalData`] for e.g. logging purposes.
+pub struct OperationalInfo<'a> {
+ tracking_id: Cow<'a, str>,
+ target: OperationalDataTarget,
+ proofs_height: Height,
+ batch_len: usize,
+}
+
+impl<'a> OperationalInfo<'a> {
+ pub fn target(&self) -> OperationalDataTarget {
+ self.target
+ }
+
+ /// Returns the length of the assembled batch of in-transit messages.
+ pub fn batch_len(&self) -> usize {
+ self.batch_len
+ }
+
+ pub fn into_owned(self) -> OperationalInfo<'static> {
+ let Self {
+ tracking_id,
+ target,
+ proofs_height,
+ batch_len,
+ } = self;
+ OperationalInfo {
+ tracking_id: tracking_id.into_owned().into(),
+ target,
+ proofs_height,
+ batch_len,
+ }
+ }
+}
+
+impl<'a> fmt::Display for OperationalInfo<'a> {
  fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
  write!(
  f,
  "{} ->{} @{}; len={}",
- self.tracking_id,
- self.target,
- self.proofs_height,
- self.batch.len(),
+ self.tracking_id, self.target, self.proofs_height, self.batch_len,
  )
  }
 }