You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@river.apache.org by Peter Firmstone <ji...@zeus.net.au> on 2013/03/17 13:23:12 UTC
Two tests still failing
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.
Re: Two tests still failing
Posted by Peter Firmstone <ji...@zeus.net.au>.
Dan,
I think I found the issue, I suspect it's a spurious wakeup during a
call to wait(callBackWait) that doesn't check the condition is true or
the timeout isn't long enough.
It could simply be that the callBackWait period is too short.
In any case you can't tell if you've been woken by a spurious wakeup or
a timeout, I'm going to add the check as see if it flys.
This is part of the isAvailable() method, if this returns false, the
lease isn't available.
See com.sun.jini.test.impl.outrigger.leasing.UseNotifyLeaseTest
In other words, if i shorten up the wait time, I can simulate failure.
ant -f
C:\\Users\\peter\\Documents\\NetBeansProjects\\peterConcurrentPolicy
qa.run-tests
qa.run-tests:
qa.james-brown:
Deleting directory
C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\soul
Created dir:
C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\soul
Creating
C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\soul\soul.201303182142051385
qa.run-tests:
-----------------------------------------
CONFIGURATION FILE:
C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\src\com\sun\jini\test\resources\qaHarness.prop
-----------------------------------------
SETTING UP THE TEST LIST:
Adding test:
com/sun/jini/test/impl/outrigger/leasing/UseNotifyLeaseTestRenew.td
-----------------------------------------
GENERAL HARNESS CONFIGURATION INFORMATION:
Date started:
Mon Mar 18 21:42:52 EST 2013
Installation directory of the JSK:
com.sun.jini.jsk.home=C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy
Installation directory of the harness:
com.sun.jini.qa.home=C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa
Categories being tested:
categories=No Categories
-----------------------------------------
ENVIRONMENT PROPERTIES:
JVM information:
Java HotSpot(TM) Client VM, 20.1-b02, 32 bit VM mode
Sun Microsystems Inc.
OS information:
Windows 7, 6.1, x86
-----------------------------------------
STARTING TO RUN THE TESTS
Running com/sun/jini/test/impl/outrigger/leasing/UseNotifyLeaseTestRenew.td
Time is Mon Mar 18 21:42:52 EST 2013
Starting test in separate process with command:
'C:\Program Files\Java\jdk1.6.0_26\jre\bin\java'
-Djava.security.manager=org.apache.river.api.security.CombinerSecurityManager
-Djava.security.policy=file:/C:/Users/peter/Documents/NetBeansProjects/peterConcurrentPolicy/qa/harness/policy/defaulttest.policy
'-Djava.rmi.server.codebase=http://medusa:9082/qa1-outrigger-dl.jar
http://medusa:9082/qa1-share-dl.jar' -cp
C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\lib\jiniharness.jar;C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\lib\jinitests.jar;C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\lib\jsk-platform.jar;C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\lib\jsk-lib.jar;C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\lib\high-scale-lib.jar;C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\lib\custard-apple-1.0.2.jar
-ea -esa -client '-Djava.ext.dirs=C:\Program
Files\Java\jdk1.6.0_26\jre\lib\ext;C:\windows\Sun\Java\lib\ext;C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\lib-ext;C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\lib-ext'
-Dcom.sun.jini.jsk.port=9080 -Dcom.sun.jini.qa.port=9081
-Dcom.sun.jini.jsk.home=C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy
-Dcom.sun.jini.qa.home=C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa
-Dcom.sun.jini.qa.harness.harnessJar=C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\lib\jiniharness.jar
-Dcom.sun.jini.qa.harness.testJar=C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\lib\jinitests.jar
-Dcom.sun.jini.qa.harness.runjiniserver=true
-Dcom.sun.jini.qa.harness.runkitserver=true
-Djava.security.properties=file:/C:/Users/peter/Documents/NetBeansProjects/peterConcurrentPolicy/qa/harness/trust/dynamic-policy.properties
-Dcom.sun.jini.qa.harness.testhosts=
-Djava.util.logging.config.file=C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\src\com\sun\jini\test\resources\qa1.logging
-Dcom.sun.jini.test.home=C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa
-Dcom.sun.jini.test.port=9082
-Dcom.sun.jini.qa.harness.policies=file:/C:/Users/peter/Documents/NetBeansProjects/peterConcurrentPolicy/qa/src/com/sun/jini/test/resources/jinitest.policy
'-Djava.ext.dirs=C:\Program
Files\Java\jdk1.6.0_26\jre\lib\ext;C:\windows\Sun\Java\lib\ext;C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\lib-ext;C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\lib-ext'
com.sun.jini.qa.harness.MasterTest
com/sun/jini/test/impl/outrigger/leasing/UseNotifyLeaseTestRenew.td
TIME: 9:42:53 PM
MasterTest.doTest INFO:
============================== CALLING CONSTRUCT()
==============================
18/03/2013 9:42:53 PM com.sun.jini.tool.ClassServer run
INFO: ClassServer started
[[C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\lib\],
port 9081]
18/03/2013 9:42:53 PM com.sun.jini.tool.ClassServer run
INFO: ClassServer started
[[C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\lib-dl\],
port 9080]
18/03/2013 9:42:53 PM com.sun.jini.tool.ClassServer run
INFO: ClassServer started
[[C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\lib\],
port 9082]
LeaseGrantTestBase.parse INFO: exact = true
LeaseGrantTestBase.parse INFO: clip = -1
LeaseGrantTestBase.parse INFO: slop = 1,000
LeaseGrantTestBase.parse INFO: durationRequest = 60,000
LeaseUsesTestBase.parse INFO: renewals = 2
LeaseUsesTestBase.parse INFO: cancel = false
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 = 50
UseNotifyLeaseTest.parse INFO: verbose = false
LeaseGrantTestBase.parse INFO: exact = true
LeaseGrantTestBase.parse INFO: clip = -1
LeaseGrantTestBase.parse INFO: slop = 1,000
LeaseGrantTestBase.parse INFO: durationRequest = 60,000
LeaseUsesTestBase.parse INFO: renewals = 2
LeaseUsesTestBase.parse INFO: cancel = false
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 = 50
UseNotifyLeaseTest.parse INFO: verbose = false
MasterTest.doTest INFO:
=============================== CALLING RUN()
===============================
NonActGrp-out: 18/03/2013 9:42:55 PM com.sun.jini.reggie.RegistrarImpl init
NonActGrp-out: INFO: started Reggie:
e5b41c25-f313-4593-9fbf-14892f7dfa14,
[QATestDefaultGroup_medusa_1363606972719],
ConstrainableLookupLocator[[jini://medusa:4160/], [null]]
NonActGrp-out: 18/03/2013 9:42:56 PM
com.sun.jini.outrigger.OutriggerServerImpl <init>
NonActGrp-out: INFO: Outrigger server started:
com.sun.jini.outrigger.OutriggerServerImpl@14b6b02
LeaseUsesTestBase.run INFO: Resource acquired
LeaseGrantTestBase.logRequest INFO: Lease resource:
LandlordLease:9f5eda09-8414-4c9b-b43f-4595bf4216d1
landlord:Proxy[OutriggerServer,BasicInvocationHandler[BasicObjectEndpoint[803a7a34-03b7-4ec7-b8a8-afa2690e6db8,TcpEndpoint[10.42.238.66:54781]]]]
landlordUuid:32080020-0b63-4c40-8b88-b3564678389c
com.sun.jini.landlord.ConstrainableLandlordLease@1037c5d6
LeaseGrantTestBase.logRequest INFO: req:1,363,607,037,637
LeaseGrantTestBase.logRequest INFO: got:1,363,607,037,620
LeaseGrantTestBase.logRequest INFO: aprox duration:59,983
LeaseGrantTestBase.logRequest INFO: drift:-17
LeaseUsesTestBase.run INFO: Expire Test: Slop = 1,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)
MasterTest.doTest INFO:
============================ CALLING TEARDOWN()
=============================
NonActGrp-out: 18/03/2013 9:43:03 PM
com.sun.jini.outrigger.OutriggerServerImpl destroy
NonActGrp-out: INFO: Outrigger server destroy thread started:
com.sun.jini.outrigger.OutriggerServerImpl@14b6b02
NonActGrp-out: 18/03/2013 9:43:03 PM com.sun.jini.reggie.RegistrarImpl
destroy
NonActGrp-out: INFO: starting Reggie shutdown
NonActGrp-out: 18/03/2013 9:43:04 PM
com.sun.jini.outrigger.OutriggerServerImpl$DestroyThread run
NonActGrp-out: INFO: Outrigger server destroy thread finished:
Thread[DestroyThread,5,(JSK) Runtime]
NonActGrp-out: 18/03/2013 9:43:04 PM
com.sun.jini.reggie.RegistrarImpl$DestroyThread run
NonActGrp-out: INFO: Reggie shutdown completed
18/03/2013 9:43:06 PM com.sun.jini.tool.ClassServer terminate
INFO: ClassServer terminated [port 9082]
18/03/2013 9:43:06 PM com.sun.jini.tool.ClassServer terminate
INFO: ClassServer terminated [port 9082]
18/03/2013 9:43:06 PM com.sun.jini.tool.ClassServer terminate
INFO: ClassServer terminated [port 9081]
18/03/2013 9:43:06 PM com.sun.jini.tool.ClassServer terminate
INFO: ClassServer terminated [port 9081]
18/03/2013 9:43:06 PM com.sun.jini.tool.ClassServer terminate
INFO: ClassServer terminated [port 9080]
18/03/2013 9:43:06 PM com.sun.jini.tool.ClassServer terminate
INFO: ClassServer terminated [port 9080]
TIME: 9:43:06 PM
Test process was destroyed and returned code 1
com/sun/jini/test/impl/outrigger/leasing/UseNotifyLeaseTestRenew.td
Test Failed: Test Failed: com.sun.jini.qa.harness.TestException:
Resource was not available before lease expiration
-----------------------------------------
SUMMARY =================================
com/sun/jini/test/impl/outrigger/leasing/UseNotifyLeaseTestRenew.td
Test Failed: Test Failed: com.sun.jini.qa.harness.TestException:
Resource was not available before lease expiration
-----------------------------------------
# of tests started = 1
# of tests completed = 1
# of tests passed = 0
# of tests failed = 1
-----------------------------------------
Date finished:
Mon Mar 18 21:43:11 EST 2013
Time elapsed:
18 seconds
Java Result: 1
qa.collect-result:
C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\build.xml:2101:
The following error occurred while executing this line:
C:\Users\peter\Documents\NetBeansProjects\peterConcurrentPolicy\qa\build.xml:357:
condition satisfied
BUILD FAILED (total time: 20 seconds)
On 18/03/2013 8:09 PM, Peter Firmstone 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.
>
> 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<ji...@zeus.net.au> 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
>
>
>
Re: Two tests still failing
Posted by Peter Firmstone <ji...@zeus.net.au>.
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<ji...@zeus.net.au> 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<ji...@zeus.net.au> 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
>>
>>
>>
Re: Two tests still failing
Posted by Dan Creswell <da...@gmail.com>.
On 18 March 2013 05:09, Peter Firmstone <ji...@zeus.net.au> 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<ji...@zeus.net.au> 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
>
>
>
Re: Two tests still failing
Posted by Peter Firmstone <ji...@zeus.net.au>.
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<ji...@zeus.net.au> 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
Re: Two tests still failing
Posted by Dan Creswell <da...@gmail.com>.
You got the error logs or can you point me at them someplace?
On 17 March 2013 07:23, Peter Firmstone <ji...@zeus.net.au> 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.