Snap sync downloader logging (hyperledger#6403)

* non-static logger for inheriting classes

* refactor to some classes and log messages to make snap sync logs make sense

* rename SnapsyncMetricsManage

* rename FastImportBlocksStep -> ImportBlocksStep

Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>

---------

Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/SyncTargetManager.java → ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/AbstractSyncTargetManager.java

@@ -32,17 +32,17 @@
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
-public abstract class SyncTargetManager {
+public abstract class AbstractSyncTargetManager {
 
-  private static final Logger LOG = LoggerFactory.getLogger(SyncTargetManager.class);
+  private static final Logger LOG = LoggerFactory.getLogger(AbstractSyncTargetManager.class);
 
   private final SynchronizerConfiguration config;
   private final ProtocolSchedule protocolSchedule;
   private final ProtocolContext protocolContext;
   private final EthContext ethContext;
   private final MetricsSystem metricsSystem;
 
-  protected SyncTargetManager(
+  protected AbstractSyncTargetManager(
       final SynchronizerConfiguration config,
       final ProtocolSchedule protocolSchedule,
       final ProtocolContext protocolContext,

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/PipelineChainDownloader.java

@@ -43,7 +43,7 @@ public class PipelineChainDownloader implements ChainDownloader {
   private static final Logger LOG = LoggerFactory.getLogger(PipelineChainDownloader.class);
   static final Duration PAUSE_AFTER_ERROR_DURATION = Duration.ofSeconds(2);
   private final SyncState syncState;
-  private final SyncTargetManager syncTargetManager;
+  private final AbstractSyncTargetManager syncTargetManager;
   private final DownloadPipelineFactory downloadPipelineFactory;
   private final EthScheduler scheduler;
 
@@ -55,7 +55,7 @@ public class PipelineChainDownloader implements ChainDownloader {
 
   public PipelineChainDownloader(
       final SyncState syncState,
-      final SyncTargetManager syncTargetManager,
+      final AbstractSyncTargetManager syncTargetManager,
       final DownloadPipelineFactory downloadPipelineFactory,
       final EthScheduler scheduler,
       final MetricsSystem metricsSystem) {

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/checkpointsync/CheckpointSyncChainDownloader.java

@@ -20,7 +20,7 @@
 import org.hyperledger.besu.ethereum.eth.sync.SynchronizerConfiguration;
 import org.hyperledger.besu.ethereum.eth.sync.fastsync.FastSyncChainDownloader;
 import org.hyperledger.besu.ethereum.eth.sync.fastsync.FastSyncState;
-import org.hyperledger.besu.ethereum.eth.sync.fastsync.FastSyncTargetManager;
+import org.hyperledger.besu.ethereum.eth.sync.fastsync.SyncTargetManager;
 import org.hyperledger.besu.ethereum.eth.sync.state.SyncState;
 import org.hyperledger.besu.ethereum.mainnet.ProtocolSchedule;
 import org.hyperledger.besu.ethereum.worldstate.WorldStateStorage;
@@ -38,8 +38,8 @@ public static ChainDownloader create(
       final MetricsSystem metricsSystem,
       final FastSyncState fastSyncState) {
 
-    final FastSyncTargetManager syncTargetManager =
-        new FastSyncTargetManager(
+    final SyncTargetManager syncTargetManager =
+        new SyncTargetManager(
             config,
             worldStateStorage,
             protocolSchedule,

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/FastSyncChainDownloader.java

@@ -38,8 +38,8 @@ public static ChainDownloader create(
       final MetricsSystem metricsSystem,
       final FastSyncState fastSyncState) {
 
-    final FastSyncTargetManager syncTargetManager =
-        new FastSyncTargetManager(
+    final SyncTargetManager syncTargetManager =
+        new SyncTargetManager(
             config,
             worldStateStorage,
             protocolSchedule,

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/FastSyncDownloadPipelineFactory.java

@@ -136,8 +136,8 @@ public Pipeline<SyncTargetRange> createDownloadPipelineForSyncTarget(final SyncT
         new DownloadBodiesStep(protocolSchedule, ethContext, metricsSystem);
     final DownloadReceiptsStep downloadReceiptsStep =
         new DownloadReceiptsStep(ethContext, metricsSystem);
-    final FastImportBlocksStep importBlockStep =
-        new FastImportBlocksStep(
+    final ImportBlocksStep importBlockStep =
+        new ImportBlocksStep(
             protocolSchedule,
             protocolContext,
             attachedValidationPolicy,

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/FastSyncDownloader.java

@@ -44,7 +44,9 @@ public class FastSyncDownloader<REQUEST> {
 
   private static final Duration FAST_SYNC_RETRY_DELAY = Duration.ofSeconds(5);
 
-  private static final Logger LOG = LoggerFactory.getLogger(FastSyncDownloader.class);
+  @SuppressWarnings("PrivateStaticFinalLoggers")
+  protected final Logger LOG = LoggerFactory.getLogger(getClass());
+
   private final WorldStateStorage worldStateStorage;
   private final WorldStateDownloader worldStateDownloader;
   private final TaskCollection<REQUEST> taskCollection;
@@ -75,7 +77,7 @@ public FastSyncDownloader(
 
   public CompletableFuture<FastSyncState> start() {
     if (!running.compareAndSet(false, true)) {
-      throw new IllegalStateException("FastSyncDownloader already running");
+      throw new IllegalStateException("SyncDownloader already running");
     }
     LOG.info("Starting sync");
     return start(initialFastSyncState);
@@ -107,7 +109,7 @@ public CompletableFuture<FastSyncState> findPivotBlock(
   protected CompletableFuture<FastSyncState> handleFailure(final Throwable error) {
     trailingPeerRequirements = Optional.empty();
     Throwable rootCause = ExceptionUtils.rootCause(error);
-    if (rootCause instanceof FastSyncException) {
+    if (rootCause instanceof SyncException) {
       return CompletableFuture.failedFuture(error);
     } else if (rootCause instanceof StalledDownloadException) {
       LOG.debug("Stalled sync re-pivoting to newer block.");
@@ -120,7 +122,7 @@ protected CompletableFuture<FastSyncState> handleFailure(final Throwable error)
       return start(FastSyncState.EMPTY_SYNC_STATE);
     } else {
       LOG.error(
-          "Encountered an unexpected error during fast sync. Restarting sync in "
+          "Encountered an unexpected error during sync. Restarting sync in "
               + FAST_SYNC_RETRY_DELAY.getSeconds()
               + " seconds.",
           error);
@@ -132,7 +134,7 @@ protected CompletableFuture<FastSyncState> handleFailure(final Throwable error)
   public void stop() {
     synchronized (this) {
       if (running.compareAndSet(true, false)) {
-        LOG.info("Stopping fast sync");
+        LOG.info("Stopping sync");
         // Cancelling the world state download will also cause the chain download to be cancelled.
         worldStateDownloader.cancel();
       }
@@ -149,7 +151,7 @@ public void deleteFastSyncState() {
         MoreFiles.deleteRecursively(fastSyncDataDirectory, RecursiveDeleteOption.ALLOW_INSECURE);
       }
     } catch (final IOException e) {
-      LOG.error("Unable to clean up fast sync state", e);
+      LOG.error("Unable to clean up sync state", e);
     }
   }
 

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/FastImportBlocksStep.java → ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/ImportBlocksStep.java

@@ -33,8 +33,8 @@
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
-public class FastImportBlocksStep implements Consumer<List<BlockWithReceipts>> {
-  private static final Logger LOG = LoggerFactory.getLogger(FastImportBlocksStep.class);
+public class ImportBlocksStep implements Consumer<List<BlockWithReceipts>> {
+  private static final Logger LOG = LoggerFactory.getLogger(ImportBlocksStep.class);
   private static final long PRINT_DELAY = TimeUnit.SECONDS.toMillis(30L);
 
   private final ProtocolSchedule protocolSchedule;
@@ -46,7 +46,7 @@ public class FastImportBlocksStep implements Consumer<List<BlockWithReceipts>> {
   private OptionalLong logStartBlock = OptionalLong.empty();
   private final BlockHeader pivotHeader;
 
-  public FastImportBlocksStep(
+  public ImportBlocksStep(
       final ProtocolSchedule protocolSchedule,
       final ProtocolContext protocolContext,
       final ValidationPolicy headerValidationPolicy,

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/PivotBlockRetriever.java

@@ -156,8 +156,7 @@ private void handleContestedPivotBlock(final long contestedBlockNumber) {
           || pivotBlockNumber.get() <= BlockHeader.GENESIS_BLOCK_NUMBER) {
         LOG.info("Max retries reached, cancel pivot block download.");
         // Pivot block selection has failed
-        result.completeExceptionally(
-            new FastSyncException(FastSyncError.PIVOT_BLOCK_HEADER_MISMATCH));
+        result.completeExceptionally(new SyncException(SyncError.PIVOT_BLOCK_HEADER_MISMATCH));
         return;
       } else {
         LOG.info("Move pivot block back to {} and retry.", pivotBlockNumber);

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/FastSyncError.java → ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/SyncError.java

@@ -14,7 +14,7 @@
  */
 package org.hyperledger.besu.ethereum.eth.sync.fastsync;
 
-public enum FastSyncError {
+public enum SyncError {
   NO_PEERS_AVAILABLE,
   PIVOT_BLOCK_HEADER_MISMATCH,
   UNEXPECTED_ERROR

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/FastSyncException.java → ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/SyncException.java

@@ -14,21 +14,21 @@
  */
 package org.hyperledger.besu.ethereum.eth.sync.fastsync;
 
-public class FastSyncException extends RuntimeException {
+public class SyncException extends RuntimeException {
 
-  private final FastSyncError error;
+  private final SyncError error;
 
-  public FastSyncException(final FastSyncError error) {
-    super("Fast sync failed: " + error);
+  public SyncException(final SyncError error) {
+    super("Sync failed: " + error);
     this.error = error;
   }
 
-  public FastSyncError getError() {
+  public SyncError getError() {
     return error;
   }
 
-  public FastSyncException(final Throwable error) {
+  public SyncException(final Throwable error) {
     super(error);
-    this.error = FastSyncError.UNEXPECTED_ERROR;
+    this.error = SyncError.UNEXPECTED_ERROR;
   }
 }

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/FastSyncTargetManager.java → ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/SyncTargetManager.java

@@ -23,7 +23,7 @@
 import org.hyperledger.besu.ethereum.eth.manager.EthContext;
 import org.hyperledger.besu.ethereum.eth.manager.EthPeer;
 import org.hyperledger.besu.ethereum.eth.manager.EthPeers;
-import org.hyperledger.besu.ethereum.eth.sync.SyncTargetManager;
+import org.hyperledger.besu.ethereum.eth.sync.AbstractSyncTargetManager;
 import org.hyperledger.besu.ethereum.eth.sync.SynchronizerConfiguration;
 import org.hyperledger.besu.ethereum.eth.sync.tasks.RetryingGetHeaderFromPeerByNumberTask;
 import org.hyperledger.besu.ethereum.mainnet.ProtocolSchedule;
@@ -39,8 +39,8 @@
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
-public class FastSyncTargetManager extends SyncTargetManager {
-  private static final Logger LOG = LoggerFactory.getLogger(FastSyncTargetManager.class);
+public class SyncTargetManager extends AbstractSyncTargetManager {
+  private static final Logger LOG = LoggerFactory.getLogger(SyncTargetManager.class);
 
   private final WorldStateStorage worldStateStorage;
   private final ProtocolSchedule protocolSchedule;
@@ -53,7 +53,7 @@ public class FastSyncTargetManager extends SyncTargetManager {
   private final int logDebugRepeatDelay = 15;
   private final int logInfoRepeatDelay = 120;
 
-  public FastSyncTargetManager(
+  public SyncTargetManager(
       final SynchronizerConfiguration config,
       final WorldStateStorage worldStateStorage,
       final ProtocolSchedule protocolSchedule,

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fullsync/FullSyncTargetManager.java

@@ -21,7 +21,7 @@
 import org.hyperledger.besu.ethereum.core.BlockHeader;
 import org.hyperledger.besu.ethereum.eth.manager.EthContext;
 import org.hyperledger.besu.ethereum.eth.manager.EthPeer;
-import org.hyperledger.besu.ethereum.eth.sync.SyncTargetManager;
+import org.hyperledger.besu.ethereum.eth.sync.AbstractSyncTargetManager;
 import org.hyperledger.besu.ethereum.eth.sync.SynchronizerConfiguration;
 import org.hyperledger.besu.ethereum.eth.sync.state.SyncTarget;
 import org.hyperledger.besu.ethereum.mainnet.ProtocolSchedule;
@@ -34,7 +34,7 @@
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
-class FullSyncTargetManager extends SyncTargetManager {
+class FullSyncTargetManager extends AbstractSyncTargetManager {
 
   private static final Logger LOG = LoggerFactory.getLogger(FullSyncTargetManager.class);
   private final ProtocolContext protocolContext;

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/snapsync/SnapSyncDownloader.java

@@ -26,13 +26,8 @@
 import java.nio.file.Path;
 import java.util.concurrent.CompletableFuture;
 
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
-
 public class SnapSyncDownloader extends FastSyncDownloader<SnapDataRequest> {
 
-  private static final Logger LOG = LoggerFactory.getLogger(SnapSyncDownloader.class);
-
   public SnapSyncDownloader(
       final FastSyncActions fastSyncActions,
       final WorldStateStorage worldStateStorage,

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/snapsync/SnapsyncMetricsManager.java → ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/snapsync/SnapSyncMetricsManager.java

@@ -15,7 +15,7 @@
 package org.hyperledger.besu.ethereum.eth.sync.snapsync;
 
 import static io.netty.util.internal.ObjectUtil.checkNonEmpty;
-import static org.hyperledger.besu.ethereum.eth.sync.snapsync.SnapsyncMetricsManager.Step.HEAL_TRIE;
+import static org.hyperledger.besu.ethereum.eth.sync.snapsync.SnapSyncMetricsManager.Step.HEAL_TRIE;
 
 import org.hyperledger.besu.ethereum.eth.manager.EthContext;
 import org.hyperledger.besu.metrics.BesuMetricCategory;
@@ -37,9 +37,9 @@
 import org.slf4j.LoggerFactory;
 
 /** Manages the metrics related to the SnapSync process. */
-public class SnapsyncMetricsManager {
+public class SnapSyncMetricsManager {
 
-  private static final Logger LOG = LoggerFactory.getLogger(SnapsyncMetricsManager.class);
+  private static final Logger LOG = LoggerFactory.getLogger(SnapSyncMetricsManager.class);
   private static final long PRINT_DELAY = TimeUnit.MINUTES.toMillis(1);
 
   private final MetricsSystem metricsSystem;
@@ -79,7 +79,7 @@ public class SnapsyncMetricsManager {
 
   private long lastNotifyTimestamp;
 
-  public SnapsyncMetricsManager(final MetricsSystem metricsSystem, final EthContext ethContext) {
+  public SnapSyncMetricsManager(final MetricsSystem metricsSystem, final EthContext ethContext) {
     this.metricsSystem = metricsSystem;
     this.ethContext = ethContext;
     percentageProgress = new AtomicReference<>(new BigDecimal(0));

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/snapsync/SnapWorldDownloadState.java

@@ -83,7 +83,7 @@ public class SnapWorldDownloadState extends WorldDownloadState<SnapDataRequest>
   private OptionalLong blockObserverId;
 
   // metrics around the snapsync
-  private final SnapsyncMetricsManager metricsManager;
+  private final SnapSyncMetricsManager metricsManager;
 
   public SnapWorldDownloadState(
       final WorldStateStorage worldStateStorage,
@@ -93,7 +93,7 @@ public SnapWorldDownloadState(
       final InMemoryTasksPriorityQueues<SnapDataRequest> pendingRequests,
       final int maxRequestsWithoutProgress,
       final long minMillisBeforeStalling,
-      final SnapsyncMetricsManager metricsManager,
+      final SnapSyncMetricsManager metricsManager,
       final Clock clock) {
     super(
         worldStateStorage,
@@ -400,7 +400,7 @@ public synchronized Task<SnapDataRequest> dequeueStorageFlatDatabaseHealingReque
         __ -> {});
   }
 
-  public SnapsyncMetricsManager getMetricsManager() {
+  public SnapSyncMetricsManager getMetricsManager() {
     return metricsManager;
   }
 

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/snapsync/SnapWorldStateDownloader.java

@@ -14,7 +14,7 @@
  */
 package org.hyperledger.besu.ethereum.eth.sync.snapsync;
 
-import static org.hyperledger.besu.ethereum.eth.sync.snapsync.SnapsyncMetricsManager.Step.DOWNLOAD;
+import static org.hyperledger.besu.ethereum.eth.sync.snapsync.SnapSyncMetricsManager.Step.DOWNLOAD;
 import static org.hyperledger.besu.ethereum.eth.sync.snapsync.request.SnapDataRequest.createAccountRangeDataRequest;
 
 import org.hyperledger.besu.datatypes.Hash;
@@ -133,8 +133,8 @@ public CompletableFuture<Void> run(
           stateRoot,
           snapTaskCollection.size());
 
-      final SnapsyncMetricsManager snapsyncMetricsManager =
-          new SnapsyncMetricsManager(metricsSystem, ethContext);
+      final SnapSyncMetricsManager snapsyncMetricsManager =
+          new SnapSyncMetricsManager(metricsSystem, ethContext);
 
       final SnapWorldDownloadState newDownloadState =
           new SnapWorldDownloadState(

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/snapsync/request/AccountRangeDataRequest.java

@@ -18,7 +18,7 @@
 import static org.hyperledger.besu.ethereum.eth.sync.snapsync.RangeManager.MIN_RANGE;
 import static org.hyperledger.besu.ethereum.eth.sync.snapsync.RangeManager.findNewBeginElementInRange;
 import static org.hyperledger.besu.ethereum.eth.sync.snapsync.RequestType.ACCOUNT_RANGE;
-import static org.hyperledger.besu.ethereum.eth.sync.snapsync.SnapsyncMetricsManager.Step.DOWNLOAD;
+import static org.hyperledger.besu.ethereum.eth.sync.snapsync.SnapSyncMetricsManager.Step.DOWNLOAD;
 import static org.hyperledger.besu.ethereum.eth.sync.snapsync.StackTrie.FlatDatabaseUpdater.noop;
 
 import org.hyperledger.besu.datatypes.Hash;

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/snapsync/request/heal/AccountFlatDatabaseHealingRangeRequest.java

@@ -16,7 +16,7 @@
 
 import static org.hyperledger.besu.ethereum.eth.sync.snapsync.RangeManager.MAX_RANGE;
 import static org.hyperledger.besu.ethereum.eth.sync.snapsync.RangeManager.MIN_RANGE;
-import static org.hyperledger.besu.ethereum.eth.sync.snapsync.SnapsyncMetricsManager.Step.HEAL_FLAT;
+import static org.hyperledger.besu.ethereum.eth.sync.snapsync.SnapSyncMetricsManager.Step.HEAL_FLAT;
 
 import org.hyperledger.besu.datatypes.Hash;
 import org.hyperledger.besu.ethereum.eth.sync.snapsync.RangeManager;

ethereum/eth/src/test/java/org/hyperledger/besu/ethereum/eth/sync/PipelineChainDownloaderTest.java

@@ -52,7 +52,7 @@
 @ExtendWith(MockitoExtension.class)
 public class PipelineChainDownloaderTest {
 
-  @Mock private SyncTargetManager syncTargetManager;
+  @Mock private AbstractSyncTargetManager syncTargetManager;
   @Mock private DownloadPipelineFactory downloadPipelineFactory;
   @Mock private EthScheduler scheduler;
   @Mock private Pipeline<?> downloadPipeline;

ethereum/eth/src/test/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/FastImportBlocksPercentageCalculationTest.java

@@ -22,11 +22,11 @@ public class FastImportBlocksPercentageCalculationTest {
 
   @Test
   public void blocksPercent_calculations() {
-    assertThat(FastImportBlocksStep.getBlocksPercent(1, 1)).isEqualByComparingTo(100l);
-    assertThat(FastImportBlocksStep.getBlocksPercent(1, 100)).isEqualByComparingTo(1l);
-    assertThat(FastImportBlocksStep.getBlocksPercent(0, 100)).isEqualByComparingTo(0l);
-    assertThat(FastImportBlocksStep.getBlocksPercent(99, 0)).isEqualByComparingTo(0l);
-    assertThat(FastImportBlocksStep.getBlocksPercent(1, 1000)).isEqualByComparingTo(0l);
-    assertThat(FastImportBlocksStep.getBlocksPercent(1, 10000)).isEqualByComparingTo(0l);
+    assertThat(ImportBlocksStep.getBlocksPercent(1, 1)).isEqualByComparingTo(100l);
+    assertThat(ImportBlocksStep.getBlocksPercent(1, 100)).isEqualByComparingTo(1l);
+    assertThat(ImportBlocksStep.getBlocksPercent(0, 100)).isEqualByComparingTo(0l);
+    assertThat(ImportBlocksStep.getBlocksPercent(99, 0)).isEqualByComparingTo(0l);
+    assertThat(ImportBlocksStep.getBlocksPercent(1, 1000)).isEqualByComparingTo(0l);
+    assertThat(ImportBlocksStep.getBlocksPercent(1, 10000)).isEqualByComparingTo(0l);
   }
 }