[Opensymphony-oscache] Re: Error in mass concurrence!
Guillaume Berche <[email protected]> Wed, 27 Apr 2005 10:37:30 +0200
| Newsgroups | gmane.comp.java.open-symphony.os-cache |
|---|---|
| Message-ID | <[email protected]> |
Chris,
I'm running into similar problems with oscache-2-1: concurrent threads hanging when calling Cache.cancelUpdate() concurrency when the blocking mode is enabled.
My understanding is that there is a small data race window between the Cache.cancelUpdate() call which removes the EntryStateUpdate from the Cache.updateStates, and the unlocking of the first potentially blocked threads in Cache.getFromCache() which would reinsert the EntryStateUpdate into Cache.updateStates. During this data race window, another thread might make a Cache.getFromCache() call and would as a result create a new EntryStateUpdate instance and assign it into the Cache.updateStates later on. This results into threads communicating with each other through distinct EntryStateUpdate instances.
I therefore refined the distribution's TestConcurrency junit test to highlight this.
The modified unit test is in the attached patch file: a new testConcurrentStaleGets() method was added to simulate more massive concurrent usage of cache.cancelUpdate()
The patch file was generated through the command "diff --exclude=*.class --exclude=*.html -Naur oscache-2-0-1-original/src/ oscache-2-0-1/src > oscache-2-0-1-modifs.patch" where the modifications were made into my local oscache-2-0-1 directory. I also include the full source for these two modified classes (built using the following command "tar cvfz modified_sources.tar.gz oscache-2-0-1/src/core/java/com/opensymphony/oscache/base/Cache.java oscache-2-0-1/src/core/test/com/opensymphony/oscache/base/TestConcurrency.java")
Additionally, I made a modification to the Cache.getFromCache() class to add the following error trace in order to help diagnostic of this problem.
// We put the updateState object back into the updateStates map so
// any remaining threads waiting on this cache entry will be notified
// once this thread has done its thing (either updated the cache or
// cancelled the update). Without this code they'll get left hanging...
synchronized (updateStates) {
Object previousObject = updateStates.put(key, updateState);
if (previousObject != null && previousObject != updateState) {
log.error("date race window triggered synchro bug: interlaced [" + previousObject+ "] instead of [" + updateState + "]");
}
}
When running this modified unit test, it works fine if few threads are configured and the number of repeat steps is low. However, when more massive concurrency is configured, then it generates the error output on the 2-1 version which is reproduced in attachement and the test fails. Can you please review the test case I provided? If this happens to be correct, we can maybe file a jira bug for it to be able to track it? I hope this modified unit test will be helpfull to support the fix for this synchro bug.
I also tried to imagine ways to fix this bug. To remove the data race, I think the simpler thing would be to keep a same EntryStateUpdate instance associated to a given key value for the whole duration of the key value (i.e. through add/and updates requests to the cache with this same key value).
Concretely, I could only find the following coding alternatives:
1- Have the EntryStateUpdate be associated to the key into the Cache.cacheMap field (for instance within the CacheEntry). However the following comment suggests this is not possible.
/**
* A set that holds keys of cache entries that are currently being built.
* The cache checks against this map when a stale entry is requested.
* If the requested key is in here, we know the entry is currently being
* built by another thread and hence we can either block and wait or serve
* the stale entry (depending on whether cache blocking is enabled or not).
* <p>
* We need to isolate these here since the actual CacheEntry
* objects may not normally be held in memory at all (eg, if no
* memory cache is configured).
*/
private Map updateStates = new HashMap();
Is this comment correct? When the actual CacheEntry object is not held in memory, I imagine the CacheEntry is then restored from disk. Would it be possible to either restore the EntryStateUpdate from disk at the same time or atomically recreate one at this time?
2- Keep the EntryStateUpdate instance present into the Cache.updateStates until the key is removed from the cache. This has the drawback of having a larger Cache.updateStates map which may increase the memory usage significantly when the number of keys is large.
Did you already study other ways to fix this problem?
Thanks in advance for your help and for contributing this great package to the community!
Best regards,
Guillaume.
> Yes special care is required when handling
> the NRE and this code ignores that completely. However I think there's
> more to it than this. I've just taken a very quick look at the changes
>that were made to make cache.removeEntry() public. It doesn't look like
> thread-safety has been taken into account! Take a look at line 390 of
> AbstractConcurrentReadCache - the internal calls that are made to
> remove() are taking care to synchronize as required. So just making
> removeEntry() public is definitely going to cause problems.
>
> One
> thing we *definitely* don't want to do is sync on
> GeneralCacheAdministrator.getFromCache() - that will both kill
> performance and cause implementation problems for users. The fix needs
> to go with removeEntry(). Without looking into this in more detail my
> first guess is that synchronizing the removeEntry() call might be
> enough. This hopefully won't affect performance too much since:
>
>a) removeEntry() wasn't exposed previously anyway
>b) internal calls to it are synchronized already
>
>I'm
> not sure it's ideal though since there will be some double-syncing
> going on internally. It's not clear to me what this will do to
> performance.
>
>Andres can you please take a look at your
> change a little more closely? Give me a buzz if you need a hand and
> I'll do what I can. I'm moving house tomorrow though so I likely won't
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
test_output_2_1.txt
(text/plain, 11.7 KB)
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Config loadProps
INFO: Properties {cache.capacity=1000}
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.general.GeneralCacheAdministrator <init>
INFO: Constructed GeneralCacheAdministrator()
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Config loadProps
INFO: Properties {cache.capacity=1000}
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.general.GeneralCacheAdministrator <init>
INFO: Constructed GeneralCacheAdministrator()
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.general.GeneralCacheAdministrator <init>
INFO: Constructed GeneralCacheAdministrator()
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.general.GeneralCacheAdministrator createCache
INFO: Creating new cache
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@7bd9f2] instead of [com.opensymphony.oscache.base.EntryUpdateState@121cc40]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@1662dc8] instead of [com.opensymphony.oscache.base.EntryUpdateState@121cc40]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@1ef9f1d] instead of [com.opensymphony.oscache.base.EntryUpdateState@b753f8]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@1c1ea29] instead of [com.opensymphony.oscache.base.EntryUpdateState@b753f8]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@1f436f5] instead of [com.opensymphony.oscache.base.EntryUpdateState@b753f8]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@4413ee] instead of [com.opensymphony.oscache.base.EntryUpdateState@b753f8]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@1786e64] instead of [com.opensymphony.oscache.base.EntryUpdateState@197a37c]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@197a37c] instead of [com.opensymphony.oscache.base.EntryUpdateState@b753f8]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@6e3d60] instead of [com.opensymphony.oscache.base.EntryUpdateState@b753f8]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@18385e3] instead of [com.opensymphony.oscache.base.EntryUpdateState@1cb25f1]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@2808b3] instead of [com.opensymphony.oscache.base.EntryUpdateState@535b58]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@922804] instead of [com.opensymphony.oscache.base.EntryUpdateState@1815859]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@cf40f5] instead of [com.opensymphony.oscache.base.EntryUpdateState@b1c260]
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.TestConcurrency$GetStaleEntryAndCancelUpdate run
SEVERE: Thread index [3845]: Unexpectedly caught exception [java.lang.IllegalStateException: Cannot cancel cache update - current state (-1) is not UPDATE_IN_PROGRESS]
java.lang.IllegalStateException: Cannot cancel cache update - current state (-1) is not UPDATE_IN_PROGRESS
at com.opensymphony.oscache.base.EntryUpdateState.cancelUpdate(EntryUpdateState.java:83)
at com.opensymphony.oscache.base.Cache.cancelUpdate(Cache.java:371)
at com.opensymphony.oscache.general.GeneralCacheAdministrator.cancelUpdate(GeneralCacheAdministrator.java:180)
at com.opensymphony.oscache.base.TestConcurrency$GetStaleEntryAndCancelUpdate.run(TestConcurrency.java:424)
at java.lang.Thread.run(Thread.java:534)
junit.framework.AssertionFailedError: Thread index [3845] : Unexpectedly caught exception [java.lang.IllegalStateException: Cannot cancel cache update - current state (-1) is not UPDATE_IN_PROGRESS]
at junit.framework.Assert.fail(Assert.java:47)
at com.opensymphony.oscache.base.TestConcurrency$GetStaleEntryAndCancelUpdate.run(TestConcurrency.java:427)
at java.lang.Thread.run(Thread.java:534)
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.TestConcurrency$GetStaleEntryAndCancelUpdate run
SEVERE: Thread index [6619]: Unexpectedly caught exception [java.lang.IllegalStateException: Cannot cancel cache update - current state (-1) is not UPDATE_IN_PROGRESS]
java.lang.IllegalStateException: Cannot cancel cache update - current state (-1) is not UPDATE_IN_PROGRESS
at com.opensymphony.oscache.base.EntryUpdateState.cancelUpdate(EntryUpdateState.java:83)
at com.opensymphony.oscache.base.Cache.cancelUpdate(Cache.java:371)
at com.opensymphony.oscache.general.GeneralCacheAdministrator.cancelUpdate(GeneralCacheAdministrator.java:180)
at com.opensymphony.oscache.base.TestConcurrency$GetStaleEntryAndCancelUpdate.run(TestConcurrency.java:424)
at java.lang.Thread.run(Thread.java:534)
junit.framework.AssertionFailedError: Thread index [6619] : Unexpectedly caught exception [java.lang.IllegalStateException: Cannot cancel cache update - current state (-1) is not UPDATE_IN_PROGRESS]
at junit.framework.Assert.fail(Assert.java:47)
at com.opensymphony.oscache.base.TestConcurrency$GetStaleEntryAndCancelUpdate.run(TestConcurrency.java:427)
at java.lang.Thread.run(Thread.java:534)
Apr 26, 2005 1:35:36 PM com.opensymphony.oscache.base.Cache getFromCache
SEVERE: date race window triggered synchro bug: interlaced [com.opensymphony.oscache.base.EntryUpdateState@503429] instead of [com.opensymphony.oscache.base.EntryUpdateState@1908ca1]
Apr 26, 2005 1:35:37 PM com.opensymphony.oscache.base.TestConcurrency$GetStaleEntryAndCancelUpdate run
SEVERE: Thread index [3202]: Unexpectedly caught exception [java.lang.IllegalStateException: Cannot cancel cache update - current state (-1) is not UPDATE_IN_PROGRESS]
java.lang.IllegalStateException: Cannot cancel cache update - current state (-1) is not UPDATE_IN_PROGRESS
at com.opensymphony.oscache.base.EntryUpdateState.cancelUpdate(EntryUpdateState.java:83)
at com.opensymphony.oscache.base.Cache.cancelUpdate(Cache.java:371)
at com.opensymphony.oscache.general.GeneralCacheAdministrator.cancelUpdate(GeneralCacheAdministrator.java:180)
at com.opensymphony.oscache.base.TestConcurrency$GetStaleEntryAndCancelUpdate.run(TestConcurrency.java:424)
at java.lang.Thread.run(Thread.java:534)
junit.framework.AssertionFailedError: Thread index [3202] : Unexpectedly caught exception [java.lang.IllegalStateException: Cannot cancel cache update - current state (-1) is not UPDATE_IN_PROGRESS]
at junit.framework.Assert.fail(Assert.java:47)
at com.opensymphony.oscache.base.TestConcurrency$GetStaleEntryAndCancelUpdate.run(TestConcurrency.java:427)
at java.lang.Thread.run(Thread.java:534)
Apr 26, 2005 1:35:42 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [5] s
Apr 26, 2005 1:35:47 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [11] s
Apr 26, 2005 1:35:53 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [16] s
Apr 26, 2005 1:35:58 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [22] s
Apr 26, 2005 1:36:04 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [27] s
Apr 26, 2005 1:36:09 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [33] s
Apr 26, 2005 1:36:15 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [38] s
Apr 26, 2005 1:36:20 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [44] s
Apr 26, 2005 1:36:26 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [49] s
Apr 26, 2005 1:36:31 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [55] s
Apr 26, 2005 1:36:37 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [61] s
Apr 26, 2005 1:36:42 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [66] s
Apr 26, 2005 1:36:48 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [72] s
Apr 26, 2005 1:36:53 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [77] s
Apr 26, 2005 1:36:59 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [83] s
Apr 26, 2005 1:37:04 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [88] s
Apr 26, 2005 1:37:10 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [94] s
Apr 26, 2005 1:37:15 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [99] s
Apr 26, 2005 1:37:21 PM com.opensymphony.oscache.base.TestConcurrency testConcurrentStaleGets
SEVERE: Thread #3 did not complete within [105] s
junit.framework.AssertionFailedError: at least one thread did not complete within [105] s
at junit.framework.Assert.fail(Assert.java:47)
at junit.framework.Assert.assertTrue(Assert.java:20)
at com.opensymphony.oscache.base.TestConcurrency.testConcurrentStaleGets(TestConcurrency.java:153)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at junit.framework.TestCase.runTest(TestCase.java:154)
at junit.framework.TestCase.runBare(TestCase.java:127)
at junit.framework.TestResult$1.protect(TestResult.java:106)
at junit.framework.TestResult.runProtected(TestResult.java:124)
at junit.framework.TestResult.run(TestResult.java:109)
at junit.framework.TestCase.run(TestCase.java:118)
at junit.framework.TestSuite.runTest(TestSuite.java:208)
at junit.framework.TestSuite.run(TestSuite.java:203)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:421)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:305)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:186)
modified_sources.tar.gz
(application/x-gzip, 10.9 KB) - not displayed
oscache-2-0-1-modifs.patch
(text/x-patch, 11.1 KB)
diff --exclude='*.class' --exclude='*.html' -Naur oscache-2-0-1-original/src/.classpath oscache-2-0-1/src/.classpath
--- oscache-2-0-1-original/src/.classpath 1970-01-01 01:00:00.000000000 +0100
+++ oscache-2-0-1/src/.classpath 2005-04-25 13:27:43.000000000 +0200
@@ -0,0 +1,6 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<classpath>
+ <classpathentry kind="src" path="core/java"/>
+ <classpathentry kind="con" path="org.eclipse.jdt.launching.JRE_CONTAINER"/>
+ <classpathentry kind="output" path="bin"/>
+</classpath>
diff --exclude='*.class' --exclude='*.html' -Naur oscache-2-0-1-original/src/core/java/.classpath oscache-2-0-1/src/core/java/.classpath
--- oscache-2-0-1-original/src/core/java/.classpath 1970-01-01 01:00:00.000000000 +0100
+++ oscache-2-0-1/src/core/java/.classpath 2005-04-25 13:29:22.000000000 +0200
@@ -0,0 +1,8 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<classpath>
+ <classpathentry kind="src" path=""/>
+ <classpathentry kind="con" path="org.eclipse.jdt.launching.JRE_CONTAINER"/>
+ <classpathentry kind="lib" path="/home/bercheg/cvsrepo/kelkoo/deliveries/commons-collections-3.1.jar"/>
+ <classpathentry kind="lib" path="/home/bercheg/cvsrepo/kelkoo/deliveries/commons-logging-1.0.2.jar"/>
+ <classpathentry kind="output" path=""/>
+</classpath>
diff --exclude='*.class' --exclude='*.html' -Naur oscache-2-0-1-original/src/core/java/com/opensymphony/oscache/base/Cache.java oscache-2-0-1/src/core/java/com/opensymphony/oscache/base/Cache.java
--- oscache-2-0-1-original/src/core/java/com/opensymphony/oscache/base/Cache.java 2003-11-05 09:19:20.000000000 +0100
+++ oscache-2-0-1/src/core/java/com/opensymphony/oscache/base/Cache.java 2005-04-25 15:47:32.000000000 +0200
@@ -268,7 +268,10 @@
// once this thread has done its thing (either updated the cache or
// cancelled the update). Without this code they'll get left hanging...
synchronized (updateStates) {
- updateStates.put(key, updateState);
+ Object previousObject = updateStates.put(key, updateState);
+ if (previousObject != null && previousObject != updateState) {
+ log.error("date race window triggered synchro bug: interlaced [" + previousObject+ "] instead of [" + updateState + "]");
+ }
}
if (cacheEntry.isNew()) {
diff --exclude='*.class' --exclude='*.html' -Naur oscache-2-0-1-original/src/core/java/.project oscache-2-0-1/src/core/java/.project
--- oscache-2-0-1-original/src/core/java/.project 1970-01-01 01:00:00.000000000 +0100
+++ oscache-2-0-1/src/core/java/.project 2005-04-25 13:28:20.000000000 +0200
@@ -0,0 +1,17 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<projectDescription>
+ <name>oscache-2-0-1</name>
+ <comment></comment>
+ <projects>
+ </projects>
+ <buildSpec>
+ <buildCommand>
+ <name>org.eclipse.jdt.core.javabuilder</name>
+ <arguments>
+ </arguments>
+ </buildCommand>
+ </buildSpec>
+ <natures>
+ <nature>org.eclipse.jdt.core.javanature</nature>
+ </natures>
+</projectDescription>
diff --exclude='*.class' --exclude='*.html' -Naur oscache-2-0-1-original/src/core/test/com/opensymphony/oscache/base/TestConcurrency.java oscache-2-0-1/src/core/test/com/opensymphony/oscache/base/TestConcurrency.java
--- oscache-2-0-1-original/src/core/test/com/opensymphony/oscache/base/TestConcurrency.java 2003-11-05 09:19:20.000000000 +0100
+++ oscache-2-0-1/src/core/test/com/opensymphony/oscache/base/TestConcurrency.java 2005-04-26 13:35:27.000000000 +0200
@@ -10,8 +10,12 @@
import junit.framework.TestCase;
import junit.framework.TestSuite;
+import java.util.BitSet;
import java.util.Properties;
+import org.apache.commons.logging.Log;
+import org.apache.commons.logging.LogFactory;
+
/**
* Test the Cache class for any concurrency problems
*
@@ -20,6 +24,8 @@
* @author <a href="mailto:[email protected]">Chris Miller</a>
*/
public class TestConcurrency extends TestCase {
+ private static transient final Log log = LogFactory.getLog(GeneralCacheAdministrator.class); //TestConcurrency.class
+
// Static variables required thru all the tests
private static GeneralCacheAdministrator admin = null;
@@ -61,6 +67,101 @@
}
/**
+ * Checks whether the cache handles simultaneous attempts to access a
+ * stable cache entry correctly when the blocking mode is enabled.
+ *
+ * Basically N threads are concurrently trying to access a same stale cache entry and each is cancelling its update. Each thread repeat this operation M times.
+ * The test is sucessfull if after some time, all threads are properly released
+ */
+ public void testConcurrentStaleGets() {
+ GeneralCacheAdministrator staticAdmin = admin;
+ admin = new GeneralCacheAdministrator(); //avoid poluting other test cases
+
+ try {
+ // A test for the case where oscache.blocking = true
+ //admin.destroy();
+
+ Properties p = new Properties();
+ p.setProperty(AbstractCacheAdministrator.CACHE_BLOCKING_KEY, "true");
+ admin = new GeneralCacheAdministrator(p);
+
+ assertTrue("The cache should be in blocking mode for this test.", admin.isBlocking());
+
+ int nbThreads = 10;
+ int retryByThreads = 10000;
+
+ String key = "new";
+
+ //First put a value
+ admin.putInCache(key, VALUE);
+
+ try {
+ //Then test without concurrency that it is reported as stale when time-to-live is zero
+ admin.getFromCache(key, 0);
+ fail("NeedsRefreshException should have been thrown");
+ } catch (NeedsRefreshException nre) {
+ //Ok this is was is excpected, we can release the update
+ admin.cancelUpdate(key);
+ }
+
+ //Then ask N threads to concurrently try to access this stale resource and each should receive a NeedsRefreshException, and cancel the update
+ Thread spawnedThreads [] = new Thread[nbThreads];
+ BitSet successfullThreadTerminations = new BitSet(nbThreads); //Track which thread successfully terminated
+ for(int threadIndex=0; threadIndex<nbThreads; threadIndex++) {
+ GetStaleEntryAndCancelUpdate getEntry = new GetStaleEntryAndCancelUpdate(key, 0, retryByThreads, threadIndex, successfullThreadTerminations);
+ Thread thread = new Thread(getEntry);
+ spawnedThreads[threadIndex] = thread;
+ thread.start();
+ }
+
+ // OK, those threads should now repeatidely be blocked waiting for the new cache
+ // entry to appear. Wait for all of them to terminate
+ int maxWaitingSeconds = 100;
+ int maxWaitForEachThread= 5;
+ long waitStartTime = System.currentTimeMillis();
+
+ boolean atLeastOneThreadRunning = false;
+
+ while (System.currentTimeMillis() - waitStartTime < maxWaitingSeconds *1000) {
+ atLeastOneThreadRunning = false;
+
+ //Wait a bit between each step to avoid consumming all CPU and preventing other threads from running.
+ try {
+ Thread.sleep(500);
+ } catch (InterruptedException ie) {
+ }
+
+ //check whether all threads are done.
+ for(int threadIndex=0; threadIndex<nbThreads; threadIndex++) {
+ Thread inspectedThread = spawnedThreads[threadIndex];
+ try {
+ inspectedThread.join(maxWaitForEachThread * 1000);
+ } catch (InterruptedException e) {
+ fail("Thread #" + threadIndex + " was interrupted");
+ }
+ if (inspectedThread.isAlive()) {
+ atLeastOneThreadRunning = true;
+ log.error("Thread #" + threadIndex + " did not complete within [" + (System.currentTimeMillis() - waitStartTime ) /1000 + "] s ");
+ }
+ }
+ if (! atLeastOneThreadRunning) {
+ break; //while loop, test success.
+ }
+
+ }
+
+ assertTrue("at least one thread did not complete within [" + (System.currentTimeMillis() - waitStartTime ) /1000 + "] s ", ! atLeastOneThreadRunning);
+
+ for(int threadIndex=0; threadIndex<nbThreads; threadIndex++) {
+ assertTrue("thread [" + threadIndex + "] did not successfully complete. ", successfullThreadTerminations.get(threadIndex));
+ }
+ } finally {
+ admin = staticAdmin;
+ //Avoid po
+ }
+ }
+
+ /**
* Check that the cache handles simultaneous attempts to access a
* new cache entry correctly
*/
@@ -294,6 +395,51 @@
}
}
+ /**
+ * Basically requests a stale entry, expects to receive a NeedsRefreshException, and always cancels the update.
+ */
+ private class GetStaleEntryAndCancelUpdate implements Runnable {
+ String key;
+ int time;
+ int retries;
+ private final int threadIndex;
+ private final BitSet successfullThreadTerminations;
+
+ GetStaleEntryAndCancelUpdate(String key, int time, int retries, int threadIndex, BitSet successfullThreadTerminations) {
+ this.key = key;
+ this.time = time;
+ this.retries = retries;
+ this.threadIndex = threadIndex;
+ this.successfullThreadTerminations = successfullThreadTerminations;
+ }
+
+ public void run() {
+ for (int retryIndex=0; retryIndex<retries; retryIndex++) {
+ try {
+ // Get from the cache
+ Object fromCache = admin.getFromCache(key, time);
+ assertNull("Thread index [" + retryIndex + "] expected stale request [" + retryIndex + "] to be received, got [" + fromCache+ "]", fromCache);
+ } catch (NeedsRefreshException nre) {
+ try {
+ admin.cancelUpdate(key);
+ } catch(Throwable t) {
+ log.error("Thread index [" + retryIndex + "]: Unexpectedly caught exception [" + t + "]", t);
+ fail("Thread index [" + retryIndex + "] : Unexpectedly caught exception [" + t + "]");
+ }
+ } catch(Throwable t) {
+ log.error("Thread index [" + retryIndex + "] : Unexpectedly caught exception [" + t + "]", t);
+ fail("Thread index [" + retryIndex + "] : Unexpectedly caught exception [" + t + "]");
+ }
+ }
+
+ //Once we successfully terminate, we update the corresponding bit to let the Junit know we succeeded.
+ synchronized(successfullThreadTerminations) {
+ successfullThreadTerminations.set(threadIndex);
+ }
+ }
+ }
+
+
private class OSGeneralTest implements Runnable {
public void doit(int i) {
int refreshPeriod = 500 /*millis*/;
diff --exclude='*.class' --exclude='*.html' -Naur oscache-2-0-1-original/src/.project oscache-2-0-1/src/.project
--- oscache-2-0-1-original/src/.project 1970-01-01 01:00:00.000000000 +0100
+++ oscache-2-0-1/src/.project 2005-04-25 12:10:33.000000000 +0200
@@ -0,0 +1,17 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<projectDescription>
+ <name>oscache-2-0-1</name>
+ <comment></comment>
+ <projects>
+ </projects>
+ <buildSpec>
+ <buildCommand>
+ <name>org.eclipse.jdt.core.javabuilder</name>
+ <arguments>
+ </arguments>
+ </buildCommand>
+ </buildSpec>
+ <natures>
+ <nature>org.eclipse.jdt.core.javanature</nature>
+ </natures>
+</projectDescription>