diff --git a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/blockcreation/IbftMiningCoordinator.java b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/blockcreation/IbftMiningCoordinator.java index 3327469489..0196e020cd 100644 --- a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/blockcreation/IbftMiningCoordinator.java +++ b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/blockcreation/IbftMiningCoordinator.java @@ -78,7 +78,7 @@ public class IbftMiningCoordinator implements MiningCoordinator, BlockAddedObser @Override public void onBlockAdded(final BlockAddedEvent event, final Blockchain blockchain) { if (event.isNewCanonicalHead()) { - LOG.info("New canonical head detected"); + LOG.trace("New canonical head detected"); eventQueue.add(new NewChainHead(event.getBlock().getHeader())); } } diff --git a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftBlockHeightManager.java b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftBlockHeightManager.java index 0bff35383f..9b4be95fbf 100644 --- a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftBlockHeightManager.java +++ b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftBlockHeightManager.java @@ -113,7 +113,7 @@ public class IbftBlockHeightManager implements BlockHeightManager { if (roundIdentifier.equals(currentRound.getRoundIdentifier())) { currentRound.createAndSendProposalMessage(clock.millis() / 1000); } else { - LOG.info( + LOG.trace( "Block timer expired for a round ({}) other than current ({})", roundIdentifier, currentRound.getRoundIdentifier()); @@ -123,14 +123,14 @@ public class IbftBlockHeightManager implements BlockHeightManager { @Override public void roundExpired(final RoundExpiry expire) { if (!expire.getView().equals(currentRound.getRoundIdentifier())) { - LOG.info( + LOG.trace( "Ignoring Round timer expired which does not match current round. round={}, timerRound={}", currentRound.getRoundIdentifier(), expire.getView()); return; } - LOG.info( + LOG.debug( "Round has expired, creating PreparedCertificate and notifying peers. round={}", currentRound.getRoundIdentifier()); final Optional preparedRoundArtifacts = @@ -155,21 +155,21 @@ public class IbftBlockHeightManager implements BlockHeightManager { @Override public void handleProposalPayload(final Proposal proposal) { - LOG.debug("Received a Proposal Payload."); + LOG.trace("Received a Proposal Payload."); actionOrBufferMessage( proposal, currentRound::handleProposalMessage, RoundState::setProposedBlock); } @Override public void handlePreparePayload(final Prepare prepare) { - LOG.debug("Received a Prepare Payload."); + LOG.trace("Received a Prepare Payload."); actionOrBufferMessage( prepare, currentRound::handlePrepareMessage, RoundState::addPrepareMessage); } @Override public void handleCommitPayload(final Commit commit) { - LOG.debug("Received a Commit Payload."); + LOG.trace("Received a Commit Payload."); actionOrBufferMessage(commit, currentRound::handleCommitMessage, RoundState::addCommitMessage); } @@ -193,18 +193,21 @@ public class IbftBlockHeightManager implements BlockHeightManager { @Override public void handleRoundChangePayload(final RoundChange message) { final ConsensusRoundIdentifier targetRound = message.getRoundIdentifier(); - LOG.info("Received a RoundChange Payload for {}", targetRound.toString()); + LOG.trace("Received a RoundChange Payload for {}", targetRound); final MessageAge messageAge = determineAgeOfPayload(message.getRoundIdentifier().getRoundNumber()); if (messageAge == PRIOR_ROUND) { - LOG.debug("Received RoundChange Payload for a prior round. targetRound={}", targetRound); + LOG.trace("Received RoundChange Payload for a prior round. targetRound={}", targetRound); return; } final Optional> result = roundChangeManager.appendRoundChangeMessage(message); if (result.isPresent()) { + LOG.debug( + "Received sufficient RoundChange messages to change round to targetRound={}", + targetRound); if (messageAge == FUTURE_ROUND) { startNewRound(targetRound.getRoundNumber()); } @@ -219,7 +222,7 @@ public class IbftBlockHeightManager implements BlockHeightManager { } private void startNewRound(final int roundNumber) { - LOG.info("Starting new round {}", roundNumber); + LOG.debug("Starting new round {}", roundNumber); if (futureRoundStateBuffer.containsKey(roundNumber)) { currentRound = roundFactory.createNewRoundWithState( @@ -240,10 +243,10 @@ public class IbftBlockHeightManager implements BlockHeightManager { determineAgeOfPayload(newRound.getRoundIdentifier().getRoundNumber()); if (messageAge == PRIOR_ROUND) { - LOG.info("Received NewRound Payload for a prior round={}", newRound.getRoundIdentifier()); + LOG.trace("Received NewRound Payload for a prior round={}", newRound.getRoundIdentifier()); return; } - LOG.info("Received NewRound Payload for {}", newRound.getRoundIdentifier()); + LOG.trace("Received NewRound Payload for {}", newRound.getRoundIdentifier()); if (newRoundMessageValidator.validateNewRoundMessage(newRound)) { if (messageAge == FUTURE_ROUND) { diff --git a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftController.java b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftController.java index 25cbf4b5f7..c8cb5d6223 100644 --- a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftController.java +++ b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftController.java @@ -158,8 +158,9 @@ public class IbftController { public void handleNewBlockEvent(final NewChainHead newChainHead) { final BlockHeader newBlockHeader = newChainHead.getNewChainHeadHeader(); final BlockHeader currentMiningParent = currentHeightManager.getParentBlockHeader(); + LOG.debug("Handling New Chain head event, chain height = {}", currentMiningParent.getNumber()); if (newBlockHeader.getNumber() < currentMiningParent.getNumber()) { - LOG.debug( + LOG.trace( "Discarding NewChainHead event, was for previous block height. chainHeight={} eventHeight={}", currentMiningParent.getNumber(), newBlockHeader.getNumber()); @@ -168,7 +169,7 @@ public class IbftController { if (newBlockHeader.getNumber() == currentMiningParent.getNumber()) { if (newBlockHeader.getHash().equals(currentMiningParent.getHash())) { - LOG.debug( + LOG.trace( "Discarding duplicate NewChainHead event. chainHeight={} newBlockHash={} parentBlockHash", newBlockHeader.getNumber(), newBlockHeader.getHash(), @@ -188,7 +189,7 @@ public class IbftController { if (isMsgForCurrentHeight(roundIndentifier)) { currentHeightManager.handleBlockTimerExpiry(roundIndentifier); } else { - LOG.debug( + LOG.trace( "Block timer event discarded as it is not for current block height chainHeight={} eventHeight={}", currentHeightManager.getChainHeight(), roundIndentifier.getSequenceNumber()); @@ -199,7 +200,7 @@ public class IbftController { if (isMsgForCurrentHeight(roundExpiry.getView())) { currentHeightManager.roundExpired(roundExpiry); } else { - LOG.debug( + LOG.trace( "Round expiry event discarded as it is not for current block height chainHeight={} eventHeight={}", currentHeightManager.getChainHeight(), roundExpiry.getView().getSequenceNumber()); diff --git a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftRound.java b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftRound.java index 959a36c852..e7a3efb817 100644 --- a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftRound.java +++ b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftRound.java @@ -81,7 +81,7 @@ public class IbftRound { public void createAndSendProposalMessage(final long headerTimeStampSeconds) { final Block block = blockCreator.createBlock(headerTimeStampSeconds); final IbftExtraData extraData = IbftExtraData.decode(block.getHeader().getExtraData()); - LOG.info( + LOG.debug( "Creating proposed block. round={} extraData={} blockHeader={}", roundState.getRoundIdentifier(), extraData, @@ -98,11 +98,11 @@ public class IbftRound { Proposal proposal; if (!bestBlockFromRoundChange.isPresent()) { - LOG.trace("Multicasting NewRound with new block. round={}", roundState.getRoundIdentifier()); + LOG.debug("Multicasting NewRound with new block. round={}", roundState.getRoundIdentifier()); final Block block = blockCreator.createBlock(headerTimestamp); proposal = messageFactory.createProposal(getRoundIdentifier(), block); } else { - LOG.trace( + LOG.debug( "Multicasting NewRound from PreparedCertificate. round={}", roundState.getRoundIdentifier()); proposal = createProposalAroundBlock(bestBlockFromRoundChange.get()); @@ -125,7 +125,7 @@ public class IbftRound { } public void handleProposalMessage(final Proposal msg) { - LOG.info("Handling a Proposal message."); + LOG.debug("Handling a Proposal message."); if (getRoundIdentifier().getRoundNumber() != 0) { LOG.error("Illegally received a Proposal message when not in Round 0."); @@ -135,7 +135,7 @@ public class IbftRound { } public void handleProposalFromNewRound(final NewRound msg) { - LOG.info("Handling a New Round Proposal."); + LOG.debug("Handling a New Round Proposal."); if (getRoundIdentifier().getRoundNumber() == 0) { LOG.error("Illegally received a NewRound message when in Round 0."); @@ -148,7 +148,7 @@ public class IbftRound { final Block block = msg.getBlock(); if (updateStateWithProposedBlock(msg)) { - LOG.info("Sending prepare message."); + LOG.debug("Sending prepare message."); transmitter.multicastPrepare(getRoundIdentifier(), block.getHash()); final Prepare localPrepareMessage = messageFactory.createPrepare(roundState.getRoundIdentifier(), block.getHash()); @@ -221,7 +221,11 @@ public class IbftRound { final long blockNumber = blockToImport.getHeader().getNumber(); final IbftExtraData extraData = IbftExtraData.decode(blockToImport.getHeader().getExtraData()); - LOG.info("Importing block to chain. block={} extraData={}", blockNumber, extraData); + LOG.info( + "Importing block to chain. round={}, hash={}", + getRoundIdentifier(), + blockToImport.getHash()); + LOG.debug("ExtraData = {}", extraData); final boolean result = blockImporter.importBlock(protocolContext, blockToImport, HeaderValidationMode.FULL); if (!result) { diff --git a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/validation/NewRoundMessageValidator.java b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/validation/NewRoundMessageValidator.java index abbd7817e4..06cd05bb47 100644 --- a/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/validation/NewRoundMessageValidator.java +++ b/consensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/validation/NewRoundMessageValidator.java @@ -100,7 +100,7 @@ public class NewRoundMessageValidator { findLatestPreparedCertificate(roundChangePayloads); if (!latestPreparedCertificate.isPresent()) { - LOG.info( + LOG.trace( "No round change messages have a preparedCertificate, any valid block may be proposed."); return true; }