Author: amitj
Date: Thu Oct 12 06:53:28 2017
New Revision: 1811914
URL: http://svn.apache.org/viewvc?rev=1811914&view=rev
Log:
OAK-5983: BlobGC should log the amount of space reclaimed after GC run is done
- Logging the total size that's cleaned up only for cases where the length is
encoded in the ids.
Modified:
jackrabbit/oak/trunk/oak-blob-plugins/pom.xml
jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java
jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/datastore/DataStoreBlobStore.java
jackrabbit/oak/trunk/oak-blob-plugins/src/test/java/org/apache/jackrabbit/oak/plugins/blob/BlobGCTest.java
Modified: jackrabbit/oak/trunk/oak-blob-plugins/pom.xml
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-blob-plugins/pom.xml?rev=1811914&r1=1811913&r2=1811914&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-blob-plugins/pom.xml (original)
+++ jackrabbit/oak/trunk/oak-blob-plugins/pom.xml Thu Oct 12 06:53:28 2017
@@ -205,6 +205,13 @@
<artifactId>org.apache.sling.testing.osgi-mock</artifactId>
<scope>test</scope>
</dependency>
+ <dependency>
+ <groupId>org.apache.jackrabbit</groupId>
+ <artifactId>oak-commons</artifactId>
+ <version>${project.version}</version>
+ <classifier>tests</classifier>
+ <scope>test</scope>
+ </dependency>
</dependencies>
</project>
Modified:
jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java?rev=1811914&r1=1811913&r2=1811914&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java
(original)
+++
jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java
Thu Oct 12 06:53:28 2017
@@ -41,8 +41,10 @@ import javax.annotation.Nullable;
import com.google.common.base.Charsets;
import com.google.common.base.Function;
import com.google.common.base.Joiner;
+import com.google.common.base.Splitter;
import com.google.common.base.StandardSystemProperty;
import com.google.common.base.Stopwatch;
+import com.google.common.base.Strings;
import com.google.common.collect.Iterators;
import com.google.common.collect.Lists;
import com.google.common.collect.Maps;
@@ -57,6 +59,7 @@ import org.apache.jackrabbit.oak.api.jmx
import org.apache.jackrabbit.oak.commons.FileIOUtils;
import
org.apache.jackrabbit.oak.commons.FileIOUtils.FileLineDifferenceIterator;
import org.apache.jackrabbit.oak.plugins.blob.datastore.BlobTracker;
+import org.apache.jackrabbit.oak.plugins.blob.datastore.DataStoreBlobStore;
import org.apache.jackrabbit.oak.plugins.blob.datastore.SharedDataStoreUtils;
import
org.apache.jackrabbit.oak.plugins.blob.datastore.SharedDataStoreUtils.SharedStoreRecordType;
import org.apache.jackrabbit.oak.spi.blob.GarbageCollectableBlobStore;
@@ -403,6 +406,8 @@ public class MarkSweepGarbageCollector i
BufferedWriter removesWriter = null;
LineIterator iterator = null;
+ long deletedSize = 0;
+ int numDeletedSizeAvailable = 0;
try {
removesWriter = Files.newWriter(fs.getGarbage(), Charsets.UTF_8);
ArrayDeque<String> removesQueue = new ArrayDeque<String>();
@@ -416,6 +421,17 @@ public class MarkSweepGarbageCollector i
deleted += BlobCollectionType.get(blobStore)
.sweepInternal(blobStore, ids, removesQueue,
maxModifiedTime);
saveBatchToFile(newArrayList(removesQueue), removesWriter);
+
+ for(String deletedIdRow : removesQueue) {
+ String strLength =
Splitter.on(DELIM).trimResults().splitToList(deletedIdRow).get(1);
+ if (!Strings.isNullOrEmpty(strLength)) {
+ long length = Long.valueOf(strLength);
+ if (length != -1) {
+ deletedSize += length;
+ numDeletedSizeAvailable += 1;
+ }
+ }
+ }
removesQueue.clear();
}
} finally {
@@ -432,6 +448,12 @@ public class MarkSweepGarbageCollector i
timestampToString(maxModifiedTime));
}
+ if (deletedSize > 0) {
+ LOG.info("Estimated size recovered for {} deleted blobs is {} ({}
bytes)",
+ numDeletedSizeAvailable,
+
org.apache.jackrabbit.oak.commons.IOUtils.humanReadableByteCount(deletedSize),
deletedSize);
+ }
+
// Remove all the merged marked references
GarbageCollectionType.get(blobStore).removeAllMarkedReferences(blobStore);
LOG.debug("Ending sweep phase of the garbage collector");
@@ -766,30 +788,6 @@ public class MarkSweepGarbageCollector i
*/
private enum BlobCollectionType {
TRACKER {
- /**
- * Deletes the given batch by deleting individually to exactly
know the actual deletes.
- */
- @Override
- long sweepInternal(GarbageCollectableBlobStore blobStore,
List<String> ids,
- ArrayDeque<String> exceptionQueue, long maxModified) {
- long totalDeleted = 0;
- LOG.trace("Blob ids to be deleted {}", ids);
- for (String id : ids) {
- try {
- long deleted =
blobStore.countDeleteChunks(newArrayList(id), maxModified);
- if (deleted != 1) {
- LOG.debug("Blob [{}] not deleted", id);
- } else {
- exceptionQueue.add(id);
- }
- totalDeleted += deleted;
- } catch (Exception e) {
- LOG.warn("Error occurred while deleting blob with id
[{}]", id, e);
- }
- }
- return totalDeleted;
- }
-
@Override
void retrieve(GarbageCollectableBlobStore blobStore,
GarbageCollectorFileState fs, int batchCount) throws
Exception {
@@ -818,29 +816,28 @@ public class MarkSweepGarbageCollector i
DEFAULT;
/**
- * Deletes a batch of blobs from blob store.
- *
- * @param blobStore blobStore
- * @param ids ids to sweep
- * @param exceptionQueue add removes to the queue
- * @param maxModified maxModified time of blobs to be deleted
- * @return
+ * Deletes the given batch by deleting individually to exactly know
the actual deletes.
*/
- long sweepInternal(GarbageCollectableBlobStore blobStore,
- List<String> ids, ArrayDeque<String> exceptionQueue, long
maxModified) {
- long deleted = 0;
- try {
- LOG.trace("Blob ids to be deleted {}", ids);
- deleted = blobStore.countDeleteChunks(ids, maxModified);
- if (deleted != ids.size()) {
- LOG.debug("Some [{}] blobs were not deleted from the batch
: [{}]",
- ids.size() - deleted, ids);
+ long sweepInternal(GarbageCollectableBlobStore blobStore, List<String>
ids,
+ ArrayDeque<String> exceptionQueue, long maxModified) {
+ long totalDeleted = 0;
+ LOG.trace("Blob ids to be deleted {}", ids);
+ for (String id : ids) {
+ try {
+ // Estimate the size of the blob
+ long length = DataStoreBlobStore.BlobId.of(id).getLength();
+ long deleted =
blobStore.countDeleteChunks(newArrayList(id), maxModified);
+ if (deleted != 1) {
+ LOG.debug("Blob [{}] not deleted", id);
+ } else {
+ exceptionQueue.add(Joiner.on(DELIM).join(id, length));
+ totalDeleted += 1;
+ }
+ } catch (Exception e) {
+ LOG.warn("Error occurred while deleting blob with id
[{}]", id, e);
}
- exceptionQueue.addAll(ids);
- } catch (Exception e) {
- LOG.warn("Error occurred while deleting blob with ids [{}]",
ids, e);
}
- return deleted;
+ return totalDeleted;
}
/**
Modified:
jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/datastore/DataStoreBlobStore.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/datastore/DataStoreBlobStore.java?rev=1811914&r1=1811913&r2=1811914&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/datastore/DataStoreBlobStore.java
(original)
+++
jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/datastore/DataStoreBlobStore.java
Thu Oct 12 06:53:28 2017
@@ -660,6 +660,10 @@ public class DataStoreBlobStore
return blobId;
}
+ public long getLength() {
+ return length;
+ }
+
final String blobId;
final long length;
Modified:
jackrabbit/oak/trunk/oak-blob-plugins/src/test/java/org/apache/jackrabbit/oak/plugins/blob/BlobGCTest.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-blob-plugins/src/test/java/org/apache/jackrabbit/oak/plugins/blob/BlobGCTest.java?rev=1811914&r1=1811913&r2=1811914&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-blob-plugins/src/test/java/org/apache/jackrabbit/oak/plugins/blob/BlobGCTest.java
(original)
+++
jackrabbit/oak/trunk/oak-blob-plugins/src/test/java/org/apache/jackrabbit/oak/plugins/blob/BlobGCTest.java
Thu Oct 12 06:53:28 2017
@@ -27,7 +27,6 @@ import java.io.InputStream;
import java.io.OutputStream;
import java.security.DigestOutputStream;
import java.security.MessageDigest;
-import java.util.Date;
import java.util.HashSet;
import java.util.Iterator;
import java.util.List;
@@ -36,14 +35,12 @@ import java.util.Random;
import java.util.Set;
import java.util.concurrent.Executors;
import java.util.concurrent.ThreadPoolExecutor;
-import java.util.concurrent.atomic.AtomicInteger;
-import java.util.concurrent.atomic.AtomicLong;
import java.util.concurrent.atomic.AtomicReference;
import javax.annotation.CheckForNull;
import javax.annotation.Nonnull;
-import javax.management.openmbean.TabularData;
+import ch.qos.logback.classic.Level;
import com.google.common.collect.Iterators;
import com.google.common.collect.Lists;
import com.google.common.collect.Maps;
@@ -54,6 +51,7 @@ import org.apache.jackrabbit.core.data.D
import org.apache.jackrabbit.core.data.DataRecord;
import org.apache.jackrabbit.core.data.DataStoreException;
import org.apache.jackrabbit.oak.api.Blob;
+import org.apache.jackrabbit.oak.commons.junit.LogCustomizer;
import org.apache.jackrabbit.oak.api.CommitFailedException;
import org.apache.jackrabbit.oak.api.jmx.CheckpointMBean;
import org.apache.jackrabbit.oak.plugins.blob.datastore.SharedDataStoreUtils;
@@ -70,7 +68,6 @@ import org.apache.jackrabbit.oak.spi.sta
import org.apache.jackrabbit.oak.spi.whiteboard.DefaultWhiteboard;
import org.apache.jackrabbit.oak.spi.whiteboard.Registration;
import org.apache.jackrabbit.oak.spi.whiteboard.Whiteboard;
-import org.apache.jackrabbit.oak.spi.whiteboard.WhiteboardUtils;
import org.apache.jackrabbit.oak.stats.Clock;
import org.junit.Before;
import org.junit.Rule;
@@ -153,6 +150,33 @@ public class BlobGCTest {
assertTrue(Sets.symmetricDifference(state.blobsAdded,
existingAfterGC).isEmpty());
}
+ @Test
+ public void gcCheckDeletedSize() throws Exception {
+ log.info("Staring gcCheckDeletedSize()");
+
+ BlobStoreState state = setUp(10, 5, 100);
+
+ log.info("{} blobs added : {}", state.blobsAdded.size(),
state.blobsAdded);
+ log.info("{} blobs remaining : {}", state.blobsPresent.size(),
state.blobsPresent);
+
+ // Capture logs for the second round of gc
+ LogCustomizer customLogs = LogCustomizer
+ .forLogger(MarkSweepGarbageCollector.class.getName())
+ .enable(Level.INFO)
+ .filter(Level.INFO)
+ .contains("Estimated size recovered for")
+ .create();
+ customLogs.starting();
+
+ Set<String> existingAfterGC = gcInternal(0);
+ assertEquals(1, customLogs.getLogs().size());
+ long deletedSize = (state.blobsAdded.size() -
state.blobsPresent.size()) * 100;
+
assertTrue(customLogs.getLogs().get(0).contains(String.valueOf(deletedSize)));
+
+ customLogs.finished();
+ assertTrue(Sets.symmetricDifference(state.blobsPresent,
existingAfterGC).isEmpty());
+ }
+
protected Set<String> gcInternal(long maxBlobGcInSecs) throws Exception {
ThreadPoolExecutor executor = (ThreadPoolExecutor)
Executors.newFixedThreadPool(10);
MarkSweepGarbageCollector gc = initGC(maxBlobGcInSecs, executor);
@@ -411,6 +435,7 @@ public class BlobGCTest {
try {
byte[] data = IOUtils.toByteArray(in);
String id = getIdForInputStream(new
ByteArrayInputStream(data));
+ id += "#" + data.length;
TestRecord rec = new TestRecord(id, data, clock.getTime());
store.put(id, rec);
log.info("Blob created {} with timestamp {}", rec.id,
rec.lastModified);
