You are viewing a plain text version of this content. The canonical link for it is here.
Posted to oak-commits@jackrabbit.apache.org by mr...@apache.org on 2017/02/14 17:04:28 UTC

svn commit: r1782991 - in /jackrabbit/oak/trunk/oak-core/src: main/java/org/apache/jackrabbit/oak/plugins/document/ main/java/org/apache/jackrabbit/oak/plugins/document/mongo/ main/java/org/apache/jackrabbit/oak/plugins/document/rdb/ test/java/org/apac...

Author: mreutegg
Date: Tue Feb 14 17:04:28 2017
New Revision: 1782991

URL: http://svn.apache.org/viewvc?rev=1782991&view=rev
Log:
OAK-5617: Metrics for DocumentStore.remove()

Modified:
    jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStats.java
    jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsCollector.java
    jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsMBean.java
    jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/mongo/MongoDocumentStore.java
    jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBDocumentStore.java
    jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsIT.java
    jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsTest.java

Modified: jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStats.java
URL: http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStats.java?rev=1782991&r1=1782990&r2=1782991&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStats.java (original)
+++ jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStats.java Tue Feb 14 17:04:28 2017
@@ -69,6 +69,9 @@ public class DocumentStoreStats implemen
     static final String NODES_UPDATE_RETRY_COUNT = "DOCUMENT_NODES_UPDATE_RETRY";
     static final String NODES_UPDATE_TIMER = "DOCUMENT_NODES_UPDATE_TIMER";
 
+    static final String NODES_REMOVE = "DOCUMENT_NODES_REMOVE";
+    static final String NODES_REMOVE_TIMER = "DOCUMENT_NODES_REMOVE_TIMER";
+
     static final String JOURNAL_QUERY = "DOCUMENT_JOURNAL_QUERY";
     static final String JOURNAL_CREATE = "DOCUMENT_JOURNAL_CREATE";
     static final String JOURNAL_QUERY_TIMER = "DOCUMENT_JOURNAL_QUERY_TIMER";
@@ -102,6 +105,8 @@ public class DocumentStoreStats implemen
     private final MeterStats createSplitNodeMeter;
     private final MeterStats updateNodeFailureMeter;
     private final MeterStats updateNodeRetryCountMeter;
+    private final MeterStats removeNodes;
+    private final TimerStats removeNodesTimer;
 
     public DocumentStoreStats(StatisticsProvider provider) {
         statisticsProvider = checkNotNull(provider);
@@ -137,6 +142,9 @@ public class DocumentStoreStats implemen
 
         queryNodesLock = provider.getMeter(NODES_QUERY_LOCK, StatsOptions.DEFAULT);
         queryNodesLockTimer = provider.getTimer(NODES_QUERY_LOCK_TIMER, StatsOptions.METRICS_ONLY);
+
+        removeNodes = provider.getMeter(NODES_REMOVE, StatsOptions.DEFAULT);
+        removeNodesTimer = provider.getTimer(NODES_REMOVE_TIMER, StatsOptions.METRICS_ONLY);
     }
 
     //~------------------------------------------< DocumentStoreStatsCollector >
@@ -268,6 +276,19 @@ public class DocumentStoreStats implemen
         perfLog(timeTakenNanos, "findAndModify [{}]", key);
     }
 
+    @Override
+    public void doneRemove(long timeTakenNanos,
+                           Collection<? extends Document> collection,
+                           int removeCount) {
+        if (collection == Collection.NODES) {
+            if (removeCount > 0) {
+                removeNodes.mark(removeCount);
+                removeNodesTimer.update(timeTakenNanos / removeCount, TimeUnit.NANOSECONDS);
+            }
+        }
+        perfLog(timeTakenNanos, "remove [{}]", removeCount);
+    }
+
     private void perfLog(long timeTakenNanos, String logMessagePrefix, Object... arguments){
         if (!perfLog.isDebugEnabled()){
             return;
@@ -313,6 +334,11 @@ public class DocumentStoreStats implemen
     }
 
     @Override
+    public long getNodesRemoveCount() {
+        return removeNodes.getCount();
+    }
+
+    @Override
     public long getJournalCreateCount() {
         return createJournal.getCount();
     }
@@ -387,6 +413,11 @@ public class DocumentStoreStats implemen
         return getTimeSeriesData(NODES_UPDATE_FAILURE, NODES_UPDATE_FAILURE);
     }
 
+    @Override
+    public CompositeData getRemoveNodesHistory() {
+        return getTimeSeriesData(NODES_REMOVE, NODES_REMOVE);
+    }
+
     private CompositeData getTimeSeriesData(String name, String desc){
         return TimeSeriesStatsUtil.asCompositeData(getTimeSeries(name), desc);
     }

