You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@geode.apache.org by "Hitesh Khamesra (JIRA)" <ji...@apache.org> on 2016/06/22 16:52:58 UTC
[jira] [Commented] (GEODE-1582) CI failure:
PersistentPartitionedRegionOldConfigDUnitTest.testCleanStop
[ https://issues.apache.org/jira/browse/GEODE-1582?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15344726#comment-15344726 ]
Hitesh Khamesra commented on GEODE-1582:
----------------------------------------
Skip to content
titletitle log in
search
ENABLE AUTO REFRESH
Jenkins
Geode_develop_DistributedTests
#2963
Test Results
com.gemstone.gemfire.internal.cache.partitioned
PersistentPartitionedRegionOldConfigDUnitTest
testCleanStop
Back to Project
Status
Changes
Console Output
View Build Information
History
Parameters
Metadata
Environment Variables
Git Build Data
Test Result
Changes since last success
Compare environment
JS Widgets
Previous Build
Next Build
Regression
com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionOldConfigDUnitTest.testCleanStop
Failing for the past 1 build (Since Failed#2963 )
Took 1 sec.
Failed 1 times in the last 16 runs. Stability: 93 %
Error Message
com.gemstone.gemfire.test.dunit.RMIException: While invoking com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$1.run in VM 1 running on Host japan.gemstone.com with 4 VMs
Stacktrace
com.gemstone.gemfire.test.dunit.RMIException: While invoking com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$1.run in VM 1 running on Host japan.gemstone.com with 4 VMs
at com.gemstone.gemfire.test.dunit.VM.invoke(VM.java:389)
at com.gemstone.gemfire.test.dunit.VM.invoke(VM.java:355)
at com.gemstone.gemfire.test.dunit.VM.invoke(VM.java:293)
at com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.checkRecoveredFromDisk(PersistentPartitionedRegionTestBase.java:100)
at com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionDUnitTest.testCleanStop(PersistentPartitionedRegionDUnitTest.java:1353)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:112)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:56)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:66)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:109)
at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54)
at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.AssertionError: expected:<0> but was:<1>
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:645)
at org.junit.Assert.assertEquals(Assert.java:631)
at com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$1.run(PersistentPartitionedRegionTestBase.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at hydra.MethExecutor.executeObject(MethExecutor.java:268)
at com.gemstone.gemfire.test.dunit.standalone.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:82)
at sun.reflect.GeneratedMethodAccessor157.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:323)
at sun.rmi.transport.Transport$1.run(Transport.java:200)
at sun.rmi.transport.Transport$1.run(Transport.java:197)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.Transport.serviceCall(Transport.java:196)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$95(TCPTransport.java:683)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
... 3 more
Standard Output
Previously run tests: [StatisticsDUnitTest, Bug41733DUnitTest, PartitionedRegionEntryCountDUnitTest, PartitionedRegionMetaDataCleanupDUnitTest, PersistentPartitionedRegionDUnitTest, Bug39356DUnitTest, PersistentPartitionedRegionOldConfigDUnitTest]
[vm_0][info 2016/06/19 03:29:06.849 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
[vm_0][info 2016/06/19 03:29:06.849 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM) (took 0 ms)
[vm_1][info 2016/06/19 03:29:06.850 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
[vm_1][info 2016/06/19 03:29:06.850 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM) (took 0 ms)
[vm_2][info 2016/06/19 03:29:06.850 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
[vm_2][info 2016/06/19 03:29:06.850 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM) (took 0 ms)
[vm_3][info 2016/06/19 03:29:06.851 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
[vm_3][info 2016/06/19 03:29:06.851 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM) (took 0 ms)
[setup] START TEST PersistentPartitionedRegionOldConfigDUnitTest.testRegisterInterestNoDataStores
[vm_0][info 2016/06/19 03:29:06.851 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1001199593.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1001199593@6ec0672a
[vm_0][info 2016/06/19 03:29:06.851 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1001199593.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1001199593@6ec0672a (took 0 ms)
[vm_1][info 2016/06/19 03:29:06.851 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1582618712.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1582618712@5f241c5b
[vm_1][info 2016/06/19 03:29:06.852 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1582618712.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1582618712@5f241c5b (took 0 ms)
[vm_2][info 2016/06/19 03:29:06.852 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1077830635.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1077830635@7f35baa0
[vm_2][info 2016/06/19 03:29:06.852 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1077830635.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$9/1077830635@7f35baa0 (took 0 ms)
[vm_3][info 2016/06/19 03:29:06.852 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$4/2046342202.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$4/2046342202@20769357
[vm_3][info 2016/06/19 03:29:06.852 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$4/2046342202.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$4/2046342202@20769357 (took 0 ms)
[vm_0][info 2016/06/19 03:29:06.852 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.setRegionName with 1 args
[vm_0][info 2016/06/19 03:29:06.853 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.setRegionName with 1 args (took 0 ms)
[vm_1][info 2016/06/19 03:29:06.853 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.setRegionName with 1 args
[vm_1][info 2016/06/19 03:29:06.853 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.setRegionName with 1 args (took 0 ms)
[vm_2][info 2016/06/19 03:29:06.853 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.setRegionName with 1 args
[vm_2][info 2016/06/19 03:29:06.853 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.setRegionName with 1 args (took 0 ms)
[vm_3][info 2016/06/19 03:29:06.853 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.setRegionName with 1 args
[vm_3][info 2016/06/19 03:29:06.853 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.setRegionName with 1 args (took 0 ms)
[info 2016/06/19 03:29:06.853 PDT <Test worker> tid=0xa] <ExpectedException action=add>Connection reset</ExpectedException>
[info 2016/06/19 03:29:06.854 PDT <Test worker> tid=0xa] <ExpectedException action=add>Connection reset</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.854 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_0][info 2016/06/19 03:29:06.854 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>Connection reset</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.854 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>Connection reset</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.854 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_1][info 2016/06/19 03:29:06.854 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_1][info 2016/06/19 03:29:06.855 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>Connection reset</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.855 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>Connection reset</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.855 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_2][info 2016/06/19 03:29:06.855 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_2][info 2016/06/19 03:29:06.855 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Connection reset</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.855 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Connection reset</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.855 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_3][info 2016/06/19 03:29:06.856 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_3][info 2016/06/19 03:29:06.856 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Connection reset</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.856 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Connection reset</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.856 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[info 2016/06/19 03:29:06.856 PDT <Test worker> tid=0xa] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[info 2016/06/19 03:29:06.856 PDT <Test worker> tid=0xa] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.856 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_0][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_1][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_1][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_2][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_2][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.857 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_3][info 2016/06/19 03:29:06.858 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_3][info 2016/06/19 03:29:06.858 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.858 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>SocketTimeoutException</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.858 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[info 2016/06/19 03:29:06.858 PDT <Test worker> tid=0xa] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[info 2016/06/19 03:29:06.858 PDT <Test worker> tid=0xa] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.858 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_0][info 2016/06/19 03:29:06.858 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_1][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_1][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_2][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_2][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_3][info 2016/06/19 03:29:06.859 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_3][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>ServerConnectivityException</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[info 2016/06/19 03:29:06.860 PDT <Test worker> tid=0xa] <ExpectedException action=add>Socket Closed</ExpectedException>
[info 2016/06/19 03:29:06.860 PDT <Test worker> tid=0xa] <ExpectedException action=add>Socket Closed</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_0][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>Socket Closed</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>Socket Closed</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_1][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_1][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>Socket Closed</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>Socket Closed</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.860 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_2][info 2016/06/19 03:29:06.861 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_2][info 2016/06/19 03:29:06.861 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Socket Closed</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.861 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Socket Closed</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.861 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_3][info 2016/06/19 03:29:06.861 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_3][info 2016/06/19 03:29:06.861 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Socket Closed</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.861 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Socket Closed</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.861 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[info 2016/06/19 03:29:06.861 PDT <Test worker> tid=0xa] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[info 2016/06/19 03:29:06.861 PDT <Test worker> tid=0xa] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_0][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[vm_0][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_1][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_1][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[vm_1][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_2][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_2][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[vm_2][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_3][info 2016/06/19 03:29:06.862 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
[vm_3][info 2016/06/19 03:29:06.863 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.863 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=add>Unexpected IOException</ExpectedException>
[vm_3][info 2016/06/19 03:29:06.863 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException" (took 0 ms)
[vm_0][info 2016/06/19 03:29:06.866 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionDUnitTest$8.call with 0 args on object: "create per"
[vm_0]distributed system properties: {locators=localhost[27085], enable-cluster-configuration=false, use-cluster-configuration=false, mcast-port=0, disable-auto-reconnect=true, log-level=info}
[vm_0][info 2016/06/19 03:29:06.868 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Startup Configuration:
[vm_0] ### GemFire Properties defined with api ###
[vm_0]disable-auto-reconnect=true
[vm_0]enable-cluster-configuration=false
[vm_0]locators=localhost[27085]
[vm_0]log-level=info
[vm_0]mcast-port=0
[vm_0]use-cluster-configuration=false
[vm_0]### GemFire Properties using default values ###
[vm_0]ack-severe-alert-threshold=0
[vm_0]ack-wait-threshold=15
[vm_0]archive-disk-space-limit=0
[vm_0]archive-file-size-limit=0
[vm_0]async-distribution-timeout=0
[vm_0]async-max-queue-size=8
[vm_0]async-queue-timeout=60000
[vm_0]bind-address=
[vm_0]cache-xml-file=cache.xml
[vm_0]cluster-configuration-dir=
[vm_0]cluster-ssl-ciphers=any
[vm_0]cluster-ssl-enabled=false
[vm_0]cluster-ssl-keystore=
[vm_0]cluster-ssl-keystore-password=
[vm_0]cluster-ssl-keystore-type=
[vm_0]cluster-ssl-protocols=any
[vm_0]cluster-ssl-require-authentication=true
[vm_0]cluster-ssl-truststore=
[vm_0]cluster-ssl-truststore-password=
[vm_0]conflate-events=server
[vm_0]conserve-sockets=true
[vm_0]delta-propagation=true
[vm_0]deploy-working-dir=.
[vm_0]disable-tcp=false
[vm_0]distributed-system-id=-1
[vm_0]distributed-transactions=false
[vm_0]durable-client-id=
[vm_0]durable-client-timeout=300
[vm_0]enable-network-partition-detection=false
[vm_0]enable-time-statistics=false
[vm_0]enforce-unique-host=false
[vm_0]gateway-ssl-ciphers=any
[vm_0]gateway-ssl-enabled=false
[vm_0]gateway-ssl-keystore=
[vm_0]gateway-ssl-keystore-password=
[vm_0]gateway-ssl-keystore-type=
[vm_0]gateway-ssl-protocols=any
[vm_0]gateway-ssl-require-authentication=true
[vm_0]gateway-ssl-truststore=
[vm_0]gateway-ssl-truststore-password=
[vm_0]groups=
[vm_0]http-service-bind-address=
[vm_0]http-service-port=7070
[vm_0]http-service-ssl-ciphers=any
[vm_0]http-service-ssl-enabled=false
[vm_0]http-service-ssl-keystore=
[vm_0]http-service-ssl-keystore-password=
[vm_0]http-service-ssl-keystore-type=
[vm_0]http-service-ssl-protocols=any
[vm_0]http-service-ssl-require-authentication=false
[vm_0]http-service-ssl-truststore=
[vm_0]http-service-ssl-truststore-password=
[vm_0]jmx-manager=false
[vm_0]jmx-manager-access-file=
[vm_0]jmx-manager-bind-address=
[vm_0]jmx-manager-hostname-for-clients=
[vm_0]jmx-manager-http-port=7070
[vm_0]jmx-manager-password-file=
[vm_0]jmx-manager-port=1099
[vm_0]jmx-manager-ssl=false
[vm_0]jmx-manager-ssl-ciphers=any
[vm_0]jmx-manager-ssl-enabled=false
[vm_0]jmx-manager-ssl-keystore=
[vm_0]jmx-manager-ssl-keystore-password=
[vm_0]jmx-manager-ssl-keystore-type=
[vm_0]jmx-manager-ssl-protocols=any
[vm_0]jmx-manager-ssl-require-authentication=true
[vm_0]jmx-manager-ssl-truststore=
[vm_0]jmx-manager-ssl-truststore-password=
[vm_0]jmx-manager-start=false
[vm_0]jmx-manager-update-rate=2000
[vm_0]load-cluster-configuration-from-dir=false
[vm_0]locator-wait-time=0
[vm_0]lock-memory=false
[vm_0]log-disk-space-limit=0
[vm_0]log-file=
[vm_0]log-file-size-limit=0
[vm_0]max-num-reconnect-tries=3
[vm_0]max-wait-time-reconnect=60000
[vm_0]mcast-address=239.192.81.1
[vm_0]mcast-flow-control=1048576, 0.25, 5000
[vm_0]mcast-recv-buffer-size=1048576
[vm_0]mcast-send-buffer-size=65535
[vm_0]mcast-ttl=32
[vm_0]member-timeout=5000
[vm_0]membership-port-range=1024-65535
[vm_0]memcached-bind-address=
[vm_0]memcached-port=0
[vm_0]memcached-protocol=ASCII
[vm_0]name=
[vm_0]off-heap-memory-size=
[vm_0]redis-bind-address=
[vm_0]redis-password=
[vm_0]redis-port=0
[vm_0]redundancy-zone=
[vm_0]remote-locators=
[vm_0]remove-unresponsive-client=false
[vm_0]roles=
[vm_0]security-client-accessor=
[vm_0]security-client-accessor-pp=
[vm_0]security-client-auth-init=
[vm_0]security-client-authenticator=
[vm_0]security-client-dhalgo=
[vm_0]security-log-file=
[vm_0]security-log-level=config
[vm_0]security-peer-auth-init=
[vm_0]security-peer-authenticator=
[vm_0]security-peer-verifymember-timeout=1000
[vm_0]server-bind-address=
[vm_0]server-ssl-ciphers=any
[vm_0]server-ssl-enabled=false
[vm_0]server-ssl-keystore=
[vm_0]server-ssl-keystore-password=
[vm_0]server-ssl-keystore-type=
[vm_0]server-ssl-protocols=any
[vm_0]server-ssl-require-authentication=true
[vm_0]server-ssl-truststore=
[vm_0]server-ssl-truststore-password=
[vm_0]socket-buffer-size=32768
[vm_0]socket-lease-time=60000
[vm_0]ssl-ciphers=any
[vm_0]ssl-enabled=false
[vm_0]ssl-protocols=any
[vm_0]ssl-require-authentication=true
[vm_0]start-dev-rest-api=false
[vm_0]start-locator=
[vm_0]statistic-archive-file=
[vm_0]statistic-sample-rate=1000
[vm_0]statistic-sampling-enabled=true
[vm_0]tcp-port=0
[vm_0]udp-fragment-size=60000
[vm_0]udp-recv-buffer-size=1048576
[vm_0]udp-send-buffer-size=65535
[vm_0]user-command-packages=
[vm_0][info 2016/06/19 03:29:06.869 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Starting membership services
[vm_0][info 2016/06/19 03:29:06.874 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] JGroups channel created (took 5ms)
[vm_0][info 2016/06/19 03:29:06.875 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] GemFire P2P Listener started on null
[vm_0][info 2016/06/19 03:29:06.875 PDT <Geode Failure Detection Server thread 0> tid=0xbae] Started failure detection server thread on japan.gemstone.com/10.118.32.37:36510.
[vm_0][info 2016/06/19 03:29:06.876 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Attempting to join the distributed system through coordinator japan(15421:locator)<ec><v0>:1024 using address japan(15426)<ec>:1025
[locator][info 2016/06/19 03:29:06.877 PDT <unicast receiver,japan-1492> tid=0x22] received join request from japan(15426)<ec>:1025
[locator][info 2016/06/19 03:29:06.977 PDT <Geode Membership View Creator> tid=0x28] View Creator is processing 5 requests for the next membership view
[locator][info 2016/06/19 03:29:06.977 PDT <Geode Membership View Creator> tid=0x28] preparing new view View[japan(15421:locator)<ec><v0>:1024|118] members: [japan(15421:locator)<ec><v0>:1024, japan(15426)<ec><v118>:1025{lead}] shutdown: [japan(15426)<ec><v116>:1025, japan(15430)<ec><v117>:1026]
[locator]failure detection ports: 56147 36510
[vm_0][info 2016/06/19 03:29:06.978 PDT <unicast receiver,japan-42572> tid=0xbaa] received new view: View[japan(15421:locator)<ec><v0>:1024|118] members: [japan(15421:locator)<ec><v0>:1024, japan(15426)<ec><v118>:1025{lead}] shutdown: [japan(15426)<ec><v116>:1025, japan(15430)<ec><v117>:1026]
[vm_0]old view is: null
[locator][info 2016/06/19 03:29:06.978 PDT <Geode Membership View Creator> tid=0x28] finished waiting for responses to view preparation
[locator][info 2016/06/19 03:29:06.978 PDT <Geode Membership View Creator> tid=0x28] received new view: View[japan(15421:locator)<ec><v0>:1024|118] members: [japan(15421:locator)<ec><v0>:1024, japan(15426)<ec><v118>:1025{lead}] shutdown: [japan(15426)<ec><v116>:1025, japan(15430)<ec><v117>:1026]
[locator]old view is: View[japan(15421:locator)<ec><v0>:1024|117] members: [japan(15421:locator)<ec><v0>:1024, japan(15426)<ec><v116>:1025{lead}, japan(15430)<ec><v117>:1026]
[locator][info 2016/06/19 03:29:06.978 PDT <Geode Membership View Creator> tid=0x28] Peer locator received new membership view: View[japan(15421:locator)<ec><v0>:1024|118] members: [japan(15421:locator)<ec><v0>:1024, japan(15426)<ec><v118>:1025{lead}] shutdown: [japan(15426)<ec><v116>:1025, japan(15430)<ec><v117>:1026]
[vm_0][info 2016/06/19 03:29:06.978 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Finished joining (took 103ms).
[vm_0][info 2016/06/19 03:29:06.978 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Starting DistributionManager japan(15426)<ec><v118>:1025. (took 110 ms)
[locator][info 2016/06/19 03:29:06.978 PDT <Geode Membership View Creator> tid=0x28] sending new view View[japan(15421:locator)<ec><v0>:1024|118] members: [japan(15421:locator)<ec><v0>:1024, japan(15426)<ec><v118>:1025{lead}] shutdown: [japan(15426)<ec><v116>:1025, japan(15430)<ec><v117>:1026]
[locator]failure detection ports: 56147 36510
[locator][info 2016/06/19 03:29:06.978 PDT <View Message Processor> tid=0x33] Membership: Processing addition < japan(15426)<ec><v118>:1025 >
[locator][info 2016/06/19 03:29:06.978 PDT <View Message Processor> tid=0x33] Admitting member <japan(15426)<ec><v118>:1025>. Now there are 2 non-admin member(s).
[vm_0][info 2016/06/19 03:29:06.978 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Initial (distribution manager) view = View[japan(15421:locator)<ec><v0>:1024|118] members: [japan(15421:locator)<ec><v0>:1024, japan(15426)<ec><v118>:1025{lead}] shutdown: [japan(15426)<ec><v116>:1025, japan(15430)<ec><v117>:1026]
[vm_0][info 2016/06/19 03:29:06.978 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Admitting member <japan(15421:locator)<ec><v0>:1024>. Now there are 1 non-admin member(s).
[vm_0][info 2016/06/19 03:29:06.978 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Admitting member <japan(15426)<ec><v118>:1025>. Now there are 2 non-admin member(s).
[locator][info 2016/06/19 03:29:06.980 PDT <Pooled High Priority Message Processor 1> tid=0x37] Member japan(15426)<ec><v118>:1025 is equivalent or in the same redundancy zone.
[vm_0][info 2016/06/19 03:29:06.981 PDT <P2P message reader for japan(15421:locator)<ec><v0>:1024 shared unordered uid=95 port=33922> tid=0xbb3] Member japan(15421:locator)<ec><v0>:1024 is equivalent or in the same redundancy zone.
[vm_0][info 2016/06/19 03:29:06.987 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Initializing region _monitoringRegion_10.118.32.37<v118>1025
[vm_0][info 2016/06/19 03:29:06.987 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Initialization of region _monitoringRegion_10.118.32.37<v118>1025 completed
[vm_0][info 2016/06/19 03:29:06.989 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
[vm_0][info 2016/06/19 03:29:06.990 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Initializing region PdxTypes
[vm_0][info 2016/06/19 03:29:06.990 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Initialization of region PdxTypes completed
[vm_0][info 2016/06/19 03:29:06.990 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Initializing region __PR
[vm_0][info 2016/06/19 03:29:06.991 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Initialization of region __PR completed
[vm_0][info 2016/06/19 03:29:06.991 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Partitioned Region /PersistentPartitionedRegionOldConfigDUnitTest_testRegisterInterestNoDataStoresRegion is born with prId=66 ident:#PersistentPartitionedRegionOldConfigDUnitTest_testRegisterInterestNoDataStoresRegion
[vm_0][info 2016/06/19 03:29:06.994 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Cache server connection listener bound to address 0.0.0.0/0.0.0.0:26377 with backlog 1,000.
[vm_0][info 2016/06/19 03:29:06.994 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] ClientHealthMonitorThread maximum allowed time between pings: 60,000
[vm_0][info 2016/06/19 03:29:06.996 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] CacheServer Configuration: port=26377 max-connections=800 max-threads=0 notify-by-subscription=true socket-buffer-size=32768 maximum-time-between-pings=60000 maximum-message-count=230000 message-time-to-live=180 eviction-policy=none capacity=1 overflow directory=. groups=[] loadProbe=ConnectionCountProbe loadPollInterval=5000 tcpNoDelay=true
[vm_0][info 2016/06/19 03:29:06.997 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: 26377
[vm_0] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionDUnitTest$8.call with 0 args on object: "create per" (took 131 ms)
[vm_1][info 2016/06/19 03:29:07.000 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionDUnitTest$9.run with 0 args on object: "create client"
[vm_1]distributed system properties: {locators=, enable-cluster-configuration=false, use-cluster-configuration=false, mcast-port=0, disable-auto-reconnect=true, log-level=info}
[vm_1][info 2016/06/19 03:29:07.005 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Running in local mode since no locators were specified.
[vm_1][info 2016/06/19 03:29:07.006 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Initializing region _monitoringRegion_10.118.32.37<v-1>0
[vm_1][info 2016/06/19 03:29:07.006 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Initialization of region _monitoringRegion_10.118.32.37<v-1>0 completed
[vm_1][info 2016/06/19 03:29:07.009 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Updating membership port. Port changed from 0 to 59,951. ID is now japan(15430:loner):0:39ed3468
[vm_0][info 2016/06/19 03:29:07.013 PDT <Handshaker 0.0.0.0/0.0.0.0:26377 Thread 1> tid=0xbc7] Initializing region _gfe_non_durable_client_with_id_japan(15430:loner):59951:39ed3468_1_queue
[vm_0][info 2016/06/19 03:29:07.013 PDT <Handshaker 0.0.0.0/0.0.0.0:26377 Thread 1> tid=0xbc7] Initialization of region _gfe_non_durable_client_with_id_japan(15430:loner):59951:39ed3468_1_queue completed
[vm_1][info 2016/06/19 03:29:07.014 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Pool pool started with multiuser-authentication=false
[vm_0][info 2016/06/19 03:29:07.014 PDT <Handshaker 0.0.0.0/0.0.0.0:26377 Thread 1> tid=0xbc7] Entry expiry tasks disabled because the queue became primary. Old messageTimeToLive was: 180
[vm_0][warn 2016/06/19 03:29:07.015 PDT <ServerConnection on port 26377 Thread 0> tid=0xbc8] Unable to find any members to host a bucket in the partitioned region. Advise you to start enough data store nodes. Partitioned Region name = /PersistentPartitionedRegionOldConfigDUnitTest_testRegisterInterestNoDataStoresRegion Redundancy level set to 0 . Number of available data stores: 0 . Number successfully allocated = 0 . Data stores: [] . Data stores successfully allocated: [] . Equivalent members: [japan(15426)<ec><v118>:1025, japan(15421:locator)<ec><v0>:1024]
[vm_1][info 2016/06/19 03:29:07.017 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] GemFireCache[id = 454949214; isClosing = true; isShutDownAll = false; created = Sun Jun 19 03:29:07 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
[vm_1][info 2016/06/19 03:29:07.018 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Destroying connection pool pool
[vm_1][warn 2016/06/19 03:29:07.019 PDT <Cache Client Updater Thread on japan(15426)<ec><v118>:1025 port 26377> tid=0xb39] Cache Client Updater Thread on japan(15426)<ec><v118>:1025 port 26377 (japan.gemstone.com:26377): abandoned wait due to cancellation.
[vm_1][warn 2016/06/19 03:29:07.019 PDT <Cache Client Updater Thread on japan(15426)<ec><v118>:1025 port 26377> tid=0xb39] Cache Client Updater Thread on japan(15426)<ec><v118>:1025 port 26377 (japan.gemstone.com:26377): no cache (exiting)
[vm_1][info 2016/06/19 03:29:07.021 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionDUnitTest$9.run with 0 args on object: "create client" (took 21 ms)
[vm_0][info 2016/06/19 03:29:07.022 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/872043423.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/872043423@73bc8b0b
[vm_0][info 2016/06/19 03:29:07.022 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] GemFireCache[id = 1316397747; isClosing = true; isShutDownAll = false; created = Sun Jun 19 03:29:06 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
[vm_0][info 2016/06/19 03:29:07.023 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Cache server on port 26,377 is shutting down.
[vm_0][info 2016/06/19 03:29:07.024 PDT <Queue Removal Thread> tid=0xbcc] The QueueRemovalThread is done.
[vm_0][info 2016/06/19 03:29:07.025 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/872043423.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/872043423@73bc8b0b (took 3 ms)
[vm_1][info 2016/06/19 03:29:07.025 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/1562392333.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/1562392333@6ea81110
[vm_1][info 2016/06/19 03:29:07.026 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/1562392333.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/1562392333@6ea81110 (took 0 ms)
[vm_2][info 2016/06/19 03:29:07.026 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/2139465429.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/2139465429@65661818
[vm_2][info 2016/06/19 03:29:07.026 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/2139465429.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/2139465429@65661818 (took 0 ms)
[vm_3][info 2016/06/19 03:29:07.027 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$5/138441976.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$5/138441976@1af24c46
[vm_3][info 2016/06/19 03:29:07.027 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$5/138441976.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$5/138441976@1af24c46 (took 0 ms)
[vm_0][info 2016/06/19 03:29:07.028 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/662573139.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/662573139@6721fb2
[vm_0][info 2016/06/19 03:29:07.028 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/662573139.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/662573139@6721fb2 (took 0 ms)
[vm_1][info 2016/06/19 03:29:07.028 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/851767686.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/851767686@605095ba
[vm_1][info 2016/06/19 03:29:07.028 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/851767686.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/851767686@605095ba (took 0 ms)
[vm_2][info 2016/06/19 03:29:07.028 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/476052029.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/476052029@4b71a491
[vm_2][info 2016/06/19 03:29:07.028 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/476052029.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/476052029@4b71a491 (took 0 ms)
[vm_3][info 2016/06/19 03:29:07.029 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$7/619475100.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$7/619475100@1ff1c03e
[vm_3][info 2016/06/19 03:29:07.029 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$7/619475100.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$7/619475100@1ff1c03e (took 0 ms)
[info 2016/06/19 03:29:07.029 PDT <Test worker> tid=0xa] <ExpectedException action=remove>Connection reset</ExpectedException>
[info 2016/06/19 03:29:07.029 PDT <Test worker> tid=0xa] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_0][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove"
[vm_0][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_0][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_0][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_0][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove" (took 0 ms)
[vm_1][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove"
[vm_1][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_1][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_1][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove" (took 0 ms)
[vm_2][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove"
[vm_2][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_2][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_2][info 2016/06/19 03:29:07.030 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove" (took 0 ms)
[vm_3][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove"
[vm_3][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_3][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] <ExpectedException action=remove>Connection reset</ExpectedException>
[vm_3][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(2)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove" (took 0 ms)
[info 2016/06/19 03:29:07.031 PDT <Test worker> tid=0xa] <ExpectedException action=remove>SocketTimeoutException</ExpectedException>
[info 2016/06/19 03:29:07.031 PDT <Test worker> tid=0xa] <ExpectedException action=remove>SocketTimeoutException</ExpectedException>
[vm_0][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove"
[vm_0][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=remove>SocketTimeoutException</ExpectedException>
[vm_0][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=remove>SocketTimeoutException</ExpectedException>
[vm_0][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] <ExpectedException action=remove>SocketTimeoutException</ExpectedException>
[vm_0][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x3f] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove" (took 0 ms)
[vm_1][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$1.run with 0 args on object: "IgnoredException remove"
[vm_1][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException action=remove>SocketTimeoutException</ExpectedException>
[vm_1][info 2016/06/19 03:29:07.031 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] <ExpectedException ac
...[truncated 5027349 chars]...
beat requests]]] from non-member japan(15426)<ec><v204>:1025
[locator][info 2016/06/19 03:29:56.722 PDT <unicast receiver,japan-1492> tid=0x22] Membership ignoring suspect request for SuspectMembersMessage [suspectRequests=[SuspectRequest [member=japan(15430)<ec><v205>:1026, reason=Member isn't responding to heartbeat requests]]] from non-member japan(15426)<ec><v204>:1025
[locator][info 2016/06/19 03:29:59.221 PDT <unicast receiver,japan-1492> tid=0x22] Membership ignoring suspect request for SuspectMembersMessage [suspectRequests=[SuspectRequest [member=japan(15421:locator)<ec><v0>:1024, reason=Member isn't responding to heartbeat requests]]] from non-member japan(15426)<ec><v204>:1025
[vm_1][info 2016/06/19 03:29:59.222 PDT <unicast receiver,japan-3404> tid=0x13ba] Membership ignoring suspect request for SuspectMembersMessage [suspectRequests=[SuspectRequest [member=japan(15421:locator)<ec><v0>:1024, reason=Member isn't responding to heartbeat requests]]] from non-member japan(15426)<ec><v204>:1025
[vm_0][warn 2016/06/19 03:30:10.913 PDT <Pooled Waiting Message Processor 0> tid=0x14b3] Daemon threads are slow to stop; culprits include: waiting pool;
[vm_0][info 2016/06/19 03:30:10.913 PDT <Pooled Waiting Message Processor 0> tid=0x14b3] Now closing distribution for japan(15426)<ec><v204>:1025
[vm_0][info 2016/06/19 03:30:10.913 PDT <Pooled Waiting Message Processor 0> tid=0x14b3] Stopping membership services
[locator][info 2016/06/19 03:30:10.914 PDT <unicast receiver,japan-1492> tid=0x22] received leave request from japan(15426)<ec><v204>:1025 for japan(15426)<ec><v204>:1025
[vm_1][info 2016/06/19 03:30:10.914 PDT <unicast receiver,japan-3404> tid=0x13ba] received leave request from japan(15426)<ec><v204>:1025 for japan(15426)<ec><v204>:1025
[vm_0][info 2016/06/19 03:30:10.914 PDT <Pooled Waiting Message Processor 0> tid=0x14b3] GMSHealthMonitor server socket is closed in stopServices().
[vm_0][info 2016/06/19 03:30:10.914 PDT <Geode Failure Detection Server thread 0> tid=0x14b1] GMSHealthMonitor server thread exiting
[vm_0][info 2016/06/19 03:30:10.914 PDT <Pooled Waiting Message Processor 0> tid=0x14b3] GMSHealthMonitor serverSocketExecutor is terminated
[vm_0][info 2016/06/19 03:30:10.918 PDT <Pooled Waiting Message Processor 0> tid=0x14b3] DistributionManager stopped in 21,009ms.
[vm_0][info 2016/06/19 03:30:10.918 PDT <Pooled Waiting Message Processor 0> tid=0x14b3] Marking DistributionManager japan(15426)<ec><v204>:1025 as closed.
[vm_0][info 2016/06/19 03:30:10.951 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Startup Configuration:
[vm_0] ### GemFire Properties defined with api ###
[vm_0]disable-auto-reconnect=true
[vm_0]enable-cluster-configuration=false
[vm_0]locators=localhost[27085]
[vm_0]log-level=info
[vm_0]mcast-port=0
[vm_0]use-cluster-configuration=false
[vm_0]### GemFire Properties using default values ###
[vm_0]ack-severe-alert-threshold=0
[vm_0]ack-wait-threshold=15
[vm_0]archive-disk-space-limit=0
[vm_0]archive-file-size-limit=0
[vm_0]async-distribution-timeout=0
[vm_0]async-max-queue-size=8
[vm_0]async-queue-timeout=60000
[vm_0]bind-address=
[vm_0]cache-xml-file=cache.xml
[vm_0]cluster-configuration-dir=
[vm_0]cluster-ssl-ciphers=any
[vm_0]cluster-ssl-enabled=false
[vm_0]cluster-ssl-keystore=
[vm_0]cluster-ssl-keystore-password=
[vm_0]cluster-ssl-keystore-type=
[vm_0]cluster-ssl-protocols=any
[vm_0]cluster-ssl-require-authentication=true
[vm_0]cluster-ssl-truststore=
[vm_0]cluster-ssl-truststore-password=
[vm_0]conflate-events=server
[vm_0]conserve-sockets=true
[vm_0]delta-propagation=true
[vm_0]deploy-working-dir=.
[vm_0]disable-tcp=false
[vm_0]distributed-system-id=-1
[vm_0]distributed-transactions=false
[vm_0]durable-client-id=
[vm_0]durable-client-timeout=300
[vm_0]enable-network-partition-detection=false
[vm_0]enable-time-statistics=false
[vm_0]enforce-unique-host=false
[vm_0]gateway-ssl-ciphers=any
[vm_0]gateway-ssl-enabled=false
[vm_0]gateway-ssl-keystore=
[vm_0]gateway-ssl-keystore-password=
[vm_0]gateway-ssl-keystore-type=
[vm_0]gateway-ssl-protocols=any
[vm_0]gateway-ssl-require-authentication=true
[vm_0]gateway-ssl-truststore=
[vm_0]gateway-ssl-truststore-password=
[vm_0]groups=
[vm_0]http-service-bind-address=
[vm_0]http-service-port=7070
[vm_0]http-service-ssl-ciphers=any
[vm_0]http-service-ssl-enabled=false
[vm_0]http-service-ssl-keystore=
[vm_0]http-service-ssl-keystore-password=
[vm_0]http-service-ssl-keystore-type=
[vm_0]http-service-ssl-protocols=any
[vm_0]http-service-ssl-require-authentication=false
[vm_0]http-service-ssl-truststore=
[vm_0]http-service-ssl-truststore-password=
[vm_0]jmx-manager=false
[vm_0]jmx-manager-access-file=
[vm_0]jmx-manager-bind-address=
[vm_0]jmx-manager-hostname-for-clients=
[vm_0]jmx-manager-http-port=7070
[vm_0]jmx-manager-password-file=
[vm_0]jmx-manager-port=1099
[vm_0]jmx-manager-ssl=false
[vm_0]jmx-manager-ssl-ciphers=any
[vm_0]jmx-manager-ssl-enabled=false
[vm_0]jmx-manager-ssl-keystore=
[vm_0]jmx-manager-ssl-keystore-password=
[vm_0]jmx-manager-ssl-keystore-type=
[vm_0]jmx-manager-ssl-protocols=any
[vm_0]jmx-manager-ssl-require-authentication=true
[vm_0]jmx-manager-ssl-truststore=
[vm_0]jmx-manager-ssl-truststore-password=
[vm_0]jmx-manager-start=false
[vm_0]jmx-manager-update-rate=2000
[vm_0]load-cluster-configuration-from-dir=false
[vm_0]locator-wait-time=0
[vm_0]lock-memory=false
[vm_0]log-disk-space-limit=0
[vm_0]log-file=
[vm_0]log-file-size-limit=0
[vm_0]max-num-reconnect-tries=3
[vm_0]max-wait-time-reconnect=60000
[vm_0]mcast-address=239.192.81.1
[vm_0]mcast-flow-control=1048576, 0.25, 5000
[vm_0]mcast-recv-buffer-size=1048576
[vm_0]mcast-send-buffer-size=65535
[vm_0]mcast-ttl=32
[vm_0]member-timeout=5000
[vm_0]membership-port-range=1024-65535
[vm_0]memcached-bind-address=
[vm_0]memcached-port=0
[vm_0]memcached-protocol=ASCII
[vm_0]name=
[vm_0]off-heap-memory-size=
[vm_0]redis-bind-address=
[vm_0]redis-password=
[vm_0]redis-port=0
[vm_0]redundancy-zone=
[vm_0]remote-locators=
[vm_0]remove-unresponsive-client=false
[vm_0]roles=
[vm_0]security-client-accessor=
[vm_0]security-client-accessor-pp=
[vm_0]security-client-auth-init=
[vm_0]security-client-authenticator=
[vm_0]security-client-dhalgo=
[vm_0]security-log-file=
[vm_0]security-log-level=config
[vm_0]security-peer-auth-init=
[vm_0]security-peer-authenticator=
[vm_0]security-peer-verifymember-timeout=1000
[vm_0]server-bind-address=
[vm_0]server-ssl-ciphers=any
[vm_0]server-ssl-enabled=false
[vm_0]server-ssl-keystore=
[vm_0]server-ssl-keystore-password=
[vm_0]server-ssl-keystore-type=
[vm_0]server-ssl-protocols=any
[vm_0]server-ssl-require-authentication=true
[vm_0]server-ssl-truststore=
[vm_0]server-ssl-truststore-password=
[vm_0]socket-buffer-size=32768
[vm_0]socket-lease-time=60000
[vm_0]ssl-ciphers=any
[vm_0]ssl-enabled=false
[vm_0]ssl-protocols=any
[vm_0]ssl-require-authentication=true
[vm_0]start-dev-rest-api=false
[vm_0]start-locator=
[vm_0]statistic-archive-file=
[vm_0]statistic-sample-rate=1000
[vm_0]statistic-sampling-enabled=true
[vm_0]tcp-port=0
[vm_0]udp-fragment-size=60000
[vm_0]udp-recv-buffer-size=1048576
[vm_0]udp-send-buffer-size=65535
[vm_0]user-command-packages=
[vm_0][info 2016/06/19 03:30:10.952 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Starting membership services
[vm_0][info 2016/06/19 03:30:10.958 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] JGroups channel created (took 6ms)
[vm_0][info 2016/06/19 03:30:10.958 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] GemFire P2P Listener started on null
[vm_0][info 2016/06/19 03:30:10.959 PDT <Geode Failure Detection Server thread 0> tid=0x14ef] Started failure detection server thread on /10.118.32.37:59538.
[vm_0][info 2016/06/19 03:30:10.961 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Attempting to join the distributed system through coordinator japan(15421:locator)<ec><v0>:1024 using address japan(15426)<ec>:1025
[locator][info 2016/06/19 03:30:10.961 PDT <unicast receiver,japan-1492> tid=0x22] received join request from japan(15426)<ec>:1025
[vm_0][info 2016/06/19 03:30:11.019 PDT <Pooled Waiting Message Processor 0> tid=0x14b3] Cache is confirmed closed
[locator][info 2016/06/19 03:30:11.262 PDT <Geode Membership View Creator> tid=0x28] View Creator is processing 1 requests for the next membership view
[locator][info 2016/06/19 03:30:11.262 PDT <Geode Membership View Creator> tid=0x28] preparing new view View[japan(15421:locator)<ec><v0>:1024|207] members: [japan(15421:locator)<ec><v0>:1024, japan(15430)<ec><v205>:1026{lead}, japan(15426)<ec><v207>:1025]
[locator]failure detection ports: 56147 58667 59538
[vm_0][info 2016/06/19 03:30:11.262 PDT <unicast receiver,japan-23641> tid=0x14eb] received new view: View[japan(15421:locator)<ec><v0>:1024|207] members: [japan(15421:locator)<ec><v0>:1024, japan(15430)<ec><v205>:1026{lead}, japan(15426)<ec><v207>:1025]
[vm_0]old view is: null
[vm_0][info 2016/06/19 03:30:11.263 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Finished joining (took 304ms).
[vm_0][info 2016/06/19 03:30:11.263 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Starting DistributionManager japan(15426)<ec><v207>:1025. (took 312 ms)
[locator][info 2016/06/19 03:30:11.263 PDT <Geode Membership View Creator> tid=0x28] finished waiting for responses to view preparation
[locator][info 2016/06/19 03:30:11.263 PDT <Geode Membership View Creator> tid=0x28] received new view: View[japan(15421:locator)<ec><v0>:1024|207] members: [japan(15421:locator)<ec><v0>:1024, japan(15430)<ec><v205>:1026{lead}, japan(15426)<ec><v207>:1025]
[locator]old view is: View[japan(15421:locator)<ec><v0>:1024|206] members: [japan(15421:locator)<ec><v0>:1024, japan(15430)<ec><v205>:1026{lead}] shutdown: [japan(15426)<ec><v204>:1025]
[vm_0][info 2016/06/19 03:30:11.263 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initial (distribution manager) view = View[japan(15421:locator)<ec><v0>:1024|207] members: [japan(15421:locator)<ec><v0>:1024, japan(15430)<ec><v205>:1026{lead}, japan(15426)<ec><v207>:1025]
[vm_0][info 2016/06/19 03:30:11.263 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Admitting member <japan(15421:locator)<ec><v0>:1024>. Now there are 1 non-admin member(s).
[vm_0][info 2016/06/19 03:30:11.263 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Admitting member <japan(15430)<ec><v205>:1026>. Now there are 2 non-admin member(s).
[vm_0][info 2016/06/19 03:30:11.263 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Admitting member <japan(15426)<ec><v207>:1025>. Now there are 3 non-admin member(s).
[locator][info 2016/06/19 03:30:11.263 PDT <Geode Membership View Creator> tid=0x28] Peer locator received new membership view: View[japan(15421:locator)<ec><v0>:1024|207] members: [japan(15421:locator)<ec><v0>:1024, japan(15430)<ec><v205>:1026{lead}, japan(15426)<ec><v207>:1025]
[locator][info 2016/06/19 03:30:11.263 PDT <Geode Membership View Creator> tid=0x28] sending new view View[japan(15421:locator)<ec><v0>:1024|207] members: [japan(15421:locator)<ec><v0>:1024, japan(15430)<ec><v205>:1026{lead}, japan(15426)<ec><v207>:1025]
[locator]failure detection ports: 56147 58667 59538
[locator][info 2016/06/19 03:30:11.263 PDT <View Message Processor> tid=0x33] Membership: Processing addition < japan(15426)<ec><v207>:1025 >
[vm_1][info 2016/06/19 03:30:11.264 PDT <unicast receiver,japan-3404> tid=0x13ba] received new view: View[japan(15421:locator)<ec><v0>:1024|207] members: [japan(15421:locator)<ec><v0>:1024, japan(15430)<ec><v205>:1026{lead}, japan(15426)<ec><v207>:1025]
[vm_1]old view is: View[japan(15421:locator)<ec><v0>:1024|206] members: [japan(15421:locator)<ec><v0>:1024, japan(15430)<ec><v205>:1026{lead}] shutdown: [japan(15426)<ec><v204>:1025]
[vm_1][info 2016/06/19 03:30:11.264 PDT <View Message Processor> tid=0x13de] Membership: Processing addition < japan(15426)<ec><v207>:1025 >
[vm_1][info 2016/06/19 03:30:11.264 PDT <View Message Processor> tid=0x13de] Admitting member <japan(15426)<ec><v207>:1025>. Now there are 3 non-admin member(s).
[locator][info 2016/06/19 03:30:11.263 PDT <View Message Processor> tid=0x33] Admitting member <japan(15426)<ec><v207>:1025>. Now there are 3 non-admin member(s).
[vm_1][info 2016/06/19 03:30:11.265 PDT <Pooled High Priority Message Processor 1> tid=0x13d1] Member japan(15426)<ec><v207>:1025 is equivalent or in the same redundancy zone.
[locator][info 2016/06/19 03:30:11.265 PDT <Pooled High Priority Message Processor 1> tid=0x37] Member japan(15426)<ec><v207>:1025 is equivalent or in the same redundancy zone.
[vm_0][info 2016/06/19 03:30:11.267 PDT <P2P message reader for japan(15421:locator)<ec><v0>:1024 shared unordered uid=166 port=40111> tid=0x14f9] Member japan(15421:locator)<ec><v0>:1024 is equivalent or in the same redundancy zone.
[vm_0][info 2016/06/19 03:30:11.267 PDT <P2P message reader for japan(15430)<ec><v205>:1026 shared unordered uid=252 port=40110> tid=0x14f8] Member japan(15430)<ec><v205>:1026 is equivalent or in the same redundancy zone.
[vm_0][info 2016/06/19 03:30:11.279 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initializing region _monitoringRegion_10.118.32.37<v207>1025
[vm_0][info 2016/06/19 03:30:11.280 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initialization of region _monitoringRegion_10.118.32.37<v207>1025 completed
[vm_0][info 2016/06/19 03:30:11.282 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
[vm_0][info 2016/06/19 03:30:11.283 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initializing region PdxTypes
[vm_0][info 2016/06/19 03:30:11.284 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Region PdxTypes requesting initial image from japan(15430)<ec><v205>:1026
[vm_0][info 2016/06/19 03:30:11.284 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] PdxTypes is done getting image from japan(15430)<ec><v205>:1026. isDeltaGII is false
[vm_0][info 2016/06/19 03:30:11.284 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initialization of region PdxTypes completed
[vm_0][info 2016/06/19 03:30:11.286 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Recovered disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion with unique id 8961f2fd7a9c4338-a2f5de4ae9c54c3b
[vm_0][info 2016/06/19 03:30:11.286 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Recovering oplog#1 /japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm0/diskDir/disk0/BACKUP_PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion_1.drf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.286 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Recovering oplog#1 /japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm0/diskDir/disk0/BACKUP_PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion_1.crf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.286 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] recovery oplog load took 0 ms
[vm_0][info 2016/06/19 03:30:11.286 PDT <Oplog Delete Task> tid=0x1509] Deleted oplog#1 crf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.287 PDT <Oplog Delete Task> tid=0x1509] Deleted oplog#1 drf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.287 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Created oplog#2 drf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.288 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Created oplog#2 crf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.288 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] recovery region initialization took 2 ms
[vm_0][info 2016/06/19 03:30:11.288 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initializing region __PR
[vm_0][info 2016/06/19 03:30:11.289 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Region __PR requesting initial image from japan(15430)<ec><v205>:1026
[vm_0][info 2016/06/19 03:30:11.290 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] __PR is done getting image from japan(15430)<ec><v205>:1026. isDeltaGII is false
[vm_0][info 2016/06/19 03:30:11.290 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initialization of region __PR completed
[vm_0][info 2016/06/19 03:30:11.291 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Partitioned Region /PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion is created with prId=113
[vm_0][info 2016/06/19 03:30:11.306 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: null
[vm_0] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$14.run with 0 args on object: "create pr" (took 21388 ms)
[vm_0][info 2016/06/19 03:30:11.306 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$5.run with 0 args on object: "CheckData"
[vm_0][info 2016/06/19 03:30:11.307 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: null
[vm_0] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$5.run with 0 args on object: "CheckData" (took 0 ms)
[vm_1][info 2016/06/19 03:30:11.307 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$15.call with 0 args on object: "get buckets"
[vm_1][info 2016/06/19 03:30:11.308 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: [0, 1, 2, 3]
[vm_1] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$15.call with 0 args on object: "get buckets" (took 0 ms)
[vm_0][info 2016/06/19 03:30:11.308 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$15.call with 0 args on object: "get buckets"
[vm_0][info 2016/06/19 03:30:11.308 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: []
[vm_0] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$15.call with 0 args on object: "get buckets" (took 0 ms)
[vm_0][info 2016/06/19 03:30:11.308 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$8.run with 0 args on object: "Close Cache"
[vm_0][info 2016/06/19 03:30:11.309 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] GemFireCache[id = 315940214; isClosing = true; isShutDownAll = false; created = Sun Jun 19 03:30:11 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
[vm_1][info 2016/06/19 03:30:11.312 PDT <PartitionedRegion Message Processor1> tid=0x13d8] The following persistent member has gone offline for region PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion:
[vm_1] DiskStore ID: 8961f2fd-7a9c-4338-a2f5-de4ae9c54c3b
[vm_1] Name:
[vm_1] Location: /10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm0/diskDir/disk0
[vm_1]Remaining participating members for the region include:
[vm_1][]
[vm_0][info 2016/06/19 03:30:11.321 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: null
[vm_0] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$8.run with 0 args on object: "Close Cache" (took 12 ms)
[vm_1][info 2016/06/19 03:30:11.322 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$8.run with 0 args on object: "Close Cache"
[vm_1][info 2016/06/19 03:30:11.323 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] GemFireCache[id = 1502343777; isClosing = true; isShutDownAll = false; created = Sun Jun 19 03:29:49 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
[vm_1][info 2016/06/19 03:30:11.327 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$8.run with 0 args on object: "Close Cache" (took 5 ms)
[vm_1][info 2016/06/19 03:30:11.328 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$14.run with 0 args on object: "create pr"
[vm_0][info 2016/06/19 03:30:11.328 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$14.run with 0 args on object: "create pr"
[vm_0][info 2016/06/19 03:30:11.335 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initializing region _monitoringRegion_10.118.32.37<v207>1025
[vm_0][info 2016/06/19 03:30:11.336 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initialization of region _monitoringRegion_10.118.32.37<v207>1025 completed
[vm_0][info 2016/06/19 03:30:11.338 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
[vm_0][info 2016/06/19 03:30:11.338 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initializing region PdxTypes
[vm_1][info 2016/06/19 03:30:11.339 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Initializing region _monitoringRegion_10.118.32.37<v205>1026
[vm_0][info 2016/06/19 03:30:11.339 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initialization of region PdxTypes completed
[vm_0][info 2016/06/19 03:30:11.340 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Recovered disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion with unique id 8961f2fd7a9c4338-a2f5de4ae9c54c3b
[vm_0][info 2016/06/19 03:30:11.340 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Recovering oplog#2 /japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm0/diskDir/disk0/BACKUP_PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion_2.drf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.341 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Recovering oplog#2 /japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm0/diskDir/disk0/BACKUP_PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion_2.crf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.341 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] recovery oplog load took 1 ms
[vm_0][info 2016/06/19 03:30:11.341 PDT <Oplog Delete Task> tid=0x1517] Deleted oplog#2 crf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.341 PDT <Oplog Delete Task> tid=0x1517] Deleted oplog#2 drf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.343 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Created oplog#3 drf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.344 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Created oplog#3 crf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_0][info 2016/06/19 03:30:11.344 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] recovery region initialization took 3 ms
[vm_0][info 2016/06/19 03:30:11.345 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initializing region __PR
[vm_1][info 2016/06/19 03:30:11.345 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Initialization of region _monitoringRegion_10.118.32.37<v205>1026 completed
[vm_0][info 2016/06/19 03:30:11.345 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Initialization of region __PR completed
[vm_1][info 2016/06/19 03:30:11.347 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
[vm_1][info 2016/06/19 03:30:11.347 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Initializing region PdxTypes
[vm_0][info 2016/06/19 03:30:11.348 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Partitioned Region /PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion is born with prId=114 ident:#PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion
[vm_1][info 2016/06/19 03:30:11.355 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Region PdxTypes requesting initial image from japan(15426)<ec><v207>:1025
[vm_1][info 2016/06/19 03:30:11.356 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] PdxTypes is done getting image from japan(15426)<ec><v207>:1025. isDeltaGII is false
[vm_1][info 2016/06/19 03:30:11.356 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Initialization of region PdxTypes completed
[vm_1][info 2016/06/19 03:30:11.357 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Recovered disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion with unique id c54d2932cf748f4-8f29a7c57906b158
[vm_1][info 2016/06/19 03:30:11.357 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Recovering oplog#1 /japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1/BACKUP_PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion_1.drf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_1][info 2016/06/19 03:30:11.357 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Recovering oplog#1 /japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1/BACKUP_PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion_1.crf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_1][info 2016/06/19 03:30:11.358 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] recovery oplog load took 1 ms
[vm_1][info 2016/06/19 03:30:11.359 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Created oplog#2 drf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_1][info 2016/06/19 03:30:11.360 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Created oplog#2 crf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_1][info 2016/06/19 03:30:11.361 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] recovery region initialization took 3 ms
[vm_1][info 2016/06/19 03:30:11.361 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Initializing region __PR
[vm_1][info 2016/06/19 03:30:11.362 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Region __PR requesting initial image from japan(15426)<ec><v207>:1025
[vm_1][info 2016/06/19 03:30:11.367 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] __PR is done getting image from japan(15426)<ec><v207>:1025. isDeltaGII is false
[vm_1][info 2016/06/19 03:30:11.367 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Initialization of region __PR completed
[vm_1][info 2016/06/19 03:30:11.370 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Partitioned Region /PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion is created with prId=114
[vm_1][info 2016/06/19 03:30:11.381 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_0> tid=0x13f5] Initializing region _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_0
[vm_1][info 2016/06/19 03:30:11.381 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_1> tid=0x13f6] Initializing region _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_1
[vm_1][info 2016/06/19 03:30:11.381 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_0> tid=0x13f5] Region /__PR/_B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_0 recovered from the local disk. Old persistent ID: /10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1 created at timestamp 1466332189878 version 0 diskStoreId c54d2932cf748f4-8f29a7c57906b158 name null, new persistent ID japan.gemstone.com/10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1 created at timestamp 1466332211361 version 0 diskStoreId c54d2932cf748f4-8f29a7c57906b158 name null
[vm_1][info 2016/06/19 03:30:11.381 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_1> tid=0x13f6] Region /__PR/_B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_1 recovered from the local disk. Old persistent ID: /10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1 created at timestamp 1466332189878 version 0 diskStoreId c54d2932cf748f4-8f29a7c57906b158 name null, new persistent ID japan.gemstone.com/10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1 created at timestamp 1466332211361 version 0 diskStoreId c54d2932cf748f4-8f29a7c57906b158 name null
[vm_1][info 2016/06/19 03:30:11.381 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_2> tid=0x13f7] Initializing region _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_2
[vm_1][info 2016/06/19 03:30:11.382 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_0> tid=0x13f5] Initialization of region _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_0 completed
[vm_1][info 2016/06/19 03:30:11.382 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_2> tid=0x13f7] Region /__PR/_B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_2 recovered from the local disk. Old persistent ID: /10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1 created at timestamp 1466332189878 version 0 diskStoreId c54d2932cf748f4-8f29a7c57906b158 name null, new persistent ID japan.gemstone.com/10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1 created at timestamp 1466332211361 version 0 diskStoreId c54d2932cf748f4-8f29a7c57906b158 name null
[vm_1][info 2016/06/19 03:30:11.382 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_1> tid=0x13f6] Initialization of region _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_1 completed
[vm_1][info 2016/06/19 03:30:11.383 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_2> tid=0x13f7] Initialization of region _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_2 completed
[vm_1][info 2016/06/19 03:30:11.384 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_3> tid=0x13f8] Initializing region _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_3
[vm_1][info 2016/06/19 03:30:11.384 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_3> tid=0x13f8] Region /__PR/_B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_3 recovered from the local disk. Old persistent ID: /10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1 created at timestamp 1466332189878 version 0 diskStoreId c54d2932cf748f4-8f29a7c57906b158 name null, new persistent ID japan.gemstone.com/10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm1/diskDir/disk1 created at timestamp 1466332211361 version 0 diskStoreId c54d2932cf748f4-8f29a7c57906b158 name null
[vm_1][info 2016/06/19 03:30:11.384 PDT <Recovery thread for bucket _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_3> tid=0x13f8] Initialization of region _B__PersistentPartitionedRegionOldConfigDUnitTest__testCrashDuringBucketCreationRegion_3 completed
[vm_0][info 2016/06/19 03:30:11.386 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: null
[vm_0] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$14.run with 0 args on object: "create pr" (took 58 ms)
[vm_1][info 2016/06/19 03:30:11.386 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$14.run with 0 args on object: "create pr" (took 58 ms)
[vm_0][info 2016/06/19 03:30:11.386 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$5.run with 0 args on object: "CheckData"
[vm_0][info 2016/06/19 03:30:11.387 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: null
[vm_0] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$5.run with 0 args on object: "CheckData" (took 0 ms)
[vm_1][info 2016/06/19 03:30:11.387 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$15.call with 0 args on object: "get buckets"
[vm_1][info 2016/06/19 03:30:11.388 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: [0, 1, 2, 3]
[vm_1] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$15.call with 0 args on object: "get buckets" (took 0 ms)
[vm_0][info 2016/06/19 03:30:11.388 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$15.call with 0 args on object: "get buckets"
[vm_0][info 2016/06/19 03:30:11.388 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: []
[vm_0] from com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$15.call with 0 args on object: "get buckets" (took 0 ms)
[vm_0][info 2016/06/19 03:30:11.389 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/872043423.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/872043423@73bc8b0b
[vm_0][info 2016/06/19 03:30:11.389 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] GemFireCache[id = 296441569; isClosing = true; isShutDownAll = false; created = Sun Jun 19 03:30:11 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
[vm_1][info 2016/06/19 03:30:11.393 PDT <PartitionedRegion Message Processor1> tid=0x13d8] The following persistent member has gone offline for region PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion:
[vm_1] DiskStore ID: 8961f2fd-7a9c-4338-a2f5-de4ae9c54c3b
[vm_1] Name:
[vm_1] Location: /10.118.32.37:/japan1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/dunit/vm0/diskDir/disk0
[vm_1]Remaining participating members for the region include:
[vm_1][]
[vm_0][info 2016/06/19 03:30:11.396 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/872043423.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/872043423@73bc8b0b (took 6 ms)
[vm_1][info 2016/06/19 03:30:11.396 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/1562392333.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/1562392333@6ea81110
[vm_1][info 2016/06/19 03:30:11.405 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] GemFireCache[id = 580572484; isClosing = true; isShutDownAll = false; created = Sun Jun 19 03:30:11 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
[vm_1][info 2016/06/19 03:30:11.423 PDT <Idle OplogCompactor> tid=0x13f2] Created oplog#1 krf for disk store _PersistentPartitionedRegionOldConfigDUnitTest_testCrashDuringBucketCreationRegion.
[vm_1][info 2016/06/19 03:30:11.429 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/1562392333.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/1562392333@6ea81110 (took 32 ms)
[vm_2][info 2016/06/19 03:30:11.430 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/2139465429.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/2139465429@65661818
[vm_2][info 2016/06/19 03:30:11.430 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/2139465429.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$10/2139465429@65661818 (took 0 ms)
[vm_3][info 2016/06/19 03:30:11.431 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$5/138441976.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$5/138441976@1af24c46
[vm_3][info 2016/06/19 03:30:11.432 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$5/138441976.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$5/138441976@1af24c46 (took 0 ms)
[vm_0][info 2016/06/19 03:30:11.432 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/662573139.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/662573139@6721fb2
[vm_0][info 2016/06/19 03:30:11.432 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/662573139.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/662573139@6721fb2 (took 0 ms)
[vm_1][info 2016/06/19 03:30:11.433 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/851767686.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/851767686@605095ba
[vm_1][info 2016/06/19 03:30:11.433 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/851767686.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/851767686@605095ba (took 0 ms)
[vm_2][info 2016/06/19 03:30:11.433 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/476052029.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/476052029@4b71a491
[vm_2][info 2016/06/19 03:30:11.434 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/476052029.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$12/476052029@4b71a491 (took 0 ms)
[vm_3][info 2016/06/19 03:30:11.434 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$7/619475100.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$7/619475100@1ff1c03e
[vm_3][info 2016/06/19 03:30:11.434 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$7/619475100.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$7/619475100@1ff1c03e (took 0 ms)
[vm_0][info 2016/06/19 03:30:11.435 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/110025733.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/110025733@51a5a80f
[vm_0][info 2016/06/19 03:30:11.470 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Shutting down DistributionManager japan(15426)<ec><v207>:1025.
[vm_1][info 2016/06/19 03:30:11.483 PDT <Pooled High Priority Message Processor 2> tid=0x13d2] received leave request from japan(15426)<ec><v207>:1025 for japan(15426)<ec><v207>:1025
[locator][info 2016/06/19 03:30:11.483 PDT <Pooled High Priority Message Processor 2> tid=0x9e] received leave request from japan(15426)<ec><v207>:1025 for japan(15426)<ec><v207>:1025
[locator][info 2016/06/19 03:30:11.483 PDT <Pooled High Priority Message Processor 2> tid=0x9e] Member at japan(15426)<ec><v207>:1025 gracefully left the distributed cache: shutdown message received
[vm_1][info 2016/06/19 03:30:11.483 PDT <Pooled High Priority Message Processor 2> tid=0x13d2] Member at japan(15426)<ec><v207>:1025 gracefully left the distributed cache: shutdown message received
[vm_0][info 2016/06/19 03:30:11.583 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Now closing distribution for japan(15426)<ec><v207>:1025
[vm_0][info 2016/06/19 03:30:11.584 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Stopping membership services
[vm_0][info 2016/06/19 03:30:11.584 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] GMSHealthMonitor server socket is closed in stopServices().
[vm_1][info 2016/06/19 03:30:11.584 PDT <unicast receiver,japan-3404> tid=0x13ba] received leave request from japan(15426)<ec><v207>:1025 for japan(15426)<ec><v207>:1025
[vm_0][info 2016/06/19 03:30:11.584 PDT <Geode Failure Detection Server thread 0> tid=0x14ef] GMSHealthMonitor server thread exiting
[vm_0][info 2016/06/19 03:30:11.584 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] GMSHealthMonitor serverSocketExecutor is terminated
[locator][info 2016/06/19 03:30:11.584 PDT <unicast receiver,japan-1492> tid=0x22] received leave request from japan(15426)<ec><v207>:1025 for japan(15426)<ec><v207>:1025
[vm_0][info 2016/06/19 03:30:11.586 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] DistributionManager stopped in 116ms.
[vm_0][info 2016/06/19 03:30:11.586 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Marking DistributionManager japan(15426)<ec><v207>:1025 as closed.
[vm_0][info 2016/06/19 03:30:11.586 PDT <RMI TCP Connection(13)-10.118.32.37> tid=0x12] Got result: null
[vm_0] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/110025733.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/110025733@51a5a80f (took 151 ms)
[vm_1][info 2016/06/19 03:30:11.587 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/1981200343.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/1981200343@63cb3052
[vm_1][info 2016/06/19 03:30:11.588 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Shutting down DistributionManager japan(15430)<ec><v205>:1026.
[locator][info 2016/06/19 03:30:11.588 PDT <Pooled High Priority Message Processor 2> tid=0x9e] received leave request from japan(15430)<ec><v205>:1026 for japan(15430)<ec><v205>:1026
[locator][info 2016/06/19 03:30:11.588 PDT <Pooled High Priority Message Processor 2> tid=0x9e] Member at japan(15430)<ec><v205>:1026 gracefully left the distributed cache: shutdown message received
[vm_1][info 2016/06/19 03:30:11.688 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Now closing distribution for japan(15430)<ec><v205>:1026
[vm_1][info 2016/06/19 03:30:11.688 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Stopping membership services
[vm_1][info 2016/06/19 03:30:11.689 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] GMSHealthMonitor server socket is closed in stopServices().
[locator][info 2016/06/19 03:30:11.689 PDT <unicast receiver,japan-1492> tid=0x22] received leave request from japan(15430)<ec><v205>:1026 for japan(15430)<ec><v205>:1026
[vm_1][info 2016/06/19 03:30:11.689 PDT <Geode Failure Detection Server thread 0> tid=0x13be] GMSHealthMonitor server thread exiting
[vm_1][info 2016/06/19 03:30:11.689 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] GMSHealthMonitor serverSocketExecutor is terminated
[vm_1][info 2016/06/19 03:30:11.691 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] DistributionManager stopped in 103ms.
[vm_1][info 2016/06/19 03:30:11.691 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Marking DistributionManager japan(15430)<ec><v205>:1026 as closed.
[vm_1][info 2016/06/19 03:30:11.691 PDT <RMI TCP Connection(5)-10.118.32.37> tid=0x12] Got result: null
[vm_1] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/1981200343.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/1981200343@63cb3052 (took 103 ms)
[vm_2][info 2016/06/19 03:30:11.691 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/1677849455.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/1677849455@76c73c0
[vm_2][info 2016/06/19 03:30:11.691 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Got result: null
[vm_2] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/1677849455.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$13/1677849455@76c73c0 (took 0 ms)
[vm_3][info 2016/06/19 03:30:11.692 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$8/1570987636.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$8/1570987636@1a0cadcc
[vm_3][info 2016/06/19 03:30:11.692 PDT <RMI TCP Connection(12)-10.118.32.37> tid=0x12] Got result: null
[vm_3] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$8/1570987636.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$8/1570987636@1a0cadcc (took 0 ms)
[locator][info 2016/06/19 03:30:11.693 PDT <RMI TCP Connection(4)-10.118.32.37> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/1259248680.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/1259248680@115c4ab7
[locator][info 2016/06/19 03:30:11.693 PDT <RMI TCP Connection(4)-10.118.32.37> tid=0x12] Got result: null
[locator] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/1259248680.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/1259248680@115c4ab7 (took 0 ms)
Standard Error
Cache was closed on integer 353
Eclipse integration is not enabled. Help us localize this page Page generated: Jun 22, 2016 9:48:56 AM PDTREST APIJenkins ver. 1.646
Enable Notifications
> CI failure: PersistentPartitionedRegionOldConfigDUnitTest.testCleanStop
> -----------------------------------------------------------------------
>
> Key: GEODE-1582
> URL: https://issues.apache.org/jira/browse/GEODE-1582
> Project: Geode
> Issue Type: Bug
> Components: persistence
> Reporter: Hitesh Khamesra
> Labels: CI
>
> https://brazil.gemstone.com:8080//job/Geode_develop_DistributedTests/2963/testReport/com.gemstone.gemfire.internal.cache.partitioned/PersistentPartitionedRegionOldConfigDUnitTest/testCleanStop
> com.gemstone.gemfire.test.dunit.RMIException: While invoking com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$1.run in VM 1 running on Host japan.gemstone.com with 4 VMs
> Stacktrace
> com.gemstone.gemfire.test.dunit.RMIException: While invoking com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$1.run in VM 1 running on Host japan.gemstone.com with 4 VMs
> at com.gemstone.gemfire.test.dunit.VM.invoke(VM.java:389)
> at com.gemstone.gemfire.test.dunit.VM.invoke(VM.java:355)
> at com.gemstone.gemfire.test.dunit.VM.invoke(VM.java:293)
> at com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase.checkRecoveredFromDisk(PersistentPartitionedRegionTestBase.java:100)
> at com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionDUnitTest.testCleanStop(PersistentPartitionedRegionDUnitTest.java:1353)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
> at org.junit.rules.RunRules.evaluate(RunRules.java:20)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:112)
> at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:56)
> at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:66)
> at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
> at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
> at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
> at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
> at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:109)
> at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
> at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54)
> at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: java.lang.AssertionError: expected:<0> but was:<1>
> at org.junit.Assert.fail(Assert.java:88)
> at org.junit.Assert.failNotEquals(Assert.java:834)
> at org.junit.Assert.assertEquals(Assert.java:645)
> at org.junit.Assert.assertEquals(Assert.java:631)
> at com.gemstone.gemfire.internal.cache.partitioned.PersistentPartitionedRegionTestBase$1.run(PersistentPartitionedRegionTestBase.java:106)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at hydra.MethExecutor.executeObject(MethExecutor.java:268)
> at com.gemstone.gemfire.test.dunit.standalone.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:82)
> at sun.reflect.GeneratedMethodAccessor157.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:323)
> at sun.rmi.transport.Transport$1.run(Transport.java:200)
> at sun.rmi.transport.Transport$1.run(Transport.java:197)
> at java.security.AccessController.doPrivileged(Native Method)
> at sun.rmi.transport.Transport.serviceCall(Transport.java:196)
> at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)
> at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
> at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$95(TCPTransport.java:683)
> at java.security.AccessController.doPrivileged(Native Method)
> at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
> ... 3 more
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)