Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/6609/
Java: 32bit/jdk-9-ea+171 -server -XX:+UseParallelGC

1 tests failed.
FAILED:  
org.apache.solr.cloud.CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap

Error Message:
Document mismatch on target after sync expected:<1000> but was:<0>

Stack Trace:
java.lang.AssertionError: Document mismatch on target after sync 
expected:<1000> but was:<0>
        at 
__randomizedtesting.SeedInfo.seed([A46AA559A737AD24:73BD8A2E13683563]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at org.junit.Assert.failNotEquals(Assert.java:647)
        at org.junit.Assert.assertEquals(Assert.java:128)
        at org.junit.Assert.assertEquals(Assert.java:472)
        at 
org.apache.solr.cloud.CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap(CdcrBootstrapTest.java:134)
        at 
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:563)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.base/java.lang.Thread.run(Thread.java:844)




Build Log:
[...truncated 11073 lines...]
   [junit4] Suite: org.apache.solr.cloud.CdcrBootstrapTest
   [junit4]   2> Creating dataDir: 
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\init-core-data-001
   [junit4]   2> 144257 WARN  
(SUITE-CdcrBootstrapTest-seed#[A46AA559A737AD24]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=7 numCloses=7
   [junit4]   2> 144257 INFO  
(SUITE-CdcrBootstrapTest-seed#[A46AA559A737AD24]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using TrieFields
   [junit4]   2> 144259 INFO  
(SUITE-CdcrBootstrapTest-seed#[A46AA559A737AD24]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, 
clientAuth=0.0/0.0)
   [junit4]   2> 144261 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.SolrTestCaseJ4 ###Starting testBootstrapWithSourceCluster
   [junit4]   2> 144261 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in 
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-target-001
   [junit4]   2> 144261 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 144264 INFO  (Thread-306) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 144264 INFO  (Thread-306) [    ] o.a.s.c.ZkTestServer Starting 
server
   [junit4]   2> 144271 ERROR (Thread-306) [    ] o.a.z.s.ZooKeeperServer 
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action 
on ERROR or SHUTDOWN server state changes
   [junit4]   2> 144362 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.ZkTestServer start zk server on port:56414
   [junit4]   2> 144449 INFO  (jetty-launcher-259-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 144449 INFO  (jetty-launcher-259-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@125626f{/solr,null,AVAILABLE}
   [junit4]   2> 144513 INFO  (jetty-launcher-259-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@392c64{HTTP/1.1,[http/1.1]}{127.0.0.1:56418}
   [junit4]   2> 144513 INFO  (jetty-launcher-259-thread-1) [    ] 
o.e.j.s.Server Started @145564ms
   [junit4]   2> 144514 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=56418}
   [junit4]   2> 144514 ERROR (jetty-launcher-259-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 144514 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 144514 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 144514 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 144514 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-04T08:29:19.891052400Z
   [junit4]   2> 144564 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 144590 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56414/solr
   [junit4]   2> 144864 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 144873 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:56418_solr
   [junit4]   2> 144877 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.c.Overseer Overseer 
(id=98078881195360259-127.0.0.1:56418_solr-n_0000000000) starting
   [junit4]   2> 144931 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:56418_solr
   [junit4]   2> 144949 INFO  
(OverseerStateUpdate-98078881195360259-127.0.0.1:56418_solr-n_0000000000) [    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 145376 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56418.solr.node' (registry 
'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@79abef
   [junit4]   2> 145390 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56418.solr.jvm' (registry 
'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@79abef
   [junit4]   2> 145390 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56418.solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@79abef
   [junit4]   2> 145396 INFO  (jetty-launcher-259-thread-1) [    ] 
o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath 
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-target-001\node1\.
   [junit4]   1> Target zkHost = 127.0.0.1:56414/solr
   [junit4]   2> 145567 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in 
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-source-001
   [junit4]   2> 145567 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 145569 INFO  (Thread-319) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 145569 INFO  (Thread-319) [    ] o.a.s.c.ZkTestServer Starting 
server
   [junit4]   2> 145594 ERROR (Thread-319) [    ] o.a.z.s.ZooKeeperServer 
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action 
on ERROR or SHUTDOWN server state changes
   [junit4]   2> 145668 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.ZkTestServer start zk server on port:56438
   [junit4]   2> 145706 INFO  (jetty-launcher-271-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 145708 INFO  (jetty-launcher-271-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@592dc1{/solr,null,AVAILABLE}
   [junit4]   2> 145723 INFO  (jetty-launcher-271-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@703c86{HTTP/1.1,[http/1.1]}{127.0.0.1:56442}
   [junit4]   2> 145723 INFO  (jetty-launcher-271-thread-1) [    ] 
o.e.j.s.Server Started @146774ms
   [junit4]   2> 145723 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=56442}
   [junit4]   2> 145724 ERROR (jetty-launcher-271-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 145724 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 145724 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 145724 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 145724 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-04T08:29:21.101273100Z
   [junit4]   2> 145733 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 145765 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56438/solr
   [junit4]   2> 145830 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 145831 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:56442_solr
   [junit4]   2> 145834 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.c.Overseer Overseer 
(id=98078881282064387-127.0.0.1:56442_solr-n_0000000000) starting
   [junit4]   2> 145850 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:56442_solr
   [junit4]   2> 145852 INFO  
(OverseerStateUpdate-98078881282064387-127.0.0.1:56442_solr-n_0000000000) [    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 146034 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56442.solr.node' (registry 
'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@79abef
   [junit4]   2> 146040 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56442.solr.jvm' (registry 
'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@79abef
   [junit4]   2> 146040 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56442.solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@79abef
   [junit4]   2> 146042 INFO  (jetty-launcher-271-thread-1) [    ] 
o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath 
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-source-001\node1\.
   [junit4]   2> 146244 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x15c72390ec90004, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
   [junit4]   2>        at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 146257 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x15c72390ec90005, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
   [junit4]   2>        at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 146356 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 146358 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56438/solr 
ready
   [junit4]   2> 146361 INFO  (qtp3661149-1355) [    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&nrtReplicas=1&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 146381 INFO  (OverseerThreadFactory-525-thread-1) [    ] 
o.a.s.c.CreateCollectionCmd Create collection cdcr-source
   [junit4]   2> 146586 INFO  (qtp3661149-1357) [    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&collection=cdcr-source&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 146589 INFO  (qtp3661149-1357) [    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 146699 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-source/state.json] for collection [cdcr-source] has 
occurred - updating... (live nodes size: [1])
   [junit4]   2> 147724 INFO  (qtp3661149-1357) [    ] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 7.0.0
   [junit4]   2> 147740 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but 
managed schema resource managed-schema not found - loading non-managed schema 
schema.xml instead
   [junit4]   2> 147745 INFO  (qtp3661149-1357) [    ] o.a.s.s.IndexSchema 
[cdcr-source_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 147745 INFO  (qtp3661149-1357) [    ] o.a.s.s.IndexSchema 
Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 147764 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at 
/configs/cdcr-source/managed-schema
   [junit4]   2> 147851 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in 
ZooKeeper, renamed the non-managed schema /configs/cdcr-source/schema.xml to 
/configs/cdcr-source/schema.xml.bak
   [junit4]   2> 147851 INFO  (qtp3661149-1357) [    ] o.a.s.c.CoreContainer 
Creating SolrCore 'cdcr-source_shard1_replica_n1' using configuration from 
collection cdcr-source, trusted=true
   [junit4]   2> 147852 INFO  (qtp3661149-1357) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_56442.solr.core.cdcr-source.shard1.replica_n1' (registry 
'solr.core.cdcr-source.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@79abef
   [junit4]   2> 147862 INFO  (qtp3661149-1357) [    ] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 147862 INFO  (qtp3661149-1357) [    ] o.a.s.c.SolrCore 
[[cdcr-source_shard1_replica_n1] ] Opening new SolrCore at 
[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-source-001\node1\cdcr-source_shard1_replica_n1],
 
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-source-001\node1\.\cdcr-source_shard1_replica_n1\data\]
   [junit4]   2> 148204 INFO  (qtp3661149-1357) [    ] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
   [junit4]   2> 148204 INFO  (qtp3661149-1357) [    ] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 148226 INFO  (qtp3661149-1357) [    ] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 148226 INFO  (qtp3661149-1357) [    ] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 148231 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1e38f7f[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 148248 INFO  (qtp3661149-1357) [    ] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/cdcr-source
   [junit4]   2> 148258 INFO  (qtp3661149-1357) [    ] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/cdcr-source
   [junit4]   2> 148258 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at 
/configs/cdcr-source/managed-schema
   [junit4]   2> 148285 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
   [junit4]   2> 148286 INFO  (qtp3661149-1357) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 148295 INFO  (qtp3661149-1357) [    ] 
o.a.s.h.CdcrBufferStateManager Created znode 
/collections/cdcr-source/cdcr/state/buffer
   [junit4]   2> 148300 INFO  (qtp3661149-1357) [    ] 
o.a.s.h.CdcrProcessStateManager Created znode 
/collections/cdcr-source/cdcr/state/process
   [junit4]   2> 148386 INFO  (qtp3661149-1357) [    ] o.a.s.u.UpdateLog Could 
not find max version in index or recent updates, using new clock 
1569262103442751488
   [junit4]   2> 148437 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@1e38f7f[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 148492 INFO  (qtp3661149-1357) [    ] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 148492 INFO  (qtp3661149-1357) [    ] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 148492 INFO  (qtp3661149-1357) [    ] o.a.s.c.SyncStrategy 
Sync replicas to http://127.0.0.1:56442/solr/cdcr-source_shard1_replica_n1/
   [junit4]   2> 148492 INFO  (qtp3661149-1357) [    ] o.a.s.c.SyncStrategy 
Sync Success - now sync replicas to me
   [junit4]   2> 148492 INFO  (qtp3661149-1357) [    ] o.a.s.c.SyncStrategy 
http://127.0.0.1:56442/solr/cdcr-source_shard1_replica_n1/ has no replicas
   [junit4]   2> 148492 INFO  (qtp3661149-1357) [    ] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 148545 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-source:shard1
   [junit4]   2> 148548 INFO  (qtp3661149-1357) [    ] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:56442/solr/cdcr-source_shard1_replica_n1/ shard1
   [junit4]   2> 148661 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-source/state.json] for collection [cdcr-source] has 
occurred - updating... (live nodes size: [1])
   [junit4]   2> 148736 INFO  (qtp3661149-1357) [    ] o.a.s.c.ZkController I 
am the leader, no recovery necessary
   [junit4]   2> 148756 INFO  (qtp3661149-1357) [    ] o.a.s.s.HttpSolrCall 
[admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&collection=cdcr-source&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=2169
   [junit4]   2> 148824 INFO  (qtp3661149-1355) [    ] 
o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 
30 seconds. Check all shard replicas
   [junit4]   2> 148884 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-source/state.json] for collection [cdcr-source] has 
occurred - updating... (live nodes size: [1])
   [junit4]   2> 149828 INFO  (qtp3661149-1355) [    ] o.a.s.s.HttpSolrCall 
[admin] webapp=null path=/admin/collections 
params={replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&nrtReplicas=1&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2}
 status=0 QTime=3459
   [junit4]   1> Adding 10 docs with commit=true, numDocs=100
   [junit4]   2> 149954 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=64
   [junit4]   2> 149956 INFO  (qtp3661149-1359) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262105089015808,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 149956 INFO  (qtp3661149-1359) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262105089015808
   [junit4]   2> 150024 INFO  (qtp3661149-1359) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@b310b6[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 150024 INFO  (qtp3661149-1359) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 150032 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@b310b6[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)))}
   [junit4]   2> 150036 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=80
   [junit4]   1> Adding 10 docs with commit=true, numDocs=200
   [junit4]   2> 150068 INFO  (qtp3661149-1360) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=29
   [junit4]   2> 150071 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262105209602048,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 150071 INFO  (qtp3661149-1362) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262105209602048
   [junit4]   2> 150337 INFO  (qtp3661149-1362) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1a64136[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 150337 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 150337 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@1a64136[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)
 Uninverting(_1(7.0.0):C100)))}
   [junit4]   2> 150337 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=269
   [junit4]   1> Adding 10 docs with commit=true, numDocs=300
   [junit4]   2> 150379 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=36
   [junit4]   2> 150379 INFO  (qtp3661149-1357) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262105532563456,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 150379 INFO  (qtp3661149-1357) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262105532563456
   [junit4]   2> 150501 INFO  
(OverseerCollectionConfigSetProcessor-98078881282064387-127.0.0.1:56442_solr-n_0000000000)
 [    ] o.a.s.c.OverseerTaskQueue Response ZK path: 
/overseer/collection-queue-work/qnr-0000000000 doesn't exist.  Requestor may 
have disconnected from ZooKeeper
   [junit4]   2> 150587 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@2e5d78[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 150588 INFO  (qtp3661149-1357) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 150592 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@2e5d78[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)
 Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100)))}
   [junit4]   2> 150592 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=210
   [junit4]   1> Adding 10 docs with commit=true, numDocs=400
   [junit4]   2> 150619 INFO  (qtp3661149-1355) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=21
   [junit4]   2> 150621 INFO  (qtp3661149-1358) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262105786318848,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 150621 INFO  (qtp3661149-1358) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262105786318848
   [junit4]   2> 150885 INFO  (qtp3661149-1358) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1c82c8e[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 150886 INFO  (qtp3661149-1358) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 150887 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@1c82c8e[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)
 Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) 
Uninverting(_3(7.0.0):C100)))}
   [junit4]   2> 150888 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=266
   [junit4]   1> Adding 10 docs with commit=true, numDocs=500
   [junit4]   2> 150916 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=22
   [junit4]   2> 150918 INFO  (qtp3661149-1360) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262106097745920,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 150918 INFO  (qtp3661149-1360) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262106097745920
   [junit4]   2> 150976 INFO  (qtp3661149-1360) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@b0576[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 150977 INFO  (qtp3661149-1360) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 150980 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@b0576[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)
 Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) 
Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100)))}
   [junit4]   2> 150980 INFO  (qtp3661149-1360) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=62
   [junit4]   1> Adding 10 docs with commit=true, numDocs=600
   [junit4]   2> 150992 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=10
   [junit4]   2> 150993 INFO  (qtp3661149-1361) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262106176389120,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 150993 INFO  (qtp3661149-1361) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262106176389120
   [junit4]   2> 151054 INFO  (qtp3661149-1361) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@b88473[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 151055 INFO  (qtp3661149-1361) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 151057 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@b88473[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)
 Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) 
Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) 
Uninverting(_5(7.0.0):C100)))}
   [junit4]   2> 151057 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=64
   [junit4]   1> Adding 10 docs with commit=true, numDocs=700
   [junit4]   2> 151071 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=12
   [junit4]   2> 151073 INFO  (qtp3661149-1355) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262106260275200,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 151073 INFO  (qtp3661149-1355) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262106260275200
   [junit4]   2> 151159 INFO  (qtp3661149-1355) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@3b495b[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 151160 INFO  (qtp3661149-1355) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 151162 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@3b495b[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)
 Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) 
Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) 
Uninverting(_5(7.0.0):C100) Uninverting(_6(7.0.0):C100)))}
   [junit4]   2> 151162 INFO  (qtp3661149-1355) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=89
   [junit4]   1> Adding 10 docs with commit=true, numDocs=800
   [junit4]   2> 151175 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=10
   [junit4]   2> 151176 INFO  (qtp3661149-1359) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262106368278528,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 151176 INFO  (qtp3661149-1359) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262106368278528
   [junit4]   2> 151247 INFO  (qtp3661149-1359) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1a91820[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 151248 INFO  (qtp3661149-1359) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 151249 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@1a91820[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)
 Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) 
Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) 
Uninverting(_5(7.0.0):C100) Uninverting(_6(7.0.0):C100) 
Uninverting(_7(7.0.0):C100)))}
   [junit4]   2> 151251 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=73
   [junit4]   1> Adding 10 docs with commit=true, numDocs=900
   [junit4]   2> 151263 INFO  (qtp3661149-1360) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=11
   [junit4]   2> 151266 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262106462650368,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 151266 INFO  (qtp3661149-1362) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262106462650368
   [junit4]   2> 151362 INFO  (qtp3661149-1362) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@addfd2[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 151363 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 151364 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@addfd2[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)
 Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) 
Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) 
Uninverting(_5(7.0.0):C100) Uninverting(_6(7.0.0):C100) 
Uninverting(_7(7.0.0):C100) Uninverting(_8(7.0.0):C100)))}
   [junit4]   2> 151364 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=99
   [junit4]   1> Adding 10 docs with commit=true, numDocs=1000
   [junit4]   2> 151378 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=11
   [junit4]   2> 151379 INFO  (qtp3661149-1357) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262106581139456,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 151379 INFO  (qtp3661149-1357) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262106581139456
   [junit4]   2> 151497 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@fcee73[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 151498 INFO  (qtp3661149-1357) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 151500 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@fcee73[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)
 Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) 
Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) 
Uninverting(_5(7.0.0):C100) Uninverting(_6(7.0.0):C100) 
Uninverting(_7(7.0.0):C100) Uninverting(_8(7.0.0):C100) 
Uninverting(_9(7.0.0):C100)))}
   [junit4]   2> 151501 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=122
   [junit4]   2> 151504 INFO  (qtp3661149-1355) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=cdcr-source:3&wt=javabin&version=2} hits=1000 status=0 
