Move block header errors from trace/debug to info (#1568)

CHANGELOG.md

@@ -4,11 +4,11 @@
 
 ### Additions and Improvements
 * Added `memory` as an option to `--key-value-storage`.  This ephemeral storage is intended for sync testing and debugging.  [\#1617](https://github.com/hyperledger/besu/pull/1617)
-* Fixed gasPrice parameter not always respected when passed to `eth_estimateGas` endpoint [#1636](https://github.com/hyperledger/besu/pull/1636)
-* Enabled eth65 by default [#1682](https://github.com/hyperledger/besu/pull/1682)
+* Fixed gasPrice parameter not always respected when passed to `eth_estimateGas` endpoint [\#1636](https://github.com/hyperledger/besu/pull/1636)
+* Enabled eth65 by default [\#1682](https://github.com/hyperledger/besu/pull/1682)
 
 ### Bug Fixes
-
+* Block Validation Errors should be at least INFO level not DEBUG or TRACE.  Bug [\#1568](https://github.com/hyperledger/besu/pull/1568) PR [\#1706](https://github.com/hyperledger/besu/pull/1706)
 
 #### Previously identified known issues
 

consensus/clique/src/main/java/org/hyperledger/besu/consensus/clique/headervalidationrules/CliqueDifficultyValidationRule.java

@@ -23,8 +23,13 @@
 
 import java.math.BigInteger;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+
 public class CliqueDifficultyValidationRule implements AttachedBlockHeaderValidationRule {
 
+  private static final Logger LOG = LogManager.getLogger();
+
   @Override
   public boolean validate(
       final BlockHeader header, final BlockHeader parent, final ProtocolContext protocolContext) {
@@ -36,7 +41,15 @@ public boolean validate(
 
     final BigInteger actualDifficulty = header.getDifficulty().toBigInteger();
 
-    return expectedDifficulty.equals(actualDifficulty);
+    if (!expectedDifficulty.equals(actualDifficulty)) {
+      LOG.info(
+          "Invalid block header: difficulty {} does not equal expected difficulty {}",
+          actualDifficulty,
+          expectedDifficulty);
+      return false;
+    }
+
+    return true;
   }
 
   @Override

consensus/clique/src/main/java/org/hyperledger/besu/consensus/clique/headervalidationrules/CliqueExtraDataValidationRule.java

@@ -66,10 +66,12 @@ public boolean validate(
       return extraDataIsValid(storedValidators, header);
 
     } catch (final RLPException ex) {
-      LOG.trace("ExtraData field was unable to be deserialised into an Clique Struct.", ex);
+      LOG.info(
+          "Invalid block header: ExtraData field was unable to be deserialised into an Clique Struct.",
+          ex);
       return false;
     } catch (final IllegalArgumentException ex) {
-      LOG.trace("Failed to verify extra data", ex);
+      LOG.info("Invalid block header: Failed to verify extra data", ex);
       return false;
     }
   }
@@ -81,21 +83,21 @@ private boolean extraDataIsValid(
     final Address proposer = cliqueExtraData.getProposerAddress();
 
     if (!expectedValidators.contains(proposer)) {
-      LOG.trace("Proposer sealing block is not a member of the signers.");
+      LOG.info("Invalid block header: Proposer sealing block is not a member of the signers.");
       return false;
     }
 
     if (epochManager.isEpochBlock(header.getNumber())) {
       if (!Iterables.elementsEqual(cliqueExtraData.getValidators(), expectedValidators)) {
-        LOG.trace(
-            "Incorrect signers. Expected {} but got {}.",
+        LOG.info(
+            "Invalid block header: Incorrect signers. Expected {} but got {}.",
             expectedValidators,
             cliqueExtraData.getValidators());
         return false;
       }
     } else {
       if (!cliqueExtraData.getValidators().isEmpty()) {
-        LOG.trace("Signer list on non-epoch blocks must be empty.");
+        LOG.info("Invalid block header: Signer list on non-epoch blocks must be empty.");
         return false;
       }
     }

consensus/clique/src/main/java/org/hyperledger/besu/consensus/clique/headervalidationrules/CoinbaseHeaderValidationRule.java

@@ -19,8 +19,13 @@
 import org.hyperledger.besu.ethereum.core.BlockHeader;
 import org.hyperledger.besu.ethereum.mainnet.DetachedBlockHeaderValidationRule;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+
 public class CoinbaseHeaderValidationRule implements DetachedBlockHeaderValidationRule {
 
+  private static final Logger LOG = LogManager.getLogger();
+
   private final EpochManager epochManager;
 
   public CoinbaseHeaderValidationRule(final EpochManager epochManager) {
@@ -31,8 +36,12 @@ public CoinbaseHeaderValidationRule(final EpochManager epochManager) {
   // The coinbase field is used for voting nodes in/out of the validator group. However, no votes
   // are allowed to be cast on epoch blocks
   public boolean validate(final BlockHeader header, final BlockHeader parent) {
-    if (epochManager.isEpochBlock(header.getNumber())) {
-      return header.getCoinbase().equals(CliqueBlockInterface.NO_VOTE_SUBJECT);
+    if (epochManager.isEpochBlock(header.getNumber())
+        && !header.getCoinbase().equals(CliqueBlockInterface.NO_VOTE_SUBJECT)) {
+      LOG.info(
+          "Invalid block header: No clique in/out voting may occur on epoch blocks ({})",
+          header.getNumber());
+      return false;
     }
     return true;
   }

consensus/clique/src/main/java/org/hyperledger/besu/consensus/clique/headervalidationrules/SignerRateLimitValidationRule.java

@@ -20,14 +20,24 @@
 import org.hyperledger.besu.ethereum.core.BlockHeader;
 import org.hyperledger.besu.ethereum.mainnet.AttachedBlockHeaderValidationRule;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+
 public class SignerRateLimitValidationRule implements AttachedBlockHeaderValidationRule {
 
+  private static final Logger LOG = LogManager.getLogger();
+
   @Override
   public boolean validate(
       final BlockHeader header, final BlockHeader parent, final ProtocolContext protocolContext) {
     final Address blockSigner = CliqueHelpers.getProposerOfBlock(header);
 
-    return CliqueHelpers.addressIsAllowedToProduceNextBlock(blockSigner, protocolContext, parent);
+    if (!CliqueHelpers.addressIsAllowedToProduceNextBlock(blockSigner, protocolContext, parent)) {
+      LOG.info("Invalid block header: {} is not allowed to produce next block", blockSigner);
+      return false;
+    }
+
+    return true;
   }
 
   @Override

consensus/clique/src/main/java/org/hyperledger/besu/consensus/clique/headervalidationrules/VoteValidationRule.java

@@ -36,7 +36,7 @@ public class VoteValidationRule implements DetachedBlockHeaderValidationRule {
   public boolean validate(final BlockHeader header, final BlockHeader parent) {
     final long nonce = header.getNonce();
     if (!CliqueBlockInterface.isValidVoteValue(nonce)) {
-      LOG.trace("Nonce value ({}) is neither auth or drop.", nonce);
+      LOG.info("Invalid block header: Nonce value ({}) is neither auth or drop.", nonce);
       return false;
     }
     return true;

consensus/ibft/src/main/java/org/hyperledger/besu/consensus/ibft/headervalidationrules/IbftCoinbaseValidationRule.java

@@ -48,8 +48,8 @@ public boolean validate(
     final Collection<Address> storedValidators = validatorProvider.getValidators();
 
     if (!storedValidators.contains(proposer)) {
-      LOGGER.trace(
-          "Block proposer is not a member of the validators. proposer={}, validators={}",
+      LOGGER.info(
+          "Invalid block header: Block proposer is not a member of the validators. proposer={}, validators={}",
           proposer,
           storedValidators);
       return false;

consensus/ibft/src/main/java/org/hyperledger/besu/consensus/ibft/headervalidationrules/IbftCommitSealsValidationRule.java

@@ -58,7 +58,7 @@ public boolean validate(
     final List<Address> committersWithoutDuplicates = new ArrayList<>(new HashSet<>(committers));
 
     if (committers.size() != committersWithoutDuplicates.size()) {
-      LOGGER.trace("Duplicated seals found in header.");
+      LOGGER.info("Invalid block header: Duplicated seals found in header.");
       return false;
     }
 
@@ -70,16 +70,16 @@ private boolean validateCommitters(
 
     final int minimumSealsRequired = calculateRequiredValidatorQuorum(storedValidators.size());
     if (committers.size() < minimumSealsRequired) {
-      LOGGER.trace(
-          "Insufficient committers to seal block. (Required {}, received {})",
+      LOGGER.info(
+          "Invalid block header: Insufficient committers to seal block. (Required {}, received {})",
           minimumSealsRequired,
           committers.size());
       return false;
     }
 
     if (!storedValidators.containsAll(committers)) {
-      LOGGER.trace(
-          "Not all committers are in the locally maintained validator list. validators={} committers={}",
+      LOGGER.info(
+          "Invalid block header: Not all committers are in the locally maintained validator list. validators={} committers={}",
           storedValidators,
           committers);
       return false;

consensus/ibft/src/main/java/org/hyperledger/besu/consensus/ibft/headervalidationrules/IbftValidatorsValidationRule.java

@@ -54,27 +54,29 @@ public boolean validate(
           new TreeSet<>(ibftExtraData.getValidators());
 
       if (!Iterables.elementsEqual(ibftExtraData.getValidators(), sortedReportedValidators)) {
-        LOGGER.trace(
-            "Validators are not sorted in ascending order. Expected {} but got {}.",
+        LOGGER.info(
+            "Invalid block header: Validators are not sorted in ascending order. Expected {} but got {}.",
             sortedReportedValidators,
             ibftExtraData.getValidators());
         return false;
       }
 
       final Collection<Address> storedValidators = validatorProvider.getValidators();
       if (!Iterables.elementsEqual(ibftExtraData.getValidators(), storedValidators)) {
-        LOGGER.trace(
-            "Incorrect validators. Expected {} but got {}.",
+        LOGGER.info(
+            "Invalid block header: Incorrect validators. Expected {} but got {}.",
             storedValidators,
             ibftExtraData.getValidators());
         return false;
       }
 
     } catch (final RLPException ex) {
-      LOGGER.trace("ExtraData field was unable to be deserialised into an IBFT Struct.", ex);
+      LOGGER.info(
+          "Invalid block header: ExtraData field was unable to be deserialised into an IBFT Struct.",
+          ex);
       return false;
     } catch (final IllegalArgumentException ex) {
-      LOGGER.trace("Failed to verify extra data", ex);
+      LOGGER.info("Invalid block header: Failed to verify extra data", ex);
       return false;
     }
 

consensus/ibft/src/main/java/org/hyperledger/besu/consensus/ibft/headervalidationrules/IbftVanityDataValidationRule.java

@@ -32,7 +32,7 @@ public boolean validate(
     final IbftExtraData extraData = IbftExtraData.decode(header);
 
     if (extraData.getVanityData().size() != IbftExtraData.EXTRA_VANITY_LENGTH) {
-      LOG.trace("Ibft Extra Data does not contain 32 bytes of vanity data.");
+      LOG.info("Invalid block header: Ibft Extra Data does not contain 32 bytes of vanity data.");
       return false;
     }
     return true;

consensus/ibftlegacy/src/main/java/org/hyperledger/besu/consensus/ibftlegacy/headervalidationrules/IbftExtraDataValidationRule.java

@@ -65,7 +65,7 @@ public boolean validate(
       final Collection<Address> storedValidators = validatorProvider.getValidators();
 
       if (!storedValidators.contains(proposer)) {
-        LOG.trace("Proposer sealing block is not a member of the validators.");
+        LOG.info("Invalid block header: Proposer sealing block is not a member of the validators.");
         return false;
       }
 
@@ -81,29 +81,31 @@ public boolean validate(
           new TreeSet<>(ibftExtraData.getValidators());
 
       if (!Iterables.elementsEqual(ibftExtraData.getValidators(), sortedReportedValidators)) {
-        LOG.trace(
-            "Validators are not sorted in ascending order. Expected {} but got {}.",
+        LOG.info(
+            "Invalid block header: Validators are not sorted in ascending order. Expected {} but got {}.",
             sortedReportedValidators,
             ibftExtraData.getValidators());
         return false;
       }
 
       if (!Iterables.elementsEqual(ibftExtraData.getValidators(), storedValidators)) {
-        LOG.trace(
-            "Incorrect validators. Expected {} but got {}.",
+        LOG.info(
+            "Invalid block header: Incorrect validators. Expected {} but got {}.",
             storedValidators,
             ibftExtraData.getValidators());
         return false;
       }
 
     } catch (final RLPException ex) {
-      LOG.trace("ExtraData field was unable to be deserialised into an IBFT Struct.", ex);
+      LOG.info(
+          "Invalid block header: ExtraData field was unable to be deserialised into an IBFT Struct.",
+          ex);
       return false;
     } catch (final IllegalArgumentException ex) {
-      LOG.trace("Failed to verify extra data", ex);
+      LOG.info("Invalid block header: Failed to verify extra data", ex);
       return false;
     } catch (final RuntimeException ex) {
-      LOG.trace("Failed to find validators at parent");
+      LOG.info("Invalid block header: Failed to find validators at parent");
       return false;
     }
 
@@ -116,15 +118,16 @@ private boolean validateCommitters(
     final int minimumSealsRequired =
         IbftHelpers.calculateRequiredValidatorQuorum(storedValidators.size());
     if (committers.size() < minimumSealsRequired) {
-      LOG.trace(
-          "Insufficient committers to seal block. (Required {}, received {})",
+      LOG.info(
+          "Invalid block header: Insufficient committers to seal block. (Required {}, received {})",
           minimumSealsRequired,
           committers.size());
       return false;
     }
 
     if (!storedValidators.containsAll(committers)) {
-      LOG.trace("Not all committers are in the locally maintained validator list.");
+      LOG.info(
+          "Invalid block header: Not all committers are in the locally maintained validator list.");
       return false;
     }
 

consensus/ibftlegacy/src/main/java/org/hyperledger/besu/consensus/ibftlegacy/headervalidationrules/VoteValidationRule.java

@@ -36,7 +36,7 @@ public class VoteValidationRule implements DetachedBlockHeaderValidationRule {
   public boolean validate(final BlockHeader header, final BlockHeader parent) {
     final long nonce = header.getNonce();
     if (!IbftLegacyBlockInterface.isValidVoteValue(nonce)) {
-      LOG.trace("Nonce value ({}) is neither auth or drop.", nonce);
+      LOG.info("Invalid block header: Nonce value ({}) is neither auth or drop.", nonce);
       return false;
     }
     return true;

ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/MainnetBlockBodyValidator.java

@@ -121,7 +121,7 @@ public boolean validateBodyLight(
 
   private static boolean validateTransactionsRoot(final Bytes32 expected, final Bytes32 actual) {
     if (!expected.equals(actual)) {
-      LOG.warn(
+      LOG.info(
           "Invalid block: transaction root mismatch (expected={}, actual={})", expected, actual);
       return false;
     }

ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/headervalidationrules/AncestryValidationRule.java

@@ -30,16 +30,15 @@ public class AncestryValidationRule implements DetachedBlockHeaderValidationRule
   @Override
   public boolean validate(final BlockHeader header, final BlockHeader parent) {
     if (!header.getParentHash().equals(parent.getHash())) {
-      LOG.trace(
-          "Invalid parent block header.  Parent hash {} does not match "
-              + "supplied parent header {}.",
+      LOG.info(
+          "Invalid block header:  Parent hash {} does not match " + "supplied parent header {}.",
           header.getParentHash(),
           parent.getHash());
       return false;
     }
 
     if (header.getNumber() != (parent.getNumber() + 1)) {
-      LOG.trace(
+      LOG.info(
           "Invalid block header: number {} is not one more than parent number {}",
           header.getNumber(),
           parent.getNumber());

ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/headervalidationrules/CalculatedDifficultyValidationRule.java

@@ -41,7 +41,7 @@ public boolean validate(
         difficultyCalculator.nextDifficulty(header.getTimestamp(), parent, context);
 
     if (actualDifficulty.compareTo(expectedDifficulty) != 0) {
-      LOG.trace(
+      LOG.info(
           "Invalid block header: difficulty {} does not equal expected difficulty {}",
           actualDifficulty,
           expectedDifficulty);

ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/headervalidationrules/ConstantFieldValidationRule.java

@@ -40,8 +40,8 @@ public ConstantFieldValidationRule(
   public boolean validate(final BlockHeader header, final BlockHeader parent) {
     final T actualValue = accessor.apply(header);
     if (!actualValue.equals(expectedValue)) {
-      LOG.trace(
-          "{} failed validation. Actual != Expected ({} != {}).",
+      LOG.info(
+          "Invalid block header: Field {} failed validation. Actual != Expected ({} != {}).",
           fieldName,
           actualValue,
           expectedValue);

ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/headervalidationrules/EIP1559BlockHeaderGasPriceValidationRule.java

@@ -50,15 +50,15 @@ public boolean validate(final BlockHeader header, final BlockHeader parent) {
           eip1559.computeBaseFee(
               header.getNumber(), parentBaseFee, parent.getGasUsed(), targetGasUsed);
       if (baseFee != header.getBaseFee().orElseThrow()) {
-        LOG.trace(
+        LOG.info(
             "Invalid block header: basefee {} does not equal expected basefee {}",
             header.getBaseFee().orElseThrow(),
             baseFee);
         return false;
       }
       return baseFee == currentBaseFee && eip1559.isValidBaseFee(parentBaseFee, currentBaseFee);
     } catch (final EIP1559MissingBaseFeeFromBlockHeader e) {
-      LOG.trace(e.getMessage());
+      LOG.info("Invalid block header: " + e.getMessage());
       return false;
     }
   }

ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/headervalidationrules/ExtraDataMaxLengthValidationRule.java

@@ -41,7 +41,7 @@ public boolean validate(final BlockHeader header, final BlockHeader parent) {
 
   private boolean validateExtraData(final Bytes extraData) {
     if (extraData.size() > maxExtraDataBytes) {
-      LOG.trace(
+      LOG.info(
           "Invalid block header: extra data field length {} is greater {}",
           extraData.size(),
           maxExtraDataBytes);