Modified: jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsCollector.java
URL: http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsCollector.java?rev=1782991&r1=1782990&r2=1782991&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsCollector.java (original)
+++ jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsCollector.java Tue Feb 14 17:04:28 2017
@@ -92,4 +92,14 @@ public interface DocumentStoreStatsColle
      */
     void doneFindAndModify(long timeTakenNanos, Collection<? extends Document> collection, String key,
                            boolean newEntry, boolean success, int retryCount);
+
+    /**
+     * Called when a remove operation for documents was completed.
+     * @param timeTakenNanos time taken
+     * @param collection the collection
+     * @param removeCount the number of removed documents
+     */
+    void doneRemove(long timeTakenNanos,
+                    Collection<? extends Document> collection,
+                    int removeCount);
 }

Modified: jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsMBean.java
URL: http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsMBean.java?rev=1782991&r1=1782990&r2=1782991&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsMBean.java (original)
+++ jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsMBean.java Tue Feb 14 17:04:28 2017
@@ -38,6 +38,8 @@ public interface DocumentStoreStatsMBean
 
     long getNodesUpdateCount();
 
+    long getNodesRemoveCount();
+
     long getJournalCreateCount();
 
     long getJournalReadCount();
@@ -67,4 +69,6 @@ public interface DocumentStoreStatsMBean
     CompositeData getUpdateNodesRetryHistory();
 
     CompositeData getUpdateNodesFailureHistory();
+
+    CompositeData getRemoveNodesHistory();
 }

Modified: jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/mongo/MongoDocumentStore.java
URL: http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/mongo/MongoDocumentStore.java?rev=1782991&r1=1782990&r2=1782991&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/mongo/MongoDocumentStore.java (original)
+++ jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/mongo/MongoDocumentStore.java Tue Feb 14 17:04:28 2017
@@ -646,14 +646,14 @@ public class MongoDocumentStore implemen
     public <T extends Document> void remove(Collection<T> collection, String key) {
         log("remove", key);
         DBCollection dbCollection = getDBCollection(collection);
-        long start = PERFLOG.start();
+        Stopwatch watch = startWatch();
         try {
             dbCollection.remove(getByKeyQuery(key).get());
         } catch (Exception e) {
             throw DocumentStoreException.convert(e, "Remove failed for " + key);
         } finally {
             invalidateCache(collection, key);
-            PERFLOG.end(start, 1, "remove key={}", key);
+            stats.doneRemove(watch.elapsed(TimeUnit.NANOSECONDS), collection, 1);
         }
     }
 
@@ -661,7 +661,7 @@ public class MongoDocumentStore implemen
     public <T extends Document> void remove(Collection<T> collection, List<String> keys) {
         log("remove", keys);
         DBCollection dbCollection = getDBCollection(collection);
-        long start = PERFLOG.start();
+        Stopwatch watch = startWatch();
         try {
             for(List<String> keyBatch : Lists.partition(keys, IN_CLAUSE_BATCH_SIZE)){
                 DBObject query = QueryBuilder.start(Document.ID).in(keyBatch).get();
@@ -678,7 +678,7 @@ public class MongoDocumentStore implemen
                 }
             }
         } finally {
-            PERFLOG.end(start, 1, "remove keys={}", keys);
+            stats.doneRemove(watch.elapsed(TimeUnit.NANOSECONDS), collection, keys.size());
         }
     }
 
@@ -688,7 +688,7 @@ public class MongoDocumentStore implemen
         log("remove", toRemove);
         int num = 0;
         DBCollection dbCollection = getDBCollection(collection);
-        long start = PERFLOG.start();
+        Stopwatch watch = startWatch();
         try {
             List<String> batchIds = Lists.newArrayList();
             List<DBObject> batch = Lists.newArrayList();
@@ -716,7 +716,7 @@ public class MongoDocumentStore implemen
                 }
             }
         } finally {
-            PERFLOG.end(start, 1, "remove keys={}", toRemove);
+            stats.doneRemove(watch.elapsed(TimeUnit.NANOSECONDS), collection, num);
         }
         return num;
     }
@@ -728,7 +728,7 @@ public class MongoDocumentStore implemen
         log("remove", collection, indexedProperty, startValue, endValue);
         int num = 0;
         DBCollection dbCollection = getDBCollection(collection);
-        long start = PERFLOG.start();
+        Stopwatch watch = startWatch();
         try {
             QueryBuilder queryBuilder = QueryBuilder.start(indexedProperty);
             queryBuilder.greaterThan(startValue);
@@ -749,7 +749,7 @@ public class MongoDocumentStore implemen
                 }
             }
         } finally {
-            PERFLOG.end(start, 1, "remove from {}: {} in ({}, {})", collection, indexedProperty, startValue, endValue);
+            stats.doneRemove(watch.elapsed(TimeUnit.NANOSECONDS), collection, num);
         }
         return num;
     }

