Merged BRANCHES/DEV/mward/head_cachestats to HEAD:

89575: ACE-3327: Work In Progress. TX cache statistics.
   89642: ACE-3327: Exposes statistics through JMX. Adds hit ratio.
   89649: ACE-3327: Added "@since 5.0" to new classes.
   89691: ACE-3327: improved TransactionalCache stats tests.
   89743: ACE-3327: fixed lack of thread safety for InMemoryCacheStatistics.
   89752: ACE-3327: now possible to disable/enable tx cache statistics per-cache with properties.



git-svn-id: https://svn.alfresco.com/repos/alfresco-enterprise/alfresco/HEAD/root@89798 c4b6b30b-aa2e-2d43-bbcb-ca4b014f7261

source/java/org/alfresco/repo/cache/CacheStatistics.java

@@ -0,0 +1,67 @@
+/*
+ * Copyright (C) 2005-2014 Alfresco Software Limited.
+ *
+ * This file is part of Alfresco
+ *
+ * Alfresco is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Lesser General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * Alfresco is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public License
+ * along with Alfresco. If not, see <http://www.gnu.org/licenses/>.
+ */
+package org.alfresco.repo.cache;
+
+import org.alfresco.repo.cache.TransactionStats.OpType;
+
+/**
+ * Centralised cache statistics service. Transactional caches participating
+ * in statistical collection will provide their data to this service using the
+ * {@link #add(String, TransactionStats)} method. The data is then aggregated
+ * so that, for example, the hit ratio for a particular cache may be retrieved.
+ * 
+ * @since 5.0
+ * @author Matt Ward
+ */
+public interface CacheStatistics
+{
+    /**
+     * Add new details to the system wide cache statistics.
+     */
+    void add(String cacheName, TransactionStats stats);
+    
+    /**
+     * Get the number of occurrences of the given operation type,
+     * retrieve the number of cache hits that have happened to the cache.
+     * 
+     * @param cacheName Name of the cache.
+     * @param opType    Type of cache operation.
+     * @return long count
+     */
+    long count(String cacheName, OpType opType);
+    
+    /**
+     * The mean time in nanoseconds for all operations of the given type.
+     * 
+     * @param cacheName  The cache name.
+     * @param opType     Type of operation, e.g. cache hits.
+     * @return Time in nanos (double) or NaN if not available yet.
+     */
+    double meanTime(String cacheName, OpType opType);
+    
+    /**
+     * The hit ratio for the given cache, where 1.0 is the maximum possible
+     * value and 0.0 represents a cache that has never successfully
+     * returned a previously cached value. 
+     * 
+     * @param cacheName  The cache name.
+     * @return ratio (double)
+     */
+    double hitMissRatio(String cacheName); 
+}

source/java/org/alfresco/repo/cache/CacheStatisticsCreated.java

@@ -0,0 +1,51 @@
+/*
+ * Copyright (C) 2005-2014 Alfresco Software Limited.
+ *
+ * This file is part of Alfresco
+ *
+ * Alfresco is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Lesser General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * Alfresco is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public License
+ * along with Alfresco. If not, see <http://www.gnu.org/licenses/>.
+ */
+package org.alfresco.repo.cache;
+
+import org.springframework.context.ApplicationEvent;
+
+/**
+ * Signal that cache statistics have been registered for the given cache.
+ * 
+ * @since 5.0
+ * @author Matt Ward
+ */
+public class CacheStatisticsCreated extends ApplicationEvent
+{
+    private static final long serialVersionUID = 1L;
+    private final CacheStatistics cacheStats;
+    private final String cacheName;
+    
+    public CacheStatisticsCreated(CacheStatistics cacheStats, String cacheName)
+    {
+        super(cacheStats);
+        this.cacheStats = cacheStats;
+        this.cacheName = cacheName;
+    }
+
+    public CacheStatistics getCacheStats()
+    {
+        return this.cacheStats;
+    }
+
+    public String getCacheName()
+    {
+        return this.cacheName;
+    }
+}

source/java/org/alfresco/repo/cache/InMemoryCacheStatistics.java

