Re: Two tests still failing

Mon, 18 Mar 2013 05:48:07 -0700

Actually it turns out that callBackWait is more important than slop, since this is the timout period, but then a spurious wakeup can also cause an issue.
The cpu load is between 70 to 100% during the test. Perhaps Arm just needs a little more time. 

Will know soon. ;)

On 18/03/2013 10:35 PM, Dan Creswell wrote:

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



























					Reply via email to