See <https://builds.apache.org/job/river-qa-refactor-jdk7/39/changes>
Changes:
[peter_firmstone] After changing startTimeout to volatile, the test later
failed again after repeated runs, with the same cause appended below.
This commit doubles the default Mux startTimout and connection timeouts to 30
seconds.
Test failure:
com/sun/jini/test/impl/outrigger/matching/StressTestWithShutdown.td
[java] java.rmi.ConnectIOException: I/O exception connecting to
BasicObjectEndpoint[049eaa35-f725-490f-89b4-f32f064dba0d,TcpEndpoint[10.1.1.2:56674]];
nested exception is:
[java] java.io.IOException: timeout waiting for server to respond to
handshake
[java] at
net.jini.jeri.BasicInvocationHandler.wrapSafeIOException(BasicInvocationHandler.java:893)
[java] at
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:711)
[java] at
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
[java] at
net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
[java] at com.sun.jini.outrigger.$Proxy1.write(Unknown Source)
[java] at
com.sun.jini.outrigger.SpaceProxy2.write(SpaceProxy2.java:296)
[java] at
com.sun.jini.test.impl.outrigger.matching.StressTest$WriteRandomEntryTask.spaceWrite(StressTest.java:585)
[java] at
com.sun.jini.test.impl.outrigger.matching.StressTest$WriteRandomEntryTask.run(StressTest.java:548)
[java] at
com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
[java] Caused by: java.io.IOException: timeout waiting for server to
respond to handshake
[java] at com.sun.jini.jeri.internal.mux.Mux.start(Mux.java:240)
[java] at
com.sun.jini.jeri.internal.mux.MuxClient.start(MuxClient.java:35)
[java] at
net.jini.jeri.connection.ConnectionManager$OutboundMux.newRequest(ConnectionManager.java:375)
[java] at
net.jini.jeri.connection.ConnectionManager$ReqIterator.next(ConnectionManager.java:665)
[java] at
net.jini.jeri.BasicObjectEndpoint$1.next(BasicObjectEndpoint.java:370)
[java] at
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:708)
[java] ... 7 more
[peter_firmstone] Refactored to use configuration.
[peter_firmstone] Mux field defaultTimout was written by threads synchronizing
on ConnectionManager's lock during startup, however reads were performed while
holding muxLock. The documentation stated that access to defaultTimeout was
unsynchronized.
The failing test:
com/sun/jini/test/impl/outrigger/matching/StressTestWithShutdown.td
Suspected cause: because reads and writes were synchronized on different locks
and defaultTimout was neither final nor volatile, threads could see
defaultTimeout in it's default constructed state of 0, causing an IOException:
[java] TestBase.fail FINE: WriteTask_190: Caught an unexpected Exception
during a retry
[java] java.rmi.ConnectIOException: I/O exception connecting to
BasicObjectEndpoint[b3755737-cdf3-49d7-adb1-33197bc3a993,TcpEndpoint[10.1.1.2:54176]];
nested exception is:
[java] java.io.IOException: timeout waiting for server to respond to
handshake
[java] at
net.jini.jeri.BasicInvocationHandler.wrapSafeIOException(BasicInvocationHandler.java:893)
[java] at
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:711)
[java] at
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethod(BasicInvocationHandler.java:659)
[java] at
net.jini.jeri.BasicInvocationHandler.invoke(BasicInvocationHandler.java:528)
[java] at com.sun.jini.outrigger.$Proxy1.write(Unknown Source)
[java] at
com.sun.jini.outrigger.SpaceProxy2.write(SpaceProxy2.java:296)
[java] at
com.sun.jini.test.impl.outrigger.matching.StressTest$WriteRandomEntryTask.spaceWrite(StressTest.java:585)
[java] at
com.sun.jini.test.impl.outrigger.matching.StressTest$WriteRandomEntryTask.run(StressTest.java:548)
[java] at
com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
[java] Caused by: java.io.IOException: timeout waiting for server to
respond to handshake
[java] at
com.sun.jini.jeri.internal.mux.MuxClient.newRequest(MuxClient.java:68)
[java] at
net.jini.jeri.connection.ConnectionManager$OutboundMux.newRequest(ConnectionManager.java:391)
[java] at
net.jini.jeri.connection.ConnectionManager$ReqIterator.next(ConnectionManager.java:665)
[java] at
net.jini.jeri.BasicObjectEndpoint$1.next(BasicObjectEndpoint.java:370)
[java] at
net.jini.jeri.BasicInvocationHandler.invokeRemoteMethodOnce(BasicInvocationHandler.java:708)
[java] ... 7 more
I was reliably able to reproduce this on Solaris 10 sparc, 4 x 450MHz Ultra 80
with interleaved Ram.
java version "1.6.0_30"
Java(TM) SE Runtime Environment (build 1.6.0_30-b12)
Java HotSpot(TM) Server VM (build 20.5-b03, mixed mode)
Changing the field to volatile (state wasn't dependant on previous state and
wouldn't cause deadlock) fixed the issue.
------------------------------------------
[...truncated 8836 lines...]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionTakeIfExistsTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionTakeIfExistsWaitTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionTakeNO_WAITTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionTakeReadTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionTakeTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionTakeWaitTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionWriteLeaseANYTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionWriteLeaseFOREVERTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionWriteNegativeLeaseTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionWriteTakeIfExistsNotifyTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionWriteTakeIfExistsTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionWriteTakeNotifyTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionWriteTakeTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotTransactionWriteTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotWriteLeaseANYTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotWriteLeaseFOREVERTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotWriteNegativeLeaseTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/spec/javaspace/conformance/snapshot/SnapshotWriteTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/AdminIFShutdownTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/AdminIFTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/LeaseExpireCancelTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/LeaseExpireRenewTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/LeaseMapTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/LeaseTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/MahaloCreateShutdownTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/MahaloIFTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/MahaloImplReadyStateTest.td
[java] Test Skipped: verifiers are:
com.sun.jini.test.impl.mercury.ActivatableMercuryVerifier
com.sun.jini.qa.harness.SkipConfigTestVerifier
[java] -----------------------------------------
[java]
com/sun/jini/test/impl/mahalo/NestableServerTransactionCreatedToStringTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/impl/mahalo/NestableTransactionCreatedToStringTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/PrepareAndCommitExceptionTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/PrepareAndCommitExceptionTest2.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/PrepareAndCommitExceptionTest3.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/PrepareAndCommitExceptionTest4.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/PrepareAndCommitExceptionTest5.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/RandomStressTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/ServerTransactionEqualityTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/ServerTransactionToStringTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/TransactionCreatedToStringTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/impl/mahalo/TransactionManagerCreatedToStringTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
com/sun/jini/test/impl/mahalo/TxnMgrImplNullActivationConfigEntries.td
[java] Test Skipped: verifiers are:
com.sun.jini.test.impl.mahalo.ActivatableMahaloVerifier
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/TxnMgrImplNullConfigEntries.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/TxnMgrImplNullRecoveredLocators.td
[java] Test Skipped: verifiers are:
com.sun.jini.test.impl.mahalo.ActivatableMahaloVerifier
[java] -----------------------------------------
[java] com/sun/jini/test/impl/mahalo/TxnMgrProxyEqualityTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/AsynchAbortOnCommitTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/AsynchAbortOnPrepareTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/CommitExpiredTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/CommitTimeoutTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/GetStateTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/JoinIdempotentTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/JoinWhileActiveTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/ManyParticipantsTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/PrepareTimeoutTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/RollBackErrorTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/RollForwardErrorTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java] com/sun/jini/test/spec/txnmanager/TwoPhaseTest.td
[java] Test Passed: OK
[java]
[java] -----------------------------------------
[java]
[java] # of tests started = 1411
[java] # of tests completed = 1411
[java] # of tests skipped = 47
[java] # of tests passed = 1410
[java] # of tests failed = 1
[java]
[java] -----------------------------------------
[java]
[java] Date finished:
[java] Sun Mar 10 23:34:19 UTC 2013
[java] Time elapsed:
[java] 59857 seconds
[java]
[java] Java Result: 1
collect-result:
[copy] Copying 1 file to
<https://builds.apache.org/job/river-qa-refactor-jdk7/ws/trunk/qa/result>
[copy] Copying 1 file to
<https://builds.apache.org/job/river-qa-refactor-jdk7/ws/trunk/qa/result>
[zip] Building zip:
<https://builds.apache.org/job/river-qa-refactor-jdk7/39/artifact/trunk/qa/result/qaresults-amd64-Linux-1.7.0_04.zip>
BUILD FAILED
<https://builds.apache.org/job/river-qa-refactor-jdk7/ws/trunk/build.xml>:2093:
The following error occurred while executing this line:
<https://builds.apache.org/job/river-qa-refactor-jdk7/ws/trunk/qa/build.xml>:406:
The following error occurred while executing this line:
<https://builds.apache.org/job/river-qa-refactor-jdk7/ws/trunk/qa/build.xml>:380:
condition satisfied
Total time: 1003 minutes 26 seconds
Build step 'Invoke Ant' marked build as failure
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Archiving artifacts