@@ -0,0 +1,240 @@
+/*
+ * Copyright (C) 2005-2014 Alfresco Software Limited.
+ *
+ * This file is part of Alfresco
+ *
+ * Alfresco is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Lesser General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * Alfresco is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public License
+ * along with Alfresco. If not, see <http://www.gnu.org/licenses/>.
+ */
+package org.alfresco.repo.cache;
+
+import java.util.HashMap;
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.ConcurrentMap;
+import java.util.concurrent.locks.ReentrantReadWriteLock;
+import java.util.concurrent.locks.ReentrantReadWriteLock.ReadLock;
+import java.util.concurrent.locks.ReentrantReadWriteLock.WriteLock;
+
+import org.alfresco.repo.cache.TransactionStats.OpType;
+import org.apache.commons.math3.stat.descriptive.SummaryStatistics;
+import org.springframework.beans.BeansException;
+import org.springframework.context.ApplicationContext;
+import org.springframework.context.ApplicationContextAware;
+
+/**
+ * Simple non-persistent implementation of {@link CacheStatistics}. Statistics
+ * are empty at repository startup.
+ * 
+ * @since 5.0
+ * @author Matt Ward
+ */
+public class InMemoryCacheStatistics implements CacheStatistics, ApplicationContextAware
+{
+    /** Read/Write locks by cache name */
+    private final ConcurrentMap<String, ReentrantReadWriteLock> locks = new ConcurrentHashMap<>();
+    private Map<String, Map<OpType, OperationStats>> cacheToStatsMap = new HashMap<>();
+    private ApplicationContext applicationContext;
+    
+    
+    @Override
+    public long count(String cacheName, OpType opType)
+    {
+        ReadLock readLock = getReadLock(cacheName);
+        readLock.lock();
+        try
+        {
+            Map<OpType, OperationStats> cacheStats = cacheToStatsMap.get(cacheName);
+            if (cacheStats == null)
+            {
+                throw new NoStatsForCache(cacheName);
+            }
+            OperationStats opStats = cacheStats.get(opType);
+            return opStats.count;
+        }
+        finally
+        {
+            readLock.unlock();
+        }
+    }
+
+    @Override
+    public double meanTime(String cacheName, OpType opType)
+    {
+        ReadLock readLock = getReadLock(cacheName);
+        readLock.lock();
+        try
+        {
+            Map<OpType, OperationStats> cacheStats = cacheToStatsMap.get(cacheName);
+            if (cacheStats == null)
+            {
+                throw new NoStatsForCache(cacheName);
+            }
+            OperationStats opStats = cacheStats.get(opType);
+            return opStats.meanTime();
+        }
+        finally
+        {
+            readLock.unlock();
+        }
+    }
+
+    @Override
+    public void add(String cacheName, TransactionStats txStats)
+    {
+        boolean registerCacheStats = false;
+        WriteLock writeLock = getWriteLock(cacheName);
+        writeLock.lock();
+        try
+        {
+            // Are we adding new stats for a previously unseen cache?
+            registerCacheStats = !cacheToStatsMap.containsKey(cacheName);
+            if (registerCacheStats)
+            {
+                // There are no statistics yet for this cache. 
+                cacheToStatsMap.put(cacheName, new HashMap<OpType, OperationStats>());
+            }
+            Map<OpType, OperationStats> cacheStats = cacheToStatsMap.get(cacheName);
+            
+            for (OpType opType : OpType.values())
+            {                
+                SummaryStatistics txOpSummary = txStats.getTimings(opType);
+                long count = txOpSummary.getN();
+                double totalTime = txOpSummary.getSum();
+                    
+                OperationStats oldStats = cacheStats.get(opType);
+                OperationStats newStats;
+                if (oldStats == null)
+                {
+                    newStats = new OperationStats(totalTime, count);
+                }
+                else
+                {
+                    newStats = new OperationStats(oldStats, totalTime, count);
+                }
+                cacheStats.put(opType, newStats);
+            }
+        }
+        finally
+        {
+            writeLock.unlock();
+        }
+        
+        if (registerCacheStats)
+        {
+            // We've added stats for a previously unseen cache, raise an event
+            // so that an MBean for the cache may be registered, for example. 
+            applicationContext.publishEvent(new CacheStatisticsCreated(this, cacheName));
+        }
+    }
+    
+    @Override
+    public double hitMissRatio(String cacheName)
+    {
+        ReadLock readLock = getReadLock(cacheName);
+        readLock.lock();
+        try
+        {
+            Map<OpType, OperationStats> cacheStats = cacheToStatsMap.get(cacheName);
+            if (cacheStats == null)
+            {
+                throw new NoStatsForCache(cacheName);
+            }
+            long hits = cacheStats.get(OpType.GET_HIT).count;
+            long misses = cacheStats.get(OpType.GET_MISS).count;
+            return (double)hits / (hits+misses);
+        }
+        finally
+        {
+            readLock.unlock();
+        }
+    }
+
+    /**
+     * Represents a single cache operation type's statistics.
+     */
+    private static final class OperationStats
+    {
+        /** Total time spent in operations of this type */
+        private final double totalTime;
+        /** Count of how many instances of this operation occurred. */
+        private final long count;
+        
+        public OperationStats(double totalTime, long count)
+        {
+            this.totalTime = totalTime;
+            this.count = count;
+        }
+        
+        public OperationStats(OperationStats source, double totalTime, long count)
+        {
+            if (Double.compare(source.totalTime, Double.NaN) == 0)
+            {
+                // No previous time to add new time to.
+                this.totalTime = totalTime;
+            }
+            else
+            {
+                this.totalTime = source.totalTime + totalTime;
+            }
+            this.count = source.count + count;
+        }
+        
+        public double meanTime()
+        {
+            return totalTime / count;
+        }
+    }
+
+    @Override
+    public void setApplicationContext(ApplicationContext applicationContext) throws BeansException
+    {
+        this.applicationContext = applicationContext;
+    }
+    
+    
+    /**
+     * Gets a {@link ReentrantReadWriteLock} for a specific cache, lazily
+     * creating the lock if necessary. Locks may be created per cache
+     * (rather than hashing to a smaller pool) since the number of
+     * caches is not too large.
+     * 
+     * @param cacheName  Cache name to obtain lock for.
+     * @return ReentrantReadWriteLock
+     */
+    private ReentrantReadWriteLock getLock(String cacheName)
+    {
+        if (!locks.containsKey(cacheName))
+        {
+            ReentrantReadWriteLock newLock = new ReentrantReadWriteLock();
+            if (locks.putIfAbsent(cacheName, newLock) == null)
+            {
+                // Lock was successfully added to map.
+                return newLock;
+            };
+        }
+        return locks.get(cacheName);
+    }
+    
+    private ReadLock getReadLock(String cacheName)
+    {
+        ReadLock readLock = getLock(cacheName).readLock();
+        return readLock;
+    }
+    
+    private WriteLock getWriteLock(String cacheName)
+    {
+        WriteLock writeLock = getLock(cacheName).writeLock();
+        return writeLock;
+    }
+}

