Return-Path: Delivered-To: apmail-commons-dev-archive@www.apache.org Received: (qmail 7325 invoked from network); 1 Jun 2009 17:06:31 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.3) by minotaur.apache.org with SMTP; 1 Jun 2009 17:06:31 -0000 Received: (qmail 1008 invoked by uid 500); 1 Jun 2009 17:06:43 -0000 Delivered-To: apmail-commons-dev-archive@commons.apache.org Received: (qmail 874 invoked by uid 500); 1 Jun 2009 17:06:43 -0000 Mailing-List: contact dev-help@commons.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: "Commons Developers List" Delivered-To: mailing list dev@commons.apache.org Received: (qmail 864 invoked by uid 99); 1 Jun 2009 17:06:43 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 01 Jun 2009 17:06:43 +0000 X-ASF-Spam-Status: No, hits=-0.0 required=10.0 tests=SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of sebbaz@gmail.com designates 74.125.78.148 as permitted sender) Received: from [74.125.78.148] (HELO ey-out-1920.google.com) (74.125.78.148) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 01 Jun 2009 17:06:35 +0000 Received: by ey-out-1920.google.com with SMTP id 3so1396397eyh.60 for ; Mon, 01 Jun 2009 10:06:13 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:mime-version:received:in-reply-to:references :date:message-id:subject:from:to:content-type :content-transfer-encoding; bh=99QQvN2+QzoIxygBORXEBabVVuFQoIKjrNDyymUvgwU=; b=E09ciai5BSDhbX83KIzwrR0YAcIUpiWk9Y05Xw54Yr1LCg0ZWUuF52jI4n/x009Wyi c1QrEl/v1GzNWEDiLz+K0+JGlRq9fihdrnaOFAVl2aECt+x/EKmi9y01jwUHRyysI0ll EK7ScshwDfBrXRV/RAuFj+p1ZcMyejh6hNcAc= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :content-type:content-transfer-encoding; b=uRCoPFJ1SaZHlPfWgNjc782637o3FFvuiOnKPDa0EIULZuEIgBIQuwzPG4ZlkFqU/1 7Zr/Qt7jB3P7uMTDddiSYTfj4cU4UZgMMv1Yp1AI11Ml3GFxYe0pw358SOuRR1Mc2oG6 SZAGfXPfV98GJzDWWhuNjlzOUE+BJRZ/v4P8A= MIME-Version: 1.0 Received: by 10.216.26.82 with SMTP id b60mr1903510wea.177.1243875971192; Mon, 01 Jun 2009 10:06:11 -0700 (PDT) In-Reply-To: <25aac9fc0906010925u3859dcc4yd3f4b3aecde6e442@mail.gmail.com> References: <4A21E4BA.9070708@gmail.com> <25aac9fc0905310718q2cf91088vfef5c54bab090bd8@mail.gmail.com> <4A2294B1.2060304@gmail.com> <25aac9fc0905310800g38fdd37eh1d1a84c130c1694c@mail.gmail.com> <25aac9fc0905310906x78d3d44eq497e5eb5b3398a87@mail.gmail.com> <4A22BAA8.8000004@gmail.com> <4A231D05.8070904@gmail.com> <25aac9fc0906010642m56476da5q7b864587b8576d34@mail.gmail.com> <25aac9fc0906010830xca5d78cj4174e6be79177352@mail.gmail.com> <25aac9fc0906010925u3859dcc4yd3f4b3aecde6e442@mail.gmail.com> Date: Mon, 1 Jun 2009 18:06:10 +0100 Message-ID: <25aac9fc0906011006w154001bcl430a054411008dbc@mail.gmail.com> Subject: Re: [pool] 1.5-RC2 available for review From: sebb To: Commons Developers List Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit X-Virus-Checked: Checked by ClamAV on apache.org On 01/06/2009, sebb wrote: > On 01/06/2009, sebb wrote: > > On 01/06/2009, sebb wrote: > > > On 01/06/2009, Phil Steitz wrote: > > > > Phil Steitz wrote: > > > > > > > > > sebb wrote: > > > > > > > > > > > On 31/05/2009, sebb wrote: > > > > > > > > > > > > > > > > > > > On 31/05/2009, Phil Steitz wrote: > > > > > > > > sebb wrote: > > > > > > > > > > > > > > > > > On 31/05/2009, Phil Steitz wrote: > > > > > > > > > > > > > > > > > > > > > > > > > > > > sebb wrote: > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > On 31/05/2009, Phil Steitz wrote: > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Thanks to all who provided feedback on RC1. > > > > > > > > > > > > > > > > > > > > > > > > Changes in RC2 > > > > > > > > > > > > > > > > > > > > > > > > * Fixed copyright date in NOTICE.txt > > > > > > > > > > > > * Restored development reports > > > > > > > > > > > > * Improved thread-safety and timing/reliability in GOP, > > > > GKOP tests > > > > > > > > - > > > > > > > > > > > > thanks, sebb! > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Unfortunately not enough, see below... > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > * Added link to release javadoc in site.xml > > > > > > > > > > > > * Fixed xml errors in changes.xml > > > > > > > > > > > > * Added test for ErodingPerKeyKeyedObjectPool > > > > > > > > > > > > * Changed clirr comparison version from 1.3 to 1.4 > > > > > > > > > > > > * Added missing attributes to sources jar manifest > > > > > > > > > > > > > > > > > > > > > > > > The files are here: > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > http://people.apache.org/~psteitz/commons-pool-1.5-RC2/ > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Source and binary archives agree with each other; hashes and > > > > sigs OK. > > > > > > > > > > > > > > > > > > > > > > Unfortunately, I got a new test failure with Java 1.4.2 and > > > > Maven: > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > testEvictorVisiting(org.apache.commons.pool.impl.TestGenericKeyedObjectPool) > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Time elapsed: 0.063 sec <<< FAILURE! > > > > > > > > > > > junit.framework.AssertionFailedError > > > > > > > > > > > at > > > > junit.framework.Assert.fail(Assert.java:47) > > > > > > > > > > > at > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > junit.framework.Assert.assertTrue(Assert.java:20) > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > at > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > junit.framework.Assert.assertTrue(Assert.java:27) > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > at > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > org.apache.commons.pool.impl.TestGenericKeyedObjectPool.checkEvictorVisiting(TestGenericKeyedObjectPool.java:947) > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > at > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > org.apache.commons.pool.impl.TestGenericKeyedObjectPool.testEvictorVisiting(TestGenericKeyedObjectPool.java:810) > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > I tried re-running the test, and it was OK. Tried rebuild and > > > > retest - > > > > > > > > OK. > > > > > > > > > > > > > > > > > > > > > > As far as I can tell, that particular test does not use > > > > threads or > > > > > > > > > > > timers as part of the test case, so that suggests that there > > > > might be > > > > > > > > > > > a timing/threading issue in the main pool code. > > > > > > > > > > > > > > > > > > > > > > I'll try re-running the test case a few more times to see if > > > > I can get > > > > > > > > > > > it to go wrong again. > > > > > > > > > > > > > > > > > > > > > > Also, clearly the failure message needs to be enhanced to > > > > show which > > > > > > > > > > > of the following checks failed: > > > > > > > > > > > > > > > > > > > > > > assertTrue(visitCount >= cycleCount && > > > > > > > > > > > visitCount <= cycleCount + 1); > > > > > > > > > > > > > > > > > > > > > > Unfortunately a lot of the assertions fail to provide any > > > > details of > > > > > > > > > > > what has gone wrong, which make debugging a lot harder. > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Thanks for finding and looking into this. Should not be > > > > happening. > > > > > > > > Sorry > > > > > > > > > > the tests in general and this one in particular are so cryptic. > > > > What > > > > > > > > this > > > > > > > > > > one is doing is verifying that the evictor visits idle > > > > instances in the > > > > > > > > > > keyed pools in oldest-to-youngest order and does not > > > > systematically miss > > > > > > > > > > any. What would be good to know at the time of the failure > > > > above is the > > > > > > > > > > values of the local variables visitCount, cycleCount and > > > > totalInstances. > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Probably also the values of the enclosing loop counts. > > > > > > > > > It would perhaps be useful to not fail on the first such error, > > > > but > > > > > > > > > only fail when all the objects have been checked, so one could > > > > see how > > > > > > > > > many objects are not visited the expected number of times. > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > What is going on in this part of the test is that there are > > > > three keyed > > > > > > > > > > pools randomly generated containing a total of totalInstances > > > > idle > > > > > > > > objects. > > > > > > > > > > The evictor is run a random number of times (between 10 and 60) > > > > and what > > > > > > > > we > > > > > > > > > > expect is that each instance in the combined pool will be > > > > "visited" > > > > > > > > either > > > > > > > > > > cycleCount or cycleCount +1 times, where > > > > > > > > > > cycleCount = (runs * > > > > pool.getNumTestsPerEvictionRun()) > > > > > > > > / > > > > > > > > > > totalInstances. That is the assertion that is failing. I > > > > don't see > > > > > > > > off > > > > > > > > > > the top of my head how this can be timing or > > > > concurrency-related. > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Could there be an issue with checking the age? > > > > > > > > > I don't know how the ages are compared, but Java time resolution > > > > means > > > > > > > > > multiple objects can be created in the same time slot. > > > > > > > > > > > > > > > > > > > > > > > > > > Not in this case. The test that is failing is not looking at age > > > > or > > > > > > > > "evicting" instances because of age. It is just validating idle > > > > objects in > > > > > > > > the pool (testWhileIdle = true). > > > > > > > > > > > > > > > > > > > > > Could the evictor be visiting items in the wrong order? > > > > > > > Perhaps favouring one object over another? > > > > > > > > > > > > > > I guess we'd need to validate all the counts before failing in order > > > > > > > to find out. > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > I will > > > > > > > > > > also look into this and see if I can get it to fail. Thanks > > > > again for > > > > > > > > your > > > > > > > > > > help on this. > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > In case it helps, my DOS script for this is: > > > > > > > > > > > > > > > > > > call mvn compiler:testCompile > > > > > > > > > echo Start >>testn.log > > > > > > > > > :LOOP0 > > > > > > > > > echo %DATE% %TIME% >>testn.log > > > > > > > > > call mvn -Dtest=TestGenericKeyedObjectPool > > > > surefire:test > > > > > > > > > goto LOOP%ERRORLEVEL% > > > > > > > > > :LOOP1 > > > > > > > > > type target\surefire-reports\*.txt >>testn.log > > > > > > > > > call bell > > > > > > > > > > > > > > > > > > If you are not using Windows, it should be easy to change > > > > accordingly > > > > > > > > > > > > > > > > > > I have also just seen the following error: > > > > > > > > > > > > > > > > > > Running > > > > > > > > > > > > org.apache.commons.pool.impl.TestGenericKeyedObjectPool > > > > > > > > > java.util.NoSuchElementException: Timeout > > > > waiting for > > > > > > > > idle object > > > > > > > > > at > > > > > > > > > > > > org.apache.commons.pool.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:1139) > > > > > > > > > at > > > > > > > > > > > > org.apache.commons.pool.impl.TestGenericKeyedObjectPool$TestThread.run(TestGenericKeyedObjectPool.java:1339) > > > > > > > > > at java.lang.Thread.run(Thread.java:534) > > > > > > > > > > > > > > > > > > I'm working on improving the reporting for this as well (at > > > > present > > > > > > > > > the stack trace only goes to stderr; it would be useful if it was > > > > > > > > > added to the surefire report). > > > > > > > > > > > > > > > > > > > > > > > > > > Thanks. That one could be timing. Pls go ahead and commit your > > > > > > > > improvements so we can be looking at the same traces. > > > > > > > > > > > > > > > > > > > > > OK, done. > > > > > > > > > > > > > > > > > > > > > > > > > > > Just had another fail: > > > > > > > > > > > > > > > > testEvictorVisiting(org.apache.commons.pool.impl.TestGenericKeyedObjectPool) > > > > > > Time elapsed: 0.094 sec <<< FAILURE! > > > > > > junit.framework.AssertionFailedError: i 0 j 0 k 20 > > > > visitCount 0 > > > > > > cycleCount 1 totalInstances 70 Length 21 > > > > > > at junit.framework.Assert.fail(Assert.java:47) > > > > > > at junit.framework.Assert.assertTrue(Assert.java:20) > > > > > > at > > > > org.apache.commons.pool.impl.TestGenericKeyedObjectPool.checkEvictorVisiting(TestGenericKeyedObjectPool.java:949) > > > > > > at > > > > org.apache.commons.pool.impl.TestGenericKeyedObjectPool.testEvictorVisiting(TestGenericKeyedObjectPool.java:812) > > > > > > > > > > > > Line 949 is the same as previous 947 (added 2 imports) > > > > > > > > > > > > Do the extra details of the numbers help? > > > > > > > > > > > > > > > > > Yes! I think I have found the problem. I think the change in r776085 to > > > > address POOL-125 inadvertently changed the order of the elements in the > > > > evictioncursor when the pool is operating in FIFO mode (why I asked about > > > > the line number above). I have been able to reproduce the failure using jdk > > > > 1.4. I am working on a fix. Strange that it does not seem to show up using > > > > 1.6. Must be a PRNG artifact. > > > > > > > > > The modified code looks correct. Could be a test bug. Still > > > > investigating... > > > > > > > > > I've noticed that k == (twoLength - 1) i.e. it is always the last > > > entry that fails the check, and it seems to always be 1 less than > > > expected. > > > > > > I've added some code to my working copy to print out the visit counts > > > for the other entries on failure; if that works OK I'll commit it. > > > > > > > > > Committed the code. > > > > One example failure is: > > > > Tests run: 43, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: > > 28.672 sec <<< FAILURE! > > > > testEvictorVisiting(org.apache.commons.pool.impl.TestGenericKeyedObjectPool) > > > > Time elapsed: 0.031 sec <<< FAILURE! > > junit.framework.AssertionFailedError: TWO Visits:2 2 2 2 2 2 2 2 2 2 2 > > 2 2 2 2 1 runs=52 lifo=false i=0 j=0 k=15 visitCount=1 cycleCount=2 > > totalInstances=52 Lengths=10,26,16 > > > > at junit.framework.Assert.fail(Assert.java:47) > > > > at org.apache.commons.pool.impl.TestGenericKeyedObjectPool.checkEvictorVisiting(TestGenericKeyedObjectPool.java:962) > > > > at org.apache.commons.pool.impl.TestGenericKeyedObjectPool.testEvictorVisiting(TestGenericKeyedObjectPool.java:812) > > > > > > This shows that all the visitCounts are OK apart from the last. > > Perhaps an off-by-one error somewhere? > > > > Two more fails: > > > > junit.framework.AssertionFailedError: TWO Visits:2 2 2 2 2 2 2 2 2 2 2 > > 2 2 2 2 2 2 2 2 2 2 2 2 2 2 2 1 runs=59 lifo=false i=0 j=0 k=26 > > visitCount=1 cycleCount=2 totalInstances=59 Lengths=17,15,27 > > > > junit.framework.AssertionFailedError: TWO Visits:1 1 1 1 1 1 1 1 1 1 1 > > 1 1 1 1 1 0 runs=23 lifo=false i=0 j=0 k=16 visitCount=0 cycleCount=1 > > totalInstances=46 Lengths=17,12,17 > > > > > I just tried using the fixed numbers from a failed run (instead of > using random ones), and it fails every time with the following > settings: > > runs=26 > Lengths=12,12,28 > > So it's clearly some kind of logic error - looks like it occurs where > "runs" is an exact multiple of "totalInstances". s/multiple/divisor/ As an experiment, I tried switching the order of the entries in the smallPrimes array to 3,2,5,7. I expected the test to fail on the second loop, but it did not fail. I think this must mean that pool.clear() does not reset the pool fully. > > > > > > > > > Phil > > > > > > > > > > > > > > > > > > Cryptic as they may be, I am happy to see that the unit tests picked up > > > > this little bug :) > > > > > > > > > > Thanks! > > > > > > > > > > Phil > > > > > > > > > > > > > > > > > > > > > > > > > Phil > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Phil > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > == > > > > > > > > > > > > > > > > > > > > > > Not sure if this is a problem, but the RELEASE-NOTES etc > > > > refer to > > > > > > > > 1.5-RC2. > > > > > > > > > > > > > > > > > > > > > > The OSGI versions likewise include the RC2. > > > > > > > > > > > > > > > > > > > > > > Does that mean there will need to be another build and vote > > > > before > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > release? > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Yes. I will roll a "final" candidate with the artifact name > > > > changed > > > > > > > > (but > > > > > > > > > > tag name still RC-) and we will VOTE on that. > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > The tag is here: > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > http://svn.apache.org/repos/asf/commons/proper/pool/tags/POOL_1_5_RC2/ > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > I used "Last Changed Rev: 780316" > > > > > > > > > > > > > > > > > > > > > > The differences between the xml files have now disappeared; > > > > not sure > > > > > > > > > > > what went wrong before. > > > > > > > > > > > > > > > > > > > > > > Also the only difference between the tag and the source > > > > archives are > > > > > > > > > > > doap and release notes, as expected. > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > Thanks! > > > > > > > > > > > > > > > > > > > > > > > > Phil > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > To unsubscribe, e-mail: > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > dev-unsubscribe@commons.apache.org > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > For additional commands, e-mail: > > > > dev-help@commons.apache.org > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > To unsubscribe, e-mail: > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > dev-unsubscribe@commons.apache.org > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > For additional commands, e-mail: dev-help@commons.apache.org > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > > > > > > > > > To unsubscribe, e-mail: > > > > > > > > dev-unsubscribe@commons.apache.org > > > > > > > > > > For additional commands, e-mail: dev-help@commons.apache.org > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > > > > > > > > To unsubscribe, e-mail: > > > > > > > > dev-unsubscribe@commons.apache.org > > > > > > > > > For additional commands, e-mail: dev-help@commons.apache.org > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > > > > > > > To unsubscribe, e-mail: > > > > dev-unsubscribe@commons.apache.org > > > > > > > > For additional commands, e-mail: dev-help@commons.apache.org > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > > > > > To unsubscribe, e-mail: > > > > dev-unsubscribe@commons.apache.org > > > > > > For additional commands, e-mail: dev-help@commons.apache.org > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > > > To unsubscribe, e-mail: dev-unsubscribe@commons.apache.org > > > > For additional commands, e-mail: dev-help@commons.apache.org > > > > > > > > > > > > > > --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscribe@commons.apache.org For additional commands, e-mail: dev-help@commons.apache.org