Added event MessagesReceived for better visibility on receiving side (#1655)

* Added event `MessagesReceived` for better visibility on receiving side

* Fixes/comments from PR

* Final cleanup

bridges/modules/messages/src/inbound_lane.rs

@@ -21,9 +21,8 @@ use crate::Config;
 use bp_messages::{
 	target_chain::{DispatchMessage, DispatchMessageData, MessageDispatch},
 	DeliveredMessages, InboundLaneData, LaneId, MessageKey, MessageNonce, OutboundLaneData,
-	UnrewardedRelayer,
+	ReceivalResult, UnrewardedRelayer,
 };
-use bp_runtime::messages::MessageDispatchResult;
 use codec::{Decode, Encode, EncodeLike, MaxEncodedLen};
 use frame_support::{traits::Get, RuntimeDebug};
 use scale_info::{Type, TypeInfo};
@@ -108,22 +107,6 @@ impl<T: Config<I>, I: 'static> MaxEncodedLen for StoredInboundLaneData<T, I> {
 	}
 }
 
-/// Result of single message receival.
-#[derive(RuntimeDebug, PartialEq, Eq)]
-pub enum ReceivalResult {
-	/// Message has been received and dispatched. Note that we don't care whether dispatch has
-	/// been successful or not - in both case message falls into this category.
-	///
-	/// The message dispatch result is also returned.
-	Dispatched(MessageDispatchResult),
-	/// Message has invalid nonce and lane has rejected to accept this message.
-	InvalidNonce,
-	/// There are too many unrewarded relayer entries at the lane.
-	TooManyUnrewardedRelayers,
-	/// There are too many unconfirmed messages at the lane.
-	TooManyUnconfirmedMessages,
-}
-
 /// Inbound messages lane.
 pub struct InboundLane<S> {
 	storage: S,
@@ -181,12 +164,12 @@ impl<S: InboundLaneStorage> InboundLane<S> {
 	}
 
 	/// Receive new message.
-	pub fn receive_message<P: MessageDispatch<AccountId>, AccountId>(
+	pub fn receive_message<Dispatch: MessageDispatch<AccountId>, AccountId>(
 		&mut self,
 		relayer_at_bridged_chain: &S::Relayer,
 		relayer_at_this_chain: &AccountId,
 		nonce: MessageNonce,
-		message_data: DispatchMessageData<P::DispatchPayload>,
+		message_data: DispatchMessageData<Dispatch::DispatchPayload>,
 	) -> ReceivalResult {
 		let mut data = self.storage.data();
 		let is_correct_message = nonce == data.last_delivered_nonce() + 1;
@@ -206,7 +189,7 @@ impl<S: InboundLaneStorage> InboundLane<S> {
 		}
 
 		// then, dispatch message
-		let dispatch_result = P::dispatch(
+		let dispatch_result = Dispatch::dispatch(
 			relayer_at_this_chain,
 			DispatchMessage {
 				key: MessageKey { lane_id: self.storage.id(), nonce },

bridges/modules/messages/src/lib.rs

@@ -46,7 +46,7 @@ pub use weights_ext::{
 };
 
 use crate::{
-	inbound_lane::{InboundLane, InboundLaneStorage, ReceivalResult},
+	inbound_lane::{InboundLane, InboundLaneStorage},
 	outbound_lane::{OutboundLane, OutboundLaneStorage, ReceivalConfirmationResult},
 };
 
@@ -91,6 +91,7 @@ pub const LOG_TARGET: &str = "runtime::bridge-messages";
 #[frame_support::pallet]
 pub mod pallet {
 	use super::*;
+	use bp_messages::{ReceivalResult, ReceivedMessages};
 	use frame_support::pallet_prelude::*;
 	use frame_system::pallet_prelude::*;
 
@@ -298,6 +299,7 @@ pub mod pallet {
 			// dispatch messages and (optionally) update lane(s) state(s)
 			let mut total_messages = 0;
 			let mut valid_messages = 0;
+			let mut messages_received_status = Vec::with_capacity(messages.len());
 			let mut dispatch_weight_left = dispatch_weight;
 			for (lane_id, lane_data) in messages {
 				let mut lane = inbound_lane::<T, I>(lane_id);
@@ -314,24 +316,37 @@ pub mod pallet {
 					}
 				}
 
+				let mut lane_messages_received_status =
+					ReceivedMessages::new(lane_id, Vec::with_capacity(lane_data.messages.len()));
+				let mut is_lane_processing_stopped_no_weight_left = false;
+
 				for mut message in lane_data.messages {
 					debug_assert_eq!(message.key.lane_id, lane_id);
+					total_messages += 1;
+
+					if is_lane_processing_stopped_no_weight_left {
+						lane_messages_received_status
+							.push_skipped_for_not_enough_weight(message.key.nonce);
+						continue
+					}
 
 					// ensure that relayer has declared enough weight for dispatching next message
 					// on this lane. We can't dispatch lane messages out-of-order, so if declared
 					// weight is not enough, let's move to next lane
-					let dispatch_weight = T::MessageDispatch::dispatch_weight(&mut message);
-					if dispatch_weight.any_gt(dispatch_weight_left) {
+					let message_dispatch_weight = T::MessageDispatch::dispatch_weight(&mut message);
+					if message_dispatch_weight.any_gt(dispatch_weight_left) {
 						log::trace!(
 							target: LOG_TARGET,
 							"Cannot dispatch any more messages on lane {:?}. Weight: declared={}, left={}",
 							lane_id,
-							dispatch_weight,
+							message_dispatch_weight,
 							dispatch_weight_left,
 						);
-						break
+						lane_messages_received_status
+							.push_skipped_for_not_enough_weight(message.key.nonce);
+						is_lane_processing_stopped_no_weight_left = true;
+						continue
 					}
-					total_messages += 1;
 
 					let receival_result = lane.receive_message::<T::MessageDispatch, T::AccountId>(
 						&relayer_id_at_bridged_chain,
@@ -346,7 +361,7 @@ pub mod pallet {
 					// losing funds for messages dispatch. But keep in mind that relayer pays base
 					// delivery transaction cost anyway. And base cost covers everything except
 					// dispatch, so we have a balance here.
-					let (unspent_weight, refund_pay_dispatch_fee) = match receival_result {
+					let (unspent_weight, refund_pay_dispatch_fee) = match &receival_result {
 						ReceivalResult::Dispatched(dispatch_result) => {
 							valid_messages += 1;
 							(
@@ -356,11 +371,12 @@ pub mod pallet {
 						},
 						ReceivalResult::InvalidNonce |
 						ReceivalResult::TooManyUnrewardedRelayers |
-						ReceivalResult::TooManyUnconfirmedMessages => (dispatch_weight, true),
+						ReceivalResult::TooManyUnconfirmedMessages => (message_dispatch_weight, true),
 					};
+					lane_messages_received_status.push(message.key.nonce, receival_result);
 
-					let unspent_weight = unspent_weight.min(dispatch_weight);
-					dispatch_weight_left -= dispatch_weight - unspent_weight;
+					let unspent_weight = unspent_weight.min(message_dispatch_weight);
+					dispatch_weight_left -= message_dispatch_weight - unspent_weight;
 					actual_weight = actual_weight.saturating_sub(unspent_weight).saturating_sub(
 						// delivery call weight formula assumes that the fee is paid at
 						// this (target) chain. If the message is prepaid at the source
@@ -372,9 +388,11 @@ pub mod pallet {
 						},
 					);
 				}
+
+				messages_received_status.push(lane_messages_received_status);
 			}
 
-			log::trace!(
+			log::debug!(
 				target: LOG_TARGET,
 				"Received messages: total={}, valid={}. Weight used: {}/{}",
 				total_messages,
@@ -383,6 +401,8 @@ pub mod pallet {
 				declared_weight,
 			);
 
+			Self::deposit_event(Event::MessagesReceived(messages_received_status));
+
 			Ok(PostDispatchInfo { actual_weight: Some(actual_weight), pays_fee: Pays::Yes })
 		}
 
@@ -494,6 +514,8 @@ pub mod pallet {
 	pub enum Event<T: Config<I>, I: 'static = ()> {
 		/// Message has been accepted and is waiting to be delivered.
 		MessageAccepted { lane_id: LaneId, nonce: MessageNonce },
+		/// Messages have been received from the bridged chain.
+		MessagesReceived(Vec<ReceivedMessages<ReceivalResult>>),
 		/// Messages in the inclusive range have been delivered to the bridged chain.
 		MessagesDelivered { lane_id: LaneId, messages: DeliveredMessages },
 	}

bridges/primitives/messages/src/lib.rs

@@ -32,6 +32,7 @@ pub mod storage_keys;
 pub mod target_chain;
 
 // Weight is reexported to avoid additional frame-support dependencies in related crates.
+use bp_runtime::messages::MessageDispatchResult;
 pub use frame_support::weights::Weight;
 
 /// Messages pallet operating mode.
@@ -218,6 +219,47 @@ pub struct UnrewardedRelayer<RelayerId> {
 	pub messages: DeliveredMessages,
 }
 
+/// Received messages with their dispatch result.
+#[derive(Clone, Default, Encode, Decode, RuntimeDebug, PartialEq, Eq, TypeInfo)]
+pub struct ReceivedMessages<Result> {
+	/// Id of the lane which is receiving messages.
+	pub lane: LaneId,
+	/// Result of messages which we tried to dispatch
+	pub receive_results: Vec<(MessageNonce, Result)>,
+	/// Messages which were skipped and never dispatched
+	pub skipped_for_not_enough_weight: Vec<MessageNonce>,
+}
+
+impl<Result> ReceivedMessages<Result> {
+	pub fn new(lane: LaneId, receive_results: Vec<(MessageNonce, Result)>) -> Self {
+		ReceivedMessages { lane, receive_results, skipped_for_not_enough_weight: Vec::new() }
+	}
+
+	pub fn push(&mut self, message: MessageNonce, result: Result) {
+		self.receive_results.push((message, result));
+	}
+
+	pub fn push_skipped_for_not_enough_weight(&mut self, message: MessageNonce) {
+		self.skipped_for_not_enough_weight.push(message);
+	}
+}
+
+/// Result of single message receival.
+#[derive(RuntimeDebug, Encode, Decode, PartialEq, Eq, Clone, TypeInfo)]
+pub enum ReceivalResult {
+	/// Message has been received and dispatched. Note that we don't care whether dispatch has
+	/// been successful or not - in both case message falls into this category.
+	///
+	/// The message dispatch result is also returned.
+	Dispatched(MessageDispatchResult),
+	/// Message has invalid nonce and lane has rejected to accept this message.
+	InvalidNonce,
+	/// There are too many unrewarded relayer entries at the lane.
+	TooManyUnrewardedRelayers,
+	/// There are too many unconfirmed messages at the lane.
+	TooManyUnconfirmedMessages,
+}
+
 /// Delivered messages with their dispatch result.
 #[derive(Clone, Default, Encode, Decode, RuntimeDebug, PartialEq, Eq, TypeInfo)]
 pub struct DeliveredMessages {