source/java/org/alfresco/repo/cache/NoOpCacheStatistics.java

@@ -0,0 +1,56 @@
+/*
+ * Copyright (C) 2005-2014 Alfresco Software Limited.
+ *
+ * This file is part of Alfresco
+ *
+ * Alfresco is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Lesser General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * Alfresco is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public License
+ * along with Alfresco. If not, see <http://www.gnu.org/licenses/>.
+ */
+package org.alfresco.repo.cache;
+
+import org.alfresco.repo.cache.TransactionStats.OpType;
+
+/**
+ * A do-nothing implementation of {@link CacheStatistics}. Used
+ * by the {@link TransactionalCache} if it is not explicitly
+ * injected with an implementation.
+ * 
+ * @since 5.0
+ * @author Matt Ward
+ */
+public class NoOpCacheStatistics implements CacheStatistics
+{
+    @Override
+    public void add(String cacheName, TransactionStats stats)
+    {
+        // Does nothing
+    }
+
+    @Override
+    public long count(String cacheName, OpType opType)
+    {
+        return 0;
+    }
+
+    @Override
+    public double meanTime(String cacheName, OpType opType)
+    {
+        return Double.NaN;
+    }
+
+    @Override
+    public double hitMissRatio(String cacheName)
+    {
+        return Double.NaN;
+    }
+}

