more resilient subsystems (#1908)

* backing: extract log target

* bitfield-signing: extract log target

* utils: fix a typo

* provisioner: extract log target

* candidate selection: remove unused error variant

* bitfield-distribution: change the return type of run

* pov-distribution: extract log target

* collator-protocol: simplify runtime request

* collation-generation: do not exit early on error

* collation-generation: do not exit on double init

* collator-protocol: do not exit on errors and rename LOG_TARGET

* collator-protocol: a workaround for ununused imports warning

* Update node/network/bitfield-distribution/src/lib.rs

* collation-generation: elevate warn! to error!

* collator-protocol: fix imports

* post merge fix

* fix compilation

polkadot/node/network/collator-protocol/src/collator_side.rs

@@ -16,9 +16,9 @@
 
 use std::collections::HashMap;
 
-use super::{TARGET,  Result};
+use super::{LOG_TARGET,  Result};
 
-use futures::{StreamExt, channel::oneshot, task::Poll};
+use futures::{StreamExt, task::Poll};
 use log::warn;
 
 use polkadot_primitives::v1::{
@@ -28,7 +28,7 @@ use polkadot_primitives::v1::{
 use polkadot_subsystem::{
 	FromOverseer, OverseerSignal, SubsystemContext,
 	messages::{
-		AllMessages, CollatorProtocolMessage, RuntimeApiMessage, RuntimeApiRequest,
+		AllMessages, CollatorProtocolMessage,
 		NetworkBridgeMessage,
 	},
 };
@@ -39,6 +39,7 @@ use polkadot_node_subsystem_util::{
 	validator_discovery,
 	request_validators_ctx,
 	request_validator_groups_ctx,
+	request_availability_cores_ctx,
 	metrics::{self, prometheus},
 };
 
@@ -152,7 +153,7 @@ where
 	// This collation is not in the active-leaves set.
 	if !state.view.contains(&relay_parent) {
 		warn!(
-			target: TARGET,
+			target: LOG_TARGET,
 			"Distribute collation message parent {:?} is outside of our view",
 			relay_parent,
 		);
@@ -171,7 +172,7 @@ where
 		Some(core) => core,
 		None => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"Looks like no core is assigned to {:?} at {:?}", id, relay_parent,
 			);
 			return Ok(());
@@ -183,7 +184,7 @@ where
 		Some(validators) => validators,
 		None => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"There are no validators assigned to {:?} core", our_core,
 			);
 
@@ -224,16 +225,7 @@ async fn determine_core<Context>(
 where
 	Context: SubsystemContext<Message = CollatorProtocolMessage>
 {
-	let (tx, rx) = oneshot::channel();
-
-	ctx.send_message(AllMessages::RuntimeApi(
-		RuntimeApiMessage::Request(
-			relay_parent,
-			RuntimeApiRequest::AvailabilityCores(tx),
-		)
-	)).await?;
-
-	let cores = rx.await??;
+	let cores = request_availability_cores_ctx(relay_parent, ctx).await?.await??;
 
 	for (idx, core) in cores.iter().enumerate() {
 		if let CoreState::Scheduled(occupied) = core {
@@ -386,7 +378,7 @@ where
 					// If the ParaId of a collation requested to be distributed does not match
 					// the one we expect, we ignore the message.
 					warn!(
-						target: TARGET,
+						target: LOG_TARGET,
 						"DistributeCollation message for para {:?} while collating on {:?}",
 						receipt.descriptor.para_id,
 						id,
@@ -397,7 +389,7 @@ where
 				}
 				None => {
 					warn!(
-						target: TARGET,
+						target: LOG_TARGET,
 						"DistributeCollation message for para {:?} while not collating on any",
 						receipt.descriptor.para_id,
 					);
@@ -406,19 +398,19 @@ where
 		}
 		FetchCollation(_, _, _, _) => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"FetchCollation message is not expected on the collator side of the protocol",
 			);
 		}
 		ReportCollator(_) => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"ReportCollator message is not expected on the collator side of the protocol",
 			);
 		}
 		NoteGoodCollation(_) => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"NoteGoodCollation message is not expected on the collator side of the protocol",
 			);
 		}
@@ -429,7 +421,7 @@ where
 				event,
 			).await {
 				warn!(
-					target: TARGET,
+					target: LOG_TARGET,
 					"Failed to handle incoming network message: {:?}", e,
 				);
 			}
@@ -484,13 +476,13 @@ where
 	match msg {
 		Declare(_) => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"Declare message is not expected on the collator side of the protocol",
 			);
 		}
 		AdvertiseCollation(_, _) => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"AdvertiseCollation message is not expected on the collator side of the protocol",
 			);
 		}
@@ -503,7 +495,7 @@ where
 						}
 					} else {
 						warn!(
-							target: TARGET,
+							target: LOG_TARGET,
 							"Received a RequestCollation for {:?} while collating on {:?}",
 							para_id, our_para_id,
 						);
@@ -511,7 +503,7 @@ where
 				}
 				None => {
 					warn!(
-						target: TARGET,
+						target: LOG_TARGET,
 						"Received a RequestCollation for {:?} while not collating on any para",
 						para_id,
 					);
@@ -520,7 +512,7 @@ where
 		}
 		Collation(_, _, _) => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"Collation message is not expected on the collator side of the protocol",
 			);
 		}
