Fix "Backward sync stuck in a loop" #6749 (#6756)

* minimal change to fix BWS

Signed-off-by: stefan.pingel@consensys.net <stefan.pingel@consensys.net>
Signed-off-by: Simon Dudley <simon.dudley@consensys.net>
Co-authored-by: Simon Dudley <simon.dudley@consensys.net>

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/backwardsync/BackwardSyncAlgorithm.java

@@ -22,11 +22,13 @@ import org.hyperledger.besu.datatypes.Hash;
 import org.hyperledger.besu.ethereum.chain.MutableBlockchain;
 import org.hyperledger.besu.ethereum.core.Block;
 import org.hyperledger.besu.ethereum.core.BlockHeader;
+import org.hyperledger.besu.ethereum.eth.manager.exceptions.MaxRetriesReachedException;
 import org.hyperledger.besu.ethereum.eth.manager.task.WaitForPeersTask;
 import org.hyperledger.besu.plugin.services.BesuEvents;
 
 import java.util.Optional;
 import java.util.concurrent.CompletableFuture;
+import java.util.concurrent.CompletionException;
 import java.util.concurrent.CountDownLatch;
 import java.util.concurrent.ExecutionException;
 import java.util.concurrent.TimeUnit;
@@ -61,16 +63,40 @@ public class BackwardSyncAlgorithm implements BesuEvents.InitialSyncCompletionLi
   public CompletableFuture<Void> pickNextStep() {
     final Optional<Hash> firstHash = context.getBackwardChain().getFirstHashToAppend();
     if (firstHash.isPresent()) {
-      return executeSyncStep(firstHash.get())
-          .thenAccept(
-              result -> {
-                LOG.atDebug()
-                    .setMessage("Backward sync target block is {}")
-                    .addArgument(result::toLogString)
-                    .log();
-                context.getBackwardChain().removeFromHashToAppend(firstHash.get());
-                context.getStatus().updateTargetHeight(result.getHeader().getNumber());
+      final CompletableFuture<Void> syncStep = new CompletableFuture<>();
+      executeSyncStep(firstHash.get())
+          .whenComplete(
+              (result, error) -> {
+                if (error != null) {
+                  if (error instanceof CompletionException
+                      && error.getCause() instanceof MaxRetriesReachedException) {
+                    context.getBackwardChain().removeFromHashToAppend(firstHash.get());
+                    LOG.atWarn()
+                        .setMessage(
+                            "Unable to retrieve block {} from any peer, with {} peers available. Could be a reorged block. Waiting for the next block from the consensus client to try again.")
+                        .addArgument(firstHash.get())
+                        .addArgument(context.getEthContext().getEthPeers().peerCount())
+                        .addArgument(context.getBackwardChain().getFirstHashToAppend())
+                        .log();
+                    LOG.atDebug()
+                        .setMessage("Removing hash {} from hashesToAppend")
+                        .addArgument(firstHash.get())
+                        .log();
+                    syncStep.complete(null);
+                  } else {
+                    syncStep.completeExceptionally(error);
+                  }
+                } else {
+                  LOG.atDebug()
+                      .setMessage("Backward sync target block is {}")
+                      .addArgument(result::toLogString)
+                      .log();
+                  context.getBackwardChain().removeFromHashToAppend(firstHash.get());
+                  context.getStatus().updateTargetHeight(result.getHeader().getNumber());
+                  syncStep.complete(null);
+                }
               });
+      return syncStep;
     }
     if (!context.isReady()) {
       return waitForReady();

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/backwardsync/BackwardSyncContext.java

@@ -408,7 +408,7 @@ public class BackwardSyncContext {
     final float completedPercentage = 100.0f * imported / estimatedTotal;
 
     if (completedPercentage < 100.0f) {
-      if (currentStatus.progressLogDue()) {
+      if (currentStatus.progressLogDue() && targetHeight > 0) {
         LOG.info(
             String.format(
                 "Backward sync phase 2 of 2, %.2f%% completed, imported %d blocks of at least %d (current head %d, target head %d). Peers: %d",

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/backwardsync/BackwardSyncStep.java

@@ -61,7 +61,8 @@ public class BackwardSyncStep {
         context.getProtocolContext().getBlockchain().getBlockHeader(hash);
     if (blockHeader.isPresent()) {
       LOG.debug(
-          "Hash {} already present in local blockchain no need to request headers to peers", hash);
+          "Hash {} already present in local blockchain no need to request headers from peers",
+          hash);
       return CompletableFuture.completedFuture(List.of(blockHeader.get()));
     }
 

ethereum/eth/src/test/java/org/hyperledger/besu/ethereum/eth/sync/backwardsync/BackwardSyncContextTest.java

@@ -83,7 +83,7 @@ public class BackwardSyncContextTest {
   public static final int REMOTE_HEIGHT = 50;
   public static final int UNCLE_HEIGHT = 25 - 3;
 
-  public static final int NUM_OF_RETRIES = 100;
+  public static final int NUM_OF_RETRIES = 1;
   public static final int TEST_MAX_BAD_CHAIN_EVENT_ENTRIES = 25;
 
   private BackwardSyncContext context;
@@ -186,13 +186,16 @@ public class BackwardSyncContextTest {
   }
 
   private Block createUncle(final int i, final Hash parentHash) {
+    return createBlock(i, parentHash);
+  }
+
+  private Block createBlock(final int i, final Hash parentHash) {
     final BlockDataGenerator.BlockOptions options =
         new BlockDataGenerator.BlockOptions()
             .setBlockNumber(i)
             .setParentHash(parentHash)
             .transactionTypes(TransactionType.ACCESS_LIST);
-    final Block block = blockDataGenerator.block(options);
-    return block;
+    return blockDataGenerator.block(options);
   }
 
   public static BackwardChain inMemoryBackwardChain() {
@@ -438,4 +441,53 @@ public class BackwardSyncContextTest {
       }
     }
   }
+
+  @SuppressWarnings("BannedMethod")
+  @Test
+  public void whenBlockNotFoundInPeers_shouldRemoveBlockFromQueueAndProgressInNextSession() {
+    // This scenario can happen due to a reorg
+    // Expectation we progress beyond the reorg block upon receiving the next FCU
+
+    // choose an intermediate remote block to create a reorg block from
+    int reorgBlockHeight = REMOTE_HEIGHT - 1; // 49
+    final Hash reorgBlockParentHash = getBlockByNumber(reorgBlockHeight - 1).getHash();
+    final Block reorgBlock = createBlock(reorgBlockHeight, reorgBlockParentHash);
+
+    // represents first FCU with a block that will become reorged away
+    final CompletableFuture<Void> fcuBeforeReorg = context.syncBackwardsUntil(reorgBlock.getHash());
+    respondUntilFutureIsDone(fcuBeforeReorg);
+    assertThat(localBlockchain.getChainHeadBlockNumber()).isLessThan(reorgBlockHeight);
+
+    // represents subsequent FCU with successfully reorged version of the same block
+    final CompletableFuture<Void> fcuAfterReorg =
+        context.syncBackwardsUntil(getBlockByNumber(reorgBlockHeight).getHash());
+    respondUntilFutureIsDone(fcuAfterReorg);
+    assertThat(localBlockchain.getChainHeadBlock())
+        .isEqualTo(remoteBlockchain.getBlockByNumber(reorgBlockHeight).orElseThrow());
+  }
+
+  @SuppressWarnings("BannedMethod")
+  @Test
+  public void
+      whenBlockNotFoundInPeers_shouldRemoveBlockFromQueueAndProgressWithQueueInSameSession() {
+    // This scenario can happen due to a reorg
+    // Expectation we progress beyond the reorg block due to FCU we received during the same session
+
+    // choose an intermediate remote block to create a reorg block from
+    int reorgBlockHeight = REMOTE_HEIGHT - 1; // 49
+    final Hash reorgBlockParentHash = getBlockByNumber(reorgBlockHeight - 1).getHash();
+    final Block reorgBlock = createBlock(reorgBlockHeight, reorgBlockParentHash);
+
+    // represents first FCU with a block that will become reorged away
+    final CompletableFuture<Void> fcuBeforeReorg = context.syncBackwardsUntil(reorgBlock.getHash());
+    // represents subsequent FCU with successfully reorged version of the same block
+    // received during the first FCU's BWS session
+    final CompletableFuture<Void> fcuAfterReorg =
+        context.syncBackwardsUntil(getBlockByNumber(reorgBlockHeight).getHash());
+
+    respondUntilFutureIsDone(fcuBeforeReorg);
+    respondUntilFutureIsDone(fcuAfterReorg);
+    assertThat(localBlockchain.getChainHeadBlock())
+        .isEqualTo(remoteBlockchain.getBlockByNumber(reorgBlockHeight).orElseThrow());
+  }
 }

gradle.properties

@@ -13,4 +13,3 @@ org.gradle.jvmargs=-Xmx4g \
 --add-opens jdk.compiler/com.sun.tools.javac.comp=ALL-UNNAMED \
 --add-opens jdk.compiler/com.sun.tools.javac.parser=ALL-UNNAMED
 # Could be moved to sonar properties after https://sonarsource.atlassian.net/browse/SONARGRADL-134
-systemProp.sonar.gradle.skipCompile=true