Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Define log target in one single place #158

Merged
merged 1 commit into from
Dec 14, 2022
Merged

Define log target in one single place #158

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions src/lib.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,9 @@ use round::ImportResult;
#[cfg(feature = "derive-codec")]
use scale_info::TypeInfo;

// Overarching log target
const LOG_TARGET: &str = "grandpa";

/// A prevote for a block and its ancestors.
#[derive(Clone, Debug, PartialEq, Eq)]
#[cfg_attr(feature = "derive-codec", derive(Encode, Decode, TypeInfo))]
Expand Down
51 changes: 30 additions & 21 deletions src/voter/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -46,7 +46,7 @@ use std::{
use crate::{
round::State as RoundState, validate_commit, voter_set::VoterSet, weights::VoteWeight,
BlockNumberOps, CatchUp, Chain, Commit, CommitValidationResult, CompactCommit, Equivocation,
HistoricalVotes, Message, Precommit, Prevote, PrimaryPropose, SignedMessage,
HistoricalVotes, Message, Precommit, Prevote, PrimaryPropose, SignedMessage, LOG_TARGET,
};
use past_rounds::PastRounds;
use voting_round::{State as VotingRoundState, VotingRound};
Expand Down Expand Up @@ -645,7 +645,9 @@ where
while let Poll::Ready(Some(item)) = Stream::poll_next(Pin::new(&mut self.global_in), cx) {
match item? {
CommunicationIn::Commit(round_number, commit, mut process_commit_outcome) => {
trace!(target: "afg", "Got commit for round_number {:?}: target_number: {:?}, target_hash: {:?}",
trace!(
target: LOG_TARGET,
"Got commit for round_number {:?}: target_number: {:?}, target_hash: {:?}",
round_number,
commit.target_number,
commit.target_hash,
Expand Down Expand Up @@ -696,7 +698,11 @@ where
}
},
CommunicationIn::CatchUp(catch_up, mut process_catch_up_outcome) => {
trace!(target: "afg", "Got catch-up message for round {}", catch_up.round_number);
trace!(
target: LOG_TARGET,
"Got catch-up message for round {}",
catch_up.round_number
);

let mut inner = self.inner.lock();

Expand Down Expand Up @@ -786,7 +792,9 @@ where
return Poll::Pending
}

trace!(target: "afg", "Best round at {} has become completable. Starting new best round at {}",
trace!(
target: LOG_TARGET,
"Best round at {} has become completable. Starting new best round at {}",
inner.best_round.round_number(),
inner.best_round.round_number() + 1,
);
Expand Down Expand Up @@ -959,8 +967,7 @@ where
E: Environment<H, N>,
{
if catch_up.round_number <= best_round_number {
trace!(target: "afg", "Ignoring because best round number is {}",
best_round_number);
trace!(target: LOG_TARGET, "Ignoring because best round number is {}", best_round_number);

return None
}
Expand All @@ -971,9 +978,10 @@ where

for prevote in &catch_up.prevotes {
if !voters.contains(&prevote.id) {
trace!(target: "afg",
"Ignoring invalid catch up, invalid voter: {:?}",
prevote.id,
trace!(
target: LOG_TARGET,
"Ignoring invalid catch up, invalid voter: {:?}",
prevote.id,
);

return None
Expand All @@ -984,9 +992,10 @@ where

for precommit in &catch_up.precommits {
if !voters.contains(&precommit.id) {
trace!(target: "afg",
"Ignoring invalid catch up, invalid voter: {:?}",
precommit.id,
trace!(
target: LOG_TARGET,
"Ignoring invalid catch up, invalid voter: {:?}",
precommit.id,
);

return None
Expand Down Expand Up @@ -1014,9 +1023,7 @@ where

let threshold = voters.threshold();
if pv < threshold || pc < threshold {
trace!(target: "afg",
"Ignoring invalid catch up, missing voter threshold"
);
trace!(target: LOG_TARGET, "Ignoring invalid catch up, missing voter threshold");

return None
}
Expand All @@ -1033,9 +1040,10 @@ where
match round.import_prevote(env, prevote, id, signature) {
Ok(_) => {},
Err(e) => {
trace!(target: "afg",
"Ignoring invalid catch up, error importing prevote: {:?}",
e,
trace!(
target: LOG_TARGET,
"Ignoring invalid catch up, error importing prevote: {:?}",
e,
);

return None
Expand All @@ -1048,9 +1056,10 @@ where
match round.import_precommit(env, precommit, id, signature) {
Ok(_) => {},
Err(e) => {
trace!(target: "afg",
"Ignoring invalid catch up, error importing precommit: {:?}",
e,
trace!(
target: LOG_TARGET,
"Ignoring invalid catch up, error importing precommit: {:?}",
e,
);

return None
Expand Down
7 changes: 4 additions & 3 deletions src/voter/past_rounds.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,7 @@ use std::{
};

use super::{voting_round::VotingRound, Environment};
use crate::{BlockNumberOps, Commit};
use crate::{BlockNumberOps, Commit, LOG_TARGET};

// wraps a voting round with a new future that resolves when the round can
// be discarded from the working set.
Expand Down Expand Up @@ -194,7 +194,7 @@ where
Stream::poll_next(Pin::new(&mut self.import_commits), cx)
{
if !self.import_commit(voting_round, commit)? {
trace!(target: "afg", "Ignoring invalid commit");
trace!(target: LOG_TARGET, "Ignoring invalid commit");
}
}

Expand Down Expand Up @@ -342,7 +342,8 @@ where
self.past_rounds.push(round.into());

debug!(
target: "afg", "Committing: round_number = {}, \
target: LOG_TARGET,
"Committing: round_number = {}, \
target_number = {:?}, target_hash = {:?}",
number,
commit.target_number,
Expand Down
111 changes: 85 additions & 26 deletions src/voter/voting_round.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ use crate::{
voter_set::VoterSet,
weights::VoteWeight,
BlockNumberOps, Commit, HistoricalVotes, ImportResult, Message, Precommit, Prevote,
PrimaryPropose, SignedMessage, SignedPrecommit,
PrimaryPropose, SignedMessage, SignedPrecommit, LOG_TARGET,
};

/// The state of a voting round.
Expand Down Expand Up @@ -169,7 +169,13 @@ where
/// Poll the round. When the round is completable and messages have been flushed, it will return `Poll::Ready` but
/// can continue to be polled.
pub(super) fn poll(&mut self, cx: &mut Context) -> Poll<Result<(), E::Error>> {
trace!(target: "afg", "Polling round {}, state = {:?}, step = {:?}", self.votes.number(), self.votes.state(), self.state);
trace!(
target: LOG_TARGET,
"Polling round {}, state = {:?}, step = {:?}",
self.votes.number(),
self.votes.state(),
self.state
);

let pre_state = self.votes.state();
self.process_incoming(cx)?;
Expand Down Expand Up @@ -225,13 +231,22 @@ where

// the previous round estimate must be finalized
if !last_round_estimate_finalized {
trace!(target: "afg", "Round {} completable but estimate not finalized.", self.round_number());
trace!(
target: LOG_TARGET,
"Round {} completable but estimate not finalized.",
self.round_number()
);
self.log_participation(log::Level::Trace);
return Poll::Pending
}

debug!(target: "afg", "Completed round {}, state = {:?}, step = {:?}",
self.votes.number(), self.votes.state(), self.state);
debug!(
target: LOG_TARGET,
"Completed round {}, state = {:?}, step = {:?}",
self.votes.number(),
self.votes.state(),
self.state
);

self.log_participation(log::Level::Debug);

Expand Down Expand Up @@ -325,8 +340,11 @@ where
pub(super) fn bridge_state(&mut self) -> crate::bridge_state::LatterView<H, N> {
let (prior_view, latter_view) = crate::bridge_state::bridge_state(self.votes.state());
if self.bridged_round_state.is_some() {
warn!(target: "afg", "Bridged state from round {} more than once.",
self.votes.number());
warn!(
target: LOG_TARGET,
"Bridged state from round {} more than once.",
self.votes.number()
);
}

self.bridged_round_state = Some(prior_view);
Expand Down Expand Up @@ -356,7 +374,9 @@ where
.env
.is_equal_or_descendent_of(self.votes.base().0, message.target().0.clone())
{
trace!(target: "afg", "Ignoring message targeting {:?} lower than round base {:?}",
trace!(
target: LOG_TARGET,
"Ignoring message targeting {:?} lower than round base {:?}",
message.target(),
self.votes.base(),
);
Expand Down Expand Up @@ -400,17 +420,35 @@ where
let (prevote_weight, n_prevotes) = self.votes.prevote_participation();
let (precommit_weight, n_precommits) = self.votes.precommit_participation();

log::log!(target: "afg", log_level, "Round {}: prevotes: {}/{}/{} weight, {}/{} actual",
number, prevote_weight, threshold, total_weight, n_prevotes, n_voters);

log::log!(target: "afg", log_level, "Round {}: precommits: {}/{}/{} weight, {}/{} actual",
number, precommit_weight, threshold, total_weight, n_precommits, n_voters);
log::log!(
target: LOG_TARGET,
log_level,
"Round {}: prevotes: {}/{}/{} weight, {}/{} actual",
number,
prevote_weight,
threshold,
total_weight,
n_prevotes,
n_voters
);

log::log!(
target: LOG_TARGET,
log_level,
"Round {}: precommits: {}/{}/{} weight, {}/{} actual",
number,
precommit_weight,
threshold,
total_weight,
n_precommits,
n_voters
);
}

fn process_incoming(&mut self, cx: &mut Context) -> Result<(), E::Error> {
while let Poll::Ready(Some(incoming)) = Stream::poll_next(Pin::new(&mut self.incoming), cx)
{
trace!(target: "afg", "Round {}: Got incoming message", self.round_number());
trace!(target: LOG_TARGET, "Round {}: Got incoming message", self.round_number());
self.handle_vote(incoming?)?;
}

Expand All @@ -430,7 +468,11 @@ where
let should_send_primary =
maybe_finalized.map_or(true, |f| last_round_estimate.1 > f.1);
if should_send_primary {
debug!(target: "afg", "Sending primary block hint for round {}", self.votes.number());
debug!(
target: LOG_TARGET,
"Sending primary block hint for round {}",
self.votes.number()
);
let primary = PrimaryPropose {
target_hash: last_round_estimate.0,
target_number: last_round_estimate.1,
Expand All @@ -441,13 +483,21 @@ where

return Ok(())
} else {
debug!(target: "afg", "Last round estimate has been finalized, \
not sending primary block hint for round {}", self.votes.number());
debug!(
target: LOG_TARGET,
"Last round estimate has been finalized, \
not sending primary block hint for round {}",
self.votes.number()
);
}
},
(None, true) => {
debug!(target: "afg", "Last round estimate does not exist, \
not sending primary block hint for round {}", self.votes.number());
debug!(
target: LOG_TARGET,
"Last round estimate does not exist, \
not sending primary block hint for round {}",
self.votes.number()
);
},
_ => {},
}
Expand Down Expand Up @@ -482,7 +532,11 @@ where

if should_prevote {
if this.voting.is_active() {
debug!(target: "afg", "Constructing prevote for round {}", this.votes.number());
debug!(
target: LOG_TARGET,
"Constructing prevote for round {}",
this.votes.number()
);

let (base, best_chain) = this.construct_prevote(last_round_state);

Expand Down Expand Up @@ -522,17 +576,17 @@ where
if let Some(target) = best_chain {
let prevote = Prevote { target_hash: target.0, target_number: target.1 };

debug!(target: "afg", "Casting prevote for round {}", this.votes.number());
debug!(target: LOG_TARGET, "Casting prevote for round {}", this.votes.number());
this.env.prevoted(this.round_number(), prevote.clone())?;
this.votes.set_prevoted_index();
this.outgoing.push(Message::Prevote(prevote));
this.state = Some(State::Prevoted(precommit_timer));
} else {
// if this block is considered unknown, something has gone wrong.
// log and handle, but skip casting a vote.
warn!(target: "afg",
"Could not cast prevote: previously known block {:?} has disappeared",
base,
warn!(
target: LOG_TARGET,
"Could not cast prevote: previously known block {:?} has disappeared", base,
);

// when we can't construct a prevote, we shouldn't precommit.
Expand Down Expand Up @@ -589,7 +643,11 @@ where

if should_precommit {
if self.voting.is_active() {
debug!(target: "afg", "Casting precommit for round {}", self.votes.number());
debug!(
target: LOG_TARGET,
"Casting precommit for round {}",
self.votes.number()
);
let precommit = self.construct_precommit();
self.env.precommitted(self.round_number(), precommit.clone())?;
self.votes.set_precommitted_index();
Expand Down Expand Up @@ -660,7 +718,8 @@ where
},
Err(crate::Error::NotDescendent) => {
// This is only possible in case of massive equivocation
warn!(target: "afg",
warn!(
target: LOG_TARGET,
"Possible case of massive equivocation: \
last round prevote GHOST: {:?} is not a descendant of last round estimate: {:?}",
last_prevote_g,
Expand Down