On 18 March 2013 05:09, Peter Firmstone <[email protected]> wrote: > Thanks Dan, > > I extended the timeout waiting for the event to arrive for those two tests > and eliminated any further failures. > > However there is one remaining failing test on arm, it is likely a timing > issue. > > The slop is actually quite an important factor for the test to pass and it > may be too large in this case, I've since reduced it to 2000, but even that > may be too great. > > I'm going to try reducing it further. These tests seem to be very timing > dependant. >
Mmm, the generation and dispatch of events is done in the background and, obvious, with a busy or memory constrained machine (lots of gc) it can take a while. I guess it's possible that leases might be too short for propagation time in certain environments. Also worth noting that lease renewal also has to be done some time in advance of expiry with a similar care for propagation time (LRM does that by default). How busy/loaded/constrained is the machine you're testing on? > Cheers, > > Peter. > > > On 18/03/2013 11:40 AM, Dan Creswell wrote: >> >> You got the error logs or can you point me at them someplace? >> >> On 17 March 2013 07:23, Peter Firmstone<[email protected]> wrote: >>> >>> These two tests still fail on occasion on a 4 way CPU sparc: >>> >>> >>> run.tests=com/sun/jini/test/spec/javaspace/conformance/ExpirationNotifyTest.td,\ >>> >>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td >>> >>> They also fail on Jenkins, jdk7 and arm. >>> >>> Is anyone able to help find the cause? >>> >>> Regards, >>> >>> Peter. > > > Running > com/sun/jini/test/impl/outrigger/leasing/UseNotifyLeaseTestRenewCancel.td > Time is Mon Mar 11 21:04:42 CDT 2013 > Starting test in separate process with command: > /usr/lib/jvm/jdk1.7.0_06/jre/bin/java > -Djava.security.manager=org.apache.river.api.security.CombinerSecurityManager > -Djava.security.policy=file:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/harness/policy/defaulttest.policy > '-Djava.rmi.server.codebase=http://je-cal-16:9082/qa1-outrigger-dl.jar > http://je-cal-16:9082/qa1-share-dl.jar' -cp > /home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib/jiniharness.jar:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib/jinitests.jar:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/jsk-platform.jar:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/jsk-lib.jar:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/high-scale-lib.jar:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/custard-apple-1.0.2.jar > -ea -esa -client > -Djava.ext.dirs=/usr/lib/jvm/jdk1.7.0_06/jre/lib/ext:/usr/java/packages/lib/ext:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib-ext:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib-ext > -Dcom.sun.jini.jsk.port=9080 -Dcom.sun.jini.qa.port=9081 > -Dcom.sun.jini.jsk.home=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm > -Dcom.sun.jini.qa.home=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa > -Dcom.sun.jini.qa.harness.harnessJar=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib/jiniharness.jar > -Dcom.sun.jini.qa.harness.testJar=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib/jinitests.jar > -Dcom.sun.jini.qa.harness.runjiniserver=true > -Dcom.sun.jini.qa.harness.runkitserver=true > -Djava.security.properties=file:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/harness/trust/dynamic-policy.properties > -Dcom.sun.jini.qa.harness.testhosts= > -Djava.util.logging.config.file=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/src/com/sun/jini/test/resources/qa1.logging > -Dcom.sun.jini.test.home=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa > -Dcom.sun.jini.test.port=9082 > -Dcom.sun.jini.qa.harness.policies=file:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/src/com/sun/jini/test/resources/jinitest.policy > -Djava.ext.dirs=/usr/lib/jvm/jdk1.7.0_06/jre/lib/ext:/usr/java/packages/lib/ext:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib-ext:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib-ext > com.sun.jini.qa.harness.MasterTest > com/sun/jini/test/impl/outrigger/leasing/UseNotifyLeaseTestRenewCancel.td > > TIME: 9:04:42 PM > > MasterTest.doTest INFO: > ============================== CALLING CONSTRUCT() > ============================== > > AdminManager.startService FINE: starting qaClassServer > FINE: > FINE: Parameters for qaClassServer(.0): > FINE: type : classServer > FINE: impl : com.sun.jini.tool.ClassServer > FINE: directory : > /home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib > FINE: options : -ea -esa > AdminManager.startService FINE: starting jiniClassServer > Mar 11, 2013 9:04:43 PM com.sun.jini.tool.ClassServer run > INFO: ClassServer started > [[/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib/], port > 9081] > FINE: > FINE: Parameters for jiniClassServer(.0): > FINE: type : classServer > FINE: impl : com.sun.jini.tool.ClassServer > FINE: directory : > /home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib-dl > FINE: options : -ea -esa > AdminManager.startService FINE: starting testClassServer > Mar 11, 2013 9:04:43 PM com.sun.jini.tool.ClassServer run > INFO: ClassServer started > [[/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib-dl/], port > 9080] > FINE: > FINE: Parameters for testClassServer(.0): > FINE: type : classServer > FINE: impl : com.sun.jini.tool.ClassServer > FINE: directory : > /home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib > FINE: options : -ea -esa > TestBase.construct FINE: Test Name = > com.sun.jini.test.impl.outrigger.leasing.UseNotifyLeaseTest > Mar 11, 2013 9:04:43 PM com.sun.jini.tool.ClassServer run > INFO: ClassServer started > [[/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib/], port > 9082] > LeaseGrantTestBase.parse INFO: exact = true > LeaseGrantTestBase.parse INFO: clip = -1 > LeaseGrantTestBase.parse INFO: slop = 10,000 > LeaseGrantTestBase.parse INFO: durationRequest = 60,000 > LeaseUsesTestBase.parse INFO: renewals = 2 > LeaseUsesTestBase.parse INFO: cancel = true > LeaseUsesTestBase.parse INFO: renewWait = -1 > LeaseUsesTestBase.parse INFO: shutdownTime = -1 > LeaseUsesTestBase.parse INFO: restartSleep = 10,000 > LeaseUsesTestBase.parse INFO: cancelSlop = 0 > UseNotifyLeaseTest.parse INFO: callbackWait = 2000 > UseNotifyLeaseTest.parse INFO: verbose = false > LeaseGrantTestBase.parse INFO: exact = true > LeaseGrantTestBase.parse INFO: clip = -1 > LeaseGrantTestBase.parse INFO: slop = 10,000 > LeaseGrantTestBase.parse INFO: durationRequest = 60,000 > LeaseUsesTestBase.parse INFO: renewals = 2 > LeaseUsesTestBase.parse INFO: cancel = true > LeaseUsesTestBase.parse INFO: renewWait = -1 > LeaseUsesTestBase.parse INFO: shutdownTime = -1 > LeaseUsesTestBase.parse INFO: restartSleep = 10,000 > LeaseUsesTestBase.parse INFO: cancelSlop = 0 > UseNotifyLeaseTest.parse INFO: callbackWait = 2000 > UseNotifyLeaseTest.parse INFO: verbose = false > MasterTest.doTest INFO: > =============================== CALLING RUN() > =============================== > > TestBase.dbgSpecSrvcs FINE: > TestBase.specifyServices({net.jini.space.JavaSpace}) > TestBase.dbgSpecSrvcs FINE: specifyServices groups=null locator=null > useLookup =true > AdminManager.startService FINE: starting > net.jini.core.lookup.ServiceRegistrar > QAConfig.getServiceHost FINE: Selecting service host > QAConfig.getServiceHost FINE: Not distributed - selecting this host > AdminManager.startService FINE: starting nonActivatableGroup > FINE: > FINE: Parameters for nonActivatableGroup(.0): > FINE: type : nonactivatablegroup > FINE: codebase : > http://je-cal-16:9081/nonactivatablegroup-dl.jar > FINE: impl : > com.sun.jini.qa.harness.NonActivatableGroupImpl > FINE: policy file : > file:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/harness/policy/defaultnonactvm.policy > FINE: classpath : > /home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib/nonactivatablegroup.jar:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/start.jar:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/jsk-platform.jar:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/custard-apple-1.0.2.jar:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/high-scale-lib.jar > FINE: options : -ea -esa -server > FINE: properties : > -Djava.ext.dirs=/usr/lib/jvm/jdk1.7.0_06/jre/lib/ext:/usr/java/packages/lib/ext:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib-ext:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib-ext > FINE: : -Dcom.sun.jini.jsk.port=9080 > FINE: : -Dcom.sun.jini.qa.port=9081 > FINE: : > -Dcom.sun.jini.jsk.home=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm > FINE: : > -Dcom.sun.jini.qa.home=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa > FINE: : > -Dcom.sun.jini.qa.harness.harnessJar=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib/jiniharness.jar > FINE: : > -Dcom.sun.jini.qa.harness.testJar=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/lib/jinitests.jar > FINE: : -Dcom.sun.jini.qa.harness.runjiniserver=true > FINE: : -Dcom.sun.jini.qa.harness.runkitserver=true > FINE: : > -Djava.security.properties=file:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/harness/trust/dynamic-policy.properties > FINE: : -Dcom.sun.jini.qa.harness.testhosts= > FINE: : > -Djava.util.logging.config.file=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/src/com/sun/jini/test/resources/qa1.logging > FINE: : > -Dcom.sun.jini.test.home=/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa > FINE: : -Dcom.sun.jini.test.port=9082 > FINE: : > -Dcom.sun.jini.qa.harness.policies=file:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/src/com/sun/jini/test/resources/jinitest.policy > FINE: > FINE: Parameters for net.jini.core.lookup.ServiceRegistrar(.0): > FINE: type : transient > FINE: codebase : http://je-cal-16:9080/reggie-dl.jar > http://je-cal-16:9080/jsk-dl.jar > FINE: impl : com.sun.jini.reggie.TransientRegistrarImpl > FINE: component name : com.sun.jini.reggie > FINE: policy file : > file:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/harness/policy/defaultreggie.policy > FINE: classpath : > /home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/reggie.jar > FINE: service conf file : - > FINE: starter conf file : - > FINE: proxy preparer : test.reggiePreparer > FINE: option args 0 : - > FINE: option args 1 : com.sun.jini.reggie.initialMemberGroups = new > String[]{"QATestDefaultGroup_je-cal-16_1363053882071"} > FINE: option args 2 : multicast.ttl=0 > FINE: > NonActGrp-out: Mar 11, 2013 9:04:48 PM com.sun.jini.reggie.RegistrarImpl > init > NonActGrp-out: INFO: started Reggie: 51d56f1c-3eb9-4852-879d-2fb537c0afcb, > [QATestDefaultGroup_je-cal-16_1363053882071], > ConstrainableLookupLocator[[jini://je-cal-16.apache.org:4160/], [null]] > TestBase.specifyServices FINE: Starting service #0: net.jini.space.JavaSpace > AdminManager.startService FINE: starting net.jini.space.JavaSpace > QAConfig.getServiceHost FINE: Selecting service host > QAConfig.getServiceHost FINE: Not distributed - selecting this host > FINE: > FINE: Parameters for net.jini.space.JavaSpace(.0): > FINE: type : transient > FINE: codebase : http://je-cal-16:9080/outrigger-dl.jar > http://je-cal-16:9080/jsk-dl.jar > FINE: impl : com.sun.jini.outrigger.TransientOutriggerImpl > FINE: component name : com.sun.jini.outrigger > FINE: policy file : > file:/home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/qa/harness/policy/defaultoutrigger.policy > FINE: classpath : > /home/jenkins/jenkins-slave/workspace/river-qa-refactor-arm/lib/outrigger.jar > FINE: service conf file : - > FINE: starter conf file : - > FINE: proxy preparer : test.outriggerPreparer > FINE: option args 0 : - > FINE: option args 1 : com.sun.jini.outrigger.initialLookupGroups = > new String[]{"QATestDefaultGroup_je-cal-16_1363053882071"} > FINE: option args 2 : com.sun.jini.outrigger.persistenceDirectory = > "/tmp/FrontEndSpace_log3058436766902225847dir" > FINE: option args 3 : com.sun.jini.outrigger.store=new > com.sun.jini.outrigger.snaplogstore.LogStore(this) > FINE: option args 4 : multicast.ttl=0 > FINE: > NonActGrp-out: Mar 11, 2013 9:04:51 PM > com.sun.jini.outrigger.OutriggerServerImpl<init> > NonActGrp-out: INFO: Outrigger server started: > com.sun.jini.outrigger.OutriggerServerImpl@919d3e > LeaseUsesTestBase.run INFO: Resource acquired > LeaseGrantTestBase.logRequest INFO: Lease resource: > LandlordLease:dadb6d2d-f8e9-4a58-9d08-3d2ee286de6e > landlord:Proxy[OutriggerServer,BasicInvocationHandler[BasicObjectEndpoint[b538b715-9cb4-4797-95d7-599e43117cbe,TcpEndpoint[64.20.246.145:38736]]]] > landlordUuid:3a7cbd2d-cd3f-4292-a65d-5a84fe75514d > com.sun.jini.landlord.ConstrainableLandlordLease@5dbcc435 > LeaseGrantTestBase.logRequest INFO: req:1,363,053,952,524 > LeaseGrantTestBase.logRequest INFO: got:1,363,053,952,461 > LeaseGrantTestBase.logRequest INFO: aprox duration:59,937 > LeaseGrantTestBase.logRequest INFO: drift:-63 > LeaseUsesTestBase.run INFO: Expire Test: Slop = 10,000 > com.sun.jini.qa.harness.TestException: Resource was not available before > lease expiration > at > com.sun.jini.test.impl.outrigger.leasing.LeaseUsesTestBase.run(LeaseUsesTestBase.java:218) > at com.sun.jini.qa.harness.MasterTest.doTest(MasterTest.java:256) > at com.sun.jini.qa.harness.MasterTest.main(MasterTest.java:144) > > TIME: 9:05:20 PM > > MasterTest.doTest INFO: > ============================ CALLING TEARDOWN() > ============================= > > > TIME: 9:05:35 PM > > TestBase.tearDown FINE: Waiting 0 ms after cleanup() call > QATestEnvironment.tearDown FINE: Destroying remaining managed services > AdminManager.destroyService FINE: destroying service: class > com.sun.jini.outrigger.ConstrainableSpaceProxy2 > NonActGrp-out: Mar 11, 2013 9:05:35 PM > com.sun.jini.outrigger.OutriggerServerImpl destroy > NonActGrp-out: INFO: Outrigger server destroy thread started: > com.sun.jini.outrigger.OutriggerServerImpl@919d3e > AdminManager.destroyService FINE: destroying service: class > com.sun.jini.reggie.ConstrainableRegistrarProxy > NonActGrp-out: Mar 11, 2013 9:05:35 PM com.sun.jini.reggie.RegistrarImpl > destroy > NonActGrp-out: INFO: starting Reggie shutdown > AdminManager.destroyService FINE: destroying service: class > com.sun.jini.qa.harness.NonActivatableGroupImpl$GroupImpl_Stub > NonActGrp-out: Mar 11, 2013 9:05:35 PM > com.sun.jini.outrigger.OutriggerServerImpl$DestroyThread run > NonActGrp-out: INFO: Outrigger server destroy thread finished: > Thread[DestroyThread,5,(JSK) Runtime] > NonActGrp-out: Mar 11, 2013 9:05:36 PM > com.sun.jini.reggie.RegistrarImpl$DestroyThread run > NonActGrp-out: INFO: Reggie shutdown completed > AdminManager.destroyService FINE: destroying service: class > com.sun.jini.tool.ClassServer > Mar 11, 2013 9:05:38 PM com.sun.jini.tool.ClassServer terminate > INFO: ClassServer terminated [port 9081] > AdminManager.destroyService FINE: destroying service: class > com.sun.jini.tool.ClassServer > Mar 11, 2013 9:05:38 PM com.sun.jini.tool.ClassServer terminate > INFO: ClassServer terminated [port 9081] > Mar 11, 2013 9:05:38 PM com.sun.jini.tool.ClassServer terminate > INFO: ClassServer terminated [port 9080] > AdminManager.destroyService FINE: destroying service: class > com.sun.jini.tool.ClassServer > Mar 11, 2013 9:05:38 PM com.sun.jini.tool.ClassServer terminate > INFO: ClassServer terminated [port 9080] > Mar 11, 2013 9:05:38 PM com.sun.jini.tool.ClassServer terminate > INFO: ClassServer terminated [port 9082] > Mar 11, 2013 9:05:38 PM com.sun.jini.tool.ClassServer terminate > INFO: ClassServer terminated [port 9082] > > TIME: 9:05:38 PM > > Test process was destroyed and returned code 1 > com/sun/jini/test/impl/outrigger/leasing/UseNotifyLeaseTestRenewCancel.td > Test Failed: Test Failed: com.sun.jini.qa.harness.TestException: Resource > was not available before lease expiration > > >
