diff --git a/ethereum/eth/src/main/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/CompleteTaskStep.java b/ethereum/eth/src/main/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/CompleteTaskStep.java index 78edf25b9d..f4171aaca7 100644 --- a/ethereum/eth/src/main/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/CompleteTaskStep.java +++ b/ethereum/eth/src/main/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/CompleteTaskStep.java @@ -17,23 +17,39 @@ import tech.pegasys.pantheon.ethereum.worldstate.WorldStateStorage; import tech.pegasys.pantheon.metrics.Counter; import tech.pegasys.pantheon.metrics.MetricsSystem; import tech.pegasys.pantheon.metrics.PantheonMetricCategory; +import tech.pegasys.pantheon.metrics.RunnableCounter; import tech.pegasys.pantheon.services.tasks.Task; -public class CompleteTaskStep { +import java.text.DecimalFormat; +import java.util.function.LongSupplier; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +public class CompleteTaskStep { + private static final Logger LOG = LogManager.getLogger(); + private static final int DISPLAY_PROGRESS_STEP = 100000; private final WorldStateStorage worldStateStorage; - private final Counter completedRequestsCounter; + private final RunnableCounter completedRequestsCounter; private final Counter retriedRequestsCounter; + private final LongSupplier worldStatePendingRequestsCurrentSupplier; + private final DecimalFormat doubleFormatter = new DecimalFormat("#.##"); + private double estimatedWorldStateCompletion; public CompleteTaskStep( - final WorldStateStorage worldStateStorage, final MetricsSystem metricsSystem) { + final WorldStateStorage worldStateStorage, + final MetricsSystem metricsSystem, + final LongSupplier worldStatePendingRequestsCurrentSupplier) { this.worldStateStorage = worldStateStorage; - + this.worldStatePendingRequestsCurrentSupplier = worldStatePendingRequestsCurrentSupplier; completedRequestsCounter = - metricsSystem.createCounter( - PantheonMetricCategory.SYNCHRONIZER, - "world_state_completed_requests_total", - "Total number of node data requests completed as part of fast sync world state download"); + new RunnableCounter( + metricsSystem.createCounter( + PantheonMetricCategory.SYNCHRONIZER, + "world_state_completed_requests_total", + "Total number of node data requests completed as part of fast sync world state download"), + this::displayWorldStateSyncProgress, + DISPLAY_PROGRESS_STEP); retriedRequestsCounter = metricsSystem.createCounter( PantheonMetricCategory.SYNCHRONIZER, @@ -59,6 +75,21 @@ public class CompleteTaskStep { } } + private void displayWorldStateSyncProgress() { + LOG.info( + "Downloaded {} world state nodes. At least {} nodes remaining. Estimated World State completion: {} %.", + completedRequestsCounter.get(), + worldStatePendingRequestsCurrentSupplier.getAsLong(), + doubleFormatter.format(computeWorldStateSyncProgress() * 100.0)); + } + + public double computeWorldStateSyncProgress() { + final double pendingRequests = worldStatePendingRequestsCurrentSupplier.getAsLong(); + final double completedRequests = completedRequestsCounter.get(); + estimatedWorldStateCompletion = completedRequests / (completedRequests + pendingRequests); + return this.estimatedWorldStateCompletion; + } + private void enqueueChildren( final Task task, final BlockHeader blockHeader, diff --git a/ethereum/eth/src/main/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/WorldStateDownloader.java b/ethereum/eth/src/main/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/WorldStateDownloader.java index c0f171962b..bfcb43b4f3 100644 --- a/ethereum/eth/src/main/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/WorldStateDownloader.java +++ b/ethereum/eth/src/main/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/WorldStateDownloader.java @@ -128,7 +128,8 @@ public class WorldStateDownloader { .loadLocalDataStep(new LoadLocalDataStep(worldStateStorage, metricsSystem)) .requestDataStep(new RequestDataStep(ethContext, metricsSystem)) .persistDataStep(new PersistDataStep(worldStateStorage)) - .completeTaskStep(new CompleteTaskStep(worldStateStorage, metricsSystem)) + .completeTaskStep( + new CompleteTaskStep(worldStateStorage, metricsSystem, taskCollection::size)) .downloadState(newDownloadState) .pivotBlockHeader(header) .metricsSystem(metricsSystem) diff --git a/ethereum/eth/src/test/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/CompleteTaskStepTest.java b/ethereum/eth/src/test/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/CompleteTaskStepTest.java index 0931730cdf..66a671be5a 100644 --- a/ethereum/eth/src/test/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/CompleteTaskStepTest.java +++ b/ethereum/eth/src/test/java/tech/pegasys/pantheon/ethereum/eth/sync/worldstate/CompleteTaskStepTest.java @@ -38,7 +38,7 @@ public class CompleteTaskStepTest { new BlockHeaderTestFixture().stateRoot(ROOT_HASH).buildHeader(); private final CompleteTaskStep completeTaskStep = - new CompleteTaskStep(worldStateStorage, new NoOpMetricsSystem()); + new CompleteTaskStep(worldStateStorage, new NoOpMetricsSystem(), () -> 3); @SuppressWarnings("unchecked") private final ArgumentCaptor> streamCaptor = @@ -59,14 +59,7 @@ public class CompleteTaskStepTest { @Test public void shouldEnqueueChildrenAndMarkCompleteWhenTaskHasData() { // Use an arbitrary but actually valid trie node to get children from. - final Hash hash = - Hash.fromHexString("0x601a7b0d0267209790cf4c4d9e0cab11b26c537e2ade006412f48b070010e847"); - final BytesValue data = - BytesValue.fromHexString( - "0xf85180808080a05ac6993e3fbca0bfbd30173396dd5c2412657fae0bad92e401d17b2aa9a3698f80808080a012f96a0812be538c302416dc6e8df19ce18f1cc7b06a3c7a16831d766c87a9b580808080808080"); - final StubTask task = new StubTask(NodeDataRequest.createAccountDataRequest(hash)); - task.getData().setData(data); - + final StubTask task = validTask(); completeTaskStep.markAsCompleteOrFailed(blockHeader, downloadState, task); assertThat(task.isCompleted()).isTrue(); @@ -79,4 +72,22 @@ public class CompleteTaskStepTest { verify(downloadState).checkCompletion(worldStateStorage, blockHeader); } + + @Test + public void shouldComputeWorldStateProgress() { + completeTaskStep.markAsCompleteOrFailed(blockHeader, downloadState, validTask()); + // One task has been completed and there are 2 pending requests, progress should be 1/4 (25%) + assertThat(completeTaskStep.computeWorldStateSyncProgress()).isEqualTo(1.0 / 4.0); + } + + private StubTask validTask() { + final Hash hash = + Hash.fromHexString("0x601a7b0d0267209790cf4c4d9e0cab11b26c537e2ade006412f48b070010e847"); + final BytesValue data = + BytesValue.fromHexString( + "0xf85180808080a05ac6993e3fbca0bfbd30173396dd5c2412657fae0bad92e401d17b2aa9a3698f80808080a012f96a0812be538c302416dc6e8df19ce18f1cc7b06a3c7a16831d766c87a9b580808080808080"); + final StubTask task = new StubTask(NodeDataRequest.createAccountDataRequest(hash)); + task.getData().setData(data); + return task; + } } diff --git a/metrics/core/src/main/java/tech/pegasys/pantheon/metrics/RunnableCounter.java b/metrics/core/src/main/java/tech/pegasys/pantheon/metrics/RunnableCounter.java index 6838815dab..521ae2e4b6 100644 --- a/metrics/core/src/main/java/tech/pegasys/pantheon/metrics/RunnableCounter.java +++ b/metrics/core/src/main/java/tech/pegasys/pantheon/metrics/RunnableCounter.java @@ -12,7 +12,7 @@ */ package tech.pegasys.pantheon.metrics; -import java.util.concurrent.atomic.AtomicInteger; +import java.util.concurrent.atomic.AtomicLong; /** Counter that triggers a specific task each time a step is hit. */ public class RunnableCounter implements Counter { @@ -20,13 +20,13 @@ public class RunnableCounter implements Counter { private final Counter backedCounter; private final Runnable task; private final int step; - private AtomicInteger stepCounter; + private AtomicLong stepCounter; public RunnableCounter(final Counter backedCounter, final Runnable task, final int step) { this.backedCounter = backedCounter; this.task = task; this.step = step; - this.stepCounter = new AtomicInteger(0); + this.stepCounter = new AtomicLong(0); } /** @@ -46,11 +46,13 @@ public class RunnableCounter implements Counter { */ @Override public void inc(final long amount) { - stepCounter.addAndGet((int) amount); backedCounter.inc(amount); - if (stepCounter.get() == step) { + if (stepCounter.addAndGet(amount) % step == 0) { task.run(); - stepCounter = new AtomicInteger(0); } } + + public long get() { + return stepCounter.get(); + } }