Author: mreutegg
Date: Thu Nov 24 08:59:01 2016
New Revision: 1771089
URL: http://svn.apache.org/viewvc?rev=1771089&view=rev
Log:
OAK-5150: Log stats for JournalDiffLoader
Merged revision 1771022 from trunk
Modified:
jackrabbit/oak/branches/1.4/ (props changed)
jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalDiffLoader.java
jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalEntry.java
Propchange: jackrabbit/oak/branches/1.4/
------------------------------------------------------------------------------
--- svn:mergeinfo (original)
+++ svn:mergeinfo Thu Nov 24 08:59:01 2016
@@ -1,3 +1,3 @@
/jackrabbit/oak/branches/1.0:1665962
-/jackrabbit/oak/trunk:1733615,1733875,1733913,1733929,1734230,1734254,1734279,1734941,1735052,1735081,1735109,1735141,1735267,1735405,1735484,1735549,1735564,1735588,1735622,1735638,1735919,1735983,1736176,1737309-1737310,1737334,1737349,1737998,1738004,1738136,1738138,1738207,1738234,1738252,1738775,1738795,1738833,1738950,1738957,1738963,1739712,1739760,1739867,1739894,1739959-1739960,1740114,1740116,1740250,1740333,1740349,1740360,1740625-1740626,1740774,1740837,1740879,1740971,1741016,1741032,1741339,1741343,1742077,1742117,1742125,1742363,1742520,1742888,1742916,1743097,1743172,1743343,1743674,1744265,1744292,1744589,1744670,1744672,1744959,1745038,1745127,1745197,1745336,1745368,1746086,1746117,1746342,1746345,1746408,1746696,1746981,1747198,1747200,1747341-1747342,1747380,1747387,1747406,1747492,1747512,1747654,1748505,1748553,1748722,1748870,1749275,1749350,1749424,1749443,1749464,1749475,1749645,1749662,1749815,1749872,1749875,1749899,1750052,1750076-1750077,1750287,1750457
,1750462,1750465,1750495,1750626,1750809,1750886,1751410,1751445-1751446,1751478,1751753,1751755,1751871,1752198,1752202,1752259,1752273-1752274,1752283,1752292,1752438,1752447-1752448,1752508,1752596,1752616,1752659,1752672,1753262,1753331-1753332,1753335-1753336,1753355,1753444,1754117,1754239,1755157,1755191,1756520,1756580,1757119,1757166,1758213,1758713,1759433,1759795,1759826,1760326,1760340,1760373,1760387,1760486,1760492,1760494,1760661-1760662,1761412,1761444,1761571,1761762,1761787,1761876,1762453,1762612,1762632,1762635,1763347,1763355-1763356,1763378,1763465,1763735,1764678,1764705,1764814,1764898,1765817,1765983,1766071,1766423,1766496,1766519,1766554,1766644,1767265,1768446,1768637,1770982
+/jackrabbit/oak/trunk:1733615,1733875,1733913,1733929,1734230,1734254,1734279,1734941,1735052,1735081,1735109,1735141,1735267,1735405,1735484,1735549,1735564,1735588,1735622,1735638,1735919,1735983,1736176,1737309-1737310,1737334,1737349,1737998,1738004,1738136,1738138,1738207,1738234,1738252,1738775,1738795,1738833,1738950,1738957,1738963,1739712,1739760,1739867,1739894,1739959-1739960,1740114,1740116,1740250,1740333,1740349,1740360,1740625-1740626,1740774,1740837,1740879,1740971,1741016,1741032,1741339,1741343,1742077,1742117,1742125,1742363,1742520,1742888,1742916,1743097,1743172,1743343,1743674,1744265,1744292,1744589,1744670,1744672,1744959,1745038,1745127,1745197,1745336,1745368,1746086,1746117,1746342,1746345,1746408,1746696,1746981,1747198,1747200,1747341-1747342,1747380,1747387,1747406,1747492,1747512,1747654,1748505,1748553,1748722,1748870,1749275,1749350,1749424,1749443,1749464,1749475,1749645,1749662,1749815,1749872,1749875,1749899,1750052,1750076-1750077,1750287,1750457
,1750462,1750465,1750495,1750626,1750809,1750886,1751410,1751445-1751446,1751478,1751753,1751755,1751871,1752198,1752202,1752259,1752273-1752274,1752283,1752292,1752438,1752447-1752448,1752508,1752596,1752616,1752659,1752672,1753262,1753331-1753332,1753335-1753336,1753355,1753444,1754117,1754239,1755157,1755191,1756520,1756580,1757119,1757166,1758213,1758713,1759433,1759795,1759826,1760326,1760340,1760373,1760387,1760486,1760492,1760494,1760661-1760662,1761412,1761444,1761571,1761762,1761787,1761876,1762453,1762612,1762632,1762635,1763347,1763355-1763356,1763378,1763465,1763735,1764678,1764705,1764814,1764898,1765817,1765983,1766071,1766423,1766496,1766519,1766554,1766644,1767265,1768446,1768637,1770982,1771022
/jackrabbit/trunk:1345480
Modified:
jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalDiffLoader.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalDiffLoader.java?rev=1771089&r1=1771088&r2=1771089&view=diff
==============================================================================
---
jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalDiffLoader.java
(original)
+++
jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalDiffLoader.java
Thu Nov 24 08:59:01 2016
@@ -18,17 +18,22 @@ package org.apache.jackrabbit.oak.plugin
import java.io.IOException;
import java.util.Map;
+import java.util.concurrent.TimeUnit;
import javax.annotation.CheckForNull;
import javax.annotation.Nonnull;
import javax.annotation.Nullable;
+import com.google.common.base.Stopwatch;
+
import org.apache.jackrabbit.oak.cache.CacheStats;
import org.apache.jackrabbit.oak.commons.sort.StringSort;
+import org.apache.jackrabbit.oak.plugins.document.util.StringValue;
import org.apache.jackrabbit.oak.plugins.document.util.Utils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
+import static org.apache.commons.io.FileUtils.byteCountToDisplaySize;
import static org.apache.jackrabbit.oak.plugins.document.JournalEntry.asId;
import static
org.apache.jackrabbit.oak.plugins.document.JournalEntry.fillExternalChanges;
@@ -45,6 +50,8 @@ class JournalDiffLoader implements DiffC
private final DocumentNodeStore ns;
+ private Stats stats;
+
JournalDiffLoader(@Nonnull AbstractDocumentNodeState base,
@Nonnull AbstractDocumentNodeState node,
@Nonnull DocumentNodeStore ns) {
@@ -55,6 +62,7 @@ class JournalDiffLoader implements DiffC
@Override
public String call() {
+ stats = new Stats();
RevisionVector afterRev = node.getRootRevision();
RevisionVector beforeRev = base.getRootRevision();
@@ -78,7 +86,7 @@ class JournalDiffLoader implements DiffC
changes.sort();
DiffCache df = ns.getDiffCache();
- WrappedDiffCache wrappedCache = new
WrappedDiffCache(node.getPath(), df);
+ WrappedDiffCache wrappedCache = new
WrappedDiffCache(node.getPath(), df, stats);
JournalEntry.applyTo(changes, wrappedCache, beforeRev, afterRev);
return wrappedCache.changes;
@@ -86,6 +94,7 @@ class JournalDiffLoader implements DiffC
throw DocumentStoreException.convert(e);
} finally {
Utils.closeIfCloseable(changes);
+ logStats();
}
}
@@ -108,6 +117,7 @@ class JournalDiffLoader implements DiffC
JournalEntry entry = store.find(Collection.JOURNAL, asId(br));
if (entry != null) {
entry.addTo(changes);
+ stats.numJournalEntries++;
} else {
LOG.warn("Missing journal entry for {}", asId(br));
}
@@ -141,13 +151,14 @@ class JournalDiffLoader implements DiffC
// use revision with a timestamp of zero
from = new Revision(0, 0, to.getClusterId());
}
- fillExternalChanges(changes, from, to, ns.getDocumentStore());
+ stats.numJournalEntries += fillExternalChanges(changes, from, to,
ns.getDocumentStore());
}
// do we need to include changes from pending local changes?
if (!max.isRevisionNewer(localLastRev)
&& !localLastRev.equals(max.getRevision(clusterId))) {
// journal does not contain all local changes
localPending.addTo(changes);
+ stats.numJournalEntries++;
}
}
@@ -171,15 +182,50 @@ class JournalDiffLoader implements DiffC
throw new IllegalStateException("Missing branch for revision " + rv);
}
+ private void logStats() {
+ stats.sw.stop();
+ long timeInSec = stats.sw.elapsed(TimeUnit.SECONDS);
+ if (timeInSec > 60) {
+ LOG.warn(stats.toString());
+ } else if (timeInSec > 10) {
+ LOG.info(stats.toString());
+ } else {
+ LOG.debug(stats.toString());
+ }
+ }
+
+ private static class Stats {
+
+ private final Stopwatch sw = Stopwatch.createStarted();
+ private long numJournalEntries;
+ private long numDiffEntries;
+ private long keyMemory;
+ private long valueMemory;
+
+ @Override
+ public String toString() {
+ String msg = "%d diffs loaded from %d journal entries in %s. " +
+ "Keys: %s, values: %s, total: %s";
+ return String.format(msg, numDiffEntries, numJournalEntries, sw,
+ byteCountToDisplaySize(keyMemory),
+ byteCountToDisplaySize(valueMemory),
+ byteCountToDisplaySize(keyMemory + valueMemory));
+ }
+ }
+
private static class WrappedDiffCache extends DiffCache {
private final String path;
private String changes = "";
private final DiffCache cache;
+ private Stats stats;
- WrappedDiffCache(String path, DiffCache cache) {
+ WrappedDiffCache(String path,
+ DiffCache cache,
+ Stats stats) {
this.path = path;
this.cache = cache;
+ this.stats = stats;
}
@CheckForNull
@@ -197,14 +243,15 @@ class JournalDiffLoader implements DiffC
@Nonnull
@Override
- Entry newEntry(@Nonnull RevisionVector from,
- @Nonnull RevisionVector to,
+ Entry newEntry(@Nonnull final RevisionVector from,
+ @Nonnull final RevisionVector to,
boolean local) {
final Entry entry = cache.newEntry(from, to, local);
return new Entry() {
@Override
public void append(@Nonnull String path,
@Nonnull String changes) {
+ trackStats(path, from, to, changes);
entry.append(path, changes);
if (path.equals(WrappedDiffCache.this.path)) {
WrappedDiffCache.this.changes = changes;
@@ -218,6 +265,17 @@ class JournalDiffLoader implements DiffC
};
}
+ private void trackStats(String path,
+ RevisionVector from,
+ RevisionVector to,
+ String changes) {
+ stats.numDiffEntries++;
+ stats.keyMemory += new StringValue(path).getMemory();
+ stats.keyMemory += from.getMemory();
+ stats.keyMemory += to.getMemory();
+ stats.valueMemory += new StringValue(changes).getMemory();
+ }
+
@Nonnull
@Override
Iterable<CacheStats> getStats() {
Modified:
jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalEntry.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalEntry.java?rev=1771089&r1=1771088&r2=1771089&view=diff
==============================================================================
---
jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalEntry.java
(original)
+++
jackrabbit/oak/branches/1.4/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/JournalEntry.java
Thu Nov 24 08:59:01 2016
@@ -188,9 +188,10 @@ public final class JournalEntry extends
* @param from the lower bound of the revision range (exclusive).
* @param to the upper bound of the revision range (inclusive).
* @param store the document store to query.
+ * @return the number of journal entries read from the store.
* @throws IOException
*/
- static void fillExternalChanges(@Nonnull StringSort sorter,
+ static int fillExternalChanges(@Nonnull StringSort sorter,
@Nonnull Revision from,
@Nonnull Revision to,
@Nonnull DocumentStore store)
@@ -198,7 +199,7 @@ public final class JournalEntry extends
checkArgument(checkNotNull(from).getClusterId() ==
checkNotNull(to).getClusterId());
if (from.compareRevisionTime(to) >= 0) {
- return;
+ return 0;
}
// to is inclusive, but DocumentStore.query() toKey is exclusive
@@ -248,8 +249,10 @@ public final class JournalEntry extends
String maxId = asId(new Revision(Long.MAX_VALUE, 0,
to.getClusterId()));
for (JournalEntry d : store.query(JOURNAL, inclusiveToId, maxId,
1)) {
d.addTo(sorter);
+ numEntries++;
}
}
+ return numEntries;
}
long getRevisionTimestamp() {