QTime=1
   [junit4]   2> 151529 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x15c7239099e0006, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
   [junit4]   2>        at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 151535 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 151537 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[A46AA559A737AD24]) 
[    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56414/solr 
ready
   [junit4]   2> 151541 INFO  (qtp1900015-1321) [    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=1&collection.configName=cdcr-target&name=cdcr-target&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 151545 INFO  (OverseerThreadFactory-517-thread-1) [    ] 
o.a.s.c.CreateCollectionCmd Create collection cdcr-target
   [junit4]   2> 151654 INFO  (qtp1900015-1322) [    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=cdcr-target&newCollection=true&name=cdcr-target_shard1_replica_n1&action=CREATE&numShards=1&collection=cdcr-target&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 151654 INFO  (qtp1900015-1322) [    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 151762 INFO  (zkCallback-266-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-target/state.json] for collection [cdcr-target] has 
occurred - updating... (live nodes size: [1])
   [junit4]   2> 152678 INFO  (qtp1900015-1322) [    ] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 7.0.0
   [junit4]   2> 152684 INFO  (qtp1900015-1322) [    ] 
o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but 
managed schema resource managed-schema not found - loading non-managed schema 
schema.xml instead
   [junit4]   2> 152689 INFO  (qtp1900015-1322) [    ] o.a.s.s.IndexSchema 
[cdcr-target_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 152692 INFO  (qtp1900015-1322) [    ] o.a.s.s.IndexSchema 
Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 152693 INFO  (qtp1900015-1322) [    ] 
o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at 
/configs/cdcr-target/managed-schema
   [junit4]   2> 152704 INFO  (qtp1900015-1322) [    ] 
o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in 
ZooKeeper, renamed the non-managed schema /configs/cdcr-target/schema.xml to 
/configs/cdcr-target/schema.xml.bak
   [junit4]   2> 152704 INFO  (qtp1900015-1322) [    ] o.a.s.c.CoreContainer 
Creating SolrCore 'cdcr-target_shard1_replica_n1' using configuration from 
collection cdcr-target, trusted=true
   [junit4]   2> 152705 INFO  (qtp1900015-1322) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_56418.solr.core.cdcr-target.shard1.replica_n1' (registry 
'solr.core.cdcr-target.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@79abef
   [junit4]   2> 152705 INFO  (qtp1900015-1322) [    ] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 152705 INFO  (qtp1900015-1322) [    ] o.a.s.c.SolrCore 
[[cdcr-target_shard1_replica_n1] ] Opening new SolrCore at 
[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-target-001\node1\cdcr-target_shard1_replica_n1],
 
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-target-001\node1\.\cdcr-target_shard1_replica_n1\data\]
   [junit4]   2> 152975 INFO  (qtp1900015-1322) [    ] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
   [junit4]   2> 152975 INFO  (qtp1900015-1322) [    ] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 152995 INFO  (qtp1900015-1322) [    ] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 152995 INFO  (qtp1900015-1322) [    ] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 152998 INFO  (qtp1900015-1322) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@27365b[cdcr-target_shard1_replica_n1] main]
   [junit4]   2> 153000 INFO  (qtp1900015-1322) [    ] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/cdcr-target
   [junit4]   2> 153005 INFO  (qtp1900015-1322) [    ] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/cdcr-target
   [junit4]   2> 153005 INFO  (qtp1900015-1322) [    ] 
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at 
/configs/cdcr-target/managed-schema
   [junit4]   2> 153006 INFO  (qtp1900015-1322) [    ] 
o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
   [junit4]   2> 153007 INFO  (qtp1900015-1322) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 153015 INFO  (qtp1900015-1322) [    ] 
o.a.s.h.CdcrBufferStateManager Created znode 
/collections/cdcr-target/cdcr/state/buffer
   [junit4]   2> 153019 INFO  (qtp1900015-1322) [    ] 
o.a.s.h.CdcrProcessStateManager Created znode 
/collections/cdcr-target/cdcr/state/process
   [junit4]   2> 153022 INFO  (qtp1900015-1322) [    ] o.a.s.u.UpdateLog Could 
not find max version in index or recent updates, using new clock 
1569262108303949824
   [junit4]   2> 153031 INFO  (searcherExecutor-534-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-target_shard1_replica_n1] Registered new searcher 
Searcher@27365b[cdcr-target_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 153041 INFO  (qtp1900015-1322) [    ] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 153041 INFO  (qtp1900015-1322) [    ] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 153041 INFO  (qtp1900015-1322) [    ] o.a.s.c.SyncStrategy 
Sync replicas to http://127.0.0.1:56418/solr/cdcr-target_shard1_replica_n1/
   [junit4]   2> 153041 INFO  (qtp1900015-1322) [    ] o.a.s.c.SyncStrategy 
Sync Success - now sync replicas to me
   [junit4]   2> 153041 INFO  (qtp1900015-1322) [    ] o.a.s.c.SyncStrategy 
http://127.0.0.1:56418/solr/cdcr-target_shard1_replica_n1/ has no replicas
   [junit4]   2> 153041 INFO  (qtp1900015-1322) [    ] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 153045 INFO  (zkCallback-266-thread-1) [    ] 
o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-target:shard1
   [junit4]   2> 153061 INFO  (qtp1900015-1322) [    ] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:56418/solr/cdcr-target_shard1_replica_n1/ shard1
   [junit4]   2> 153170 INFO  (zkCallback-266-thread-2) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-target/state.json] for collection [cdcr-target] has 
occurred - updating... (live nodes size: [1])
   [junit4]   2> 153220 INFO  (qtp1900015-1322) [    ] o.a.s.c.ZkController I 
am the leader, no recovery necessary
   [junit4]   2> 153224 INFO  (qtp1900015-1322) [    ] o.a.s.s.HttpSolrCall 
[admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=cdcr-target&newCollection=true&name=cdcr-target_shard1_replica_n1&action=CREATE&numShards=1&collection=cdcr-target&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=1569
   [junit4]   2> 153248 INFO  (qtp1900015-1321) [    ] 
o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 
30 seconds. Check all shard replicas
   [junit4]   2> 153352 INFO  (zkCallback-266-thread-2) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-target/state.json] for collection [cdcr-target] has 
occurred - updating... (live nodes size: [1])
   [junit4]   2> 153555 INFO  
(OverseerCollectionConfigSetProcessor-98078881195360259-127.0.0.1:56418_solr-n_0000000000)
 [    ] o.a.s.c.OverseerTaskQueue Response ZK path: 
/overseer/collection-queue-work/qnr-0000000000 doesn't exist.  Requestor may 
have disconnected from ZooKeeper
   [junit4]   2> 154249 INFO  (qtp1900015-1321) [    ] o.a.s.s.HttpSolrCall 
[admin] webapp=null path=/admin/collections 
params={replicationFactor=1&collection.configName=cdcr-target&name=cdcr-target&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2}
 status=0 QTime=2708
   [junit4]   2> 154261 INFO  (zkCallback-266-thread-2) [    ] 
o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: 
WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-target/cdcr/state/process @ cdcr-target:shard1
   [junit4]   2> 154261 INFO  (qtp1900015-1321) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={qt=/cdcr&_stateVer_=cdcr-target:3&action=start&wt=javabin&version=2} 
status=0 QTime=8
   [junit4]   2> 154262 INFO  (zkCallback-266-thread-2) [    ] 
o.a.s.h.CdcrProcessStateManager Received new CDCR process state from watcher: 
STARTED @ cdcr-target:shard1
   [junit4]   2> 154271 INFO  (qtp3661149-1358) [    ] o.a.s.c.c.ZkStateReader 
Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 154273 INFO  (qtp3661149-1358) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56414/solr ready
   [junit4]   2> 154281 INFO  (qtp1900015-1314) [    ] 
o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
   [junit4]   2> 154281 INFO  (qtp1900015-1314) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=1
   [junit4]   2> 154281 INFO  (qtp1900015-1318) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={_stateVer_=cdcr-target:3&action=COLLECTIONCHECKPOINT&wt=javabin&version=2}
 status=0 QTime=7
   [junit4]   2> 154281 INFO  (qtp3661149-1358) [    ] 
o.a.s.h.CdcrReplicatorManager Create new update log reader for target 
cdcr-target with checkpoint -1 @ cdcr-source:shard1
   [junit4]   2> 154281 INFO  (qtp3661149-1358) [    ] 
o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: 
cdcr-target, shard: shard1
   [junit4]   2> 154281 INFO  (qtp3661149-1358) [    ] 
o.a.s.h.CdcrReplicatorManager Submitting bootstrap task to executor
   [junit4]   2> 154289 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: 
WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-source/cdcr/state/process @ cdcr-source:shard1
   [junit4]   2> 154290 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={qt=/cdcr&_stateVer_=cdcr-source:3&action=start&wt=javabin&version=2} 
status=0 QTime=26
   [junit4]   2> 154290 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.h.CdcrProcessStateManager Received new CDCR process state from watcher: 
STARTED @ cdcr-source:shard1
   [junit4]   2> 154290 INFO  (cdcr-bootstrap-status-290-thread-1) [    ] 
o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: 
cdcr-target shard: shard1 leader: 
http://127.0.0.1:56418/solr/cdcr-target_shard1_replica_n1/
   [junit4]   2> 154304 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={qt=/cdcr&_stateVer_=cdcr-source:3&action=queues&wt=javabin&version=2} 
status=0 QTime=12
   [junit4]   1> Cdcr queue response: 
{responseHeader={status=0,QTime=12},queues={127.0.0.1:56414/solr={cdcr-target={queueSize=1010,lastTimestamp=}}},tlogTotalSize=47659,tlogTotalCount=10,updateLogSynchronizer=stopped}
   [junit4]   2> 154306 INFO  (qtp1900015-1318) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262109650321408,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 154307 INFO  (qtp1900015-1318) [    ] 
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 154311 INFO  (qtp1900015-1318) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 154311 INFO  (qtp1900015-1320) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={qt=/cdcr&masterUrl=http://127.0.0.1:56442/solr/cdcr-source_shard1_replica_n1/&action=BOOTSTRAP&wt=javabin&version=2}
 status=0 QTime=1
   [junit4]   2> 154312 INFO  (qtp1900015-1318) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-target:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=7
   [junit4]   2> 154314 INFO  (qtp1900015-1321) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=cdcr-target:3&wt=javabin&version=2} hits=0 status=0 
QTime=0
   [junit4]   2> 154318 INFO  (qtp1900015-1320) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={qt=/cdcr&action=BOOTSTRAP_STATUS&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 154318 INFO  (cdcr-bootstrap-status-290-thread-1) [    ] 
o.a.s.h.CdcrReplicatorManager CDCR bootstrap running for 1 seconds, sleeping 
for 2000 ms
   [junit4]   2> 154321 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, 
tlog=null}
   [junit4]   2> 154325 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262109670244352,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 154326 INFO  (qtp3661149-1362) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262109670244352
   [junit4]   2> 154514 INFO  (qtp3661149-1362) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@12da155[cdcr-source_shard1_replica_n1] realtime]
   [junit4]   2> 154514 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 154514 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={waitSearcher=true&openSearcher=false&commit=true&softCommit=false&commit_end_point=true&wt=javabin&version=2}
 status=0 QTime=190
   [junit4]   2> 154519 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 
QTime=0
   [junit4]   2> 154519 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Master's generation: 12
   [junit4]   2> 154519 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Master's version: 1496564969703
   [junit4]   2> 154519 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 154519 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 154519 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Starting replication process
   [junit4]   2> 154534 INFO  (qtp3661149-1361) [    ] 
o.a.s.h.ReplicationHandler Adding tlog files to list: [{size=4657, 
name=tlog.0000000000000000000.1569262105018761216}, {size=4778, 
name=tlog.0000000000000000001.1569262105176047616}, {size=4778, 
name=tlog.0000000000000000002.1569262105495863296}, {size=4778, 
name=tlog.0000000000000000003.1569262105762201600}, {size=4778, 
name=tlog.0000000000000000004.1569262106072580096}, {size=4778, 
name=tlog.0000000000000000005.1569262106165903360}, {size=4778, 
name=tlog.0000000000000000006.1569262106245595136}, {size=4778, 
name=tlog.0000000000000000007.1569262106355695616}, {size=4778, 
name=tlog.0000000000000000008.1569262106447970304}, {size=4778, 
name=tlog.0000000000000000009.1569262106568556544}]
   [junit4]   2> 154534 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&wt=javabin&version=2&command=filelist} 
status=0 QTime=14
   [junit4]   2> 154536 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Number of files in latest index in master: 11
   [junit4]   2> 154536 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Number of tlog files in master: 10
   [junit4]   2> 154543 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
   [junit4]   2> 154544 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Starting download (fullCopy=false) to 
MockDirectoryWrapper(RAMDirectory@4f6deb 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@14cc45c)
   [junit4]   2> 154545 INFO  (qtp3661149-1355) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a.fnm&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154548 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a.nvm&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154551 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a_Lucene50_0.pos&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154558 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a.fdt&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154561 INFO  (qtp3661149-1360) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a_Lucene50_0.doc&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154567 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a_Lucene50_0.tim&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154570 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a.si&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154578 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a.fdx&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154580 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a.nvd&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154584 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=_a_Lucene50_0.tip&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154586 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&file=segments_c&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154588 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Starting download of tlog files from master: [{size=4657, 
name=tlog.0000000000000000000.1569262105018761216}, {size=4778, 
name=tlog.0000000000000000001.1569262105176047616}, {size=4778, 
name=tlog.0000000000000000002.1569262105495863296}, {size=4778, 
name=tlog.0000000000000000003.1569262105762201600}, {size=4778, 
name=tlog.0000000000000000004.1569262106072580096}, {size=4778, 
name=tlog.0000000000000000005.1569262106165903360}, {size=4778, 
name=tlog.0000000000000000006.1569262106245595136}, {size=4778, 
name=tlog.0000000000000000007.1569262106355695616}, {size=4778, 
name=tlog.0000000000000000008.1569262106447970304}, {size=4778, 
name=tlog.0000000000000000009.1569262106568556544}]
   [junit4]   2> 154596 INFO  (qtp3661149-1360) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000000.1569262105018761216&wt=filestream&command=filecontent}
 status=0 QTime=2
   [junit4]   2> 154602 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000001.1569262105176047616&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154607 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000002.1569262105495863296&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154611 INFO  (qtp3661149-1355) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000003.1569262105762201600&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154614 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000004.1569262106072580096&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154618 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000005.1569262106165903360&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154622 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000006.1569262106245595136&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154626 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000007.1569262106355695616&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154629 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000008.1569262106447970304&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154635 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000009.1569262106568556544&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 154640 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Total time taken for download 
