Since August 17th, This test seems to have started failing multiple times a day, on 7x and master, on diff jvms and OSs -- prior to Aug17 it rarely failed more then once a week.
: Date: Thu, 31 Aug 2017 15:37:21 +0000 (UTC) : From: Policeman Jenkins Server <[email protected]> : Reply-To: [email protected] : To: [email protected] : Subject: [JENKINS] Lucene-Solr-7.0-Linux (64bit/jdk1.8.0_144) - Build # 284 - : Unstable! : : Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.0-Linux/284/ : Java: 64bit/jdk1.8.0_144 -XX:+UseCompressedOops -XX:+UseParallelGC : : 1 tests failed. : FAILED: org.apache.solr.cloud.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster : : Error Message: : Document mismatch on target after sync expected:<2000> but was:<1023> : : Stack Trace: : java.lang.AssertionError: Document mismatch on target after sync expected:<2000> but was:<1023> : at __randomizedtesting.SeedInfo.seed([919AD2A8090BD205:45DF99F1EE5D61FE]:0) : at org.junit.Assert.fail(Assert.java:93) : at org.junit.Assert.failNotEquals(Assert.java:647) : at org.junit.Assert.assertEquals(Assert.java:128) : at org.junit.Assert.assertEquals(Assert.java:472) : at org.apache.solr.cloud.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster(CdcrBootstrapTest.java:309) : at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) : at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) : at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) : at java.lang.reflect.Method.invoke(Method.java:498) : at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) : at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) : at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) : at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) : at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) : at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) : at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) : at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) : at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) : at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) : at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) : at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) : at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) : at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) : at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) : at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) : at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) : at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) : at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) : at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) : at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) : at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) : at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) : at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) : at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) : at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) : at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) : at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) : at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) : at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) : at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) : at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) : at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) : at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) : at java.lang.Thread.run(Thread.java:748) : : : : : Build Log: : [...truncated 12234 lines...] : [junit4] Suite: org.apache.solr.cloud.CdcrBootstrapTest : [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001/init-core-data-001 : [junit4] 2> 1565819 WARN (SUITE-CdcrBootstrapTest-seed#[919AD2A8090BD205]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=9 numCloses=9 : [junit4] 2> 1565819 INFO (SUITE-CdcrBootstrapTest-seed#[919AD2A8090BD205]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true : [junit4] 2> 1565820 INFO (SUITE-CdcrBootstrapTest-seed#[919AD2A8090BD205]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN) : [junit4] 2> 1565822 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBootstrapWithSourceCluster : [junit4] 2> 1565822 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001/cdcr-target-001 : [junit4] 2> 1565822 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER : [junit4] 2> 1565822 INFO (Thread-3303) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 : [junit4] 2> 1565822 INFO (Thread-3303) [ ] o.a.s.c.ZkTestServer Starting server : [junit4] 2> 1565824 ERROR (Thread-3303) [ ] 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> 1565922 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.ZkTestServer start zk server on port:45707 : [junit4] 2> 1565925 INFO (jetty-launcher-1953-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 : [junit4] 2> 1565926 INFO (jetty-launcher-1953-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@23c7c468{/solr,null,AVAILABLE} : [junit4] 2> 1565929 INFO (jetty-launcher-1953-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@72802602{HTTP/1.1,[http/1.1]}{127.0.0.1:43615} : [junit4] 2> 1565929 INFO (jetty-launcher-1953-thread-1) [ ] o.e.j.s.Server Started @1567513ms : [junit4] 2> 1565929 INFO (jetty-launcher-1953-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43615} : [junit4] 2> 1565929 ERROR (jetty-launcher-1953-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. : [junit4] 2> 1565929 INFO (jetty-launcher-1953-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 : [junit4] 2> 1565929 INFO (jetty-launcher-1953-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null : [junit4] 2> 1565929 INFO (jetty-launcher-1953-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null : [junit4] 2> 1565929 INFO (jetty-launcher-1953-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T15:04:37.153Z : [junit4] 2> 1565934 INFO (jetty-launcher-1953-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... : [junit4] 2> 1565939 INFO (jetty-launcher-1953-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45707/solr : [junit4] 2> 1565969 INFO (jetty-launcher-1953-thread-1) [n:127.0.0.1:43615_solr ] o.a.s.c.Overseer Overseer (id=null) closing : [junit4] 2> 1565969 INFO (jetty-launcher-1953-thread-1) [n:127.0.0.1:43615_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43615_solr : [junit4] 2> 1565969 INFO (jetty-launcher-1953-thread-1) [n:127.0.0.1:43615_solr ] o.a.s.c.Overseer Overseer (id=98578718854152195-127.0.0.1:43615_solr-n_0000000000) starting : [junit4] 2> 1565971 INFO (jetty-launcher-1953-thread-1) [n:127.0.0.1:43615_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43615_solr : [junit4] 2> 1565972 INFO (zkCallback-1960-thread-1-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) : [junit4] 2> 1566021 INFO (jetty-launcher-1953-thread-1) [n:127.0.0.1:43615_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43615.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@520e8c87 : [junit4] 2> 1566029 INFO (jetty-launcher-1953-thread-1) [n:127.0.0.1:43615_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43615.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@520e8c87 : [junit4] 2> 1566029 INFO (jetty-launcher-1953-thread-1) [n:127.0.0.1:43615_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43615.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@520e8c87 : [junit4] 2> 1566030 INFO (jetty-launcher-1953-thread-1) [n:127.0.0.1:43615_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001/cdcr-target-001/node1/. : [junit4] 1> Target zkHost = 127.0.0.1:45707/solr : [junit4] 2> 1566047 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001/cdcr-source-001 : [junit4] 2> 1566048 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER : [junit4] 2> 1566048 INFO (Thread-3313) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 : [junit4] 2> 1566048 INFO (Thread-3313) [ ] o.a.s.c.ZkTestServer Starting server : [junit4] 2> 1566054 ERROR (Thread-3313) [ ] 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> 1566148 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.ZkTestServer start zk server on port:38635 : [junit4] 2> 1566153 INFO (jetty-launcher-1965-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 : [junit4] 2> 1566153 INFO (jetty-launcher-1965-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@396ce975{/solr,null,AVAILABLE} : [junit4] 2> 1566154 INFO (jetty-launcher-1965-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@14350e2a{HTTP/1.1,[http/1.1]}{127.0.0.1:37233} : [junit4] 2> 1566154 INFO (jetty-launcher-1965-thread-1) [ ] o.e.j.s.Server Started @1567738ms : [junit4] 2> 1566154 INFO (jetty-launcher-1965-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37233} : [junit4] 2> 1566154 ERROR (jetty-launcher-1965-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. : [junit4] 2> 1566154 INFO (jetty-launcher-1965-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 : [junit4] 2> 1566154 INFO (jetty-launcher-1965-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null : [junit4] 2> 1566155 INFO (jetty-launcher-1965-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null : [junit4] 2> 1566155 INFO (jetty-launcher-1965-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T15:04:37.379Z : [junit4] 2> 1566156 INFO (jetty-launcher-1965-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... : [junit4] 2> 1566162 INFO (jetty-launcher-1965-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38635/solr : [junit4] 2> 1566187 INFO (jetty-launcher-1965-thread-1) [n:127.0.0.1:37233_solr ] o.a.s.c.Overseer Overseer (id=null) closing : [junit4] 2> 1566188 INFO (jetty-launcher-1965-thread-1) [n:127.0.0.1:37233_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37233_solr : [junit4] 2> 1566188 INFO (jetty-launcher-1965-thread-1) [n:127.0.0.1:37233_solr ] o.a.s.c.Overseer Overseer (id=98578718869159939-127.0.0.1:37233_solr-n_0000000000) starting : [junit4] 2> 1566190 INFO (jetty-launcher-1965-thread-1) [n:127.0.0.1:37233_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37233_solr : [junit4] 2> 1566190 INFO (OverseerStateUpdate-98578718869159939-127.0.0.1:37233_solr-n_0000000000) [n:127.0.0.1:37233_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) : [junit4] 2> 1566240 INFO (jetty-launcher-1965-thread-1) [n:127.0.0.1:37233_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37233.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@520e8c87 : [junit4] 2> 1566248 INFO (jetty-launcher-1965-thread-1) [n:127.0.0.1:37233_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37233.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@520e8c87 : [junit4] 2> 1566248 INFO (jetty-launcher-1965-thread-1) [n:127.0.0.1:37233_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37233.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@520e8c87 : [junit4] 2> 1566249 INFO (jetty-launcher-1965-thread-1) [n:127.0.0.1:37233_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001/cdcr-source-001/node1/. : [junit4] 2> 1566308 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) : [junit4] 2> 1566308 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38635/solr ready : [junit4] 2> 1566309 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&nrtReplicas=1&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2 and sendToOCPQueue=true : [junit4] 2> 1566309 INFO (OverseerThreadFactory-5946-thread-1-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.c.CreateCollectionCmd Create collection cdcr-source : [junit4] 2> 1566412 INFO (OverseerStateUpdate-98578718869159939-127.0.0.1:37233_solr-n_0000000000) [n:127.0.0.1:37233_solr ] o.a.s.c.o.SliceMutator createReplica() { : [junit4] 2> "operation":"ADDREPLICA", : [junit4] 2> "collection":"cdcr-source", : [junit4] 2> "shard":"shard1", : [junit4] 2> "core":"cdcr-source_shard1_replica_n1", : [junit4] 2> "state":"down", : [junit4] 2> "base_url":"http://127.0.0.1:37233/solr";, : [junit4] 2> "type":"NRT"} : [junit4] 2> 1566613 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&collection=cdcr-source&version=2&replicaType=NRT&coreNodeName=core_node1&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin : [junit4] 2> 1566614 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores : [junit4] 2> 1566716 INFO (zkCallback-1972-thread-1-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1566717 INFO (zkCallback-1972-thread-2-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1567620 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 : [junit4] 2> 1567623 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead : [junit4] 2> 1567624 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema [cdcr-source_shard1_replica_n1] Schema name=minimal : [junit4] 2> 1567625 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id : [junit4] 2> 1567626 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/cdcr-source/managed-schema : [junit4] 2> 1567626 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/cdcr-source/schema.xml to /configs/cdcr-source/schema.xml.bak : [junit4] 2> 1567626 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-source_shard1_replica_n1' using configuration from collection cdcr-source, trusted=true : [junit4] 2> 1567627 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37233.solr.core.cdcr-source.shard1.replica_n1' (registry 'solr.core.cdcr-source.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@520e8c87 : [junit4] 2> 1567627 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder : [junit4] 2> 1567627 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [[cdcr-source_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001/cdcr-source-001/node1/cdcr-source_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001/cdcr-source-001/node1/./cdcr-source_shard1_replica_n1/data/] : [junit4] 2> 1567679 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog : [junit4] 2> 1567679 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 : [junit4] 2> 1567680 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled : [junit4] 2> 1567680 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled : [junit4] 2> 1567681 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@78710552[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1567681 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-source : [junit4] 2> 1567682 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-source : [junit4] 2> 1567682 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-source/managed-schema : [junit4] 2> 1567682 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest : [junit4] 2> 1567682 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 : [junit4] 2> 1567684 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrBufferStateManager Created znode /collections/cdcr-source/cdcr/state/buffer : [junit4] 2> 1567686 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrProcessStateManager Created znode /collections/cdcr-source/cdcr/state/process : [junit4] 2> 1567699 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@78710552[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} : [junit4] 2> 1567699 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577259503633563648 : [junit4] 2> 1567703 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. : [junit4] 2> 1567703 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync : [junit4] 2> 1567703 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:37233/solr/cdcr-source_shard1_replica_n1/ : [junit4] 2> 1567703 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me : [junit4] 2> 1567703 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:37233/solr/cdcr-source_shard1_replica_n1/ has no replicas : [junit4] 2> 1567704 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR : [junit4] 2> 1567705 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:37233/solr/cdcr-source_shard1_replica_n1/ shard1 : [junit4] 2> 1567705 INFO (zkCallback-1972-thread-2-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-source:shard1 : [junit4] 2> 1567807 INFO (zkCallback-1972-thread-1-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1567807 INFO (zkCallback-1972-thread-2-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1567855 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary : [junit4] 2> 1567856 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&collection=cdcr-source&version=2&replicaType=NRT&coreNodeName=core_node1&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin} status=0 QTime=1242 : [junit4] 2> 1567857 INFO (qtp871894883-12712) [n:127.0.0.1:37233_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> 1567959 INFO (zkCallback-1972-thread-2-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1567959 INFO (zkCallback-1972-thread-1-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1568310 INFO (OverseerCollectionConfigSetProcessor-98578718869159939-127.0.0.1:37233_solr-n_0000000000) [n:127.0.0.1:37233_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper : [junit4] 2> 1568857 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&nrtReplicas=1&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2} status=0 QTime=2548 : [junit4] 1> Adding 10 docs with commit=true, numDocs=100 : [junit4] 2> 1568864 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=5 : [junit4] 2> 1568865 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259504856203264,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1568865 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259504856203264 : [junit4] 2> 1568955 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6581721b[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1568956 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1568957 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@6581721b[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100)))} : [junit4] 2> 1568957 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=92 : [junit4] 1> Adding 10 docs with commit=true, numDocs=200 : [junit4] 2> 1568962 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=4 : [junit4] 2> 1568963 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259504958963712,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1568963 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259504958963712 : [junit4] 2> 1569110 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2ac859d5[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1569110 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1569111 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@2ac859d5[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100) Uninverting(_1(7.0.0):C100)))} : [junit4] 2> 1569111 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=147 : [junit4] 1> Adding 10 docs with commit=true, numDocs=300 : [junit4] 2> 1569114 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=2 : [junit4] 2> 1569114 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259505117298688,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1569114 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259505117298688 : [junit4] 2> 1569223 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@39ca7620[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1569223 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1569224 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@39ca7620[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100) Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100)))} : [junit4] 2> 1569224 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=109 : [junit4] 1> Adding 10 docs with commit=true, numDocs=400 : [junit4] 2> 1569227 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=2 : [junit4] 2> 1569227 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259505235787779,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1569227 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259505235787779 : [junit4] 2> 1569349 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5024157c[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1569349 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1569349 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@5024157c[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100) Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) Uninverting(_3(7.0.0):C100)))} : [junit4] 2> 1569350 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=122 : [junit4] 1> Adding 10 docs with commit=true, numDocs=500 : [junit4] 2> 1569352 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=1 : [junit4] 2> 1569352 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259505366859777,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1569352 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259505366859777 : [junit4] 2> 1569495 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5fdeef74[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1569495 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1569495 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@5fdeef74[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100) Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100)))} : [junit4] 2> 1569496 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=143 : [junit4] 1> Adding 10 docs with commit=true, numDocs=600 : [junit4] 2> 1569498 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=1 : [junit4] 2> 1569498 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259505519951879,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1569498 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259505519951879 : [junit4] 2> 1569658 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6321add7[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1569658 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1569659 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@6321add7[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100) Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) Uninverting(_5(7.0.0):C100)))} : [junit4] 2> 1569659 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=160 : [junit4] 1> Adding 10 docs with commit=true, numDocs=700 : [junit4] 2> 1569661 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=1 : [junit4] 2> 1569662 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259505691918336,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1569662 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259505691918336 : [junit4] 2> 1569834 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@be1fa3b[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1569834 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1569835 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@be1fa3b[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100) Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) Uninverting(_5(7.0.0):C100) Uninverting(_6(7.0.0):C100)))} : [junit4] 2> 1569835 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=173 : [junit4] 1> Adding 10 docs with commit=true, numDocs=800 : [junit4] 2> 1569838 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=2 : [junit4] 2> 1569839 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259505877516288,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1569839 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259505877516288 : [junit4] 2> 1570033 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@525ebe82[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1570033 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1570034 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@525ebe82[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100) Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) Uninverting(_5(7.0.0):C100) Uninverting(_6(7.0.0):C100) Uninverting(_7(7.0.0):C100)))} : [junit4] 2> 1570034 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=195 : [junit4] 1> Adding 10 docs with commit=true, numDocs=900 : [junit4] 2> 1570036 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=1 : [junit4] 2> 1570036 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259506084085813,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1570036 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259506084085813 : [junit4] 2> 1570244 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@49d6a5bd[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1570244 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1570245 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@49d6a5bd[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100) Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) Uninverting(_5(7.0.0):C100) Uninverting(_6(7.0.0):C100) Uninverting(_7(7.0.0):C100) Uninverting(_8(7.0.0):C100)))} : [junit4] 2> 1570245 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=208 : [junit4] 1> Adding 10 docs with commit=true, numDocs=1000 : [junit4] 2> 1570248 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2} status=0 QTime=1 : [junit4] 2> 1570248 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259506306383878,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1570248 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259506306383878 : [junit4] 2> 1570481 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4783dcc1[cdcr-source_shard1_replica_n1] main] : [junit4] 2> 1570481 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1570482 INFO (searcherExecutor-5949-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@4783dcc1[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C100) Uninverting(_1(7.0.0):C100) Uninverting(_2(7.0.0):C100) Uninverting(_3(7.0.0):C100) Uninverting(_4(7.0.0):C100) Uninverting(_5(7.0.0):C100) Uninverting(_6(7.0.0):C100) Uninverting(_7(7.0.0):C100) Uninverting(_8(7.0.0):C100) Uninverting(_9(7.0.0):C100)))} : [junit4] 2> 1570483 INFO (qtp871894883-12712) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=235 : [junit4] 2> 1570484 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&_stateVer_=cdcr-source:4&wt=javabin&version=2} hits=1000 status=0 QTime=0 : [junit4] 2> 1570487 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) : [junit4] 2> 1570487 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:45707/solr ready : [junit4] 2> 1570488 INFO (qtp849071628-12670) [n:127.0.0.1:43615_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=cdcr-target&name=cdcr-target&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true : [junit4] 2> 1570489 INFO (OverseerThreadFactory-5938-thread-1-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.c.CreateCollectionCmd Create collection cdcr-target : [junit4] 2> 1570591 INFO (OverseerStateUpdate-98578718854152195-127.0.0.1:43615_solr-n_0000000000) [n:127.0.0.1:43615_solr ] o.a.s.c.o.SliceMutator createReplica() { : [junit4] 2> "operation":"ADDREPLICA", : [junit4] 2> "collection":"cdcr-target", : [junit4] 2> "shard":"shard1", : [junit4] 2> "core":"cdcr-target_shard1_replica_n1", : [junit4] 2> "state":"down", : [junit4] 2> "base_url":"http://127.0.0.1:43615/solr";, : [junit4] 2> "type":"NRT"} : [junit4] 2> 1570792 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node1&collection.configName=cdcr-target&newCollection=true&name=cdcr-target_shard1_replica_n1&action=CREATE&numShards=1&collection=cdcr-target&shard=shard1&wt=javabin&version=2&replicaType=NRT : [junit4] 2> 1570793 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores : [junit4] 2> 1570895 INFO (zkCallback-1960-thread-1-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1570895 INFO (zkCallback-1960-thread-2-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1571799 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 : [junit4] 2> 1571801 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead : [junit4] 2> 1571803 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.s.IndexSchema [cdcr-target_shard1_replica_n1] Schema name=minimal : [junit4] 2> 1571804 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id : [junit4] 2> 1571804 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/cdcr-target/managed-schema : [junit4] 2> 1571805 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/cdcr-target/schema.xml to /configs/cdcr-target/schema.xml.bak : [junit4] 2> 1571805 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-target_shard1_replica_n1' using configuration from collection cdcr-target, trusted=true : [junit4] 2> 1571805 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43615.solr.core.cdcr-target.shard1.replica_n1' (registry 'solr.core.cdcr-target.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@520e8c87 : [junit4] 2> 1571805 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder : [junit4] 2> 1571805 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.SolrCore [[cdcr-target_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001/cdcr-target-001/node1/cdcr-target_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001/cdcr-target-001/node1/./cdcr-target_shard1_replica_n1/data/] : [junit4] 2> 1571839 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog : [junit4] 2> 1571839 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 : [junit4] 2> 1571840 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled : [junit4] 2> 1571840 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled : [junit4] 2> 1571841 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@49ed295d[cdcr-target_shard1_replica_n1] main] : [junit4] 2> 1571842 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-target : [junit4] 2> 1571842 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-target : [junit4] 2> 1571842 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-target/managed-schema : [junit4] 2> 1571842 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest : [junit4] 2> 1571842 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 : [junit4] 2> 1571843 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.CdcrBufferStateManager Created znode /collections/cdcr-target/cdcr/state/buffer : [junit4] 2> 1571844 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.CdcrProcessStateManager Created znode /collections/cdcr-target/cdcr/state/process : [junit4] 2> 1571845 INFO (searcherExecutor-5955-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-target_shard1_replica_n1] Registered new searcher Searcher@49ed295d[cdcr-target_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} : [junit4] 2> 1571845 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577259507980959744 : [junit4] 2> 1571847 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. : [junit4] 2> 1571847 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync : [junit4] 2> 1571847 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43615/solr/cdcr-target_shard1_replica_n1/ : [junit4] 2> 1571847 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me : [junit4] 2> 1571847 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:43615/solr/cdcr-target_shard1_replica_n1/ has no replicas : [junit4] 2> 1571847 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR : [junit4] 2> 1571848 INFO (zkCallback-1960-thread-2-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-target:shard1 : [junit4] 2> 1571849 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:43615/solr/cdcr-target_shard1_replica_n1/ shard1 : [junit4] 2> 1571950 INFO (zkCallback-1960-thread-2-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1571950 INFO (zkCallback-1960-thread-1-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1572000 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary : [junit4] 2> 1572001 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node1&collection.configName=cdcr-target&newCollection=true&name=cdcr-target_shard1_replica_n1&action=CREATE&numShards=1&collection=cdcr-target&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1208 : [junit4] 2> 1572002 INFO (qtp849071628-12670) [n:127.0.0.1:43615_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> 1572102 INFO (zkCallback-1960-thread-2-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1572102 INFO (zkCallback-1960-thread-1-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1572490 INFO (OverseerCollectionConfigSetProcessor-98578718854152195-127.0.0.1:43615_solr-n_0000000000) [n:127.0.0.1:43615_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper : [junit4] 2> 1573002 INFO (qtp849071628-12670) [n:127.0.0.1:43615_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=cdcr-target&name=cdcr-target&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2514 : [junit4] 2> 1573005 INFO (zkCallback-1960-thread-2-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/cdcr/state/process @ cdcr-target:shard1 : [junit4] 2> 1573005 INFO (qtp849071628-12671) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/cdcr params={qt=/cdcr&_stateVer_=cdcr-target:4&action=start&wt=javabin&version=2} status=0 QTime=1 : [junit4] 2> 1573005 INFO (zkCallback-1960-thread-2-processing-n:127.0.0.1:43615_solr) [n:127.0.0.1:43615_solr ] o.a.s.h.CdcrProcessStateManager Received new CDCR process state from watcher: STARTED @ cdcr-target:shard1 : [junit4] 2> 1573007 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) : [junit4] 2> 1573007 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:45707/solr ready : [junit4] 2> 1573009 INFO (qtp849071628-12671) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0 : [junit4] 2> 1573010 INFO (qtp849071628-12671) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=0 : [junit4] 2> 1573010 INFO (qtp849071628-12672) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/cdcr params={_stateVer_=cdcr-target:4&action=COLLECTIONCHECKPOINT&wt=javabin&version=2} status=0 QTime=2 : [junit4] 2> 1573010 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Create new update log reader for target cdcr-target with checkpoint -1 @ cdcr-source:shard1 : [junit4] 2> 1573010 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: cdcr-target, shard: shard1 : [junit4] 2> 1573012 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Submitting bootstrap task to executor : [junit4] 2> 1573012 INFO (zkCallback-1972-thread-1-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/cdcr/state/process @ cdcr-source:shard1 : [junit4] 2> 1573012 INFO (cdcr-bootstrap-status-1984-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: cdcr-target shard: shard1 leader: http://127.0.0.1:43615/solr/cdcr-target_shard1_replica_n1/ : [junit4] 2> 1573013 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/cdcr params={qt=/cdcr&_stateVer_=cdcr-source:4&action=start&wt=javabin&version=2} status=0 QTime=7 : [junit4] 2> 1573013 INFO (zkCallback-1972-thread-1-processing-n:127.0.0.1:37233_solr) [n:127.0.0.1:37233_solr ] o.a.s.h.CdcrProcessStateManager Received new CDCR process state from watcher: STARTED @ cdcr-source:shard1 : [junit4] 2> 1573014 INFO (qtp871894883-12710) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/cdcr params={qt=/cdcr&_stateVer_=cdcr-source:4&action=queues&wt=javabin&version=2} status=0 QTime=0 : [junit4] 1> Cdcr queue response: {responseHeader={status=0,QTime=0},queues={127.0.0.1:45707/solr={cdcr-target={queueSize=1010,lastTimestamp=}}},tlogTotalSize=47659,tlogTotalCount=10,updateLogSynchronizer=stopped} : [junit4] 2> 1573014 INFO (qtp849071628-12670) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/cdcr params={qt=/cdcr&masterUrl=http://127.0.0.1:37233/solr/cdcr-source_shard1_replica_n1/&action=BOOTSTRAP&wt=javabin&version=2} status=0 QTime=0 : [junit4] 2> 1573014 INFO (qtp849071628-12666) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259509206745088,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1573014 INFO (qtp849071628-12666) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. : [junit4] 2> 1573015 INFO (qtp849071628-12666) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1573015 INFO (qtp849071628-12666) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-target:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=0 : [junit4] 2> 1573015 INFO (qtp849071628-12671) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&_stateVer_=cdcr-target:4&wt=javabin&version=2} hits=0 status=0 QTime=0 : [junit4] 2> 1573015 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null} : [junit4] 2> 1573015 INFO (qtp849071628-12667) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.c.S.Request [cdcr-target_shard1_replica_n1] webapp=/solr path=/cdcr params={qt=/cdcr&action=BOOTSTRAP_STATUS&wt=javabin&version=2} status=0 QTime=0 : [junit4] 2> 1573016 INFO (cdcr-bootstrap-status-1984-thread-1-processing-n:127.0.0.1:37233_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager CDCR bootstrap running for 1 seconds, sleeping for 2000 ms : [junit4] 2> 1573016 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1577259509208842240,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} : [junit4] 2> 1573016 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5591d1d0 commitCommandVersion:1577259509208842240 : [junit4] 2> 1573105 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4d54df1a[cdcr-source_shard1_replica_n1] realtime] : [junit4] 2> 1573105 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush : [junit4] 2> 1573105 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={waitSearcher=true&openSearcher=false&commit=true&softCommit=false&commit_end_point=true&wt=javabin&version=2} status=0 QTime=88 : [junit4] 2> 1573106 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 : [junit4] 2> 1573106 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Master's generation: 12 : [junit4] 2> 1573106 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Master's version: 1504191884240 : [junit4] 2> 1573106 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Slave's generation: 1 : [junit4] 2> 1573106 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Slave's version: 0 : [junit4] 2> 1573106 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Starting replication process : [junit4] 2> 1573108 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.h.ReplicationHandler Adding tlog files to list: [{size=4657, name=tlog.0000000000000000000.1577259504849911808}, {size=4778, name=tlog.0000000000000000001.1577259504953720832}, {size=4778, name=tlog.0000000000000000002.1577259505114152960}, {size=4778, name=tlog.0000000000000000003.1577259505233690624}, {size=4778, name=tlog.0000000000000000004.1577259505364762624}, {size=4778, name=tlog.0000000000000000005.1577259505517854720}, {size=4778, name=tlog.0000000000000000006.1577259505689821184}, {size=4778, name=tlog.0000000000000000007.1577259505874370560}, {size=4778, name=tlog.0000000000000000008.1577259506083037184}, {size=4778, name=tlog.0000000000000000009.1577259506304286720}] : [junit4] 2> 1573108 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=1 : [junit4] 2> 1573108 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Number of files in latest index in master: 15 : [junit4] 2> 1573108 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Number of tlog files in master: 10 : [junit4] 2> 1573109 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. : [junit4] 2> 1573109 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@4f704f4a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@11eb65fb) : [junit4] 2> 1573109 INFO (qtp871894883-12708) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a_Lucene50_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573110 INFO (qtp871894883-12709) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573111 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a_Lucene50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573111 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a_Lucene50_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573112 INFO (qtp871894883-12708) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a_Lucene70_0.dvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573112 INFO (qtp871894883-12709) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573112 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573113 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a_Lucene50_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573113 INFO (qtp871894883-12708) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573114 INFO (qtp871894883-12709) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573114 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a.dii&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573115 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a.dim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573115 INFO (qtp871894883-12708) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573116 INFO (qtp871894883-12709) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=_a_Lucene70_0.dvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573116 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&file=segments_c&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573117 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.h.IndexFetcher Starting download of tlog files from master: [{size=4657, name=tlog.0000000000000000000.1577259504849911808}, {size=4778, name=tlog.0000000000000000001.1577259504953720832}, {size=4778, name=tlog.0000000000000000002.1577259505114152960}, {size=4778, name=tlog.0000000000000000003.1577259505233690624}, {size=4778, name=tlog.0000000000000000004.1577259505364762624}, {size=4778, name=tlog.0000000000000000005.1577259505517854720}, {size=4778, name=tlog.0000000000000000006.1577259505689821184}, {size=4778, name=tlog.0000000000000000007.1577259505874370560}, {size=4778, name=tlog.0000000000000000008.1577259506083037184}, {size=4778, name=tlog.0000000000000000009.1577259506304286720}] : [junit4] 2> 1573124 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000000.1577259504849911808&wt=filestream&command=filecontent} status=0 QTime=3 : [junit4] 2> 1573125 INFO (qtp871894883-12708) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000001.1577259504953720832&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573126 INFO (qtp871894883-12709) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000002.1577259505114152960&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573127 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000003.1577259505233690624&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573127 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000004.1577259505364762624&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573128 INFO (qtp871894883-12708) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000005.1577259505517854720&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573128 INFO (qtp871894883-12709) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000006.1577259505689821184&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573129 INFO (qtp871894883-12713) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000007.1577259505874370560&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573129 INFO (qtp871894883-12707) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000008.1577259506083037184&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573130 INFO (qtp871894883-12708) [n:127.0.0.1:37233_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/replication params={generation=12&qt=/replication&checksum=true&tlogFile=tlog.0000000000000000009.1577259506304286720&wt=filestream&command=filecontent} status=0 QTime=0 : [junit4] 2> 1573130 INFO (recoveryExecutor-1958-thread-1-processing-n:127.0.0.1:43615_solr x:cdcr-target_shard1_replica_n1 s:shard1 c:cdcr-target r:core_node1) [n:127.0.0.1:43615_solr c:cdcr-targe : : [...truncated too long message...] : : olrJmxReporter@327a04f8: rootName = solr_38963, 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@74773370 : [junit4] 2> 1767227 INFO (zkCallback-2036-thread-3-processing-n:127.0.0.1:38963_solr) [n:127.0.0.1:38963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1767227 INFO (zkCallback-2036-thread-4-processing-n:127.0.0.1:38963_solr) [n:127.0.0.1:38963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1]) : [junit4] 2> 1767234 INFO (coreCloseExecutor-6089-thread-1) [n:127.0.0.1:38963_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.cdcr-target.shard1.leader, tag=1409637354 : [junit4] 2> 1767234 INFO (coreCloseExecutor-6089-thread-1) [n:127.0.0.1:38963_solr c:cdcr-target s:shard1 r:core_node1 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> 1767235 INFO (jetty-closer-2030-thread-1) [ ] o.a.s.c.Overseer Overseer (id=98578722459418627-127.0.0.1:38963_solr-n_0000000000) closing : [junit4] 2> 1767235 INFO (OverseerStateUpdate-98578722459418627-127.0.0.1:38963_solr-n_0000000000) [n:127.0.0.1:38963_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:38963_solr : [junit4] 2> 1767236 WARN (zkCallback-2036-thread-4-processing-n:127.0.0.1:38963_solr) [n:127.0.0.1:38963_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] : [junit4] 2> 1767236 INFO (jetty-closer-2030-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@194fb4ee{/solr,null,UNAVAILABLE} : [junit4] 2> 1767236 ERROR (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[919AD2A8090BD205]) [ ] 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> 1767237 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45067 45067 : [junit4] 2> 1772288 INFO (Thread-3362) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45067 45067 : [junit4] 2> 1772288 WARN (Thread-3362) [ ] o.a.s.c.ZkTestServer Watch limit violations: : [junit4] 2> Maximum concurrent create/delete watches above limit: : [junit4] 2> : [junit4] 2> 3 /solr/aliases.json : [junit4] 2> 3 /solr/clusterprops.json : [junit4] 2> 2 /solr/configs/cdcr-target/managed-schema : [junit4] 2> 2 /solr/collections/cdcr-target/leaders/shard1/leader : [junit4] 2> : [junit4] 2> Maximum concurrent data watches above limit: : [junit4] 2> : [junit4] 2> 6 /solr/collections/cdcr-target/state.json : [junit4] 2> 3 /solr/collections/cdcr-target/cdcr/state/process : [junit4] 2> 3 /solr/clusterstate.json : [junit4] 2> 2 /solr/collections/cdcr-target/cdcr/state/buffer : [junit4] 2> : [junit4] 2> Maximum concurrent children watches above limit: : [junit4] 2> : [junit4] 2> 3 /solr/live_nodes : [junit4] 2> 3 /solr/collections : [junit4] 2> : [junit4] 2> 1772289 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[919AD2A8090BD205]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBootstrapWithContinousIndexingOnSourceCluster : [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CdcrBootstrapTest -Dtests.method=testBootstrapWithContinousIndexingOnSourceCluster -Dtests.seed=919AD2A8090BD205 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hu -Dtests.timezone=Etc/GMT-5 -Dtests.asserts=true -Dtests.file.encoding=US-ASCII : [junit4] FAILURE 151s J2 | CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster <<< : [junit4] > Throwable #1: java.lang.AssertionError: Document mismatch on target after sync expected:<2000> but was:<1023> : [junit4] > at __randomizedtesting.SeedInfo.seed([919AD2A8090BD205:45DF99F1EE5D61FE]:0) : [junit4] > at org.apache.solr.cloud.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster(CdcrBootstrapTest.java:309) : [junit4] > at java.lang.Thread.run(Thread.java:748) : [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrBootstrapTest_919AD2A8090BD205-001 : [junit4] 2> NOTE: test params are: codec=Lucene70, sim=RandomSimilarity(queryNorm=false): {}, locale=hu, timezone=Etc/GMT-5 : [junit4] 2> NOTE: Linux 4.10.0-33-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=187589312,total=536346624 : [junit4] 2> NOTE: All tests run in this JVM: [DistributedFacetPivotSmallTest, SuggesterTest, URLClassifyProcessorTest, TestFieldTypeResource, TestQueryUtils, TestReRankQParserPlugin, DocumentBuilderTest, TestXmlQParser, TestSimpleTextCodec, TestShortCircuitedRequests, TestFieldCollectionResource, SortByFunctionTest, StatsComponentTest, HighlighterMaxOffsetTest, TestDistributedMissingSort, TestImplicitCoreProperties, TestPKIAuthenticationPlugin, TestSchemaSimilarityResource, StressHdfsTest, ZkStateWriterTest, TestRecovery, TestDocTermOrds, TestStandardQParsers, TestHdfsBackupRestoreCore, TestManagedSchema, BlockJoinFacetRandomTest, UninvertDocValuesMergePolicyTest, TestSortByMinMaxFunction, DirectUpdateHandlerTest, ReturnFieldsTest, TestAnalyzedSuggestions, TestUseDocValuesAsStored, RollingRestartTest, TestSearcherReuse, DateFieldTest, TestCloudInspectUtil, RequiredFieldsTest, TestSolrCloudSnapshots, TestSubQueryTransformerDistrib, TestStressInPlaceUpdates, JvmMetricsTest, Test ComplexPhraseQParserPlugin, OverriddenZkACLAndCredentialsProvidersTest, TestDistributedStatsComponentCardinality, SearchHandlerTest, TestSolrDeletionPolicy2, FullSolrCloudDistribCmdsTest, TestDFRSimilarityFactory, TestNumericTerms64, TestLFUCache, SearchHandlerTest, ConjunctionSolrSpellCheckerTest, TermsComponentTest, TestLegacyField, RulesTest, HdfsRestartWhileUpdatingTest, ExplicitHLLTest, TestFoldingMultitermQuery, TestUniqueKeyFieldResource, SimpleMLTQParserTest, SegmentsInfoRequestHandlerTest, TestSuggestSpellingConverter, TestBulkSchemaConcurrent, TestFieldCacheSort, SimplePostToolTest, TestNRTOpen, TestRequestStatusCollectionAPI, MergeStrategyTest, AnalysisErrorHandlingTest, CleanupOldIndexTest, ConnectionManagerTest, PeerSyncReplicationTest, FastVectorHighlighterTest, TestJettySolrRunner, TestInPlaceUpdatesStandalone, TestSolr4Spatial2, DirectoryFactoryTest, DistributedQueryComponentOptimizationTest, RegexBoostProcessorTest, DateMathParserTest, PolyFieldTest, TestTolerantUpd ateProcessorCloud, SuggesterFSTTest, TestRestoreCore, TestCopyFieldCollectionResource, TestFastWriter, TestRebalanceLeaders, DistributedQueueTest, CollectionStateFormat2Test, PingRequestHandlerTest, TestManagedSynonymGraphFilterFactory, TestLegacyTerms, HdfsTlogReplayBufferedWhileIndexingTest, TestNonDefinedSimilarityFactory, TestCloudNestedDocsSort, TimeZoneUtilsTest, TestOverriddenPrefixQueryForCustomFieldType, TestHdfsCloudBackupRestore, BadIndexSchemaTest, DistribCursorPagingTest, TestRestManager, TestMissingGroups, RecoveryZkTest, TestInitQParser, BasicAuthStandaloneTest, SpellPossibilityIteratorTest, TestQueryWrapperFilter, TestGraphMLResponseWriter, TestFilteredDocIdSet, DistributedDebugComponentTest, TestDistribDocBasedVersion, TestCloudPseudoReturnFields, TestDefaultStatsCache, TestCustomDocTransformer, QueryResultKeyTest, InfixSuggestersTest, SimpleFacetsTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, SyncSliceTest, OverseerTest, Te stRandomDVFaceting, AutoCommitTest, TestStressReorder, TestJoin, DistributedTermsComponentTest, SolrCmdDistributorTest, PeerSyncTest, TestIndexSearcher, ShowFileRequestHandlerTest, SolrIndexSplitterTest, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, SolrRequestParserTest, WordBreakSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestUpdate, TestAtomicUpdateErrorCases, QueryEqualityTest, DocValuesMultiTest, DistanceFunctionTest, SolrInfoBeanTest, DebugComponentTest, TestSurroundQueryParser, TestWriterPerf, TestReversedWildcardFilterFactory, PrimitiveFieldTypeTest, XmlUpdateRequestHandlerTest, TermVectorComponentTest, FieldAnalysisRequestHandlerTest, LoggingHandlerTest, TestJmxIntegration, TestCSVResponseWriter, UniqFieldsUpdateProcessorFactoryTest, TestPartialUpdateDeduplication, HighlighterConfigTest, UpdateParamsTest, TestSolrIndexConfig, CopyFieldTest, BadComponentTest, MinimalSchemaTest, TestSolrCoreProperties, NotRequiredUniqueKeyTest, TestCharFilters, E choParamsTest, TestSweetSpotSimilarityFactory, TestLMDirichletSimilarityFactory, TestIBSimilarityFactory, TestFastLRUCache, PreAnalyzedFieldTest, TestSystemIdResolver, PrimUtilsTest, SpellingQueryConverterTest, RAMDirectoryFactoryTest, ClusterStateTest, TestSolrJ, TestUtils, ZkNodePropsTest, SystemInfoHandlerTest, CircularListTest, DistributedMLTComponentTest, CursorPagingTest, DistributedIntervalFacetingTest, SolrTestCaseJ4Test, TestCrossCoreJoin, TestTolerantSearch, TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, ConnectionReuseTest, AliasIntegrationTest, BaseCdcrDistributedZkTest, CdcrBootstrapTest] : [junit4] Completed [442/729 (1!)] on J2 in 206.49s, 3 tests, 1 failure <<< FAILURES! : : [...truncated 44389 lines...] : -Hoss http://www.lucidworks.com/ --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
