Report estimated disk freed up by x-trie-log prune subcommand (#6483)

Also improve logging and error handling

---------

Signed-off-by: Simon Dudley <simon.dudley@consensys.net>

besu/src/main/java/org/hyperledger/besu/cli/options/stable/DataStorageOptions.java

@@ -74,7 +74,7 @@ public class DataStorageOptions implements CLIOptions<DataStorageConfiguration>
 
     @CommandLine.Option(
         hidden = true,
-        names = {BONSAI_LIMIT_TRIE_LOGS_ENABLED},
+        names = {BONSAI_LIMIT_TRIE_LOGS_ENABLED, "--Xbonsai-trie-log-pruning-enabled"},
         description =
             "Limit the number of trie logs that are retained. (default: ${DEFAULT-VALUE})")
     private boolean bonsaiLimitTrieLogsEnabled = DEFAULT_BONSAI_LIMIT_TRIE_LOGS_ENABLED;

besu/src/main/java/org/hyperledger/besu/cli/subcommands/storage/RocksDbHelper.java

@@ -18,17 +18,53 @@ package org.hyperledger.besu.cli.subcommands.storage;
 import org.hyperledger.besu.ethereum.storage.keyvalue.KeyValueSegmentIdentifier;
 
 import java.io.PrintWriter;
+import java.util.ArrayList;
+import java.util.List;
+import java.util.function.BiConsumer;
 
 import org.bouncycastle.util.Arrays;
+import org.rocksdb.ColumnFamilyDescriptor;
 import org.rocksdb.ColumnFamilyHandle;
+import org.rocksdb.Options;
 import org.rocksdb.RocksDB;
 import org.rocksdb.RocksDBException;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
-/** RocksDB Usage subcommand helper methods for formatting and printing. */
+/** RocksDB subcommand helper methods. */
-public class RocksDbUsageHelper {
+public class RocksDbHelper {
-  private static final Logger LOG = LoggerFactory.getLogger(RocksDbUsageHelper.class);
+  private static final Logger LOG = LoggerFactory.getLogger(RocksDbHelper.class);
+
+  static void forEachColumnFamily(
+      final String dbPath, final BiConsumer<RocksDB, ColumnFamilyHandle> task) {
+    RocksDB.loadLibrary();
+    Options options = new Options();
+    options.setCreateIfMissing(true);
+
+    // Open the RocksDB database with multiple column families
+    List<byte[]> cfNames;
+    try {
+      cfNames = RocksDB.listColumnFamilies(options, dbPath);
+    } catch (RocksDBException e) {
+      throw new RuntimeException(e);
+    }
+    final List<ColumnFamilyHandle> cfHandles = new ArrayList<>();
+    final List<ColumnFamilyDescriptor> cfDescriptors = new ArrayList<>();
+    for (byte[] cfName : cfNames) {
+      cfDescriptors.add(new ColumnFamilyDescriptor(cfName));
+    }
+    try (final RocksDB rocksdb = RocksDB.openReadOnly(dbPath, cfDescriptors, cfHandles)) {
+      for (ColumnFamilyHandle cfHandle : cfHandles) {
+        task.accept(rocksdb, cfHandle);
+      }
+    } catch (RocksDBException e) {
+      throw new RuntimeException(e);
+    } finally {
+      for (ColumnFamilyHandle cfHandle : cfHandles) {
+        cfHandle.close();
+      }
+    }
+  }
 
   static void printUsageForColumnFamily(
       final RocksDB rocksdb, final ColumnFamilyHandle cfHandle, final PrintWriter out)
@@ -62,7 +98,7 @@ public class RocksDbUsageHelper {
     }
   }
 
-  private static String formatOutputSize(final long size) {
+  static String formatOutputSize(final long size) {
     if (size > (1024 * 1024 * 1024)) {
       long sizeInGiB = size / (1024 * 1024 * 1024);
       return sizeInGiB + " GiB";

besu/src/main/java/org/hyperledger/besu/cli/subcommands/storage/RocksDbSubCommand.java

@@ -19,13 +19,7 @@ import static org.hyperledger.besu.controller.BesuController.DATABASE_PATH;
 import org.hyperledger.besu.cli.util.VersionProvider;
 
 import java.io.PrintWriter;
-import java.util.ArrayList;
-import java.util.List;
 
-import org.rocksdb.ColumnFamilyDescriptor;
-import org.rocksdb.ColumnFamilyHandle;
-import org.rocksdb.Options;
-import org.rocksdb.RocksDB;
 import org.rocksdb.RocksDBException;
 import picocli.CommandLine;
 import picocli.CommandLine.Command;
@@ -82,34 +76,17 @@ public class RocksDbSubCommand implements Runnable {
               .concat("/")
               .concat(DATABASE_PATH);
 
-      RocksDB.loadLibrary();
+      RocksDbHelper.printTableHeader(out);
-      Options options = new Options();
+
-      options.setCreateIfMissing(true);
+      RocksDbHelper.forEachColumnFamily(
-
+          dbPath,
-      // Open the RocksDB database with multiple column families
+          (rocksdb, cfHandle) -> {
-      List<byte[]> cfNames;
+            try {
-      try {
+              RocksDbHelper.printUsageForColumnFamily(rocksdb, cfHandle, out);
-        cfNames = RocksDB.listColumnFamilies(options, dbPath);
+            } catch (RocksDBException e) {
-      } catch (RocksDBException e) {
+              throw new RuntimeException(e);
-        throw new RuntimeException(e);
+            }
-      }
+          });
-      final List<ColumnFamilyHandle> cfHandles = new ArrayList<>();
-      final List<ColumnFamilyDescriptor> cfDescriptors = new ArrayList<>();
-      for (byte[] cfName : cfNames) {
-        cfDescriptors.add(new ColumnFamilyDescriptor(cfName));
-      }
-      RocksDbUsageHelper.printTableHeader(out);
-      try (final RocksDB rocksdb = RocksDB.openReadOnly(dbPath, cfDescriptors, cfHandles)) {
-        for (ColumnFamilyHandle cfHandle : cfHandles) {
-          RocksDbUsageHelper.printUsageForColumnFamily(rocksdb, cfHandle, out);
-        }
-      } catch (RocksDBException e) {
-        throw new RuntimeException(e);
-      } finally {
-        for (ColumnFamilyHandle cfHandle : cfHandles) {
-          cfHandle.close();
-        }
-      }
     }
   }
 }

besu/src/main/java/org/hyperledger/besu/cli/subcommands/storage/TrieLogHelper.java

@@ -60,11 +60,12 @@ public class TrieLogHelper {
   private static final int ROCKSDB_MAX_INSERTS_PER_TRANSACTION = 1000;
   private static final Logger LOG = LoggerFactory.getLogger(TrieLogHelper.class);
 
-  void prune(
+  boolean prune(
       final DataStorageConfiguration config,
       final BonsaiWorldStateKeyValueStorage rootWorldStateStorage,
       final MutableBlockchain blockchain,
       final Path dataDirectoryPath) {
+
     final String batchFileNameBase =
         dataDirectoryPath.resolve(DATABASE_PATH).resolve(TRIE_LOG_FILE).toString();
 
@@ -82,10 +83,14 @@ public class TrieLogHelper {
         lastBlockNumberToRetainTrieLogsFor,
         rootWorldStateStorage,
         layersToRetain)) {
-      return;
+      return false;
     }
 
     final long numberOfBatches = calculateNumberOfBatches(layersToRetain);
+    LOG.info(
+        "Starting pruning: retain {} trie logs, processing in {} batches...",
+        layersToRetain,
+        numberOfBatches);
 
     processTrieLogBatches(
         rootWorldStateStorage,
@@ -102,7 +107,7 @@ public class TrieLogHelper {
             .count();
     if (countAfterPrune == layersToRetain) {
       if (deleteFiles(batchFileNameBase, numberOfBatches)) {
-        LOG.info("Prune ran successfully. Enjoy some disk space back! \uD83D\uDE80");
+        return true;
       } else {
         throw new IllegalStateException(
             "There was an error deleting the trie log backup files. Please ensure besu is working before deleting them manually.");
@@ -110,8 +115,11 @@ public class TrieLogHelper {
     } else {
       throw new IllegalStateException(
           String.format(
-              "Remaining trie logs (%d) did not match %s (%d). Trie logs backup files have not been deleted, it is safe to rerun the subcommand.",
+              "Remaining trie logs (%d) did not match %s (%d). Trie logs backup files (in %s) have not been deleted, it is safe to rerun the subcommand.",
-              countAfterPrune, BONSAI_STORAGE_FORMAT_MAX_LAYERS_TO_LOAD, layersToRetain));
+              countAfterPrune,
+              BONSAI_STORAGE_FORMAT_MAX_LAYERS_TO_LOAD,
+              layersToRetain,
+              batchFileNameBase));
     }
   }
 
@@ -131,7 +139,7 @@ public class TrieLogHelper {
       final List<Hash> trieLogKeys =
           getTrieLogKeysForBlocks(blockchain, firstBlockOfBatch, lastBlockOfBatch);
 
-      LOG.info("Saving trie logs to retain in file (batch {})...", batchNumber);
+      LOG.info("Saving trie logs to retain in file {} (batch {})...", batchFileName, batchNumber);
       saveTrieLogBatches(batchFileName, rootWorldStateStorage, trieLogKeys);
     }
 
@@ -319,7 +327,7 @@ public class TrieLogHelper {
 
     File file = new File(batchFileName);
     if (file.exists()) {
-      LOG.error("File already exists, skipping file creation");
+      LOG.warn("File already exists {}, skipping file creation", batchFileName);
       return;
     }
 
@@ -354,7 +362,7 @@ public class TrieLogHelper {
       final String batchFileName) {
     File file = new File(batchFileName);
     if (file.exists()) {
-      LOG.error("File already exists, skipping file creation");
+      LOG.warn("File already exists {}, skipping file creation", batchFileName);
       return;
     }
 

besu/src/main/java/org/hyperledger/besu/cli/subcommands/storage/TrieLogSubCommand.java

@@ -16,6 +16,9 @@ package org.hyperledger.besu.cli.subcommands.storage;
 
 import static com.google.common.base.Preconditions.checkArgument;
 import static com.google.common.base.Preconditions.checkNotNull;
+import static org.hyperledger.besu.cli.subcommands.storage.RocksDbHelper.formatOutputSize;
+import static org.hyperledger.besu.controller.BesuController.DATABASE_PATH;
+import static org.hyperledger.besu.ethereum.storage.keyvalue.KeyValueSegmentIdentifier.TRIE_LOG_STORAGE;
 
 import org.hyperledger.besu.cli.util.VersionProvider;
 import org.hyperledger.besu.controller.BesuController;
@@ -31,10 +34,14 @@ import java.io.IOException;
 import java.io.PrintWriter;
 import java.nio.file.Path;
 import java.nio.file.Paths;
+import java.util.Arrays;
 import java.util.List;
+import java.util.concurrent.atomic.AtomicLong;
 
 import org.apache.logging.log4j.Level;
 import org.apache.logging.log4j.core.config.Configurator;
+import org.rocksdb.RocksDBException;
+import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 import picocli.CommandLine;
 import picocli.CommandLine.Command;
@@ -54,6 +61,8 @@ import picocli.CommandLine.ParentCommand;
     })
 public class TrieLogSubCommand implements Runnable {
 
+  private static final Logger LOG = LoggerFactory.getLogger(TrieLogSubCommand.class);
+
   @SuppressWarnings("UnusedVariable")
   @ParentCommand
   private static StorageSubCommand parentCommand;
@@ -124,12 +133,67 @@ public class TrieLogSubCommand implements Runnable {
       final Path dataDirectoryPath =
           Paths.get(
               TrieLogSubCommand.parentCommand.parentCommand.dataDir().toAbsolutePath().toString());
+
+      LOG.info("Estimating trie logs size before pruning...");
+      long sizeBefore = estimatedSizeOfTrieLogs();
+      LOG.info("Estimated trie logs size before pruning: {}", formatOutputSize(sizeBefore));
+
       final TrieLogHelper trieLogHelper = new TrieLogHelper();
-      trieLogHelper.prune(
+      boolean success =
-          context.config(),
+          trieLogHelper.prune(
-          context.rootWorldStateStorage(),
+              context.config(),
-          context.blockchain(),
+              context.rootWorldStateStorage(),
-          dataDirectoryPath);
+              context.blockchain(),
+              dataDirectoryPath);
+
+      if (success) {
+        LOG.info("Finished pruning. Re-estimating trie logs size...");
+        final long sizeAfter = estimatedSizeOfTrieLogs();
+        LOG.info(
+            "Estimated trie logs size after pruning: {} (0 B estimate is normal when using default settings)",
+            formatOutputSize(sizeAfter));
+        long estimatedSaving = sizeBefore - sizeAfter;
+        LOG.info(
+            "Prune ran successfully. We estimate you freed up {}! \uD83D\uDE80",
+            formatOutputSize(estimatedSaving));
+        spec.commandLine()
+            .getOut()
+            .printf(
+                "Prune ran successfully. We estimate you freed up %s! \uD83D\uDE80\n",
+                formatOutputSize(estimatedSaving));
+      }
+    }
+
+    private long estimatedSizeOfTrieLogs() {
+      final String dbPath =
+          TrieLogSubCommand.parentCommand
+              .parentCommand
+              .dataDir()
+              .toString()
+              .concat("/")
+              .concat(DATABASE_PATH);
+
+      AtomicLong estimatedSaving = new AtomicLong(0L);
+      try {
+        RocksDbHelper.forEachColumnFamily(
+            dbPath,
+            (rocksdb, cfHandle) -> {
+              try {
+                if (Arrays.equals(cfHandle.getName(), TRIE_LOG_STORAGE.getId())) {
+                  estimatedSaving.set(
+                      Long.parseLong(
+                          rocksdb.getProperty(cfHandle, "rocksdb.estimate-live-data-size")));
+                }
+              } catch (RocksDBException | NumberFormatException e) {
+                throw new RuntimeException(e);
+              }
+            });
+      } catch (Exception e) {
+        LOG.warn("Error while estimating trie log size, returning 0 for estimate", e);
+        return 0L;
+      }
+
+      return estimatedSaving.get();
     }
   }
 

besu/src/test/java/org/hyperledger/besu/cli/subcommands/storage/TrieLogHelperTest.java

@@ -291,8 +291,8 @@ class TrieLogHelperTest {
                 nonValidatingTrieLogHelper.prune(
                     dataStorageConfiguration, inMemoryWorldStateSpy, blockchain, dataDir))
         .isInstanceOf(RuntimeException.class)
-        .hasMessage(
+        .hasMessageContaining(
-            "Remaining trie logs (0) did not match --bonsai-historical-block-limit (3). Trie logs backup files have not been deleted, it is safe to rerun the subcommand.");
+            "Remaining trie logs (0) did not match --bonsai-historical-block-limit (3)");
   }
 
   @Test