Modified: jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBDocumentStore.java
URL: http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBDocumentStore.java?rev=1782991&r1=1782990&r2=1782991&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBDocumentStore.java (original)
+++ jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBDocumentStore.java Tue Feb 14 17:04:28 2017
@@ -1531,6 +1531,7 @@ public class RDBDocumentStore implements
     private <T extends Document> void delete(Collection<T> collection, String id) {
         Connection connection = null;
         RDBTableMetaData tmd = getTable(collection);
+        Stopwatch watch = startWatch();
         try {
             connection = this.ch.getRWConnection();
             db.delete(connection, tmd, Collections.singletonList(id));
@@ -1539,6 +1540,7 @@ public class RDBDocumentStore implements
             throw handleException("removing " + id, ex, collection, id);
         } finally {
             this.ch.closeConnection(connection);
+            stats.doneRemove(watch.elapsed(TimeUnit.NANOSECONDS), collection, 1);
         }
     }
 
@@ -1547,6 +1549,7 @@ public class RDBDocumentStore implements
         RDBTableMetaData tmd = getTable(collection);
         for (List<String> sublist : Lists.partition(ids, 64)) {
             Connection connection = null;
+            Stopwatch watch = startWatch();
             try {
                 connection = this.ch.getRWConnection();
                 numDeleted += db.delete(connection, tmd, sublist);
@@ -1555,6 +1558,7 @@ public class RDBDocumentStore implements
                 throw handleException("removing " + ids, ex, collection, ids);
             } finally {
                 this.ch.closeConnection(connection);
+                stats.doneRemove(watch.elapsed(TimeUnit.NANOSECONDS), collection, ids.size());
             }
         }
         return numDeleted;
@@ -1571,15 +1575,19 @@ public class RDBDocumentStore implements
             subMap.put(entry.getKey(), entry.getValue());
             if (subMap.size() == 64 || !it.hasNext()) {
                 Connection connection = null;
+                int num = 0;
+                Stopwatch watch = startWatch();
                 try {
                     connection = this.ch.getRWConnection();
-                    numDeleted += db.delete(connection, tmd, subMap);
+                    num = db.delete(connection, tmd, subMap);
+                    numDeleted += num;
                     connection.commit();
                 } catch (Exception ex) {
                     Set<String> ids = subMap.keySet();
                     throw handleException("deleting " + ids, ex, collection, ids);
                 } finally {
                     this.ch.closeConnection(connection);
+                    stats.doneRemove(watch.elapsed(TimeUnit.NANOSECONDS), collection, num);
                 }
                 subMap.clear();
             }
@@ -1590,6 +1598,7 @@ public class RDBDocumentStore implements
     private <T extends Document> int deleteWithCondition(Collection<T> collection, List<QueryCondition> conditions) {
         int numDeleted = 0;
         RDBTableMetaData tmd = getTable(collection);
+        Stopwatch watch = startWatch();
         Connection connection = null;
         try {
             connection = this.ch.getRWConnection();
@@ -1599,6 +1608,7 @@ public class RDBDocumentStore implements
             throw DocumentStoreException.convert(ex, "deleting " + collection + ": " + conditions);
         } finally {
             this.ch.closeConnection(connection);
+            stats.doneRemove(watch.elapsed(TimeUnit.NANOSECONDS), collection, numDeleted);
         }
         return numDeleted;
     }

Modified: jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsIT.java
URL: http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsIT.java?rev=1782991&r1=1782990&r2=1782991&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsIT.java (original)
+++ jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsIT.java Tue Feb 14 17:04:28 2017
@@ -22,8 +22,14 @@ package org.apache.jackrabbit.oak.plugin
 import java.util.ArrayList;
 import java.util.Collections;
 import java.util.List;
+import java.util.Map;
 import java.util.UUID;
 
+import com.google.common.collect.Lists;
+import com.google.common.collect.Maps;
+
+import org.apache.jackrabbit.oak.plugins.document.UpdateOp.Condition;
+import org.apache.jackrabbit.oak.plugins.document.UpdateOp.Key;
 import org.apache.jackrabbit.oak.plugins.document.memory.MemoryDocumentStore;
 import org.apache.jackrabbit.oak.plugins.document.mongo.MongoDocumentStore;
 import org.apache.jackrabbit.oak.plugins.document.rdb.RDBDocumentStore;
@@ -33,6 +39,10 @@ import org.junit.Test;
 import org.junit.rules.TestName;
 
 import static java.util.Collections.singletonList;