@@ -655,7 +647,7 @@ where
 			while let Poll::Ready(Some((validator_id, peer_id))) = futures::poll!(request.next()) {
 				if let Err(err) = handle_validator_connected(&mut ctx, &mut state, peer_id, validator_id).await {
 					warn!(
-						target: TARGET,
+						target: LOG_TARGET,
 						"Failed to declare our collator id: {:?}",
 						err,
 					);
@@ -667,7 +659,11 @@ where
 
 		while let Poll::Ready(msg) = futures::poll!(ctx.recv()) {
 			match msg? {
-				Communication { msg } => process_msg(&mut ctx, &mut state, msg).await?,
+				Communication { msg } => {
+					if let Err(e) = process_msg(&mut ctx, &mut state, msg).await {
+						warn!(target: LOG_TARGET, "Failed to process message: {}", e);
+					}
+				},
 				Signal(ActiveLeaves(_update)) => {}
 				Signal(BlockFinalized(_)) => {}
 				Signal(Conclude) => return Ok(()),
@@ -696,7 +692,7 @@ mod tests {
 		BlockData, CandidateDescriptor, CollatorPair, ScheduledCore,
 		ValidatorIndex, GroupRotationInfo, AuthorityDiscoveryId,
 	};
-	use polkadot_subsystem::ActiveLeavesUpdate;
+	use polkadot_subsystem::{ActiveLeavesUpdate, messages::{RuntimeApiMessage, RuntimeApiRequest}};
 	use polkadot_node_subsystem_util::TimeoutExt;
 	use polkadot_subsystem_testhelpers as test_helpers;
 	use polkadot_node_network_protocol::ObservedRole;
@@ -818,7 +814,7 @@ mod tests {
 				log::LevelFilter::Trace,
 			)
 			.filter(
-				Some(TARGET),
+				Some(LOG_TARGET),
 				log::LevelFilter::Trace,
 			)
 			.try_init();

polkadot/node/network/collator-protocol/src/lib.rs

@@ -43,7 +43,7 @@ use polkadot_node_subsystem_util::{
 mod collator_side;
 mod validator_side;
 
-const TARGET: &'static str = "colp";
+const LOG_TARGET: &'static str = "collator_protocol";
 const REQUEST_TIMEOUT: Duration = Duration::from_secs(1);
 
 #[derive(Debug, Error)]
@@ -140,7 +140,7 @@ where
 	Context: SubsystemContext<Message = CollatorProtocolMessage>,
 {
 	trace!(
-		target: TARGET,
+		target: LOG_TARGET,
 		"Reputation change of {:?} for peer {:?}", rep, peer,
 	);
 

polkadot/node/network/collator-protocol/src/validator_side.rs

@@ -45,7 +45,7 @@ use polkadot_node_subsystem_util::{
 	metrics::{self, prometheus},
 };
 
-use super::{modify_reputation, TARGET, Result};
+use super::{modify_reputation, LOG_TARGET, Result};
 
 const COST_UNEXPECTED_MESSAGE: Rep = Rep::new(-10, "An unexpected message");
 const COST_REQUEST_TIMED_OUT: Rep = Rep::new(-20, "A collation request has timed out");
@@ -207,7 +207,7 @@ where
 					// We do not want this to be fatal because the receving subsystem
 					// may have closed the results channel for some reason.
 					trace!(
-						target: TARGET,
+						target: LOG_TARGET,
 						"Failed to send collation: {:?}", e,
 					);
 				}
@@ -381,7 +381,7 @@ where
 {
 	if !state.view.contains(&relay_parent) {
 		trace!(
-			target: TARGET,
+			target: LOG_TARGET,
 			"Collation by {} on {} on relay parent {} is no longer in view",
 			peer_id, para_id, relay_parent,
 		);
@@ -390,7 +390,7 @@ where
 
 	if state.requested_collations.contains_key(&(relay_parent, para_id.clone(), peer_id.clone())) {
 		trace!(
-			target: TARGET,
+			target: LOG_TARGET,
 			"Collation by {} on {} on relay parent {} has already been requested",
 			peer_id, para_id, relay_parent,
 		);
@@ -614,13 +614,13 @@ where
 	match msg {
 		CollateOn(id) => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"CollateOn({}) message is not expected on the validator side of the protocol", id,
 			);
 		}
 		DistributeCollation(_, _) => {
 			warn!(
-				target: TARGET,
+				target: LOG_TARGET,
 				"DistributeCollation message is not expected on the validator side of the protocol",
 			);
 		}
@@ -640,7 +640,7 @@ where
 				event,
 			).await {
 				warn!(
-					target: TARGET,
+					target: LOG_TARGET,
 					"Failed to handle incoming network message: {:?}", e,
 				);
 			}
@@ -671,7 +671,7 @@ where
 	loop {
 		if let Poll::Ready(msg) = futures::poll!(ctx.recv()) {
 			let msg = msg?;
-			trace!(target: TARGET, "Received a message {:?}", msg);
+			trace!(target: LOG_TARGET, "Received a message {:?}", msg);
 
 			match msg {
 				Communication { msg } => process_msg(&mut ctx, msg, &mut state).await?,
@@ -687,7 +687,7 @@ where
 			// if the chain has not moved on yet.
 			match request {
 				CollationRequestResult::Timeout(id) => {
-					trace!(target: TARGET, "Request timed out {}", id);
+					trace!(target: LOG_TARGET, "Request timed out {}", id);
 					request_timed_out(&mut ctx, &mut state, id).await?;
 				}
 				CollationRequestResult::Received(id) => {
@@ -759,7 +759,7 @@ mod tests {
 				log::LevelFilter::Trace,
 			)
 			.filter(
-				Some(TARGET),
+				Some(LOG_TARGET),
 				log::LevelFilter::Trace,
 			)
 			.try_init();