From d08170278bc795a322fbe21368bff84145b8e467 Mon Sep 17 00:00:00 2001
From: Tsvetomir Dimitrov <tsvetomir@parity.io>
Date: Tue, 12 Sep 2023 09:49:48 +0300
Subject: [PATCH] Additional logging for `dispute-coordinator` (#1494)

---
 .../dispute-coordinator/src/initialized.rs    |  7 +++++++
 .../src/participation/mod.rs                  | 19 +++++++++++++++++++
 .../src/participation/queues/mod.rs           | 10 ++++++++++
 3 files changed, 36 insertions(+)

diff --git a/polkadot/node/core/dispute-coordinator/src/initialized.rs b/polkadot/node/core/dispute-coordinator/src/initialized.rs
index 9bfca2d81a04..9cd544a8c536 100644
--- a/polkadot/node/core/dispute-coordinator/src/initialized.rs
+++ b/polkadot/node/core/dispute-coordinator/src/initialized.rs
@@ -301,6 +301,13 @@ impl Initialized {
 		self.participation.process_active_leaves_update(ctx, &update).await?;
 
 		if let Some(new_leaf) = update.activated {
+			gum::trace!(
+				target: LOG_TARGET,
+				leaf_hash = ?new_leaf.hash,
+				block_number = new_leaf.number,
+				"Processing ActivatedLeaf"
+			);
+
 			let session_idx =
 				self.runtime_info.get_session_index_for_child(ctx.sender(), new_leaf.hash).await;
 
diff --git a/polkadot/node/core/dispute-coordinator/src/participation/mod.rs b/polkadot/node/core/dispute-coordinator/src/participation/mod.rs
index 5a3c4be90aa0..35d07b411e8f 100644
--- a/polkadot/node/core/dispute-coordinator/src/participation/mod.rs
+++ b/polkadot/node/core/dispute-coordinator/src/participation/mod.rs
@@ -260,6 +260,13 @@ impl Participation {
 		req: ParticipationRequest,
 		recent_head: Hash,
 	) -> FatalResult<()> {
+		gum::trace!(
+			target: LOG_TARGET,
+			candidate_hash = ?req.candidate_hash(),
+			session = req.session(),
+			"Forking participation"
+		);
+
 		let participation_timer = self.metrics.time_participation();
 		if self.running_participations.insert(*req.candidate_hash()) {
 			let sender = ctx.sender().clone();
@@ -314,12 +321,24 @@ async fn participate(
 		},
 		Ok(Ok(data)) => data,
 		Ok(Err(RecoveryError::Invalid)) => {
+			gum::debug!(
+				target: LOG_TARGET,
+				candidate_hash = ?req.candidate_hash(),
+				session = req.session(),
+				"Invalid availability data during participation"
+			);
 			// the available data was recovered but it is invalid, therefore we'll
 			// vote negatively for the candidate dispute
 			send_result(&mut result_sender, req, ParticipationOutcome::Invalid).await;
 			return
 		},
 		Ok(Err(RecoveryError::Unavailable)) | Ok(Err(RecoveryError::ChannelClosed)) => {
+			gum::debug!(
+				target: LOG_TARGET,
+				candidate_hash = ?req.candidate_hash(),
+				session = req.session(),
+				"Can't fetch availability data in participation"
+			);
 			send_result(&mut result_sender, req, ParticipationOutcome::Unavailable).await;
 			return
 		},
diff --git a/polkadot/node/core/dispute-coordinator/src/participation/queues/mod.rs b/polkadot/node/core/dispute-coordinator/src/participation/queues/mod.rs
index 1105135a747f..d9e86def168c 100644
--- a/polkadot/node/core/dispute-coordinator/src/participation/queues/mod.rs
+++ b/polkadot/node/core/dispute-coordinator/src/participation/queues/mod.rs
@@ -277,6 +277,11 @@ impl Queues {
 			match self.priority.entry(comparator) {
 				Entry::Occupied(_) => req.discard_timer(),
 				Entry::Vacant(vac) => {
+					gum::trace!(
+						target: LOG_TARGET,
+						candidate_hash = ?req.candidate_hash(),
+						"Added to priority participation queue"
+					);
 					vac.insert(req);
 				},
 			}
@@ -295,6 +300,11 @@ impl Queues {
 			match self.best_effort.entry(comparator) {
 				Entry::Occupied(_) => req.discard_timer(),
 				Entry::Vacant(vac) => {
+					gum::trace!(
+						target: LOG_TARGET,
+						candidate_hash = ?req.candidate_hash(),
+						"Added to best effort participation queue"
+					);
 					vac.insert(req);
 				},
 			}