(fullCopy=false,bytesDownloaded=106171) : 0 secs (null bytes/sec) to 
MockDirectoryWrapper(RAMDirectory@4f6deb 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@14cc45c)
   [junit4]   2> 154686 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
   [junit4]   2> 154686 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.IndexFetcher Reloading SolrCore cdcr-target_shard1_replica_n1
   [junit4]   2> 154711 INFO  (Thread-330) [    ] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 7.0.0
   [junit4]   2> 154724 INFO  (Thread-330) [    ] o.a.s.s.IndexSchema 
[cdcr-target_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 154724 INFO  (Thread-330) [    ] o.a.s.s.IndexSchema Loaded 
schema minimal/1.1 with uniqueid field id
   [junit4]   2> 154724 INFO  (Thread-330) [    ] o.a.s.c.CoreContainer 
Reloading SolrCore 'cdcr-target_shard1_replica_n1' using configuration from 
collection cdcr-target
   [junit4]   2> 154751 INFO  (Thread-330) [    ] o.a.s.m.r.SolrJmxReporter JMX 
monitoring for 'solr_56418.solr.core.cdcr-target.shard1.replica_n1' (registry 
'solr.core.cdcr-target.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@79abef
   [junit4]   2> 154751 INFO  (Thread-330) [    ] o.a.s.c.SolrCore 
[[cdcr-target_shard1_replica_n1] ] Opening new SolrCore at 
[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-target-001\node1\cdcr-target_shard1_replica_n1],
 
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001\cdcr-target-001\node1\.\cdcr-target_shard1_replica_n1\data\]
   [junit4]   2> 154924 INFO  (Thread-330) [    ] o.a.s.u.CommitTracker Hard 
AutoCommit: disabled
   [junit4]   2> 154924 INFO  (Thread-330) [    ] o.a.s.u.CommitTracker Soft 
AutoCommit: disabled
   [junit4]   2> 154926 INFO  (Thread-330) [    ] o.a.s.s.SolrIndexSearcher 
Opening [Searcher@1c67bdd[cdcr-target_shard1_replica_n1] main]
   [junit4]   2> 154928 INFO  (Thread-330) [    ] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/cdcr-target
   [junit4]   2> 154929 INFO  (Thread-330) [    ] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/cdcr-target
   [junit4]   2> 154929 INFO  (Thread-330) [    ] o.a.s.s.ZkIndexSchemaReader 
Creating ZooKeeper watch for the managed schema at 
/configs/cdcr-target/managed-schema
   [junit4]   2> 154930 INFO  (Thread-330) [    ] o.a.s.s.ZkIndexSchemaReader 
Current schema version 0 is already the latest
   [junit4]   2> 154930 INFO  (Thread-330) [    ] o.a.s.h.ReplicationHandler 
Commits will be reserved for  10000
   [junit4]   2> 154936 INFO  (searcherExecutor-546-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-target_shard1_replica_n1] Registered new searcher 
Searcher@1c67bdd[cdcr-target_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)))}
   [junit4]   2> 154947 INFO  (Thread-330) [    ] o.a.s.u.DefaultSolrCoreState 
