diff --git a/client/beefy/src/aux_schema.rs b/client/beefy/src/aux_schema.rs index 67deee19b58b0..fafa9948c5444 100644 --- a/client/beefy/src/aux_schema.rs +++ b/client/beefy/src/aux_schema.rs @@ -18,7 +18,7 @@ //! Schema for BEEFY state persisted in the aux-db. -use crate::worker::PersistedState; +use crate::{worker::PersistedState, LOG_TARGET}; use codec::{Decode, Encode}; use log::{info, trace}; use sc_client_api::{backend::AuxStore, Backend}; @@ -31,7 +31,7 @@ const WORKER_STATE: &[u8] = b"beefy_voter_state"; const CURRENT_VERSION: u32 = 1; pub(crate) fn write_current_version(backend: &B) -> ClientResult<()> { - info!(target: "beefy", "🥩 write aux schema version {:?}", CURRENT_VERSION); + info!(target: LOG_TARGET, "🥩 write aux schema version {:?}", CURRENT_VERSION); AuxStore::insert_aux(backend, &[(VERSION_KEY, CURRENT_VERSION.encode().as_slice())], &[]) } @@ -40,7 +40,7 @@ pub(crate) fn write_voter_state( backend: &B, state: &PersistedState, ) -> ClientResult<()> { - trace!(target: "beefy", "🥩 persisting {:?}", state); + trace!(target: LOG_TARGET, "🥩 persisting {:?}", state); backend.insert_aux(&[(WORKER_STATE, state.encode().as_slice())], &[]) } diff --git a/client/beefy/src/communication/gossip.rs b/client/beefy/src/communication/gossip.rs index bbc35ac8e526e..116a6286ed54d 100644 --- a/client/beefy/src/communication/gossip.rs +++ b/client/beefy/src/communication/gossip.rs @@ -28,7 +28,7 @@ use log::{debug, trace}; use parking_lot::{Mutex, RwLock}; use wasm_timer::Instant; -use crate::{communication::peers::KnownPeers, keystore::BeefyKeystore}; +use crate::{communication::peers::KnownPeers, keystore::BeefyKeystore, LOG_TARGET}; use beefy_primitives::{ crypto::{Public, Signature}, VoteMessage, @@ -122,7 +122,7 @@ where /// /// Noting round will start a live `round`. pub(crate) fn note_round(&self, round: NumberFor) { - debug!(target: "beefy", "🥩 About to note gossip round #{}", round); + debug!(target: LOG_TARGET, "🥩 About to note gossip round #{}", round); self.known_votes.write().insert(round); } @@ -130,7 +130,7 @@ where /// /// This can be called once round is complete so we stop gossiping for it. pub(crate) fn conclude_round(&self, round: NumberFor) { - debug!(target: "beefy", "🥩 About to drop gossip round #{}", round); + debug!(target: LOG_TARGET, "🥩 About to drop gossip round #{}", round); self.known_votes.write().conclude(round); } } @@ -174,7 +174,10 @@ where return ValidationResult::ProcessAndKeep(self.topic) } else { // TODO: report peer - debug!(target: "beefy", "🥩 Bad signature on message: {:?}, from: {:?}", msg, sender); + debug!( + target: LOG_TARGET, + "🥩 Bad signature on message: {:?}, from: {:?}", msg, sender + ); } } @@ -192,7 +195,7 @@ where let round = msg.commitment.block_number; let expired = !known_votes.is_live(&round); - trace!(target: "beefy", "🥩 Message for round #{} expired: {}", round, expired); + trace!(target: LOG_TARGET, "🥩 Message for round #{} expired: {}", round, expired); expired }) @@ -226,7 +229,7 @@ where let round = msg.commitment.block_number; let allowed = known_votes.is_live(&round); - trace!(target: "beefy", "🥩 Message for round #{} allowed: {}", round, allowed); + trace!(target: LOG_TARGET, "🥩 Message for round #{} allowed: {}", round, allowed); allowed }) diff --git a/client/beefy/src/communication/request_response/incoming_requests_handler.rs b/client/beefy/src/communication/request_response/incoming_requests_handler.rs index 9f02b7162b54c..d3be73dc06a43 100644 --- a/client/beefy/src/communication/request_response/incoming_requests_handler.rs +++ b/client/beefy/src/communication/request_response/incoming_requests_handler.rs @@ -30,7 +30,7 @@ use sp_runtime::traits::Block; use std::{marker::PhantomData, sync::Arc}; use crate::communication::request_response::{ - on_demand_justifications_protocol_config, Error, JustificationRequest, + on_demand_justifications_protocol_config, Error, JustificationRequest, BEEFY_SYNC_LOG_TARGET, }; /// A request coming in, including a sender for sending responses. @@ -174,21 +174,21 @@ where /// Run [`BeefyJustifsRequestHandler`]. pub async fn run(mut self) { - trace!(target: "beefy::sync", "🥩 Running BeefyJustifsRequestHandler"); + trace!(target: BEEFY_SYNC_LOG_TARGET, "🥩 Running BeefyJustifsRequestHandler"); while let Ok(request) = self.request_receiver.recv(|| vec![]).await { let peer = request.peer; match self.handle_request(request) { Ok(()) => { debug!( - target: "beefy::sync", + target: BEEFY_SYNC_LOG_TARGET, "🥩 Handled BEEFY justification request from {:?}.", peer ) }, Err(e) => { // TODO (issue #12293): apply reputation changes here based on error type. debug!( - target: "beefy::sync", + target: BEEFY_SYNC_LOG_TARGET, "🥩 Failed to handle BEEFY justification request from {:?}: {}", peer, e, ) }, diff --git a/client/beefy/src/communication/request_response/mod.rs b/client/beefy/src/communication/request_response/mod.rs index c83bb9d57e91b..22a20c247086d 100644 --- a/client/beefy/src/communication/request_response/mod.rs +++ b/client/beefy/src/communication/request_response/mod.rs @@ -40,6 +40,8 @@ const JUSTIF_CHANNEL_SIZE: usize = 10; const MAX_RESPONSE_SIZE: u64 = 1024 * 1024; const JUSTIF_REQUEST_TIMEOUT: Duration = Duration::from_secs(3); +const BEEFY_SYNC_LOG_TARGET: &str = "beefy::sync"; + /// Get the configuration for the BEEFY justifications Request/response protocol. /// /// Returns a receiver for messages received on this protocol and the requested diff --git a/client/beefy/src/communication/request_response/outgoing_requests_engine.rs b/client/beefy/src/communication/request_response/outgoing_requests_engine.rs index 00ee7610dd4f0..c7dc269b495cc 100644 --- a/client/beefy/src/communication/request_response/outgoing_requests_engine.rs +++ b/client/beefy/src/communication/request_response/outgoing_requests_engine.rs @@ -32,7 +32,7 @@ use sp_runtime::traits::{Block, NumberFor}; use std::{collections::VecDeque, result::Result, sync::Arc}; use crate::{ - communication::request_response::{Error, JustificationRequest}, + communication::request_response::{Error, JustificationRequest, BEEFY_SYNC_LOG_TARGET}, justification::{decode_and_verify_finality_proof, BeefyVersionedFinalityProof}, KnownPeers, }; @@ -96,10 +96,8 @@ impl OnDemandJustificationsEngine { fn request_from_peer(&mut self, peer: PeerId, req_info: RequestInfo) { debug!( - target: "beefy::sync", - "🥩 requesting justif #{:?} from peer {:?}", - req_info.block, - peer, + target: BEEFY_SYNC_LOG_TARGET, + "🥩 requesting justif #{:?} from peer {:?}", req_info.block, peer, ); let payload = JustificationRequest:: { begin: req_info.block }.encode(); @@ -132,7 +130,10 @@ impl OnDemandJustificationsEngine { if let Some(peer) = self.try_next_peer() { self.request_from_peer(peer, RequestInfo { block, active_set }); } else { - debug!(target: "beefy::sync", "🥩 no good peers to request justif #{:?} from", block); + debug!( + target: BEEFY_SYNC_LOG_TARGET, + "🥩 no good peers to request justif #{:?} from", block + ); } } @@ -141,8 +142,8 @@ impl OnDemandJustificationsEngine { match &self.state { State::AwaitingResponse(_, req_info, _) if req_info.block <= block => { debug!( - target: "beefy::sync", "🥩 cancel pending request for justification #{:?}", - req_info.block + target: BEEFY_SYNC_LOG_TARGET, + "🥩 cancel pending request for justification #{:?}", req_info.block ); self.state = State::Idle; }, @@ -159,17 +160,21 @@ impl OnDemandJustificationsEngine { response .map_err(|e| { debug!( - target: "beefy::sync", + target: BEEFY_SYNC_LOG_TARGET, "🥩 for on demand justification #{:?}, peer {:?} hung up: {:?}", - req_info.block, peer, e + req_info.block, + peer, + e ); Error::InvalidResponse })? .map_err(|e| { debug!( - target: "beefy::sync", + target: BEEFY_SYNC_LOG_TARGET, "🥩 for on demand justification #{:?}, peer {:?} error: {:?}", - req_info.block, peer, e + req_info.block, + peer, + e ); Error::InvalidResponse }) @@ -181,7 +186,7 @@ impl OnDemandJustificationsEngine { ) .map_err(|e| { debug!( - target: "beefy::sync", + target: BEEFY_SYNC_LOG_TARGET, "🥩 for on demand justification #{:?}, peer {:?} responded with invalid proof: {:?}", req_info.block, peer, e ); @@ -213,14 +218,16 @@ impl OnDemandJustificationsEngine { if let Some(peer) = self.try_next_peer() { self.request_from_peer(peer, req_info); } else { - warn!(target: "beefy::sync", "🥩 ran out of peers to request justif #{:?} from", block); + warn!( + target: BEEFY_SYNC_LOG_TARGET, + "🥩 ran out of peers to request justif #{:?} from", block + ); } }) .map(|proof| { debug!( - target: "beefy::sync", - "🥩 received valid on-demand justif #{:?} from {:?}", - block, peer + target: BEEFY_SYNC_LOG_TARGET, + "🥩 received valid on-demand justif #{:?} from {:?}", block, peer ); proof }) diff --git a/client/beefy/src/import.rs b/client/beefy/src/import.rs index 0ed50d0ec8c98..f0fe3bfa024dc 100644 --- a/client/beefy/src/import.rs +++ b/client/beefy/src/import.rs @@ -35,6 +35,7 @@ use sc_consensus::{BlockCheckParams, BlockImport, BlockImportParams, ImportResul use crate::{ communication::notification::BeefyVersionedFinalityProofSender, justification::{decode_and_verify_finality_proof, BeefyVersionedFinalityProof}, + LOG_TARGET, }; /// A block-import handler for BEEFY. @@ -138,16 +139,20 @@ where (Some(encoded), ImportResult::Imported(_)) => { if let Ok(proof) = self.decode_and_verify(&encoded, number, hash) { // The proof is valid and the block is imported and final, we can import. - debug!(target: "beefy", "🥩 import justif {:?} for block number {:?}.", proof, number); + debug!( + target: LOG_TARGET, + "🥩 import justif {:?} for block number {:?}.", proof, number + ); // Send the justification to the BEEFY voter for processing. self.justification_sender .notify(|| Ok::<_, ()>(proof)) .expect("forwards closure result; the closure always returns Ok; qed."); } else { debug!( - target: "beefy", + target: LOG_TARGET, "🥩 error decoding justification: {:?} for imported block {:?}", - encoded, number, + encoded, + number, ); } }, diff --git a/client/beefy/src/keystore.rs b/client/beefy/src/keystore.rs index 8d77410746e52..d1f5615a93701 100644 --- a/client/beefy/src/keystore.rs +++ b/client/beefy/src/keystore.rs @@ -28,7 +28,7 @@ use beefy_primitives::{ BeefyAuthorityId, KEY_TYPE, }; -use crate::error; +use crate::{error, LOG_TARGET}; /// A BEEFY specific keystore implemented as a `Newtype`. This is basically a /// wrapper around [`sp_keystore::SyncCryptoStore`] and allows to customize @@ -53,7 +53,12 @@ impl BeefyKeystore { .collect(); if public.len() > 1 { - warn!(target: "beefy", "🥩 Multiple private keys found for: {:?} ({})", public, public.len()); + warn!( + target: LOG_TARGET, + "🥩 Multiple private keys found for: {:?} ({})", + public, + public.len() + ); } public.get(0).cloned() diff --git a/client/beefy/src/lib.rs b/client/beefy/src/lib.rs index 5b6531822a0a1..185f3b1ad502e 100644 --- a/client/beefy/src/lib.rs +++ b/client/beefy/src/lib.rs @@ -75,6 +75,8 @@ pub use communication::beefy_protocol_name::{ #[cfg(test)] mod tests; +const LOG_TARGET: &str = "beefy"; + /// A convenience BEEFY client trait that defines all the type bounds a BEEFY client /// has to satisfy. Ideally that should actually be a trait alias. Unfortunately as /// of today, Rust does not allow a type alias to be used as a trait bound. Tracking @@ -252,11 +254,11 @@ where prometheus_registry.as_ref().map(metrics::Metrics::register).and_then( |result| match result { Ok(metrics) => { - debug!(target: "beefy", "🥩 Registered metrics"); + debug!(target: LOG_TARGET, "🥩 Registered metrics"); Some(metrics) }, Err(err) => { - debug!(target: "beefy", "🥩 Failed to register metrics: {:?}", err); + debug!(target: LOG_TARGET, "🥩 Failed to register metrics: {:?}", err); None }, }, @@ -276,7 +278,7 @@ where }) { Ok(state) => state, Err(e) => { - error!(target: "beefy", "Error: {:?}. Terminating.", e); + error!(target: LOG_TARGET, "Error: {:?}. Terminating.", e); return }, }; @@ -321,7 +323,7 @@ where state.set_best_grandpa(best_grandpa); // Overwrite persisted data with newly provided `min_block_delta`. state.set_min_block_delta(min_block_delta); - info!(target: "beefy", "🥩 Loading BEEFY voter state from db: {:?}.", state); + info!(target: LOG_TARGET, "🥩 Loading BEEFY voter state from db: {:?}.", state); Ok(state) } else { initialize_voter_state(backend, runtime, best_grandpa, min_block_delta) @@ -357,7 +359,7 @@ where .map(|justifs| justifs.get(BEEFY_ENGINE_ID).is_some()) { info!( - target: "beefy", + target: LOG_TARGET, "🥩 Initialize BEEFY voter at last BEEFY finalized block: {:?}.", *header.number() ); @@ -382,10 +384,11 @@ where let genesis_set = expect_validator_set(runtime, BlockId::hash(header.hash())) .and_then(genesis_set_sanity_check)?; info!( - target: "beefy", + target: LOG_TARGET, "🥩 Loading BEEFY voter state from genesis on what appears to be first startup. \ Starting voting rounds at block {:?}, genesis validator set {:?}.", - genesis_num, genesis_set, + genesis_num, + genesis_set, ); sessions.push_front(Rounds::new(genesis_num, genesis_set)); @@ -394,7 +397,11 @@ where } if let Some(active) = worker::find_authorities_change::(&header) { - info!(target: "beefy", "🥩 Marking block {:?} as BEEFY Mandatory.", *header.number()); + info!( + target: LOG_TARGET, + "🥩 Marking block {:?} as BEEFY Mandatory.", + *header.number() + ); sessions.push_front(Rounds::new(*header.number(), active)); } @@ -407,7 +414,7 @@ where .flatten() .ok_or_else(|| { let msg = format!("{}. Could not initialize BEEFY voter.", parent_hash); - error!(target: "beefy", "🥩 {}", msg); + error!(target: LOG_TARGET, "🥩 {}", msg); ClientError::Consensus(sp_consensus::Error::StateUnavailable(msg)) })?; @@ -432,7 +439,7 @@ where R: ProvideRuntimeApi, R::Api: BeefyApi, { - info!(target: "beefy", "🥩 BEEFY gadget waiting for BEEFY pallet to become available..."); + info!(target: LOG_TARGET, "🥩 BEEFY gadget waiting for BEEFY pallet to become available..."); loop { futures::select! { notif = finality.next() => { @@ -444,7 +451,7 @@ where if let Some(active) = runtime.runtime_api().validator_set(&at).ok().flatten() { // Beefy pallet available, return best grandpa at the time. info!( - target: "beefy", "🥩 BEEFY pallet available: block {:?} validator set {:?}", + target: LOG_TARGET, "🥩 BEEFY pallet available: block {:?} validator set {:?}", notif.header.number(), active ); return Ok(notif.header) @@ -456,7 +463,7 @@ where } } let err_msg = "🥩 Gossip engine has unexpectedly terminated.".into(); - error!(target: "beefy", "{}", err_msg); + error!(target: LOG_TARGET, "{}", err_msg); Err(ClientError::Backend(err_msg)) } @@ -466,7 +473,7 @@ fn genesis_set_sanity_check( if active.id() == GENESIS_AUTHORITY_SET_ID { Ok(active) } else { - error!(target: "beefy", "🥩 Unexpected ID for genesis validator set {:?}.", active); + error!(target: LOG_TARGET, "🥩 Unexpected ID for genesis validator set {:?}.", active); Err(ClientError::Backend("BEEFY Genesis sanity check failed.".into())) } } diff --git a/client/beefy/src/round.rs b/client/beefy/src/round.rs index 48d3d087299d0..647d42110e926 100644 --- a/client/beefy/src/round.rs +++ b/client/beefy/src/round.rs @@ -16,6 +16,8 @@ // You should have received a copy of the GNU General Public License // along with this program. If not, see . +use crate::LOG_TARGET; + use beefy_primitives::{ crypto::{Public, Signature}, ValidatorSet, ValidatorSetId, @@ -122,11 +124,11 @@ where ) -> bool { let num = round.1; if num < self.session_start || Some(num) <= self.best_done { - debug!(target: "beefy", "🥩 received vote for old stale round {:?}, ignoring", num); + debug!(target: LOG_TARGET, "🥩 received vote for old stale round {:?}, ignoring", num); false } else if !self.validators().iter().any(|id| vote.0 == *id) { debug!( - target: "beefy", + target: LOG_TARGET, "🥩 received vote {:?} from validator that is not in the validator set, ignoring", vote ); @@ -145,7 +147,7 @@ where .get(round) .map(|tracker| tracker.is_done(threshold(self.validator_set.len()))) .unwrap_or(false); - trace!(target: "beefy", "🥩 Round #{} done: {}", round.1, done); + trace!(target: LOG_TARGET, "🥩 Round #{} done: {}", round.1, done); if done { let signatures = self.rounds.remove(round)?.votes; @@ -165,7 +167,7 @@ where self.rounds.retain(|&(_, number), _| number > round_num); self.mandatory_done = self.mandatory_done || round_num == self.session_start; self.best_done = self.best_done.max(Some(round_num)); - debug!(target: "beefy", "🥩 Concluded round #{}", round_num); + debug!(target: LOG_TARGET, "🥩 Concluded round #{}", round_num); } } diff --git a/client/beefy/src/worker.rs b/client/beefy/src/worker.rs index 8ec1403bb32d9..19ab52f520225 100644 --- a/client/beefy/src/worker.rs +++ b/client/beefy/src/worker.rs @@ -27,7 +27,7 @@ use crate::{ metric_inc, metric_set, metrics::Metrics, round::Rounds, - BeefyVoterLinks, + BeefyVoterLinks, LOG_TARGET, }; use beefy_primitives::{ crypto::{AuthorityId, Signature}, @@ -129,7 +129,7 @@ impl VoterOracle { min_block_delta: min_block_delta.max(1), }) } else { - error!(target: "beefy", "🥩 Invalid sessions queue: {:?}.", sessions); + error!(target: LOG_TARGET, "🥩 Invalid sessions queue: {:?}.", sessions); None } } @@ -227,7 +227,7 @@ impl VoterOracle { let rounds = if let Some(r) = self.sessions.front() { r } else { - debug!(target: "beefy", "🥩 No voting round started"); + debug!(target: LOG_TARGET, "🥩 No voting round started"); return None }; @@ -235,7 +235,7 @@ impl VoterOracle { let target = vote_target(best_grandpa, best_beefy, rounds.session_start(), self.min_block_delta); trace!( - target: "beefy", + target: LOG_TARGET, "🥩 best beefy: #{:?}, best finalized: #{:?}, current_vote_target: {:?}", best_beefy, best_grandpa, @@ -405,7 +405,7 @@ where if store.intersection(&active).count() == 0 { let msg = "no authority public key found in store".to_string(); - debug!(target: "beefy", "🥩 for block {:?} {}", block, msg); + debug!(target: LOG_TARGET, "🥩 for block {:?} {}", block, msg); Err(Error::Keystore(msg)) } else { Ok(()) @@ -418,13 +418,14 @@ where validator_set: ValidatorSet, new_session_start: NumberFor, ) { - debug!(target: "beefy", "🥩 New active validator set: {:?}", validator_set); + debug!(target: LOG_TARGET, "🥩 New active validator set: {:?}", validator_set); // BEEFY should finalize a mandatory block during each session. if let Some(active_session) = self.active_rounds() { if !active_session.mandatory_done() { debug!( - target: "beefy", "🥩 New session {} while active session {} is still lagging.", + target: LOG_TARGET, + "🥩 New session {} while active session {} is still lagging.", validator_set.id(), active_session.validator_set_id(), ); @@ -432,7 +433,7 @@ where } } - if log_enabled!(target: "beefy", log::Level::Debug) { + if log_enabled!(target: LOG_TARGET, log::Level::Debug) { // verify the new validator set - only do it if we're also logging the warning let _ = self.verify_validator_set(&new_session_start, &validator_set); } @@ -443,14 +444,15 @@ where .add_session(Rounds::new(new_session_start, validator_set)); metric_set!(self, beefy_validator_set_id, id); info!( - target: "beefy", + target: LOG_TARGET, "🥩 New Rounds for validator set id: {:?} with session_start {:?}", - id, new_session_start + id, + new_session_start ); } fn handle_finality_notification(&mut self, notification: &FinalityNotification) { - debug!(target: "beefy", "🥩 Finality notification: {:?}", notification); + debug!(target: LOG_TARGET, "🥩 Finality notification: {:?}", notification); let header = ¬ification.header; if *header.number() > self.best_grandpa_block() { @@ -491,14 +493,17 @@ where false, )?, RoundAction::Enqueue => { - debug!(target: "beefy", "🥩 Buffer vote for round: {:?}.", block_num); + debug!(target: LOG_TARGET, "🥩 Buffer vote for round: {:?}.", block_num); if self.pending_votes.len() < MAX_BUFFERED_VOTE_ROUNDS { let votes_vec = self.pending_votes.entry(block_num).or_default(); if votes_vec.try_push(vote).is_err() { - warn!(target: "beefy", "🥩 Buffer vote dropped for round: {:?}", block_num) + warn!( + target: LOG_TARGET, + "🥩 Buffer vote dropped for round: {:?}", block_num + ) } } else { - warn!(target: "beefy", "🥩 Buffer vote dropped for round: {:?}.", block_num); + warn!(target: LOG_TARGET, "🥩 Buffer vote dropped for round: {:?}.", block_num); } }, RoundAction::Drop => (), @@ -520,15 +525,18 @@ where let best_grandpa = self.best_grandpa_block(); match self.voting_oracle().triage_round(block_num, best_grandpa)? { RoundAction::Process => { - debug!(target: "beefy", "🥩 Process justification for round: {:?}.", block_num); + debug!(target: LOG_TARGET, "🥩 Process justification for round: {:?}.", block_num); self.finalize(justification)? }, RoundAction::Enqueue => { - debug!(target: "beefy", "🥩 Buffer justification for round: {:?}.", block_num); + debug!(target: LOG_TARGET, "🥩 Buffer justification for round: {:?}.", block_num); if self.pending_justifications.len() < MAX_BUFFERED_JUSTIFICATIONS { self.pending_justifications.entry(block_num).or_insert(justification); } else { - warn!(target: "beefy", "🥩 Buffer justification dropped for round: {:?}.", block_num); + warn!( + target: LOG_TARGET, + "🥩 Buffer justification dropped for round: {:?}.", block_num + ); } }, RoundAction::Drop => (), @@ -566,7 +574,10 @@ where metric_set!(self, beefy_round_concluded, block_num); - info!(target: "beefy", "🥩 Round #{} concluded, finality_proof: {:?}.", round.1, finality_proof); + info!( + target: LOG_TARGET, + "🥩 Round #{} concluded, finality_proof: {:?}.", round.1, finality_proof + ); // We created the `finality_proof` and know to be valid. // New state is persisted after finalization. @@ -627,7 +638,10 @@ where self.backend .append_justification(hash, (BEEFY_ENGINE_ID, finality_proof.encode())) }) { - error!(target: "beefy", "🥩 Error {:?} on appending justification: {:?}", e, finality_proof); + error!( + target: LOG_TARGET, + "🥩 Error {:?} on appending justification: {:?}", e, finality_proof + ); } self.links @@ -635,7 +649,7 @@ where .notify(|| Ok::<_, ()>(finality_proof)) .expect("forwards closure result; the closure always returns Ok; qed."); } else { - debug!(target: "beefy", "🥩 Can't set best beefy to older: {}", block_num); + debug!(target: LOG_TARGET, "🥩 Can't set best beefy to older: {}", block_num); } Ok(()) } @@ -666,9 +680,9 @@ where if !self.pending_justifications.is_empty() { let justifs_to_handle = to_process_for(&mut self.pending_justifications, interval, _ph); for (num, justification) in justifs_to_handle.into_iter() { - debug!(target: "beefy", "🥩 Handle buffered justification for: {:?}.", num); + debug!(target: LOG_TARGET, "🥩 Handle buffered justification for: {:?}.", num); if let Err(err) = self.finalize(justification) { - error!(target: "beefy", "🥩 Error finalizing block: {}", err); + error!(target: LOG_TARGET, "🥩 Error finalizing block: {}", err); } } // Possibly new interval after processing justifications. @@ -679,14 +693,14 @@ where if !self.pending_votes.is_empty() { let votes_to_handle = to_process_for(&mut self.pending_votes, interval, _ph); for (num, votes) in votes_to_handle.into_iter() { - debug!(target: "beefy", "🥩 Handle buffered votes for: {:?}.", num); + debug!(target: LOG_TARGET, "🥩 Handle buffered votes for: {:?}.", num); for v in votes.into_iter() { if let Err(err) = self.handle_vote( (v.commitment.payload, v.commitment.block_number), (v.id, v.signature), false, ) { - error!(target: "beefy", "🥩 Error handling buffered vote: {}", err); + error!(target: LOG_TARGET, "🥩 Error handling buffered vote: {}", err); }; } } @@ -711,7 +725,7 @@ where /// /// Also handle this self vote by calling `self.handle_vote()` for it. fn do_vote(&mut self, target_number: NumberFor) -> Result<(), Error> { - debug!(target: "beefy", "🥩 Try voting on {}", target_number); + debug!(target: LOG_TARGET, "🥩 Try voting on {}", target_number); // Most of the time we get here, `target` is actually `best_grandpa`, // avoid getting header from backend in that case. @@ -743,7 +757,7 @@ where let payload = if let Some(hash) = self.payload_provider.payload(&target_header) { hash } else { - warn!(target: "beefy", "🥩 No MMR root digest found for: {:?}", target_hash); + warn!(target: LOG_TARGET, "🥩 No MMR root digest found for: {:?}", target_hash); return Ok(()) }; @@ -753,16 +767,22 @@ where .active_rounds_mut() .ok_or(Error::UninitSession)?; if !rounds.should_self_vote(&(payload.clone(), target_number)) { - debug!(target: "beefy", "🥩 Don't double vote for block number: {:?}", target_number); + debug!( + target: LOG_TARGET, + "🥩 Don't double vote for block number: {:?}", target_number + ); return Ok(()) } let (validators, validator_set_id) = (rounds.validators(), rounds.validator_set_id()); let authority_id = if let Some(id) = self.key_store.authority_id(validators) { - debug!(target: "beefy", "🥩 Local authority id: {:?}", id); + debug!(target: LOG_TARGET, "🥩 Local authority id: {:?}", id); id } else { - debug!(target: "beefy", "🥩 Missing validator id - can't vote for: {:?}", target_hash); + debug!( + target: LOG_TARGET, + "🥩 Missing validator id - can't vote for: {:?}", target_hash + ); return Ok(()) }; @@ -772,13 +792,13 @@ where let signature = match self.key_store.sign(&authority_id, &encoded_commitment) { Ok(sig) => sig, Err(err) => { - warn!(target: "beefy", "🥩 Error signing commitment: {:?}", err); + warn!(target: LOG_TARGET, "🥩 Error signing commitment: {:?}", err); return Ok(()) }, }; trace!( - target: "beefy", + target: LOG_TARGET, "🥩 Produced signature using {:?}, is_valid: {:?}", authority_id, BeefyKeystore::verify(&authority_id, &signature, &encoded_commitment) @@ -790,14 +810,14 @@ where metric_inc!(self, beefy_votes_sent); - debug!(target: "beefy", "🥩 Sent vote message: {:?}", message); + debug!(target: LOG_TARGET, "🥩 Sent vote message: {:?}", message); if let Err(err) = self.handle_vote( (message.commitment.payload, message.commitment.block_number), (message.id, message.signature), true, ) { - error!(target: "beefy", "🥩 Error handling self vote: {}", err); + error!(target: LOG_TARGET, "🥩 Error handling self vote: {}", err); } self.gossip_engine.gossip_message(topic::(), encoded_message, false); @@ -808,14 +828,14 @@ where fn process_new_state(&mut self) { // Handle pending justifications and/or votes for now GRANDPA finalized blocks. if let Err(err) = self.try_pending_justif_and_votes() { - debug!(target: "beefy", "🥩 {}", err); + debug!(target: LOG_TARGET, "🥩 {}", err); } // Don't bother voting or requesting justifications during major sync. if !self.network.is_major_syncing() { // There were external events, 'state' is changed, author a vote if needed/possible. if let Err(err) = self.try_to_vote() { - debug!(target: "beefy", "🥩 {}", err); + debug!(target: LOG_TARGET, "🥩 {}", err); } // If the current target is a mandatory block, // make sure there's also an on-demand justification request out for it. @@ -835,13 +855,17 @@ where mut block_import_justif: Fuse>>, mut finality_notifications: Fuse>, ) { - info!(target: "beefy", "🥩 run BEEFY worker, best grandpa: #{:?}.", self.best_grandpa_block()); + info!( + target: LOG_TARGET, + "🥩 run BEEFY worker, best grandpa: #{:?}.", + self.best_grandpa_block() + ); let mut votes = Box::pin( self.gossip_engine .messages_for(topic::()) .filter_map(|notification| async move { - trace!(target: "beefy", "🥩 Got vote message: {:?}", notification); + trace!(target: LOG_TARGET, "🥩 Got vote message: {:?}", notification); VoteMessage::, AuthorityId, Signature>::decode( &mut ¬ification.message[..], @@ -863,7 +887,7 @@ where // Use `select_biased!` to prioritize order below. // Make sure to pump gossip engine. _ = gossip_engine => { - error!(target: "beefy", "🥩 Gossip engine has terminated, closing worker."); + error!(target: LOG_TARGET, "🥩 Gossip engine has terminated, closing worker."); return; }, // Process finality notifications first since these drive the voter. @@ -871,7 +895,7 @@ where if let Some(notification) = notification { self.handle_finality_notification(¬ification); } else { - error!(target: "beefy", "🥩 Finality stream terminated, closing worker."); + error!(target: LOG_TARGET, "🥩 Finality stream terminated, closing worker."); return; } }, @@ -879,7 +903,7 @@ where justif = self.on_demand_justifications.next().fuse() => { if let Some(justif) = justif { if let Err(err) = self.triage_incoming_justif(justif) { - debug!(target: "beefy", "🥩 {}", err); + debug!(target: LOG_TARGET, "🥩 {}", err); } } }, @@ -888,10 +912,10 @@ where // Block import justifications have already been verified to be valid // by `BeefyBlockImport`. if let Err(err) = self.triage_incoming_justif(justif) { - debug!(target: "beefy", "🥩 {}", err); + debug!(target: LOG_TARGET, "🥩 {}", err); } } else { - error!(target: "beefy", "🥩 Block import stream terminated, closing worker."); + error!(target: LOG_TARGET, "🥩 Block import stream terminated, closing worker."); return; } }, @@ -900,10 +924,10 @@ where if let Some(vote) = vote { // Votes have already been verified to be valid by the gossip validator. if let Err(err) = self.triage_incoming_vote(vote) { - debug!(target: "beefy", "🥩 {}", err); + debug!(target: LOG_TARGET, "🥩 {}", err); } } else { - error!(target: "beefy", "🥩 Votes gossiping stream terminated, closing worker."); + error!(target: LOG_TARGET, "🥩 Votes gossiping stream terminated, closing worker."); return; } }, @@ -937,18 +961,14 @@ where // if the mandatory block (session_start) does not have a beefy justification yet, // we vote on it let target = if best_beefy < session_start { - debug!( - target: "beefy", - "🥩 vote target - mandatory block: #{:?}", - session_start, - ); + debug!(target: LOG_TARGET, "🥩 vote target - mandatory block: #{:?}", session_start,); session_start } else { let diff = best_grandpa.saturating_sub(best_beefy) + 1u32.into(); let diff = diff.saturated_into::() / 2; let target = best_beefy + min_delta.max(diff.next_power_of_two()).into(); trace!( - target: "beefy", + target: LOG_TARGET, "🥩 vote target - diff: {:?}, next_power_of_two: {:?}, target block: #{:?}", diff, diff.next_power_of_two(),