source/java/org/alfresco/repo/cache/NoStatsForCache.java

@@ -0,0 +1,26 @@
+package org.alfresco.repo.cache;
+
+/**
+ * Read operations on {@link CacheStatistics} throw this
+ * RuntimeException when no statistics exist for the
+ * specified cache.
+ * 
+ * @since 5.0
+ * @author Matt Ward
+ */
+public class NoStatsForCache extends RuntimeException
+{
+    private static final long serialVersionUID = 1L;
+    private final String cacheName;
+    
+    public NoStatsForCache(String cacheName)
+    {
+        super("No statistics have been calculated for cache ["+cacheName+"]");
+        this.cacheName = cacheName;
+    }
+
+    public String getCacheName()
+    {
+        return this.cacheName;
+    }
+}

source/java/org/alfresco/repo/cache/TransactionStats.java

@@ -0,0 +1,80 @@
+/*
+ * Copyright (C) 2005-2014 Alfresco Software Limited.
+ *
+ * This file is part of Alfresco
+ *
+ * Alfresco is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Lesser General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * Alfresco is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public License
+ * along with Alfresco. If not, see <http://www.gnu.org/licenses/>.
+ */
+package org.alfresco.repo.cache;
+
+import java.util.HashMap;
+import java.util.Map;
+
+import org.apache.commons.math3.stat.descriptive.SummaryStatistics;
+
+/**
+ * Only to be used within a single transaction/thread.
+ * 
+ * @since 5.0
+ * @author Matt Ward
+ */
+public class TransactionStats
+{
+    private Map<OpType, SummaryStatistics> timings = new HashMap<>();
+    
+    /**
+     * Cache operation type.
+     */
+    public enum OpType
+    {
+        GET_HIT,
+        GET_MISS,
+        PUT,
+        REMOVE,
+        CLEAR
+    }
+    
+    public long getCount(OpType op)
+    {
+        SummaryStatistics stats = getTimings(op);
+        return stats.getN();
+    }
+    
+    public SummaryStatistics getTimings(OpType op)
+    {
+        SummaryStatistics opTimings = timings.get(op);
+        if (opTimings == null)
+        {
+            opTimings = new SummaryStatistics();
+            timings.put(op, opTimings);
+        }
+        return opTimings;
+    }
+    
+    public void record(long start, long end, OpType op)
+    {   
+        if (end < start)
+        {
+            throw new IllegalArgumentException("End time [" + end + "] occurs before start time [" + start + "].");
+        }
+        double timeTaken = end - start;
+        addTiming(op, timeTaken);
+    }
+
+    private void addTiming(OpType op, double time)
+    {
+        SummaryStatistics opTimings = getTimings(op);
+        opTimings.addValue(time);
+    }
+}

source/java/org/alfresco/repo/cache/TransactionalCache.java

@@ -27,6 +27,7 @@ import java.util.Map;
 import java.util.Set;
 
 import org.alfresco.error.AlfrescoRuntimeException;
+import org.alfresco.repo.cache.TransactionStats.OpType;
 import org.alfresco.repo.tenant.TenantService;
 import org.alfresco.repo.tenant.TenantUtil;
 import org.alfresco.repo.transaction.AlfrescoTransactionSupport;
@@ -92,7 +93,10 @@ public class TransactionalCache<K extends Serializable, V extends Object>
     private int maxCacheSize = 500;
     /** a unique string identifying this instance when binding resources */
     private String resourceKeyTxnData;
-    
+    /** A "null" CacheStatistics impl is used by default for backwards compatibility */
+    private CacheStatistics cacheStats = new NoOpCacheStatistics();
+    /** Enable collection of statistics? */
+    private boolean cacheStatsEnabled = false;
     private boolean isTenantAware = true; // true if tenant-aware (default), false if system-wide
     
     /**
@@ -212,6 +216,16 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         this.isTenantAware = isTenantAware;
     }
     
+    public void setCacheStats(CacheStatistics cacheStats)
+    {
+        this.cacheStats = cacheStats;
+    }
+
+    public void setCacheStatsEnabled(boolean cacheStatsEnabled)
+    {
+        this.cacheStatsEnabled = cacheStatsEnabled;
+    }
+
     /**
      * Ensures that all properties have been set
      */
