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/03 02:18:12 UTC

Help: Javaspace concurrency expert needed

Who's smart enough to figure out the cause and fix this test failure?

   

     [java] -----------------------------------------
     [java]
     [java] Running 
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
     [java] Time is Sat Mar 02 10:16:04 EST 2013
     [java] Starting test in separate process with command:
     [java] 
/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/bin/java 
-Djava.security.manager=org.apache.river.api.security.CombinerSecurityManager 
-Djava.security.policy=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaulttest.policy 
-Djava.rmi.server.codebase=http://Bryan-Thompson-MacBook-Air.local:9082/qa1-javaspace-dl.jar 
-cp 
/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar:/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar 
-client 
-Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext 
-Dcom.sun.jini.jsk.port=9080 -Dcom.sun.jini.qa.port=9081 
-Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk 
-Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa 
-Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar 
-Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar 
-Dcom.sun.jini.qa.harness.runjiniserver=true 
-Dcom.sun.jini.qa.harness.runkitserver=true 
-Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties 
-Dcom.sun.jini.qa.harness.testhosts= 
-Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging 
-Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa 
-Dcom.sun.jini.test.port=9082 
-Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy 
-Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext 
com.sun.jini.qa.harness.MasterTest 
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td 

     [java]
     [java] TIME: 10:16:05 AM
     [java]
     [java] MasterTest.doTest INFO:
     [java] ============================== CALLING CONSTRUCT() 
==============================
     [java]
     [java] AdminManager.startService FINE: starting qaClassServer
     [java] FINE:
     [java] FINE: Parameters for qaClassServer(.0):
     [java] FINE:      type              : classServer
     [java] FINE:      impl              : com.sun.jini.tool.ClassServer
     [java] FINE:      directory         : 
