[
https://issues.apache.org/jira/browse/GEODE-1699?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15433805#comment-15433805
]
Dan Smith commented on GEODE-1699:
----------------------------------
I have not been able to reproduce this issue.
However, one thing I noticed is that the accessor VM is actually also a
datastore. So even though this test case is called
returnCorrectResultsWhenRebalanceHappensWhileSenderIsPaused, there is actually
still a VM where the sender is *not* paused, and it's dispatching events. I
think that's why the test failed once but has not reproduced.
That still doesn't explain why the test failed since it should be perfectly
valid to rebalance while the senders are not paused. Perhaps a test case
targeted at rebalancing during other points of dispatching entries could
reproduce that issue.
> LuceneQueriesPeerPRRedundancyDUnitTest.returnCorrectResultsWhenRebalanceHappensWhileSenderIsPaused
> --------------------------------------------------------------------------------------------------
>
> Key: GEODE-1699
> URL: https://issues.apache.org/jira/browse/GEODE-1699
> Project: Geode
> Issue Type: Bug
> Components: lucene
> Reporter: Kevin Duling
> Assignee: Dan Smith
> Labels: ci
>
> In Geode_develop_DistributedTests/3402:
> {noformat}
> Error Message
> java.lang.AssertionError
> Stacktrace
> java.lang.AssertionError
> at org.junit.Assert.fail(Assert.java:86)
> at org.junit.Assert.assertTrue(Assert.java:41)
> at org.junit.Assert.assertTrue(Assert.java:52)
> at
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPRBase.returnCorrectResultsWhenRebalanceHappensWhileSenderIsPaused(LuceneQueriesPRBase.java:120)
> 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.GeneratedMethodAccessor4.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
> at
> org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
> at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
> at
> org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:109)
> at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
> at
> org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54)
> at
> org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Standard Output
> Previously run tests: [LuceneIndexCreationDUnitTest,
> LuceneQueriesPeerPRRedundancyDUnitTest]
> [vm_0][info 2016/07/25 23:28:46.613 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(setupVM)
> [vm_0][info 2016/07/25 23:28:46.614 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] 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/25 23:28:46.614 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(setupVM)
> [vm_1][info 2016/07/25 23:28:46.615 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on
> object: runnable(setupVM) (took 0 ms)
> [vm_2][info 2016/07/25 23:28:46.615 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(setupVM)
> [vm_2][info 2016/07/25 23:28:46.616 PDT <RMI TCP Connection(1)-10.118.33.108>
> 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/25 23:28:46.617 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(setupVM)
> [vm_3][info 2016/07/25 23:28:46.617 PDT <RMI TCP Connection(1)-10.118.33.108>
> 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
> LuceneQueriesPeerPRRedundancyDUnitTest.returnCorrectResultsWhenMovePrimaryHappensOnIndexUpdate
> [vm_1][info 2016/07/25 23:28:46.630 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$55/37221661.call
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$55/37221661@b8f85a6
> [vm_1]distributed system properties: {locators=localhost[37501],
> enable-cluster-configuration=false, use-cluster-configuration=false,
> mcast-port=0, disable-auto-reconnect=true, log-level=info}
> [vm_1][info 2016/07/25 23:28:46.632 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Startup Configuration:
> [vm_1] ### GemFire Properties defined with api ###
> [vm_1]disable-auto-reconnect=true
> [vm_1]enable-cluster-configuration=false
> [vm_1]locators=localhost[37501]
> [vm_1]log-level=info
> [vm_1]mcast-port=0
> [vm_1]use-cluster-configuration=false
> [vm_1]### GemFire Properties using default values ###
> [vm_1]ack-severe-alert-threshold=0
> [vm_1]ack-wait-threshold=15
> [vm_1]archive-disk-space-limit=0
> [vm_1]archive-file-size-limit=0
> [vm_1]async-distribution-timeout=0
> [vm_1]async-max-queue-size=8
> [vm_1]async-queue-timeout=60000
> [vm_1]bind-address=
> [vm_1]cache-xml-file=cache.xml
> [vm_1]cluster-configuration-dir=
> [vm_1]cluster-ssl-ciphers=any
> [vm_1]cluster-ssl-enabled=false
> [vm_1]cluster-ssl-keystore=
> [vm_1]cluster-ssl-keystore-password=
> [vm_1]cluster-ssl-keystore-type=
> [vm_1]cluster-ssl-protocols=any
> [vm_1]cluster-ssl-require-authentication=true
> [vm_1]cluster-ssl-truststore=
> [vm_1]cluster-ssl-truststore-password=
> [vm_1]conflate-events=server
> [vm_1]conserve-sockets=true
> [vm_1]delta-propagation=true
> [vm_1]deploy-working-dir=.
> [vm_1]disable-tcp=false
> [vm_1]distributed-system-id=-1
> [vm_1]distributed-transactions=false
> [vm_1]durable-client-id=
> [vm_1]durable-client-timeout=300
> [vm_1]enable-network-partition-detection=false
> [vm_1]enable-time-statistics=false
> [vm_1]enforce-unique-host=false
> [vm_1]gateway-ssl-ciphers=any
> [vm_1]gateway-ssl-enabled=false
> [vm_1]gateway-ssl-keystore=
> [vm_1]gateway-ssl-keystore-password=
> [vm_1]gateway-ssl-keystore-type=
> [vm_1]gateway-ssl-protocols=any
> [vm_1]gateway-ssl-require-authentication=true
> [vm_1]gateway-ssl-truststore=
> [vm_1]gateway-ssl-truststore-password=
> [vm_1]groups=
> [vm_1]http-service-bind-address=
> [vm_1]http-service-port=7070
> [vm_1]http-service-ssl-ciphers=any
> [vm_1]http-service-ssl-enabled=false
> [vm_1]http-service-ssl-keystore=
> [vm_1]http-service-ssl-keystore-password=
> [vm_1]http-service-ssl-keystore-type=
> [vm_1]http-service-ssl-protocols=any
> [vm_1]http-service-ssl-require-authentication=false
> [vm_1]http-service-ssl-truststore=
> [vm_1]http-service-ssl-truststore-password=
> [vm_1]jmx-manager=false
> [vm_1]jmx-manager-access-file=
> [vm_1]jmx-manager-bind-address=
> [vm_1]jmx-manager-hostname-for-clients=
> [vm_1]jmx-manager-http-port=7070
> [vm_1]jmx-manager-password-file=
> [vm_1]jmx-manager-port=1099
> [vm_1]jmx-manager-ssl=false
> [vm_1]jmx-manager-ssl-ciphers=any
> [vm_1]jmx-manager-ssl-enabled=false
> [vm_1]jmx-manager-ssl-keystore=
> [vm_1]jmx-manager-ssl-keystore-password=
> [vm_1]jmx-manager-ssl-keystore-type=
> [vm_1]jmx-manager-ssl-protocols=any
> [vm_1]jmx-manager-ssl-require-authentication=true
> [vm_1]jmx-manager-ssl-truststore=
> [vm_1]jmx-manager-ssl-truststore-password=
> [vm_1]jmx-manager-start=false
> [vm_1]jmx-manager-update-rate=2000
> [vm_1]load-cluster-configuration-from-dir=false
> [vm_1]locator-wait-time=0
> [vm_1]lock-memory=false
> [vm_1]log-disk-space-limit=0
> [vm_1]log-file=
> [vm_1]log-file-size-limit=0
> [vm_1]max-num-reconnect-tries=3
> [vm_1]max-wait-time-reconnect=60000
> [vm_1]mcast-address=239.192.81.1
> [vm_1]mcast-flow-control=1048576, 0.25, 5000
> [vm_1]mcast-recv-buffer-size=1048576
> [vm_1]mcast-send-buffer-size=65535
> [vm_1]mcast-ttl=32
> [vm_1]member-timeout=5000
> [vm_1]membership-port-range=1024-65535
> [vm_1]memcached-bind-address=
> [vm_1]memcached-port=0
> [vm_1]memcached-protocol=ASCII
> [vm_1]name=
> [vm_1]off-heap-memory-size=
> [vm_1]redis-bind-address=
> [vm_1]redis-password=
> [vm_1]redis-port=0
> [vm_1]redundancy-zone=
> [vm_1]remote-locators=
> [vm_1]remove-unresponsive-client=false
> [vm_1]roles=
> [vm_1]security-client-accessor=
> [vm_1]security-client-accessor-pp=
> [vm_1]security-client-auth-init=
> [vm_1]security-client-authenticator=
> [vm_1]security-client-dhalgo=
> [vm_1]security-log-file=
> [vm_1]security-log-level=config
> [vm_1]security-manager=
> [vm_1]security-peer-auth-init=
> [vm_1]security-peer-authenticator=
> [vm_1]security-peer-verifymember-timeout=1000
> [vm_1]security-post-processor=
> [vm_1]server-bind-address=
> [vm_1]server-ssl-ciphers=any
> [vm_1]server-ssl-enabled=false
> [vm_1]server-ssl-keystore=
> [vm_1]server-ssl-keystore-password=
> [vm_1]server-ssl-keystore-type=
> [vm_1]server-ssl-protocols=any
> [vm_1]server-ssl-require-authentication=true
> [vm_1]server-ssl-truststore=
> [vm_1]server-ssl-truststore-password=
> [vm_1]socket-buffer-size=32768
> [vm_1]socket-lease-time=60000
> [vm_1]ssl-ciphers=any
> [vm_1]ssl-enabled=false
> [vm_1]ssl-protocols=any
> [vm_1]ssl-require-authentication=true
> [vm_1]start-dev-rest-api=false
> [vm_1]start-locator=
> [vm_1]statistic-archive-file=
> [vm_1]statistic-sample-rate=1000
> [vm_1]statistic-sampling-enabled=true
> [vm_1]tcp-port=0
> [vm_1]udp-fragment-size=60000
> [vm_1]udp-recv-buffer-size=1048576
> [vm_1]udp-send-buffer-size=65535
> [vm_1]user-command-packages=
> [vm_1][info 2016/07/25 23:28:46.634 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Starting membership services
> [vm_1][info 2016/07/25 23:28:46.642 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] JGroups channel created (took 8ms)
> [vm_1][info 2016/07/25 23:28:46.643 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] GemFire P2P Listener started on null
> [vm_1][info 2016/07/25 23:28:46.644 PDT <Geode Failure Detection Server
> thread 0> tid=0x8c1] Started failure detection server thread on
> cc6-co6.gemstone.com/10.118.33.108:4404.
> [vm_1][info 2016/07/25 23:28:46.645 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Attempting to join the distributed system through coordinator
> cc6-co6(18670:locator)<ec><v0>:1024 using address cc6-co6(18734)<ec>:1025
> [locator][info 2016/07/25 23:28:46.646 PDT <unicast receiver,cc6-co6-22518>
> tid=0x21] received join request from cc6-co6(18734)<ec>:1025
> [locator][info 2016/07/25 23:28:46.746 PDT <Geode Membership View Creator>
> tid=0x27] View Creator is processing 5 requests for the next membership view
> [locator][info 2016/07/25 23:28:46.746 PDT <Geode Membership View Creator>
> tid=0x27] preparing new view View[cc6-co6(18670:locator)<ec><v0>:1024|70]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}] shutdown: [cc6-co6(18734)<ec><v69>:1026,
> cc6-co6(18730)<ec><v68>:1025]
> [locator]failure detection ports: 4450 4404
> [locator][info 2016/07/25 23:28:46.747 PDT <Geode Membership View Creator>
> tid=0x27] finished waiting for responses to view preparation
> [vm_1][info 2016/07/25 23:28:46.747 PDT <unicast receiver,cc6-co6-42175>
> tid=0x8bd] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|70]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}] shutdown: [cc6-co6(18734)<ec><v69>:1026,
> cc6-co6(18730)<ec><v68>:1025]
> [vm_1]old view is: null
> [vm_1][info 2016/07/25 23:28:46.748 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Finished joining (took 104ms).
> [vm_1][info 2016/07/25 23:28:46.748 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Starting DistributionManager cc6-co6(18734)<ec><v70>:1025. (took
> 115 ms)
> [locator][info 2016/07/25 23:28:46.747 PDT <Geode Membership View Creator>
> tid=0x27] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|70]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}] shutdown: [cc6-co6(18734)<ec><v69>:1026,
> cc6-co6(18730)<ec><v68>:1025]
> [locator]old view is: View[cc6-co6(18670:locator)<ec><v0>:1024|69] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18730)<ec><v68>:1025{lead},
> cc6-co6(18734)<ec><v69>:1026]
> [locator][info 2016/07/25 23:28:46.747 PDT <Geode Membership View Creator>
> tid=0x27] Peer locator received new membership view:
> View[cc6-co6(18670:locator)<ec><v0>:1024|70] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead}]
> shutdown: [cc6-co6(18734)<ec><v69>:1026, cc6-co6(18730)<ec><v68>:1025]
> [locator][info 2016/07/25 23:28:46.748 PDT <Geode Membership View Creator>
> tid=0x27] sending new view View[cc6-co6(18670:locator)<ec><v0>:1024|70]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}] shutdown: [cc6-co6(18734)<ec><v69>:1026,
> cc6-co6(18730)<ec><v68>:1025]
> [locator]failure detection ports: 4450 4404
> [locator][info 2016/07/25 23:28:46.748 PDT <View Message Processor> tid=0x33]
> Membership: Processing addition < cc6-co6(18734)<ec><v70>:1025 >
> [locator][info 2016/07/25 23:28:46.748 PDT <View Message Processor> tid=0x33]
> Admitting member <cc6-co6(18734)<ec><v70>:1025>. Now there are 2 non-admin
> member(s).
> [vm_1][info 2016/07/25 23:28:46.748 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initial (distribution manager) view =
> View[cc6-co6(18670:locator)<ec><v0>:1024|70] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead}]
> shutdown: [cc6-co6(18734)<ec><v69>:1026, cc6-co6(18730)<ec><v68>:1025]
> [vm_1][info 2016/07/25 23:28:46.748 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Admitting member <cc6-co6(18670:locator)<ec><v0>:1024>. Now there
> are 1 non-admin member(s).
> [vm_1][info 2016/07/25 23:28:46.748 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Admitting member <cc6-co6(18734)<ec><v70>:1025>. Now there are 2
> non-admin member(s).
> [locator][info 2016/07/25 23:28:46.751 PDT <Pooled High Priority Message
> Processor 2> tid=0x66] Member cc6-co6(18734)<ec><v70>:1025 is equivalent or
> in the same redundancy zone.
> [vm_1][info 2016/07/25 23:28:46.752 PDT <P2P message reader for
> cc6-co6(18670:locator)<ec><v0>:1024 shared unordered uid=69 port=58213>
> tid=0x8c7] Member cc6-co6(18670:locator)<ec><v0>:1024 is equivalent or in the
> same redundancy zone.
> [vm_1][info 2016/07/25 23:28:46.764 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _monitoringRegion_10.118.33.108<v70>1025
> [vm_1][info 2016/07/25 23:28:46.764 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _monitoringRegion_10.118.33.108<v70>1025
> completed
> [vm_1][info 2016/07/25 23:28:46.768 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] The cache has been created with "use-cluster-configuration=false".
> It will not receive any cluster configuration
> [vm_1][info 2016/07/25 23:28:46.769 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region PdxTypes
> [vm_1][info 2016/07/25 23:28:46.769 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region PdxTypes completed
> [vm_1][info 2016/07/25 23:28:46.770 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: cc6-co6(18734)<ec><v70>:1025
> [vm_1] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$55/37221661.call
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$55/37221661@b8f85a6
> (took 139 ms)
> [vm_0][info 2016/07/25 23:28:46.817 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$52/1738566126.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$52/1738566126@6bd0d35e
> [vm_0][info 2016/07/25 23:28:46.819 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_0] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$52/1738566126.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$52/1738566126@6bd0d35e
> (took 2 ms)
> [vm_0][info 2016/07/25 23:28:46.824 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$56/596729083.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$56/596729083@66dd9b6d
> [vm_0]distributed system properties: {locators=localhost[37501],
> enable-cluster-configuration=false, use-cluster-configuration=false,
> mcast-port=0, disable-auto-reconnect=true, log-level=info}
> [vm_0][info 2016/07/25 23:28:46.827 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Startup Configuration:
> [vm_0] ### GemFire Properties defined with api ###
> [vm_0]disable-auto-reconnect=true
> [vm_0]enable-cluster-configuration=false
> [vm_0]locators=localhost[37501]
> [vm_0]log-level=info
> [vm_0]mcast-port=0
> [vm_0]use-cluster-configuration=false
> [vm_0]### GemFire Properties using default values ###
> [vm_0]ack-severe-alert-threshold=0
> [vm_0]ack-wait-threshold=15
> [vm_0]archive-disk-space-limit=0
> [vm_0]archive-file-size-limit=0
> [vm_0]async-distribution-timeout=0
> [vm_0]async-max-queue-size=8
> [vm_0]async-queue-timeout=60000
> [vm_0]bind-address=
> [vm_0]cache-xml-file=cache.xml
> [vm_0]cluster-configuration-dir=
> [vm_0]cluster-ssl-ciphers=any
> [vm_0]cluster-ssl-enabled=false
> [vm_0]cluster-ssl-keystore=
> [vm_0]cluster-ssl-keystore-password=
> [vm_0]cluster-ssl-keystore-type=
> [vm_0]cluster-ssl-protocols=any
> [vm_0]cluster-ssl-require-authentication=true
> [vm_0]cluster-ssl-truststore=
> [vm_0]cluster-ssl-truststore-password=
> [vm_0]conflate-events=server
> [vm_0]conserve-sockets=true
> [vm_0]delta-propagation=true
> [vm_0]deploy-working-dir=.
> [vm_0]disable-tcp=false
> [vm_0]distributed-system-id=-1
> [vm_0]distributed-transactions=false
> [vm_0]durable-client-id=
> [vm_0]durable-client-timeout=300
> [vm_0]enable-network-partition-detection=false
> [vm_0]enable-time-statistics=false
> [vm_0]enforce-unique-host=false
> [vm_0]gateway-ssl-ciphers=any
> [vm_0]gateway-ssl-enabled=false
> [vm_0]gateway-ssl-keystore=
> [vm_0]gateway-ssl-keystore-password=
> [vm_0]gateway-ssl-keystore-type=
> [vm_0]gateway-ssl-protocols=any
> [vm_0]gateway-ssl-require-authentication=true
> [vm_0]gateway-ssl-truststore=
> [vm_0]gateway-ssl-truststore-password=
> [vm_0]groups=
> [vm_0]http-service-bind-address=
> [vm_0]http-service-port=7070
> [vm_0]http-service-ssl-ciphers=any
> [vm_0]http-service-ssl-enabled=false
> [vm_0]http-service-ssl-keystore=
> [vm_0]http-service-ssl-keystore-password=
> [vm_0]http-service-ssl-keystore-type=
> [vm_0]http-service-ssl-protocols=any
> [vm_0]http-service-ssl-require-authentication=false
> [vm_0]http-service-ssl-truststore=
> [vm_0]http-service-ssl-truststore-password=
> [vm_0]jmx-manager=false
> [vm_0]jmx-manager-access-file=
> [vm_0]jmx-manager-bind-address=
> [vm_0]jmx-manager-hostname-for-clients=
> [vm_0]jmx-manager-http-port=7070
> [vm_0]jmx-manager-password-file=
> [vm_0]jmx-manager-port=1099
> [vm_0]jmx-manager-ssl=false
> [vm_0]jmx-manager-ssl-ciphers=any
> [vm_0]jmx-manager-ssl-enabled=false
> [vm_0]jmx-manager-ssl-keystore=
> [vm_0]jmx-manager-ssl-keystore-password=
> [vm_0]jmx-manager-ssl-keystore-type=
> [vm_0]jmx-manager-ssl-protocols=any
> [vm_0]jmx-manager-ssl-require-authentication=true
> [vm_0]jmx-manager-ssl-truststore=
> [vm_0]jmx-manager-ssl-truststore-password=
> [vm_0]jmx-manager-start=false
> [vm_0]jmx-manager-update-rate=2000
> [vm_0]load-cluster-configuration-from-dir=false
> [vm_0]locator-wait-time=0
> [vm_0]lock-memory=false
> [vm_0]log-disk-space-limit=0
> [vm_0]log-file=
> [vm_0]log-file-size-limit=0
> [vm_0]max-num-reconnect-tries=3
> [vm_0]max-wait-time-reconnect=60000
> [vm_0]mcast-address=239.192.81.1
> [vm_0]mcast-flow-control=1048576, 0.25, 5000
> [vm_0]mcast-recv-buffer-size=1048576
> [vm_0]mcast-send-buffer-size=65535
> [vm_0]mcast-ttl=32
> [vm_0]member-timeout=5000
> [vm_0]membership-port-range=1024-65535
> [vm_0]memcached-bind-address=
> [vm_0]memcached-port=0
> [vm_0]memcached-protocol=ASCII
> [vm_0]name=
> [vm_0]off-heap-memory-size=
> [vm_0]redis-bind-address=
> [vm_0]redis-password=
> [vm_0]redis-port=0
> [vm_0]redundancy-zone=
> [vm_0]remote-locators=
> [vm_0]remove-unresponsive-client=false
> [vm_0]roles=
> [vm_0]security-client-accessor=
> [vm_0]security-client-accessor-pp=
> [vm_0]security-client-auth-init=
> [vm_0]security-client-authenticator=
> [vm_0]security-client-dhalgo=
> [vm_0]security-log-file=
> [vm_0]security-log-level=config
> [vm_0]security-manager=
> [vm_0]security-peer-auth-init=
> [vm_0]security-peer-authenticator=
> [vm_0]security-peer-verifymember-timeout=1000
> [vm_0]security-post-processor=
> [vm_0]server-bind-address=
> [vm_0]server-ssl-ciphers=any
> [vm_0]server-ssl-enabled=false
> [vm_0]server-ssl-keystore=
> [vm_0]server-ssl-keystore-password=
> [vm_0]server-ssl-keystore-type=
> [vm_0]server-ssl-protocols=any
> [vm_0]server-ssl-require-authentication=true
> [vm_0]server-ssl-truststore=
> [vm_0]server-ssl-truststore-password=
> [vm_0]socket-buffer-size=32768
> [vm_0]socket-lease-time=60000
> [vm_0]ssl-ciphers=any
> [vm_0]ssl-enabled=false
> [vm_0]ssl-protocols=any
> [vm_0]ssl-require-authentication=true
> [vm_0]start-dev-rest-api=false
> [vm_0]start-locator=
> [vm_0]statistic-archive-file=
> [vm_0]statistic-sample-rate=1000
> [vm_0]statistic-sampling-enabled=true
> [vm_0]tcp-port=0
> [vm_0]udp-fragment-size=60000
> [vm_0]udp-recv-buffer-size=1048576
> [vm_0]udp-send-buffer-size=65535
> [vm_0]user-command-packages=
> [vm_0][info 2016/07/25 23:28:46.830 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Starting membership services
> [vm_0][info 2016/07/25 23:28:46.838 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] JGroups channel created (took 8ms)
> [vm_0][info 2016/07/25 23:28:46.841 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] GemFire P2P Listener started on null
> [vm_0][info 2016/07/25 23:28:46.841 PDT <Geode Failure Detection Server
> thread 0> tid=0x890] Started failure detection server thread on
> cc6-co6.gemstone.com/10.118.33.108:12497.
> [vm_0][info 2016/07/25 23:28:46.843 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Attempting to join the distributed system through coordinator
> cc6-co6(18670:locator)<ec><v0>:1024 using address cc6-co6(18730)<ec>:1026
> [locator][info 2016/07/25 23:28:46.843 PDT <unicast receiver,cc6-co6-22518>
> tid=0x21] received join request from cc6-co6(18730)<ec>:1026
> [locator][info 2016/07/25 23:28:47.144 PDT <Geode Membership View Creator>
> tid=0x27] View Creator is processing 1 requests for the next membership view
> [locator][info 2016/07/25 23:28:47.144 PDT <Geode Membership View Creator>
> tid=0x27] preparing new view View[cc6-co6(18670:locator)<ec><v0>:1024|71]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026]
> [locator]failure detection ports: 4450 4404 12497
> [locator][info 2016/07/25 23:28:47.145 PDT <Geode Membership View Creator>
> tid=0x27] finished waiting for responses to view preparation
> [vm_0][info 2016/07/25 23:28:47.145 PDT <unicast receiver,cc6-co6-36426>
> tid=0x88c] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|71]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026]
> [vm_0]old view is: null
> [vm_0][info 2016/07/25 23:28:47.145 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Finished joining (took 304ms).
> [locator][info 2016/07/25 23:28:47.145 PDT <Geode Membership View Creator>
> tid=0x27] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|71]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026]
> [locator]old view is: View[cc6-co6(18670:locator)<ec><v0>:1024|70] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead}]
> shutdown: [cc6-co6(18734)<ec><v69>:1026, cc6-co6(18730)<ec><v68>:1025]
> [locator][info 2016/07/25 23:28:47.145 PDT <Geode Membership View Creator>
> tid=0x27] Peer locator received new membership view:
> View[cc6-co6(18670:locator)<ec><v0>:1024|71] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead},
> cc6-co6(18730)<ec><v71>:1026]
> [locator][info 2016/07/25 23:28:47.145 PDT <Geode Membership View Creator>
> tid=0x27] sending new view View[cc6-co6(18670:locator)<ec><v0>:1024|71]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026]
> [locator]failure detection ports: 4450 4404 12497
> [locator][info 2016/07/25 23:28:47.146 PDT <View Message Processor> tid=0x33]
> Membership: Processing addition < cc6-co6(18730)<ec><v71>:1026 >
> [vm_0][info 2016/07/25 23:28:47.145 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Starting DistributionManager cc6-co6(18730)<ec><v71>:1026. (took
> 316 ms)
> [vm_0][info 2016/07/25 23:28:47.146 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initial (distribution manager) view =
> View[cc6-co6(18670:locator)<ec><v0>:1024|71] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead},
> cc6-co6(18730)<ec><v71>:1026]
> [vm_0][info 2016/07/25 23:28:47.146 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Admitting member <cc6-co6(18670:locator)<ec><v0>:1024>. Now there
> are 1 non-admin member(s).
> [vm_1][info 2016/07/25 23:28:47.146 PDT <unicast receiver,cc6-co6-42175>
> tid=0x8bd] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|71]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026]
> [vm_1]old view is: View[cc6-co6(18670:locator)<ec><v0>:1024|70] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead}]
> shutdown: [cc6-co6(18734)<ec><v69>:1026, cc6-co6(18730)<ec><v68>:1025]
> [vm_0][info 2016/07/25 23:28:47.146 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Admitting member <cc6-co6(18734)<ec><v70>:1025>. Now there are 2
> non-admin member(s).
> [vm_0][info 2016/07/25 23:28:47.146 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Admitting member <cc6-co6(18730)<ec><v71>:1026>. Now there are 3
> non-admin member(s).
> [locator][info 2016/07/25 23:28:47.146 PDT <View Message Processor> tid=0x33]
> Admitting member <cc6-co6(18730)<ec><v71>:1026>. Now there are 3 non-admin
> member(s).
> [vm_1][info 2016/07/25 23:28:47.148 PDT <View Message Processor> tid=0x8d4]
> Membership: Processing addition < cc6-co6(18730)<ec><v71>:1026 >
> [vm_1][info 2016/07/25 23:28:47.148 PDT <View Message Processor> tid=0x8d4]
> Admitting member <cc6-co6(18730)<ec><v71>:1026>. Now there are 3 non-admin
> member(s).
> [locator][info 2016/07/25 23:28:47.150 PDT <Pooled High Priority Message
> Processor 2> tid=0x66] Member cc6-co6(18730)<ec><v71>:1026 is equivalent or
> in the same redundancy zone.
> [vm_1][info 2016/07/25 23:28:47.150 PDT <Pooled High Priority Message
> Processor 1> tid=0x8d2] Member cc6-co6(18730)<ec><v71>:1026 is equivalent or
> in the same redundancy zone.
> [vm_0][info 2016/07/25 23:28:47.152 PDT <P2P message reader for
> cc6-co6(18734)<ec><v70>:1025 shared unordered uid=101 port=34394> tid=0x898]
> Member cc6-co6(18734)<ec><v70>:1025 is equivalent or in the same redundancy
> zone.
> [vm_0][info 2016/07/25 23:28:47.153 PDT <P2P message reader for
> cc6-co6(18670:locator)<ec><v0>:1024 shared unordered uid=70 port=34393>
> tid=0x897] Member cc6-co6(18670:locator)<ec><v0>:1024 is equivalent or in the
> same redundancy zone.
> [vm_0][info 2016/07/25 23:28:47.169 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _monitoringRegion_10.118.33.108<v71>1026
> [vm_0][info 2016/07/25 23:28:47.170 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _monitoringRegion_10.118.33.108<v71>1026
> completed
> [vm_0][info 2016/07/25 23:28:47.174 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] The cache has been created with "use-cluster-configuration=false".
> It will not receive any cluster configuration
> [vm_0][info 2016/07/25 23:28:47.177 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region PdxTypes
> [vm_0][info 2016/07/25 23:28:47.186 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region PdxTypes requesting initial image from
> cc6-co6(18734)<ec><v70>:1025
> [vm_0][info 2016/07/25 23:28:47.193 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] PdxTypes is done getting image from cc6-co6(18734)<ec><v70>:1025.
> isDeltaGII is false
> [vm_0][info 2016/07/25 23:28:47.193 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region PdxTypes completed
> [vm_0][info 2016/07/25 23:28:47.195 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region __PR
> [vm_0][info 2016/07/25 23:28:47.196 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region __PR completed
> [vm_0][info 2016/07/25 23:28:47.198 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region /region is born with prId=191 ident:#region
> [vm_0][info 2016/07/25 23:28:47.201 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region /index#_region.files is born with prId=192
> ident:#index#_region.files
> [vm_0][info 2016/07/25 23:28:47.205 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region /index#_region.chunks is born with prId=193
> ident:#index#_region.chunks
> [vm_0][info 2016/07/25 23:28:47.209 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region gatewayEventIdIndexMetaData
> [vm_0][info 2016/07/25 23:28:47.217 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region gatewayEventIdIndexMetaData completed
> [vm_0][info 2016/07/25 23:28:47.219 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] ConcurrentParallelGatewaySenderEventProcessor: dispatcher threads 1
> [vm_0][info 2016/07/25 23:28:47.221 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Created disk store
> DiskStore-0-0-com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest.returnCorrectResultsWhenMovePrimaryHappensOnIndexUpdate
> with unique id c7df94e2f13e4857-b57b12ac0cb4b587
> [vm_0][info 2016/07/25 23:28:47.222 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] recovery region initialization took 0 ms
> [vm_0][info 2016/07/25 23:28:47.226 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region
> /AsyncEventQueue_index#_region_PARALLEL_GATEWAY_SENDER_QUEUE is born with
> prId=194 ident:#AsyncEventQueue_index#_region_PARALLEL_GATEWAY_SENDER_QUEUE
> [vm_0][info 2016/07/25 23:28:47.229 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Started
> ParallelGatewaySender{id=AsyncEventQueue_index#_region,remoteDsId=-1,isRunning
> =true}
> [vm_0][info 2016/07/25 23:28:47.230 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_0] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$56/596729083.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$56/596729083@66dd9b6d
> (took 405 ms)
> [vm_1][info 2016/07/25 23:28:47.234 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$57/669645819.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$57/669645819@54f020c8
> [vm_1][info 2016/07/25 23:28:47.235 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region __PR
> [vm_1][info 2016/07/25 23:28:47.239 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region __PR requesting initial image from
> cc6-co6(18730)<ec><v71>:1026
> [vm_1][info 2016/07/25 23:28:47.241 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] __PR is done getting image from cc6-co6(18730)<ec><v71>:1026.
> isDeltaGII is false
> [vm_1][info 2016/07/25 23:28:47.241 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region __PR completed
> [vm_1][info 2016/07/25 23:28:47.244 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region /region is created with prId=191
> [vm_1][info 2016/07/25 23:28:47.250 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region /index#_region.files is created with prId=192
> [vm_1][info 2016/07/25 23:28:47.254 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region /index#_region.chunks is created with prId=193
> [vm_1][info 2016/07/25 23:28:47.259 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region gatewayEventIdIndexMetaData
> [vm_1][info 2016/07/25 23:28:47.261 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region gatewayEventIdIndexMetaData requesting initial image from
> cc6-co6(18730)<ec><v71>:1026
> [vm_1][info 2016/07/25 23:28:47.261 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] gatewayEventIdIndexMetaData is done getting image from
> cc6-co6(18730)<ec><v71>:1026. isDeltaGII is false
> [vm_1][info 2016/07/25 23:28:47.262 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region gatewayEventIdIndexMetaData completed
> [vm_1][info 2016/07/25 23:28:47.264 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] ConcurrentParallelGatewaySenderEventProcessor: dispatcher threads 1
> [vm_1][info 2016/07/25 23:28:47.267 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Created disk store
> DiskStore-0-1-com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest.returnCorrectResultsWhenMovePrimaryHappensOnIndexUpdate
> with unique id 903281c6a7f34277-a27b609b46365054
> [vm_1][info 2016/07/25 23:28:47.267 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] recovery region initialization took 0 ms
> [vm_1][info 2016/07/25 23:28:47.268 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region
> /AsyncEventQueue_index#_region_PARALLEL_GATEWAY_SENDER_QUEUE is created with
> prId=194
> [vm_1][info 2016/07/25 23:28:47.278 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Started
> ParallelGatewaySender{id=AsyncEventQueue_index#_region,remoteDsId=-1,isRunning
> =true}
> [vm_1][info 2016/07/25 23:28:47.289 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_1] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$57/669645819.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$57/669645819@54f020c8
> (took 54 ms)
> [vm_3][info 2016/07/25 23:28:47.323 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$9/1142979127.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$9/1142979127@19601318
> [vm_3]distributed system properties: {locators=localhost[37501],
> enable-cluster-configuration=false, use-cluster-configuration=false,
> mcast-port=0, disable-auto-reconnect=true, log-level=info}
> [vm_3]76.592: [GC (Metadata GC Threshold) [PSYoungGen:
> 59827K->6657K(112128K)] 65794K->12632K(369152K), 0.0053999 secs] [Times:
> user=0.01 sys=0.00, real=0.00 secs]
> [vm_3]76.597: [Full GC (Metadata GC Threshold) [PSYoungGen:
> 6657K->0K(112128K)] [ParOldGen: 5974K->9807K(106496K)]
> 12632K->9807K(218624K), [Metaspace: 20901K->20901K(1069056K)], 0.0247435
> secs] [Times: user=0.05 sys=0.00, real=0.03 secs]
> [vm_3][info 2016/07/25 23:28:48.003 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Startup Configuration:
> [vm_3] ### GemFire Properties defined with api ###
> [vm_3]disable-auto-reconnect=true
> [vm_3]enable-cluster-configuration=false
> [vm_3]locators=localhost[37501]
> [vm_3]log-level=info
> [vm_3]mcast-port=0
> [vm_3]use-cluster-configuration=false
> [vm_3]### GemFire Properties using default values ###
> [vm_3]ack-severe-alert-threshold=0
> [vm_3]ack-wait-threshold=15
> [vm_3]archive-disk-space-limit=0
> [vm_3]archive-file-size-limit=0
> [vm_3]async-distribution-timeout=0
> [vm_3]async-max-queue-size=8
> [vm_3]async-queue-timeout=60000
> [vm_3]bind-address=
> [vm_3]cache-xml-file=cache.xml
> [vm_3]cluster-configuration-dir=
> [vm_3]cluster-ssl-ciphers=any
> [vm_3]cluster-ssl-enabled=false
> [vm_3]cluster-ssl-keystore=
> [vm_3]cluster-ssl-keystore-password=
> [vm_3]cluster-ssl-keystore-type=
> [vm_3]cluster-ssl-protocols=any
> [vm_3]cluster-ssl-require-authentication=true
> [vm_3]cluster-ssl-truststore=
> [vm_3]cluster-ssl-truststore-password=
> [vm_3]conflate-events=server
> [vm_3]conserve-sockets=true
> [vm_3]delta-propagation=true
> [vm_3]deploy-working-dir=.
> [vm_3]disable-tcp=false
> [vm_3]distributed-system-id=-1
> [vm_3]distributed-transactions=false
> [vm_3]durable-client-id=
> [vm_3]durable-client-timeout=300
> [vm_3]enable-network-partition-detection=false
> [vm_3]enable-time-statistics=false
> [vm_3]enforce-unique-host=false
> [vm_3]gateway-ssl-ciphers=any
> [vm_3]gateway-ssl-enabled=false
> [vm_3]gateway-ssl-keystore=
> [vm_3]gateway-ssl-keystore-password=
> [vm_3]gateway-ssl-keystore-type=
> [vm_3]gateway-ssl-protocols=any
> [vm_3]gateway-ssl-require-authentication=true
> [vm_3]gateway-ssl-truststore=
> [vm_3]gateway-ssl-truststore-password=
> [vm_3]groups=
> [vm_3]http-service-bind-address=
> [vm_3]http-service-port=7070
> [vm_3]http-service-ssl-ciphers=any
> [vm_3]http-service-ssl-enabled=false
> [vm_3]http-service-ssl-keystore=
> [vm_3]http-service-ssl-keystore-password=
> [vm_3]http-service-ssl-keystore-type=
> [vm_3]http-service-ssl-protocols=any
> [vm_3]http-service-ssl-require-authentication=false
> [vm_3]http-service-ssl-truststore=
> [vm_3]http-service-ssl-truststore-password=
> [vm_3]jmx-manager=false
> [vm_3]jmx-manager-access-file=
> [vm_3]jmx-manager-bind-address=
> [vm_3]jmx-manager-hostname-for-clients=
> [vm_3]jmx-manager-http-port=7070
> [vm_3]jmx-manager-password-file=
> [vm_3]jmx-manager-port=1099
> [vm_3]jmx-manager-ssl=false
> [vm_3]jmx-manager-ssl-ciphers=any
> [vm_3]jmx-manager-ssl-enabled=false
> [vm_3]jmx-manager-ssl-keystore=
> [vm_3]jmx-manager-ssl-keystore-password=
> [vm_3]jmx-manager-ssl-keystore-type=
> [vm_3]jmx-manager-ssl-protocols=any
> [vm_3]jmx-manager-ssl-require-authentication=true
> [vm_3]jmx-manager-ssl-truststore=
> [vm_3]jmx-manager-ssl-truststore-password=
> [vm_3]jmx-manager-start=false
> [vm_3]jmx-manager-update-rate=2000
> [vm_3]load-cluster-configuration-from-dir=false
> [vm_3]locator-wait-time=0
> [vm_3]lock-memory=false
> [vm_3]log-disk-space-limit=0
> [vm_3]log-file=
> [vm_3]log-file-size-limit=0
> [vm_3]max-num-reconnect-tries=3
> [vm_3]max-wait-time-reconnect=60000
> [vm_3]mcast-address=239.192.81.1
> [vm_3]mcast-flow-control=1048576, 0.25, 5000
> [vm_3]mcast-recv-buffer-size=1048576
> [vm_3]mcast-send-buffer-size=65535
> [vm_3]mcast-ttl=32
> [vm_3]member-timeout=5000
> [vm_3]membership-port-range=1024-65535
> [vm_3]memcached-bind-address=
> [vm_3]memcached-port=0
> [vm_3]memcached-protocol=ASCII
> [vm_3]name=
> [vm_3]off-heap-memory-size=
> [vm_3]redis-bind-address=
> [vm_3]redis-password=
> [vm_3]redis-port=0
> [vm_3]redundancy-zone=
> [vm_3]remote-locators=
> [vm_3]remove-unresponsive-client=false
> [vm_3]roles=
> [vm_3]security-client-accessor=
> [vm_3]security-client-accessor-pp=
> [vm_3]security-client-auth-init=
> [vm_3]security-client-authenticator=
> [vm_3]security-client-dhalgo=
> [vm_3]security-log-file=
> [vm_3]security-log-level=config
> [vm_3]security-manager=
> [vm_3]security-peer-auth-init=
> [vm_3]security-peer-authenticator=
> [vm_3]security-peer-verifymember-timeout=1000
> [vm_3]security-post-processor=
> [vm_3]server-bind-address=
> [vm_3]server-ssl-ciphers=any
> [vm_3]server-ssl-enabled=false
> [vm_3]server-ssl-keystore=
> [vm_3]server-ssl-keystore-password=
> [vm_3]server-ssl-keystore-type=
> [vm_3]server-ssl-protocols=any
> [vm_3]server-ssl-require-authentication=true
> [vm_3]server-ssl-truststore=
> [vm_3]server-ssl-truststore-password=
> [vm_3]socket-buffer-size=32768
> [vm_3]socket-lease-time=60000
> [vm_3]ssl-ciphers=any
> [vm_3]ssl-enabled=false
> [vm_3]ssl-protocols=any
> [vm_3]ssl-require-authentication=true
> [vm_3]start-dev-rest-api=false
> [vm_3]start-locator=
> [vm_3]statistic-archive-file=
> [vm_3]statistic-sample-rate=1000
> [vm_3]statistic-sampling-enabled=true
> [vm_3]tcp-port=0
> [vm_3]udp-fragment-size=60000
> [vm_3]udp-recv-buffer-size=1048576
> [vm_3]udp-send-buffer-size=65535
> [vm_3]user-command-packages=
> [vm_3][info 2016/07/25 23:28:48.203 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Starting membership services
> [vm_3][info 2016/07/25 23:28:48.319 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] JGroups channel created (took 116ms)
> [vm_3][info 2016/07/25 23:28:48.331 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] GemFire P2P Listener started on null
> [vm_3][info 2016/07/25 23:28:48.333 PDT <Geode Failure Detection Server
> thread 0> tid=0x2a] Started failure detection server thread on
> cc6-co6.gemstone.com/10.118.33.108:60660.
> [vm_3][info 2016/07/25 23:28:48.345 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Attempting to join the distributed system through coordinator
> cc6-co6(18670:locator)<ec><v0>:1024 using address cc6-co6(18744)<ec>:1027
> [locator][info 2016/07/25 23:28:48.354 PDT <unicast receiver,cc6-co6-22518>
> tid=0x21] received join request from cc6-co6(18744)<ec>:1027
> [locator][info 2016/07/25 23:28:48.655 PDT <Geode Membership View Creator>
> tid=0x27] View Creator is processing 1 requests for the next membership view
> [locator][info 2016/07/25 23:28:48.655 PDT <Geode Membership View Creator>
> tid=0x27] preparing new view View[cc6-co6(18670:locator)<ec><v0>:1024|72]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026,
> cc6-co6(18744)<ec><v72>:1027]
> [locator]failure detection ports: 4450 4404 12497 60660
> [locator][info 2016/07/25 23:28:48.660 PDT <Geode Membership View Creator>
> tid=0x27] finished waiting for responses to view preparation
> [locator][info 2016/07/25 23:28:48.660 PDT <Geode Membership View Creator>
> tid=0x27] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|72]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026,
> cc6-co6(18744)<ec><v72>:1027]
> [locator]old view is: View[cc6-co6(18670:locator)<ec><v0>:1024|71] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead},
> cc6-co6(18730)<ec><v71>:1026]
> [vm_3][info 2016/07/25 23:28:48.660 PDT <unicast receiver,cc6-co6-47298>
> tid=0x26] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|72]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026,
> cc6-co6(18744)<ec><v72>:1027]
> [vm_3]old view is: null
> [locator][info 2016/07/25 23:28:48.660 PDT <Geode Membership View Creator>
> tid=0x27] Peer locator received new membership view:
> View[cc6-co6(18670:locator)<ec><v0>:1024|72] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead},
> cc6-co6(18730)<ec><v71>:1026, cc6-co6(18744)<ec><v72>:1027]
> [locator][info 2016/07/25 23:28:48.660 PDT <Geode Membership View Creator>
> tid=0x27] sending new view View[cc6-co6(18670:locator)<ec><v0>:1024|72]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026,
> cc6-co6(18744)<ec><v72>:1027]
> [locator]failure detection ports: 4450 4404 12497 60660
> [locator][info 2016/07/25 23:28:48.660 PDT <View Message Processor> tid=0x33]
> Membership: Processing addition < cc6-co6(18744)<ec><v72>:1027 >
> [locator][info 2016/07/25 23:28:48.660 PDT <View Message Processor> tid=0x33]
> Admitting member <cc6-co6(18744)<ec><v72>:1027>. Now there are 4 non-admin
> member(s).
> [vm_1][info 2016/07/25 23:28:48.661 PDT <unicast receiver,cc6-co6-42175>
> tid=0x8bd] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|72]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026,
> cc6-co6(18744)<ec><v72>:1027]
> [vm_1]old view is: View[cc6-co6(18670:locator)<ec><v0>:1024|71] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead},
> cc6-co6(18730)<ec><v71>:1026]
> [vm_0][info 2016/07/25 23:28:48.661 PDT <unicast receiver,cc6-co6-36426>
> tid=0x88c] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|72]
> members: [cc6-co6(18670:locator)<ec><v0>:1024,
> cc6-co6(18734)<ec><v70>:1025{lead}, cc6-co6(18730)<ec><v71>:1026,
> cc6-co6(18744)<ec><v72>:1027]
> [vm_0]old view is: View[cc6-co6(18670:locator)<ec><v0>:1024|71] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead},
> cc6-co6(18730)<ec><v71>:1026]
> [vm_1][info 2016/07/25 23:28:48.661 PDT <View Message Processor> tid=0x8d4]
> Membership: Processing addition < cc6-co6(18744)<ec><v72>:1027 >
> [vm_1][info 2016/07/25 23:28:48.662 PDT <View Message Processor> tid=0x8d4]
> Admitting member <cc6-co6(18744)<ec><v72>:1027>. Now there are 4 non-admin
> member(s).
> [vm_0][info 2016/07/25 23:28:48.663 PDT <View Message Processor> tid=0x8b0]
> Membership: Processing addition < cc6-co6(18744)<ec><v72>:1027 >
> [vm_0][info 2016/07/25 23:28:48.663 PDT <View Message Processor> tid=0x8b0]
> Admitting member <cc6-co6(18744)<ec><v72>:1027>. Now there are 4 non-admin
> member(s).
> [vm_3][info 2016/07/25 23:28:48.663 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Finished joining (took 330ms).
> [vm_3][info 2016/07/25 23:28:48.665 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Starting DistributionManager cc6-co6(18744)<ec><v72>:1027. (took
> 611 ms)
> [vm_3][info 2016/07/25 23:28:48.666 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initial (distribution manager) view =
> View[cc6-co6(18670:locator)<ec><v0>:1024|72] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18734)<ec><v70>:1025{lead},
> cc6-co6(18730)<ec><v71>:1026, cc6-co6(18744)<ec><v72>:1027]
> [vm_3][info 2016/07/25 23:28:48.666 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Admitting member <cc6-co6(18670:locator)<ec><v0>:1024>. Now there
> are 1 non-admin member(s).
> [vm_3][info 2016/07/25 23:28:48.667 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Admitting member <cc6-co6(18734)<ec><v70>:1025>. Now there are 2
> non-admin member(s).
> [vm_3][info 2016/07/25 23:28:48.667 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Admitting member <cc6-co6(18730)<ec><v71>:1026>. Now there are 3
> non-admin member(s).
> [vm_3][info 2016/07/25 23:28:48.668 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Admitting member <cc6-co6(18744)<ec><v72>:1027>. Now there are 4
> non-admin member(s).
> [vm_0][info 2016/07/25 23:28:48.700 PDT <Pooled High Priority Message
> Processor 2> tid=0x8a4] Member cc6-co6(18744)<ec><v72>:1027 is equivalent or
> in the same redundancy zone.
> [locator][info 2016/07/25 23:28:48.700 PDT <Pooled High Priority Message
> Processor 2> tid=0x66] Member cc6-co6(18744)<ec><v72>:1027 is equivalent or
> in the same redundancy zone.
> [vm_1][info 2016/07/25 23:28:48.700 PDT <Pooled High Priority Message
> Processor 3> tid=0x8dc] Member cc6-co6(18744)<ec><v72>:1027 is equivalent or
> in the same redundancy zone.
> [vm_3][info 2016/07/25 23:28:48.712 PDT <P2P message reader for
> cc6-co6(18670:locator)<ec><v0>:1024 shared unordered uid=71 port=33395>
> tid=0x35] Member cc6-co6(18670:locator)<ec><v0>:1024 is equivalent or in the
> same redundancy zone.
> [vm_3][info 2016/07/25 23:28:48.712 PDT <P2P message reader for
> cc6-co6(18730)<ec><v71>:1026 shared unordered uid=105 port=33393> tid=0x33]
> Member cc6-co6(18730)<ec><v71>:1026 is equivalent or in the same redundancy
> zone.
> [vm_3][info 2016/07/25 23:28:48.713 PDT <P2P message reader for
> cc6-co6(18734)<ec><v70>:1025 shared unordered uid=103 port=33394> tid=0x34]
> Member cc6-co6(18734)<ec><v70>:1025 is equivalent or in the same redundancy
> zone.
> [vm_3][info 2016/07/25 23:28:48.938 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _monitoringRegion_10.118.33.108<v72>1027
> [vm_3][info 2016/07/25 23:28:48.946 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _monitoringRegion_10.118.33.108<v72>1027
> completed
> [vm_3]78.409: [GC (Allocation Failure) [PSYoungGen: 96256K->12615K(112128K)]
> 106063K->22431K(218624K), 0.0107326 secs] [Times: user=0.04 sys=0.00,
> real=0.01 secs]
> [vm_3][info 2016/07/25 23:28:50.087 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] The cache has been created with "use-cluster-configuration=false".
> It will not receive any cluster configuration
> [vm_3][info 2016/07/25 23:28:50.106 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region PdxTypes
> [vm_3][info 2016/07/25 23:28:50.123 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region PdxTypes requesting initial image from
> cc6-co6(18730)<ec><v71>:1026
> [vm_3][info 2016/07/25 23:28:50.136 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] PdxTypes is done getting image from cc6-co6(18730)<ec><v71>:1026.
> isDeltaGII is false
> [vm_3][info 2016/07/25 23:28:50.137 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region PdxTypes completed
> [vm_3][info 2016/07/25 23:28:50.205 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region __PR
> [vm_3][info 2016/07/25 23:28:50.211 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region __PR requesting initial image from
> cc6-co6(18730)<ec><v71>:1026
> [vm_3][info 2016/07/25 23:28:50.251 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] __PR is done getting image from cc6-co6(18730)<ec><v71>:1026.
> isDeltaGII is false
> [vm_3][info 2016/07/25 23:28:50.251 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region __PR completed
> [vm_3][info 2016/07/25 23:28:50.279 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region /region is created with prId=191
> [vm_3][info 2016/07/25 23:28:50.341 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region /index#_region.files is created with prId=192
> [vm_3]79.244: [GC (Metadata GC Threshold) [PSYoungGen:
> 45318K->7615K(112128K)] 55133K->17430K(218624K), 0.0115630 secs] [Times:
> user=0.04 sys=0.00, real=0.01 secs]
> [vm_3]79.256: [Full GC (Metadata GC Threshold) [PSYoungGen:
> 7615K->0K(112128K)] [ParOldGen: 9815K->12669K(181248K)]
> 17430K->12669K(293376K), [Metaspace: 34865K->34865K(1081344K)], 0.1050533
> secs] [Times: user=0.39 sys=0.00, real=0.11 secs]
> [vm_3][info 2016/07/25 23:28:50.484 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region /index#_region.chunks is created with prId=193
> [vm_3][info 2016/07/25 23:28:50.542 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region gatewayEventIdIndexMetaData
> [vm_3][info 2016/07/25 23:28:50.550 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region gatewayEventIdIndexMetaData requesting initial image from
> cc6-co6(18734)<ec><v70>:1025
> [vm_3][info 2016/07/25 23:28:50.554 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] gatewayEventIdIndexMetaData is done getting image from
> cc6-co6(18734)<ec><v70>:1025. isDeltaGII is false
> [vm_3][info 2016/07/25 23:28:50.554 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region gatewayEventIdIndexMetaData completed
> [vm_3][info 2016/07/25 23:28:50.564 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] ConcurrentParallelGatewaySenderEventProcessor: dispatcher threads 1
> [vm_3][info 2016/07/25 23:28:50.610 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Created disk store
> DiskStore-0-3-com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest.returnCorrectResultsWhenMovePrimaryHappensOnIndexUpdate
> with unique id 5b26251651f14829-958124f7744c2fbd
> [vm_3][info 2016/07/25 23:28:50.623 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] recovery region initialization took 2 ms
> [vm_3][info 2016/07/25 23:28:50.639 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Partitioned Region
> /AsyncEventQueue_index#_region_PARALLEL_GATEWAY_SENDER_QUEUE is created with
> prId=194
> [vm_3][info 2016/07/25 23:28:50.660 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Started
> ParallelGatewaySender{id=AsyncEventQueue_index#_region,remoteDsId=-1,isRunning
> =true}
> [vm_3][info 2016/07/25 23:28:50.674 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_3] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$9/1142979127.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$9/1142979127@19601318
> (took 3350 ms)
> [vm_0][info 2016/07/25 23:28:50.678 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$58/677963080.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPeerPRRedundancyDUnitTest$$Lambda$58/677963080@75e89fea
> [vm_0][info 2016/07/25 23:28:50.679 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Paused
> ParallelGatewaySender{id=AsyncEventQueue_index#_region,remoteDsId=-1,isRunning
> =true}
> [vm_0][info 2016/07/25 23:28:51.4
> ...[truncated 3804337 chars]...
> _3] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$49/156043325.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$49/156043325@4104d043
> (took 447 ms)
> [vm_3][info 2016/07/25 23:30:34.492 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$42/1329698320.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$42/1329698320@5855bec2
> [vm_3][info 2016/07/25 23:30:34.493 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__region_1
> [vm_3][info 2016/07/25 23:30:34.497 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__region_1 completed
> [vm_3][info 2016/07/25 23:30:34.499 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.files_1
> [vm_3][info 2016/07/25 23:30:34.500 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.files_1 completed
> [vm_3][info 2016/07/25 23:30:34.501 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.chunks_1
> [vm_3][info 2016/07/25 23:30:34.502 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.chunks_1 completed
> [vm_3][info 2016/07/25 23:30:34.504 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_1
> [vm_3][info 2016/07/25 23:30:34.504 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_1
> completed
> [vm_1][info 2016/07/25 23:30:34.506 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region _B__region_1
> [vm_1][info 2016/07/25 23:30:34.510 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Region _B__region_1 requesting initial image from
> cc6-co6(18744)<ec><v112>:1027
> [vm_1][info 2016/07/25 23:30:34.510 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] _B__region_1 is done getting image from
> cc6-co6(18744)<ec><v112>:1027. isDeltaGII is false
> [vm_1][info 2016/07/25 23:30:34.510 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region _B__region_1 completed
> [vm_1][info 2016/07/25 23:30:34.512 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region _B__index#__region.files_1
> [vm_1][info 2016/07/25 23:30:34.513 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Region _B__index#__region.files_1 requesting initial image from
> cc6-co6(18744)<ec><v112>:1027
> [vm_1][info 2016/07/25 23:30:34.514 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] _B__index#__region.files_1 is done getting image from
> cc6-co6(18744)<ec><v112>:1027. isDeltaGII is false
> [vm_1][info 2016/07/25 23:30:34.514 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region _B__index#__region.files_1 completed
> [vm_1][info 2016/07/25 23:30:34.516 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region _B__index#__region.chunks_1
> [vm_1][info 2016/07/25 23:30:34.517 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Region _B__index#__region.chunks_1 requesting initial image from
> cc6-co6(18744)<ec><v112>:1027
> [vm_1][info 2016/07/25 23:30:34.518 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] _B__index#__region.chunks_1 is done getting image from
> cc6-co6(18744)<ec><v112>:1027. isDeltaGII is false
> [vm_1][info 2016/07/25 23:30:34.518 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region _B__index#__region.chunks_1 completed
> [vm_1][info 2016/07/25 23:30:34.519 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_1
> [vm_1][info 2016/07/25 23:30:34.521 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_1
> requesting initial image from cc6-co6(18744)<ec><v112>:1027
> [vm_1][info 2016/07/25 23:30:34.521 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2]
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_1 is
> done getting image from cc6-co6(18744)<ec><v112>:1027. isDeltaGII is false
> [vm_1][info 2016/07/25 23:30:34.521 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_1
> completed
> [vm_0][info 2016/07/25 23:30:34.530 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initializing region _B__region_2
> [vm_0][info 2016/07/25 23:30:34.531 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initialization of region _B__region_2 completed
> [vm_0][info 2016/07/25 23:30:34.532 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initializing region _B__index#__region.files_2
> [vm_0][info 2016/07/25 23:30:34.532 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initialization of region _B__index#__region.files_2 completed
> [vm_0][info 2016/07/25 23:30:34.535 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initializing region _B__index#__region.chunks_2
> [vm_0][info 2016/07/25 23:30:34.535 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initialization of region _B__index#__region.chunks_2 completed
> [vm_0][info 2016/07/25 23:30:34.536 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_2
> [vm_0][info 2016/07/25 23:30:34.537 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_2
> completed
> [vm_1][info 2016/07/25 23:30:34.539 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region _B__region_2
> [vm_1][info 2016/07/25 23:30:34.541 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Region _B__region_2 requesting initial image from
> cc6-co6(18730)<ec><v110>:1025
> [vm_1][info 2016/07/25 23:30:34.541 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] _B__region_2 is done getting image from
> cc6-co6(18730)<ec><v110>:1025. isDeltaGII is false
> [vm_1][info 2016/07/25 23:30:34.541 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region _B__region_2 completed
> [vm_1][info 2016/07/25 23:30:34.543 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region _B__index#__region.files_2
> [vm_1][info 2016/07/25 23:30:34.547 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Region _B__index#__region.files_2 requesting initial image from
> cc6-co6(18730)<ec><v110>:1025
> [vm_1][info 2016/07/25 23:30:34.548 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] _B__index#__region.files_2 is done getting image from
> cc6-co6(18730)<ec><v110>:1025. isDeltaGII is false
> [vm_1][info 2016/07/25 23:30:34.548 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region _B__index#__region.files_2 completed
> [vm_1][info 2016/07/25 23:30:34.551 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region _B__index#__region.chunks_2
> [vm_1][info 2016/07/25 23:30:34.553 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Region _B__index#__region.chunks_2 requesting initial image from
> cc6-co6(18730)<ec><v110>:1025
> [vm_1][info 2016/07/25 23:30:34.553 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] _B__index#__region.chunks_2 is done getting image from
> cc6-co6(18730)<ec><v110>:1025. isDeltaGII is false
> [vm_1][info 2016/07/25 23:30:34.553 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region _B__index#__region.chunks_2 completed
> [vm_1][info 2016/07/25 23:30:34.555 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_2
> [vm_1][info 2016/07/25 23:30:34.556 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_2
> requesting initial image from cc6-co6(18730)<ec><v110>:1025
> [vm_1][info 2016/07/25 23:30:34.556 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2]
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_2 is
> done getting image from cc6-co6(18730)<ec><v110>:1025. isDeltaGII is false
> [vm_1][info 2016/07/25 23:30:34.556 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_2
> completed
> [vm_3]183.460: [GC (Allocation Failure) [PSYoungGen: 141708K->9613K(147456K)]
> 155290K->23203K(328704K), 0.0162865 secs] [Times: user=0.03 sys=0.00,
> real=0.02 secs]
> [vm_3][info 2016/07/25 23:30:34.583 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_3] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$42/1329698320.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$42/1329698320@5855bec2
> (took 90 ms)
> [vm_0][info 2016/07/25 23:30:34.585 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$78/513086664.call
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$78/513086664@61274f36
> [vm_0][info 2016/07/25 23:30:34.795 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Got result: true
> [vm_0] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$78/513086664.call
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$78/513086664@61274f36
> (took 209 ms)
> [vm_3][info 2016/07/25 23:30:34.797 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$24/2019836676.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$24/2019836676@7069cc
> [vm_1][info 2016/07/25 23:30:34.798 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region _B__region_0
> [vm_1][info 2016/07/25 23:30:34.799 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region _B__region_0 completed
> [vm_1][info 2016/07/25 23:30:34.800 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region _B__index#__region.files_0
> [vm_1][info 2016/07/25 23:30:34.800 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region _B__index#__region.files_0 completed
> [vm_1][info 2016/07/25 23:30:34.802 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region _B__index#__region.chunks_0
> [vm_1][info 2016/07/25 23:30:34.802 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region _B__index#__region.chunks_0 completed
> [vm_1][info 2016/07/25 23:30:34.803 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_0
> [vm_1][info 2016/07/25 23:30:34.804 PDT <Pooled Waiting Message Processor 0>
> tid=0xbc2] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_0
> completed
> [vm_3][info 2016/07/25 23:30:34.806 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__region_0
> [vm_3][info 2016/07/25 23:30:34.808 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region _B__region_0 requesting initial image from
> cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:34.808 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] _B__region_0 is done getting image from
> cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.808 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__region_0 completed
> [vm_3][info 2016/07/25 23:30:34.810 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.files_0
> [vm_3][info 2016/07/25 23:30:34.811 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region _B__index#__region.files_0 requesting initial image from
> cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:34.812 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] _B__index#__region.files_0 is done getting image from
> cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.812 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.files_0 completed
> [vm_3][info 2016/07/25 23:30:34.813 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.chunks_0
> [vm_3][info 2016/07/25 23:30:34.814 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region _B__index#__region.chunks_0 requesting initial image from
> cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:34.815 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] _B__index#__region.chunks_0 is done getting image from
> cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.815 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.chunks_0 completed
> [vm_3][info 2016/07/25 23:30:34.816 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_0
> [vm_3][info 2016/07/25 23:30:34.817 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_0
> requesting initial image from cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:34.818 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12]
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_0 is
> done getting image from cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.818 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_0
> completed
> [vm_0][info 2016/07/25 23:30:34.822 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initializing region _B__region_3
> [vm_0][info 2016/07/25 23:30:34.823 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initialization of region _B__region_3 completed
> [vm_0][info 2016/07/25 23:30:34.824 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initializing region _B__index#__region.files_3
> [vm_0][info 2016/07/25 23:30:34.824 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initialization of region _B__index#__region.files_3 completed
> [vm_0][info 2016/07/25 23:30:34.825 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initializing region _B__index#__region.chunks_3
> [vm_0][info 2016/07/25 23:30:34.826 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initialization of region _B__index#__region.chunks_3 completed
> [vm_0][info 2016/07/25 23:30:34.830 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_3
> [vm_0][info 2016/07/25 23:30:34.831 PDT <Pooled Waiting Message Processor 1>
> tid=0xb96] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_3
> completed
> [vm_3][info 2016/07/25 23:30:34.832 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__region_3
> [vm_3][info 2016/07/25 23:30:34.834 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region _B__region_3 requesting initial image from
> cc6-co6(18730)<ec><v110>:1025
> [vm_3][info 2016/07/25 23:30:34.834 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] _B__region_3 is done getting image from
> cc6-co6(18730)<ec><v110>:1025. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.834 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__region_3 completed
> [vm_3][info 2016/07/25 23:30:34.836 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.files_3
> [vm_3][info 2016/07/25 23:30:34.837 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region _B__index#__region.files_3 requesting initial image from
> cc6-co6(18730)<ec><v110>:1025
> [vm_3][info 2016/07/25 23:30:34.838 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] _B__index#__region.files_3 is done getting image from
> cc6-co6(18730)<ec><v110>:1025. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.838 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.files_3 completed
> [vm_3][info 2016/07/25 23:30:34.839 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.chunks_3
> [vm_3][info 2016/07/25 23:30:34.840 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region _B__index#__region.chunks_3 requesting initial image from
> cc6-co6(18730)<ec><v110>:1025
> [vm_3][info 2016/07/25 23:30:34.841 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] _B__index#__region.chunks_3 is done getting image from
> cc6-co6(18730)<ec><v110>:1025. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.841 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.chunks_3 completed
> [vm_3][info 2016/07/25 23:30:34.844 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_3
> [vm_3][info 2016/07/25 23:30:34.845 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_3
> requesting initial image from cc6-co6(18730)<ec><v110>:1025
> [vm_3][info 2016/07/25 23:30:34.846 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12]
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_3 is
> done getting image from cc6-co6(18730)<ec><v110>:1025. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.846 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_3
> completed
> [vm_3][info 2016/07/25 23:30:34.852 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__region_4
> [vm_3][info 2016/07/25 23:30:34.855 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__region_4 completed
> [vm_3][info 2016/07/25 23:30:34.856 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.files_4
> [vm_3][info 2016/07/25 23:30:34.857 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.files_4 completed
> [vm_3][info 2016/07/25 23:30:34.858 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.chunks_4
> [vm_3][info 2016/07/25 23:30:34.858 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.chunks_4 completed
> [vm_3][info 2016/07/25 23:30:34.859 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_4
> [vm_3][info 2016/07/25 23:30:34.860 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_4
> completed
> [vm_0][info 2016/07/25 23:30:34.862 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initializing region _B__region_4
> [vm_0][info 2016/07/25 23:30:34.863 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Region _B__region_4 requesting initial image from
> cc6-co6(18744)<ec><v112>:1027
> [vm_0][info 2016/07/25 23:30:34.863 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] _B__region_4 is done getting image from
> cc6-co6(18744)<ec><v112>:1027. isDeltaGII is false
> [vm_0][info 2016/07/25 23:30:34.863 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initialization of region _B__region_4 completed
> [vm_0][info 2016/07/25 23:30:34.864 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initializing region _B__index#__region.files_4
> [vm_0][info 2016/07/25 23:30:34.865 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Region _B__index#__region.files_4 requesting initial image from
> cc6-co6(18744)<ec><v112>:1027
> [vm_0][info 2016/07/25 23:30:34.866 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] _B__index#__region.files_4 is done getting image from
> cc6-co6(18744)<ec><v112>:1027. isDeltaGII is false
> [vm_0][info 2016/07/25 23:30:34.866 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initialization of region _B__index#__region.files_4 completed
> [vm_0][info 2016/07/25 23:30:34.866 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initializing region _B__index#__region.chunks_4
> [vm_0][info 2016/07/25 23:30:34.867 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Region _B__index#__region.chunks_4 requesting initial image from
> cc6-co6(18744)<ec><v112>:1027
> [vm_0][info 2016/07/25 23:30:34.868 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] _B__index#__region.chunks_4 is done getting image from
> cc6-co6(18744)<ec><v112>:1027. isDeltaGII is false
> [vm_0][info 2016/07/25 23:30:34.868 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initialization of region _B__index#__region.chunks_4 completed
> [vm_0][info 2016/07/25 23:30:34.869 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_4
> [vm_0][info 2016/07/25 23:30:34.870 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_4
> requesting initial image from cc6-co6(18744)<ec><v112>:1027
> [vm_0][info 2016/07/25 23:30:34.870 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77]
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_4 is
> done getting image from cc6-co6(18744)<ec><v112>:1027. isDeltaGII is false
> [vm_0][info 2016/07/25 23:30:34.870 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_4
> completed
> [vm_1][info 2016/07/25 23:30:34.882 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initializing region _B__region_5
> [vm_1][info 2016/07/25 23:30:34.883 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initialization of region _B__region_5 completed
> [vm_1][info 2016/07/25 23:30:34.884 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initializing region _B__index#__region.files_5
> [vm_1][info 2016/07/25 23:30:34.885 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initialization of region _B__index#__region.files_5 completed
> [vm_1][info 2016/07/25 23:30:34.886 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initializing region _B__index#__region.chunks_5
> [vm_1][info 2016/07/25 23:30:34.886 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initialization of region _B__index#__region.chunks_5 completed
> [vm_1][info 2016/07/25 23:30:34.888 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_5
> [vm_1][info 2016/07/25 23:30:34.888 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_5
> completed
> [vm_0][info 2016/07/25 23:30:34.890 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initializing region _B__region_5
> [vm_0][info 2016/07/25 23:30:34.892 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Region _B__region_5 requesting initial image from
> cc6-co6(18734)<ec><v111>:1026
> [vm_0][info 2016/07/25 23:30:34.893 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] _B__region_5 is done getting image from
> cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_0][info 2016/07/25 23:30:34.893 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initialization of region _B__region_5 completed
> [vm_0][info 2016/07/25 23:30:34.894 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initializing region _B__index#__region.files_5
> [vm_0][info 2016/07/25 23:30:34.896 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Region _B__index#__region.files_5 requesting initial image from
> cc6-co6(18734)<ec><v111>:1026
> [vm_0][info 2016/07/25 23:30:34.896 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] _B__index#__region.files_5 is done getting image from
> cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_0][info 2016/07/25 23:30:34.896 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initialization of region _B__index#__region.files_5 completed
> [vm_0][info 2016/07/25 23:30:34.897 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initializing region _B__index#__region.chunks_5
> [vm_0][info 2016/07/25 23:30:34.898 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Region _B__index#__region.chunks_5 requesting initial image from
> cc6-co6(18734)<ec><v111>:1026
> [vm_0][info 2016/07/25 23:30:34.899 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] _B__index#__region.chunks_5 is done getting image from
> cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_0][info 2016/07/25 23:30:34.899 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initialization of region _B__index#__region.chunks_5 completed
> [vm_0][info 2016/07/25 23:30:34.900 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_5
> [vm_0][info 2016/07/25 23:30:34.901 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_5
> requesting initial image from cc6-co6(18734)<ec><v111>:1026
> [vm_0][info 2016/07/25 23:30:34.902 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77]
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_5 is
> done getting image from cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_0][info 2016/07/25 23:30:34.902 PDT <Pooled Waiting Message Processor 0>
> tid=0xb77] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_5
> completed
> [vm_1][info 2016/07/25 23:30:34.905 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initializing region _B__region_6
> [vm_1][info 2016/07/25 23:30:34.906 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initialization of region _B__region_6 completed
> [vm_1][info 2016/07/25 23:30:34.907 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initializing region _B__index#__region.files_6
> [vm_1][info 2016/07/25 23:30:34.908 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initialization of region _B__index#__region.files_6 completed
> [vm_1][info 2016/07/25 23:30:34.909 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initializing region _B__index#__region.chunks_6
> [vm_1][info 2016/07/25 23:30:34.910 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initialization of region _B__index#__region.chunks_6 completed
> [vm_1][info 2016/07/25 23:30:34.911 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_6
> [vm_1][info 2016/07/25 23:30:34.911 PDT <Pooled Waiting Message Processor 1>
> tid=0xbe4] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_6
> completed
> [vm_3][info 2016/07/25 23:30:34.913 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__region_6
> [vm_3][info 2016/07/25 23:30:34.915 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region _B__region_6 requesting initial image from
> cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:34.916 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] _B__region_6 is done getting image from
> cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.916 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__region_6 completed
> [vm_3][info 2016/07/25 23:30:34.920 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.files_6
> [vm_3][info 2016/07/25 23:30:34.926 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region _B__index#__region.files_6 requesting initial image from
> cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:34.926 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] _B__index#__region.files_6 is done getting image from
> cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.926 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.files_6 completed
> [vm_3][info 2016/07/25 23:30:34.928 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region _B__index#__region.chunks_6
> [vm_3][info 2016/07/25 23:30:34.930 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region _B__index#__region.chunks_6 requesting initial image from
> cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:34.930 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] _B__index#__region.chunks_6 is done getting image from
> cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.930 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region _B__index#__region.chunks_6 completed
> [vm_3][info 2016/07/25 23:30:34.932 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initializing region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_6
> [vm_3][info 2016/07/25 23:30:34.934 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_6
> requesting initial image from cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:34.935 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12]
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_6 is
> done getting image from cc6-co6(18734)<ec><v111>:1026. isDeltaGII is false
> [vm_3][info 2016/07/25 23:30:34.935 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Initialization of region
> _B__AsyncEventQueue__index#__region__PARALLEL__GATEWAY__SENDER__QUEUE_6
> completed
> [vm_3][info 2016/07/25 23:30:34.945 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_3] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$24/2019836676.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$24/2019836676@7069cc
> (took 148 ms)
> [vm_3][info 2016/07/25 23:30:34.946 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$24/2019836676.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$24/2019836676@17fa466c
> [vm_3][info 2016/07/25 23:30:34.949 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_3] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$24/2019836676.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesBase$$Lambda$24/2019836676@17fa466c
> (took 2 ms)
> [vm_0][info 2016/07/25 23:30:34.950 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPRBase$$Lambda$63/930256572.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPRBase$$Lambda$63/930256572@47a6e557
> [vm_0][info 2016/07/25 23:30:34.950 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_0] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPRBase$$Lambda$63/930256572.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPRBase$$Lambda$63/930256572@47a6e557
> (took 0 ms)
> [vm_1][info 2016/07/25 23:30:34.951 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPRBase$$Lambda$63/498054385.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPRBase$$Lambda$63/498054385@561dc4fc
> [vm_1][info 2016/07/25 23:30:34.951 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_1] from
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPRBase$$Lambda$63/498054385.run
> with 0 args on object:
> com.gemstone.gemfire.cache.lucene.LuceneQueriesPRBase$$Lambda$63/498054385@561dc4fc
> (took 0 ms)
> [vm_0][info 2016/07/25 23:30:34.956 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$14/303647603.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$14/303647603@2ccb5725
> [vm_0][info 2016/07/25 23:30:34.956 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] GemFireCache[id = 79898859; isClosing = true; isShutDownAll =
> false; created = Mon Jul 25 23:30:33 PDT 2016; server = false; copyOnRead =
> false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_0][info 2016/07/25 23:30:34.982 PDT <BatchRemovalThread> tid=0xb8e] The
> QueueRemovalThread is done.
> [vm_0][info 2016/07/25 23:30:34.983 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Stopped
> ParallelGatewaySender{id=AsyncEventQueue_index#_region,remoteDsId=-1,isRunning
> =false}
> [vm_3][warn 2016/07/25 23:30:34.985 PDT <PartitionedRegion Message
> Processor1> tid=0x358] Redundancy has dropped below 1 configured copies to 0
> actual copies for /index#_region.chunks
> [vm_1][warn 2016/07/25 23:30:34.984 PDT <PartitionedRegion Message
> Processor1> tid=0xbe5] Redundancy has dropped below 1 configured copies to 0
> actual copies for /index#_region.chunks
> [vm_1][warn 2016/07/25 23:30:34.991 PDT <PartitionedRegion Message
> Processor1> tid=0xbe5] Redundancy has dropped below 1 configured copies to 0
> actual copies for /AsyncEventQueue_index#_region_PARALLEL_GATEWAY_SENDER_QUEUE
> [vm_3][warn 2016/07/25 23:30:34.991 PDT <PartitionedRegion Message
> Processor1> tid=0x358] Redundancy has dropped below 1 configured copies to 0
> actual copies for /AsyncEventQueue_index#_region_PARALLEL_GATEWAY_SENDER_QUEUE
> [vm_1][warn 2016/07/25 23:30:34.993 PDT <PartitionedRegion Message
> Processor1> tid=0xbe5] Redundancy has dropped below 1 configured copies to 0
> actual copies for /region
> [vm_3][warn 2016/07/25 23:30:34.993 PDT <PartitionedRegion Message
> Processor1> tid=0x358] Redundancy has dropped below 1 configured copies to 0
> actual copies for /region
> [vm_1][warn 2016/07/25 23:30:34.994 PDT <PartitionedRegion Message
> Processor1> tid=0xbe5] Redundancy has dropped below 1 configured copies to 0
> actual copies for /index#_region.files
> [vm_3][warn 2016/07/25 23:30:34.994 PDT <PartitionedRegion Message
> Processor1> tid=0x358] Redundancy has dropped below 1 configured copies to 0
> actual copies for /index#_region.files
> [vm_0][info 2016/07/25 23:30:35.002 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_0] from
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$14/303647603.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$14/303647603@2ccb5725
> (took 46 ms)
> [vm_1][info 2016/07/25 23:30:35.003 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/1928058397.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/1928058397@125d5e77
> [vm_1][info 2016/07/25 23:30:35.004 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] GemFireCache[id = 1609637974; isClosing = true; isShutDownAll =
> false; created = Mon Jul 25 23:30:33 PDT 2016; server = false; copyOnRead =
> false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_1][info 2016/07/25 23:30:35.009 PDT <BatchRemovalThread> tid=0xbdc] The
> QueueRemovalThread is done.
> [vm_1][info 2016/07/25 23:30:35.009 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Stopped
> ParallelGatewaySender{id=AsyncEventQueue_index#_region,remoteDsId=-1,isRunning
> =true}
> [vm_1][info 2016/07/25 23:30:35.027 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_1] from
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/1928058397.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$9/1928058397@125d5e77
> (took 23 ms)
> [vm_2][info 2016/07/25 23:30:35.028 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/721238299.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/721238299@2e4ce1ce
> [vm_2][info 2016/07/25 23:30:35.029 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_2] from
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/721238299.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/721238299@2e4ce1ce
> (took 0 ms)
> [vm_3][info 2016/07/25 23:30:35.029 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/350815370.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/350815370@23bcbb57
> [vm_3][info 2016/07/25 23:30:35.030 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] GemFireCache[id = 1660963560; isClosing = true; isShutDownAll =
> false; created = Mon Jul 25 23:30:34 PDT 2016; server = false; copyOnRead =
> false; lockLease = 120; lockTimeout = 60]: Now closing.
> [vm_3][info 2016/07/25 23:30:35.070 PDT <BatchRemovalThread> tid=0x357] The
> QueueRemovalThread is done.
> [vm_3][info 2016/07/25 23:30:35.071 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Stopped
> ParallelGatewaySender{id=AsyncEventQueue_index#_region,remoteDsId=-1,isRunning
> =false}
> [vm_3][info 2016/07/25 23:30:35.134 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_3] from
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/350815370.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.cache.internal.JUnit4CacheTestCase$$Lambda$4/350815370@23bcbb57
> (took 104 ms)
> [vm_0][info 2016/07/25 23:30:35.135 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_0][info 2016/07/25 23:30:35.135 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] 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/25 23:30:35.136 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_1][info 2016/07/25 23:30:35.136 PDT <RMI TCP Connection(5)-10.118.33.108>
> 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/25 23:30:35.137 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_2][info 2016/07/25 23:30:35.137 PDT <RMI TCP Connection(5)-10.118.33.108>
> 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/25 23:30:35.137 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(tearDownCreationStackGenerator)
> [vm_3][info 2016/07/25 23:30:35.138 PDT <RMI TCP Connection(1)-10.118.33.108>
> 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/25 23:30:35.138 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(tearDownVM)
> [vm_0][info 2016/07/25 23:30:35.139 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Shutting down DistributionManager cc6-co6(18730)<ec><v110>:1025.
> [vm_1][info 2016/07/25 23:30:35.140 PDT <Pooled High Priority Message
> Processor 2> tid=0xbd4] received leave request from
> cc6-co6(18730)<ec><v110>:1025 for cc6-co6(18730)<ec><v110>:1025
> [vm_1][info 2016/07/25 23:30:35.140 PDT <Pooled High Priority Message
> Processor 2> tid=0xbd4] Member at cc6-co6(18730)<ec><v110>:1025 gracefully
> left the distributed cache: shutdown message received
> [vm_3][info 2016/07/25 23:30:35.140 PDT <Pooled High Priority Message
> Processor 1> tid=0x34c] received leave request from
> cc6-co6(18730)<ec><v110>:1025 for cc6-co6(18730)<ec><v110>:1025
> [vm_3][info 2016/07/25 23:30:35.140 PDT <Pooled High Priority Message
> Processor 1> tid=0x34c] Member at cc6-co6(18730)<ec><v110>:1025 gracefully
> left the distributed cache: shutdown message received
> [locator][info 2016/07/25 23:30:35.141 PDT <Pooled High Priority Message
> Processor 2> tid=0x66] received leave request from
> cc6-co6(18730)<ec><v110>:1025 for cc6-co6(18730)<ec><v110>:1025
> [locator][info 2016/07/25 23:30:35.141 PDT <Pooled High Priority Message
> Processor 2> tid=0x66] Member at cc6-co6(18730)<ec><v110>:1025 gracefully
> left the distributed cache: shutdown message received
> [vm_0][info 2016/07/25 23:30:35.241 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Now closing distribution for cc6-co6(18730)<ec><v110>:1025
> [vm_0][info 2016/07/25 23:30:35.241 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Stopping membership services
> [locator][info 2016/07/25 23:30:35.242 PDT <unicast receiver,cc6-co6-22518>
> tid=0x21] received leave request from cc6-co6(18730)<ec><v110>:1025 for
> cc6-co6(18730)<ec><v110>:1025
> [vm_0][info 2016/07/25 23:30:35.242 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] GMSHealthMonitor server socket is closed in stopServices().
> [vm_0][info 2016/07/25 23:30:35.242 PDT <Geode Failure Detection Server
> thread 0> tid=0xb74] GMSHealthMonitor server thread exiting
> [vm_1][info 2016/07/25 23:30:35.242 PDT <unicast receiver,cc6-co6-20244>
> tid=0xbbb] received leave request from cc6-co6(18730)<ec><v110>:1025 for
> cc6-co6(18730)<ec><v110>:1025
> [vm_0][info 2016/07/25 23:30:35.242 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] GMSHealthMonitor serverSocketExecutor is terminated
> [vm_3][info 2016/07/25 23:30:35.242 PDT <unicast receiver,cc6-co6-33060>
> tid=0x331] received leave request from cc6-co6(18730)<ec><v110>:1025 for
> cc6-co6(18730)<ec><v110>:1025
> [vm_0][info 2016/07/25 23:30:35.246 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] DistributionManager stopped in 107ms.
> [vm_0][info 2016/07/25 23:30:35.246 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Marking DistributionManager cc6-co6(18730)<ec><v110>:1025 as closed.
> [vm_0][info 2016/07/25 23:30:35.246 PDT <RMI TCP Connection(6)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_0] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on
> object: runnable(tearDownVM) (took 108 ms)
> [vm_1][info 2016/07/25 23:30:35.247 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(tearDownVM)
> [vm_1][info 2016/07/25 23:30:35.248 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Shutting down DistributionManager cc6-co6(18734)<ec><v111>:1026.
> [vm_3][info 2016/07/25 23:30:35.249 PDT <Pooled High Priority Message
> Processor 1> tid=0x34c] received leave request from
> cc6-co6(18734)<ec><v111>:1026 for cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:35.249 PDT <Pooled High Priority Message
> Processor 1> tid=0x34c] Member at cc6-co6(18734)<ec><v111>:1026 gracefully
> left the distributed cache: shutdown message received
> [locator][info 2016/07/25 23:30:35.249 PDT <Pooled High Priority Message
> Processor 2> tid=0x66] received leave request from
> cc6-co6(18734)<ec><v111>:1026 for cc6-co6(18734)<ec><v111>:1026
> [locator][info 2016/07/25 23:30:35.249 PDT <Pooled High Priority Message
> Processor 2> tid=0x66] Member at cc6-co6(18734)<ec><v111>:1026 gracefully
> left the distributed cache: shutdown message received
> [vm_1][info 2016/07/25 23:30:35.350 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Now closing distribution for cc6-co6(18734)<ec><v111>:1026
> [vm_1][info 2016/07/25 23:30:35.350 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Stopping membership services
> [vm_1][info 2016/07/25 23:30:35.350 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] GMSHealthMonitor server socket is closed in stopServices().
> [locator][info 2016/07/25 23:30:35.350 PDT <unicast receiver,cc6-co6-22518>
> tid=0x21] received leave request from cc6-co6(18734)<ec><v111>:1026 for
> cc6-co6(18734)<ec><v111>:1026
> [vm_3][info 2016/07/25 23:30:35.351 PDT <unicast receiver,cc6-co6-33060>
> tid=0x331] received leave request from cc6-co6(18734)<ec><v111>:1026 for
> cc6-co6(18734)<ec><v111>:1026
> [vm_1][info 2016/07/25 23:30:35.351 PDT <Geode Failure Detection Server
> thread 0> tid=0xbbf] GMSHealthMonitor server thread exiting
> [vm_1][info 2016/07/25 23:30:35.351 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] GMSHealthMonitor serverSocketExecutor is terminated
> [vm_1][info 2016/07/25 23:30:35.354 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] DistributionManager stopped in 106ms.
> [vm_1][info 2016/07/25 23:30:35.354 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Marking DistributionManager cc6-co6(18734)<ec><v111>:1026 as closed.
> [vm_1][info 2016/07/25 23:30:35.354 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_1] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on
> object: runnable(tearDownVM) (took 107 ms)
> [vm_2][info 2016/07/25 23:30:35.355 PDT <RMI TCP Connection(5)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(tearDownVM)
> [vm_2][info 2016/07/25 23:30:35.356 PDT <RMI TCP Connection(5)-10.118.33.108>
> 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/25 23:30:35.356 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Received method: com.gemstone.gemfire.test.dunit.NamedRunnable.run
> with 0 args on object: runnable(tearDownVM)
> [vm_3][info 2016/07/25 23:30:35.357 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Shutting down DistributionManager cc6-co6(18744)<ec><v112>:1027.
> [locator][info 2016/07/25 23:30:35.358 PDT <Pooled High Priority Message
> Processor 2> tid=0x66] received leave request from
> cc6-co6(18744)<ec><v112>:1027 for cc6-co6(18744)<ec><v112>:1027
> [locator][info 2016/07/25 23:30:35.358 PDT <Pooled High Priority Message
> Processor 2> tid=0x66] Member at cc6-co6(18744)<ec><v112>:1027 gracefully
> left the distributed cache: shutdown message received
> [locator][info 2016/07/25 23:30:35.459 PDT <Geode Membership View Creator>
> tid=0x27] View Creator is processing 5 requests for the next membership view
> [locator][info 2016/07/25 23:30:35.459 PDT <Geode Membership View Creator>
> tid=0x27] received new view: View[cc6-co6(18670:locator)<ec><v0>:1024|113]
> members: [cc6-co6(18670:locator)<ec><v0>:1024] shutdown:
> [cc6-co6(18734)<ec><v111>:1026, cc6-co6(18744)<ec><v112>:1027,
> cc6-co6(18730)<ec><v110>:1025]
> [locator]old view is: View[cc6-co6(18670:locator)<ec><v0>:1024|112] members:
> [cc6-co6(18670:locator)<ec><v0>:1024, cc6-co6(18730)<ec><v110>:1025{lead},
> cc6-co6(18734)<ec><v111>:1026, cc6-co6(18744)<ec><v112>:1027]
> [locator][info 2016/07/25 23:30:35.459 PDT <Geode Membership View Creator>
> tid=0x27] Peer locator received new membership view:
> View[cc6-co6(18670:locator)<ec><v0>:1024|113] members:
> [cc6-co6(18670:locator)<ec><v0>:1024] shutdown:
> [cc6-co6(18734)<ec><v111>:1026, cc6-co6(18744)<ec><v112>:1027,
> cc6-co6(18730)<ec><v110>:1025]
> [locator][info 2016/07/25 23:30:35.460 PDT <Geode Membership View Creator>
> tid=0x27] no recipients for new view aside from myself
> [vm_3][info 2016/07/25 23:30:35.460 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Now closing distribution for cc6-co6(18744)<ec><v112>:1027
> [vm_3][info 2016/07/25 23:30:35.460 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Stopping membership services
> [locator][info 2016/07/25 23:30:35.461 PDT <unicast receiver,cc6-co6-22518>
> tid=0x21] received leave request from cc6-co6(18744)<ec><v112>:1027 for
> cc6-co6(18744)<ec><v112>:1027
> [vm_3][info 2016/07/25 23:30:35.461 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] GMSHealthMonitor server socket is closed in stopServices().
> [vm_3][info 2016/07/25 23:30:35.461 PDT <Geode Failure Detection Server
> thread 0> tid=0x335] GMSHealthMonitor server thread exiting
> [vm_3][info 2016/07/25 23:30:35.461 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] GMSHealthMonitor serverSocketExecutor is terminated
> [vm_3][info 2016/07/25 23:30:35.469 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] DistributionManager stopped in 112ms.
> [vm_3][info 2016/07/25 23:30:35.469 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Marking DistributionManager cc6-co6(18744)<ec><v112>:1027 as closed.
> [vm_3][info 2016/07/25 23:30:35.469 PDT <RMI TCP Connection(1)-10.118.33.108>
> tid=0x12] Got result: null
> [vm_3] from com.gemstone.gemfire.test.dunit.NamedRunnable.run with 0 args on
> object: runnable(tearDownVM) (took 112 ms)
> [locator][info 2016/07/25 23:30:35.470 PDT <RMI TCP
> Connection(2)-10.118.33.108> tid=0x12] Received method:
> com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/496014553.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/496014553@783c14cf
> [locator][info 2016/07/25 23:30:35.470 PDT <RMI TCP
> Connection(2)-10.118.33.108> tid=0x12] Got result: null
> [locator] from
> com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/496014553.run
> with 0 args on object:
> com.gemstone.gemfire.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$6/496014553@783c14cf
> (took 0 ms)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