@@ -248,6 +262,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
             data.removedItemsCache = new HashSet<Serializable>(13);
             data.lockedItemsCache = new HashSet<Serializable>(13);
             data.isReadOnly = AlfrescoTransactionSupport.getTransactionReadState() == TxnReadState.TXN_READ_ONLY;
+            data.stats = new TransactionStats();
 
             // ensure that we get the transaction callbacks as we have bound the unique
             // transactional caches to a common manager
@@ -405,30 +420,55 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         return cacheKeys;
     }
     
+    /**
+     * @see #getSharedCacheValue(SimpleCache, Serializable, TransactionStats)
+     */
+    public static <KEY extends Serializable, VAL> VAL getSharedCacheValue(SimpleCache<KEY, ValueHolder<VAL>> sharedCache, KEY key)
+    {
+        return getSharedCacheValue(sharedCache, key);
+    }
+    
     /**
      * Fetches a value from the shared cache.  If values were wrapped,
      * then they will be unwrapped before being returned.  If code requires
      * direct access to the wrapper object as well, then this call should not
      * be used.
+     * <p>
+     * If a TransactionStats instance is passed in, then cache access stats
+     * are tracked, otherwise - if null is passed in then stats are not tracked.
      * 
      * @param key           the key
      * @return              Returns the value or <tt>null</tt>
      */
     @SuppressWarnings("unchecked")
-    public static <KEY extends Serializable, VAL> VAL getSharedCacheValue(SimpleCache<KEY, ValueHolder<VAL>> sharedCache, KEY key)
+    public static <KEY extends Serializable, VAL> VAL getSharedCacheValue(SimpleCache<KEY, ValueHolder<VAL>> sharedCache, KEY key, TransactionStats stats)
     {
+        final long startNanos = stats != null ? System.nanoTime() : 0;
         Object possibleWrapper = sharedCache.get(key);
+        final long endNanos = stats != null ? System.nanoTime() : 0;
         if (possibleWrapper == null)
         {
+            if (stats != null)
+            {
+                stats.record(startNanos, endNanos, OpType.GET_MISS);
+            }
             return null;
         }
         else if (possibleWrapper instanceof ValueHolder)
         {
+            if (stats != null)
+            {
+                stats.record(startNanos, endNanos, OpType.GET_HIT);
+            }
             ValueHolder<VAL> wrapper = (ValueHolder<VAL>) possibleWrapper;
             return wrapper.getValue();
         }
         else
         {
+            if (stats != null)
+            {
+                stats.record(startNanos, endNanos, OpType.GET_MISS);
+            }
             throw new IllegalStateException("All entries for TransactionalCache must be put using TransactionalCache.putSharedCacheValue.");
         }
     }
@@ -442,10 +482,16 @@ public class TransactionalCache<K extends Serializable, V extends Object>
      * 
      * @since 4.2.3
      */
