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.
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
