Re: [Opensymphony-oscache] Re: Error in mass concurrence!

Guillaume Berche <[email protected]> Wed, 27 Apr 2005 18:36:36 +0200
Newsgroups gmane.comp.java.open-symphony.os-cache
Message-ID <[email protected]>
Andres,

Thanks for your answer. I tried with the latest CVS code and am getting 
the same errors and test failure.

I looked at the cvs history but did not find the removeEntry() method 
synchronization modification you refer to. I looked into 
Cache.removeEntry() variants and GeneralCacheAdministrator.removeEntry()

[1137:bercheg@dazzler 18:21:44 oscache]$ cvs status 
src/core/java/com/opensymphony/oscache/base/Cache.java
===================================================================
File: Cache.java        Status: Locally Modified

   Working revision:    1.14
   Repository revision: 1.14    
/cvs/oscache/src/core/java/com/opensymphony/oscache/base/Cache.java,v
   Sticky Tag:          (none)
   Sticky Date:         (none)
   Sticky Options:      (none)

[1138:bercheg@dazzler 18:23:53 oscache]$ cvs log 
src/core/java/com/opensymphony/oscache/base/Cache.java

RCS file: 
/cvs/oscache/src/core/java/com/opensymphony/oscache/base/Cache.java,v
Working file: src/core/java/com/opensymphony/oscache/base/Cache.java
head: 1.14
branch:
locks: strict
access list:
symbolic names:
        v2_1_1: 1.13.0.2
        Root_v2_1_1: 1.13
        v2_1: 1.13
        v2_0_2: 1.6
        v2_0_1: 1.6
        v2_0: 1.4
        v2_0_beta_2: 1.3
keyword substitution: kv
total revisions: 14;    selected revisions: 14
description:
----------------------------
revision 1.14
date: 2005/03/17 20:29:55;  author: dres;  state: Exp;  lines: +2 -2
Submitted by:  Andres March

CACHE-145  removeEntry(String key) has been made public and exposed in 
the GeneralCacheAdministrator

[...]

[1143:bercheg@dazzler 18:29:33 oscache]$ cat CVS/Root
:pserver:[email protected]:/cvs
[1145:bercheg@dazzler 18:30:18 oscache]$ cat CVS/Repository
oscache

Am I looking at the right CVS repositoy?



[1140:bercheg@dazzler 18:25:15 oscache]$ cvs diff 
src/core/java/com/opensymphony/oscache/base/Cache.java
Index: src/core/java/com/opensymphony/oscache/base/Cache.java
===================================================================
RCS file: 
/cvs/oscache/src/core/java/com/opensymphony/oscache/base/Cache.java,v
retrieving revision 1.14
diff -r1.14 Cache.java
274c274,278
<                                 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+ "]");
 >                                 }

Thanks,

Guillaume.



Andres March wrote:

> Can you try the latest CVS code? We have synchronized removeEntry.  I 
> will have a look at your code.
>
> Guillaume Berche wrote:
>
>> 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
>>
>>
>> ------------------------------------------------------------------------
>>
>> 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) 
>>
>>  
>>
>> ------------------------------------------------------------------------
>>
>> 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>
>>
>>  
>>
>> ------------------------------------------------------------------------
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [email protected]
>> For additional commands, e-mail: [email protected]
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [email protected]
> For additional commands, e-mail: [email protected]
>