/Users/bryan/Documents/workspace/river/trunk/qa/lib
     [java] FINE:      options           :
     [java] AdminManager.startService FINE: starting jiniClassServer
     [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
     [java] INFO: ClassServer started 
[[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9081]
     [java] FINE:
     [java] FINE: Parameters for jiniClassServer(.0):
     [java] FINE:      type              : classServer
     [java] FINE:      impl              : com.sun.jini.tool.ClassServer
     [java] FINE:      directory         : 
/Users/bryan/Documents/workspace/river/trunk/lib-dl
     [java] FINE:      options           :
     [java] AdminManager.startService FINE: starting testClassServer
     [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
     [java] INFO: ClassServer started 
[[/Users/bryan/Documents/workspace/river/trunk/lib-dl/], port 9080]
     [java] FINE:
     [java] FINE: Parameters for testClassServer(.0):
     [java] FINE:      type              : classServer
     [java] FINE:      impl              : com.sun.jini.tool.ClassServer
     [java] FINE:      directory         : 
/Users/bryan/Documents/workspace/river/trunk/qa/lib
     [java] FINE:      options           :
     [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
     [java] INFO: ClassServer started 
[[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9082]
     [java] JavaSpaceTest.logDebugText FINE: : Test Name = 
com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest
     [java] JavaSpaceTest.logDebugText FINE: : ----- JavaSpace Info -----
     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace impl class     
-- com.sun.jini.outrigger.PersistentOutriggerImpl
     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace codebase       
-- http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar 
http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace classpath      
-- /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace policy file    
-- 
file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy
     [java] JavaSpaceTest.logDebugText FINE: : --------------------------
     [java] AdminManager.startService FINE: starting 
net.jini.space.JavaSpace
     [java] QAConfig.getServiceHost FINE: Selecting service host
     [java] QAConfig.getServiceHost FINE: Not distributed - selecting 
this host
     [java] AdminManager.startService FINE: starting nonActivatableGroup
     [java] FINE:
     [java] FINE: Parameters for nonActivatableGroup(.0):
     [java] FINE:      type              : nonactivatablegroup
     [java] FINE:      codebase          : 
http://Bryan-Thompson-MacBook-Air.local:9081/nonactivatablegroup-dl.jar
     [java] FINE:      impl              : 
com.sun.jini.qa.harness.NonActivatableGroupImpl
     [java] FINE:      policy file       : 
file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultnonactvm.policy
     [java] FINE:      classpath         : 
/Users/bryan/Documents/workspace/river/trunk/qa/lib/nonactivatablegroup.jar:/Users/bryan/Documents/workspace/river/trunk/lib/start.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar
     [java] FINE:      options           : -server
     [java] FINE:      properties        : 
-Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
     [java] FINE:                        : -Dcom.sun.jini.jsk.port=9080
     [java] FINE:                        : -Dcom.sun.jini.qa.port=9081
     [java] FINE:                        : 
-Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
     [java] FINE:                        : 
-Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
     [java] FINE:                        : 
-Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar
     [java] FINE:                        : 
-Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar
     [java] FINE:                        : 
-Dcom.sun.jini.qa.harness.runjiniserver=true
     [java] FINE:                        : 
-Dcom.sun.jini.qa.harness.runkitserver=true
     [java] FINE:                        : 
-Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties
     [java] FINE:                        : 
-Dcom.sun.jini.qa.harness.testhosts=
     [java] FINE:                        : 
-Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging
     [java] FINE:                        : 
-Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa
     [java] FINE:                        : -Dcom.sun.jini.test.port=9082
     [java] FINE:                        : 
-Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy
     [java] FINE:
     [java] FINE: Parameters for net.jini.space.JavaSpace(.0):
     [java] FINE:      type              : transient
     [java] FINE:      codebase          : 
http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar 
http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
     [java] FINE:      impl              : 
com.sun.jini.outrigger.TransientOutriggerImpl
     [java] FINE:      component name    : com.sun.jini.outrigger
     [java] FINE:      policy file       : 
file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy
     [java] FINE:      classpath         : 
/Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
     [java] FINE:      service conf file : -
     [java] FINE:      starter conf file : -
     [java] FINE:      proxy preparer    : test.outriggerPreparer
     [java] FINE:      option args 0     : -
     [java] FINE:      option args 1     : 
com.sun.jini.outrigger.initialLookupGroups = new 
String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
     [java] FINE:      option args 2     : 
com.sun.jini.outrigger.persistenceDirectory = 
"/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/FrontEndSpace_log7620264300505337132dir"
     [java] FINE:      option args 3     : 
com.sun.jini.outrigger.store=new 
com.sun.jini.outrigger.snaplogstore.LogStore(this)
     [java] FINE:      option args 4     : multicast.ttl=0
     [java] FINE:
     [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM 
com.sun.jini.outrigger.OutriggerServerImpl <init>
     [java] NonActGrp-out: INFO: Outrigger server started: 
com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
     [java] JavaSpaceTest.logDebugText FINE: : ----- Transaction Manager 
Info -----
     [java] JavaSpaceTest.logDebugText FINE: : TxnManager impl class     
-- com.sun.jini.mahalo.ActivatableMahaloImpl
     [java] JavaSpaceTest.logDebugText FINE: : TxnManager codebase       
-- http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar 
http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
     [java] JavaSpaceTest.logDebugText FINE: : TxnManager classpath      
-- /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
     [java] JavaSpaceTest.logDebugText FINE: : TxnManager policy file    
-- 
file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy
     [java] JavaSpaceTest.logDebugText FINE: : 
------------------------------------
     [java] AdminManager.startService FINE: starting 
net.jini.core.transaction.server.TransactionManager
     [java] QAConfig.getServiceHost FINE: Selecting service host
     [java] QAConfig.getServiceHost FINE: Not distributed - selecting 
this host
     [java] FINE:
     [java] FINE: Parameters for 
net.jini.core.transaction.server.TransactionManager(.0):
     [java] FINE:      type              : transient
     [java] FINE:      codebase          : 
http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar 
http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
     [java] FINE:      impl              : 
com.sun.jini.mahalo.TransientMahaloImpl
     [java] FINE:      component name    : com.sun.jini.mahalo
     [java] FINE:      policy file       : 
file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy
     [java] FINE:      classpath         : 
/Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
     [java] FINE:      service conf file : -
     [java] FINE:      starter conf file : -
     [java] FINE:      proxy preparer    : test.mahaloPreparer
     [java] FINE:      option args 0     : -
     [java] FINE:      option args 1     : 
com.sun.jini.mahalo.initialLookupGroups = new 
String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
     [java] FINE:      option args 2     : 
com.sun.jini.mahalo.persistenceDirectory = 
"/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/TxnManagerImpl_log04834234852756133875dir"
     [java] FINE:      option args 3     : multicast.ttl=0
     [java] FINE:
     [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM 
com.sun.jini.mahalo.TxnManagerImpl doInit
     [java] NonActGrp-out: INFO: Mahalo started: 
com.sun.jini.mahalo.TransientMahaloImpl@22d16a1f
     [java] MasterTest.doTest INFO:
     [java] =============================== CALLING RUN() 
===============================
     [java]
     [java]
     [java] TIME: 10:16:53 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to 
to let some listeners expire...
     [java]
     [java] TIME: 10:17:13 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to 
let to let transaction expires...
     [java]
     [java] TIME: 10:17:33 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to 
to let some listeners expire...
     [java]
     [java] TIME: 10:18:13 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to 
to let some listeners expire...
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to 
let all listeners get notifications.
     [java]
     [java] TIME: 10:18:53 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 40000) has got 2 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 80000) has got 6 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 120000) has got 8 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 600000) has got 10 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = Lease.FOREVER) has got 10 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 40000) has got 2 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : FAILED: 
SnapshotNotifyCounter: (snapshot for template SimpleEntry: [name = 
TestEntry #1, id = 1], lease time = 80000) has got 2 notifications 
instead of 4 required.
     [java] JavaSpaceTest.logDebugText FINE: : FAILED: 
SnapshotNotifyCounter: (snapshot for template SimpleEntry: [name = 
TestEntry #1, id = 1], lease time = 120000) has got 2 notifications 
instead of 4 required.
     [java] JavaSpaceTest.logDebugText FINE: : FAILED: 
SnapshotNotifyCounter: (snapshot for template SimpleEntry: [name = 
TestEntry #1, id = 1], lease time = 600000) has got 2 notifications 
instead of 4 required.
     [java] JavaSpaceTest.logDebugText FINE: : FAILED: 
SnapshotNotifyCounter: (snapshot for template SimpleEntry: [name = 
TestEntry #1, id = 1], lease time = Lease.FOREVER) has got 2 
notifications instead of 4 required.
     [java] JavaSpaceTest.logDebugText FINE: : Stage 1 with writing 
ordinal entries has been completed.
     [java] JavaSpaceTest.logDebugText FINE: : 
------------------------------
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : Starting 2-nd stage with 
snapshots.
     [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM 
com.sun.jini.outrigger.Notifier$NotifyTask logFailure
     [java] NonActGrp-out: INFO: Encountered definite exceptionwhile 
preparing to send/sending event, dropping registration
     [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such 
object in table
     [java] NonActGrp-out:     at 
net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
     [java] NonActGrp-out:     at 
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806)
     [java] NonActGrp-out:     at 
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
     [java] NonActGrp-out:     at 
net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
     [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
     [java] NonActGrp-out:     at 
com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337)
     [java] NonActGrp-out:     at 
com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
     [java] NonActGrp-out:     at 
com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
     [java] NonActGrp-out:     at 
com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
     [java] NonActGrp-out:
     [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM 
com.sun.jini.outrigger.Notifier$NotifyTask logFailure
     [java] NonActGrp-out: INFO: Encountered definite exceptionwhile 
preparing to send/sending event, dropping registration
     [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such 
object in table
     [java] NonActGrp-out:     at 
net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
     [java] NonActGrp-out:     at 
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806)
     [java] NonActGrp-out:     at 
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
     [java] NonActGrp-out:     at 
net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
     [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
     [java] NonActGrp-out:     at 
com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337)
     [java] NonActGrp-out:     at 
com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
     [java] NonActGrp-out:     at 
com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
     [java] NonActGrp-out:     at 
com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
     [java] NonActGrp-out:
     [java]
     [java] TIME: 10:19:38 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to 
to let some listeners expire...
     [java]
     [java] TIME: 10:19:58 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to 
let to let transaction expires...
     [java]
     [java] TIME: 10:20:18 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to 
to let some listeners expire...
     [java]
     [java] TIME: 10:20:58 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to 
to let some listeners expire...
     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to 
let all listeners get notifications.
     [java]
     [java] TIME: 10:21:38 AM
     [java]
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has 
got 2 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 40000) has got 2 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has 
got 6 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 80000) has got 6 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has 
got 8 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 120000) has got 8 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has 
got 10 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 600000) has got 10 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 
Lease.FOREVER) has got 10 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = Lease.FOREVER) has got 10 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has 
got 2 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 40000) has got 2 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has 
got 4 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 80000) has got 4 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has 
got 4 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 120000) has got 4 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has 
got 4 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = 600000) has got 4 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template 
= SimpleEntry: [name = TestEntry #1, id = 1], lease time = 
Lease.FOREVER) has got 4 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter: 
(snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease 
time = Lease.FOREVER) has got 4 notifications as expected
     [java] JavaSpaceTest.logDebugText FINE: : Stage 2 with writing 
snapshots has been completed.
     [java]
     [java] com.sun.jini.qa.harness.TestException: Not all listeners've 
got expected number of events.
     [java]     at 
com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest.run(SnapshotExpirationNotifyTest.java:369)
     [java]     at 
com.sun.jini.qa.harness.MasterTest.doTest(MasterTest.java:256)
     [java]     at 
com.sun.jini.qa.harness.MasterTest.main(MasterTest.java:144)
     [java] MasterTest.doTest INFO:
     [java] ============================ CALLING TEARDOWN() 
=============================
     [java]
     [java] QATestEnvironment.tearDown FINE: Destroying remaining 
managed services
     [java] AdminManager.destroyService FINE: destroying service: class 
com.sun.jini.outrigger.ConstrainableSpaceProxy2
     [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM 
com.sun.jini.outrigger.OutriggerServerImpl destroy
     [java] NonActGrp-out: INFO: Outrigger server destroy thread 
started: com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
     [java] AdminManager.destroyService FINE: destroying service: class 
com.sun.jini.mahalo.TxnMgrProxy$ConstrainableTxnMgrProxy
     [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM 
com.sun.jini.outrigger.OutriggerServerImpl$DestroyThread run
     [java] NonActGrp-out: INFO: Outrigger server destroy thread 
finished: Thread[DestroyThread,5,(JSK) Runtime]
     [java] AdminManager.destroyService FINE: destroying service: class 
com.sun.jini.qa.harness.NonActivatableGroupImpl$GroupImpl_Stub
     [java] AdminManager.destroyService FINE: destroying service: class 
com.sun.jini.tool.ClassServer
     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
     [java] INFO: ClassServer terminated [port 9080]
     [java] AdminManager.destroyService FINE: destroying service: class 
com.sun.jini.tool.ClassServer
     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
     [java] INFO: ClassServer terminated [port 9080]
     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
     [java] INFO: ClassServer terminated [port 9082]
     [java] AdminManager.destroyService FINE: destroying service: class 
com.sun.jini.tool.ClassServer
     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
     [java] INFO: ClassServer terminated [port 9082]
     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
     [java] INFO: ClassServer terminated [port 9081]
     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
     [java] INFO: ClassServer terminated [port 9081]
     [java]
     [java] TIME: 10:21:41 AM
     [java]
     [java] Test process was destroyed and returned code 1
     [java] 
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
     [java] Test Failed: Test Failed: 
com.sun.jini.qa.harness.TestException: Not all listeners've got expected 
number of events.
     [java]
     [java]
     [java] -----------------------------------------

Re: Help: Javaspace concurrency expert needed

Posted by Peter Firmstone <ji...@zeus.net.au>.
On 7/03/2013 11:49 PM, Gregg Wonderly wrote:
> Much of timer management in lease type usage, uses the 50% expired 
> rule, to make sure and try ahead of time to renew the lease or 
> otherwise register interest.  Should these tests really be up against 
> the proverbial wall (clock) in these tests?

     I don't think it was considered when the test was written, back 
then there was a delay before objects were collected, but this delay 
caused a problem when clean and dirty calls arrived out of order, it's 
documented in ObjectTable anyways.   When I fixed it, Objects were 
removed from the ObjectTable immediately.

>   Is there really any value in doing that, specifically because of 
> CPU/network stack timing and inter-process latency?

Probably not, but the test passes now ;)

>
> Gregg
>
> On 3/7/2013 7:40 AM, Peter Firmstone wrote:
>> The cause was the test sleeping and waking up as the DGC lease 
>> expired, the object was collected from the ObjectTable and the events 
>> couldn't be sent.
>>
>> DGC's a lot faster than it used to be, it's concurrent too now.
>>
>> It's not the same DGC people remember, if you had trouble with DGC in 
>> the past, it's worth trying again, Peter Jones was invaluable in 
>> helping to sort this out some time ago, he sent me a link to a paper 
>> on DGC (from DIGITAL research labs in 1993) and left very useful 
>> development hints in the form of bug reports and code comments.  The 
>> concurrent library's really helped to address the remaining issues.
>>
>> To fix this test failure, I reduced the test sleep times by 10ms. 
>> From 10,000 to 9,990 ms and 20,000 to 19,990 ms.
>>
>> Regards,
>>
>> Peter.
>>
>>
>>
>> On 3/03/2013 7:33 PM, Dan Creswell wrote:
>>> Suggests a remote reference registered via notify has gone AWOL when
>>> it shouldn't have done.
>>>
>>> The usual causes for that are DGC or garbage collection as the result
>>> of nothing holding on to the exported object.
>>>
>>> Looks like you're running trunk?
>>>
>>> On 3 March 2013 01:18, Peter Firmstone<ji...@zeus.net.au> wrote:
>>>> Who's smart enough to figure out the cause and fix this test failure?
>>>>
>>>>
>>>>      [java] -----------------------------------------
>>>>      [java]
>>>>      [java] Running
>>>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td 
>>>>
>>>>      [java] Time is Sat Mar 02 10:16:04 EST 2013
>>>>      [java] Starting test in separate process with command:
>>>>      [java]
>>>> /Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/bin/java 
>>>>
>>>> -Djava.security.manager=org.apache.river.api.security.CombinerSecurityManager 
>>>>
>>>> -Djava.security.policy=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaulttest.policy 
>>>>
>>>> -Djava.rmi.server.codebase=http://Bryan-Thompson-MacBook-Air.local:9082/qa1-javaspace-dl.jar 
>>>>
>>>> -cp
>>>> /Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar:/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar 
>>>>
>>>> -client
>>>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext 
>>>>
>>>> -Dcom.sun.jini.jsk.port=9080 -Dcom.sun.jini.qa.port=9081
>>>> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
>>>> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>>> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar 
>>>>
>>>> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar 
>>>>
>>>> -Dcom.sun.jini.qa.harness.runjiniserver=true
>>>> -Dcom.sun.jini.qa.harness.runkitserver=true
>>>> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties 
>>>>
>>>> -Dcom.sun.jini.qa.harness.testhosts=
>>>> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging 
>>>>
>>>> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa 
>>>>
>>>> -Dcom.sun.jini.test.port=9082
>>>> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy 
>>>>
>>>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext 
>>>>
>>>> com.sun.jini.qa.harness.MasterTest
>>>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td 
>>>>
>>>>      [java]
>>>>      [java] TIME: 10:16:05 AM
>>>>      [java]
>>>>      [java] MasterTest.doTest INFO:
>>>>      [java] ============================== CALLING CONSTRUCT()
>>>> ==============================
>>>>      [java]
>>>>      [java] AdminManager.startService FINE: starting qaClassServer
>>>>      [java] FINE:
>>>>      [java] FINE: Parameters for qaClassServer(.0):
>>>>      [java] FINE:      type              : classServer
>>>>      [java] FINE:      impl              : 
>>>> com.sun.jini.tool.ClassServer
>>>>      [java] FINE:      directory         :
>>>> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>>>>      [java] FINE:      options           :
>>>>      [java] AdminManager.startService FINE: starting jiniClassServer
>>>>      [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>>>      [java] INFO: ClassServer started
>>>> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9081]
>>>>      [java] FINE:
>>>>      [java] FINE: Parameters for jiniClassServer(.0):
>>>>      [java] FINE:      type              : classServer
>>>>      [java] FINE:      impl              : 
>>>> com.sun.jini.tool.ClassServer
>>>>      [java] FINE:      directory         :
>>>> /Users/bryan/Documents/workspace/river/trunk/lib-dl
>>>>      [java] FINE:      options           :
>>>>      [java] AdminManager.startService FINE: starting testClassServer
>>>>      [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>>>      [java] INFO: ClassServer started
>>>> [[/Users/bryan/Documents/workspace/river/trunk/lib-dl/], port 9080]
>>>>      [java] FINE:
>>>>      [java] FINE: Parameters for testClassServer(.0):
>>>>      [java] FINE:      type              : classServer
>>>>      [java] FINE:      impl              : 
>>>> com.sun.jini.tool.ClassServer
>>>>      [java] FINE:      directory         :
>>>> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>>>>      [java] FINE:      options           :
>>>>      [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>>>      [java] INFO: ClassServer started
>>>> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9082]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : Test Name =
>>>> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest 
>>>>
>>>>      [java] JavaSpaceTest.logDebugText FINE: : ----- JavaSpace Info 
>>>> -----
>>>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace impl 
>>>> class     --
>>>> com.sun.jini.outrigger.PersistentOutriggerImpl
>>>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace 
>>>> codebase       --
>>>> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
>>>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace 
>>>> classpath      --
>>>> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>>>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace policy file
>>>> -- 
>>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy 
>>>>
>>>>      [java] JavaSpaceTest.logDebugText FINE: : 
>>>> --------------------------
>>>>      [java] AdminManager.startService FINE: starting 
>>>> net.jini.space.JavaSpace
>>>>      [java] QAConfig.getServiceHost FINE: Selecting service host
>>>>      [java] QAConfig.getServiceHost FINE: Not distributed - 
>>>> selecting this
>>>> host
>>>>      [java] AdminManager.startService FINE: starting 
>>>> nonActivatableGroup
>>>>      [java] FINE:
>>>>      [java] FINE: Parameters for nonActivatableGroup(.0):
>>>>      [java] FINE:      type              : nonactivatablegroup
>>>>      [java] FINE:      codebase          :
>>>> http://Bryan-Thompson-MacBook-Air.local:9081/nonactivatablegroup-dl.jar 
>>>>
>>>>      [java] FINE:      impl              :
>>>> com.sun.jini.qa.harness.NonActivatableGroupImpl
>>>>      [java] FINE:      policy file       :
>>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultnonactvm.policy 
>>>>
>>>>      [java] FINE:      classpath         :
>>>> /Users/bryan/Documents/workspace/river/trunk/qa/lib/nonactivatablegroup.jar:/Users/bryan/Documents/workspace/river/trunk/lib/start.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar 
>>>>
>>>>      [java] FINE:      options           : -server
>>>>      [java] FINE:      properties        :
>>>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext 
>>>>
>>>>      [java] FINE:                        : 
>>>> -Dcom.sun.jini.jsk.port=9080
>>>>      [java] FINE:                        : -Dcom.sun.jini.qa.port=9081
>>>>      [java] FINE:                        :
>>>> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
>>>>      [java] FINE:                        :
>>>> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>>>      [java] FINE:                        :
>>>> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar 
>>>>
>>>>      [java] FINE:                        :
>>>> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar 
>>>>
>>>>      [java] FINE:                        :
>>>> -Dcom.sun.jini.qa.harness.runjiniserver=true
>>>>      [java] FINE:                        :
>>>> -Dcom.sun.jini.qa.harness.runkitserver=true
>>>>      [java] FINE:                        :
>>>> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties 
>>>>
>>>>      [java] FINE:                        :
>>>> -Dcom.sun.jini.qa.harness.testhosts=
>>>>      [java] FINE:                        :
>>>> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging 
>>>>
>>>>      [java] FINE:                        :
>>>> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa 
>>>>
>>>>      [java] FINE:                        : 
>>>> -Dcom.sun.jini.test.port=9082
>>>>      [java] FINE:                        :
>>>> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy 
>>>>
>>>>      [java] FINE:
>>>>      [java] FINE: Parameters for net.jini.space.JavaSpace(.0):
>>>>      [java] FINE:      type              : transient
>>>>      [java] FINE:      codebase          :
>>>> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
>>>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>>>      [java] FINE:      impl              :
>>>> com.sun.jini.outrigger.TransientOutriggerImpl
>>>>      [java] FINE:      component name    : com.sun.jini.outrigger
>>>>      [java] FINE:      policy file       :
>>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy 
>>>>
>>>>      [java] FINE:      classpath         :
>>>> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>>>>      [java] FINE:      service conf file : -
>>>>      [java] FINE:      starter conf file : -
>>>>      [java] FINE:      proxy preparer    : test.outriggerPreparer
>>>>      [java] FINE:      option args 0     : -
>>>>      [java] FINE:      option args 1     :
>>>> com.sun.jini.outrigger.initialLookupGroups = new
>>>> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"} 
>>>>
>>>>      [java] FINE:      option args 2     :
>>>> com.sun.jini.outrigger.persistenceDirectory =
>>>> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/FrontEndSpace_log7620264300505337132dir" 
>>>>
>>>>      [java] FINE:      option args 3     : 
>>>> com.sun.jini.outrigger.store=new
>>>> com.sun.jini.outrigger.snaplogstore.LogStore(this)
>>>>      [java] FINE:      option args 4     : multicast.ttl=0
>>>>      [java] FINE:
>>>>      [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
>>>> com.sun.jini.outrigger.OutriggerServerImpl<init>
>>>>      [java] NonActGrp-out: INFO: Outrigger server started:
>>>> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>>>>      [java] JavaSpaceTest.logDebugText FINE: : ----- Transaction 
>>>> Manager Info
>>>> -----
>>>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager impl 
>>>> class     --
>>>> com.sun.jini.mahalo.ActivatableMahaloImpl
>>>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager 
>>>> codebase       --
>>>> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
>>>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager 
>>>> classpath      --
>>>> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>>>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager policy file
>>>> -- 
>>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy 
>>>>
>>>>      [java] JavaSpaceTest.logDebugText FINE: :
>>>> ------------------------------------
>>>>      [java] AdminManager.startService FINE: starting
>>>> net.jini.core.transaction.server.TransactionManager
>>>>      [java] QAConfig.getServiceHost FINE: Selecting service host
>>>>      [java] QAConfig.getServiceHost FINE: Not distributed - 
>>>> selecting this
>>>> host
>>>>      [java] FINE:
>>>>      [java] FINE: Parameters for
>>>> net.jini.core.transaction.server.TransactionManager(.0):
>>>>      [java] FINE:      type              : transient
>>>>      [java] FINE:      codebase          :
>>>> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
>>>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>>>      [java] FINE:      impl              :
>>>> com.sun.jini.mahalo.TransientMahaloImpl
>>>>      [java] FINE:      component name    : com.sun.jini.mahalo
>>>>      [java] FINE:      policy file       :
>>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy 
>>>>
>>>>      [java] FINE:      classpath         :
>>>> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>>>>      [java] FINE:      service conf file : -
>>>>      [java] FINE:      starter conf file : -
>>>>      [java] FINE:      proxy preparer    : test.mahaloPreparer
>>>>      [java] FINE:      option args 0     : -
>>>>      [java] FINE:      option args 1     :
>>>> com.sun.jini.mahalo.initialLookupGroups = new
>>>> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"} 
>>>>
>>>>      [java] FINE:      option args 2     :
>>>> com.sun.jini.mahalo.persistenceDirectory =
>>>> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/TxnManagerImpl_log04834234852756133875dir" 
>>>>
>>>>      [java] FINE:      option args 3     : multicast.ttl=0
>>>>      [java] FINE:
>>>>      [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
>>>> com.sun.jini.mahalo.TxnManagerImpl doInit
>>>>      [java] NonActGrp-out: INFO: Mahalo started:
>>>> com.sun.jini.mahalo.TransientMahaloImpl@22d16a1f
>>>>      [java] MasterTest.doTest INFO:
>>>>      [java] =============================== CALLING RUN()
>>>> ===============================
>>>>      [java]
>>>>      [java]
>>>>      [java] TIME: 10:16:53 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 45000 to to
>>>> let some listeners expire...
>>>>      [java]
>>>>      [java] TIME: 10:17:13 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 20000 to let
>>>> to let transaction expires...
>>>>      [java]
>>>>      [java] TIME: 10:17:33 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 20000 to to
>>>> let some listeners expire...
>>>>      [java]
>>>>      [java] TIME: 10:18:13 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 40000 to to
>>>> let some listeners expire...
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 40000 to let
>>>> all listeners get notifications.
>>>>      [java]
>>>>      [java] TIME: 10:18:53 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 40000) has got 2 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 80000) has got 6 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 120000) has got 8 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 600000) has got 10 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = Lease.FOREVER) has got 10 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 40000) has got 2 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: 
>>>> SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 80000) has got 2 notifications instead of 4 required.
>>>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: 
>>>> SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 120000) has got 2 notifications instead of 4 required.
>>>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: 
>>>> SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 600000) has got 2 notifications instead of 4 required.
>>>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: 
>>>> SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = Lease.FOREVER) has got 2 notifications instead of 4 required.
>>>>      [java] JavaSpaceTest.logDebugText FINE: : Stage 1 with writing 
>>>> ordinal
>>>> entries has been completed.
>>>>      [java] JavaSpaceTest.logDebugText FINE: : 
>>>> ------------------------------
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : Starting 2-nd stage 
>>>> with
>>>> snapshots.
>>>>      [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
>>>> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>>>>      [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
>>>> preparing to send/sending event, dropping registration
>>>>      [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such 
>>>> object in
>>>> table
>>>>      [java] NonActGrp-out:     at
>>>> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428) 
>>>>
>>>>      [java] NonActGrp-out:     at
>>>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806) 
>>>>
>>>>      [java] NonActGrp-out:     at
>>>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659) 
>>>>
>>>>      [java] NonActGrp-out:     at
>>>> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528) 
>>>>
>>>>      [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>>>>      [java] NonActGrp-out:     at
>>>> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337) 
>>>>
>>>>      [java] NonActGrp-out:     at
>>>> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>>>>      [java] NonActGrp-out:     at
>>>> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>>>>      [java] NonActGrp-out:     at
>>>> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>>>>      [java] NonActGrp-out:
>>>>      [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
>>>> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>>>>      [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
>>>> preparing to send/sending event, dropping registration
>>>>      [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such 
>>>> object in
>>>> table
>>>>      [java] NonActGrp-out:     at
>>>> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428) 
>>>>
>>>>      [java] NonActGrp-out:     at
>>>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806) 
>>>>
>>>>      [java] NonActGrp-out:     at
>>>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659) 
>>>>
>>>>      [java] NonActGrp-out:     at
>>>> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528) 
>>>>
>>>>      [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>>>>      [java] NonActGrp-out:     at
>>>> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337) 
>>>>
>>>>      [java] NonActGrp-out:     at
>>>> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>>>>      [java] NonActGrp-out:     at
>>>> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>>>>      [java] NonActGrp-out:     at
>>>> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>>>>      [java] NonActGrp-out:
>>>>      [java]
>>>>      [java] TIME: 10:19:38 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 45000 to to
>>>> let some listeners expire...
>>>>      [java]
>>>>      [java] TIME: 10:19:58 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 20000 to let
>>>> to let transaction expires...
>>>>      [java]
>>>>      [java] TIME: 10:20:18 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 20000 to to
>>>> let some listeners expire...
>>>>      [java]
>>>>      [java] TIME: 10:20:58 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 40000 to to
>>>> let some listeners expire...
>>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 
>>>> 40000 to let
>>>> all listeners get notifications.
>>>>      [java]
>>>>      [java] TIME: 10:21:38 AM
>>>>      [java]
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has 
>>>> got 2
>>>> notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 40000) has got 2 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has 
>>>> got 6
>>>> notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 80000) has got 6 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) 
>>>> has got 8
>>>> notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 120000) has got 8 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) 
>>>> has got 10
>>>> notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 600000) has got 10 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 
>>>> Lease.FOREVER) has
>>>> got 10 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = Lease.FOREVER) has got 10 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has 
>>>> got 2
>>>> notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 40000) has got 2 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has 
>>>> got 4
>>>> notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 80000) has got 4 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) 
>>>> has got 4
>>>> notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 120000) has got 4 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) 
>>>> has got 4
>>>> notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = 600000) has got 4 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: 
>>>> (template =
>>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 
>>>> Lease.FOREVER) has
>>>> got 4 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], 
>>>> lease
>>>> time = Lease.FOREVER) has got 4 notifications as expected
>>>>      [java] JavaSpaceTest.logDebugText FINE: : Stage 2 with writing 
>>>> snapshots
>>>> has been completed.
>>>>      [java]
>>>>      [java] com.sun.jini.qa.harness.TestException: Not all 
>>>> listeners've got
>>>> expected number of events.
>>>>      [java]     at
>>>> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest.run(SnapshotExpirationNotifyTest.java:369) 
>>>>
>>>>      [java]     at
>>>> com.sun.jini.qa.harness.MasterTest.doTest(MasterTest.java:256)
>>>>      [java]     at
>>>> com.sun.jini.qa.harness.MasterTest.main(MasterTest.java:144)
>>>>      [java] MasterTest.doTest INFO:
>>>>      [java] ============================ CALLING TEARDOWN()
>>>> =============================
>>>>      [java]
>>>>      [java] QATestEnvironment.tearDown FINE: Destroying remaining 
>>>> managed
>>>> services
>>>>      [java] AdminManager.destroyService FINE: destroying service: 
>>>> class
>>>> com.sun.jini.outrigger.ConstrainableSpaceProxy2
>>>>      [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
>>>> com.sun.jini.outrigger.OutriggerServerImpl destroy
>>>>      [java] NonActGrp-out: INFO: Outrigger server destroy thread 
>>>> started:
>>>> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>>>>      [java] AdminManager.destroyService FINE: destroying service: 
>>>> class
>>>> com.sun.jini.mahalo.TxnMgrProxy$ConstrainableTxnMgrProxy
>>>>      [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
>>>> com.sun.jini.outrigger.OutriggerServerImpl$DestroyThread run
>>>>      [java] NonActGrp-out: INFO: Outrigger server destroy thread 
>>>> finished:
>>>> Thread[DestroyThread,5,(JSK) Runtime]
>>>>      [java] AdminManager.destroyService FINE: destroying service: 
>>>> class
>>>> com.sun.jini.qa.harness.NonActivatableGroupImpl$GroupImpl_Stub
>>>>      [java] AdminManager.destroyService FINE: destroying service: 
>>>> class
>>>> com.sun.jini.tool.ClassServer
>>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer 
>>>> terminate
>>>>      [java] INFO: ClassServer terminated [port 9080]
>>>>      [java] AdminManager.destroyService FINE: destroying service: 
>>>> class
>>>> com.sun.jini.tool.ClassServer
>>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer 
>>>> terminate
>>>>      [java] INFO: ClassServer terminated [port 9080]
>>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer 
>>>> terminate
>>>>      [java] INFO: ClassServer terminated [port 9082]
>>>>      [java] AdminManager.destroyService FINE: destroying service: 
>>>> class
>>>> com.sun.jini.tool.ClassServer
>>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer 
>>>> terminate
>>>>      [java] INFO: ClassServer terminated [port 9082]
>>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer 
>>>> terminate
>>>>      [java] INFO: ClassServer terminated [port 9081]
>>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer 
>>>> terminate
>>>>      [java] INFO: ClassServer terminated [port 9081]
>>>>      [java]
>>>>      [java] TIME: 10:21:41 AM
>>>>      [java]
>>>>      [java] Test process was destroyed and returned code 1
>>>>      [java]
>>>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td 
>>>>
>>>>      [java] Test Failed: Test Failed: 
>>>> com.sun.jini.qa.harness.TestException:
>>>> Not all listeners've got expected number of events.
>>>>      [java]
>>>>      [java]
>>>>      [java] -----------------------------------------
>>
>>
>


Re: Help: Javaspace concurrency expert needed

Posted by Gregg Wonderly <gr...@wonderly.org>.
Much of timer management in lease type usage, uses the 50% expired rule, to make 
sure and try ahead of time to renew the lease or otherwise register interest.  
Should these tests really be up against the proverbial wall (clock) in these 
tests?  Is there really any value in doing that, specifically because of 
CPU/network stack timing and inter-process latency?

Gregg

On 3/7/2013 7:40 AM, Peter Firmstone wrote:
> The cause was the test sleeping and waking up as the DGC lease expired, the 
> object was collected from the ObjectTable and the events couldn't be sent.
>
> DGC's a lot faster than it used to be, it's concurrent too now.
>
> It's not the same DGC people remember, if you had trouble with DGC in the 
> past, it's worth trying again, Peter Jones was invaluable in helping to sort 
> this out some time ago, he sent me a link to a paper on DGC (from DIGITAL 
> research labs in 1993) and left very useful development hints in the form of 
> bug reports and code comments.  The concurrent library's really helped to 
> address the remaining issues.
>
> To fix this test failure, I reduced the test sleep times by 10ms. From 10,000 
> to 9,990 ms and 20,000 to 19,990 ms.
>
> Regards,
>
> Peter.
>
>
>
> On 3/03/2013 7:33 PM, Dan Creswell wrote:
>> Suggests a remote reference registered via notify has gone AWOL when
>> it shouldn't have done.
>>
>> The usual causes for that are DGC or garbage collection as the result
>> of nothing holding on to the exported object.
>>
>> Looks like you're running trunk?
>>
>> On 3 March 2013 01:18, Peter Firmstone<ji...@zeus.net.au> wrote:
>>> Who's smart enough to figure out the cause and fix this test failure?
>>>
>>>
>>>      [java] -----------------------------------------
>>>      [java]
>>>      [java] Running
>>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td 
>>>
>>>      [java] Time is Sat Mar 02 10:16:04 EST 2013
>>>      [java] Starting test in separate process with command:
>>>      [java]
>>> /Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/bin/java
>>> -Djava.security.manager=org.apache.river.api.security.CombinerSecurityManager
>>> -Djava.security.policy=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaulttest.policy 
>>>
>>> -Djava.rmi.server.codebase=http://Bryan-Thompson-MacBook-Air.local:9082/qa1-javaspace-dl.jar 
>>>
>>> -cp
>>> /Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar:/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar 
>>>
>>> -client
>>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext 
>>>
>>> -Dcom.sun.jini.jsk.port=9080 -Dcom.sun.jini.qa.port=9081
>>> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
>>> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar 
>>>
>>> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar 
>>>
>>> -Dcom.sun.jini.qa.harness.runjiniserver=true
>>> -Dcom.sun.jini.qa.harness.runkitserver=true
>>> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties 
>>>
>>> -Dcom.sun.jini.qa.harness.testhosts=
>>> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging 
>>>
>>> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>> -Dcom.sun.jini.test.port=9082
>>> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy 
>>>
>>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext 
>>>
>>> com.sun.jini.qa.harness.MasterTest
>>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td 
>>>
>>>      [java]
>>>      [java] TIME: 10:16:05 AM
>>>      [java]
>>>      [java] MasterTest.doTest INFO:
>>>      [java] ============================== CALLING CONSTRUCT()
>>> ==============================
>>>      [java]
>>>      [java] AdminManager.startService FINE: starting qaClassServer
>>>      [java] FINE:
>>>      [java] FINE: Parameters for qaClassServer(.0):
>>>      [java] FINE:      type              : classServer
>>>      [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>>>      [java] FINE:      directory         :
>>> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>>>      [java] FINE:      options           :
>>>      [java] AdminManager.startService FINE: starting jiniClassServer
>>>      [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>>      [java] INFO: ClassServer started
>>> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9081]
>>>      [java] FINE:
>>>      [java] FINE: Parameters for jiniClassServer(.0):
>>>      [java] FINE:      type              : classServer
>>>      [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>>>      [java] FINE:      directory         :
>>> /Users/bryan/Documents/workspace/river/trunk/lib-dl
>>>      [java] FINE:      options           :
>>>      [java] AdminManager.startService FINE: starting testClassServer
>>>      [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>>      [java] INFO: ClassServer started
>>> [[/Users/bryan/Documents/workspace/river/trunk/lib-dl/], port 9080]
>>>      [java] FINE:
>>>      [java] FINE: Parameters for testClassServer(.0):
>>>      [java] FINE:      type              : classServer
>>>      [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>>>      [java] FINE:      directory         :
>>> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>>>      [java] FINE:      options           :
>>>      [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>>      [java] INFO: ClassServer started
>>> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9082]
>>>      [java] JavaSpaceTest.logDebugText FINE: : Test Name =
>>> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest 
>>>
>>>      [java] JavaSpaceTest.logDebugText FINE: : ----- JavaSpace Info -----
>>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace impl class     --
>>> com.sun.jini.outrigger.PersistentOutriggerImpl
>>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace codebase       --
>>> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
>>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace classpath      --
>>> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace policy file
>>> -- 
>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy 
>>>
>>>      [java] JavaSpaceTest.logDebugText FINE: : --------------------------
>>>      [java] AdminManager.startService FINE: starting net.jini.space.JavaSpace
>>>      [java] QAConfig.getServiceHost FINE: Selecting service host
>>>      [java] QAConfig.getServiceHost FINE: Not distributed - selecting this
>>> host
>>>      [java] AdminManager.startService FINE: starting nonActivatableGroup
>>>      [java] FINE:
>>>      [java] FINE: Parameters for nonActivatableGroup(.0):
>>>      [java] FINE:      type              : nonactivatablegroup
>>>      [java] FINE:      codebase          :
>>> http://Bryan-Thompson-MacBook-Air.local:9081/nonactivatablegroup-dl.jar
>>>      [java] FINE:      impl              :
>>> com.sun.jini.qa.harness.NonActivatableGroupImpl
>>>      [java] FINE:      policy file       :
>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultnonactvm.policy 
>>>
>>>      [java] FINE:      classpath         :
>>> /Users/bryan/Documents/workspace/river/trunk/qa/lib/nonactivatablegroup.jar:/Users/bryan/Documents/workspace/river/trunk/lib/start.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar 
>>>
>>>      [java] FINE:      options           : -server
>>>      [java] FINE:      properties        :
>>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext 
>>>
>>>      [java] FINE:                        : -Dcom.sun.jini.jsk.port=9080
>>>      [java] FINE:                        : -Dcom.sun.jini.qa.port=9081
>>>      [java] FINE:                        :
>>> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
>>>      [java] FINE:                        :
>>> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>>      [java] FINE:                        :
>>> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar 
>>>
>>>      [java] FINE:                        :
>>> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar 
>>>
>>>      [java] FINE:                        :
>>> -Dcom.sun.jini.qa.harness.runjiniserver=true
>>>      [java] FINE:                        :
>>> -Dcom.sun.jini.qa.harness.runkitserver=true
>>>      [java] FINE:                        :
>>> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties 
>>>
>>>      [java] FINE:                        :
>>> -Dcom.sun.jini.qa.harness.testhosts=
>>>      [java] FINE:                        :
>>> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging 
>>>
>>>      [java] FINE:                        :
>>> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>>      [java] FINE:                        : -Dcom.sun.jini.test.port=9082
>>>      [java] FINE:                        :
>>> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy 
>>>
>>>      [java] FINE:
>>>      [java] FINE: Parameters for net.jini.space.JavaSpace(.0):
>>>      [java] FINE:      type              : transient
>>>      [java] FINE:      codebase          :
>>> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
>>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>>      [java] FINE:      impl              :
>>> com.sun.jini.outrigger.TransientOutriggerImpl
>>>      [java] FINE:      component name    : com.sun.jini.outrigger
>>>      [java] FINE:      policy file       :
>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy 
>>>
>>>      [java] FINE:      classpath         :
>>> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>>>      [java] FINE:      service conf file : -
>>>      [java] FINE:      starter conf file : -
>>>      [java] FINE:      proxy preparer    : test.outriggerPreparer
>>>      [java] FINE:      option args 0     : -
>>>      [java] FINE:      option args 1     :
>>> com.sun.jini.outrigger.initialLookupGroups = new
>>> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
>>>      [java] FINE:      option args 2     :
>>> com.sun.jini.outrigger.persistenceDirectory =
>>> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/FrontEndSpace_log7620264300505337132dir" 
>>>
>>>      [java] FINE:      option args 3     : com.sun.jini.outrigger.store=new
>>> com.sun.jini.outrigger.snaplogstore.LogStore(this)
>>>      [java] FINE:      option args 4     : multicast.ttl=0
>>>      [java] FINE:
>>>      [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
>>> com.sun.jini.outrigger.OutriggerServerImpl<init>
>>>      [java] NonActGrp-out: INFO: Outrigger server started:
>>> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>>>      [java] JavaSpaceTest.logDebugText FINE: : ----- Transaction Manager Info
>>> -----
>>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager impl class     --
>>> com.sun.jini.mahalo.ActivatableMahaloImpl
>>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager codebase       --
>>> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
>>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager classpath      --
>>> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager policy file
>>> -- 
>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy 
>>>
>>>      [java] JavaSpaceTest.logDebugText FINE: :
>>> ------------------------------------
>>>      [java] AdminManager.startService FINE: starting
>>> net.jini.core.transaction.server.TransactionManager
>>>      [java] QAConfig.getServiceHost FINE: Selecting service host
>>>      [java] QAConfig.getServiceHost FINE: Not distributed - selecting this
>>> host
>>>      [java] FINE:
>>>      [java] FINE: Parameters for
>>> net.jini.core.transaction.server.TransactionManager(.0):
>>>      [java] FINE:      type              : transient
>>>      [java] FINE:      codebase          :
>>> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
>>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>>      [java] FINE:      impl              :
>>> com.sun.jini.mahalo.TransientMahaloImpl
>>>      [java] FINE:      component name    : com.sun.jini.mahalo
>>>      [java] FINE:      policy file       :
>>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy 
>>>
>>>      [java] FINE:      classpath         :
>>> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>>>      [java] FINE:      service conf file : -
>>>      [java] FINE:      starter conf file : -
>>>      [java] FINE:      proxy preparer    : test.mahaloPreparer
>>>      [java] FINE:      option args 0     : -
>>>      [java] FINE:      option args 1     :
>>> com.sun.jini.mahalo.initialLookupGroups = new
>>> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
>>>      [java] FINE:      option args 2     :
>>> com.sun.jini.mahalo.persistenceDirectory =
>>> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/TxnManagerImpl_log04834234852756133875dir" 
>>>
>>>      [java] FINE:      option args 3     : multicast.ttl=0
>>>      [java] FINE:
>>>      [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
>>> com.sun.jini.mahalo.TxnManagerImpl doInit
>>>      [java] NonActGrp-out: INFO: Mahalo started:
>>> com.sun.jini.mahalo.TransientMahaloImpl@22d16a1f
>>>      [java] MasterTest.doTest INFO:
>>>      [java] =============================== CALLING RUN()
>>> ===============================
>>>      [java]
>>>      [java]
>>>      [java] TIME: 10:16:53 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to to
>>> let some listeners expire...
>>>      [java]
>>>      [java] TIME: 10:17:13 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to let
>>> to let transaction expires...
>>>      [java]
>>>      [java] TIME: 10:17:33 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to to
>>> let some listeners expire...
>>>      [java]
>>>      [java] TIME: 10:18:13 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to to
>>> let some listeners expire...
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to let
>>> all listeners get notifications.
>>>      [java]
>>>      [java] TIME: 10:18:53 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 40000) has got 2 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 80000) has got 6 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 120000) has got 8 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 600000) has got 10 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = Lease.FOREVER) has got 10 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 40000) has got 2 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 80000) has got 2 notifications instead of 4 required.
>>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 120000) has got 2 notifications instead of 4 required.
>>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 600000) has got 2 notifications instead of 4 required.
>>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = Lease.FOREVER) has got 2 notifications instead of 4 required.
>>>      [java] JavaSpaceTest.logDebugText FINE: : Stage 1 with writing ordinal
>>> entries has been completed.
>>>      [java] JavaSpaceTest.logDebugText FINE: : ------------------------------
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : Starting 2-nd stage with
>>> snapshots.
>>>      [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
>>> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>>>      [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
>>> preparing to send/sending event, dropping registration
>>>      [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such object in
>>> table
>>>      [java] NonActGrp-out:     at
>>> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
>>>      [java] NonActGrp-out:     at
>>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806) 
>>>
>>>      [java] NonActGrp-out:     at
>>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659) 
>>>
>>>      [java] NonActGrp-out:     at
>>> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
>>>      [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>>>      [java] NonActGrp-out:     at
>>> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337) 
>>>
>>>      [java] NonActGrp-out:     at
>>> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>>>      [java] NonActGrp-out:     at
>>> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>>>      [java] NonActGrp-out:     at
>>> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>>>      [java] NonActGrp-out:
>>>      [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
>>> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>>>      [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
>>> preparing to send/sending event, dropping registration
>>>      [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such object in
>>> table
>>>      [java] NonActGrp-out:     at
>>> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
>>>      [java] NonActGrp-out:     at
>>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806) 
>>>
>>>      [java] NonActGrp-out:     at
>>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659) 
>>>
>>>      [java] NonActGrp-out:     at
>>> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
>>>      [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>>>      [java] NonActGrp-out:     at
>>> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337) 
>>>
>>>      [java] NonActGrp-out:     at
>>> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>>>      [java] NonActGrp-out:     at
>>> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>>>      [java] NonActGrp-out:     at
>>> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>>>      [java] NonActGrp-out:
>>>      [java]
>>>      [java] TIME: 10:19:38 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to to
>>> let some listeners expire...
>>>      [java]
>>>      [java] TIME: 10:19:58 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to let
>>> to let transaction expires...
>>>      [java]
>>>      [java] TIME: 10:20:18 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to to
>>> let some listeners expire...
>>>      [java]
>>>      [java] TIME: 10:20:58 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to to
>>> let some listeners expire...
>>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to let
>>> all listeners get notifications.
>>>      [java]
>>>      [java] TIME: 10:21:38 AM
>>>      [java]
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has got 2
>>> notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 40000) has got 2 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has got 6
>>> notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 80000) has got 6 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has got 8
>>> notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 120000) has got 8 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has got 10
>>> notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 600000) has got 10 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = Lease.FOREVER) has
>>> got 10 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = Lease.FOREVER) has got 10 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has got 2
>>> notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 40000) has got 2 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has got 4
>>> notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 80000) has got 4 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has got 4
>>> notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 120000) has got 4 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has got 4
>>> notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = 600000) has got 4 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = Lease.FOREVER) has
>>> got 4 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>>> time = Lease.FOREVER) has got 4 notifications as expected
>>>      [java] JavaSpaceTest.logDebugText FINE: : Stage 2 with writing snapshots
>>> has been completed.
>>>      [java]
>>>      [java] com.sun.jini.qa.harness.TestException: Not all listeners've got
>>> expected number of events.
>>>      [java]     at
>>> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest.run(SnapshotExpirationNotifyTest.java:369) 
>>>
>>>      [java]     at
>>> com.sun.jini.qa.harness.MasterTest.doTest(MasterTest.java:256)
>>>      [java]     at
>>> com.sun.jini.qa.harness.MasterTest.main(MasterTest.java:144)
>>>      [java] MasterTest.doTest INFO:
>>>      [java] ============================ CALLING TEARDOWN()
>>> =============================
>>>      [java]
>>>      [java] QATestEnvironment.tearDown FINE: Destroying remaining managed
>>> services
>>>      [java] AdminManager.destroyService FINE: destroying service: class
>>> com.sun.jini.outrigger.ConstrainableSpaceProxy2
>>>      [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
>>> com.sun.jini.outrigger.OutriggerServerImpl destroy
>>>      [java] NonActGrp-out: INFO: Outrigger server destroy thread started:
>>> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>>>      [java] AdminManager.destroyService FINE: destroying service: class
>>> com.sun.jini.mahalo.TxnMgrProxy$ConstrainableTxnMgrProxy
>>>      [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
>>> com.sun.jini.outrigger.OutriggerServerImpl$DestroyThread run
>>>      [java] NonActGrp-out: INFO: Outrigger server destroy thread finished:
>>> Thread[DestroyThread,5,(JSK) Runtime]
>>>      [java] AdminManager.destroyService FINE: destroying service: class
>>> com.sun.jini.qa.harness.NonActivatableGroupImpl$GroupImpl_Stub
>>>      [java] AdminManager.destroyService FINE: destroying service: class
>>> com.sun.jini.tool.ClassServer
>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>>      [java] INFO: ClassServer terminated [port 9080]
>>>      [java] AdminManager.destroyService FINE: destroying service: class
>>> com.sun.jini.tool.ClassServer
>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>>      [java] INFO: ClassServer terminated [port 9080]
>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>>      [java] INFO: ClassServer terminated [port 9082]
>>>      [java] AdminManager.destroyService FINE: destroying service: class
>>> com.sun.jini.tool.ClassServer
>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>>      [java] INFO: ClassServer terminated [port 9082]
>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>>      [java] INFO: ClassServer terminated [port 9081]
>>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>>      [java] INFO: ClassServer terminated [port 9081]
>>>      [java]
>>>      [java] TIME: 10:21:41 AM
>>>      [java]
>>>      [java] Test process was destroyed and returned code 1
>>>      [java]
>>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td 
>>>
>>>      [java] Test Failed: Test Failed: com.sun.jini.qa.harness.TestException:
>>> Not all listeners've got expected number of events.
>>>      [java]
>>>      [java]
>>>      [java] -----------------------------------------
>
>


Re: Help: Javaspace concurrency expert needed

Posted by Peter Firmstone <ji...@zeus.net.au>.
The cause was the test sleeping and waking up as the DGC lease expired, 
the object was collected from the ObjectTable and the events couldn't be 
sent.

DGC's a lot faster than it used to be, it's concurrent too now.

It's not the same DGC people remember, if you had trouble with DGC in 
the past, it's worth trying again, Peter Jones was invaluable in helping 
to sort this out some time ago, he sent me a link to a paper on DGC 
(from DIGITAL research labs in 1993) and left very useful development 
hints in the form of bug reports and code comments.  The concurrent 
library's really helped to address the remaining issues.

To fix this test failure, I reduced the test sleep times by 10ms.  From 
10,000 to 9,990 ms and 20,000 to 19,990 ms.

Regards,

Peter.



On 3/03/2013 7:33 PM, Dan Creswell wrote:
> Suggests a remote reference registered via notify has gone AWOL when
> it shouldn't have done.
>
> The usual causes for that are DGC or garbage collection as the result
> of nothing holding on to the exported object.
>
> Looks like you're running trunk?
>
> On 3 March 2013 01:18, Peter Firmstone<ji...@zeus.net.au>  wrote:
>> Who's smart enough to figure out the cause and fix this test failure?
>>
>>
>>      [java] -----------------------------------------
>>      [java]
>>      [java] Running
>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
>>      [java] Time is Sat Mar 02 10:16:04 EST 2013
>>      [java] Starting test in separate process with command:
>>      [java]
>> /Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/bin/java
>> -Djava.security.manager=org.apache.river.api.security.CombinerSecurityManager
>> -Djava.security.policy=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaulttest.policy
>> -Djava.rmi.server.codebase=http://Bryan-Thompson-MacBook-Air.local:9082/qa1-javaspace-dl.jar
>> -cp
>> /Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar:/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar
>> -client
>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
>> -Dcom.sun.jini.jsk.port=9080 -Dcom.sun.jini.qa.port=9081
>> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
>> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
>> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar
>> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar
>> -Dcom.sun.jini.qa.harness.runjiniserver=true
>> -Dcom.sun.jini.qa.harness.runkitserver=true
>> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties
>> -Dcom.sun.jini.qa.harness.testhosts=
>> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging
>> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa
>> -Dcom.sun.jini.test.port=9082
>> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy
>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
>> com.sun.jini.qa.harness.MasterTest
>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
>>      [java]
>>      [java] TIME: 10:16:05 AM
>>      [java]
>>      [java] MasterTest.doTest INFO:
>>      [java] ============================== CALLING CONSTRUCT()
>> ==============================
>>      [java]
>>      [java] AdminManager.startService FINE: starting qaClassServer
>>      [java] FINE:
>>      [java] FINE: Parameters for qaClassServer(.0):
>>      [java] FINE:      type              : classServer
>>      [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>>      [java] FINE:      directory         :
>> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>>      [java] FINE:      options           :
>>      [java] AdminManager.startService FINE: starting jiniClassServer
>>      [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>      [java] INFO: ClassServer started
>> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9081]
>>      [java] FINE:
>>      [java] FINE: Parameters for jiniClassServer(.0):
>>      [java] FINE:      type              : classServer
>>      [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>>      [java] FINE:      directory         :
>> /Users/bryan/Documents/workspace/river/trunk/lib-dl
>>      [java] FINE:      options           :
>>      [java] AdminManager.startService FINE: starting testClassServer
>>      [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>      [java] INFO: ClassServer started
>> [[/Users/bryan/Documents/workspace/river/trunk/lib-dl/], port 9080]
>>      [java] FINE:
>>      [java] FINE: Parameters for testClassServer(.0):
>>      [java] FINE:      type              : classServer
>>      [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>>      [java] FINE:      directory         :
>> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>>      [java] FINE:      options           :
>>      [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>      [java] INFO: ClassServer started
>> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9082]
>>      [java] JavaSpaceTest.logDebugText FINE: : Test Name =
>> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest
>>      [java] JavaSpaceTest.logDebugText FINE: : ----- JavaSpace Info -----
>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace impl class     --
>> com.sun.jini.outrigger.PersistentOutriggerImpl
>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace codebase       --
>> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace classpath      --
>> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>>      [java] JavaSpaceTest.logDebugText FINE: : JavaSpace policy file
>> --
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy
>>      [java] JavaSpaceTest.logDebugText FINE: : --------------------------
>>      [java] AdminManager.startService FINE: starting net.jini.space.JavaSpace
>>      [java] QAConfig.getServiceHost FINE: Selecting service host
>>      [java] QAConfig.getServiceHost FINE: Not distributed - selecting this
>> host
>>      [java] AdminManager.startService FINE: starting nonActivatableGroup
>>      [java] FINE:
>>      [java] FINE: Parameters for nonActivatableGroup(.0):
>>      [java] FINE:      type              : nonactivatablegroup
>>      [java] FINE:      codebase          :
>> http://Bryan-Thompson-MacBook-Air.local:9081/nonactivatablegroup-dl.jar
>>      [java] FINE:      impl              :
>> com.sun.jini.qa.harness.NonActivatableGroupImpl
>>      [java] FINE:      policy file       :
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultnonactvm.policy
>>      [java] FINE:      classpath         :
>> /Users/bryan/Documents/workspace/river/trunk/qa/lib/nonactivatablegroup.jar:/Users/bryan/Documents/workspace/river/trunk/lib/start.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar
>>      [java] FINE:      options           : -server
>>      [java] FINE:      properties        :
>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
>>      [java] FINE:                        : -Dcom.sun.jini.jsk.port=9080
>>      [java] FINE:                        : -Dcom.sun.jini.qa.port=9081
>>      [java] FINE:                        :
>> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
>>      [java] FINE:                        :
>> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>      [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar
>>      [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar
>>      [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.runjiniserver=true
>>      [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.runkitserver=true
>>      [java] FINE:                        :
>> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties
>>      [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.testhosts=
>>      [java] FINE:                        :
>> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging
>>      [java] FINE:                        :
>> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>      [java] FINE:                        : -Dcom.sun.jini.test.port=9082
>>      [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy
>>      [java] FINE:
>>      [java] FINE: Parameters for net.jini.space.JavaSpace(.0):
>>      [java] FINE:      type              : transient
>>      [java] FINE:      codebase          :
>> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>      [java] FINE:      impl              :
>> com.sun.jini.outrigger.TransientOutriggerImpl
>>      [java] FINE:      component name    : com.sun.jini.outrigger
>>      [java] FINE:      policy file       :
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy
>>      [java] FINE:      classpath         :
>> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>>      [java] FINE:      service conf file : -
>>      [java] FINE:      starter conf file : -
>>      [java] FINE:      proxy preparer    : test.outriggerPreparer
>>      [java] FINE:      option args 0     : -
>>      [java] FINE:      option args 1     :
>> com.sun.jini.outrigger.initialLookupGroups = new
>> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
>>      [java] FINE:      option args 2     :
>> com.sun.jini.outrigger.persistenceDirectory =
>> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/FrontEndSpace_log7620264300505337132dir"
>>      [java] FINE:      option args 3     : com.sun.jini.outrigger.store=new
>> com.sun.jini.outrigger.snaplogstore.LogStore(this)
>>      [java] FINE:      option args 4     : multicast.ttl=0
>>      [java] FINE:
>>      [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
>> com.sun.jini.outrigger.OutriggerServerImpl<init>
>>      [java] NonActGrp-out: INFO: Outrigger server started:
>> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>>      [java] JavaSpaceTest.logDebugText FINE: : ----- Transaction Manager Info
>> -----
>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager impl class     --
>> com.sun.jini.mahalo.ActivatableMahaloImpl
>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager codebase       --
>> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager classpath      --
>> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>>      [java] JavaSpaceTest.logDebugText FINE: : TxnManager policy file
>> --
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy
>>      [java] JavaSpaceTest.logDebugText FINE: :
>> ------------------------------------
>>      [java] AdminManager.startService FINE: starting
>> net.jini.core.transaction.server.TransactionManager
>>      [java] QAConfig.getServiceHost FINE: Selecting service host
>>      [java] QAConfig.getServiceHost FINE: Not distributed - selecting this
>> host
>>      [java] FINE:
>>      [java] FINE: Parameters for
>> net.jini.core.transaction.server.TransactionManager(.0):
>>      [java] FINE:      type              : transient
>>      [java] FINE:      codebase          :
>> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>      [java] FINE:      impl              :
>> com.sun.jini.mahalo.TransientMahaloImpl
>>      [java] FINE:      component name    : com.sun.jini.mahalo
>>      [java] FINE:      policy file       :
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy
>>      [java] FINE:      classpath         :
>> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>>      [java] FINE:      service conf file : -
>>      [java] FINE:      starter conf file : -
>>      [java] FINE:      proxy preparer    : test.mahaloPreparer
>>      [java] FINE:      option args 0     : -
>>      [java] FINE:      option args 1     :
>> com.sun.jini.mahalo.initialLookupGroups = new
>> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
>>      [java] FINE:      option args 2     :
>> com.sun.jini.mahalo.persistenceDirectory =
>> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/TxnManagerImpl_log04834234852756133875dir"
>>      [java] FINE:      option args 3     : multicast.ttl=0
>>      [java] FINE:
>>      [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
>> com.sun.jini.mahalo.TxnManagerImpl doInit
>>      [java] NonActGrp-out: INFO: Mahalo started:
>> com.sun.jini.mahalo.TransientMahaloImpl@22d16a1f
>>      [java] MasterTest.doTest INFO:
>>      [java] =============================== CALLING RUN()
>> ===============================
>>      [java]
>>      [java]
>>      [java] TIME: 10:16:53 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to to
>> let some listeners expire...
>>      [java]
>>      [java] TIME: 10:17:13 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to let
>> to let transaction expires...
>>      [java]
>>      [java] TIME: 10:17:33 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to to
>> let some listeners expire...
>>      [java]
>>      [java] TIME: 10:18:13 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to to
>> let some listeners expire...
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to let
>> all listeners get notifications.
>>      [java]
>>      [java] TIME: 10:18:53 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 40000) has got 2 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 80000) has got 6 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 120000) has got 8 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 600000) has got 10 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = Lease.FOREVER) has got 10 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 40000) has got 2 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 80000) has got 2 notifications instead of 4 required.
>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 120000) has got 2 notifications instead of 4 required.
>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 600000) has got 2 notifications instead of 4 required.
>>      [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = Lease.FOREVER) has got 2 notifications instead of 4 required.
>>      [java] JavaSpaceTest.logDebugText FINE: : Stage 1 with writing ordinal
>> entries has been completed.
>>      [java] JavaSpaceTest.logDebugText FINE: : ------------------------------
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : Starting 2-nd stage with
>> snapshots.
>>      [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
>> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>>      [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
>> preparing to send/sending event, dropping registration
>>      [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such object in
>> table
>>      [java] NonActGrp-out:     at
>> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
>>      [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806)
>>      [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
>>      [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
>>      [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>>      [java] NonActGrp-out:     at
>> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337)
>>      [java] NonActGrp-out:     at
>> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>>      [java] NonActGrp-out:     at
>> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>>      [java] NonActGrp-out:     at
>> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>>      [java] NonActGrp-out:
>>      [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
>> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>>      [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
>> preparing to send/sending event, dropping registration
>>      [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such object in
>> table
>>      [java] NonActGrp-out:     at
>> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
>>      [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806)
>>      [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
>>      [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
>>      [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>>      [java] NonActGrp-out:     at
>> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337)
>>      [java] NonActGrp-out:     at
>> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>>      [java] NonActGrp-out:     at
>> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>>      [java] NonActGrp-out:     at
>> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>>      [java] NonActGrp-out:
>>      [java]
>>      [java] TIME: 10:19:38 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to to
>> let some listeners expire...
>>      [java]
>>      [java] TIME: 10:19:58 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to let
>> to let transaction expires...
>>      [java]
>>      [java] TIME: 10:20:18 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to to
>> let some listeners expire...
>>      [java]
>>      [java] TIME: 10:20:58 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to to
>> let some listeners expire...
>>      [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to let
>> all listeners get notifications.
>>      [java]
>>      [java] TIME: 10:21:38 AM
>>      [java]
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has got 2
>> notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 40000) has got 2 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has got 6
>> notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 80000) has got 6 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has got 8
>> notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 120000) has got 8 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has got 10
>> notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 600000) has got 10 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = Lease.FOREVER) has
>> got 10 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = Lease.FOREVER) has got 10 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has got 2
>> notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 40000) has got 2 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has got 4
>> notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 80000) has got 4 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has got 4
>> notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 120000) has got 4 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has got 4
>> notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 600000) has got 4 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = Lease.FOREVER) has
>> got 4 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = Lease.FOREVER) has got 4 notifications as expected
>>      [java] JavaSpaceTest.logDebugText FINE: : Stage 2 with writing snapshots
>> has been completed.
>>      [java]
>>      [java] com.sun.jini.qa.harness.TestException: Not all listeners've got
>> expected number of events.
>>      [java]     at
>> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest.run(SnapshotExpirationNotifyTest.java:369)
>>      [java]     at
>> com.sun.jini.qa.harness.MasterTest.doTest(MasterTest.java:256)
>>      [java]     at
>> com.sun.jini.qa.harness.MasterTest.main(MasterTest.java:144)
>>      [java] MasterTest.doTest INFO:
>>      [java] ============================ CALLING TEARDOWN()
>> =============================
>>      [java]
>>      [java] QATestEnvironment.tearDown FINE: Destroying remaining managed
>> services
>>      [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.outrigger.ConstrainableSpaceProxy2
>>      [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
>> com.sun.jini.outrigger.OutriggerServerImpl destroy
>>      [java] NonActGrp-out: INFO: Outrigger server destroy thread started:
>> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>>      [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.mahalo.TxnMgrProxy$ConstrainableTxnMgrProxy
>>      [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
>> com.sun.jini.outrigger.OutriggerServerImpl$DestroyThread run
>>      [java] NonActGrp-out: INFO: Outrigger server destroy thread finished:
>> Thread[DestroyThread,5,(JSK) Runtime]
>>      [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.qa.harness.NonActivatableGroupImpl$GroupImpl_Stub
>>      [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.tool.ClassServer
>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>      [java] INFO: ClassServer terminated [port 9080]
>>      [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.tool.ClassServer
>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>      [java] INFO: ClassServer terminated [port 9080]
>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>      [java] INFO: ClassServer terminated [port 9082]
>>      [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.tool.ClassServer
>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>      [java] INFO: ClassServer terminated [port 9082]
>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>      [java] INFO: ClassServer terminated [port 9081]
>>      [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>      [java] INFO: ClassServer terminated [port 9081]
>>      [java]
>>      [java] TIME: 10:21:41 AM
>>      [java]
>>      [java] Test process was destroyed and returned code 1
>>      [java]
>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
>>      [java] Test Failed: Test Failed: com.sun.jini.qa.harness.TestException:
>> Not all listeners've got expected number of events.
>>      [java]
>>      [java]
>>      [java] -----------------------------------------


Re: Help: Javaspace concurrency expert needed

Posted by Peter Firmstone <ji...@zeus.net.au>.
Dan Creswell wrote:
> Suggests a remote reference registered via notify has gone AWOL when
> it shouldn't have done.
>
> The usual causes for that are DGC or garbage collection as the result
> of nothing holding on to the exported object.
>
> Looks like you're running trunk?
>   

skunk/qa_refactor/trunk

> On 3 March 2013 01:18, Peter Firmstone <ji...@zeus.net.au> wrote:
>   
>> Who's smart enough to figure out the cause and fix this test failure?
>>
>>
>>     [java] -----------------------------------------
>>     [java]
>>     [java] Running
>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
>>     [java] Time is Sat Mar 02 10:16:04 EST 2013
>>     [java] Starting test in separate process with command:
>>     [java]
>> /Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/bin/java
>> -Djava.security.manager=org.apache.river.api.security.CombinerSecurityManager
>> -Djava.security.policy=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaulttest.policy
>> -Djava.rmi.server.codebase=http://Bryan-Thompson-MacBook-Air.local:9082/qa1-javaspace-dl.jar
>> -cp
>> /Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar:/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar
>> -client
>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
>> -Dcom.sun.jini.jsk.port=9080 -Dcom.sun.jini.qa.port=9081
>> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
>> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
>> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar
>> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar
>> -Dcom.sun.jini.qa.harness.runjiniserver=true
>> -Dcom.sun.jini.qa.harness.runkitserver=true
>> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties
>> -Dcom.sun.jini.qa.harness.testhosts=
>> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging
>> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa
>> -Dcom.sun.jini.test.port=9082
>> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy
>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
>> com.sun.jini.qa.harness.MasterTest
>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
>>     [java]
>>     [java] TIME: 10:16:05 AM
>>     [java]
>>     [java] MasterTest.doTest INFO:
>>     [java] ============================== CALLING CONSTRUCT()
>> ==============================
>>     [java]
>>     [java] AdminManager.startService FINE: starting qaClassServer
>>     [java] FINE:
>>     [java] FINE: Parameters for qaClassServer(.0):
>>     [java] FINE:      type              : classServer
>>     [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>>     [java] FINE:      directory         :
>> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>>     [java] FINE:      options           :
>>     [java] AdminManager.startService FINE: starting jiniClassServer
>>     [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>     [java] INFO: ClassServer started
>> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9081]
>>     [java] FINE:
>>     [java] FINE: Parameters for jiniClassServer(.0):
>>     [java] FINE:      type              : classServer
>>     [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>>     [java] FINE:      directory         :
>> /Users/bryan/Documents/workspace/river/trunk/lib-dl
>>     [java] FINE:      options           :
>>     [java] AdminManager.startService FINE: starting testClassServer
>>     [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>     [java] INFO: ClassServer started
>> [[/Users/bryan/Documents/workspace/river/trunk/lib-dl/], port 9080]
>>     [java] FINE:
>>     [java] FINE: Parameters for testClassServer(.0):
>>     [java] FINE:      type              : classServer
>>     [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>>     [java] FINE:      directory         :
>> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>>     [java] FINE:      options           :
>>     [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>>     [java] INFO: ClassServer started
>> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9082]
>>     [java] JavaSpaceTest.logDebugText FINE: : Test Name =
>> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest
>>     [java] JavaSpaceTest.logDebugText FINE: : ----- JavaSpace Info -----
>>     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace impl class     --
>> com.sun.jini.outrigger.PersistentOutriggerImpl
>>     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace codebase       --
>> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace classpath      --
>> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>>     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace policy file
>> --
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy
>>     [java] JavaSpaceTest.logDebugText FINE: : --------------------------
>>     [java] AdminManager.startService FINE: starting net.jini.space.JavaSpace
>>     [java] QAConfig.getServiceHost FINE: Selecting service host
>>     [java] QAConfig.getServiceHost FINE: Not distributed - selecting this
>> host
>>     [java] AdminManager.startService FINE: starting nonActivatableGroup
>>     [java] FINE:
>>     [java] FINE: Parameters for nonActivatableGroup(.0):
>>     [java] FINE:      type              : nonactivatablegroup
>>     [java] FINE:      codebase          :
>> http://Bryan-Thompson-MacBook-Air.local:9081/nonactivatablegroup-dl.jar
>>     [java] FINE:      impl              :
>> com.sun.jini.qa.harness.NonActivatableGroupImpl
>>     [java] FINE:      policy file       :
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultnonactvm.policy
>>     [java] FINE:      classpath         :
>> /Users/bryan/Documents/workspace/river/trunk/qa/lib/nonactivatablegroup.jar:/Users/bryan/Documents/workspace/river/trunk/lib/start.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar
>>     [java] FINE:      options           : -server
>>     [java] FINE:      properties        :
>> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
>>     [java] FINE:                        : -Dcom.sun.jini.jsk.port=9080
>>     [java] FINE:                        : -Dcom.sun.jini.qa.port=9081
>>     [java] FINE:                        :
>> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
>>     [java] FINE:                        :
>> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>     [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar
>>     [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar
>>     [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.runjiniserver=true
>>     [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.runkitserver=true
>>     [java] FINE:                        :
>> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties
>>     [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.testhosts=
>>     [java] FINE:                        :
>> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging
>>     [java] FINE:                        :
>> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa
>>     [java] FINE:                        : -Dcom.sun.jini.test.port=9082
>>     [java] FINE:                        :
>> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy
>>     [java] FINE:
>>     [java] FINE: Parameters for net.jini.space.JavaSpace(.0):
>>     [java] FINE:      type              : transient
>>     [java] FINE:      codebase          :
>> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>     [java] FINE:      impl              :
>> com.sun.jini.outrigger.TransientOutriggerImpl
>>     [java] FINE:      component name    : com.sun.jini.outrigger
>>     [java] FINE:      policy file       :
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy
>>     [java] FINE:      classpath         :
>> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>>     [java] FINE:      service conf file : -
>>     [java] FINE:      starter conf file : -
>>     [java] FINE:      proxy preparer    : test.outriggerPreparer
>>     [java] FINE:      option args 0     : -
>>     [java] FINE:      option args 1     :
>> com.sun.jini.outrigger.initialLookupGroups = new
>> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
>>     [java] FINE:      option args 2     :
>> com.sun.jini.outrigger.persistenceDirectory =
>> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/FrontEndSpace_log7620264300505337132dir"
>>     [java] FINE:      option args 3     : com.sun.jini.outrigger.store=new
>> com.sun.jini.outrigger.snaplogstore.LogStore(this)
>>     [java] FINE:      option args 4     : multicast.ttl=0
>>     [java] FINE:
>>     [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
>> com.sun.jini.outrigger.OutriggerServerImpl <init>
>>     [java] NonActGrp-out: INFO: Outrigger server started:
>> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>>     [java] JavaSpaceTest.logDebugText FINE: : ----- Transaction Manager Info
>> -----
>>     [java] JavaSpaceTest.logDebugText FINE: : TxnManager impl class     --
>> com.sun.jini.mahalo.ActivatableMahaloImpl
>>     [java] JavaSpaceTest.logDebugText FINE: : TxnManager codebase       --
>> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>     [java] JavaSpaceTest.logDebugText FINE: : TxnManager classpath      --
>> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>>     [java] JavaSpaceTest.logDebugText FINE: : TxnManager policy file
>> --
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy
>>     [java] JavaSpaceTest.logDebugText FINE: :
>> ------------------------------------
>>     [java] AdminManager.startService FINE: starting
>> net.jini.core.transaction.server.TransactionManager
>>     [java] QAConfig.getServiceHost FINE: Selecting service host
>>     [java] QAConfig.getServiceHost FINE: Not distributed - selecting this
>> host
>>     [java] FINE:
>>     [java] FINE: Parameters for
>> net.jini.core.transaction.server.TransactionManager(.0):
>>     [java] FINE:      type              : transient
>>     [java] FINE:      codebase          :
>> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
>> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>>     [java] FINE:      impl              :
>> com.sun.jini.mahalo.TransientMahaloImpl
>>     [java] FINE:      component name    : com.sun.jini.mahalo
>>     [java] FINE:      policy file       :
>> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy
>>     [java] FINE:      classpath         :
>> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>>     [java] FINE:      service conf file : -
>>     [java] FINE:      starter conf file : -
>>     [java] FINE:      proxy preparer    : test.mahaloPreparer
>>     [java] FINE:      option args 0     : -
>>     [java] FINE:      option args 1     :
>> com.sun.jini.mahalo.initialLookupGroups = new
>> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
>>     [java] FINE:      option args 2     :
>> com.sun.jini.mahalo.persistenceDirectory =
>> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/TxnManagerImpl_log04834234852756133875dir"
>>     [java] FINE:      option args 3     : multicast.ttl=0
>>     [java] FINE:
>>     [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
>> com.sun.jini.mahalo.TxnManagerImpl doInit
>>     [java] NonActGrp-out: INFO: Mahalo started:
>> com.sun.jini.mahalo.TransientMahaloImpl@22d16a1f
>>     [java] MasterTest.doTest INFO:
>>     [java] =============================== CALLING RUN()
>> ===============================
>>     [java]
>>     [java]
>>     [java] TIME: 10:16:53 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to to
>> let some listeners expire...
>>     [java]
>>     [java] TIME: 10:17:13 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to let
>> to let transaction expires...
>>     [java]
>>     [java] TIME: 10:17:33 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to to
>> let some listeners expire...
>>     [java]
>>     [java] TIME: 10:18:13 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to to
>> let some listeners expire...
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to let
>> all listeners get notifications.
>>     [java]
>>     [java] TIME: 10:18:53 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 40000) has got 2 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 80000) has got 6 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 120000) has got 8 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 600000) has got 10 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = Lease.FOREVER) has got 10 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 40000) has got 2 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 80000) has got 2 notifications instead of 4 required.
>>     [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 120000) has got 2 notifications instead of 4 required.
>>     [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 600000) has got 2 notifications instead of 4 required.
>>     [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = Lease.FOREVER) has got 2 notifications instead of 4 required.
>>     [java] JavaSpaceTest.logDebugText FINE: : Stage 1 with writing ordinal
>> entries has been completed.
>>     [java] JavaSpaceTest.logDebugText FINE: : ------------------------------
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : Starting 2-nd stage with
>> snapshots.
>>     [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
>> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>>     [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
>> preparing to send/sending event, dropping registration
>>     [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such object in
>> table
>>     [java] NonActGrp-out:     at
>> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
>>     [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806)
>>     [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
>>     [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
>>     [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>>     [java] NonActGrp-out:     at
>> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337)
>>     [java] NonActGrp-out:     at
>> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>>     [java] NonActGrp-out:     at
>> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>>     [java] NonActGrp-out:     at
>> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>>     [java] NonActGrp-out:
>>     [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
>> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>>     [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
>> preparing to send/sending event, dropping registration
>>     [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such object in
>> table
>>     [java] NonActGrp-out:     at
>> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
>>     [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806)
>>     [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
>>     [java] NonActGrp-out:     at
>> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
>>     [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>>     [java] NonActGrp-out:     at
>> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337)
>>     [java] NonActGrp-out:     at
>> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>>     [java] NonActGrp-out:     at
>> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>>     [java] NonActGrp-out:     at
>> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>>     [java] NonActGrp-out:
>>     [java]
>>     [java] TIME: 10:19:38 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to to
>> let some listeners expire...
>>     [java]
>>     [java] TIME: 10:19:58 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to let
>> to let transaction expires...
>>     [java]
>>     [java] TIME: 10:20:18 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to to
>> let some listeners expire...
>>     [java]
>>     [java] TIME: 10:20:58 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to to
>> let some listeners expire...
>>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to let
>> all listeners get notifications.
>>     [java]
>>     [java] TIME: 10:21:38 AM
>>     [java]
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has got 2
>> notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 40000) has got 2 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has got 6
>> notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 80000) has got 6 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has got 8
>> notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 120000) has got 8 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has got 10
>> notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 600000) has got 10 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = Lease.FOREVER) has
>> got 10 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = Lease.FOREVER) has got 10 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has got 2
>> notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 40000) has got 2 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has got 4
>> notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 80000) has got 4 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has got 4
>> notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 120000) has got 4 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has got 4
>> notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = 600000) has got 4 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
>> SimpleEntry: [name = TestEntry #1, id = 1], lease time = Lease.FOREVER) has
>> got 4 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
>> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
>> time = Lease.FOREVER) has got 4 notifications as expected
>>     [java] JavaSpaceTest.logDebugText FINE: : Stage 2 with writing snapshots
>> has been completed.
>>     [java]
>>     [java] com.sun.jini.qa.harness.TestException: Not all listeners've got
>> expected number of events.
>>     [java]     at
>> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest.run(SnapshotExpirationNotifyTest.java:369)
>>     [java]     at
>> com.sun.jini.qa.harness.MasterTest.doTest(MasterTest.java:256)
>>     [java]     at
>> com.sun.jini.qa.harness.MasterTest.main(MasterTest.java:144)
>>     [java] MasterTest.doTest INFO:
>>     [java] ============================ CALLING TEARDOWN()
>> =============================
>>     [java]
>>     [java] QATestEnvironment.tearDown FINE: Destroying remaining managed
>> services
>>     [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.outrigger.ConstrainableSpaceProxy2
>>     [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
>> com.sun.jini.outrigger.OutriggerServerImpl destroy
>>     [java] NonActGrp-out: INFO: Outrigger server destroy thread started:
>> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>>     [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.mahalo.TxnMgrProxy$ConstrainableTxnMgrProxy
>>     [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
>> com.sun.jini.outrigger.OutriggerServerImpl$DestroyThread run
>>     [java] NonActGrp-out: INFO: Outrigger server destroy thread finished:
>> Thread[DestroyThread,5,(JSK) Runtime]
>>     [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.qa.harness.NonActivatableGroupImpl$GroupImpl_Stub
>>     [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.tool.ClassServer
>>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>     [java] INFO: ClassServer terminated [port 9080]
>>     [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.tool.ClassServer
>>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>     [java] INFO: ClassServer terminated [port 9080]
>>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>     [java] INFO: ClassServer terminated [port 9082]
>>     [java] AdminManager.destroyService FINE: destroying service: class
>> com.sun.jini.tool.ClassServer
>>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>     [java] INFO: ClassServer terminated [port 9082]
>>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>     [java] INFO: ClassServer terminated [port 9081]
>>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>>     [java] INFO: ClassServer terminated [port 9081]
>>     [java]
>>     [java] TIME: 10:21:41 AM
>>     [java]
>>     [java] Test process was destroyed and returned code 1
>>     [java]
>> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
>>     [java] Test Failed: Test Failed: com.sun.jini.qa.harness.TestException:
>> Not all listeners've got expected number of events.
>>     [java]
>>     [java]
>>     [java] -----------------------------------------
>>     
>
>   


Re: Help: Javaspace concurrency expert needed

Posted by Dan Creswell <da...@gmail.com>.
Suggests a remote reference registered via notify has gone AWOL when
it shouldn't have done.

The usual causes for that are DGC or garbage collection as the result
of nothing holding on to the exported object.

Looks like you're running trunk?

On 3 March 2013 01:18, Peter Firmstone <ji...@zeus.net.au> wrote:
> Who's smart enough to figure out the cause and fix this test failure?
>
>
>     [java] -----------------------------------------
>     [java]
>     [java] Running
> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
>     [java] Time is Sat Mar 02 10:16:04 EST 2013
>     [java] Starting test in separate process with command:
>     [java]
> /Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/bin/java
> -Djava.security.manager=org.apache.river.api.security.CombinerSecurityManager
> -Djava.security.policy=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaulttest.policy
> -Djava.rmi.server.codebase=http://Bryan-Thompson-MacBook-Air.local:9082/qa1-javaspace-dl.jar
> -cp
> /Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar:/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar
> -client
> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
> -Dcom.sun.jini.jsk.port=9080 -Dcom.sun.jini.qa.port=9081
> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar
> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar
> -Dcom.sun.jini.qa.harness.runjiniserver=true
> -Dcom.sun.jini.qa.harness.runkitserver=true
> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties
> -Dcom.sun.jini.qa.harness.testhosts=
> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging
> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa
> -Dcom.sun.jini.test.port=9082
> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy
> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
> com.sun.jini.qa.harness.MasterTest
> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
>     [java]
>     [java] TIME: 10:16:05 AM
>     [java]
>     [java] MasterTest.doTest INFO:
>     [java] ============================== CALLING CONSTRUCT()
> ==============================
>     [java]
>     [java] AdminManager.startService FINE: starting qaClassServer
>     [java] FINE:
>     [java] FINE: Parameters for qaClassServer(.0):
>     [java] FINE:      type              : classServer
>     [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>     [java] FINE:      directory         :
> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>     [java] FINE:      options           :
>     [java] AdminManager.startService FINE: starting jiniClassServer
>     [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>     [java] INFO: ClassServer started
> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9081]
>     [java] FINE:
>     [java] FINE: Parameters for jiniClassServer(.0):
>     [java] FINE:      type              : classServer
>     [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>     [java] FINE:      directory         :
> /Users/bryan/Documents/workspace/river/trunk/lib-dl
>     [java] FINE:      options           :
>     [java] AdminManager.startService FINE: starting testClassServer
>     [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>     [java] INFO: ClassServer started
> [[/Users/bryan/Documents/workspace/river/trunk/lib-dl/], port 9080]
>     [java] FINE:
>     [java] FINE: Parameters for testClassServer(.0):
>     [java] FINE:      type              : classServer
>     [java] FINE:      impl              : com.sun.jini.tool.ClassServer
>     [java] FINE:      directory         :
> /Users/bryan/Documents/workspace/river/trunk/qa/lib
>     [java] FINE:      options           :
>     [java] Mar 02, 2013 10:16:05 AM com.sun.jini.tool.ClassServer run
>     [java] INFO: ClassServer started
> [[/Users/bryan/Documents/workspace/river/trunk/qa/lib/], port 9082]
>     [java] JavaSpaceTest.logDebugText FINE: : Test Name =
> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest
>     [java] JavaSpaceTest.logDebugText FINE: : ----- JavaSpace Info -----
>     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace impl class     --
> com.sun.jini.outrigger.PersistentOutriggerImpl
>     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace codebase       --
> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace classpath      --
> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>     [java] JavaSpaceTest.logDebugText FINE: : JavaSpace policy file
> --
> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy
>     [java] JavaSpaceTest.logDebugText FINE: : --------------------------
>     [java] AdminManager.startService FINE: starting net.jini.space.JavaSpace
>     [java] QAConfig.getServiceHost FINE: Selecting service host
>     [java] QAConfig.getServiceHost FINE: Not distributed - selecting this
> host
>     [java] AdminManager.startService FINE: starting nonActivatableGroup
>     [java] FINE:
>     [java] FINE: Parameters for nonActivatableGroup(.0):
>     [java] FINE:      type              : nonactivatablegroup
>     [java] FINE:      codebase          :
> http://Bryan-Thompson-MacBook-Air.local:9081/nonactivatablegroup-dl.jar
>     [java] FINE:      impl              :
> com.sun.jini.qa.harness.NonActivatableGroupImpl
>     [java] FINE:      policy file       :
> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultnonactvm.policy
>     [java] FINE:      classpath         :
> /Users/bryan/Documents/workspace/river/trunk/qa/lib/nonactivatablegroup.jar:/Users/bryan/Documents/workspace/river/trunk/lib/start.jar:/Users/bryan/Documents/workspace/river/trunk/lib/jsk-platform.jar:/Users/bryan/Documents/workspace/river/trunk/lib/custard-apple-1.0.2.jar:/Users/bryan/Documents/workspace/river/trunk/lib/high-scale-lib.jar
>     [java] FINE:      options           : -server
>     [java] FINE:      properties        :
> -Djava.ext.dirs=/Users/bryan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_11.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:/Users/bryan/Documents/workspace/river/trunk/qa/lib-ext:/Users/bryan/Documents/workspace/river/trunk/lib-ext
>     [java] FINE:                        : -Dcom.sun.jini.jsk.port=9080
>     [java] FINE:                        : -Dcom.sun.jini.qa.port=9081
>     [java] FINE:                        :
> -Dcom.sun.jini.jsk.home=/Users/bryan/Documents/workspace/river/trunk
>     [java] FINE:                        :
> -Dcom.sun.jini.qa.home=/Users/bryan/Documents/workspace/river/trunk/qa
>     [java] FINE:                        :
> -Dcom.sun.jini.qa.harness.harnessJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jiniharness.jar
>     [java] FINE:                        :
> -Dcom.sun.jini.qa.harness.testJar=/Users/bryan/Documents/workspace/river/trunk/qa/lib/jinitests.jar
>     [java] FINE:                        :
> -Dcom.sun.jini.qa.harness.runjiniserver=true
>     [java] FINE:                        :
> -Dcom.sun.jini.qa.harness.runkitserver=true
>     [java] FINE:                        :
> -Djava.security.properties=file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/trust/dynamic-policy.properties
>     [java] FINE:                        :
> -Dcom.sun.jini.qa.harness.testhosts=
>     [java] FINE:                        :
> -Djava.util.logging.config.file=/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/qa1.logging
>     [java] FINE:                        :
> -Dcom.sun.jini.test.home=/Users/bryan/Documents/workspace/river/trunk/qa
>     [java] FINE:                        : -Dcom.sun.jini.test.port=9082
>     [java] FINE:                        :
> -Dcom.sun.jini.qa.harness.policies=file:/Users/bryan/Documents/workspace/river/trunk/qa/src/com/sun/jini/test/resources/jinitest.policy
>     [java] FINE:
>     [java] FINE: Parameters for net.jini.space.JavaSpace(.0):
>     [java] FINE:      type              : transient
>     [java] FINE:      codebase          :
> http://Bryan-Thompson-MacBook-Air.local:9080/outrigger-dl.jar
> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>     [java] FINE:      impl              :
> com.sun.jini.outrigger.TransientOutriggerImpl
>     [java] FINE:      component name    : com.sun.jini.outrigger
>     [java] FINE:      policy file       :
> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultoutrigger.policy
>     [java] FINE:      classpath         :
> /Users/bryan/Documents/workspace/river/trunk/lib/outrigger.jar
>     [java] FINE:      service conf file : -
>     [java] FINE:      starter conf file : -
>     [java] FINE:      proxy preparer    : test.outriggerPreparer
>     [java] FINE:      option args 0     : -
>     [java] FINE:      option args 1     :
> com.sun.jini.outrigger.initialLookupGroups = new
> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
>     [java] FINE:      option args 2     :
> com.sun.jini.outrigger.persistenceDirectory =
> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/FrontEndSpace_log7620264300505337132dir"
>     [java] FINE:      option args 3     : com.sun.jini.outrigger.store=new
> com.sun.jini.outrigger.snaplogstore.LogStore(this)
>     [java] FINE:      option args 4     : multicast.ttl=0
>     [java] FINE:
>     [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
> com.sun.jini.outrigger.OutriggerServerImpl <init>
>     [java] NonActGrp-out: INFO: Outrigger server started:
> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>     [java] JavaSpaceTest.logDebugText FINE: : ----- Transaction Manager Info
> -----
>     [java] JavaSpaceTest.logDebugText FINE: : TxnManager impl class     --
> com.sun.jini.mahalo.ActivatableMahaloImpl
>     [java] JavaSpaceTest.logDebugText FINE: : TxnManager codebase       --
> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>     [java] JavaSpaceTest.logDebugText FINE: : TxnManager classpath      --
> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>     [java] JavaSpaceTest.logDebugText FINE: : TxnManager policy file
> --
> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy
>     [java] JavaSpaceTest.logDebugText FINE: :
> ------------------------------------
>     [java] AdminManager.startService FINE: starting
> net.jini.core.transaction.server.TransactionManager
>     [java] QAConfig.getServiceHost FINE: Selecting service host
>     [java] QAConfig.getServiceHost FINE: Not distributed - selecting this
> host
>     [java] FINE:
>     [java] FINE: Parameters for
> net.jini.core.transaction.server.TransactionManager(.0):
>     [java] FINE:      type              : transient
>     [java] FINE:      codebase          :
> http://Bryan-Thompson-MacBook-Air.local:9080/mahalo-dl.jar
> http://Bryan-Thompson-MacBook-Air.local:9080/jsk-dl.jar
>     [java] FINE:      impl              :
> com.sun.jini.mahalo.TransientMahaloImpl
>     [java] FINE:      component name    : com.sun.jini.mahalo
>     [java] FINE:      policy file       :
> file:/Users/bryan/Documents/workspace/river/trunk/qa/harness/policy/defaultmahalo.policy
>     [java] FINE:      classpath         :
> /Users/bryan/Documents/workspace/river/trunk/lib/mahalo.jar
>     [java] FINE:      service conf file : -
>     [java] FINE:      starter conf file : -
>     [java] FINE:      proxy preparer    : test.mahaloPreparer
>     [java] FINE:      option args 0     : -
>     [java] FINE:      option args 1     :
> com.sun.jini.mahalo.initialLookupGroups = new
> String[]{"QATestDefaultGroup_Bryan-Thompson-MacBook-Air.local_1362237364614"}
>     [java] FINE:      option args 2     :
> com.sun.jini.mahalo.persistenceDirectory =
> "/var/folders/f4/pdnb1x7n00x04cgyk11xg0s00000gn/T/TxnManagerImpl_log04834234852756133875dir"
>     [java] FINE:      option args 3     : multicast.ttl=0
>     [java] FINE:
>     [java] NonActGrp-out: Mar 02, 2013 10:16:07 AM
> com.sun.jini.mahalo.TxnManagerImpl doInit
>     [java] NonActGrp-out: INFO: Mahalo started:
> com.sun.jini.mahalo.TransientMahaloImpl@22d16a1f
>     [java] MasterTest.doTest INFO:
>     [java] =============================== CALLING RUN()
> ===============================
>     [java]
>     [java]
>     [java] TIME: 10:16:53 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to to
> let some listeners expire...
>     [java]
>     [java] TIME: 10:17:13 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to let
> to let transaction expires...
>     [java]
>     [java] TIME: 10:17:33 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to to
> let some listeners expire...
>     [java]
>     [java] TIME: 10:18:13 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to to
> let some listeners expire...
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to let
> all listeners get notifications.
>     [java]
>     [java] TIME: 10:18:53 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 40000) has got 2 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 80000) has got 6 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 120000) has got 8 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 600000) has got 10 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = Lease.FOREVER) has got 10 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 40000) has got 2 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 80000) has got 2 notifications instead of 4 required.
>     [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 120000) has got 2 notifications instead of 4 required.
>     [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 600000) has got 2 notifications instead of 4 required.
>     [java] JavaSpaceTest.logDebugText FINE: : FAILED: SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = Lease.FOREVER) has got 2 notifications instead of 4 required.
>     [java] JavaSpaceTest.logDebugText FINE: : Stage 1 with writing ordinal
> entries has been completed.
>     [java] JavaSpaceTest.logDebugText FINE: : ------------------------------
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : Starting 2-nd stage with
> snapshots.
>     [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>     [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
> preparing to send/sending event, dropping registration
>     [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such object in
> table
>     [java] NonActGrp-out:     at
> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
>     [java] NonActGrp-out:     at
> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806)
>     [java] NonActGrp-out:     at
> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
>     [java] NonActGrp-out:     at
> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
>     [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>     [java] NonActGrp-out:     at
> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337)
>     [java] NonActGrp-out:     at
> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>     [java] NonActGrp-out:     at
> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>     [java] NonActGrp-out:     at
> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>     [java] NonActGrp-out:
>     [java] NonActGrp-out: Mar 02, 2013 10:18:53 AM
> com.sun.jini.outrigger.Notifier$NotifyTask logFailure
>     [java] NonActGrp-out: INFO: Encountered definite exceptionwhile
> preparing to send/sending event, dropping registration
>     [java] NonActGrp-out: java.rmi.NoSuchObjectException: no such object in
> table
>     [java] NonActGrp-out:     at
> net.jini.jeri.BasicObjectEndpoint.executeCall(BasicObjectEndpoint.java:428)
>     [java] NonActGrp-out:     at
> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:806)
>     [java] NonActGrp-out:     at
> net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
>     [java] NonActGrp-out:     at
> net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
>     [java] NonActGrp-out:     at $Proxy4.notify(Unknown Source)
>     [java] NonActGrp-out:     at
> com.sun.jini.outrigger.EventRegistrationWatcher$BasicEventSender.sendEvent(EventRegistrationWatcher.java:337)
>     [java] NonActGrp-out:     at
> com.sun.jini.outrigger.Notifier$NotifyTask.tryOnce(Notifier.java:187)
>     [java] NonActGrp-out:     at
> com.sun.jini.thread.RetryTask.run(RetryTask.java:131)
>     [java] NonActGrp-out:     at
> com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
>     [java] NonActGrp-out:
>     [java]
>     [java] TIME: 10:19:38 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 45000 to to
> let some listeners expire...
>     [java]
>     [java] TIME: 10:19:58 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to let
> to let transaction expires...
>     [java]
>     [java] TIME: 10:20:18 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 20000 to to
> let some listeners expire...
>     [java]
>     [java] TIME: 10:20:58 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to to
> let some listeners expire...
>     [java] JavaSpaceTest.logDebugText FINE: : now sleeping for 40000 to let
> all listeners get notifications.
>     [java]
>     [java] TIME: 10:21:38 AM
>     [java]
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has got 2
> notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 40000) has got 2 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has got 6
> notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 80000) has got 6 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has got 8
> notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 120000) has got 8 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has got 10
> notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 600000) has got 10 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = Lease.FOREVER) has
> got 10 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = Lease.FOREVER) has got 10 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 40000) has got 2
> notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 40000) has got 2 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 80000) has got 4
> notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 80000) has got 4 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 120000) has got 4
> notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 120000) has got 4 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = 600000) has got 4
> notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = 600000) has got 4 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : NotifyCounter: (template =
> SimpleEntry: [name = TestEntry #1, id = 1], lease time = Lease.FOREVER) has
> got 4 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : SnapshotNotifyCounter:
> (snapshot for template SimpleEntry: [name = TestEntry #1, id = 1], lease
> time = Lease.FOREVER) has got 4 notifications as expected
>     [java] JavaSpaceTest.logDebugText FINE: : Stage 2 with writing snapshots
> has been completed.
>     [java]
>     [java] com.sun.jini.qa.harness.TestException: Not all listeners've got
> expected number of events.
>     [java]     at
> com.sun.jini.test.spec.javaspace.conformance.snapshot.SnapshotExpirationNotifyTest.run(SnapshotExpirationNotifyTest.java:369)
>     [java]     at
> com.sun.jini.qa.harness.MasterTest.doTest(MasterTest.java:256)
>     [java]     at
> com.sun.jini.qa.harness.MasterTest.main(MasterTest.java:144)
>     [java] MasterTest.doTest INFO:
>     [java] ============================ CALLING TEARDOWN()
> =============================
>     [java]
>     [java] QATestEnvironment.tearDown FINE: Destroying remaining managed
> services
>     [java] AdminManager.destroyService FINE: destroying service: class
> com.sun.jini.outrigger.ConstrainableSpaceProxy2
>     [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
> com.sun.jini.outrigger.OutriggerServerImpl destroy
>     [java] NonActGrp-out: INFO: Outrigger server destroy thread started:
> com.sun.jini.outrigger.OutriggerServerImpl@4c6c3e
>     [java] AdminManager.destroyService FINE: destroying service: class
> com.sun.jini.mahalo.TxnMgrProxy$ConstrainableTxnMgrProxy
>     [java] NonActGrp-out: Mar 02, 2013 10:21:39 AM
> com.sun.jini.outrigger.OutriggerServerImpl$DestroyThread run
>     [java] NonActGrp-out: INFO: Outrigger server destroy thread finished:
> Thread[DestroyThread,5,(JSK) Runtime]
>     [java] AdminManager.destroyService FINE: destroying service: class
> com.sun.jini.qa.harness.NonActivatableGroupImpl$GroupImpl_Stub
>     [java] AdminManager.destroyService FINE: destroying service: class
> com.sun.jini.tool.ClassServer
>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>     [java] INFO: ClassServer terminated [port 9080]
>     [java] AdminManager.destroyService FINE: destroying service: class
> com.sun.jini.tool.ClassServer
>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>     [java] INFO: ClassServer terminated [port 9080]
>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>     [java] INFO: ClassServer terminated [port 9082]
>     [java] AdminManager.destroyService FINE: destroying service: class
> com.sun.jini.tool.ClassServer
>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>     [java] INFO: ClassServer terminated [port 9082]
>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>     [java] INFO: ClassServer terminated [port 9081]
>     [java] Mar 02, 2013 10:21:41 AM com.sun.jini.tool.ClassServer terminate
>     [java] INFO: ClassServer terminated [port 9081]
>     [java]
>     [java] TIME: 10:21:41 AM
>     [java]
>     [java] Test process was destroyed and returned code 1
>     [java]
> com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotExpirationNotifyTest.td
>     [java] Test Failed: Test Failed: com.sun.jini.qa.harness.TestException:
> Not all listeners've got expected number of events.
>     [java]
>     [java]
>     [java] -----------------------------------------