• Bug
  • Status: Closed
  • 1 Critical
  • Resolution: Fixed
  • ehcache-core
  • cdennis
  • Reporter: cstoeber
  • December 08, 2010
  • 0
  • Watchers: 3
  • July 27, 2012
  • January 03, 2011

Description

As requested, here is my bug report regarding my forum entry: http://forums.terracotta.org/forums/posts/list/4592.page

In the following example I am using a disk persistent cache with overflowToDisk and timeToIdle of 60 seconds and timeToLive of 10 minutes.

As you can see in the output the cached element will be removed through the DiskExpiryTask allthough I am accessing the object every 30 seconds. It seems to me that the last access time of the element in the disk store will not be updated. And so the DiskExpiryTask is removing an up to date element. Especially see the lastAccessDate while getting the element and while it will be expired. The lastAccessDate while expiring is the date from putting it to the cache (plus 1 second).

I am expecting that with this configuration the element will expire after 60 seconds without access or after a lifetime of 10 minutes.

I am using EHCache 2.3.0.

 import java.util.Date;
 
 import net.sf.ehcache.Cache;
 import net.sf.ehcache.CacheException;
 import net.sf.ehcache.CacheManager;
 import net.sf.ehcache.Ehcache;
 import net.sf.ehcache.Element;
 import net.sf.ehcache.config.CacheConfiguration;
 import net.sf.ehcache.event.CacheEventListener;
 
 public class EHCacheTest
 {
 
   public static void main(String[] args)
   {
     CacheManager cacheManager = CacheManager.getInstance();
 
     CacheConfiguration configuration = new CacheConfiguration("testCache", 20);
     configuration.setOverflowToDisk(true);
     configuration.setTimeToIdleSeconds(60);
     configuration.setTimeToLiveSeconds(10 * 60);
     configuration.setDiskPersistent(true);
 
     Cache cache = new Cache(configuration);
     cache.getCacheEventNotificationService().registerListener(new CacheEventListener()
     {
 
       @Override
       public void notifyRemoveAll(Ehcache arg0)
       {
         System.out.println("removeAll");
       }
 
       @Override
       public void notifyElementUpdated(Ehcache arg0, Element arg1) throws CacheException
       {
         System.out.println("updated: " + arg1.getKey());
       }
 
       @Override
       public void notifyElementRemoved(Ehcache arg0, Element arg1) throws CacheException
       {
         System.out.println("removed: " + arg1.getKey());
       }
 
       @Override
       public void notifyElementPut(Ehcache arg0, Element arg1) throws CacheException
       {
         System.out.println("put: " + arg1);
         System.out.println("put: lastAccessDate: " + new Date(arg1.getLastAccessTime()));
         System.out.println("put: expirationDate: " + new Date(arg1.getExpirationTime()));
       }
 
       @Override
       public void notifyElementExpired(Ehcache arg0, Element arg1)
       {
         System.out.println("expired: " + arg1);
         System.out.println("expired: lastAccessDate: " + new Date(arg1.getLastAccessTime()));
         System.out.println("expired: expirationDate: " + new Date(arg1.getExpirationTime()));
         new Exception().printStackTrace();
       }
 
       @Override
       public void notifyElementEvicted(Ehcache arg0, Element arg1)
       {
         System.out.println("evicted: " + arg1.getKey());
       }
 
       @Override
       public void dispose()
       {
         System.out.println("dispose");
       }
 
       @Override
       public Object clone() throws CloneNotSupportedException
       {
         return super.clone();
       }
     });
 
     cacheManager.addCache(cache);
 
     cache.put(new Element("1", "A value"));
 
     while (true)
     {
       Element element = cache.get("1");
 
       System.out.println("get: " + new Date());
       System.out.println("get: " + element);
       if (element != null)
       {
         System.out.println("get: lastAccessDate: " + new Date(element.getLastAccessTime()));
         System.out.println("get: expirationDate: " + new Date(element.getExpirationTime()));
       }
       else
       {
         break;
       }
 
       try
       {
         Thread.sleep(30 * 1000);
       }
       catch (InterruptedException e)
       {
         //
       }
     }
 
     cache.removeAll();
 
     cacheManager.shutdown();
   }
 }

{noformat} put: [ key = 1, value=A value, version=1, hitCount=0, CreationTime = 1291709161187, LastAccessTime = 1291709161187 ] put: lastAccessDate: Tue Dec 07 09:06:01 CET 2010 put: expirationDate: Tue Dec 07 09:07:01 CET 2010 get: Tue Dec 07 09:06:01 CET 2010 get: [ key = 1, value=A value, version=1, hitCount=1, CreationTime = 1291709161187, LastAccessTime = 1291709161205 ] get: lastAccessDate: Tue Dec 07 09:06:01 CET 2010 get: expirationDate: Tue Dec 07 09:07:01 CET 2010 get: Tue Dec 07 09:06:31 CET 2010 get: [ key = 1, value=A value, version=1, hitCount=2, CreationTime = 1291709161187, LastAccessTime = 1291709191206 ] get: lastAccessDate: Tue Dec 07 09:06:31 CET 2010 get: expirationDate: Tue Dec 07 09:07:31 CET 2010 get: Tue Dec 07 09:07:01 CET 2010 get: [ key = 1, value=A value, version=1, hitCount=3, CreationTime = 1291709161187, LastAccessTime = 1291709221207 ] get: lastAccessDate: Tue Dec 07 09:07:01 CET 2010 get: expirationDate: Tue Dec 07 09:08:01 CET 2010 get: Tue Dec 07 09:07:31 CET 2010 get: [ key = 1, value=A value, version=1, hitCount=4, CreationTime = 1291709161187, LastAccessTime = 1291709251208 ] get: lastAccessDate: Tue Dec 07 09:07:31 CET 2010 get: expirationDate: Tue Dec 07 09:08:31 CET 2010 expired: [ key = 1, value=A value, version=1, hitCount=1, CreationTime = 1291709162000, LastAccessTime = 1291709162000 ] expired: lastAccessDate: Tue Dec 07 09:06:02 CET 2010 expired: expirationDate: Tue Dec 07 09:07:02 CET 2010 java.lang.Exception at EHCacheTest$1.notifyElementExpired(EHCacheTest.java:60) at net.sf.ehcache.event.RegisteredEventListeners.notifyElementExpiry(RegisteredEventListeners.java:139) at net.sf.ehcache.store.compound.factories.DiskStorageFactory$DiskExpiryTask.checkExpiry(DiskStorageFactory.java:675) at net.sf.ehcache.store.compound.factories.DiskStorageFactory$DiskExpiryTask.run(DiskStorageFactory.java:664) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) get: Tue Dec 07 09:08:01 CET 2010 get: null removeAll dispose {noformat}

Comments

Fiona OShea 2010-12-08

Gary commented in forums

Looks like a righteous bug wherein the DiskStore is caching the Element's expirationDate in another data structure. Would you mind creating a JIRA ticket for the problem, including the sample code?