New IndexWriter is ready to be used.
   [junit4]   2> 154954 INFO  (Thread-330) [    ] o.a.s.s.SolrIndexSearcher 
Opening [Searcher@4a169f[cdcr-target_shard1_replica_n1] main]
   [junit4]   2> 154959 INFO  (searcherExecutor-546-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-target_shard1_replica_n1] Registered new searcher 
Searcher@4a169f[cdcr-target_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)))}
   [junit4]   2> 154959 INFO  (Thread-330) [    ] o.a.s.c.SolrCore 
[cdcr-target_shard1_replica_n1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@1f34944
   [junit4]   2> 154959 INFO  (Thread-330) [    ] o.a.s.h.CdcrRequestHandler 
Solr core is being closed - shutting down CDCR handler @ cdcr-target:shard1
   [junit4]   2> 154960 INFO  (Thread-330) [    ] o.a.s.m.SolrMetricManager 
Closing metric reporters for registry=solr.core.cdcr-target.shard1.replica_n1, 
tag=32721220
   [junit4]   2> 154966 INFO  (Thread-330) [    ] o.a.s.m.SolrMetricManager 
Closing metric reporters for 
registry=solr.collection.cdcr-target.shard1.leader, tag=32721220
   [junit4]   2> 154968 INFO  (recoveryExecutor-264-thread-1) [    ] 
o.a.s.h.CdcrRequestHandler No replay needed.
   [junit4]   2> 155318 INFO  (qtp1900015-1321) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262110711480320,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 155318 INFO  (qtp1900015-1321) [    ] 
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 155322 INFO  (qtp1900015-1321) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 155323 INFO  (qtp1900015-1321) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-target:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=5
   [junit4]   2> 155324 INFO  (qtp1900015-1317) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=cdcr-target:3&wt=javabin&version=2} hits=1000 status=0 
