Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.0-Linux/423/
Java: 64bit/jdk1.8.0_144 -XX:+UseCompressedOops -XX:+UseG1GC
2 tests failed.
FAILED: org.apache.solr.cloud.CdcrBootstrapTest.testBootstrapWithSourceCluster
Error Message:
Document mismatch on target after sync expected:<2000> but was:<1000>
Stack Trace:
java.lang.AssertionError: Document mismatch on target after sync
expected:<2000> but was:<1000>
at
__randomizedtesting.SeedInfo.seed([F6025A0113D01E08:2F540BC510B40D42]: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.testBootstrapWithSourceCluster(CdcrBootstrapTest.java:232)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
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
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.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.cloud.ReplaceNodeTest.test
Error Message:
Stack Trace:
java.lang.AssertionError
at
__randomizedtesting.SeedInfo.seed([F6025A0113D01E08:7E5665DBBD2C73F0]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertTrue(Assert.java:54)
at org.apache.solr.cloud.ReplaceNodeTest.test(ReplaceNodeTest.java:98)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
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
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.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 12536 lines...]
[junit4] Suite: org.apache.solr.cloud.CdcrBootstrapTest
[junit4] 2> Creating dataDir:
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_F6025A0113D01E08-001/init-core-data-001
[junit4] 2> 1286083 WARN
(SUITE-CdcrBootstrapTest-seed#[F6025A0113D01E08]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 1286083 INFO
(SUITE-CdcrBootstrapTest-seed#[F6025A0113D01E08]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1286084 INFO
(SUITE-CdcrBootstrapTest-seed#[F6025A0113D01E08]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] IGNOR/A 0.00s J1 |
CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster
[junit4] > Assumption #1: 'awaitsfix' test group is disabled
(@AwaitsFix(bugUrl=https://issues.apache.org/jira/browse/SOLR-11278))
[junit4] 2> 1286089 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testBootstrapWithSourceCluster
[junit4] 2> 1286089 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_F6025A0113D01E08-001/cdcr-target-001
[junit4] 2> 1286089 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1286089 INFO (Thread-4327) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1286089 INFO (Thread-4327) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 1286090 ERROR (Thread-4327) [ ] 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> 1286189 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.ZkTestServer start zk server on port:37567
[junit4] 2> 1286196 INFO (jetty-launcher-1545-thread-1) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1286208 INFO (jetty-launcher-1545-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@36586535{/solr,null,AVAILABLE}
[junit4] 2> 1286208 INFO (jetty-launcher-1545-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@464ebd9c{SSL,[ssl,
http/1.1]}{127.0.0.1:44799}
[junit4] 2> 1286208 INFO (jetty-launcher-1545-thread-1) [ ]
o.e.j.s.Server Started @1288101ms
[junit4] 2> 1286208 INFO (jetty-launcher-1545-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=44799}
[junit4] 2> 1286208 ERROR (jetty-launcher-1545-thread-1) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1286209 INFO (jetty-launcher-1545-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.0.1
[junit4] 2> 1286209 INFO (jetty-launcher-1545-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1286209 INFO (jetty-launcher-1545-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config
dir: null
[junit4] 2> 1286209 INFO (jetty-launcher-1545-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-10-05T09:37:00.072Z
[junit4] 2> 1286243 INFO (jetty-launcher-1545-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1286271 INFO (jetty-launcher-1545-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37567/solr
[junit4] 2> 1286323 INFO (jetty-launcher-1545-thread-1)
[n:127.0.0.1:44799_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1286324 INFO (jetty-launcher-1545-thread-1)
[n:127.0.0.1:44799_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:44799_solr
[junit4] 2> 1286324 INFO (jetty-launcher-1545-thread-1)
[n:127.0.0.1:44799_solr ] o.a.s.c.Overseer Overseer
(id=98775611470839811-127.0.0.1:44799_solr-n_0000000000) starting
[junit4] 2> 1286342 INFO (jetty-launcher-1545-thread-1)
[n:127.0.0.1:44799_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:44799_solr
[junit4] 2> 1286343 INFO
(zkCallback-1552-thread-1-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1286423 INFO (jetty-launcher-1545-thread-1)
[n:127.0.0.1:44799_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44799.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@653a911
[junit4] 2> 1286430 INFO (jetty-launcher-1545-thread-1)
[n:127.0.0.1:44799_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44799.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@653a911
[junit4] 2> 1286430 INFO (jetty-launcher-1545-thread-1)
[n:127.0.0.1:44799_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44799.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@653a911
[junit4] 2> 1286431 INFO (jetty-launcher-1545-thread-1)
[n:127.0.0.1:44799_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_F6025A0113D01E08-001/cdcr-target-001/node1/.
[junit4] 1> Target zkHost = 127.0.0.1:37567/solr
[junit4] 2> 1286460 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_F6025A0113D01E08-001/cdcr-source-001
[junit4] 2> 1286460 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1286460 INFO (Thread-4337) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1286460 INFO (Thread-4337) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 1286468 ERROR (Thread-4337) [ ] 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> 1286560 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.ZkTestServer start zk server on port:41491
[junit4] 2> 1286565 INFO (jetty-launcher-1557-thread-1) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1286567 INFO (jetty-launcher-1557-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6a625c7d{/solr,null,AVAILABLE}
[junit4] 2> 1286568 INFO (jetty-launcher-1557-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@7045cbb4{SSL,[ssl,
http/1.1]}{127.0.0.1:37589}
[junit4] 2> 1286568 INFO (jetty-launcher-1557-thread-1) [ ]
o.e.j.s.Server Started @1288461ms
[junit4] 2> 1286568 INFO (jetty-launcher-1557-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=37589}
[junit4] 2> 1286568 ERROR (jetty-launcher-1557-thread-1) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1286568 INFO (jetty-launcher-1557-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.0.1
[junit4] 2> 1286568 INFO (jetty-launcher-1557-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1286568 INFO (jetty-launcher-1557-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config
dir: null
[junit4] 2> 1286568 INFO (jetty-launcher-1557-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-10-05T09:37:00.431Z
[junit4] 2> 1286580 INFO (jetty-launcher-1557-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1286589 INFO (jetty-launcher-1557-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41491/solr
[junit4] 2> 1286700 INFO (jetty-launcher-1557-thread-1)
[n:127.0.0.1:37589_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1286700 INFO (jetty-launcher-1557-thread-1)
[n:127.0.0.1:37589_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:37589_solr
[junit4] 2> 1286701 INFO (jetty-launcher-1557-thread-1)
[n:127.0.0.1:37589_solr ] o.a.s.c.Overseer Overseer
(id=98775611495153667-127.0.0.1:37589_solr-n_0000000000) starting
[junit4] 2> 1286704 INFO (jetty-launcher-1557-thread-1)
[n:127.0.0.1:37589_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:37589_solr
[junit4] 2> 1286705 INFO
(zkCallback-1564-thread-1-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1286768 INFO (jetty-launcher-1557-thread-1)
[n:127.0.0.1:37589_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37589.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@653a911
[junit4] 2> 1286777 INFO (jetty-launcher-1557-thread-1)
[n:127.0.0.1:37589_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37589.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@653a911
[junit4] 2> 1286778 INFO (jetty-launcher-1557-thread-1)
[n:127.0.0.1:37589_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37589.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@653a911
[junit4] 2> 1286779 INFO (jetty-launcher-1557-thread-1)
[n:127.0.0.1:37589_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_F6025A0113D01E08-001/cdcr-source-001/node1/.
[junit4] 2> 1286810 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 0x15eebe533a40006, 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.lang.Thread.run(Thread.java:748)
[junit4] 2> 1286847 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1286848 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41491/solr
ready
[junit4] 2> 1286887 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
] 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> 1286895 INFO
(OverseerThreadFactory-5448-thread-1-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] o.a.s.c.CreateCollectionCmd Create collection
cdcr-source
[junit4] 2> 1287009 INFO
(OverseerStateUpdate-98775611495153667-127.0.0.1:37589_solr-n_0000000000)
[n:127.0.0.1:37589_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"cdcr-source",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"cdcr-source_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:37589/solr";,
[junit4] 2> "type":"NRT"}
[junit4] 2> 1287214 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
] o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&collection=cdcr-source&version=2&replicaType=NRT&coreNodeName=core_node1&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin
[junit4] 2> 1287214 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 1287323 INFO
(zkCallback-1564-thread-1-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] 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> 1287324 INFO
(zkCallback-1564-thread-2-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] 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> 1288341 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 1288345 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1288347 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.IndexSchema [cdcr-source_shard1_replica_n1] Schema name=minimal
[junit4] 2> 1288349 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1288349 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at
/configs/cdcr-source/managed-schema
[junit4] 2> 1288350 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1288350 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.CoreContainer Creating SolrCore 'cdcr-source_shard1_replica_n1' using
configuration from collection cdcr-source, trusted=true
[junit4] 2> 1288351 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37589.solr.core.cdcr-source.shard1.replica_n1' (registry
'solr.core.cdcr-source.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@653a911
[junit4] 2> 1288352 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1288352 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.SolrCore [[cdcr-source_shard1_replica_n1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_F6025A0113D01E08-001/cdcr-source-001/node1/cdcr-source_shard1_replica_n1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_F6025A0113D01E08-001/cdcr-source-001/node1/./cdcr-source_shard1_replica_n1/data/]
[junit4] 2> 1288480 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 1288480 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1288480 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1288481 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1288482 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@440c1c89[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1288483 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/cdcr-source
[junit4] 2> 1288483 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/cdcr-source
[junit4] 2> 1288483 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/cdcr-source/managed-schema
[junit4] 2> 1288483 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1288483 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1288487 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.h.CdcrBufferStateManager Created znode
/collections/cdcr-source/cdcr/state/buffer
[junit4] 2> 1288489 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.h.CdcrProcessStateManager Created znode
/collections/cdcr-source/cdcr/state/process
[junit4] 2> 1288508 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1580409786068893696
[junit4] 2> 1288510 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@440c1c89[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1288513 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1288514 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1288514 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.SyncStrategy Sync replicas to
https://127.0.0.1:37589/solr/cdcr-source_shard1_replica_n1/
[junit4] 2> 1288514 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1288514 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.SyncStrategy
https://127.0.0.1:37589/solr/cdcr-source_shard1_replica_n1/ has no replicas
[junit4] 2> 1288514 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 1288516 INFO
(zkCallback-1564-thread-2-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] o.a.s.h.CdcrLeaderStateManager Received new leader
state @ cdcr-source:shard1
[junit4] 2> 1288523 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
https://127.0.0.1:37589/solr/cdcr-source_shard1_replica_n1/ shard1
[junit4] 2> 1288637 INFO
(zkCallback-1564-thread-2-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] 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> 1288637 INFO
(zkCallback-1564-thread-1-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] 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> 1288675 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1288676 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&collection=cdcr-source&version=2&replicaType=NRT&coreNodeName=core_node1&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin}
status=0 QTime=1462
[junit4] 2> 1288681 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most
30 seconds. Check all shard replicas
[junit4] 2> 1288782 INFO
(zkCallback-1564-thread-1-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] 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> 1288782 INFO
(zkCallback-1564-thread-2-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] 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> 1288899 INFO
(OverseerCollectionConfigSetProcessor-98775611495153667-127.0.0.1:37589_solr-n_0000000000)
[n:127.0.0.1:37589_solr ] 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> 1289681 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
] 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=2794
[junit4] 1> Adding 10 docs with commit=true, numDocs=100
[junit4] 2> 1289693 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 1289698 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409787316699136,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1289698 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409787316699136
[junit4] 2> 1289812 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@21e1f4dd[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1289813 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1289814 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@21e1f4dd[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)))}
[junit4] 2> 1289814 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=116
[junit4] 1> Adding 10 docs with commit=true, numDocs=200
[junit4] 2> 1289821 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 1289822 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409787446722560,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1289822 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409787446722560
[junit4] 2> 1289940 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@1e6de64a[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1289940 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1289942 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@1e6de64a[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)
Uninverting(_1(7.0.1):C100)))}
[junit4] 2> 1289942 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=120
[junit4] 1> Adding 10 docs with commit=true, numDocs=300
[junit4] 2> 1289946 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 1289946 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409787576745984,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1289946 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409787576745984
[junit4] 2> 1290120 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@4fbeca8f[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1290120 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1290121 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@4fbeca8f[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)
Uninverting(_1(7.0.1):C100) Uninverting(_2(7.0.1):C100)))}
[junit4] 2> 1290122 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=175
[junit4] 1> Adding 10 docs with commit=true, numDocs=400
[junit4] 2> 1290126 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 1290126 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409787765489664,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1290126 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409787765489664
[junit4] 2> 1290293 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@14da1643[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1290294 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1290295 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@14da1643[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)
Uninverting(_1(7.0.1):C100) Uninverting(_2(7.0.1):C100)
Uninverting(_3(7.0.1):C100)))}
[junit4] 2> 1290295 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=169
[junit4] 1> Adding 10 docs with commit=true, numDocs=500
[junit4] 2> 1290299 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1290302 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409787950039040,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1290302 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409787950039040
[junit4] 2> 1290532 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@6f9de3e1[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1290534 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@6f9de3e1[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)
Uninverting(_1(7.0.1):C100) Uninverting(_2(7.0.1):C100)
Uninverting(_3(7.0.1):C100) Uninverting(_4(7.0.1):C100)))}
[junit4] 2> 1290535 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1290535 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=233
[junit4] 1> Adding 10 docs with commit=true, numDocs=600
[junit4] 2> 1290539 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 1290540 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409788199600128,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1290540 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409788199600128
[junit4] 2> 1290762 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@3526ed09[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1290764 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@3526ed09[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)
Uninverting(_1(7.0.1):C100) Uninverting(_2(7.0.1):C100)
Uninverting(_3(7.0.1):C100) Uninverting(_4(7.0.1):C100)
Uninverting(_5(7.0.1):C100)))}
[junit4] 2> 1290764 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1290764 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=223
[junit4] 1> Adding 10 docs with commit=true, numDocs=700
[junit4] 2> 1290767 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1290768 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409788438675456,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1290768 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409788438675456
[junit4] 2> 1291010 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@7dbc0800[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1291010 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1291013 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@7dbc0800[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)
Uninverting(_1(7.0.1):C100) Uninverting(_2(7.0.1):C100)
Uninverting(_3(7.0.1):C100) Uninverting(_4(7.0.1):C100)
Uninverting(_5(7.0.1):C100) Uninverting(_6(7.0.1):C100)))}
[junit4] 2> 1291013 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=244
[junit4] 1> Adding 10 docs with commit=true, numDocs=800
[junit4] 2> 1291017 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1291017 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409788699770880,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1291017 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409788699770880
[junit4] 2> 1291265 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@4517ce27[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1291265 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1291266 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@4517ce27[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)
Uninverting(_1(7.0.1):C100) Uninverting(_2(7.0.1):C100)
Uninverting(_3(7.0.1):C100) Uninverting(_4(7.0.1):C100)
Uninverting(_5(7.0.1):C100) Uninverting(_6(7.0.1):C100)
Uninverting(_7(7.0.1):C100)))}
[junit4] 2> 1291266 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=249
[junit4] 1> Adding 10 docs with commit=true, numDocs=900
[junit4] 2> 1291270 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1291270 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409788965060608,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1291270 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409788965060608
[junit4] 2> 1291547 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@4eaaa1d4[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1291549 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@4eaaa1d4[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)
Uninverting(_1(7.0.1):C100) Uninverting(_2(7.0.1):C100)
Uninverting(_3(7.0.1):C100) Uninverting(_4(7.0.1):C100)
Uninverting(_5(7.0.1):C100) Uninverting(_6(7.0.1):C100)
Uninverting(_7(7.0.1):C100) Uninverting(_8(7.0.1):C100)))}
[junit4] 2> 1291550 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1291550 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=279
[junit4] 1> Adding 10 docs with commit=true, numDocs=1000
[junit4] 2> 1291553 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1291565 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409789274390528,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1291565 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409789274390528
[junit4] 2> 1291873 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@bf48cae[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 1291874 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1291875 INFO
(searcherExecutor-5451-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-source_shard1_replica_n1] Registered new searcher
Searcher@bf48cae[cdcr-source_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C100)
Uninverting(_1(7.0.1):C100) Uninverting(_2(7.0.1):C100)
Uninverting(_3(7.0.1):C100) Uninverting(_4(7.0.1):C100)
Uninverting(_5(7.0.1):C100) Uninverting(_6(7.0.1):C100)
Uninverting(_7(7.0.1):C100) Uninverting(_8(7.0.1):C100)
Uninverting(_9(7.0.1):C100)))}
[junit4] 2> 1291878 INFO (qtp1119975618-12063) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=320
[junit4] 2> 1291880 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/select
params={q=*:*&_stateVer_=cdcr-source:4&wt=javabin&version=2} hits=1000 status=0
QTime=0
[junit4] 2> 1291947 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1291948 INFO
(TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[F6025A0113D01E08])
[ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37567/solr
ready
[junit4] 2> 1291988 INFO (qtp849607788-12022) [n:127.0.0.1:44799_solr
] 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> 1291989 INFO
(OverseerThreadFactory-5440-thread-1-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] o.a.s.c.CreateCollectionCmd Create collection
cdcr-target
[junit4] 2> 1292095 INFO
(OverseerStateUpdate-98775611470839811-127.0.0.1:44799_solr-n_0000000000)
[n:127.0.0.1:44799_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"cdcr-target",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"cdcr-target_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:44799/solr";,
[junit4] 2> "type":"NRT"}
[junit4] 2> 1292299 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
] o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&coreNodeName=core_node1&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> 1292300 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 1292403 INFO
(zkCallback-1552-thread-1-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] 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> 1292405 INFO
(zkCallback-1552-thread-2-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] 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> 1293307 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 1293309 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
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> 1293311 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.s.IndexSchema [cdcr-target_shard1_replica_n1] Schema name=minimal
[junit4] 2> 1293313 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1293313 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at
/configs/cdcr-target/managed-schema
[junit4] 2> 1293314 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
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> 1293314 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.CoreContainer Creating SolrCore 'cdcr-target_shard1_replica_n1' using
configuration from collection cdcr-target, trusted=true
[junit4] 2> 1293314 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44799.solr.core.cdcr-target.shard1.replica_n1' (registry
'solr.core.cdcr-target.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@653a911
[junit4] 2> 1293315 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1293315 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.SolrCore [[cdcr-target_shard1_replica_n1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_F6025A0113D01E08-001/cdcr-target-001/node1/cdcr-target_shard1_replica_n1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_F6025A0113D01E08-001/cdcr-target-001/node1/./cdcr-target_shard1_replica_n1/data/]
[junit4] 2> 1308360 WARN (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.h.a.SystemInfoHandler Resolving canonical hostname for local host took
15.012 seconds, possible DNS misconfiguration. Set the
'solr.dns.prevent.reverse.lookup' sysprop to true on startup to prevent future
lookups if DNS can not be fixed.
[junit4] 2> 1308368 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 1308368 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1308369 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1308369 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1308371 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@392db0ba[cdcr-target_shard1_replica_n1] main]
[junit4] 2> 1308371 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/cdcr-target
[junit4] 2> 1308372 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/cdcr-target
[junit4] 2> 1308372 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/cdcr-target/managed-schema
[junit4] 2> 1308372 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1308372 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1308373 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.h.CdcrBufferStateManager Created znode
/collections/cdcr-target/cdcr/state/buffer
[junit4] 2> 1308374 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.h.CdcrProcessStateManager Created znode
/collections/cdcr-target/cdcr/state/process
[junit4] 2> 1308374 INFO
(searcherExecutor-5457-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.c.SolrCore
[cdcr-target_shard1_replica_n1] Registered new searcher
Searcher@392db0ba[cdcr-target_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1308375 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1580409806900953088
[junit4] 2> 1308380 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1308380 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1308380 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.SyncStrategy Sync replicas to
https://127.0.0.1:44799/solr/cdcr-target_shard1_replica_n1/
[junit4] 2> 1308381 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1308381 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.SyncStrategy
https://127.0.0.1:44799/solr/cdcr-target_shard1_replica_n1/ has no replicas
[junit4] 2> 1308381 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 1308381 INFO
(zkCallback-1552-thread-1-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] 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> 1308381 INFO
(zkCallback-1552-thread-2-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] 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> 1308382 INFO
(zkCallback-1552-thread-2-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] o.a.s.h.CdcrLeaderStateManager Received new leader
state @ cdcr-target:shard1
[junit4] 2> 1308384 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
https://127.0.0.1:44799/solr/cdcr-target_shard1_replica_n1/ shard1
[junit4] 2> 1308485 INFO
(zkCallback-1552-thread-2-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] 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> 1308485 INFO
(zkCallback-1552-thread-1-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] 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> 1308534 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1308535 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={qt=/admin/cores&coreNodeName=core_node1&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=16236
[junit4] 2> 1308537 INFO (qtp849607788-12022) [n:127.0.0.1:44799_solr
] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most
30 seconds. Check all shard replicas
[junit4] 2> 1308636 INFO
(zkCallback-1552-thread-1-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] 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> 1308636 INFO
(zkCallback-1552-thread-2-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] 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> 1309537 INFO (qtp849607788-12022) [n:127.0.0.1:44799_solr
] 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=17549
[junit4] 2> 1309540 INFO
(zkCallback-1552-thread-2-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] 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> 1309540 INFO
(zkCallback-1552-thread-2-processing-n:127.0.0.1:44799_solr)
[n:127.0.0.1:44799_solr ] o.a.s.h.CdcrProcessStateManager Received new CDCR
process state from watcher: STARTED @ cdcr-target:shard1
[junit4] 2> 1309540 INFO (qtp849607788-12027) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/cdcr
params={qt=/cdcr&_stateVer_=cdcr-target:5&action=start&wt=javabin&version=2}
status=0 QTime=1
[junit4] 2> 1309543 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1309544 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37567/solr ready
[junit4] 2> 1309550 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 1309550 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
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=0
[junit4] 2> 1309550 INFO (qtp849607788-12022) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/cdcr
params={_stateVer_=cdcr-target:5&action=COLLECTIONCHECKPOINT&wt=javabin&version=2}
status=0 QTime=4
[junit4] 2> 1309551 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.h.CdcrReplicatorManager Create new update log reader for target
cdcr-target with checkpoint -1 @ cdcr-source:shard1
[junit4] 2> 1309551 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection:
cdcr-target, shard: shard1
[junit4] 2> 1309554 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.h.CdcrReplicatorManager Submitting bootstrap task to executor
[junit4] 2> 1309555 INFO
(cdcr-bootstrap-status-1576-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Attempting to
bootstrap target collection: cdcr-target shard: shard1 leader:
https://127.0.0.1:44799/solr/cdcr-target_shard1_replica_n1/
[junit4] 2> 1309556 INFO
(zkCallback-1564-thread-2-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] 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> 1309556 INFO
(zkCallback-1564-thread-2-processing-n:127.0.0.1:37589_solr)
[n:127.0.0.1:37589_solr ] o.a.s.h.CdcrProcessStateManager Received new CDCR
process state from watcher: STARTED @ cdcr-source:shard1
[junit4] 2> 1309556 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/cdcr
params={qt=/cdcr&_stateVer_=cdcr-source:4&action=start&wt=javabin&version=2}
status=0 QTime=14
[junit4] 2> 1309557 INFO (qtp1119975618-12069) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/cdcr
params={qt=/cdcr&_stateVer_=cdcr-source:4&action=queues&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 1309558 INFO (qtp849607788-12027) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/cdcr
params={qt=/cdcr&masterUrl=https://127.0.0.1:37589/solr/cdcr-source_shard1_replica_n1/&action=BOOTSTRAP&wt=javabin&version=2}
status=0 QTime=1
[junit4] 1> Cdcr queue response:
{responseHeader={status=0,QTime=0},queues={127.0.0.1:37567/solr={cdcr-target={queueSize=1010,lastTimestamp=}}},tlogTotalSize=47659,tlogTotalCount=10,updateLogSynchronizer=stopped}
[junit4] 2> 1309558 INFO (qtp849607788-12023) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409808141418496,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1309559 INFO (qtp849607788-12023) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1309559 INFO (qtp849607788-12023) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1309559 INFO (qtp849607788-12023) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/update
params={_stateVer_=cdcr-target:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 1309559 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.u.UpdateLog Starting to buffer updates.
FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1309559 INFO (qtp849607788-12029) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
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> 1309560 INFO (qtp849607788-12022) [n:127.0.0.1:44799_solr
c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/select
params={q=*:*&_stateVer_=cdcr-target:5&wt=javabin&version=2} hits=0 status=0
QTime=0
[junit4] 2> 1309560 INFO
(cdcr-bootstrap-status-1576-thread-1-processing-n:127.0.0.1:37589_solr
x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1)
[n:127.0.0.1:37589_solr c:cdcr-source s:shard1 r:core_node1
x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager CDCR bootstrap
running for 1 seconds, sleeping for 2000 ms
[junit4] 2> 1309562 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1580409808145612800,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1309562 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b34004a
commitCommandVersion:1580409808145612800
[junit4] 2> 1309668 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@31916f1f[cdcr-source_shard1_replica_n1] realtime]
[junit4] 2> 1309668 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1309668 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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=106
[junit4] 2> 1309671 INFO (qtp1119975618-12065) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1309671 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Master's generation: 12
[junit4] 2> 1309671 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Master's version:
1507196243425
[junit4] 2> 1309671 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1309671 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 1309671 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Starting replication
process
[junit4] 2> 1309674 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.h.ReplicationHandler Adding tlog files to list: [{size=4657,
name=tlog.0000000000000000000.1580409787303067648}, {size=4778,
name=tlog.0000000000000000001.1580409787439382528}, {size=4778,
name=tlog.0000000000000000002.1580409787573600256}, {size=4778,
name=tlog.0000000000000000003.1580409787762343936}, {size=4778,
name=tlog.0000000000000000004.1580409787943747584}, {size=4778,
name=tlog.0000000000000000005.1580409788196454400}, {size=4778,
name=tlog.0000000000000000006.1580409788435529728}, {size=4778,
name=tlog.0000000000000000007.1580409788696625152}, {size=4778,
name=tlog.0000000000000000008.1580409788961914880}, {size=4778,
name=tlog.0000000000000000009.1580409789259710464}]
[junit4] 2> 1309674 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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=2
[junit4] 2> 1309674 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Number of files in latest
index in master: 18
[junit4] 2> 1309674 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Number of tlog files in
master: 10
[junit4] 2> 1309675 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.u.DefaultSolrCoreState New IndexWriter
is ready to be used.
[junit4] 2> 1309675 INFO
(recoveryExecutor-1550-thread-1-processing-n:127.0.0.1:44799_solr
x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1)
[n:127.0.0.1:44799_solr c:cdcr-target s:shard1 r:core_node1
x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Starting download
(fullCopy=false) to MockDirectoryWrapper(RAMDirectory@555c279d
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@43f736c3)
[junit4] 2> 1309675 INFO (qtp1119975618-12066) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1309677 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1309678 INFO (qtp1119975618-12065) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1309679 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1309679 INFO (qtp1119975618-12066) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1309680 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1309681 INFO (qtp1119975618-12065) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr
path=/replication
params={generation=12&qt=/replication&file=_a_MockRandom_0.sd&checksum=true&wt=filestream&command=filecontent}
status=0 QTime=0
[junit4] 2> 1309681 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1309682 INFO (qtp1119975618-12066) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr
path=/replication
params={generation=12&qt=/replication&file=_a_MockRandom_0.doc&checksum=true&wt=filestream&command=filecontent}
status=0 QTime=0
[junit4] 2> 1309683 INFO (qtp1119975618-12070) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr
path=/replication
params={generation=12&qt=/replication&file=_a_MockRandom_0.pos&checksum=true&wt=filestream&command=filecontent}
status=0 QTime=0
[junit4] 2> 1309684 INFO (qtp1119975618-12065) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr
path=/replication
params={generation=12&qt=/replication&file=_a_MockRandom_0.tii&checksum=true&wt=filestream&command=filecontent}
status=0 QTime=0
[junit4] 2> 1309684 INFO (qtp1119975618-12068) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
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> 1309685 INFO (qtp1119975618-12066) [n:127.0.0.1:37589_solr
c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1]
o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr
path=/replication params={generati
[...truncated too long message...]
lback-2374-thread-2-processing-n:127.0.0.1:41603_solr) [n:127.0.0.1:41603_solr
] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to
ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1720021 INFO (jetty-closer-2343-thread-6) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@3b0fbcb{/solr,null,UNAVAILABLE}
[junit4] 2> 1720023 WARN
(zkCallback-2362-thread-2-processing-n:127.0.0.1:35941_solr)
[n:127.0.0.1:35941_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1720023 INFO (jetty-closer-2343-thread-4) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@154d997f{/solr,null,UNAVAILABLE}
[junit4] 2> 1720024 WARN
(zkCallback-2371-thread-1-processing-n:127.0.0.1:33549_solr)
[n:127.0.0.1:33549_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1720024 INFO (jetty-closer-2343-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@4af8fd90{/solr,null,UNAVAILABLE}
[junit4] 2> 1721022 WARN
(zkCallback-2372-thread-1-processing-n:127.0.0.1:44651_solr)
[n:127.0.0.1:44651_solr c:replacenodetest_coll s:shard3 r:core_node11
x:replacenodetest_coll_shard3_replica_n2] o.a.s.c.SyncStrategy Closed, skipping
sync up.
[junit4] 2> 1721022 INFO
(zkCallback-2372-thread-1-processing-n:127.0.0.1:44651_solr)
[n:127.0.0.1:44651_solr c:replacenodetest_coll s:shard3 r:core_node11
x:replacenodetest_coll_shard3_replica_n2] o.a.s.c.ShardLeaderElectionContext We
failed sync, but we have no versions - we can't sync in that case - we were
active before, so become leader anyway
[junit4] 2> 1721022 INFO
(zkCallback-2372-thread-1-processing-n:127.0.0.1:44651_solr)
[n:127.0.0.1:44651_solr c:replacenodetest_coll s:shard3 r:core_node11
x:replacenodetest_coll_shard3_replica_n2] o.a.s.c.SolrCore
[replacenodetest_coll_shard3_replica_n2] CLOSING SolrCore
org.apache.solr.core.SolrCore@292fb260
[junit4] 2> 1721022 INFO
(zkCallback-2372-thread-1-processing-n:127.0.0.1:44651_solr)
[n:127.0.0.1:44651_solr c:replacenodetest_coll s:shard3 r:core_node11
x:replacenodetest_coll_shard3_replica_n2] o.a.s.m.SolrMetricManager Closing
metric reporters for registry=solr.core.replacenodetest_coll.shard3.replica_n2,
tag=690991712
[junit4] 2> 1721022 INFO
(zkCallback-2372-thread-1-processing-n:127.0.0.1:44651_solr)
[n:127.0.0.1:44651_solr c:replacenodetest_coll s:shard3 r:core_node11
x:replacenodetest_coll_shard3_replica_n2] o.a.s.m.r.SolrJmxReporter Closing
reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@d9fbe2c: rootName =
solr_44651, domain = solr.core.replacenodetest_coll.shard3.replica_n2, service
url = null, agent id = null] for registry
solr.core.replacenodetest_coll.shard3.replica_n2 /
com.codahale.metrics.MetricRegistry@8ae2ec0
[junit4] 2> 1721031 INFO
(zkCallback-2372-thread-1-processing-n:127.0.0.1:44651_solr)
[n:127.0.0.1:44651_solr c:replacenodetest_coll s:shard3 r:core_node11
x:replacenodetest_coll_shard3_replica_n2] o.a.s.m.SolrMetricManager Closing
metric reporters for
registry=solr.collection.replacenodetest_coll.shard3.leader, tag=690991712
[junit4] 2> 1721032 INFO
(zkCallback-2372-thread-1-processing-n:127.0.0.1:44651_solr)
[n:127.0.0.1:44651_solr c:replacenodetest_coll s:shard3 r:core_node11
x:replacenodetest_coll_shard3_replica_n2]
o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader
parent node, won't remove previous leader registration.
[junit4] 2> 1753525 INFO
(OverseerThreadFactory-6471-thread-2-processing-n:127.0.0.1:44651_solr)
[n:127.0.0.1:44651_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 1753526 INFO (jetty-closer-2343-thread-5) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@264b03c6{/solr,null,UNAVAILABLE}
[junit4] 2> 1753526 ERROR
(SUITE-ReplaceNodeTest-seed#[F6025A0113D01E08]-worker) [ ]
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> 1753526 INFO
(SUITE-ReplaceNodeTest-seed#[F6025A0113D01E08]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:42365 42365
[junit4] 2> 1758587 INFO (Thread-2705) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:42365 42365
[junit4] 2> 1758587 WARN (Thread-2705) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/aliases.json
[junit4] 2> 6 /solr/security.json
[junit4] 2> 6 /solr/configs/conf1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 49
/solr/collections/replacenodetest_coll/state.json
[junit4] 2> 7 /solr/clusterstate.json
[junit4] 2> 7 /solr/clusterprops.json
[junit4] 2> 2
/solr/overseer_elect/election/98775638489235466-127.0.0.1:35941_solr-n_0000000001
[junit4] 2> 2
/solr/overseer_elect/election/98775638489235472-127.0.0.1:44651_solr-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/live_nodes
[junit4] 2> 7 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ReplaceNodeTest_F6025A0113D01E08-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70),
sim=RandomSimilarity(queryNorm=false): {}, locale=ga-IE, timezone=Etc/GMT+8
[junit4] 2> NOTE: Linux 4.10.0-33-generic amd64/Oracle Corporation
1.8.0_144 (64-bit)/cpus=8,threads=1,free=165480072,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestReqParamsAPI,
SolrMetricsIntegrationTest, TestPayloadScoreQParserPlugin,
AsyncCallRequestStatusResponseTest, TestClassNameShortening,
TestSubQueryTransformerCrossCore, TestCloudPivotFacet, TestSolrXml,
UniqFieldsUpdateProcessorFactoryTest, TermVectorComponentDistributedTest,
TestLMJelinekMercerSimilarityFactory, TestDFISimilarityFactory,
CdcrReplicationDistributedZkTest, TestFieldTypeCollectionResource,
HdfsBasicDistributedZkTest, CollectionReloadTest, TestBinaryResponseWriter,
NumericFieldsTest, TestCoreAdminApis, TestConfigSets, SuggesterTest,
InfoHandlerTest, TestSha256AuthenticationProvider, TestGroupingSearch,
TestNoOpRegenerator, SignatureUpdateProcessorFactoryTest, RecoveryZkTest,
TestReload, TestAnalyzedSuggestions, TestSchemalessBufferedUpdates,
TestIndexSearcher, CloudMLTQParserTest, PingRequestHandlerTest,
DateRangeFieldTest, LeaderElectionTest, TestReversedWildcardFilterFactory,
TestPullReplica, BooleanFieldTest, RuleEngineTest,
OutOfBoxZkACLAndCredentialsProvidersTest, TestJmxIntegration,
TestExclusionRuleCollectionAccess, SolrJmxReporterCloudTest,
TestSQLHandlerNonCloud, DirectUpdateHandlerTest, TestFreeTextSuggestions,
TolerantUpdateProcessorTest, ActionThrottleTest, OverseerModifyCollectionTest,
TestNumericRangeQuery32, TestShardHandlerFactory,
DirectUpdateHandlerOptimizeTest, TestSurroundQueryParser,
TestHalfAndHalfDocValues, DocumentBuilderTest, DateMathParserTest,
CustomCollectionTest, TestClusterProperties, SpellPossibilityIteratorTest,
QueryEqualityTest, ClassificationUpdateProcessorTest, TestRequestForwarding,
NotRequiredUniqueKeyTest, TestFieldCacheReopen, TestDocBasedVersionConstraints,
TestFoldingMultitermQuery, SolrTestCaseJ4Test, SolrCoreMetricManagerTest,
LeaderInitiatedRecoveryOnCommitTest, OverseerTest, SpatialRPTFieldTypeTest,
TestPushWriter, TestSolrCloudWithDelegationTokens,
TestComplexPhraseLeadingWildcard, TestSmileRequest, AnalyticsMergeStrategyTest,
TestSystemCollAutoCreate, SimpleFacetsTest, SuggesterFSTTest,
TestDistributedMissingSort, HLLSerializationTest, MoveReplicaTest,
TestConfigSetsAPIExclusivity, AddBlockUpdateTest,
TestDeleteCollectionOnDownNodes, TestMacros, CdcrVersionReplicationTest,
DistribJoinFromCollectionTest, TestSegmentSorting, TestMaxScoreQueryParser,
CopyFieldTest, TlogReplayBufferedWhileIndexingTest, VersionInfoTest,
TestDynamicFieldResource, TestEmbeddedSolrServerSchemaAPI,
SolrCloudReportersTest, DeleteStatusTest, FullSolrCloudDistribCmdsTest,
PrimitiveFieldTypeTest, TestStressReorder, HdfsThreadLeakTest,
UnloadDistributedZkTest, DateFieldTest, RemoteQueryErrorTest, TestApiFramework,
MinimalSchemaTest, TestTlogReplica, TestTrie, BasicAuthIntegrationTest,
BitVectorTest, TestPseudoReturnFields, SolrCoreCheckLockOnStartupTest,
SolrCloudExampleTest, CoreAdminCreateDiscoverTest, BasicDistributedZk2Test,
OpenCloseCoreStressTest, LeaderElectionIntegrationTest, BasicZkTest,
ClusterStateUpdateTest, ZkSolrClientTest, ZkCLITest, TestFaceting,
TestRecovery, TestStressVersions, HardAutoCommitTest, TestRangeQuery,
SpellCheckComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestSort,
TestBadConfig, SoftAutoCommitTest, SolrPluginUtilsTest, ReturnFieldsTest,
MBeansHandlerTest, BinaryUpdateRequestHandlerTest, SearchHandlerTest,
HighlighterConfigTest, TestSolrIndexConfig, ResponseLogComponentTest,
BadComponentTest, TestSolrDeletionPolicy2, SampleTest,
TestFuzzyAnalyzedSuggestions, DirectSolrConnectionTest, TestCodecSupport,
TestSweetSpotSimilarityFactory, TestFastWriter, TestFastOutputStream,
ChaosMonkeyNothingIsSafeTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest,
ChaosMonkeySafeLeaderWithPullReplicasTest,
CollectionsAPIAsyncDistributedZkTest, DistribCursorPagingTest,
DistributedVersionInfoTest, MissingSegmentRecoveryTest, MultiThreadedOCPTest,
ReplaceNodeTest]
[junit4] Completed [499/730 (2!)] on J2 in 60.19s, 1 test, 1 failure <<<
FAILURES!
[...truncated 44276 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
