geode-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Bruce Schuchardt (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (GEODE-1711) PersistentRVVRecoveryDUnitTest.testWriteCorrectVersionToKrf
Date Tue, 02 Aug 2016 15:31:20 GMT

     [ https://issues.apache.org/jira/browse/GEODE-1711?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Bruce Schuchardt updated GEODE-1711:
------------------------------------
    Component/s: persistence

> PersistentRVVRecoveryDUnitTest.testWriteCorrectVersionToKrf
> -----------------------------------------------------------
>
>                 Key: GEODE-1711
>                 URL: https://issues.apache.org/jira/browse/GEODE-1711
>             Project: Geode
>          Issue Type: Bug
>          Components: persistence
>            Reporter: Kevin Duling
>              Labels: CI
>
> In Geode_develop_DistributedTests/3421:
> {noformat}
> Error Message
> com.gemstone.gemfire.cache.DiskAccessException: For DiskStore: PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion: Could not schedule asynchronous write because the flusher thread had been terminated.
> Stacktrace
> com.gemstone.gemfire.cache.DiskAccessException: For DiskStore: PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion: Could not schedule asynchronous write because the flusher thread had been terminated.
> 	at com.gemstone.gemfire.internal.cache.DiskStoreImpl.checkForFlusherThreadTermination(DiskStoreImpl.java:1223)
> 	at com.gemstone.gemfire.internal.cache.DiskStoreImpl.addAsyncItem(DiskStoreImpl.java:1271)
> 	at com.gemstone.gemfire.internal.cache.DiskStoreImpl.scheduleAsyncWrite(DiskStoreImpl.java:1335)
> 	at com.gemstone.gemfire.internal.cache.DiskRegion.scheduleAsyncWrite(DiskRegion.java:483)
> 	at com.gemstone.gemfire.internal.cache.DiskEntry$Helper.scheduleAsyncWrite(DiskEntry.java:1494)
> 	at com.gemstone.gemfire.internal.cache.DiskEntry$Helper.update(DiskEntry.java:1034)
> 	at com.gemstone.gemfire.internal.cache.AbstractDiskRegionEntry.setValue(AbstractDiskRegionEntry.java:42)
> 	at com.gemstone.gemfire.internal.cache.AbstractRegionEntry.setValueWithTombstoneCheck(AbstractRegionEntry.java:241)
> 	at com.gemstone.gemfire.internal.cache.EntryEventImpl.setNewValueInRegion(EntryEventImpl.java:1614)
> 	at com.gemstone.gemfire.internal.cache.EntryEventImpl.putExistingEntry(EntryEventImpl.java:1482)
> 	at com.gemstone.gemfire.internal.cache.AbstractRegionMap.updateEntry(AbstractRegionMap.java:2882)
> 	at com.gemstone.gemfire.internal.cache.AbstractRegionMap.basicPut(AbstractRegionMap.java:2713)
> 	at com.gemstone.gemfire.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5955)
> 	at com.gemstone.gemfire.internal.cache.DistributedRegion.virtualPut(DistributedRegion.java:348)
> 	at com.gemstone.gemfire.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:132)
> 	at com.gemstone.gemfire.internal.cache.LocalRegion.basicPut(LocalRegion.java:5350)
> 	at com.gemstone.gemfire.internal.cache.LocalRegion.validatedPut(LocalRegion.java:1668)
> 	at com.gemstone.gemfire.internal.cache.LocalRegion.put(LocalRegion.java:1655)
> 	at com.gemstone.gemfire.internal.cache.AbstractRegion.put(AbstractRegion.java:288)
> 	at com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest.testWriteCorrectVersionToKrf(PersistentRVVRecoveryDUnitTest.java:824)
> 	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.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.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.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.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)
> Standard Output
> Previously run tests: [PersistentRecoveryOrderDUnitTest, PersistentRVVRecoveryDUnitTest]
> [vm_0][info 2016/07/27 08:22:42.569 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
> [vm_0][info 2016/07/27 08:22:42.570 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] 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/07/27 08:22:42.571 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
> [vm_1][info 2016/07/27 08:22:42.571 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] 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/07/27 08:22:42.573 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
> [vm_2][info 2016/07/27 08:22:42.573 PDT <RMI TCP Connection(13)-10.118.32.90> 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)
> [setup] START TEST PersistentRVVRecoveryDUnitTest.testNoConcurrencyChecks
> [vm_3][info 2016/07/27 08:22:42.576 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
> [vm_3][info 2016/07/27 08:22:42.576 PDT <RMI TCP Connection(13)-10.118.32.90> 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)
> [vm_0][info 2016/07/27 08:22:42.576 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args
> [vm_0][info 2016/07/27 08:22:42.576 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args (took 0 ms)
> [vm_1][info 2016/07/27 08:22:42.577 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args
> [vm_1][info 2016/07/27 08:22:42.577 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args (took 0 ms)
> [vm_2][info 2016/07/27 08:22:42.577 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args
> [vm_2][info 2016/07/27 08:22:42.578 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args (took 0 ms)
> [vm_3][info 2016/07/27 08:22:42.578 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args
> [vm_3][info 2016/07/27 08:22:42.578 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args (took 0 ms)
> distributed system properties: {locators=localhost[52265], enable-cluster-configuration=false, use-cluster-configuration=false, mcast-port=0, disable-auto-reconnect=true, log-level=info}
> [locator][info 2016/07/27 08:22:42.653 PDT <Geode Membership View Creator> tid=0x27] View Creator is processing 4 requests for the next membership view
> [locator][info 2016/07/27 08:22:42.653 PDT <Geode Membership View Creator> tid=0x27] received new view: View[venezuela(12353:locator)<ec><v0>:1025|62] members: [venezuela(12353:locator)<ec><v0>:1025]  shutdown: [venezuela(12418)<ec><v61>:1028, venezuela(12414)<ec><v58>:1026]
> [locator]old view is: View[venezuela(12353:locator)<ec><v0>:1025|61] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12414)<ec><v58>:1026{lead}, venezuela(12418)<ec><v61>:1028]
> [locator][info 2016/07/27 08:22:42.653 PDT <Geode Membership View Creator> tid=0x27] Peer locator received new membership view: View[venezuela(12353:locator)<ec><v0>:1025|62] members: [venezuela(12353:locator)<ec><v0>:1025]  shutdown: [venezuela(12418)<ec><v61>:1028, venezuela(12414)<ec><v58>:1026]
> [locator][info 2016/07/27 08:22:42.653 PDT <Geode Membership View Creator> tid=0x27] no recipients for new view aside from myself
> [info 2016/07/27 08:22:42.839 PDT <Test worker> tid=0xa] Startup Configuration:
>  ### GemFire Properties defined with api ###
> disable-auto-reconnect=true
> enable-cluster-configuration=false
> locators=localhost[52265]
> log-level=info
> mcast-port=0
> use-cluster-configuration=false
> ### GemFire Properties using default values ###
> ack-severe-alert-threshold=0
> ack-wait-threshold=15
> archive-disk-space-limit=0
> archive-file-size-limit=0
> async-distribution-timeout=0
> async-max-queue-size=8
> async-queue-timeout=60000
> bind-address=
> cache-xml-file=cache.xml
> cluster-configuration-dir=
> cluster-ssl-ciphers=any
> cluster-ssl-enabled=false
> cluster-ssl-keystore=
> cluster-ssl-keystore-password=
> cluster-ssl-keystore-type=
> cluster-ssl-protocols=any
> cluster-ssl-require-authentication=true
> cluster-ssl-truststore=
> cluster-ssl-truststore-password=
> conflate-events=server
> conserve-sockets=true
> delta-propagation=true
> deploy-working-dir=.
> disable-tcp=false
> distributed-system-id=-1
> distributed-transactions=false
> durable-client-id=
> durable-client-timeout=300
> enable-network-partition-detection=false
> enable-time-statistics=false
> enforce-unique-host=false
> gateway-ssl-ciphers=any
> gateway-ssl-enabled=false
> gateway-ssl-keystore=
> gateway-ssl-keystore-password=
> gateway-ssl-keystore-type=
> gateway-ssl-protocols=any
> gateway-ssl-require-authentication=true
> gateway-ssl-truststore=
> gateway-ssl-truststore-password=
> groups=
> http-service-bind-address=
> http-service-port=7070
> http-service-ssl-ciphers=any
> http-service-ssl-enabled=false
> http-service-ssl-keystore=
> http-service-ssl-keystore-password=
> http-service-ssl-keystore-type=
> http-service-ssl-protocols=any
> http-service-ssl-require-authentication=false
> http-service-ssl-truststore=
> http-service-ssl-truststore-password=
> jmx-manager=false
> jmx-manager-access-file=
> jmx-manager-bind-address=
> jmx-manager-hostname-for-clients=
> jmx-manager-http-port=7070
> jmx-manager-password-file=
> jmx-manager-port=1099
> jmx-manager-ssl=false
> jmx-manager-ssl-ciphers=any
> jmx-manager-ssl-enabled=false
> jmx-manager-ssl-keystore=
> jmx-manager-ssl-keystore-password=
> jmx-manager-ssl-keystore-type=
> jmx-manager-ssl-protocols=any
> jmx-manager-ssl-require-authentication=true
> jmx-manager-ssl-truststore=
> jmx-manager-ssl-truststore-password=
> jmx-manager-start=false
> jmx-manager-update-rate=2000
> load-cluster-configuration-from-dir=false
> locator-wait-time=0
> lock-memory=false
> log-disk-space-limit=0
> log-file=
> log-file-size-limit=0
> max-num-reconnect-tries=3
> max-wait-time-reconnect=60000
> mcast-address=239.192.81.1
> mcast-flow-control=1048576, 0.25, 5000
> mcast-recv-buffer-size=1048576
> mcast-send-buffer-size=65535
> mcast-ttl=32
> member-timeout=5000
> membership-port-range=1024-65535
> memcached-bind-address=
> memcached-port=0
> memcached-protocol=ASCII
> name=
> off-heap-memory-size=
> redis-bind-address=
> redis-password=
> redis-port=0
> redundancy-zone=
> remote-locators=
> remove-unresponsive-client=false
> roles=
> security-client-accessor=
> security-client-accessor-pp=
> security-client-auth-init=
> security-client-authenticator=
> security-client-dhalgo=
> security-log-file=
> security-log-level=config
> security-manager=
> security-peer-auth-init=
> security-peer-authenticator=
> security-peer-verifymember-timeout=1000
> security-post-processor=
> server-bind-address=
> server-ssl-ciphers=any
> server-ssl-enabled=false
> server-ssl-keystore=
> server-ssl-keystore-password=
> server-ssl-keystore-type=
> server-ssl-protocols=any
> server-ssl-require-authentication=true
> server-ssl-truststore=
> server-ssl-truststore-password=
> socket-buffer-size=32768
> socket-lease-time=60000
> ssl-ciphers=any
> ssl-enabled=false
> ssl-protocols=any
> ssl-require-authentication=true
> start-dev-rest-api=false
> start-locator=
> statistic-archive-file=
> statistic-sample-rate=1000
> statistic-sampling-enabled=true
> tcp-port=0
> udp-fragment-size=60000
> udp-recv-buffer-size=1048576
> udp-send-buffer-size=65535
> user-command-packages=
> [info 2016/07/27 08:22:43.008 PDT <Test worker> tid=0xa] Starting membership services
> [info 2016/07/27 08:22:43.101 PDT <Test worker> tid=0xa] JGroups channel created (took 92ms)
> [info 2016/07/27 08:22:43.108 PDT <Test worker> tid=0xa] GemFire P2P Listener started on  null
> [info 2016/07/27 08:22:43.110 PDT <Geode Failure Detection Server thread 0> tid=0xa2] Started failure detection server thread on venezuela.gemstone.com/10.118.32.90:30225.
> [info 2016/07/27 08:22:43.122 PDT <Test worker> tid=0xa] Attempting to join the distributed system through coordinator venezuela(12353:locator)<ec><v0>:1025 using address venezuela(12321)<ec>:1026
> [locator][info 2016/07/27 08:22:43.131 PDT <unicast receiver,venezuela-31226> tid=0x21] received join request from venezuela(12321)<ec>:1026
> [locator][info 2016/07/27 08:22:43.437 PDT <Geode Membership View Creator> tid=0x27] View Creator is processing 1 requests for the next membership view
> [locator][info 2016/07/27 08:22:43.437 PDT <Geode Membership View Creator> tid=0x27] preparing new view View[venezuela(12353:locator)<ec><v0>:1025|63] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v63>:1026{lead}]
> [locator]failure detection ports: 45258 30225
> [locator][info 2016/07/27 08:22:43.441 PDT <Geode Membership View Creator> tid=0x27] finished waiting for responses to view preparation
> [locator][info 2016/07/27 08:22:43.441 PDT <Geode Membership View Creator> tid=0x27] received new view: View[venezuela(12353:locator)<ec><v0>:1025|63] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v63>:1026{lead}]
> [locator]old view is: View[venezuela(12353:locator)<ec><v0>:1025|62] members: [venezuela(12353:locator)<ec><v0>:1025]  shutdown: [venezuela(12418)<ec><v61>:1028, venezuela(12414)<ec><v58>:1026]
> [locator][info 2016/07/27 08:22:43.441 PDT <Geode Membership View Creator> tid=0x27] Peer locator received new membership view: View[venezuela(12353:locator)<ec><v0>:1025|63] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v63>:1026{lead}]
> [locator][info 2016/07/27 08:22:43.442 PDT <Geode Membership View Creator> tid=0x27] sending new view View[venezuela(12353:locator)<ec><v0>:1025|63] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v63>:1026{lead}]
> [locator]failure detection ports: 45258 30225
> [locator][info 2016/07/27 08:22:43.442 PDT <View Message Processor> tid=0x33] Membership: Processing addition < venezuela(12321)<ec><v63>:1026 >
> [locator][info 2016/07/27 08:22:43.442 PDT <View Message Processor> tid=0x33] Admitting member <venezuela(12321)<ec><v63>:1026>. Now there are 2 non-admin member(s).
> [info 2016/07/27 08:22:43.442 PDT <unicast receiver,venezuela-6806> tid=0x9e] received new view: View[venezuela(12353:locator)<ec><v0>:1025|63] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v63>:1026{lead}]
> old view is: null
> [info 2016/07/27 08:22:43.445 PDT <Test worker> tid=0xa] Finished joining (took 334ms).
> [info 2016/07/27 08:22:43.446 PDT <Test worker> tid=0xa] Starting DistributionManager venezuela(12321)<ec><v63>:1026.  (took 562 ms)
> [info 2016/07/27 08:22:43.447 PDT <Test worker> tid=0xa] Initial (distribution manager) view =  View[venezuela(12353:locator)<ec><v0>:1025|63] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v63>:1026{lead}]
> [info 2016/07/27 08:22:43.447 PDT <Test worker> tid=0xa] Admitting member <venezuela(12353:locator)<ec><v0>:1025>. Now there are 1 non-admin member(s).
> [info 2016/07/27 08:22:43.448 PDT <Test worker> tid=0xa] Admitting member <venezuela(12321)<ec><v63>:1026>. Now there are 2 non-admin member(s).
> [locator][info 2016/07/27 08:22:43.468 PDT <Pooled High Priority Message Processor 2> tid=0x47] Member venezuela(12321)<ec><v63>:1026 is equivalent or in the same redundancy zone.
> [info 2016/07/27 08:22:43.475 PDT <P2P message reader for venezuela(12353:locator)<ec><v0>:1025 shared unordered uid=54 port=54835> tid=0xa7] Member venezuela(12353:locator)<ec><v0>:1025 is equivalent or in the same redundancy zone.
> [info 2016/07/27 08:22:43.684 PDT <Test worker> tid=0xa] Initializing region _monitoringRegion_10.118.32.90<v63>1026
> [info 2016/07/27 08:22:43.691 PDT <Test worker> tid=0xa] Initialization of region _monitoringRegion_10.118.32.90<v63>1026 completed
> [info 2016/07/27 08:22:43.913 PDT <Test worker> tid=0xa] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
> [info 2016/07/27 08:22:43.926 PDT <Test worker> tid=0xa] Initializing region PdxTypes
> [info 2016/07/27 08:22:43.928 PDT <Test worker> tid=0xa] Initialization of region PdxTypes completed
> [info 2016/07/27 08:22:43.952 PDT <Test worker> tid=0xa] GemFireCache[id = 923031962; isClosing = true; isShutDownAll = false; created = Wed Jul 27 08:22:43 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_0][info 2016/07/27 08:22:43.989 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/72500195.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/72500195@310e441b
> [vm_0][info 2016/07/27 08:22:43.989 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/72500195.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/72500195@310e441b (took 0 ms)
> [vm_1][info 2016/07/27 08:22:43.990 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$8/949738456.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$8/949738456@72df2354
> [vm_1][info 2016/07/27 08:22:43.990 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Got result: null
> [vm_1] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$8/949738456.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$8/949738456@72df2354 (took 0 ms)
> [vm_2][info 2016/07/27 08:22:43.991 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/1504845286.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/1504845286@17d31ca3
> [vm_2][info 2016/07/27 08:22:43.991 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/1504845286.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/1504845286@17d31ca3 (took 0 ms)
> [vm_3][info 2016/07/27 08:22:43.992 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/640281163.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/640281163@2e3019b0
> [vm_3][info 2016/07/27 08:22:43.992 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/640281163.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/640281163@2e3019b0 (took 0 ms)
> [vm_0][info 2016/07/27 08:22:43.992 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args
> [vm_0][info 2016/07/27 08:22:43.993 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args (took 0 ms)
> [vm_1][info 2016/07/27 08:22:43.993 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args
> [vm_1][info 2016/07/27 08:22:43.993 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args (took 0 ms)
> [vm_2][info 2016/07/27 08:22:43.993 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args
> [vm_2][info 2016/07/27 08:22:43.994 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args (took 0 ms)
> [vm_3][info 2016/07/27 08:22:43.994 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args
> [vm_3][info 2016/07/27 08:22:43.994 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args (took 0 ms)
> [vm_0][info 2016/07/27 08:22:43.995 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_0][info 2016/07/27 08:22:43.995 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator) (took 0 ms)
> [vm_1][info 2016/07/27 08:22:43.995 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_1][info 2016/07/27 08:22:43.995 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Got result: null
> [vm_1] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator) (took 0 ms)
> [vm_2][info 2016/07/27 08:22:43.996 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_2][info 2016/07/27 08:22:43.996 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator) (took 0 ms)
> [vm_3][info 2016/07/27 08:22:43.996 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_3][info 2016/07/27 08:22:43.996 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator) (took 0 ms)
> [info 2016/07/27 08:22:44.000 PDT <Test worker> tid=0xa] Shutting down DistributionManager venezuela(12321)<ec><v63>:1026. 
> [locator][info 2016/07/27 08:22:44.002 PDT <Pooled High Priority Message Processor 2> tid=0x47] received leave request from venezuela(12321)<ec><v63>:1026 for venezuela(12321)<ec><v63>:1026
> [locator][info 2016/07/27 08:22:44.002 PDT <Pooled High Priority Message Processor 2> tid=0x47] Member at venezuela(12321)<ec><v63>:1026 gracefully left the distributed cache: shutdown message received
> [info 2016/07/27 08:22:44.104 PDT <Test worker> tid=0xa] Now closing distribution for venezuela(12321)<ec><v63>:1026
> [info 2016/07/27 08:22:44.104 PDT <Test worker> tid=0xa] Stopping membership services
> [locator][info 2016/07/27 08:22:44.106 PDT <unicast receiver,venezuela-31226> tid=0x21] received leave request from venezuela(12321)<ec><v63>:1026 for venezuela(12321)<ec><v63>:1026
> [info 2016/07/27 08:22:44.107 PDT <Test worker> tid=0xa] GMSHealthMonitor server socket is closed in stopServices().
> [info 2016/07/27 08:22:44.108 PDT <Geode Failure Detection Server thread 0> tid=0xa2] GMSHealthMonitor server thread exiting
> [info 2016/07/27 08:22:44.108 PDT <Test worker> tid=0xa] GMSHealthMonitor serverSocketExecutor is terminated
> [info 2016/07/27 08:22:44.114 PDT <Test worker> tid=0xa] DistributionManager stopped in 114ms.
> [info 2016/07/27 08:22:44.114 PDT <Test worker> tid=0xa] Marking DistributionManager venezuela(12321)<ec><v63>:1026 as closed.
> [vm_1][info 2016/07/27 08:22:44.117 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM)
> [vm_1][info 2016/07/27 08:22:44.117 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Got result: null
> [vm_1] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM) (took 0 ms)
> [vm_0][info 2016/07/27 08:22:44.117 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM)
> [vm_0][info 2016/07/27 08:22:44.117 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM) (took 0 ms)
> [vm_2][info 2016/07/27 08:22:44.119 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM)
> [vm_2][info 2016/07/27 08:22:44.119 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM) (took 0 ms)
> [vm_3][info 2016/07/27 08:22:44.120 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM)
> [vm_3][info 2016/07/27 08:22:44.120 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM) (took 0 ms)
> [locator][info 2016/07/27 08:22:44.121 PDT <RMI TCP Connection(2)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/609302019.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/609302019@658426d0
> [locator][info 2016/07/27 08:22:44.121 PDT <RMI TCP Connection(2)-10.118.32.90> tid=0x12] Got result: null
> [locator] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/609302019.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/609302019@658426d0 (took 0 ms)
> Previously run tests: [PersistentRecoveryOrderDUnitTest, PersistentRVVRecoveryDUnitTest]
> [vm_0][info 2016/07/27 08:22:44.125 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
> [vm_0][info 2016/07/27 08:22:44.126 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] 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/07/27 08:22:44.129 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
> [vm_1][info 2016/07/27 08:22:44.129 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] 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/07/27 08:22:44.130 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
> [vm_2][info 2016/07/27 08:22:44.130 PDT <RMI TCP Connection(13)-10.118.32.90> 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/07/27 08:22:44.130 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(setupVM)
> [vm_3][info 2016/07/27 08:22:44.131 PDT <RMI TCP Connection(13)-10.118.32.90> 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 PersistentRVVRecoveryDUnitTest.testWriteCorrectVersionToKrf
> [vm_0][info 2016/07/27 08:22:44.132 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args
> [vm_0][info 2016/07/27 08:22:44.132 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args (took 0 ms)
> [vm_1][info 2016/07/27 08:22:44.133 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args
> [vm_1][info 2016/07/27 08:22:44.133 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args (took 0 ms)
> [vm_2][info 2016/07/27 08:22:44.133 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args
> [vm_2][info 2016/07/27 08:22:44.134 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args (took 0 ms)
> distributed system properties: {locators=localhost[52265], enable-cluster-configuration=false, use-cluster-configuration=false, mcast-port=0, disable-auto-reconnect=true, log-level=info}
> [vm_3][info 2016/07/27 08:22:44.135 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args
> [vm_3][info 2016/07/27 08:22:44.135 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase.setRegionName with 1 args (took 0 ms)
> [info 2016/07/27 08:22:44.139 PDT <Test worker> tid=0xa] Startup Configuration:
>  ### GemFire Properties defined with api ###
> disable-auto-reconnect=true
> enable-cluster-configuration=false
> locators=localhost[52265]
> log-level=info
> mcast-port=0
> use-cluster-configuration=false
> ### GemFire Properties using default values ###
> ack-severe-alert-threshold=0
> ack-wait-threshold=15
> archive-disk-space-limit=0
> archive-file-size-limit=0
> async-distribution-timeout=0
> async-max-queue-size=8
> async-queue-timeout=60000
> bind-address=
> cache-xml-file=cache.xml
> cluster-configuration-dir=
> cluster-ssl-ciphers=any
> cluster-ssl-enabled=false
> cluster-ssl-keystore=
> cluster-ssl-keystore-password=
> cluster-ssl-keystore-type=
> cluster-ssl-protocols=any
> cluster-ssl-require-authentication=true
> cluster-ssl-truststore=
> cluster-ssl-truststore-password=
> conflate-events=server
> conserve-sockets=true
> delta-propagation=true
> deploy-working-dir=.
> disable-tcp=false
> distributed-system-id=-1
> distributed-transactions=false
> durable-client-id=
> durable-client-timeout=300
> enable-network-partition-detection=false
> enable-time-statistics=false
> enforce-unique-host=false
> gateway-ssl-ciphers=any
> gateway-ssl-enabled=false
> gateway-ssl-keystore=
> gateway-ssl-keystore-password=
> gateway-ssl-keystore-type=
> gateway-ssl-protocols=any
> gateway-ssl-require-authentication=true
> gateway-ssl-truststore=
> gateway-ssl-truststore-password=
> groups=
> http-service-bind-address=
> http-service-port=7070
> http-service-ssl-ciphers=any
> http-service-ssl-enabled=false
> http-service-ssl-keystore=
> http-service-ssl-keystore-password=
> http-service-ssl-keystore-type=
> http-service-ssl-protocols=any
> http-service-ssl-require-authentication=false
> http-service-ssl-truststore=
> http-service-ssl-truststore-password=
> jmx-manager=false
> jmx-manager-access-file=
> jmx-manager-bind-address=
> jmx-manager-hostname-for-clients=
> jmx-manager-http-port=7070
> jmx-manager-password-file=
> jmx-manager-port=1099
> jmx-manager-ssl=false
> jmx-manager-ssl-ciphers=any
> jmx-manager-ssl-enabled=false
> jmx-manager-ssl-keystore=
> jmx-manager-ssl-keystore-password=
> jmx-manager-ssl-keystore-type=
> jmx-manager-ssl-protocols=any
> jmx-manager-ssl-require-authentication=true
> jmx-manager-ssl-truststore=
> jmx-manager-ssl-truststore-password=
> jmx-manager-start=false
> jmx-manager-update-rate=2000
> load-cluster-configuration-from-dir=false
> locator-wait-time=0
> lock-memory=false
> log-disk-space-limit=0
> log-file=
> log-file-size-limit=0
> max-num-reconnect-tries=3
> max-wait-time-reconnect=60000
> mcast-address=239.192.81.1
> mcast-flow-control=1048576, 0.25, 5000
> mcast-recv-buffer-size=1048576
> mcast-send-buffer-size=65535
> mcast-ttl=32
> member-timeout=5000
> membership-port-range=1024-65535
> memcached-bind-address=
> memcached-port=0
> memcached-protocol=ASCII
> name=
> off-heap-memory-size=
> redis-bind-address=
> redis-password=
> redis-port=0
> redundancy-zone=
> remote-locators=
> remove-unresponsive-client=false
> roles=
> security-client-accessor=
> security-client-accessor-pp=
> security-client-auth-init=
> security-client-authenticator=
> security-client-dhalgo=
> security-log-file=
> security-log-level=config
> security-manager=
> security-peer-auth-init=
> security-peer-authenticator=
> security-peer-verifymember-timeout=1000
> security-post-processor=
> server-bind-address=
> server-ssl-ciphers=any
> server-ssl-enabled=false
> server-ssl-keystore=
> server-ssl-keystore-password=
> server-ssl-keystore-type=
> server-ssl-protocols=any
> server-ssl-require-authentication=true
> server-ssl-truststore=
> server-ssl-truststore-password=
> socket-buffer-size=32768
> socket-lease-time=60000
> ssl-ciphers=any
> ssl-enabled=false
> ssl-protocols=any
> ssl-require-authentication=true
> start-dev-rest-api=false
> start-locator=
> statistic-archive-file=
> statistic-sample-rate=1000
> statistic-sampling-enabled=true
> tcp-port=0
> udp-fragment-size=60000
> udp-recv-buffer-size=1048576
> udp-send-buffer-size=65535
> user-command-packages=
> [info 2016/07/27 08:22:44.141 PDT <Test worker> tid=0xa] Starting membership services
> [info 2016/07/27 08:22:44.150 PDT <Test worker> tid=0xa] JGroups channel created (took 9ms)
> [info 2016/07/27 08:22:44.151 PDT <Test worker> tid=0xa] GemFire P2P Listener started on  null
> [info 2016/07/27 08:22:44.152 PDT <Geode Failure Detection Server thread 0> tid=0xca] Started failure detection server thread on venezuela.gemstone.com/10.118.32.90:47292.
> [info 2016/07/27 08:22:44.153 PDT <Test worker> tid=0xa] Attempting to join the distributed system through coordinator venezuela(12353:locator)<ec><v0>:1025 using address venezuela(12321)<ec>:1026
> [locator][info 2016/07/27 08:22:44.154 PDT <unicast receiver,venezuela-31226> tid=0x21] received join request from venezuela(12321)<ec>:1026
> [locator][info 2016/07/27 08:22:44.357 PDT <Geode Membership View Creator> tid=0x27] View Creator is processing 3 requests for the next membership view
> [locator][info 2016/07/27 08:22:44.358 PDT <Geode Membership View Creator> tid=0x27] preparing new view View[venezuela(12353:locator)<ec><v0>:1025|64] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v64>:1026{lead}]  shutdown: [venezuela(12321)<ec><v63>:1026]
> [locator]failure detection ports: 45258 47292
> [locator][info 2016/07/27 08:22:44.359 PDT <Geode Membership View Creator> tid=0x27] finished waiting for responses to view preparation
> [locator][info 2016/07/27 08:22:44.359 PDT <Geode Membership View Creator> tid=0x27] received new view: View[venezuela(12353:locator)<ec><v0>:1025|64] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v64>:1026{lead}]  shutdown: [venezuela(12321)<ec><v63>:1026]
> [locator]old view is: View[venezuela(12353:locator)<ec><v0>:1025|63] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v63>:1026{lead}]
> [locator][info 2016/07/27 08:22:44.359 PDT <Geode Membership View Creator> tid=0x27] Peer locator received new membership view: View[venezuela(12353:locator)<ec><v0>:1025|64] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v64>:1026{lead}]  shutdown: [venezuela(12321)<ec><v63>:1026]
> [info 2016/07/27 08:22:44.359 PDT <unicast receiver,venezuela-23921> tid=0xc6] received new view: View[venezuela(12353:locator)<ec><v0>:1025|64] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v64>:1026{lead}]  shutdown: [venezuela(12321)<ec><v63>:1026]
> old view is: null
> [locator][info 2016/07/27 08:22:44.360 PDT <Geode Membership View Creator> tid=0x27] sending new view View[venezuela(12353:locator)<ec><v0>:1025|64] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v64>:1026{lead}]  shutdown: [venezuela(12321)<ec><v63>:1026]
> [locator]failure detection ports: 45258 47292
> [locator][info 2016/07/27 08:22:44.360 PDT <View Message Processor> tid=0x33] Membership: Processing addition < venezuela(12321)<ec><v64>:1026 >
> [locator][info 2016/07/27 08:22:44.360 PDT <View Message Processor> tid=0x33] Admitting member <venezuela(12321)<ec><v64>:1026>. Now there are 2 non-admin member(s).
> [info 2016/07/27 08:22:44.360 PDT <Test worker> tid=0xa] Finished joining (took 208ms).
> [info 2016/07/27 08:22:44.361 PDT <Test worker> tid=0xa] Starting DistributionManager venezuela(12321)<ec><v64>:1026.  (took 221 ms)
> [info 2016/07/27 08:22:44.361 PDT <Test worker> tid=0xa] Initial (distribution manager) view =  View[venezuela(12353:locator)<ec><v0>:1025|64] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12321)<ec><v64>:1026{lead}]  shutdown: [venezuela(12321)<ec><v63>:1026]
> [info 2016/07/27 08:22:44.361 PDT <Test worker> tid=0xa] Admitting member <venezuela(12353:locator)<ec><v0>:1025>. Now there are 1 non-admin member(s).
> [info 2016/07/27 08:22:44.361 PDT <Test worker> tid=0xa] Admitting member <venezuela(12321)<ec><v64>:1026>. Now there are 2 non-admin member(s).
> [locator][info 2016/07/27 08:22:44.364 PDT <Pooled High Priority Message Processor 2> tid=0x47] Member venezuela(12321)<ec><v64>:1026 is equivalent or in the same redundancy zone.
> [info 2016/07/27 08:22:44.366 PDT <P2P message reader for venezuela(12353:locator)<ec><v0>:1025 shared unordered uid=55 port=58813> tid=0xcf] Member venezuela(12353:locator)<ec><v0>:1025 is equivalent or in the same redundancy zone.
> [info 2016/07/27 08:22:44.375 PDT <Test worker> tid=0xa] Initializing region _monitoringRegion_10.118.32.90<v64>1026
> [info 2016/07/27 08:22:44.376 PDT <Test worker> tid=0xa] Initialization of region _monitoringRegion_10.118.32.90<v64>1026 completed
> [info 2016/07/27 08:22:44.381 PDT <Test worker> tid=0xa] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
> [info 2016/07/27 08:22:44.382 PDT <Test worker> tid=0xa] Initializing region PdxTypes
> [info 2016/07/27 08:22:44.384 PDT <Test worker> tid=0xa] Initialization of region PdxTypes completed
> [info 2016/07/27 08:22:44.419 PDT <Test worker> tid=0xa] Created disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion with unique id 9048b6bb98354e5f-8d643eccc5e71544
> [info 2016/07/27 08:22:44.431 PDT <Test worker> tid=0xa] recovery region initialization took 1 ms
> [info 2016/07/27 08:22:44.502 PDT <Test worker> tid=0xa] Created oplog#1 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:44.506 PDT <Test worker> tid=0xa] Created oplog#1 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [warn 2016/07/27 08:22:44.511 PDT <Test worker> tid=0xa] Creating persistent region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion, but enable-network-partition-detection is set to false. Running with network partition detection disabled can lead to an unrecoverable system in the event of a network split.
> [info 2016/07/27 08:22:44.512 PDT <Test worker> tid=0xa] Initializing region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion
> [info 2016/07/27 08:22:44.515 PDT <Test worker> tid=0xa] Region /PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion was created on this member with the persistent id venezuela.gemstone.com/10.118.32.90:/venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testWriteCorrectVersionToKrf/1 created at timestamp 1469632964511 version 0 diskStoreId 9048b6bb98354e5f-8d643eccc5e71544 name .
> [info 2016/07/27 08:22:44.516 PDT <Test worker> tid=0xa] Initialization of region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion completed
> [info 2016/07/27 08:22:44.525 PDT <Test worker> tid=0xa] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [info 2016/07/27 08:22:44.526 PDT <Test worker> tid=0xa] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [info 2016/07/27 08:22:44.526 PDT <Test worker> tid=0xa] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [vm_0][info 2016/07/27 08:22:44.526 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
> [vm_0][info 2016/07/27 08:22:44.526 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [vm_0][info 2016/07/27 08:22:44.526 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [vm_0][info 2016/07/27 08:22:44.526 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] 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/07/27 08:22:44.527 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
> [vm_1][info 2016/07/27 08:22:44.527 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [vm_1][info 2016/07/27 08:22:44.527 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [vm_1][info 2016/07/27 08:22:44.527 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0x1ee] 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/07/27 08:22:44.529 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
> [vm_2][info 2016/07/27 08:22:44.529 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [vm_2][info 2016/07/27 08:22:44.529 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [vm_2][info 2016/07/27 08:22:44.529 PDT <RMI TCP Connection(13)-10.118.32.90> 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/07/27 08:22:44.532 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.IgnoredException$2.run with 0 args on object: "IgnoredException addIgnoredException"
> [vm_3][info 2016/07/27 08:22:44.533 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [vm_3][info 2016/07/27 08:22:44.533 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] <ExpectedException action=add>DiskAccessException</ExpectedException>
> [vm_3][info 2016/07/27 08:22:44.533 PDT <RMI TCP Connection(13)-10.118.32.90> 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/07/27 08:22:45.411 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#2 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.412 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#2 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.417 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#3 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.417 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#3 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.421 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#4 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.421 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#4 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.423 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#5 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.424 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#5 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.426 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#6 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.427 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#6 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.430 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#7 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.430 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#7 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.432 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#8 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.433 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#8 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.434 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#9 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.435 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] Created oplog#9 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.437 PDT <Oplog Delete Task> tid=0xdf] Deleted oplog#3 crf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.437 PDT <Oplog Delete Task> tid=0xdf] Deleted oplog#3 drf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.440 PDT <Idle OplogCompactor> tid=0xdd] Created oplog#1 krf for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion.
> [info 2016/07/27 08:22:45.442 PDT <OplogCompactor PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion for oplog oplog#1> tid=0xdd] OplogCompactor for PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion compaction oplog id(s): oplog#1
> [error 2016/07/27 08:22:45.442 PDT <Asynchronous disk writer for region PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion> tid=0xdc] A DiskAccessException has occurred while writing to the disk for disk store PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion. The cache will be closed.
> com.gemstone.gemfire.cache.DiskAccessException
> 	at com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$16.afterWritingBytes(PersistentRVVRecoveryDUnitTest.java:802)
> 	at com.gemstone.gemfire.internal.cache.DiskStoreImpl$FlusherThread.run(DiskStoreImpl.java:1743)
> 	at java.lang.Thread.run(Thread.java:745)
> [error 2016/07/27 08:22:45.443 PDT <Test worker> tid=0xa] A DiskAccessException has occurred while writing to the disk for region /PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion. The cache will be closed.
> com.gemstone.gemfire.cache.DiskAccessException: For DiskStore: PersistentRVVRecoveryDUnitTest_testWriteCorrectVersionToKrfRegion: Could not schedule asynchronous write because the flusher thread had been terminated.
> 	at com.gemstone.gemfire.internal.cache.DiskStoreImpl.checkForFlusherThreadTermination(DiskStoreImpl.java:1223)
> 	at com.gemstone.gemfire.internal.cache.DiskStoreImpl.addAsyncItem(DiskStoreImpl.java:1271)
> 	at com.gemstone.gemfire.internal.cache.DiskStoreImpl.scheduleAsyncWrite(DiskStoreImpl.java:1335)
> 	at com.gemstone.gemfire.internal.cache.DiskRegion.scheduleAsyncWrite(DiskRegion.java:483)
> 	at com.gemstone.gemfire.internal.cache.DiskEntry$Helper.scheduleAsyncWrite(DiskEntry.java:1494)
> 	at com.gemstone.gemfire.internal.cache.DiskEntry$Helper.update(DiskEntry.java:1034)
> 	at com.gemstone.gemfire.internal.cache.AbstractDiskRegionEntry.setValue(AbstractDiskRegionEntry.java:42)
> 	at com.gemstone.gemfire.internal.cache.AbstractRegionEntry.setValueWithTombstoneCheck(AbstractRegionEntry.java:241)
> 	at com.gemstone.gemfire.internal.cache.EntryEventImpl.setNewValueInRegion(EntryEventImpl.java:1614)
> 	at com.gemstone.gemfire.internal.cache.EntryEventImpl.putExistingEntry(EntryEventImpl.java:1482)
> 	at com.gemstone.gemfire.internal.cache.AbstractRegionMap.updateEntry(AbstractRegionMap.java:2882)
> 	at com.gemstone.gemfire.internal.cache.AbstractRegionMap.basicPut(AbstractRegionMap.java:2713)
> 	at com.gemstone.gemfire.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5955)
> 	at com.gemstone.gemfire.internal.cache.DistributedRegion.virtualPut(DistributedRegion.java:348)
> 	at com.gemstone.gemfire.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:132)
> 	at com.gemstone.gemfire.internal.cache.LocalRegion.basicPut(LocalRegion.java:5350)
> 	at com.gemstone.gemfire.internal.cache.LocalRegion.validatedPut(LocalRegion.java:1668)
> 	at com.gemstone.gemfire.internal.cache.LocalRegion.put(LocalRegion.java:1655)
> 	at com.gemstone.gemfire.internal.cache.AbstractRegion.put(AbstractRegion.java:288)
> 	at com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest.testWriteCorrectVersionToKrf(PersistentRVVRecoveryDUnitTest.java:824)
> 	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.jav
> ...[truncated 404278 chars]...
> o 2016/07/27 08:22:52.187 PDT <unicast receiver,venezuela-14080> tid=0x6ec] received new view: View[venezuela(12353:locator)<ec><v0>:1025|79] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12414)<ec><v77>:1026{lead}, venezuela(12418)<ec><v78>:1028, venezuela(12422)<ec><v79>:1029]
> [vm_1]old view is: View[venezuela(12353:locator)<ec><v0>:1025|78] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12414)<ec><v77>:1026{lead}, venezuela(12418)<ec><v78>:1028]
> [vm_0][info 2016/07/27 08:22:52.188 PDT <View Message Processor> tid=0x640] Membership: Processing addition < venezuela(12422)<ec><v79>:1029 >
> [vm_0][info 2016/07/27 08:22:52.188 PDT <View Message Processor> tid=0x640] Admitting member <venezuela(12422)<ec><v79>:1029>. Now there are 4 non-admin member(s).
> [vm_1][info 2016/07/27 08:22:52.188 PDT <View Message Processor> tid=0x70a] Membership: Processing addition < venezuela(12422)<ec><v79>:1029 >
> [vm_1][info 2016/07/27 08:22:52.188 PDT <View Message Processor> tid=0x70a] Admitting member <venezuela(12422)<ec><v79>:1029>. Now there are 4 non-admin member(s).
> [locator][info 2016/07/27 08:22:52.187 PDT <View Message Processor> tid=0x33] Admitting member <venezuela(12422)<ec><v79>:1029>. Now there are 4 non-admin member(s).
> [locator][info 2016/07/27 08:22:52.191 PDT <Pooled High Priority Message Processor 2> tid=0x47] Member venezuela(12422)<ec><v79>:1029 is equivalent or in the same redundancy zone.
> [vm_1][info 2016/07/27 08:22:52.192 PDT <Pooled High Priority Message Processor 1> tid=0x704] Member venezuela(12422)<ec><v79>:1029 is equivalent or in the same redundancy zone.
> [vm_0][info 2016/07/27 08:22:52.194 PDT <Pooled High Priority Message Processor 1> tid=0x639] Member venezuela(12422)<ec><v79>:1029 is equivalent or in the same redundancy zone.
> [vm_2][info 2016/07/27 08:22:52.196 PDT <P2P message reader for venezuela(12353:locator)<ec><v0>:1025 shared unordered uid=69 port=33472> tid=0x229] Member venezuela(12353:locator)<ec><v0>:1025 is equivalent or in the same redundancy zone.
> [vm_2][info 2016/07/27 08:22:52.197 PDT <P2P message reader for venezuela(12414)<ec><v77>:1026 shared unordered uid=102 port=33474> tid=0x22b] Member venezuela(12414)<ec><v77>:1026 is equivalent or in the same redundancy zone.
> [vm_2][info 2016/07/27 08:22:52.197 PDT <P2P message reader for venezuela(12418)<ec><v78>:1028 shared unordered uid=97 port=33473> tid=0x22a] Member venezuela(12418)<ec><v78>:1028 is equivalent or in the same redundancy zone.
> [vm_2][info 2016/07/27 08:22:52.209 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Initializing region _monitoringRegion_10.118.32.90<v79>1029
> [vm_2][info 2016/07/27 08:22:52.211 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Initialization of region _monitoringRegion_10.118.32.90<v79>1029 completed
> [vm_2][info 2016/07/27 08:22:52.215 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
> [vm_2][info 2016/07/27 08:22:52.216 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Initializing region PdxTypes
> [vm_2][info 2016/07/27 08:22:52.221 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Region PdxTypes requesting initial image from venezuela(12414)<ec><v77>:1026
> [vm_2][info 2016/07/27 08:22:52.222 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] PdxTypes is done getting image from venezuela(12414)<ec><v77>:1026. isDeltaGII is false
> [vm_2][info 2016/07/27 08:22:52.222 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Initialization of region PdxTypes completed
> [vm_2][info 2016/07/27 08:22:52.229 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Created disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion with unique id d622de9692114548-927ae2095ddda5f8
> [vm_2][info 2016/07/27 08:22:52.230 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] recovery region initialization took 0 ms
> [vm_2][info 2016/07/27 08:22:52.232 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Created oplog#1 drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_2][info 2016/07/27 08:22:52.232 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Created oplog#1 crf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_2][info 2016/07/27 08:22:52.233 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Initializing region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion
> [vm_2][info 2016/07/27 08:22:52.239 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion requesting initial image from venezuela(12418)<ec><v78>:1028
> [vm_2][info 2016/07/27 08:22:52.241 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion is done getting image from venezuela(12418)<ec><v78>:1028. isDeltaGII is false
> [vm_2][info 2016/07/27 08:22:52.241 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion initialized persistent id: venezuela.gemstone.com/10.118.32.90:/venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/2 created at timestamp 1469632972233 version 0 diskStoreId d622de9692114548-927ae2095ddda5f8 name  with data from venezuela(12418)<ec><v78>:1028.
> [vm_2][info 2016/07/27 08:22:52.241 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Initialization of region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion completed
> [vm_2][info 2016/07/27 08:22:52.243 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$7.run with 0 args on object: "Create persistent region" (took 383 ms)
> [vm_0][info 2016/07/27 08:22:52.244 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$19.run with 0 args on object: "createData"
> [vm_0][info 2016/07/27 08:22:52.252 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$19.run with 0 args on object: "createData" (took 7 ms)
> [vm_1][info 2016/07/27 08:22:52.253 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$19.run with 0 args on object: "createData"
> [vm_1][info 2016/07/27 08:22:52.263 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$19.run with 0 args on object: "createData" (took 9 ms)
> [vm_2][info 2016/07/27 08:22:52.263 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$19.run with 0 args on object: "createData"
> [vm_2][info 2016/07/27 08:22:52.273 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$19.run with 0 args on object: "createData" (took 8 ms)
> [vm_1][info 2016/07/27 08:22:52.273 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$21.run with 0 args on object: "destroy"
> [vm_1][info 2016/07/27 08:22:52.275 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$21.run with 0 args on object: "destroy" (took 1 ms)
> [vm_0][info 2016/07/27 08:22:52.276 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$21.run with 0 args on object: "destroy"
> [vm_0][info 2016/07/27 08:22:52.277 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$21.run with 0 args on object: "destroy" (took 1 ms)
> [vm_0][info 2016/07/27 08:22:52.278 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV"
> [vm_0][info 2016/07/27 08:22:52.278 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: [B@6287740d
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_1][info 2016/07/27 08:22:52.279 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV"
> [vm_1][info 2016/07/27 08:22:52.279 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: [B@3d9fd327
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_2][info 2016/07/27 08:22:52.280 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV"
> [vm_2][info 2016/07/27 08:22:52.280 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: [B@7178467d
> [vm_2] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_2][info 2016/07/27 08:22:52.280 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache"
> [vm_2][info 2016/07/27 08:22:52.282 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] GemFireCache[id = 1372605178; isClosing = true; isShutDownAll = false; created = Wed Jul 27 08:22:52 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_2][info 2016/07/27 08:22:54.071 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Created oplog#1 krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_2][info 2016/07/27 08:22:54.076 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache" (took 1795 ms)
> [vm_1][info 2016/07/27 08:22:54.077 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache"
> [vm_1][info 2016/07/27 08:22:54.079 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] GemFireCache[id = 189009256; isClosing = true; isShutDownAll = false; created = Wed Jul 27 08:22:51 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_1][info 2016/07/27 08:22:54.089 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Created oplog#1 krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.092 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache" (took 14 ms)
> [vm_0][info 2016/07/27 08:22:54.093 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache"
> [vm_0][info 2016/07/27 08:22:54.095 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] GemFireCache[id = 1594119895; isClosing = true; isShutDownAll = false; created = Wed Jul 27 08:22:51 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_0][info 2016/07/27 08:22:54.104 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Created oplog#1 krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_0][info 2016/07/27 08:22:54.106 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache" (took 13 ms)
> [vm_0][info 2016/07/27 08:22:54.107 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$7.run with 0 args on object: "Create persistent region"
> [vm_0][info 2016/07/27 08:22:54.113 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Initializing region _monitoringRegion_10.118.32.90<v77>1026
> [vm_0][info 2016/07/27 08:22:54.114 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Initialization of region _monitoringRegion_10.118.32.90<v77>1026 completed
> [vm_0][info 2016/07/27 08:22:54.116 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
> [vm_0][info 2016/07/27 08:22:54.117 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Initializing region PdxTypes
> [vm_0][info 2016/07/27 08:22:54.119 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Initialization of region PdxTypes completed
> [vm_0][info 2016/07/27 08:22:54.120 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Recovered disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion with unique id 68f3eb6a1a354b9a-9ca04f3f6513b7df
> [vm_0][info 2016/07/27 08:22:54.121 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Recovering oplog#1 /venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/0/BACKUPPersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion_1.drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_0][info 2016/07/27 08:22:54.121 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Recovering oplog#1 /venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/0/BACKUPPersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion_1.krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_0][info 2016/07/27 08:22:54.122 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] recovery oplog load took 1 ms
> [vm_0][info 2016/07/27 08:22:54.122 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Created oplog#2 drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_0][info 2016/07/27 08:22:54.123 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Created oplog#2 crf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_0][info 2016/07/27 08:22:54.123 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] recovery region initialization took 1 ms
> [vm_0][info 2016/07/27 08:22:54.124 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Initializing region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion
> [vm_0][info 2016/07/27 08:22:54.126 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Region /PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion recovered from the local disk. Old persistent ID: /10.118.32.90:/venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/0 created at timestamp 1469632971474 version 0 diskStoreId 68f3eb6a1a354b9a-9ca04f3f6513b7df name , new persistent ID venezuela.gemstone.com/10.118.32.90:/venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/0 created at timestamp 1469632974123 version 0 diskStoreId 68f3eb6a1a354b9a-9ca04f3f6513b7df name 
> [vm_0][info 2016/07/27 08:22:54.127 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Initialization of region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion completed
> [vm_0][info 2016/07/27 08:22:54.128 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$7.run with 0 args on object: "Create persistent region" (took 20 ms)
> [vm_0][info 2016/07/27 08:22:54.128 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV"
> [vm_0][info 2016/07/27 08:22:54.128 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: [B@74a68ea6
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_0][info 2016/07/27 08:22:54.129 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$19.run with 0 args on object: "createData"
> [vm_0][info 2016/07/27 08:22:54.129 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$19.run with 0 args on object: "createData" (took 0 ms)
> [vm_0][info 2016/07/27 08:22:54.130 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV"
> [vm_0][info 2016/07/27 08:22:54.130 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: [B@8b08803
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_0][info 2016/07/27 08:22:54.130 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$23.call with 0 args on object: "getRVV"
> [vm_0][info 2016/07/27 08:22:54.130 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: [B@53e38bf3
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$23.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_1][info 2016/07/27 08:22:54.132 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$7.run with 0 args on object: "Create persistent region"
> [vm_1][info 2016/07/27 08:22:54.137 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initializing region _monitoringRegion_10.118.32.90<v78>1028
> [vm_1][info 2016/07/27 08:22:54.138 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initialization of region _monitoringRegion_10.118.32.90<v78>1028 completed
> [vm_1][info 2016/07/27 08:22:54.140 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
> [vm_1][info 2016/07/27 08:22:54.141 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initializing region PdxTypes
> [vm_1][info 2016/07/27 08:22:54.145 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Region PdxTypes requesting initial image from venezuela(12414)<ec><v77>:1026
> [vm_1][info 2016/07/27 08:22:54.145 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] PdxTypes is done getting image from venezuela(12414)<ec><v77>:1026. isDeltaGII is false
> [vm_1][info 2016/07/27 08:22:54.146 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initialization of region PdxTypes completed
> [vm_1][info 2016/07/27 08:22:54.147 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Recovered disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion with unique id 521556444b114433-894e0052e0d0d7b6
> [vm_1][info 2016/07/27 08:22:54.147 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Recovering oplog#1 /venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/1/BACKUPPersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion_1.drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.148 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Recovering oplog#1 /venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/1/BACKUPPersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion_1.krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.148 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] recovery oplog load took 1 ms
> [vm_1][info 2016/07/27 08:22:54.149 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Created oplog#2 drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.149 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Created oplog#2 crf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.150 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] recovery region initialization took 2 ms
> [vm_1][info 2016/07/27 08:22:54.151 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initializing region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion
> [vm_1][info 2016/07/27 08:22:54.163 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion requesting initial image from venezuela(12414)<ec><v77>:1026
> [vm_1][info 2016/07/27 08:22:54.165 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion is done getting image from venezuela(12414)<ec><v77>:1026. isDeltaGII is true
> [vm_1][info 2016/07/27 08:22:54.165 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion initialized persistent id: venezuela.gemstone.com/10.118.32.90:/venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/1 created at timestamp 1469632974150 version 0 diskStoreId 521556444b114433-894e0052e0d0d7b6 name  with data from venezuela(12414)<ec><v77>:1026.
> [vm_1][info 2016/07/27 08:22:54.166 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initialization of region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion completed
> [vm_1][info 2016/07/27 08:22:54.168 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$7.run with 0 args on object: "Create persistent region" (took 35 ms)
> [vm_1][info 2016/07/27 08:22:54.169 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV"
> [vm_1][info 2016/07/27 08:22:54.169 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: [B@26de7ab4
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_1][info 2016/07/27 08:22:54.170 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$23.call with 0 args on object: "getRVV"
> [vm_1][info 2016/07/27 08:22:54.170 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: [B@4a7865c3
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$23.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_0][info 2016/07/27 08:22:54.171 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache"
> [vm_0][info 2016/07/27 08:22:54.172 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] GemFireCache[id = 1640756305; isClosing = true; isShutDownAll = false; created = Wed Jul 27 08:22:54 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_0][info 2016/07/27 08:22:54.183 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Created oplog#2 krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_0][info 2016/07/27 08:22:54.187 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache" (took 16 ms)
> [vm_1][info 2016/07/27 08:22:54.188 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache"
> [vm_1][info 2016/07/27 08:22:54.189 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] GemFireCache[id = 196827383; isClosing = true; isShutDownAll = false; created = Wed Jul 27 08:22:54 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_1][info 2016/07/27 08:22:54.196 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Created oplog#2 krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.201 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$4.run with 0 args on object: "close cache" (took 12 ms)
> [vm_1][info 2016/07/27 08:22:54.203 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$7.run with 0 args on object: "Create persistent region"
> [vm_1][info 2016/07/27 08:22:54.214 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initializing region _monitoringRegion_10.118.32.90<v78>1028
> [vm_1][info 2016/07/27 08:22:54.215 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initialization of region _monitoringRegion_10.118.32.90<v78>1028 completed
> [vm_1][info 2016/07/27 08:22:54.218 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] The cache has been created with "use-cluster-configuration=false". It will not receive any cluster configuration
> [vm_1][info 2016/07/27 08:22:54.218 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initializing region PdxTypes
> [vm_1][info 2016/07/27 08:22:54.219 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initialization of region PdxTypes completed
> [vm_1][info 2016/07/27 08:22:54.220 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Recovered disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion with unique id 521556444b114433-894e0052e0d0d7b6
> [vm_1][info 2016/07/27 08:22:54.220 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Recovering oplog#2 /venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/1/BACKUPPersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion_2.drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.221 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Recovering oplog#1 /venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/1/BACKUPPersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion_1.drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.221 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Recovering oplog#2 /venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/1/BACKUPPersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion_2.krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.221 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Recovering oplog#1 /venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/1/BACKUPPersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion_1.krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.222 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] recovery oplog load took 2 ms
> [vm_1][info 2016/07/27 08:22:54.222 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Created oplog#3 drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.223 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Created oplog#3 crf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.223 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] recovery region initialization took 1 ms
> [vm_1][info 2016/07/27 08:22:54.224 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initializing region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion
> [vm_1][info 2016/07/27 08:22:54.226 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Region /PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion recovered from the local disk. Old persistent ID: /10.118.32.90:/venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/1 created at timestamp 1469632974150 version 0 diskStoreId 521556444b114433-894e0052e0d0d7b6 name , new persistent ID venezuela.gemstone.com/10.118.32.90:/venezuela1/users/build/jenkins/blds/workspace/Geode_develop_DistributedTests/geode-core/build/distributedTest/diskDir-testRecoveryWithKRF/1 created at timestamp 1469632974223 version 0 diskStoreId 521556444b114433-894e0052e0d0d7b6 name 
> [vm_1][info 2016/07/27 08:22:54.226 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Initialization of region PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion completed
> [vm_1][info 2016/07/27 08:22:54.227 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentReplicatedTestBase$7.run with 0 args on object: "Create persistent region" (took 23 ms)
> [vm_1][info 2016/07/27 08:22:54.228 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV"
> [vm_1][info 2016/07/27 08:22:54.228 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: [B@3706224
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_1][info 2016/07/27 08:22:54.229 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV"
> [vm_1][info 2016/07/27 08:22:54.229 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: [B@3d41da06
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentRVVRecoveryDUnitTest$22.call with 0 args on object: "getRVV" (took 0 ms)
> [vm_0][info 2016/07/27 08:22:54.230 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/72500195.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/72500195@310e441b
> [vm_0][info 2016/07/27 08:22:54.230 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/72500195.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/72500195@310e441b (took 0 ms)
> [vm_1][info 2016/07/27 08:22:54.231 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$8/949738456.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$8/949738456@72df2354
> [vm_1][info 2016/07/27 08:22:54.231 PDT <Idle OplogCompactor> tid=0x729] Closing oplog#2 early since it is empty. It is for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.233 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] GemFireCache[id = 349580945; isClosing = true; isShutDownAll = false; created = Wed Jul 27 08:22:54 PDT 2016; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_1][info 2016/07/27 08:22:54.234 PDT <Oplog Delete Task> tid=0x72a] Deleted oplog#2 crf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.234 PDT <Oplog Delete Task> tid=0x72a] Deleted oplog#2 krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.235 PDT <Oplog Delete Task> tid=0x72a] Deleted oplog#2 drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.235 PDT <Oplog Delete Task> tid=0x72a] Deleted oplog#1 crf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.235 PDT <Oplog Delete Task> tid=0x72a] Deleted oplog#1 krf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.235 PDT <Oplog Delete Task> tid=0x72a] Deleted oplog#1 drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.237 PDT <Oplog Delete Task> tid=0x72a] Deleted oplog#3 crf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.237 PDT <Oplog Delete Task> tid=0x72a] Deleted oplog#3 drf for disk store PersistentRVVRecoveryDUnitTest_testRecoveryWithKRFRegion.
> [vm_1][info 2016/07/27 08:22:54.239 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$8/949738456.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$8/949738456@72df2354 (took 7 ms)
> [vm_2][info 2016/07/27 08:22:54.239 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/1504845286.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/1504845286@17d31ca3
> [vm_2][info 2016/07/27 08:22:54.240 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/1504845286.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/1504845286@17d31ca3 (took 0 ms)
> [vm_3][info 2016/07/27 08:22:54.240 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/640281163.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/640281163@2e3019b0
> [vm_3][info 2016/07/27 08:22:54.241 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/640281163.run with 0 args on object: com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/640281163@2e3019b0 (took 0 ms)
> [vm_0][info 2016/07/27 08:22:54.247 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args
> [vm_0][info 2016/07/27 08:22:54.247 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args (took 0 ms)
> [vm_1][info 2016/07/27 08:22:54.248 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args
> [vm_1][info 2016/07/27 08:22:54.248 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args (took 0 ms)
> [vm_2][info 2016/07/27 08:22:54.249 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args
> [vm_2][info 2016/07/27 08:22:54.249 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args (took 0 ms)
> [vm_3][info 2016/07/27 08:22:54.249 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args
> [vm_3][info 2016/07/27 08:22:54.250 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.internal.cache.persistence.PersistentRecoveryOrderDUnitTest.resetAckWaitThreshold with 0 args (took 0 ms)
> [vm_0][info 2016/07/27 08:22:54.250 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_0][info 2016/07/27 08:22:54.250 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator) (took 0 ms)
> [vm_1][info 2016/07/27 08:22:54.251 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_1][info 2016/07/27 08:22:54.251 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator) (took 0 ms)
> [vm_2][info 2016/07/27 08:22:54.252 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_2][info 2016/07/27 08:22:54.252 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator) (took 0 ms)
> [vm_3][info 2016/07/27 08:22:54.252 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_3][info 2016/07/27 08:22:54.252 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownCreationStackGenerator) (took 0 ms)
> [vm_0][info 2016/07/27 08:22:54.253 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM)
> [vm_0][info 2016/07/27 08:22:54.254 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Shutting down DistributionManager venezuela(12414)<ec><v77>:1026. 
> [locator][info 2016/07/27 08:22:54.254 PDT <Pooled High Priority Message Processor 1> tid=0x37] received leave request from venezuela(12414)<ec><v77>:1026 for venezuela(12414)<ec><v77>:1026
> [vm_1][info 2016/07/27 08:22:54.254 PDT <Pooled High Priority Message Processor 3> tid=0x727] received leave request from venezuela(12414)<ec><v77>:1026 for venezuela(12414)<ec><v77>:1026
> [vm_1][info 2016/07/27 08:22:54.255 PDT <Pooled High Priority Message Processor 3> tid=0x727] Member at venezuela(12414)<ec><v77>:1026 gracefully left the distributed cache: shutdown message received
> [vm_2][info 2016/07/27 08:22:54.254 PDT <Pooled High Priority Message Processor 2> tid=0x237] received leave request from venezuela(12414)<ec><v77>:1026 for venezuela(12414)<ec><v77>:1026
> [vm_2][info 2016/07/27 08:22:54.255 PDT <Pooled High Priority Message Processor 2> tid=0x237] Member at venezuela(12414)<ec><v77>:1026 gracefully left the distributed cache: shutdown message received
> [locator][info 2016/07/27 08:22:54.254 PDT <Pooled High Priority Message Processor 1> tid=0x37] Member at venezuela(12414)<ec><v77>:1026 gracefully left the distributed cache: shutdown message received
> [vm_0][info 2016/07/27 08:22:54.357 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Now closing distribution for venezuela(12414)<ec><v77>:1026
> [vm_0][info 2016/07/27 08:22:54.357 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Stopping membership services
> [vm_1][info 2016/07/27 08:22:54.357 PDT <unicast receiver,venezuela-14080> tid=0x6ec] received leave request from venezuela(12414)<ec><v77>:1026 for venezuela(12414)<ec><v77>:1026
> [vm_2][info 2016/07/27 08:22:54.358 PDT <unicast receiver,venezuela-27526> tid=0x21c] received leave request from venezuela(12414)<ec><v77>:1026 for venezuela(12414)<ec><v77>:1026
> [vm_0][info 2016/07/27 08:22:54.357 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] GMSHealthMonitor server socket is closed in stopServices().
> [vm_0][info 2016/07/27 08:22:54.358 PDT <Geode Failure Detection Server thread 0> tid=0x629] GMSHealthMonitor server thread exiting
> [vm_0][info 2016/07/27 08:22:54.358 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] GMSHealthMonitor serverSocketExecutor is terminated
> [locator][info 2016/07/27 08:22:54.358 PDT <unicast receiver,venezuela-31226> tid=0x21] received leave request from venezuela(12414)<ec><v77>:1026 for venezuela(12414)<ec><v77>:1026
> [vm_0][info 2016/07/27 08:22:54.363 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] DistributionManager stopped in 109ms.
> [vm_0][info 2016/07/27 08:22:54.363 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Marking DistributionManager venezuela(12414)<ec><v77>:1026 as closed.
> [vm_0][info 2016/07/27 08:22:54.363 PDT <RMI TCP Connection(14)-10.118.32.90> tid=0xbe] Got result: null
> [vm_0] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM) (took 110 ms)
> [vm_1][info 2016/07/27 08:22:54.364 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM)
> [vm_1][info 2016/07/27 08:22:54.365 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Shutting down DistributionManager venezuela(12418)<ec><v78>:1028. 
> [locator][info 2016/07/27 08:22:54.365 PDT <Pooled High Priority Message Processor 1> tid=0x37] received leave request from venezuela(12418)<ec><v78>:1028 for venezuela(12418)<ec><v78>:1028
> [locator][info 2016/07/27 08:22:54.366 PDT <Pooled High Priority Message Processor 1> tid=0x37] Member at venezuela(12418)<ec><v78>:1028 gracefully left the distributed cache: shutdown message received
> [vm_2][info 2016/07/27 08:22:54.365 PDT <Pooled High Priority Message Processor 2> tid=0x237] received leave request from venezuela(12418)<ec><v78>:1028 for venezuela(12418)<ec><v78>:1028
> [vm_2][info 2016/07/27 08:22:54.366 PDT <Pooled High Priority Message Processor 2> tid=0x237] Member at venezuela(12418)<ec><v78>:1028 gracefully left the distributed cache: shutdown message received
> [vm_1][info 2016/07/27 08:22:54.468 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Now closing distribution for venezuela(12418)<ec><v78>:1028
> [vm_1][info 2016/07/27 08:22:54.468 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Stopping membership services
> [vm_2][info 2016/07/27 08:22:54.468 PDT <unicast receiver,venezuela-27526> tid=0x21c] received leave request from venezuela(12418)<ec><v78>:1028 for venezuela(12418)<ec><v78>:1028
> [locator][info 2016/07/27 08:22:54.469 PDT <unicast receiver,venezuela-31226> tid=0x21] received leave request from venezuela(12418)<ec><v78>:1028 for venezuela(12418)<ec><v78>:1028
> [vm_1][info 2016/07/27 08:22:54.469 PDT <Geode Failure Detection Server thread 0> tid=0x6f0] GMSHealthMonitor server thread exiting
> [vm_1][info 2016/07/27 08:22:54.469 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] GMSHealthMonitor server socket is closed in stopServices().
> [vm_1][info 2016/07/27 08:22:54.469 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] GMSHealthMonitor serverSocketExecutor is terminated
> [vm_1][info 2016/07/27 08:22:54.472 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] DistributionManager stopped in 107ms.
> [vm_1][info 2016/07/27 08:22:54.473 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Marking DistributionManager venezuela(12418)<ec><v78>:1028 as closed.
> [vm_1][info 2016/07/27 08:22:54.473 PDT <RMI TCP Connection(15)-10.118.32.90> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM) (took 108 ms)
> [vm_2][info 2016/07/27 08:22:54.474 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM)
> [vm_2][info 2016/07/27 08:22:54.474 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Shutting down DistributionManager venezuela(12422)<ec><v79>:1029. 
> [locator][info 2016/07/27 08:22:54.475 PDT <Pooled High Priority Message Processor 1> tid=0x37] received leave request from venezuela(12422)<ec><v79>:1029 for venezuela(12422)<ec><v79>:1029
> [locator][info 2016/07/27 08:22:54.475 PDT <Pooled High Priority Message Processor 1> tid=0x37] Member at venezuela(12422)<ec><v79>:1029 gracefully left the distributed cache: shutdown message received
> [locator][info 2016/07/27 08:22:54.577 PDT <Geode Membership View Creator> tid=0x27] View Creator is processing 5 requests for the next membership view
> [locator][info 2016/07/27 08:22:54.577 PDT <Geode Membership View Creator> tid=0x27] received new view: View[venezuela(12353:locator)<ec><v0>:1025|80] members: [venezuela(12353:locator)<ec><v0>:1025]  shutdown: [venezuela(12418)<ec><v78>:1028, venezuela(12422)<ec><v79>:1029, venezuela(12414)<ec><v77>:1026]
> [locator]old view is: View[venezuela(12353:locator)<ec><v0>:1025|79] members: [venezuela(12353:locator)<ec><v0>:1025, venezuela(12414)<ec><v77>:1026{lead}, venezuela(12418)<ec><v78>:1028, venezuela(12422)<ec><v79>:1029]
> [locator][info 2016/07/27 08:22:54.577 PDT <Geode Membership View Creator> tid=0x27] Peer locator received new membership view: View[venezuela(12353:locator)<ec><v0>:1025|80] members: [venezuela(12353:locator)<ec><v0>:1025]  shutdown: [venezuela(12418)<ec><v78>:1028, venezuela(12422)<ec><v79>:1029, venezuela(12414)<ec><v77>:1026]
> [locator][info 2016/07/27 08:22:54.578 PDT <Geode Membership View Creator> tid=0x27] no recipients for new view aside from myself
> [vm_2][info 2016/07/27 08:22:54.578 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Now closing distribution for venezuela(12422)<ec><v79>:1029
> [vm_2][info 2016/07/27 08:22:54.578 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Stopping membership services
> [locator][info 2016/07/27 08:22:54.579 PDT <unicast receiver,venezuela-31226> tid=0x21] received leave request from venezuela(12422)<ec><v79>:1029 for venezuela(12422)<ec><v79>:1029
> [vm_2][info 2016/07/27 08:22:54.579 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] GMSHealthMonitor server socket is closed in stopServices().
> [vm_2][info 2016/07/27 08:22:54.579 PDT <Geode Failure Detection Server thread 0> tid=0x220] GMSHealthMonitor server thread exiting
> [vm_2][info 2016/07/27 08:22:54.579 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] GMSHealthMonitor serverSocketExecutor is terminated
> [vm_2][info 2016/07/27 08:22:54.582 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] DistributionManager stopped in 108ms.
> [vm_2][info 2016/07/27 08:22:54.582 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Marking DistributionManager venezuela(12422)<ec><v79>:1029 as closed.
> [vm_2][info 2016/07/27 08:22:54.582 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_2] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM) (took 108 ms)
> [vm_3][info 2016/07/27 08:22:54.583 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM)
> [vm_3][info 2016/07/27 08:22:54.583 PDT <RMI TCP Connection(13)-10.118.32.90> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on object: runnable(tearDownVM) (took 0 ms)
> [locator][info 2016/07/27 08:22:54.584 PDT <RMI TCP Connection(2)-10.118.32.90> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/609302019.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/609302019@658426d0
> [locator][info 2016/07/27 08:22:54.584 PDT <RMI TCP Connection(2)-10.118.32.90> tid=0x12] Got result: null
> [locator] from com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/609302019.run with 0 args on object: com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/609302019@658426d0 (took 0 ms)
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message