QTime=0
   [junit4]   2> 155328 INFO  (qtp1900015-1314) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={qt=/cdcr&action=CANCEL_BOOTSTRAP&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 156320 WARN  (cdcr-bootstrap-status-290-thread-1) [    ] 
o.a.s.h.CdcrReplicatorManager Cancelling waiting for bootstrap on target: 
cdcr-target shard: shard1 to complete
   [junit4]   2> 156321 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: 
WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-source/cdcr/state/process @ cdcr-source:shard1
   [junit4]   2> 156321 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={qt=/cdcr&_stateVer_=cdcr-source:3&action=stop&wt=javabin&version=2} 
status=0 QTime=995
   [junit4]   2> 156330 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.h.CdcrProcessStateManager Received new CDCR process state from watcher: 
STOPPED @ cdcr-source:shard1
   [junit4]   2> 156334 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.h.CdcrBufferStateManager The CDCR buffer state has changed: WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-source/cdcr/state/buffer @ cdcr-source:shard1
   [junit4]   2> 156337 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={qt=/cdcr&_stateVer_=cdcr-source:3&action=disablebuffer&wt=javabin&version=2}
 status=0 QTime=6
   [junit4]   2> 156337 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.h.CdcrBufferStateManager Received new CDCR buffer state from watcher: 
DISABLED @ cdcr-source:shard1
   [junit4]   1> Adding 100 docs with commit=true, numDocs=1100
   [junit4]   2> 156356 INFO  (qtp3661149-1355) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=19
   [junit4]   2> 156360 INFO  (qtp3661149-1357) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262111804096512,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 156360 INFO  (qtp3661149-1357) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262111804096512
   [junit4]   2> 156421 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@15b0510[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 156424 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@15b0510[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)
 Uninverting(_b(7.0.0):C100)))}
   [junit4]   2> 156428 INFO  (qtp3661149-1357) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 156490 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=129
   [junit4]   1> Adding 100 docs with commit=true, numDocs=1200
   [junit4]   2> 156504 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=10
   [junit4]   2> 156505 INFO  (qtp3661149-1360) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262111956140032,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 156506 INFO  (qtp3661149-1360) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262111956140032
   [junit4]   2> 156556 INFO  (qtp3661149-1360) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@692081[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 156557 INFO  (qtp3661149-1360) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 156561 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@692081[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)
 Uninverting(_b(7.0.0):C100) Uninverting(_c(7.0.0):C100)))}
   [junit4]   2> 156561 INFO  (qtp3661149-1360) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=56
   [junit4]   1> Adding 100 docs with commit=true, numDocs=1300
   [junit4]   2> 156575 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=11
   [junit4]   2> 156577 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262112031637504,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 156577 INFO  (qtp3661149-1362) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262112031637504
   [junit4]   2> 156632 INFO  (qtp3661149-1362) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@13e6af7[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 156634 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 156635 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@13e6af7[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)
 Uninverting(_b(7.0.0):C100) Uninverting(_c(7.0.0):C100) 
Uninverting(_d(7.0.0):C100)))}
   [junit4]   2> 156636 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=58
   [junit4]   1> Adding 100 docs with commit=true, numDocs=1400
   [junit4]   2> 156647 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=9
   [junit4]   2> 156648 INFO  (qtp3661149-1355) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262112106086400,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 156649 INFO  (qtp3661149-1355) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262112106086400
   [junit4]   2> 156718 INFO  (qtp3661149-1355) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@14d9e66[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 156720 INFO  (qtp3661149-1355) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 156721 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@14d9e66[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)
 Uninverting(_b(7.0.0):C100) Uninverting(_c(7.0.0):C100) 
Uninverting(_d(7.0.0):C100) Uninverting(_e(7.0.0):C100)))}
   [junit4]   2> 156722 INFO  (qtp3661149-1355) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=73
   [junit4]   1> Adding 100 docs with commit=true, numDocs=1500
   [junit4]   2> 156733 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=9
   [junit4]   2> 156735 INFO  (qtp3661149-1358) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262112197312512,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 156735 INFO  (qtp3661149-1358) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262112197312512
   [junit4]   2> 156810 INFO  (qtp3661149-1358) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@18512d7[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 156812 INFO  (qtp3661149-1358) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 156814 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@18512d7[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)
 Uninverting(_b(7.0.0):C100) Uninverting(_c(7.0.0):C100) 
Uninverting(_d(7.0.0):C100) Uninverting(_e(7.0.0):C100) 
Uninverting(_f(7.0.0):C100)))}
   [junit4]   2> 156814 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=79
   [junit4]   1> Adding 100 docs with commit=true, numDocs=1600
   [junit4]   2> 156826 INFO  (qtp3661149-1360) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=10
   [junit4]   2> 156828 INFO  (qtp3661149-1359) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262112294830080,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 156828 INFO  (qtp3661149-1359) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262112294830080
   [junit4]   2> 156923 INFO  (qtp3661149-1359) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@7405a3[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 156925 INFO  (qtp3661149-1359) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 156925 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@7405a3[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)
 Uninverting(_b(7.0.0):C100) Uninverting(_c(7.0.0):C100) 
Uninverting(_d(7.0.0):C100) Uninverting(_e(7.0.0):C100) 
Uninverting(_f(7.0.0):C100) Uninverting(_g(7.0.0):C100)))}
   [junit4]   2> 156926 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=98
   [junit4]   1> Adding 100 docs with commit=true, numDocs=1700
   [junit4]   2> 156934 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=9
   [junit4]   2> 156939 INFO  (qtp3661149-1361) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262112411222016,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 156939 INFO  (qtp3661149-1361) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262112411222016
   [junit4]   2> 157093 INFO  (qtp3661149-1361) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1f9920e[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 157094 INFO  (qtp3661149-1361) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 157096 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@1f9920e[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)
 Uninverting(_b(7.0.0):C100) Uninverting(_c(7.0.0):C100) 
Uninverting(_d(7.0.0):C100) Uninverting(_e(7.0.0):C100) 
Uninverting(_f(7.0.0):C100) Uninverting(_g(7.0.0):C100) 
Uninverting(_h(7.0.0):C100)))}
   [junit4]   2> 157097 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=158
   [junit4]   1> Adding 100 docs with commit=true, numDocs=1800
   [junit4]   2> 157109 INFO  (qtp3661149-1355) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=9
   [junit4]   2> 157111 INFO  (qtp3661149-1357) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262112591577088,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 157111 INFO  (qtp3661149-1357) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262112591577088
   [junit4]   2> 157220 INFO  (qtp3661149-1357) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@6c2ee8[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 157224 INFO  (qtp3661149-1357) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 157225 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@6c2ee8[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)
 Uninverting(_b(7.0.0):C100) Uninverting(_c(7.0.0):C100) 
Uninverting(_d(7.0.0):C100) Uninverting(_e(7.0.0):C100) 
Uninverting(_f(7.0.0):C100) Uninverting(_g(7.0.0):C100) 
Uninverting(_h(7.0.0):C100) Uninverting(_i(7.0.0):C100)))}
   [junit4]   2> 157226 INFO  (qtp3661149-1357) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=115
   [junit4]   1> Adding 100 docs with commit=true, numDocs=1900
   [junit4]   2> 157239 INFO  (qtp3661149-1358) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=10
   [junit4]   2> 157241 INFO  (qtp3661149-1360) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262112727891968,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 157241 INFO  (qtp3661149-1360) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262112727891968
   [junit4]   2> 157355 INFO  (qtp3661149-1360) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1351800[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 157356 INFO  (qtp3661149-1360) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 157360 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@1351800[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):C1000)
 Uninverting(_b(7.0.0):C100) Uninverting(_c(7.0.0):C100) 
