You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@jackrabbit.apache.org by al...@apache.org on 2011/10/13 15:43:47 UTC
svn commit: r1182853 - in /jackrabbit/branches/2.2/jackrabbit-core: ./
src/main/java/org/apache/jackrabbit/core/cache/
src/main/java/org/apache/jackrabbit/core/persistence/bundle/
src/main/java/org/apache/jackrabbit/core/state/ src/test/java/org/apache...
Author: alexparvulescu
Date: Thu Oct 13 13:43:46 2011
New Revision: 1182853
URL: http://svn.apache.org/viewvc?rev=1182853&view=rev
Log:
JCR-3098 Add hit miss statistics and logging to caches
Modified:
jackrabbit/branches/2.2/jackrabbit-core/ (props changed)
jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/AbstractCache.java
jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/Cache.java
jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheAccessListener.java
jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheManager.java
jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/ConcurrentCache.java
jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/persistence/bundle/AbstractBundlePersistenceManager.java
jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/state/MLRUItemStateCache.java
jackrabbit/branches/2.2/jackrabbit-core/src/test/java/org/apache/jackrabbit/core/cache/ConcurrentCacheTest.java
Propchange: jackrabbit/branches/2.2/jackrabbit-core/
------------------------------------------------------------------------------
--- svn:mergeinfo (added)
+++ svn:mergeinfo Thu Oct 13 13:43:46 2011
@@ -0,0 +1,6 @@
+/jackrabbit/branches/1.5/jackrabbit-core:794012,794100,794102
+/jackrabbit/branches/JCR-2272/jackrabbit-core:1173165-1176545
+/jackrabbit/sandbox/JCR-1456/jackrabbit-core:774917-886178
+/jackrabbit/sandbox/JCR-2170/jackrabbit-core:812417-816332
+/jackrabbit/sandbox/tripod-JCR-2209/jackrabbit-core:795441-795863
+/jackrabbit/trunk/jackrabbit-core:1038201,1038203,1038205,1038657,1039064,1039347,1039408,1039422-1039423,1039888,1039946,1040033,1040090,1040459,1040601,1040606,1040661,1040958,1041379,1041439,1041761,1042643,1042647,1042978-1042982,1043084-1043086,1043088,1043343,1043357-1043358,1043430,1043554,1043616,1043618,1043637,1043656,1043893,1043897,1044239,1044312,1044451,1044613,1049473,1049491,1049514,1049518,1049520,1049859,1049870,1049874,1049878,1049880,1049883,1049889,1049891,1049894-1049895,1049899-1049901,1049909-1049911,1049915-1049916,1049919,1049923,1049925,1049931,1049936,1049939,1050212,1050298,1050346,1050551,1055068,1055070-1055071,1055116-1055117,1055127,1055134,1055164,1055498,1060431,1060434,1060753,1063756,1064670,1065599,1065622,1066059,1066071,1069831,1071562,1071573,1071680,1074140,1079314,1079317,1080186,1080540,1087304,1088991,1089032,1089053,1089436,1092106,1092117,1092683,1097363,1097513-1097514,1098963-1098964,1099033,1099172,1100242,1100286,1101046,110
2601,1104027,1128175,1130192,1130228,1132993,1136353,1136360,1138511,1141141,1141717,1143396,1143738,1144332,1144338,1144695,1152258,1155431,1157175,1165609,1173196,1174822,1174887,1175988,1176423,1176465,1176515,1176546,1177249,1177340,1179548,1180922,1182713,1182835
Modified: jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/AbstractCache.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/AbstractCache.java?rev=1182853&r1=1182852&r2=1182853&view=diff
==============================================================================
--- jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/AbstractCache.java (original)
+++ jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/AbstractCache.java Thu Oct 13 13:43:46 2011
@@ -65,6 +65,22 @@ public abstract class AbstractCache impl
private final AtomicLong accessCount = new AtomicLong();
/**
+ * Cache access counter. Unike his counterpart {@link #accessCount}, this
+ * does not get reset.
+ *
+ * It is used in the cases where a cache listener needs to call
+ * {@link Cache#resetAccessCount()}, but also needs a total access count. If
+ * you are sure that nobody calls reset, you can just use
+ * {@link #accessCount}.
+ */
+ private final AtomicLong totalAccessCount = new AtomicLong();
+
+ /**
+ * Cache miss counter.
+ */
+ private final AtomicLong missCount = new AtomicLong();
+
+ /**
* Cache access listener. Set in the
* {@link #setAccessListener(CacheAccessListener)} method and accessed
* by periodically by the {@link #recordCacheAccess()} method.
@@ -98,15 +114,20 @@ public abstract class AbstractCache impl
* interval has passed since the previous listener call.
*/
protected void recordCacheAccess() {
+ totalAccessCount.incrementAndGet();
long count = accessCount.incrementAndGet();
if (count % ACCESS_INTERVAL == 0) {
CacheAccessListener listener = accessListener.get();
if (listener != null) {
- listener.cacheAccessed();
+ listener.cacheAccessed(count);
}
}
}
+ protected void recordCacheMiss() {
+ missCount.incrementAndGet();
+ }
+
public long getAccessCount() {
return accessCount.get();
}
@@ -114,6 +135,18 @@ public abstract class AbstractCache impl
public void resetAccessCount() {
accessCount.set(0);
}
+
+ public long getTotalAccessCount(){
+ return totalAccessCount.get();
+ }
+
+ public long getMissCount() {
+ return missCount.get();
+ }
+
+ public void resetMissCount() {
+ missCount.set(0);
+ }
public long getMemoryUsed() {
return memoryUsed.get();
@@ -146,4 +179,25 @@ public abstract class AbstractCache impl
}
}
+ /**
+ * {@inheritDoc}
+ */
+ public String getCacheInfoAsString() {
+ long u = getMemoryUsed() / 1024;
+ long m = getMaxMemorySize() / 1024;
+ StringBuilder c = new StringBuilder();
+ c.append("cachename=");
+ c.append(this.toString());
+ c.append(", elements=");
+ c.append(getElementCount());
+ c.append(", usedmemorykb=");
+ c.append(u);
+ c.append(", maxmemorykb=");
+ c.append(m);
+ c.append(", access=");
+ c.append(getTotalAccessCount());
+ c.append(", miss=");
+ c.append(getMissCount());
+ return c.toString();
+ }
}
Modified: jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/Cache.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/Cache.java?rev=1182853&r1=1182852&r2=1182853&view=diff
==============================================================================
--- jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/Cache.java (original)
+++ jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/Cache.java Thu Oct 13 13:43:46 2011
@@ -45,7 +45,6 @@ public interface Cache {
* Get the number of accesses (get or set) until resetAccessCount was called.
* @return the count
*/
-
long getAccessCount();
/**
@@ -54,8 +53,37 @@ public interface Cache {
void resetAccessCount();
/**
+ * Get the total number of cache accesses.
+ * @return the number of hits
+ */
+ long getTotalAccessCount();
+
+ /**
+ * Get the number of cache misses.
+ *
+ * @return the number of misses
+ */
+ long getMissCount();
+
+ /**
+ * Reset the cache miss counter.
+ */
+ void resetMissCount();
+
+ /**
+ * Get the number of elements/objects in the cache.
+ * @return the number of elements
+ */
+ long getElementCount();
+
+ /**
* Add a listener to this cache that is informed after a number of accesses.
*/
void setAccessListener(CacheAccessListener listener);
+ /**
+ * Gathers the stats of the cache for logging.
+ */
+ String getCacheInfoAsString();
+
}
Modified: jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheAccessListener.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheAccessListener.java?rev=1182853&r1=1182852&r2=1182853&view=diff
==============================================================================
--- jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheAccessListener.java (original)
+++ jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheAccessListener.java Thu Oct 13 13:43:46 2011
@@ -28,9 +28,10 @@ public interface CacheAccessListener {
int ACCESS_INTERVAL = 127;
/**
- * The cache calls this method after a number of accessed.
+ * The cache calls this method after a number of accessed.<br>
+ * For statistical purposes, the cache access count is included
*/
- void cacheAccessed();
+ void cacheAccessed(long accessCount);
/**
* Called after the cache is no longer used.
Modified: jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheManager.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheManager.java?rev=1182853&r1=1182852&r2=1182853&view=diff
==============================================================================
--- jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheManager.java (original)
+++ jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/CacheManager.java Thu Oct 13 13:43:46 2011
@@ -17,6 +17,7 @@
package org.apache.jackrabbit.core.cache;
import java.util.ArrayList;
+import java.util.List;
import java.util.WeakHashMap;
import org.slf4j.Logger;
@@ -54,6 +55,9 @@ public class CacheManager implements Cac
/** The default minimum resize interval (in ms). */
private static final int DEFAULT_MIN_RESIZE_INTERVAL = 1000;
+ /** The default minimum stats logging interval (in ms). */
+ private static final int DEFAULT_LOG_STATS_INTERVAL = 60 * 1000;
+
/** The size of a big object, to detect if a cache is full or not. */
private static final int BIG_OBJECT_SIZE = 16 * 1024;
@@ -77,11 +81,21 @@ public class CacheManager implements Cac
"org.apache.jackrabbit.cacheResizeInterval",
DEFAULT_MIN_RESIZE_INTERVAL);
- /** The last time the caches where resized. */
+ /** The minimum interval time between stats are logged */
+ private long minLogStatsInterval = Long.getLong(
+ "org.apache.jackrabbit.cacheLogStatsInterval",
+ DEFAULT_LOG_STATS_INTERVAL);
+
+ /** The last time the caches where resized. */
private volatile long nextResize =
System.currentTimeMillis() + DEFAULT_MIN_RESIZE_INTERVAL;
+ /** The last time the cache stats were logged. */
+ private volatile long nextLogStats =
+ System.currentTimeMillis() + DEFAULT_LOG_STATS_INTERVAL;
+
+
public long getMaxMemory() {
return maxMemory;
}
@@ -118,7 +132,10 @@ public class CacheManager implements Cac
* After one of the caches is accessed a number of times, this method is called.
* Resize the caches if required.
*/
- public void cacheAccessed() {
+ public void cacheAccessed(long accessCount) {
+
+ logCacheStats();
+
long now = System.currentTimeMillis();
if (now < nextResize) {
return;
@@ -136,7 +153,23 @@ public class CacheManager implements Cac
}
/**
- * Re-calcualte the maximum memory for each cache, and set the new limits.
+ * Log info about the caches.
+ */
+ private void logCacheStats() {
+ if (log.isInfoEnabled()) {
+ long now = System.currentTimeMillis();
+ if (now < nextLogStats) {
+ return;
+ }
+ for (Cache cache : caches.keySet()) {
+ log.info(cache.getCacheInfoAsString());
+ }
+ nextLogStats = now + minLogStatsInterval;
+ }
+ }
+
+ /**
+ * Re-calculate the maximum memory for each cache, and set the new limits.
*/
private void resizeAll() {
if (log.isDebugEnabled()) {
@@ -146,11 +179,9 @@ public class CacheManager implements Cac
// entries in a weak hash map may disappear any time
// so can't use size() / keySet() directly
// only using the iterator guarantees that we don't get null references
- ArrayList<Cache> list = new ArrayList<Cache>();
+ List<Cache> list = new ArrayList<Cache>();
synchronized (caches) {
- for (Cache c: caches.keySet()) {
- list.add(c);
- }
+ list.addAll(caches.keySet());
}
if (list.size() == 0) {
// nothing to do
Modified: jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/ConcurrentCache.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/ConcurrentCache.java?rev=1182853&r1=1182852&r2=1182853&view=diff
==============================================================================
--- jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/ConcurrentCache.java (original)
+++ jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/cache/ConcurrentCache.java Thu Oct 13 13:43:46 2011
@@ -57,10 +57,12 @@ public class ConcurrentCache<K, V> exten
}
+ private final String name;
private final Map<K, E<V>>[] segments;
@SuppressWarnings({ "unchecked", "serial" })
- public ConcurrentCache(int numberOfSegments) {
+ public ConcurrentCache(String name, int numberOfSegments) {
+ this.name = name;
this.segments = new Map[numberOfSegments];
for (int i = 0; i < segments.length; i++) {
segments[i] = new LinkedHashMap<K, E<V>>(16, 0.75f, true) {
@@ -77,8 +79,8 @@ public class ConcurrentCache<K, V> exten
}
}
- public ConcurrentCache() {
- this(DEFAULT_NUMBER_OF_SEGMENTS);
+ public ConcurrentCache(String name) {
+ this(name, DEFAULT_NUMBER_OF_SEGMENTS);
}
/**
@@ -124,10 +126,10 @@ public class ConcurrentCache<K, V> exten
E<V> entry = segment.get(key);
if (entry != null) {
return entry.value;
- } else {
- return null;
}
}
+ recordCacheMiss();
+ return null;
}
/**
@@ -252,4 +254,17 @@ public class ConcurrentCache<K, V> exten
}
}
+ public long getElementCount() {
+ long count = 0;
+ for (int i = 0; i < segments.length; i++) {
+ count += segments[i].size();
+ }
+ return count;
+ }
+
+ @Override
+ public String toString() {
+ return name + "[" + getClass().getSimpleName() + "@"
+ + Integer.toHexString(hashCode()) + "]";
+ }
}
Modified: jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/persistence/bundle/AbstractBundlePersistenceManager.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/persistence/bundle/AbstractBundlePersistenceManager.java?rev=1182853&r1=1182852&r2=1182853&view=diff
==============================================================================
--- jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/persistence/bundle/AbstractBundlePersistenceManager.java (original)
+++ jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/persistence/bundle/AbstractBundlePersistenceManager.java Thu Oct 13 13:43:46 2011
@@ -28,6 +28,8 @@ import javax.jcr.PropertyType;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
+import org.apache.jackrabbit.core.cache.Cache;
+import org.apache.jackrabbit.core.cache.CacheAccessListener;
import org.apache.jackrabbit.core.cache.ConcurrentCache;
import org.apache.jackrabbit.core.fs.FileSystemResource;
import org.apache.jackrabbit.core.fs.FileSystem;
@@ -82,7 +84,7 @@ import org.apache.jackrabbit.spi.Name;
* </ul>
*/
public abstract class AbstractBundlePersistenceManager implements
- PersistenceManager, CachingPersistenceManager, IterablePersistenceManager {
+ PersistenceManager, CachingPersistenceManager, IterablePersistenceManager, CacheAccessListener {
/** the default logger */
private static Logger log = LoggerFactory.getLogger(AbstractBundlePersistenceManager.class);
@@ -112,6 +114,18 @@ public abstract class AbstractBundlePers
/** the cache of loaded bundles */
private ConcurrentCache<NodeId, NodePropBundle> bundles;
+ /** The default minimum stats logging interval (in ms). */
+ private static final int DEFAULT_LOG_STATS_INTERVAL = 60 * 1000;
+
+ /** The minimum interval time between stats are logged */
+ private long minLogStatsInterval = Long.getLong(
+ "org.apache.jackrabbit.cacheLogStatsInterval",
+ DEFAULT_LOG_STATS_INTERVAL);
+
+ /** The last time the cache stats were logged. */
+ private volatile long nextLogStats =
+ System.currentTimeMillis() + DEFAULT_LOG_STATS_INTERVAL;
+
/** the persistence manager context */
protected PMContext context;
@@ -377,8 +391,9 @@ public abstract class AbstractBundlePers
public void init(PMContext context) throws Exception {
this.context = context;
// init bundle cache
- bundles = new ConcurrentCache<NodeId, NodePropBundle>();
+ bundles = new ConcurrentCache<NodeId, NodePropBundle>(context.getHomeDir().getName() + "BundleCache");
bundles.setMaxMemorySize(bundleCacheSize);
+ bundles.setAccessListener(this);
}
/**
@@ -709,4 +724,22 @@ public abstract class AbstractBundlePers
bundles.remove(id);
}
+ public void cacheAccessed(long accessCount) {
+ logCacheStats();
+ }
+
+ private void logCacheStats() {
+ if (log.isInfoEnabled()) {
+ long now = System.currentTimeMillis();
+ if (now < nextLogStats) {
+ return;
+ }
+ log.info(bundles.getCacheInfoAsString());
+ nextLogStats = now + minLogStatsInterval;
+ }
+ }
+
+ public void disposeCache(Cache cache) {
+ // NOOP
+ }
}
Modified: jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/state/MLRUItemStateCache.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/state/MLRUItemStateCache.java?rev=1182853&r1=1182852&r2=1182853&view=diff
==============================================================================
--- jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/state/MLRUItemStateCache.java (original)
+++ jackrabbit/branches/2.2/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/state/MLRUItemStateCache.java Thu Oct 13 13:43:46 2011
@@ -45,7 +45,7 @@ public class MLRUItemStateCache implemen
private volatile long numWrites = 0;
private final ConcurrentCache<ItemId, ItemState> cache =
- new ConcurrentCache<ItemId, ItemState>();
+ new ConcurrentCache<ItemId, ItemState>(MLRUItemStateCache.class.getSimpleName());
public MLRUItemStateCache(CacheManager cacheMgr) {
cache.setMaxMemorySize(DEFAULT_MAX_MEM);
Modified: jackrabbit/branches/2.2/jackrabbit-core/src/test/java/org/apache/jackrabbit/core/cache/ConcurrentCacheTest.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.2/jackrabbit-core/src/test/java/org/apache/jackrabbit/core/cache/ConcurrentCacheTest.java?rev=1182853&r1=1182852&r2=1182853&view=diff
==============================================================================
--- jackrabbit/branches/2.2/jackrabbit-core/src/test/java/org/apache/jackrabbit/core/cache/ConcurrentCacheTest.java (original)
+++ jackrabbit/branches/2.2/jackrabbit-core/src/test/java/org/apache/jackrabbit/core/cache/ConcurrentCacheTest.java Thu Oct 13 13:43:46 2011
@@ -37,7 +37,7 @@ public class ConcurrentCacheTest extends
}
ConcurrentCache<NodeId, NodeId> cache =
- new ConcurrentCache<NodeId, NodeId>();
+ new ConcurrentCache<NodeId, NodeId>("test");
cache.setMaxMemorySize(ids.length / 2);
for (int i = 0; i < ids.length; i++) {