You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/08/02 01:29:17 UTC
[JENKINS] Lucene-Solr-7.x-Linux (32bit/jdk1.8.0_172) - Build # 2466
- Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2466/
Java: 32bit/jdk1.8.0_172 -client -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.cdcr.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster
Error Message:
Document mismatch on target after sync expected:<2000> but was:<1902>
Stack Trace:
java.lang.AssertionError: Document mismatch on target after sync expected:<2000> but was:<1902>
at __randomizedtesting.SeedInfo.seed([D7614FFF0D149393:32404A6EA422068]: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.cdcr.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster(CdcrBootstrapTest.java:296)
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:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
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:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
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 14337 lines...]
[junit4] Suite: org.apache.solr.cloud.cdcr.CdcrBootstrapTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/init-core-data-001
[junit4] 2> 2481379 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/cdcr-target-001
[junit4] 2> 2481379 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2481380 INFO (Thread-3628) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2481380 INFO (Thread-3628) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2481391 ERROR (Thread-3628) [ ] 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> 2481480 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.ZkTestServer start zk server on port:34775
[junit4] 2> 2481482 INFO (zkConnectionManagerCallback-5204-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2481489 INFO (jetty-launcher-5201-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 2481491 INFO (jetty-launcher-5201-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2481491 INFO (jetty-launcher-5201-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2481491 INFO (jetty-launcher-5201-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2481491 INFO (jetty-launcher-5201-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1dda1fa{/solr,null,AVAILABLE}
[junit4] 2> 2481492 INFO (jetty-launcher-5201-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1d5c32a{HTTP/1.1,[http/1.1]}{127.0.0.1:38905}
[junit4] 2> 2481492 INFO (jetty-launcher-5201-thread-1) [ ] o.e.j.s.Server Started @2481540ms
[junit4] 2> 2481492 INFO (jetty-launcher-5201-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=38905}
[junit4] 2> 2481493 ERROR (jetty-launcher-5201-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2481493 INFO (jetty-launcher-5201-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2481493 INFO (jetty-launcher-5201-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 2481493 INFO (jetty-launcher-5201-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2481493 INFO (jetty-launcher-5201-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2481493 INFO (jetty-launcher-5201-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-02T01:00:15.442Z
[junit4] 2> 2481494 INFO (zkConnectionManagerCallback-5206-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2481495 INFO (jetty-launcher-5201-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2482354 INFO (jetty-launcher-5201-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34775/solr
[junit4] 2> 2482356 INFO (zkConnectionManagerCallback-5210-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2482359 INFO (zkConnectionManagerCallback-5212-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2482407 INFO (jetty-launcher-5201-thread-1) [n:127.0.0.1:38905_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:38905_solr
[junit4] 2> 2482407 INFO (jetty-launcher-5201-thread-1) [n:127.0.0.1:38905_solr ] o.a.s.c.Overseer Overseer (id=72088651561828355-127.0.0.1:38905_solr-n_0000000000) starting
[junit4] 2> 2482412 INFO (zkConnectionManagerCallback-5219-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2482414 INFO (jetty-launcher-5201-thread-1) [n:127.0.0.1:38905_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34775/solr ready
[junit4] 2> 2482415 INFO (OverseerStateUpdate-72088651561828355-127.0.0.1:38905_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:38905_solr
[junit4] 2> 2482415 INFO (jetty-launcher-5201-thread-1) [n:127.0.0.1:38905_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38905_solr
[junit4] 2> 2482416 INFO (zkCallback-5211-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2482416 INFO (zkCallback-5218-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2482432 INFO (jetty-launcher-5201-thread-1) [n:127.0.0.1:38905_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2482455 INFO (jetty-launcher-5201-thread-1) [n:127.0.0.1:38905_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38905.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2482463 INFO (jetty-launcher-5201-thread-1) [n:127.0.0.1:38905_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38905.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2482463 INFO (jetty-launcher-5201-thread-1) [n:127.0.0.1:38905_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38905.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2482465 INFO (jetty-launcher-5201-thread-1) [n:127.0.0.1:38905_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/cdcr-target-001/node1/.
[junit4] 2> 2482480 INFO (zkConnectionManagerCallback-5222-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2482483 INFO (zkConnectionManagerCallback-5225-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2482485 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.c.CdcrBootstrapTest Target zkHost = 127.0.0.1:34775/solr
[junit4] 2> 2482485 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/cdcr-source-001
[junit4] 2> 2482485 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2482485 INFO (Thread-3638) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2482485 INFO (Thread-3638) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2482487 ERROR (Thread-3638) [ ] 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> 2482585 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.ZkTestServer start zk server on port:41953
[junit4] 2> 2482587 INFO (zkConnectionManagerCallback-5229-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2482590 INFO (jetty-launcher-5226-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 2482590 INFO (jetty-launcher-5226-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2482590 INFO (jetty-launcher-5226-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2482590 INFO (jetty-launcher-5226-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 2482591 INFO (jetty-launcher-5226-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1ee0be8{/solr,null,AVAILABLE}
[junit4] 2> 2482591 INFO (jetty-launcher-5226-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1d07bd7{HTTP/1.1,[http/1.1]}{127.0.0.1:36533}
[junit4] 2> 2482591 INFO (jetty-launcher-5226-thread-1) [ ] o.e.j.s.Server Started @2482639ms
[junit4] 2> 2482591 INFO (jetty-launcher-5226-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36533}
[junit4] 2> 2482591 ERROR (jetty-launcher-5226-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2482592 INFO (jetty-launcher-5226-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2482592 INFO (jetty-launcher-5226-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 2482592 INFO (jetty-launcher-5226-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2482592 INFO (jetty-launcher-5226-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2482592 INFO (jetty-launcher-5226-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-02T01:00:16.541Z
[junit4] 2> 2482594 INFO (zkConnectionManagerCallback-5231-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2482595 INFO (jetty-launcher-5226-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2483506 INFO (jetty-launcher-5226-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41953/solr
[junit4] 2> 2483509 INFO (zkConnectionManagerCallback-5235-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2483512 INFO (zkConnectionManagerCallback-5237-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2483567 INFO (jetty-launcher-5226-thread-1) [n:127.0.0.1:36533_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:36533_solr
[junit4] 2> 2483567 INFO (jetty-launcher-5226-thread-1) [n:127.0.0.1:36533_solr ] o.a.s.c.Overseer Overseer (id=72088651633655811-127.0.0.1:36533_solr-n_0000000000) starting
[junit4] 2> 2483572 INFO (zkConnectionManagerCallback-5244-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2483574 INFO (jetty-launcher-5226-thread-1) [n:127.0.0.1:36533_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41953/solr ready
[junit4] 2> 2483574 INFO (OverseerStateUpdate-72088651633655811-127.0.0.1:36533_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:36533_solr
[junit4] 2> 2483575 INFO (jetty-launcher-5226-thread-1) [n:127.0.0.1:36533_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36533_solr
[junit4] 2> 2483576 INFO (zkCallback-5236-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2483576 INFO (zkCallback-5243-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2483591 INFO (jetty-launcher-5226-thread-1) [n:127.0.0.1:36533_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2483606 INFO (jetty-launcher-5226-thread-1) [n:127.0.0.1:36533_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36533.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2483613 INFO (jetty-launcher-5226-thread-1) [n:127.0.0.1:36533_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36533.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2483614 INFO (jetty-launcher-5226-thread-1) [n:127.0.0.1:36533_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36533.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2483615 INFO (jetty-launcher-5226-thread-1) [n:127.0.0.1:36533_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/cdcr-source-001/node1/.
[junit4] 2> 2483637 INFO (zkConnectionManagerCallback-5247-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2483640 INFO (zkConnectionManagerCallback-5250-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2483642 INFO (zkConnectionManagerCallback-5252-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2483646 INFO (zkConnectionManagerCallback-5256-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2483647 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2483647 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41953/solr ready
[junit4] 2> 2483648 INFO (qtp28211824-17735) [n:127.0.0.1:36533_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 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> 2483650 INFO (OverseerThreadFactory-6249-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection cdcr-source
[junit4] 2> 2483756 INFO (OverseerStateUpdate-72088651633655811-127.0.0.1:36533_solr-n_0000000000) [ ] 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":"http://127.0.0.1:36533/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2483959 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1] 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_node2&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin
[junit4] 2> 2483960 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2484973 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
[junit4] 2> 2484981 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema [cdcr-source_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2484983 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2484983 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 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> 2484984 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36533.solr.core.cdcr-source.shard1.replica_n1' (registry 'solr.core.cdcr-source.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2484984 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2484984 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 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.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/cdcr-source-001/node1/cdcr-source_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/cdcr-source-001/node1/./cdcr-source_shard1_replica_n1/data/]
[junit4] 2> 2485062 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2485062 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2485063 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2485063 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2485065 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b0bae9[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2485066 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-source
[junit4] 2> 2485067 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 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> 2485067 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2485068 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@1b0bae9[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2485068 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1607646963582369792
[junit4] 2> 2485073 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-source/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 2485074 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2485074 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2485074 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36533/solr/cdcr-source_shard1_replica_n1/
[junit4] 2> 2485075 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2485075 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:36533/solr/cdcr-source_shard1_replica_n1/ has no replicas
[junit4] 2> 2485075 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2485076 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36533/solr/cdcr-source_shard1_replica_n1/ shard1
[junit4] 2> 2485178 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2485180 INFO (qtp28211824-17730) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 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_node2&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin} status=0 QTime=1220
[junit4] 2> 2485183 INFO (qtp28211824-17735) [n:127.0.0.1:36533_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> 2485280 INFO (zkCallback-5236-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 2485652 INFO (OverseerCollectionConfigSetProcessor-72088651633655811-127.0.0.1:36533_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2486183 INFO (qtp28211824-17735) [n:127.0.0.1:36533_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={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=2534
[junit4] 2> 2486201 INFO (qtp28211824-17729) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-source/terms/shard1 to Terms{values={core_node2=1}, version=1}
[junit4] 2> 2486201 INFO (qtp28211824-17729) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_0 (1607646964754677760), source_1 (1607646964758872064), source_2 (1607646964759920640), source_3 (1607646964759920641), source_4 (1607646964759920642), source_5 (1607646964759920643), source_6 (1607646964759920644), source_7 (1607646964759920645), source_8 (1607646964759920646), source_9 (1607646964759920647), ... (100 adds)]} 0 15
[junit4] 2> 2486202 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646964771454976,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2486202 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646964771454976
[junit4] 2> 2486335 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1549073[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2486336 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2486337 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@1549073[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100)))}
[junit4] 2> 2486337 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 135
[junit4] 2> 2486348 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_100 (1607646964915109888), source_101 (1607646964917207040), source_102 (1607646964917207041), source_103 (1607646964917207042), source_104 (1607646964917207043), source_105 (1607646964917207044), source_106 (1607646964917207045), source_107 (1607646964917207046), source_108 (1607646964918255616), source_109 (1607646964918255617), ... (100 adds)]} 0 9
[junit4] 2> 2486350 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646964926644224,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2486350 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646964926644224
[junit4] 2> 2486463 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1156842[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2486463 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2486465 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@1156842[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100)))}
[junit4] 2> 2486465 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 115
[junit4] 2> 2486475 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_200 (1607646965049327616), source_201 (1607646965050376192), source_202 (1607646965050376193), source_203 (1607646965050376194), source_204 (1607646965050376195), source_205 (1607646965050376196), source_206 (1607646965050376197), source_207 (1607646965050376198), source_208 (1607646965050376199), source_209 (1607646965050376200), ... (100 adds)]} 0 8
[junit4] 2> 2486476 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646965058764800,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2486476 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646965058764800
[junit4] 2> 2486599 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1835ca5[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2486599 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2486601 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@1835ca5[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100)))}
[junit4] 2> 2486601 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 125
[junit4] 2> 2486611 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_300 (1607646965190885376), source_301 (1607646965192982528), source_302 (1607646965192982529), source_303 (1607646965192982530), source_304 (1607646965192982531), source_305 (1607646965192982532), source_306 (1607646965192982533), source_307 (1607646965192982534), source_308 (1607646965192982535), source_309 (1607646965192982536), ... (100 adds)]} 0 8
[junit4] 2> 2486612 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646965201371136,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2486612 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646965201371136
[junit4] 2> 2486752 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1994423[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2486752 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2486754 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@1994423[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100)))}
[junit4] 2> 2486754 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 142
[junit4] 2> 2486763 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_400 (1607646965351317504), source_401 (1607646965352366080), source_402 (1607646965352366081), source_403 (1607646965353414656), source_404 (1607646965353414657), source_405 (1607646965353414658), source_406 (1607646965353414659), source_407 (1607646965353414660), source_408 (1607646965353414661), source_409 (1607646965353414662), ... (100 adds)]} 0 7
[junit4] 2> 2486764 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646965360754688,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2486764 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646965360754688
[junit4] 2> 2487330 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@d0109e[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2487331 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2487332 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@d0109e[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100)))}
[junit4] 2> 2487332 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 568
[junit4] 2> 2487341 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_500 (1607646965957394432), source_501 (1607646965959491584), source_502 (1607646965959491585), source_503 (1607646965959491586), source_504 (1607646965959491587), source_505 (1607646965959491588), source_506 (1607646965959491589), source_507 (1607646965959491590), source_508 (1607646965959491591), source_509 (1607646965959491592), ... (100 adds)]} 0 7
[junit4] 2> 2487342 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646965966831616,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2487342 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646965966831616
[junit4] 2> 2488076 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b2305d[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2488077 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488078 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@1b2305d[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100)))}
[junit4] 2> 2488078 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 736
[junit4] 2> 2488087 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_600 (1607646966740680704), source_601 (1607646966741729280), source_602 (1607646966741729281), source_603 (1607646966741729282), source_604 (1607646966741729283), source_605 (1607646966741729284), source_606 (1607646966741729285), source_607 (1607646966742777856), source_608 (1607646966742777857), source_609 (1607646966742777858), ... (100 adds)]} 0 7
[junit4] 2> 2488088 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646966749069312,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488088 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646966749069312
[junit4] 2> 2488624 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1c49e9e[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2488625 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488626 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@1c49e9e[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100)))}
[junit4] 2> 2488626 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 538
[junit4] 2> 2488635 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_700 (1607646967314251776), source_701 (1607646967316348928), source_702 (1607646967316348929), source_703 (1607646967316348930), source_704 (1607646967316348931), source_705 (1607646967316348932), source_706 (1607646967316348933), source_707 (1607646967316348934), source_708 (1607646967316348935), source_709 (1607646967316348936), ... (100 adds)]} 0 7
[junit4] 2> 2488637 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646967324737536,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488637 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646967324737536
[junit4] 2> 2489977 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@173e62[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2489978 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2489979 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@173e62[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100)))}
[junit4] 2> 2489979 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 1342
[junit4] 2> 2489988 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_800 (1607646968732975104), source_801 (1607646968735072256), source_802 (1607646968735072257), source_803 (1607646968735072258), source_804 (1607646968735072259), source_805 (1607646968735072260), source_806 (1607646968735072261), source_807 (1607646968735072262), source_808 (1607646968735072263), source_809 (1607646968735072264), ... (100 adds)]} 0 7
[junit4] 2> 2489989 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646968742412288,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2489989 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646968742412288
[junit4] 2> 2490636 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1bf17d5[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2490637 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2490638 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@1bf17d5[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100)))}
[junit4] 2> 2490638 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 649
[junit4] 2> 2490648 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_900 (1607646969423986688), source_901 (1607646969426083840), source_902 (1607646969426083841), source_903 (1607646969426083842), source_904 (1607646969426083843), source_905 (1607646969426083844), source_906 (1607646969426083845), source_907 (1607646969426083846), source_908 (1607646969426083847), source_909 (1607646969426083848), ... (100 adds)]} 0 8
[junit4] 2> 2490649 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1607646969434472448,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2490649 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c58393 commitCommandVersion:1607646969434472448
[junit4] 2> 2491279 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@fa83c4[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2491280 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2491281 INFO (searcherExecutor-6254-thread-1-processing-n:127.0.0.1:36533_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))}
[junit4] 2> 2491281 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 632
[junit4] 2> 2491282 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.c.CdcrBootstrapTest Adding numDocs=1000
[junit4] 2> 2491283 INFO (qtp28211824-17733) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 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> 2491285 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_0(7.5.0):C100)) docBase=0 ord=0) mavVersion:9223372036854775807
[junit4] 2> 2491285 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_1(7.5.0):C100)) docBase=100 ord=1) mavVersion:9223372036854775807
[junit4] 2> 2491285 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_2(7.5.0):C100)) docBase=200 ord=2) mavVersion:9223372036854775807
[junit4] 2> 2491286 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_3(7.5.0):C100)) docBase=300 ord=3) mavVersion:9223372036854775807
[junit4] 2> 2491286 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_4(7.5.0):C100)) docBase=400 ord=4) mavVersion:9223372036854775807
[junit4] 2> 2491286 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_5(7.5.0):C100)) docBase=500 ord=5) mavVersion:9223372036854775807
[junit4] 2> 2491286 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_6(7.5.0):C100)) docBase=600 ord=6) mavVersion:9223372036854775807
[junit4] 2> 2491286 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_7(7.5.0):C100)) docBase=700 ord=7) mavVersion:9223372036854775807
[junit4] 2> 2491287 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_8(7.5.0):C100)) docBase=800 ord=8) mavVersion:9223372036854775807
[junit4] 2> 2491287 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@fa83c4[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_9(7.5.0):C100)) docBase=900 ord=9) mavVersion:9223372036854775807
[junit4] 2> 2491287 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.IndexFingerprint IndexFingerprint millis:2.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=1607646969432375310, maxInHash=1607646969432375310, versionsHash=-1162066904035738269, numVersions=1000, numDocs=1000, maxDoc=100}
[junit4] 2> 2491287 INFO (qtp28211824-17783) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/get params={qt=/get&_stateVer_=cdcr-source:4&fingerprint=true&getVersions=1000&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 2491289 INFO (zkConnectionManagerCallback-5258-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2491293 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1d07bd7{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 2491294 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=29981340
[junit4] 2> 2491295 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 2491295 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1e53a05: rootName = solr_36533, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@1df7627
[junit4] 2> 2491302 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 2491302 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1b21543: rootName = solr_36533, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@1cae35c
[junit4] 2> 2491310 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 2491310 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@cd53ce: rootName = solr_36533, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@1ca0cd0
[junit4] 2> 2491312 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:36533_solr
[junit4] 2> 2491313 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 2491313 INFO (zkCallback-5243-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 2491313 INFO (zkCallback-5236-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 2491313 INFO (zkCallback-5255-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 2491314 INFO (zkCallback-5236-thread-2) [ ] 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: [0])
[junit4] 2> 2491314 INFO (coreCloseExecutor-6259-thread-1) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@1b64761
[junit4] 2> 2491314 INFO (coreCloseExecutor-6259-thread-1) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.cdcr-source.shard1.replica_n1, tag=1b64761
[junit4] 2> 2491314 INFO (coreCloseExecutor-6259-thread-1) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@10bdc5c: rootName = solr_36533, domain = solr.core.cdcr-source.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.cdcr-source.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@1a6d7f1
[junit4] 2> 2491323 INFO (coreCloseExecutor-6259-thread-1) [n:127.0.0.1:36533_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.cdcr-source.shard1.leader, tag=1b64761
[junit4] 2> 2491326 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.Overseer Overseer (id=72088651633655811-127.0.0.1:36533_solr-n_0000000000) closing
[junit4] 2> 2491327 INFO (OverseerStateUpdate-72088651633655811-127.0.0.1:36533_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:36533_solr
[junit4] 2> 2491327 WARN (OverseerAutoScalingTriggerThread-72088651633655811-127.0.0.1:36533_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 2491329 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1ee0be8{/solr,null,UNAVAILABLE}
[junit4] 2> 2491329 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 2491330 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 2491330 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2491330 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2491331 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2491331 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@12f6be1{/solr,null,AVAILABLE}
[junit4] 2> 2491331 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1d42647{HTTP/1.1,[http/1.1]}{127.0.0.1:42253}
[junit4] 2> 2491331 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.e.j.s.Server Started @2491379ms
[junit4] 2> 2491331 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42253}
[junit4] 2> 2491332 ERROR (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2491332 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2491332 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 2491332 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2491332 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2491332 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-02T01:00:25.281Z
[junit4] 2> 2491334 INFO (zkConnectionManagerCallback-5260-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2491334 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2493115 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41953/solr
[junit4] 2> 2493117 INFO (zkConnectionManagerCallback-5264-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2493119 INFO (zkConnectionManagerCallback-5266-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2493125 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42253_solr
[junit4] 2> 2493126 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.c.Overseer Overseer (id=72088651633655820-127.0.0.1:42253_solr-n_0000000001) starting
[junit4] 2> 2493130 INFO (zkConnectionManagerCallback-5273-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2493133 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41953/solr ready
[junit4] 2> 2493133 INFO (OverseerStateUpdate-72088651633655820-127.0.0.1:42253_solr-n_0000000001) [ ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:42253_solr
[junit4] 2> 2493134 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42253_solr
[junit4] 2> 2493134 INFO (zkCallback-5255-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2493134 INFO (zkCallback-5265-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2493134 INFO (zkCallback-5272-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2493153 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2493169 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42253.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2493178 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42253.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2493179 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42253.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2493188 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/cdcr-source-001/node1/.
[junit4] 2> 2493188 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [n:127.0.0.1:42253_solr ] o.a.s.c.CorePropertiesLocator Cores are: [cdcr-source_shard1_replica_n1]
[junit4] 2> 2493189 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2493198 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
[junit4] 2> 2493204 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr ] 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> 2493207 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr ] o.a.s.s.IndexSchema [cdcr-source_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2493209 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2493210 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr ] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/cdcr-source/managed-schema
[junit4] 2> 2493212 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr ] 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> 2494225 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
[junit4] 2> 2494236 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema [cdcr-source_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2494238 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2494238 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 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> 2494238 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42253.solr.core.cdcr-source.shard1.replica_n1' (registry 'solr.core.cdcr-source.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@81681b
[junit4] 2> 2494239 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2494239 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 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.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/cdcr-source-001/node1/cdcr-source_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001/cdcr-source-001/node1/./cdcr-source_shard1_replica_n1/data/]
[junit4] 2> 2494313 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 2494314 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2494315 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2494315 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2494335 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@c0a4d[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2494337 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-source
[junit4] 2> 2494337 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 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> 2494337 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 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> 2494337 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2494338 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2494343 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrBufferStateManager Created znode /collections/cdcr-source/cdcr/state/buffer
[junit4] 2> 2494348 INFO (coreLoadExecutor-6273-thread-1-processing-n:127.0.0.1:42253_solr) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrProcessStateManager Created znode /collections/cdcr-source/cdcr/state/process
[junit4] 2> 2494367 INFO (searcherExecutor-6274-thread-1-processing-n:127.0.0.1:42253_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@c0a4d[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.5.0):C100) Uninverting(_1(7.5.0):C100) Uninverting(_2(7.5.0):C100) Uninverting(_3(7.5.0):C100) Uninverting(_4(7.5.0):C100) Uninverting(_5(7.5.0):C100) Uninverting(_6(7.5.0):C100) Uninverting(_7(7.5.0):C100) Uninverting(_8(7.5.0):C100) Uninverting(_9(7.5.0):C100)))}
[junit4] 2> 2494367 WARN (cdcr-update-log-synchronizer-6279-thread-1) [ ] o.a.s.h.CdcrUpdateLogSynchronizer Caught unexpected exception
[junit4] 2> org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:42253/solr/cdcr-source_shard1_replica_n1: SolrCore is loading
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643) ~[java/:?]
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255) ~[java/:?]
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244) ~[java/:?]
[junit4] 2> at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) ~[java/:?]
[junit4] 2> at org.apache.solr.handler.CdcrUpdateLogSynchronizer$UpdateLogSynchronisation.run(CdcrUpdateLogSynchronizer.java:147) [java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 2494368 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[D7614FFF0D149393]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: cdcr-source failOnTimeout:true timeout (sec):330
[junit4] 1> -
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 2> 2494370 INFO (coreZkRegister-6261-thread-1-processing-n:127.0.0.1:42253_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2494371 INFO (coreZkRegister-6261-thread-1-processing-n:127.0.0.1:42253_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2494371 INFO (coreZkRegister-6261-thread-1-processing-n:127.0.0.1:42253_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:42253/solr/cdcr-source_shard1_replica_n1/
[junit4] 2> 2494371 INFO (coreZkRegister-6261-thread-1-processing-n:127.0.0.1:42253_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2494371 INFO (coreZkRegister-6261-thread-1-processing-n:127.0.0.1:42253_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:42253/solr/cdcr-source_shard1_replica_n1/ has no replicas
[junit4] 2> 2494371 INFO (coreZkRegister-6261-thread-1-processing-n:127.0.0.1:42253_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2494372 INFO (zkCallback-5265-thread-1) [ ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-source:shard1
[junit4] 2> 2494372 INFO (coreZkRegister-6261-thread-1-processing-n:127.0.0.1:42253_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:42253/solr/cdcr-source_shard1_replica_n1/ shard1
[junit4] 2> 2494373 INFO (coreZkRegister-6261-thread-1-processing-n:127.0.0.1:42253_solr x:cdcr-source_shard1_replica_n1 c:cdcr-source s:shard1 r:core_node2) [n:127.0.0.1:42253_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necess
[...truncated too long message...]
losing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 2664119 INFO (zkCallback-5366-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 2664120 INFO (zkCallback-5373-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 2664120 INFO (coreCloseExecutor-6409-thread-1) [n:127.0.0.1:43415_solr c:cdcr-target s:shard1 r:core_node2 x:cdcr-target_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-target_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@1196019
[junit4] 2> 2664120 INFO (coreCloseExecutor-6409-thread-1) [n:127.0.0.1:43415_solr c:cdcr-target s:shard1 r:core_node2 x:cdcr-target_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.cdcr-target.shard1.replica_n1, tag=1196019
[junit4] 2> 2664120 INFO (zkCallback-5366-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [0])
[junit4] 2> 2664120 INFO (coreCloseExecutor-6409-thread-1) [n:127.0.0.1:43415_solr c:cdcr-target s:shard1 r:core_node2 x:cdcr-target_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@18fcda0: rootName = solr_43415, domain = solr.core.cdcr-target.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.cdcr-target.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@16c3282
[junit4] 2> 2664130 INFO (coreCloseExecutor-6409-thread-1) [n:127.0.0.1:43415_solr c:cdcr-target s:shard1 r:core_node2 x:cdcr-target_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.cdcr-target.shard1.leader, tag=1196019
[junit4] 2> 2664130 INFO (coreCloseExecutor-6409-thread-1) [n:127.0.0.1:43415_solr c:cdcr-target s:shard1 r:core_node2 x:cdcr-target_shard1_replica_n1] o.a.s.h.CdcrRequestHandler Solr core is being closed - shutting down CDCR handler @ cdcr-target:shard1
[junit4] 2> 2664132 INFO (jetty-closer-5357-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72088662101786627-127.0.0.1:43415_solr-n_0000000000) closing
[junit4] 2> 2664132 INFO (OverseerStateUpdate-72088662101786627-127.0.0.1:43415_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43415_solr
[junit4] 2> 2664132 WARN (OverseerAutoScalingTriggerThread-72088662101786627-127.0.0.1:43415_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 2664134 INFO (jetty-closer-5357-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@52d38b{/solr,null,UNAVAILABLE}
[junit4] 2> 2664134 INFO (jetty-closer-5357-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 2664134 ERROR (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[D7614FFF0D149393]) [ ] 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> 2664135 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[D7614FFF0D149393]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37405 37405
[junit4] 2> 2664240 INFO (Thread-3695) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37405 37405
[junit4] 2> 2664240 WARN (Thread-3695) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 4 /solr/aliases.json
[junit4] 2> 4 /solr/clusterprops.json
[junit4] 2> 2 /solr/collections/cdcr-target/terms/shard1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 4 /solr/clusterstate.json
[junit4] 2> 2 /solr/collections/cdcr-target/cdcr/state/process
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 4 /solr/live_nodes
[junit4] 2> 4 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBootstrapTest_D7614FFF0D149393-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70), sim=RandomSimilarity(queryNorm=true): {}, locale=da, timezone=Africa/Dakar
[junit4] 2> NOTE: Linux 4.15.0-29-generic i386/Oracle Corporation 1.8.0_172 (32-bit)/cpus=8,threads=1,free=223983864,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [TestReqParamsAPI, TestPhraseSuggestions, TestInfoStreamLogging, HdfsRecoveryZkTest, AliasIntegrationTest, ClassificationUpdateProcessorFactoryTest, SyncSliceTest, QueryEqualityTest, TestConfigSets, TestIntervalFaceting, SuggesterTest, MetricsHandlerTest, TestSubQueryTransformerDistrib, PrimUtilsTest, ShardRoutingTest, TestCustomSort, TestBinaryField, TestSolrQueryParser, FileUtilsTest, TimeZoneUtilsTest, CloneFieldUpdateProcessorFactoryTest, TestConfigSetsAPI, TestFilteredDocIdSet, SpellPossibilityIteratorTest, GraphQueryTest, TestDocBasedVersionConstraints, UpdateLogTest, ReplicaListTransformerTest, MetricTriggerTest, CoreAdminRequestStatusTest, ChaosMonkeySafeLeaderWithPullReplicasTest, ConnectionReuseTest, TestDynamicFieldCollectionResource, NoCacheHeaderTest, TestSortByMinMaxFunction, CloudExitableDirectoryReaderTest, ShufflingReplicaListTransformerTest, CacheHeaderTest, TestFieldResource, TestStressUserVersions, NodeMutatorTest, SolrMetricReporterTest, TestCollectionAPI, TestNamedUpdateProcessors, TestJsonFacetsStatsParsing, TestGenericDistributedQueue, HdfsWriteToMultipleCollectionsTest, HighlighterTest, TestDynamicLoading, CollectionPropsTest, TestDistributedMap, ResponseBuilderTest, SoftAutoCommitTest, EchoParamsTest, TestZkChroot, SuggestComponentContextFilterQueryTest, TestLegacyNumericRangeQueryBuilder, TestInPlaceUpdatesDistrib, HdfsThreadLeakTest, DeleteShardTest, PeerSyncReplicationTest, NodeLostTriggerIntegrationTest, TestCorePropertiesReload, TestSkipOverseerOperations, TestSolrCoreParser, TestHalfAndHalfDocValues, TestMultiWordSynonyms, TestDistribIDF, TestReRankQParserPlugin, IgnoreLargeDocumentProcessorFactoryTest, SpatialFilterTest, TestRandomDVFaceting, PeerSyncWithIndexFingerprintCachingTest, ReturnFieldsTest, CollectionReloadTest, TestSQLHandlerNonCloud, LIROnShardRestartTest, DistribDocExpirationUpdateProcessorTest, TestTriggerIntegration, TestGroupingSearch, TestExpandComponent, TestCloudDeleteByQuery, HdfsCollectionsAPIDistributedZkTest, DistributedSpellCheckComponentTest, ConfigureRecoveryStrategyTest, UniqFieldsUpdateProcessorFactoryTest, TestComplexPhraseLeadingWildcard, RestoreTriggerStateTest, CheckHdfsIndexTest, SampleTest, TestStressLucene, TestComputePlanAction, ConcurrentCreateRoutedAliasTest, TestSystemIdResolver, TestLRUStatsCache, TestCloudJSONFacetSKG, ZkControllerTest, CreateCollectionCleanupTest, PluginInfoTest, HLLSerializationTest, ZkStateReaderTest, DistributedQueryComponentCustomSortTest, XmlUpdateRequestHandlerTest, TestNumericTerms32, TestFieldCacheVsDocValues, TestSweetSpotSimilarityFactory, TestRecoveryHdfs, SolrIndexMetricsTest, TestHdfsBackupRestoreCore, TestExtendedDismaxParser, IndexBasedSpellCheckerTest, DistributedFacetPivotLargeTest, CursorMarkTest, TestRandomCollapseQParserPlugin, TestHashPartitioner, TestBadConfig, ChaosMonkeyNothingIsSafeTest, MetricsConfigTest, CoreAdminCreateDiscoverTest, TestNodeLostTrigger, TriggerIntegrationTest, FullSolrCloudDistribCmdsTest, TestNumericTokenStream, BadCopyFieldTest, TestChildDocTransformer, TestSolrCloudWithSecureImpersonation, TestCloudSchemaless, RegexBoostProcessorTest, TestUseDocValuesAsStored, BufferStoreTest, EmbeddedSolrNoSerializeTest, LoggingHandlerTest, DataDrivenBlockJoinTest, TestGraphTermsQParserPlugin, DeleteInactiveReplicaTest, DistribJoinFromCollectionTest, DistributedQueueTest, HttpPartitionOnCommitTest, HttpPartitionTest, LIRRollingUpdatesTest, LeaderElectionTest, LeaderVoteWaitTimeoutTest, MigrateRouteKeyTest, RemoteQueryErrorTest, SolrCloudExampleTest, TestCryptoKeys, TestPrepRecovery, TestRebalanceLeaders, TestTolerantUpdateProcessorRandomCloud, ZkCLITest, ZkSolrClientTest, CollectionTooManyReplicasTest, CollectionsAPIDistributedZkTest, HdfsAutoAddReplicasIntegrationTest, HttpTriggerListenerTest, IndexSizeTriggerTest, MetricTriggerIntegrationTest, TriggerCooldownIntegrationTest, CdcrBootstrapTest]
[junit4] Completed [575/826 (1!)] on J0 in 182.88s, 3 tests, 1 failure <<< FAILURES!
[...truncated 45370 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2466/consoleText
[repro] Revision: 7faa803a7c9699f38b8a6b3ddd3a88c4729c5e5f
[repro] Ant options: "-Dargs=-client -XX:+UseConcMarkSweepGC"
[repro] Repro line: ant test -Dtestcase=CdcrBootstrapTest -Dtests.method=testBootstrapWithContinousIndexingOnSourceCluster -Dtests.seed=D7614FFF0D149393 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=da -Dtests.timezone=Africa/Dakar -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] CdcrBootstrapTest
[repro] ant compile-test
[...truncated 3333 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.CdcrBootstrapTest" -Dtests.showOutput=onerror "-Dargs=-client -XX:+UseConcMarkSweepGC" -Dtests.seed=D7614FFF0D149393 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=da -Dtests.timezone=Africa/Dakar -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 81 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.cdcr.CdcrBootstrapTest
[repro] Exiting with code 0
[...truncated 40 lines...]