Uninverting(_d(7.0.0):C100) Uninverting(_e(7.0.0):C100) 
Uninverting(_f(7.0.0):C100) Uninverting(_g(7.0.0):C100) 
Uninverting(_h(7.0.0):C100) Uninverting(_i(7.0.0):C100) 
Uninverting(_j(7.0.0):C100)))}
   [junit4]   2> 157360 INFO  (qtp3661149-1360) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=119
   [junit4]   1> Adding 100 docs with commit=true, numDocs=2000
   [junit4]   2> 157374 INFO  (qtp3661149-1359) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=11
   [junit4]   2> 157376 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1569262112869449728,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 157376 INFO  (qtp3661149-1362) [    ] o.a.s.u.SolrIndexWriter 
Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@9493a5 
commitCommandVersion:1569262112869449728
   [junit4]   2> 157464 INFO  (qtp3661149-1362) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@27e54d[cdcr-source_shard1_replica_n1] main]
   [junit4]   2> 157465 INFO  (qtp3661149-1362) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 157469 INFO  (searcherExecutor-528-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher 
Searcher@27e54d[cdcr-source_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_k(7.0.0):C1900)
 Uninverting(_l(7.0.0):C100)))}
   [junit4]   2> 157470 INFO  (qtp3661149-1362) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
 status=0 QTime=94
   [junit4]   2> 157473 INFO  (qtp3661149-1361) [    ] o.a.s.c.S.Request 
