Shuffled log levels (#813)

PegaSysEng · Feb 11, 2019 · 30f7254 · 30f7254
1 parent 6a35970
commit 30f7254
Show file tree

Hide file tree

Showing 5 changed files with 32 additions and 24 deletions.
diff --git a/...c/main/java/tech/pegasys/pantheon/consensus/ibft/blockcreation/IbftMiningCoordinator.java b/...c/main/java/tech/pegasys/pantheon/consensus/ibft/blockcreation/IbftMiningCoordinator.java
@@ -78,7 +78,7 @@ public void setExtraData(final BytesValue extraData) {
   @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/...c/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftBlockHeightManager.java b/...c/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftBlockHeightManager.java
@@ -113,7 +113,7 @@ public void handleBlockTimerExpiry(final ConsensusRoundIdentifier roundIdentifie
     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 void handleBlockTimerExpiry(final ConsensusRoundIdentifier roundIdentifie
   @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> preparedRoundArtifacts =
@@ -155,21 +155,21 @@ public void roundExpired(final RoundExpiry expire) {
 
   @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 @@ private <P extends Payload, M extends IbftMessage<P>> void actionOrBufferMessage
   @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<Collection<RoundChange>> 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 void handleRoundChangePayload(final RoundChange message) {
   }
 
   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 void handleNewRoundPayload(final NewRound newRound) {
         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/.../ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftController.java b/.../ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftController.java
@@ -158,8 +158,9 @@ private <P extends IbftMessage<?>> void consumeMessage(
   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 void handleNewBlockEvent(final NewChainHead newChainHead) {
 
     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 void handleBlockTimerExpiry(final BlockTimerExpiry blockTimerExpiry) {
     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 void handleRoundExpiry(final RoundExpiry roundExpiry) {
     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/...ensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftRound.java b/...ensus/ibft/src/main/java/tech/pegasys/pantheon/consensus/ibft/statemachine/IbftRound.java
@@ -81,7 +81,7 @@ public ConsensusRoundIdentifier getRoundIdentifier() {
   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 void startRoundWith(
 
     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 @@ private Proposal createProposalAroundBlock(final Block block) {
   }
 
   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 void handleProposalMessage(final Proposal msg) {
   }
 
   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 @@ private void actionReceivedProposal(final Proposal msg) {
     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 @@ private void importBlockToChain() {
 
     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/...c/main/java/tech/pegasys/pantheon/consensus/ibft/validation/NewRoundMessageValidator.java b/...c/main/java/tech/pegasys/pantheon/consensus/ibft/validation/NewRoundMessageValidator.java
@@ -100,7 +100,7 @@ private boolean validateProposalMessageMatchesLatestPrepareCertificate(
         findLatestPreparedCertificate(roundChangePayloads);
 
     if (!latestPreparedCertificate.isPresent()) {
-      LOG.info(
+      LOG.trace(
           "No round change messages have a preparedCertificate, any valid block may be proposed.");
       return true;
     }