+import static java.util.Collections.singletonMap;
+import static org.apache.jackrabbit.oak.plugins.document.NodeDocument.MODIFIED_IN_SECS;
+import static org.apache.jackrabbit.oak.plugins.document.NodeDocument.getModifiedInSecs;
+import static org.apache.jackrabbit.oak.plugins.document.UpdateOp.Condition.newEqualsCondition;
 import static org.junit.Assert.assertTrue;
 import static org.junit.Assume.assumeFalse;
 import static org.mockito.Matchers.anyInt;
@@ -143,6 +153,84 @@ public class DocumentStoreStatsIT extend
         verify(coll).doneFindAndModify(anyLong(), eq(Collection.NODES), eq(id), eq(false), eq(true), anyInt());
     }
 
+    @Test
+    public void removeSingle() throws Exception {
+        String id = testName.getMethodName();
+
+        UpdateOp up = new UpdateOp(id, true);
+        ds.create(Collection.NODES, singletonList(up));
+        removeMe.add(id);
+
+        DocumentStoreStatsCollector coll = mock(DocumentStoreStatsCollector.class);
+        configureStatsCollector(coll);
+
+        ds.remove(Collection.NODES, id);
+
+        verify(coll).doneRemove(anyLong(), eq(Collection.NODES), eq(1));
+    }
+
+    @Test
+    public void removeMultiple() throws Exception {
+        List<String> ids = Lists.newArrayList();
+        for (int i = 0; i < 10; i++) {
+            String id = testName.getMethodName() + "-" + i;
+            ids.add(id);
+            UpdateOp up = new UpdateOp(id, true);
+            ds.create(Collection.NODES, singletonList(up));
+            removeMe.add(id);
+        }
+
+        DocumentStoreStatsCollector coll = mock(DocumentStoreStatsCollector.class);
+        configureStatsCollector(coll);
+
+        ds.remove(Collection.NODES, ids);
+
+        verify(coll).doneRemove(anyLong(), eq(Collection.NODES), eq(10));
+    }
+
+    @Test
+    public void removeConditional() throws Exception {
+        Revision r = Revision.newRevision(1);
+        Key modified = new Key(MODIFIED_IN_SECS, null);
+        Condition c = newEqualsCondition(getModifiedInSecs(r.getTimestamp()));
+        Map<String, Map<Key, Condition>> ids = Maps.newHashMap();
+        for (int i = 0; i < 10; i++) {
+            String id = testName.getMethodName() + "-" + i;
+            ids.put(id, singletonMap(modified, c));
+            UpdateOp up = new UpdateOp(id, true);
+            NodeDocument.setModified(up, r);
+            ds.create(Collection.NODES, singletonList(up));
+            removeMe.add(id);
+        }
+
+        DocumentStoreStatsCollector coll = mock(DocumentStoreStatsCollector.class);
+        configureStatsCollector(coll);
+
+        ds.remove(Collection.NODES, ids);
+
+        verify(coll).doneRemove(anyLong(), eq(Collection.NODES), eq(10));
+    }
+
+    @Test
+    public void removeIndexProperty() throws Exception {
+        Revision r = new Revision(123456, 0, 1);
+        long mod = NodeDocument.getModifiedInSecs(r.getTimestamp());
+        for (int i = 0; i < 10; i++) {
+            String id = testName.getMethodName() + "-" + i;
+            UpdateOp up = new UpdateOp(id, true);
+            NodeDocument.setModified(up, r);
+            ds.create(Collection.NODES, singletonList(up));
+            removeMe.add(id);
+        }
+
+        DocumentStoreStatsCollector coll = mock(DocumentStoreStatsCollector.class);
+        configureStatsCollector(coll);
+
+        ds.remove(Collection.NODES, MODIFIED_IN_SECS, mod - 1, mod + 1);
+
+        verify(coll).doneRemove(anyLong(), eq(Collection.NODES), eq(10));
+    }
+
     private void configureStatsCollector(DocumentStoreStatsCollector stats) {
         if (ds instanceof MongoDocumentStore){
             ((MongoDocumentStore) ds).setStatsCollector(stats);

Modified: jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsTest.java
URL: http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsTest.java?rev=1782991&r1=1782990&r2=1782991&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsTest.java (original)
+++ jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/DocumentStoreStatsTest.java Tue Feb 14 17:04:28 2017
@@ -130,6 +130,15 @@ public class DocumentStoreStatsTest {
     }
 
     @Test
+    public void doneRemove() throws Exception {
+        stats.doneRemove(100, Collection.NODES, 42);
+        assertEquals(42, getMeter(DocumentStoreStats.NODES_REMOVE).getCount());
+
+        stats.doneRemove(100, Collection.NODES, 17);
+        assertEquals(59, getMeter(DocumentStoreStats.NODES_REMOVE).getCount());
+    }
+
+    @Test
     public void perfLog() throws Exception{
         String logName = DocumentStoreStats.class.getName() + ".perf";
         LogCustomizer customLogs = LogCustomizer.forLogger(logName)