[cdcr-source_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=cdcr-source:3&wt=javabin&version=2} hits=2000 status=0 
QTime=0
   [junit4]   2> 157489 INFO  (qtp1900015-1322) [    ] 
o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 1569262106579042312 
maxVersionFromIndex 1569262106579042312
   [junit4]   2> 157489 INFO  (qtp1900015-1322) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=6
   [junit4]   2> 157490 INFO  (qtp1900015-1316) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={_stateVer_=cdcr-target:3&action=COLLECTIONCHECKPOINT&wt=javabin&version=2}
 status=0 QTime=14
   [junit4]   2> 157491 INFO  (qtp3661149-1355) [    ] 
o.a.s.h.CdcrReplicatorManager Create new update log reader for target 
cdcr-target with checkpoint 1569262106579042312 @ cdcr-source:shard1
   [junit4]   2> 157491 INFO  (qtp3661149-1355) [    ] 
o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: 
cdcr-target, shard: shard1
   [junit4]   2> 157492 INFO  (qtp3661149-1355) [    ] 
o.a.s.h.CdcrReplicatorManager Submitting bootstrap task to executor
   [junit4]   2> 157493 INFO  (zkCallback-278-thread-1) [    ] 
o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: 
WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections

[...truncated too long message...]

,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 302970 INFO  (jetty-closer-348-thread-1) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=5023626
   [junit4]   2> 302970 INFO  (jetty-closer-348-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 302971 INFO  (jetty-closer-348-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 302973 INFO  (jetty-closer-348-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 302975 INFO  (jetty-closer-348-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, 
tag=null
   [junit4]   2> 302977 INFO  (coreCloseExecutor-666-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@5095b1
   [junit4]   2> 302977 INFO  (coreCloseExecutor-666-thread-1) [    ] 
o.a.s.h.CdcrRequestHandler Solr core is being closed - shutting down CDCR 
handler @ cdcr-source:shard1
   [junit4]   2> 302978 INFO  (zkCallback-354-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-source/state.json] for collection [cdcr-source] has 
occurred - updating... (live nodes size: [1])
   [junit4]   2> 302979 INFO  (qtp15279804-1648) [    ] o.a.s.c.S.Request 
[cdcr-target_shard1_replica_n1]  webapp=/solr path=/cdcr 
params={qt=/cdcr&action=CANCEL_BOOTSTRAP&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 304070 WARN  (cdcr-bootstrap-status-366-thread-1) [    ] 
o.a.s.h.CdcrReplicatorManager Cancelling waiting for bootstrap on target: 
cdcr-target shard: shard1 to complete
   [junit4]   2> 304074 INFO  (coreCloseExecutor-666-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.cdcr-source.shard1.replica_n1, tag=5281201
   [junit4]   2> 304078 INFO  (coreCloseExecutor-666-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.collection.cdcr-source.shard1.leader, tag=5281201
   [junit4]   2> 304079 INFO  (jetty-closer-348-thread-1) [    ] 
o.a.s.c.Overseer Overseer 
(id=98078890910810115-127.0.0.1:56995_solr-n_0000000000) closing
   [junit4]   2> 304079 INFO  
(OverseerStateUpdate-98078890910810115-127.0.0.1:56995_solr-n_0000000000) [    
] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:56995_solr
   [junit4]   2> 304083 WARN  (zkCallback-354-thread-1) [    ] 
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: 
[KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 304084 INFO  (jetty-closer-348-thread-1) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@ddfe69{/solr,null,UNAVAILABLE}
   [junit4]   2> 304085 ERROR 
(TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[A46AA559A737AD24])
 [    ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so 
ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 304086 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[A46AA559A737AD24])
 [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:56991 56991
   [junit4]   2> 304086 INFO  (Thread-376) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:56991 56991
   [junit4]   2> 304087 WARN  (Thread-376) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        2       /solr/aliases.json
   [junit4]   2>        2       /solr/clusterprops.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        2       /solr/clusterstate.json
   [junit4]   2>        2       /solr/collections/cdcr-source/cdcr/state/process
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        2       /solr/live_nodes
   [junit4]   2>        2       /solr/collections
   [junit4]   2> 
   [junit4]   2> 304090 INFO  (jetty-closer-336-thread-1) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@19b48e5{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 304090 INFO  (jetty-closer-336-thread-1) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=4801922
   [junit4]   2> 304090 INFO  (jetty-closer-336-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 304093 INFO  (jetty-closer-336-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 304095 INFO  (jetty-closer-336-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 304097 INFO  (jetty-closer-336-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, 
tag=null
   [junit4]   2> 304099 INFO  (coreCloseExecutor-668-thread-1) [    ] 
o.a.s.c.SolrCore [cdcr-target_shard1_replica_n1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@1d8a756
   [junit4]   2> 304099 INFO  (coreCloseExecutor-668-thread-1) [    ] 
o.a.s.h.CdcrRequestHandler Solr core is being closed - shutting down CDCR 
handler @ cdcr-target:shard1
   [junit4]   2> 304101 INFO  (coreCloseExecutor-668-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.cdcr-target.shard1.replica_n1, tag=30975830
   [junit4]   2> 304102 INFO  (zkCallback-342-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/cdcr-target/state.json] for collection [cdcr-target] has 
occurred - updating... (live nodes size: [1])
   [junit4]   2> 304104 INFO  (coreCloseExecutor-668-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.collection.cdcr-target.shard1.leader, tag=30975830
   [junit4]   2> 304106 INFO  (jetty-closer-336-thread-1) [    ] 
o.a.s.c.Overseer Overseer 
(id=98078890886561795-127.0.0.1:56971_solr-n_0000000000) closing
   [junit4]   2> 304106 INFO  
(OverseerStateUpdate-98078890886561795-127.0.0.1:56971_solr-n_0000000000) [    
] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:56971_solr
   [junit4]   2> 304107 WARN  (zkCallback-342-thread-1) [    ] 
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: 
[KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 304108 INFO  (jetty-closer-336-thread-1) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@167395c{/solr,null,UNAVAILABLE}
   [junit4]   2> 304110 ERROR 
(TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[A46AA559A737AD24])
 [    ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so 
ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 304110 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[A46AA559A737AD24])
 [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:56967 56967
   [junit4]   2> 304111 INFO  (Thread-366) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:56967 56967
   [junit4]   2> 304111 WARN  (Thread-366) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        3       /solr/configs/cdcr-target/managed-schema
   [junit4]   2>        3       /solr/aliases.json
   [junit4]   2>        3       /solr/clusterprops.json
   [junit4]   2>        3       
/solr/collections/cdcr-target/leaders/shard1/leader
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        4       /solr/collections/cdcr-target/cdcr/state/process
   [junit4]   2>        3       /solr/collections/cdcr-target/cdcr/state/buffer
   [junit4]   2>        3       /solr/clusterstate.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        3       /solr/live_nodes
   [junit4]   2>        3       /solr/collections
   [junit4]   2> 
   [junit4]   2> 304111 INFO  
(TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[A46AA559A737AD24])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending 
testBootstrapWithContinousIndexingOnSourceCluster
   [junit4]   2> NOTE: leaving temporary files on disk at: 
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.CdcrBootstrapTest_A46AA559A737AD24-001
   [junit4]   2> Jun 04, 2017 8:31:59 AM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 6 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: 
codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION,
 chunkSize=7300, maxDocsPerChunk=2, blockSize=10), 
termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION,
 chunkSize=7300, blockSize=10)), sim=RandomSimilarity(queryNorm=true): {}, 
locale=gsw-FR, timezone=SystemV/YST9YDT
   [junit4]   2> NOTE: Windows 10 10.0 x86/Oracle Corporation 9-ea 
(32-bit)/cpus=3,threads=1,free=93739232,total=236191744
   [junit4]   2> NOTE: All tests run in this JVM: 
[DistributedFacetPivotWhiteBoxTest, DefaultValueUpdateProcessorTest, 
ClusterStateTest, TestCopyFieldCollectionResource, TestCustomStream, 
BJQParserTest, DirectoryFactoryTest, TestFileDictionaryLookup, TestJoin, 
TestPathTrie, SolrCmdDistributorTest, UpdateLogTest, BasicDistributedZk2Test, 
AsyncCallRequestStatusResponseTest, AtomicUpdatesTest, 
HdfsDirectoryFactoryTest, TestSearcherReuse, ConfigSetsAPITest, 
RequestHandlersTest, AnalyticsQueryTest, CdcrBootstrapTest]
   [junit4] Completed [52/724 (1!)] on J1 in 160.67s, 3 tests, 1 failure <<< 
FAILURES!

[...truncated 38473 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to