-    public static <KEY extends Serializable, VAL> void putSharedCacheValue(SimpleCache<KEY, ValueHolder<VAL>> sharedCache, KEY key, VAL value)
+    public static <KEY extends Serializable, VAL> void putSharedCacheValue(SimpleCache<KEY, ValueHolder<VAL>> sharedCache, KEY key, VAL value, TransactionStats stats)
     {
         ValueHolder<VAL> wrapper = new ValueHolder<VAL>(value);
+        final long startNanos = System.nanoTime(); // TODO: enabled?
         sharedCache.put(key, wrapper);
+        final long endNanos = System.nanoTime();
+        if (stats != null)
+        {
+            stats.record(startNanos, endNanos, OpType.PUT);
+        }
     }
     
     /**
@@ -582,7 +628,16 @@ public class TransactionalCache<K extends Serializable, V extends Object>
                 {
                     // There is no in-txn entry for the key
                     // Use the value direct from the shared cache
-                    V value = TransactionalCache.getSharedCacheValue(sharedCache, key);
+                    V value = null;
+                    if (cacheStatsEnabled)
+                    {
+                        value = TransactionalCache.getSharedCacheValue(sharedCache, key, txnData.stats);
+                    }
+                    else
+                    {
+                        // No stats tracking, pass in null TransactionStats
+                        value = TransactionalCache.getSharedCacheValue(sharedCache, key, null);
+                    }
                     bucket = new ReadCacheBucket<V>(value);
                     txnData.updatedItemsCache.put(key, bucket);
                     return value;
@@ -592,7 +647,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         // no value found - must we ignore the shared cache?
         if (!ignoreSharedCache)
         {
-            V value = TransactionalCache.getSharedCacheValue(sharedCache, key);
+            V value = TransactionalCache.getSharedCacheValue(sharedCache, key, null);
             // go to the shared cache
             if (isDebugEnabled)
             {
@@ -629,7 +684,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         if (AlfrescoTransactionSupport.getTransactionId() == null)  // not in transaction
         {
             // no transaction
-            TransactionalCache.putSharedCacheValue(sharedCache, key, value);
+            TransactionalCache.putSharedCacheValue(sharedCache, key, value, null);
             // done
             if (isDebugEnabled)
             {
@@ -881,7 +936,14 @@ public class TransactionalCache<K extends Serializable, V extends Object>
             if (txnData.isClearOn)
             {
                 // clear shared cache
+                final long startNanos = cacheStatsEnabled ? System.nanoTime() : 0;
                 sharedCache.clear();
+                final long endNanos = cacheStatsEnabled ? System.nanoTime() : 0;
+                if (cacheStatsEnabled)
+                {
+                    TransactionStats stats = txnData.stats;
+                    stats.record(startNanos, endNanos, OpType.CLEAR);
+                }
                 if (isDebugEnabled)
                 {
                     logger.debug("Clear notification recieved in commit - clearing shared cache");
@@ -892,7 +954,11 @@ public class TransactionalCache<K extends Serializable, V extends Object>
                 // transfer any removed items
                 for (Serializable key : txnData.removedItemsCache)
                 {
+                    final long startNanos = System.nanoTime();
                     sharedCache.remove(key);
+                    final long endNanos = System.nanoTime();
+                    TransactionStats stats = txnData.stats;
+                    stats.record(startNanos, endNanos, OpType.REMOVE);
                 }
                 if (isDebugEnabled)
                 {
@@ -942,7 +1008,14 @@ public class TransactionalCache<K extends Serializable, V extends Object>
             if (txnData.isClearOn)
             {
                 // clear shared cache
+                final long startNanos = cacheStatsEnabled ? System.nanoTime() : 0;
                 sharedCache.clear();
+                final long endNanos = cacheStatsEnabled ? System.nanoTime() : 0;
+                if (cacheStatsEnabled)
+                {
+                    TransactionStats stats = txnData.stats;
+                    stats.record(startNanos, endNanos, OpType.CLEAR);
+                }
                 if (isDebugEnabled)
                 {
                     logger.debug("Clear notification recieved in commit - clearing shared cache");
@@ -953,7 +1026,11 @@ public class TransactionalCache<K extends Serializable, V extends Object>
                 // transfer any removed items
                 for (Serializable key : txnData.removedItemsCache)
                 {
+                    final long startNanos = System.nanoTime();
                     sharedCache.remove(key);
+                    final long endNanos = System.nanoTime();
+                    TransactionStats stats = txnData.stats;
+                    stats.record(startNanos, endNanos, OpType.REMOVE);
                 }
                 if (isDebugEnabled)
                 {
@@ -971,7 +1048,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
                 {
                     bucket.doPostCommit(
                             sharedCache,
-                            key, this.isMutable, this.allowEqualsChecks, txnData.isReadOnly);
+                            key, this.isMutable, this.allowEqualsChecks, txnData.isReadOnly, txnData.stats);
                 }
                 catch (Exception e)
                 {
@@ -1000,6 +1077,11 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         finally
         {
             removeCaches(txnData);
+            // Aggregate this transaction's stats with centralised cache stats.
+            if (cacheStatsEnabled)
+            {
+                cacheStats.add(name, txnData.stats);
+            }
         }
     }
 
@@ -1016,7 +1098,14 @@ public class TransactionalCache<K extends Serializable, V extends Object>
             if (txnData.isClearOn)
             {
                 // clear shared cache
+                final long startNanos = cacheStatsEnabled ? System.nanoTime() : 0;
                 sharedCache.clear();
+                final long endNanos = cacheStatsEnabled ? System.nanoTime() : 0;
+                if (cacheStatsEnabled)
+                {
+                    TransactionStats stats = txnData.stats;
+                    stats.record(startNanos, endNanos, OpType.CLEAR);
+                }
                 if (isDebugEnabled)
                 {
                     logger.debug("Clear notification recieved in rollback - clearing shared cache");
@@ -1027,7 +1116,11 @@ public class TransactionalCache<K extends Serializable, V extends Object>
                 // transfer any removed items
                 for (Serializable key : txnData.removedItemsCache)
                 {
+                    final long startNanos = System.nanoTime();
                     sharedCache.remove(key);
+                    final long endNanos = System.nanoTime();
+                    TransactionStats stats = txnData.stats;
+                    stats.record(startNanos, endNanos, OpType.REMOVE);
                 }
                 if (isDebugEnabled)
                 {
@@ -1042,6 +1135,11 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         finally
         {
             removeCaches(txnData);
+            // Aggregate this transaction's stats with centralised cache stats.
+            if (cacheStatsEnabled)
+            {
+                cacheStats.add(name, txnData.stats);
+            }
         }
     }
     
@@ -1087,7 +1185,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         public void doPostCommit(
                 SimpleCache<Serializable, ValueHolder<BV>> sharedCache,
                 Serializable key,
-                boolean mutable, boolean allowEqualsCheck, boolean readOnly);
+                boolean mutable, boolean allowEqualsCheck, boolean readOnly, TransactionStats stats);
     }
     
     /**
@@ -1117,13 +1215,13 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         public void doPostCommit(
                 SimpleCache<Serializable, ValueHolder<BV>> sharedCache,
                 Serializable key,
-                boolean mutable, boolean allowEqualsCheck, boolean readOnly)
+                boolean mutable, boolean allowEqualsCheck, boolean readOnly, TransactionStats stats)
         {
             ValueHolder<BV> sharedObjValueHolder = sharedCache.get(key);
             if (sharedObjValueHolder == null)
             {
                 // Nothing has changed, write it through
-                TransactionalCache.putSharedCacheValue(sharedCache, key, value);
+                TransactionalCache.putSharedCacheValue(sharedCache, key, value, stats);
             }
             else if (!mutable)
             {
@@ -1174,7 +1272,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         public void doPostCommit(
                 SimpleCache<Serializable, ValueHolder<BV>> sharedCache,
                 Serializable key,
-                boolean mutable, boolean allowEqualsCheck, boolean readOnly)
+                boolean mutable, boolean allowEqualsCheck, boolean readOnly, TransactionStats stats)
         {
             ValueHolder<BV> sharedObjValueHolder = sharedCache.get(key);
             if (sharedObjValueHolder == null)
@@ -1183,7 +1281,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
                 if (!mutable)
                 {
                     // We can assume that our value is correct because it's immutable
-                    TransactionalCache.putSharedCacheValue(sharedCache, key, value);
+                    TransactionalCache.putSharedCacheValue(sharedCache, key, value, stats);
                 }
                 else
                 {
@@ -1204,7 +1302,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
             {
                 // The value in the cache did not change from what we observed before.
                 // Update the value.
-                TransactionalCache.putSharedCacheValue(sharedCache, key, value);
+                TransactionalCache.putSharedCacheValue(sharedCache, key, value, stats);
             }
             else
             {
@@ -1241,7 +1339,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         public void doPostCommit(
                 SimpleCache<Serializable, ValueHolder<BV>> sharedCache,
                 Serializable key,
-                boolean mutable, boolean allowEqualsCheck, boolean readOnly)
+                boolean mutable, boolean allowEqualsCheck, boolean readOnly, TransactionStats stats)
         {
         }
     }
@@ -1257,6 +1355,7 @@ public class TransactionalCache<K extends Serializable, V extends Object>
         private boolean isClosed;
         private boolean isReadOnly;
         private boolean noSharedCacheRead;
+        private TransactionStats stats;
     }
     
     /**