This is an automated email from the ASF dual-hosted git repository.
ddanielr pushed a commit to branch 2.1
in repository https://gitbox.apache.org/repos/asf/accumulo.git
The following commit(s) were added to refs/heads/2.1 by this push:
new 2950699947 Adds batch information to GC logging (#5391)
2950699947 is described below
commit 29506999476e99ffc15019469c35705ced0d3278
Author: Daniel Roberts <[email protected]>
AuthorDate: Tue Mar 11 21:06:08 2025 -0400
Adds batch information to GC logging (#5391)
Adds batch counter to log messages.
Adds in-progress counters to long-running methods.
Uses getCompletedTaskCount which
should list the amount of completed tasks in the threadpool.
---
.../main/java/org/apache/accumulo/gc/GCRun.java | 40 +++++++++++++++++-----
.../accumulo/gc/GarbageCollectionAlgorithm.java | 9 +++--
.../accumulo/gc/SimpleGarbageCollectorTest.java | 3 +-
3 files changed, 40 insertions(+), 12 deletions(-)
diff --git a/server/gc/src/main/java/org/apache/accumulo/gc/GCRun.java
b/server/gc/src/main/java/org/apache/accumulo/gc/GCRun.java
index a4b328438f..22275c9e11 100644
--- a/server/gc/src/main/java/org/apache/accumulo/gc/GCRun.java
+++ b/server/gc/src/main/java/org/apache/accumulo/gc/GCRun.java
@@ -25,6 +25,7 @@ import static
org.apache.accumulo.core.metadata.schema.TabletMetadata.ColumnType
import java.io.FileNotFoundException;
import java.io.IOException;
+import java.time.Duration;
import java.util.ArrayList;
import java.util.Collection;
import java.util.Collections;
@@ -36,8 +37,9 @@ import java.util.Map;
import java.util.Objects;
import java.util.Set;
import java.util.SortedMap;
-import java.util.concurrent.ExecutorService;
+import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;
+import java.util.concurrent.atomic.AtomicInteger;
import java.util.stream.Stream;
import org.apache.accumulo.core.Constants;
@@ -65,6 +67,7 @@ import
org.apache.accumulo.core.metadata.schema.TabletMetadata;
import org.apache.accumulo.core.metadata.schema.TabletsMetadata;
import org.apache.accumulo.core.security.Authorizations;
import org.apache.accumulo.core.util.Pair;
+import org.apache.accumulo.core.util.Timer;
import org.apache.accumulo.core.util.UtilWaitThread;
import org.apache.accumulo.core.util.threads.ThreadPools;
import org.apache.accumulo.core.volume.Volume;
@@ -95,16 +98,19 @@ public class GCRun implements GarbageCollectionEnvironment {
private final Ample.DataLevel level;
private final ServerContext context;
private final AccumuloConfiguration config;
+ private final Duration loggingInterval = Duration.ofMinutes(1);
private long candidates = 0;
private long inUse = 0;
private long deleted = 0;
private long errors = 0;
+ private AtomicInteger batchCount;
public GCRun(Ample.DataLevel level, ServerContext context) {
this.log = LoggerFactory.getLogger(GCRun.class.getName() + "." +
level.name());
this.level = level;
this.context = context;
this.config = context.getConfiguration();
+ this.batchCount = new AtomicInteger(0);
}
@Override
@@ -132,7 +138,8 @@ public class GCRun implements GarbageCollectionEnvironment {
return;
}
- log.info("Attempting to delete gcCandidates of type {} from metadata",
type);
+ log.info("Batch {} attempting to delete {} gcCandidates of type {} from
metadata",
+ batchCount.get(), gcCandidates.size(), type);
context.getAmple().deleteGcCandidates(level, gcCandidates, type);
}
@@ -143,6 +150,7 @@ public class GCRun implements GarbageCollectionEnvironment {
long candidateBatchSize = getCandidateBatchSize() / 2;
List<GcCandidate> candidatesBatch = new ArrayList<>();
+ batchCount.incrementAndGet();
while (candidates.hasNext()) {
GcCandidate candidate = candidates.next();
@@ -288,15 +296,17 @@ public class GCRun implements
GarbageCollectionEnvironment {
List<GcCandidate> processedDeletes = Collections.synchronizedList(new
ArrayList<>());
- minimizeDeletes(confirmedDeletes, processedDeletes, fs, log);
+ minimizeDeletes(confirmedDeletes, processedDeletes, fs, log,
loggingInterval);
- ExecutorService deleteThreadPool = ThreadPools.getServerThreadPools()
+ ThreadPoolExecutor deleteThreadPool = ThreadPools.getServerThreadPools()
.createExecutorService(config, Property.GC_DELETE_THREADS);
final List<Pair<Path,Path>> replacements = context.getVolumeReplacements();
+ log.info("Batch {} attempting to delete {} gcCandidate files",
batchCount.get(),
+ confirmedDeletes.size());
+ Timer timer = Timer.startNew();
for (final GcCandidate delete : confirmedDeletes.values()) {
-
Runnable deleteTask = () -> {
boolean removeFlag = false;
@@ -320,7 +330,7 @@ public class GCRun implements GarbageCollectionEnvironment {
}
for (Path pathToDel : GcVolumeUtil.expandAllVolumesUri(fs,
fullPath)) {
- log.debug("{} Deleting {}", fileActionPrefix, pathToDel);
+ log.debug("Batch {} {} Deleting {}", batchCount.get(),
fileActionPrefix, pathToDel);
if (moveToTrash(pathToDel) || fs.deleteRecursively(pathToDel)) {
// delete succeeded, still want to delete
@@ -373,7 +383,12 @@ public class GCRun implements GarbageCollectionEnvironment
{
deleteThreadPool.shutdown();
try {
- while (!deleteThreadPool.awaitTermination(1000, TimeUnit.MILLISECONDS))
{ // empty
+ while (!deleteThreadPool.awaitTermination(1000, TimeUnit.MILLISECONDS)) {
+ if (timer.hasElapsed(loggingInterval)) {
+ log.info("Batch {} deleting file {} of {}", batchCount.get(),
+ deleteThreadPool.getCompletedTaskCount(),
confirmedDeletes.size());
+ timer.restart();
+ }
}
} catch (InterruptedException e1) {
log.error("{}", e1.getMessage(), e1);
@@ -441,7 +456,8 @@ public class GCRun implements GarbageCollectionEnvironment {
@VisibleForTesting
static void minimizeDeletes(SortedMap<String,GcCandidate> confirmedDeletes,
- List<GcCandidate> processedDeletes, VolumeManager fs, Logger logger) {
+ List<GcCandidate> processedDeletes, VolumeManager fs, Logger logger,
+ Duration loggingInterval) {
Set<Path> seenVolumes = new HashSet<>();
// when deleting a dir and all files in that dir, only need to delete the
dir.
@@ -451,7 +467,11 @@ public class GCRun implements GarbageCollectionEnvironment
{
String lastDirRel = null;
Path lastDirAbs = null;
+ Timer progressTimer = Timer.startNew();
+ int progressCount = 0;
+ int totalDeletes = confirmedDeletes.size();
while (cdIter.hasNext()) {
+ progressCount++;
Map.Entry<String,GcCandidate> entry = cdIter.next();
String relPath = entry.getKey();
Path absPath = new Path(entry.getValue().getPath());
@@ -491,6 +511,10 @@ public class GCRun implements GarbageCollectionEnvironment
{
lastDirAbs = null;
}
}
+ if (progressTimer.hasElapsed(loggingInterval)) {
+ logger.debug("Minimizing delete {} of {}", progressCount,
totalDeletes);
+ progressTimer.restart();
+ }
}
}
diff --git
a/server/gc/src/main/java/org/apache/accumulo/gc/GarbageCollectionAlgorithm.java
b/server/gc/src/main/java/org/apache/accumulo/gc/GarbageCollectionAlgorithm.java
index 419d10728f..095d9dd490 100644
---
a/server/gc/src/main/java/org/apache/accumulo/gc/GarbageCollectionAlgorithm.java
+++
b/server/gc/src/main/java/org/apache/accumulo/gc/GarbageCollectionAlgorithm.java
@@ -387,6 +387,7 @@ public class GarbageCollectionAlgorithm {
Iterator<GcCandidate> candidatesIter = gce.getCandidates();
long totalBlips = 0;
+ int batchCount = 0;
while (candidatesIter.hasNext()) {
List<GcCandidate> batchOfCandidates;
@@ -399,7 +400,8 @@ public class GarbageCollectionAlgorithm {
} finally {
candidatesSpan.end();
}
- totalBlips = deleteBatch(gce, batchOfCandidates);
+ batchCount++;
+ totalBlips = deleteBatch(gce, batchOfCandidates, batchCount);
}
return totalBlips;
}
@@ -407,11 +409,12 @@ public class GarbageCollectionAlgorithm {
/**
* Given a sub-list of possible deletion candidates, process and remove
valid deletion candidates.
*/
- private long deleteBatch(GarbageCollectionEnvironment gce, List<GcCandidate>
currentBatch)
- throws InterruptedException, TableNotFoundException, IOException {
+ private long deleteBatch(GarbageCollectionEnvironment gce, List<GcCandidate>
currentBatch,
+ int batchCount) throws InterruptedException, TableNotFoundException,
IOException {
long origSize = currentBatch.size();
gce.incrementCandidatesStat(origSize);
+ log.info("Batch {} total deletion candidates: {}", batchCount, origSize);
SortedMap<String,GcCandidate> candidateMap = makeRelative(currentBatch);
diff --git
a/server/gc/src/test/java/org/apache/accumulo/gc/SimpleGarbageCollectorTest.java
b/server/gc/src/test/java/org/apache/accumulo/gc/SimpleGarbageCollectorTest.java
index fdb66ba146..34cb62cc7b 100644
---
a/server/gc/src/test/java/org/apache/accumulo/gc/SimpleGarbageCollectorTest.java
+++
b/server/gc/src/test/java/org/apache/accumulo/gc/SimpleGarbageCollectorTest.java
@@ -31,6 +31,7 @@ import static org.junit.jupiter.api.Assertions.assertSame;
import static org.junit.jupiter.api.Assertions.assertTrue;
import java.io.FileNotFoundException;
+import java.time.Duration;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collection;
@@ -192,7 +193,7 @@ public class SimpleGarbageCollectorTest {
List<GcCandidate> processedDeletes = new ArrayList<>();
- GCRun.minimizeDeletes(confirmed, processedDeletes, volMgr2, log);
+ GCRun.minimizeDeletes(confirmed, processedDeletes, volMgr2, log,
Duration.ofMinutes(1));
TreeMap<String,GcCandidate> expected = new TreeMap<>();
expected.put("5a/t-0001", new
GcCandidate("hdfs://nn1/accumulo/tables/5a/t-0001", 0L));