You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/01/22 02:04:08 UTC
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk1.8.0_144) - Build #
21315 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21315/
Java: 64bit/jdk1.8.0_144 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.cdcr.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster
Error Message:
Document mismatch on target after sync expected:<2000> but was:<1901>
Stack Trace:
java.lang.AssertionError: Document mismatch on target after sync expected:<2000> but was:<1901>
at __randomizedtesting.SeedInfo.seed([6BA7020F5866EFF4:BFE24956BF305C0F]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.cdcr.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster(CdcrBootstrapTest.java:292)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 13814 lines...]
[junit4] Suite: org.apache.solr.cloud.cdcr.CdcrBootstrapTest
[junit4] 2> 2803329 INFO (SUITE-CdcrBootstrapTest-seed#[6BA7020F5866EFF4]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/init-core-data-001
[junit4] 2> 2803330 WARN (SUITE-CdcrBootstrapTest-seed#[6BA7020F5866EFF4]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=59 numCloses=59
[junit4] 2> 2803330 INFO (SUITE-CdcrBootstrapTest-seed#[6BA7020F5866EFF4]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 2803331 INFO (SUITE-CdcrBootstrapTest-seed#[6BA7020F5866EFF4]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 2803334 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testConvertClusterToCdcrAndBootstrap
[junit4] 2> 2803334 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/cdcr-target-001
[junit4] 2> 2803334 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2803335 INFO (Thread-6551) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2803335 INFO (Thread-6551) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2803336 ERROR (Thread-6551) [ ] 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> 2803435 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.ZkTestServer start zk server on port:38901
[junit4] 2> 2803437 INFO (zkConnectionManagerCallback-5464-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803440 INFO (jetty-launcher-5461-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T18:27:37-03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 2803449 INFO (jetty-launcher-5461-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2803449 INFO (jetty-launcher-5461-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2803449 INFO (jetty-launcher-5461-thread-1) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 2803449 INFO (jetty-launcher-5461-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@76dbf0b2{/solr,null,AVAILABLE}
[junit4] 2> 2803451 INFO (jetty-launcher-5461-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@19820600{HTTP/1.1,[http/1.1]}{127.0.0.1:34039}
[junit4] 2> 2803451 INFO (jetty-launcher-5461-thread-1) [ ] o.e.j.s.Server Started @2805125ms
[junit4] 2> 2803451 INFO (jetty-launcher-5461-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34039}
[junit4] 2> 2803452 ERROR (jetty-launcher-5461-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2803452 INFO (jetty-launcher-5461-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 2803452 INFO (jetty-launcher-5461-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2803452 INFO (jetty-launcher-5461-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2803452 INFO (jetty-launcher-5461-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-22T01:39:35.272Z
[junit4] 2> 2803461 INFO (zkConnectionManagerCallback-5466-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803461 INFO (jetty-launcher-5461-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2803473 INFO (jetty-launcher-5461-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38901/solr
[junit4] 2> 2803477 INFO (zkConnectionManagerCallback-5470-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803481 INFO (zkConnectionManagerCallback-5472-thread-1-processing-n:127.0.0.1:34039_solr) [n:127.0.0.1:34039_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803536 INFO (jetty-launcher-5461-thread-1) [n:127.0.0.1:34039_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2803536 INFO (jetty-launcher-5461-thread-1) [n:127.0.0.1:34039_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34039_solr
[junit4] 2> 2803536 INFO (jetty-launcher-5461-thread-1) [n:127.0.0.1:34039_solr ] o.a.s.c.Overseer Overseer (id=99390926038958083-127.0.0.1:34039_solr-n_0000000000) starting
[junit4] 2> 2803540 INFO (jetty-launcher-5461-thread-1) [n:127.0.0.1:34039_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34039_solr
[junit4] 2> 2803541 INFO (zkCallback-5471-thread-1-processing-n:127.0.0.1:34039_solr) [n:127.0.0.1:34039_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2803614 INFO (jetty-launcher-5461-thread-1) [n:127.0.0.1:34039_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34039.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2803621 INFO (jetty-launcher-5461-thread-1) [n:127.0.0.1:34039_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34039.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2803621 INFO (jetty-launcher-5461-thread-1) [n:127.0.0.1:34039_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34039.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2803622 INFO (jetty-launcher-5461-thread-1) [n:127.0.0.1:34039_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/cdcr-target-001/node1/.
[junit4] 2> 2803636 INFO (zkConnectionManagerCallback-5476-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803639 INFO (zkConnectionManagerCallback-5479-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803640 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.c.CdcrBootstrapTest Target zkHost = 127.0.0.1:38901/solr
[junit4] 2> 2803640 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/cdcr-source-001
[junit4] 2> 2803640 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2803640 INFO (Thread-6561) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2803640 INFO (Thread-6561) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2803649 ERROR (Thread-6561) [ ] 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> 2803740 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.ZkTestServer start zk server on port:41359
[junit4] 2> 2803742 INFO (zkConnectionManagerCallback-5483-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803746 INFO (jetty-launcher-5480-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T18:27:37-03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 2803746 INFO (jetty-launcher-5480-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2803746 INFO (jetty-launcher-5480-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2803746 INFO (jetty-launcher-5480-thread-1) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 2803746 INFO (jetty-launcher-5480-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4e5cbd47{/solr,null,AVAILABLE}
[junit4] 2> 2803746 INFO (jetty-launcher-5480-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@287467a1{HTTP/1.1,[http/1.1]}{127.0.0.1:43065}
[junit4] 2> 2803746 INFO (jetty-launcher-5480-thread-1) [ ] o.e.j.s.Server Started @2805421ms
[junit4] 2> 2803746 INFO (jetty-launcher-5480-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43065}
[junit4] 2> 2803747 ERROR (jetty-launcher-5480-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2803747 INFO (jetty-launcher-5480-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 2803747 INFO (jetty-launcher-5480-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2803747 INFO (jetty-launcher-5480-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2803747 INFO (jetty-launcher-5480-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-22T01:39:35.567Z
[junit4] 2> 2803748 INFO (zkConnectionManagerCallback-5485-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803748 INFO (jetty-launcher-5480-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2803754 INFO (jetty-launcher-5480-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41359/solr
[junit4] 2> 2803754 INFO (zkConnectionManagerCallback-5489-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803755 INFO (zkConnectionManagerCallback-5491-thread-1-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803782 INFO (jetty-launcher-5480-thread-1) [n:127.0.0.1:43065_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2803783 INFO (jetty-launcher-5480-thread-1) [n:127.0.0.1:43065_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43065_solr
[junit4] 2> 2803783 INFO (jetty-launcher-5480-thread-1) [n:127.0.0.1:43065_solr ] o.a.s.c.Overseer Overseer (id=99390926059012099-127.0.0.1:43065_solr-n_0000000000) starting
[junit4] 2> 2803786 INFO (jetty-launcher-5480-thread-1) [n:127.0.0.1:43065_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43065_solr
[junit4] 2> 2803787 INFO (zkCallback-5490-thread-1-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2803827 INFO (jetty-launcher-5480-thread-1) [n:127.0.0.1:43065_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43065.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2803832 INFO (jetty-launcher-5480-thread-1) [n:127.0.0.1:43065_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43065.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2803832 INFO (jetty-launcher-5480-thread-1) [n:127.0.0.1:43065_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43065.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2803833 INFO (jetty-launcher-5480-thread-1) [n:127.0.0.1:43065_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/cdcr-source-001/node1/.
[junit4] 2> 2803847 INFO (zkConnectionManagerCallback-5495-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803850 INFO (zkConnectionManagerCallback-5498-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803851 INFO (zkConnectionManagerCallback-5500-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803854 INFO (zkConnectionManagerCallback-5503-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2803854 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2803855 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41359/solr ready
[junit4] 2> 2803856 INFO (qtp289380191-27259) [n:127.0.0.1:43065_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> 2803857 INFO (OverseerThreadFactory-10713-thread-1-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection cdcr-source
[junit4] 2> 2803961 INFO (OverseerStateUpdate-99390926059012099-127.0.0.1:43065_solr-n_0000000000) [n:127.0.0.1:43065_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:43065/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2804162 INFO (qtp289380191-27305) [n:127.0.0.1:43065_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_node2&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin
[junit4] 2> 2804163 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2804265 INFO (zkCallback-5490-thread-1-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_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> 2804265 INFO (zkCallback-5490-thread-2-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_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> 2805169 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2805189 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema [cdcr-source_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2805190 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2805190 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-source_shard1_replica_n1' using configuration from collection cdcr-source, trusted=true
[junit4] 2> 2805191 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43065.solr.core.cdcr-source.shard1.replica_n1' (registry 'solr.core.cdcr-source.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2805191 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2805191 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [[cdcr-source_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/cdcr-source-001/node1/cdcr-source_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/cdcr-source-001/node1/./cdcr-source_shard1_replica_n1/data/]
[junit4] 2> 2805430 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2805430 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2805430 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2805430 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2805432 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1111c7d[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2805432 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-source
[junit4] 2> 2805432 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-source
[junit4] 2> 2805433 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2805434 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@1111c7d[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2805434 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1590254818824290304
[junit4] 2> 2805436 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2805436 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2805437 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43065/solr/cdcr-source_shard1_replica_n1/
[junit4] 2> 2805437 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2805437 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:43065/solr/cdcr-source_shard1_replica_n1/ has no replicas
[junit4] 2> 2805437 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2805438 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:43065/solr/cdcr-source_shard1_replica_n1/ shard1
[junit4] 2> 2805539 INFO (zkCallback-5490-thread-2-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_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> 2805539 INFO (zkCallback-5490-thread-1-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_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> 2805588 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2805590 INFO (qtp289380191-27305) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&collection=cdcr-source&version=2&replicaType=NRT&coreNodeName=core_node2&name=cdcr-source_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin} status=0 QTime=1427
[junit4] 2> 2805591 INFO (qtp289380191-27259) [n:127.0.0.1:43065_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> 2805690 INFO (zkCallback-5490-thread-1-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_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> 2805690 INFO (zkCallback-5490-thread-2-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_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> 2805859 INFO (OverseerCollectionConfigSetProcessor-99390926059012099-127.0.0.1:43065_solr-n_0000000000) [n:127.0.0.1:43065_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> 2806592 INFO (qtp289380191-27259) [n:127.0.0.1:43065_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=2736
[junit4] 2> 2806595 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_0 (1590254820039589888), source_1 (1590254820040638464), source_2 (1590254820040638465), source_3 (1590254820040638466), source_4 (1590254820040638467), source_5 (1590254820040638468), source_6 (1590254820040638469), source_7 (1590254820040638470), source_8 (1590254820040638471), source_9 (1590254820040638472), ... (100 adds)]} 0 2
[junit4] 2> 2806596 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254820042735616,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2806596 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254820042735616
[junit4] 2> 2806699 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2866f027[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2806699 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2806700 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@2866f027[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100)))}
[junit4] 2> 2806700 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 104
[junit4] 2> 2806702 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_100 (1590254820151787520), source_101 (1590254820152836096), source_102 (1590254820152836097), source_103 (1590254820152836098), source_104 (1590254820152836099), source_105 (1590254820152836100), source_106 (1590254820152836101), source_107 (1590254820152836102), source_108 (1590254820152836103), source_109 (1590254820152836104), ... (100 adds)]} 0 1
[junit4] 2> 2806703 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254820154933248,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2806703 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254820154933248
[junit4] 2> 2806825 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@f49a0d6[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2806826 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2806826 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@f49a0d6[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100)))}
[junit4] 2> 2806826 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 123
[junit4] 2> 2806829 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_200 (1590254820284956672), source_201 (1590254820286005248), source_202 (1590254820286005249), source_203 (1590254820286005250), source_204 (1590254820286005251), source_205 (1590254820286005252), source_206 (1590254820286005253), source_207 (1590254820286005254), source_208 (1590254820286005255), source_209 (1590254820286005256), ... (100 adds)]} 0 1
[junit4] 2> 2806829 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254820287053848,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2806829 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254820287053848
[junit4] 2> 2806969 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7fbcbd74[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2806970 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2806970 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@7fbcbd74[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100)))}
[junit4] 2> 2806970 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 141
[junit4] 2> 2806972 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_300 (1590254820435951616), source_301 (1590254820437000192), source_302 (1590254820437000193), source_303 (1590254820437000194), source_304 (1590254820437000195), source_305 (1590254820437000196), source_306 (1590254820437000197), source_307 (1590254820437000198), source_308 (1590254820437000199), source_309 (1590254820437000200), ... (100 adds)]} 0 1
[junit4] 2> 2806973 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254820438048768,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2806973 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254820438048768
[junit4] 2> 2807138 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@77ad7b95[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2807138 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2807139 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@77ad7b95[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100)))}
[junit4] 2> 2807139 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 166
[junit4] 2> 2807141 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_400 (1590254820612112384), source_401 (1590254820613160960), source_402 (1590254820613160961), source_403 (1590254820613160962), source_404 (1590254820613160963), source_405 (1590254820613160964), source_406 (1590254820613160965), source_407 (1590254820613160966), source_408 (1590254820613160967), source_409 (1590254820613160968), ... (100 adds)]} 0 2
[junit4] 2> 2807142 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254820615258112,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2807142 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254820615258112
[junit4] 2> 2807324 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@78efb93[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2807325 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2807325 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@78efb93[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100)))}
[junit4] 2> 2807325 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 183
[junit4] 2> 2807327 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_500 (1590254820808196096), source_501 (1590254820809244672), source_502 (1590254820809244673), source_503 (1590254820809244674), source_504 (1590254820809244675), source_505 (1590254820809244676), source_506 (1590254820809244677), source_507 (1590254820809244678), source_508 (1590254820809244679), source_509 (1590254820809244680), ... (100 adds)]} 0 1
[junit4] 2> 2807328 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254820810293248,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2807328 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254820810293248
[junit4] 2> 2807530 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@f7eb34d[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2807531 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2807531 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@f7eb34d[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100)))}
[junit4] 2> 2807531 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 203
[junit4] 2> 2807534 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_600 (1590254821024202752), source_601 (1590254821025251328), source_602 (1590254821025251329), source_603 (1590254821025251330), source_604 (1590254821025251331), source_605 (1590254821025251332), source_606 (1590254821025251333), source_607 (1590254821025251334), source_608 (1590254821025251335), source_609 (1590254821025251336), ... (100 adds)]} 0 1
[junit4] 2> 2807534 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254821026299945,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2807534 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254821026299945
[junit4] 2> 2808124 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5f428cf3[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2808124 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2808125 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@5f428cf3[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100)))}
[junit4] 2> 2808126 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 591
[junit4] 2> 2808128 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_700 (1590254821647056896), source_701 (1590254821648105472), source_702 (1590254821648105473), source_703 (1590254821648105474), source_704 (1590254821648105475), source_705 (1590254821648105476), source_706 (1590254821648105477), source_707 (1590254821648105478), source_708 (1590254821648105479), source_709 (1590254821648105480), ... (100 adds)]} 0 1
[junit4] 2> 2808129 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254821650202624,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2808129 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254821650202624
[junit4] 2> 2808597 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2985edef[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2808598 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2808599 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@2985edef[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100)))}
[junit4] 2> 2808599 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 470
[junit4] 2> 2808602 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_800 (1590254822144081920), source_801 (1590254822145130496), source_802 (1590254822145130497), source_803 (1590254822145130498), source_804 (1590254822145130499), source_805 (1590254822145130500), source_806 (1590254822145130501), source_807 (1590254822145130502), source_808 (1590254822145130503), source_809 (1590254822145130504), ... (100 adds)]} 0 2
[junit4] 2> 2808603 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254822147227648,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2808603 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254822147227648
[junit4] 2> 2808897 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@af3495e[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2808898 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2808899 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@af3495e[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100)))}
[junit4] 2> 2808899 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 295
[junit4] 2> 2808901 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&wt=javabin&version=2}{add=[source_900 (1590254822458654720), source_901 (1590254822458654721), source_902 (1590254822458654722), source_903 (1590254822458654723), source_904 (1590254822458654724), source_905 (1590254822458654725), source_906 (1590254822458654726), source_907 (1590254822458654727), source_908 (1590254822458654728), source_909 (1590254822458654729), ... (100 adds)]} 0 1
[junit4] 2> 2808902 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1590254822460751872,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2808902 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@22333a5f commitCommandVersion:1590254822460751872
[junit4] 2> 2809225 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3ff48792[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2809226 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2809227 INFO (searcherExecutor-10716-thread-1-processing-n:127.0.0.1:43065_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))}
[junit4] 2> 2809227 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-source:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 325
[junit4] 2> 2809227 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.c.CdcrBootstrapTest Adding numDocs=1000
[junit4] 2> 2809227 INFO (qtp289380191-27263) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&_stateVer_=cdcr-source:4&wt=javabin&version=2} hits=1000 status=0 QTime=0
[junit4] 2> 2809228 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_0(8.0.0):C100)) docBase=0 ord=0) mavVersion:9223372036854775807
[junit4] 2> 2809228 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_1(8.0.0):C100)) docBase=100 ord=1) mavVersion:9223372036854775807
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_2(8.0.0):C100)) docBase=200 ord=2) mavVersion:9223372036854775807
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_3(8.0.0):C100)) docBase=300 ord=3) mavVersion:9223372036854775807
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_4(8.0.0):C100)) docBase=400 ord=4) mavVersion:9223372036854775807
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_5(8.0.0):C100)) docBase=500 ord=5) mavVersion:9223372036854775807
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_6(8.0.0):C100)) docBase=600 ord=6) mavVersion:9223372036854775807
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_7(8.0.0):C100)) docBase=700 ord=7) mavVersion:9223372036854775807
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_8(8.0.0):C100)) docBase=800 ord=8) mavVersion:9223372036854775807
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore Caching fingerprint for searcher:Searcher@3ff48792[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C100) Uninverting(_1(8.0.0):C100) Uninverting(_2(8.0.0):C100) Uninverting(_3(8.0.0):C100) Uninverting(_4(8.0.0):C100) Uninverting(_5(8.0.0):C100) Uninverting(_6(8.0.0):C100) Uninverting(_7(8.0.0):C100) Uninverting(_8(8.0.0):C100) Uninverting(_9(8.0.0):C100)))} leafReaderContext:LeafReaderContext(FilterLeafReader(Uninverting(_9(8.0.0):C100)) docBase=900 ord=9) mavVersion:9223372036854775807
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.IndexFingerprint IndexFingerprint millis:1.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=1590254822459703378, maxInHash=1590254822459703378, versionsHash=6045765045101299922, numVersions=1000, numDocs=1000, maxDoc=100}
[junit4] 2> 2809229 INFO (qtp289380191-27304) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.S.Request [cdcr-source_shard1_replica_n1] webapp=/solr path=/get params={qt=/get&_stateVer_=cdcr-source:4&fingerprint=true&getVersions=1000&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 2809233 INFO (zkConnectionManagerCallback-5505-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2809237 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@287467a1{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 2809238 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2138877074
[junit4] 2> 2809239 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 2809239 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@793749e4: rootName = solr_43065, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@38e77fa
[junit4] 2> 2809247 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 2809247 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3ff7f218: rootName = solr_43065, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@b070442
[junit4] 2> 2809253 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 2809253 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@54047297: rootName = solr_43065, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@f3891fa
[junit4] 2> 2809255 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:43065_solr
[junit4] 2> 2809256 INFO (zkCallback-5502-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 2809256 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 2809256 INFO (zkCallback-5490-thread-2-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 2809256 INFO (zkCallback-5490-thread-1-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_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: [0])
[junit4] 2> 2809256 INFO (zkCallback-5490-thread-3-processing-n:127.0.0.1:43065_solr) [n:127.0.0.1:43065_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: [0])
[junit4] 2> 2809256 INFO (coreCloseExecutor-10721-thread-1) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@47b5f324
[junit4] 2> 2809256 INFO (coreCloseExecutor-10721-thread-1) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.cdcr-source.shard1.replica_n1, tag=1203106596
[junit4] 2> 2809257 INFO (coreCloseExecutor-10721-thread-1) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@757b1a40: rootName = solr_43065, domain = solr.core.cdcr-source.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.cdcr-source.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@64b78b8f
[junit4] 2> 2809266 INFO (coreCloseExecutor-10721-thread-1) [n:127.0.0.1:43065_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.cdcr-source.shard1.leader, tag=1203106596
[junit4] 2> 2809401 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.Overseer Overseer (id=99390926059012099-127.0.0.1:43065_solr-n_0000000000) closing
[junit4] 2> 2809402 INFO (OverseerStateUpdate-99390926059012099-127.0.0.1:43065_solr-n_0000000000) [n:127.0.0.1:43065_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43065_solr
[junit4] 2> 2809402 WARN (OverseerAutoScalingTriggerThread-99390926059012099-127.0.0.1:43065_solr-n_0000000000) [n:127.0.0.1:43065_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 2809405 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4e5cbd47{/solr,null,UNAVAILABLE}
[junit4] 2> 2809406 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 2809407 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T18:27:37-03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 2809407 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2809407 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2809407 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 2809407 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@d776930{/solr,null,AVAILABLE}
[junit4] 2> 2809408 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3fd74fb0{HTTP/1.1,[http/1.1]}{127.0.0.1:36389}
[junit4] 2> 2809408 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.e.j.s.Server Started @2811082ms
[junit4] 2> 2809408 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36389}
[junit4] 2> 2809408 ERROR (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2809408 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 2809408 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2809408 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2809408 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-22T01:39:41.228Z
[junit4] 2> 2809410 INFO (zkConnectionManagerCallback-5507-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2809410 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2809416 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41359/solr
[junit4] 2> 2809417 INFO (zkConnectionManagerCallback-5511-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2809418 INFO (zkConnectionManagerCallback-5513-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2809421 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [n:127.0.0.1:36389_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2809422 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [n:127.0.0.1:36389_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:36389_solr
[junit4] 2> 2809422 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [n:127.0.0.1:36389_solr ] o.a.s.c.Overseer Overseer (id=99390926059012107-127.0.0.1:36389_solr-n_0000000001) starting
[junit4] 2> 2809425 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [n:127.0.0.1:36389_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36389_solr
[junit4] 2> 2809426 INFO (zkCallback-5502-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2809427 INFO (zkCallback-5512-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2809488 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [n:127.0.0.1:36389_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36389.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2809494 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [n:127.0.0.1:36389_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36389.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2809494 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [n:127.0.0.1:36389_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36389.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2809501 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [n:127.0.0.1:36389_solr ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/cdcr-source-001/node1/.
[junit4] 2> 2809501 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [n:127.0.0.1:36389_solr ] o.a.s.c.CorePropertiesLocator Cores are: [cdcr-source_shard1_replica_n1]
[junit4] 2> 2809502 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2809508 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2809526 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 2809528 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr ] o.a.s.s.IndexSchema [cdcr-source_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2809530 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2809531 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr ] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/cdcr-source/managed-schema
[junit4] 2> 2809532 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/cdcr-source/schema.xml to /configs/cdcr-source/schema.xml.bak
[junit4] 2> 2809533 INFO (zkCallback-5512-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_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> 2809535 INFO (zkCallback-5512-thread-2-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_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> 2810536 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2810540 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema [cdcr-source_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2810541 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2810541 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-source_shard1_replica_n1' using configuration from collection cdcr-source, trusted=true
[junit4] 2> 2810541 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36389.solr.core.cdcr-source.shard1.replica_n1' (registry 'solr.core.cdcr-source.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@631ae501
[junit4] 2> 2810541 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2810541 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [[cdcr-source_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/cdcr-source-001/node1/cdcr-source_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001/cdcr-source-001/node1/./cdcr-source_shard1_replica_n1/data/]
[junit4] 2> 2810564 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 2810564 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2810564 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2810565 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2810575 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@598e5fd9[cdcr-source_shard1_replica_n1] main]
[junit4] 2> 2810576 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-source
[junit4] 2> 2810576 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-source
[junit4] 2> 2810576 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-source/managed-schema
[junit4] 2> 2810576 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2810577 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2810577 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrBufferStateManager Created znode /collections/cdcr-source/cdcr/state/buffer
[junit4] 2> 2810578 INFO (coreLoadExecutor-10732-thread-1-processing-n:127.0.0.1:36389_solr) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrProcessStateManager Created znode /collections/cdcr-source/cdcr/state/process
[junit4] 2> 2810580 INFO (searcherExecutor-10733-thread-1-processing-n:127.0.0.1:36389_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-source_shard1_replica_n1] Registered new searcher Searcher@598e5fd9[cdcr-source_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(8.0.0):C1000)))}
[junit4] 2> 2810581 WARN (cdcr-update-log-synchronizer-10738-thread-1) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.h.CdcrUpdateLogSynchronizer Caught unexpected exception
[junit4] 2> org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:36389/solr/cdcr-source_shard1_replica_n1: SolrCore is loading
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
[junit4] 2> at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
[junit4] 2> at org.apache.solr.handler.CdcrUpdateLogSynchronizer$UpdateLogSynchronisation.run(CdcrUpdateLogSynchronizer.java:147)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 2810581 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: cdcr-source failOnTimeout:true timeout (sec):330
[junit4] 1> -
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 2> 2810582 INFO (coreZkRegister-10723-thread-1-processing-n:127.0.0.1:36389_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2810582 INFO (coreZkRegister-10723-thread-1-processing-n:127.0.0.1:36389_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2810582 INFO (coreZkRegister-10723-thread-1-processing-n:127.0.0.1:36389_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36389/solr/cdcr-source_shard1_replica_n1/
[junit4] 2> 2810582 INFO (coreZkRegister-10723-thread-1-processing-n:127.0.0.1:36389_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2810582 INFO (coreZkRegister-10723-thread-1-processing-n:127.0.0.1:36389_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:36389_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:36389/solr/cdcr-source_shard1_replica_n1/ has no replicas
[junit4] 2> 2810582 INFO (coreZkRegister-10723-thread-1-processing-n:127.0.0.1:36389_solr x:cdcr-source_shard1_replica_n1 s:shard1 c:
[...truncated too long message...]
81-thread-1) [ ] o.a.s.c.Overseer Overseer (id=99390929687216131-127.0.0.1:44591_solr-n_0000000000) closing
[junit4] 2> 2994885 INFO (OverseerStateUpdate-99390929687216131-127.0.0.1:44591_solr-n_0000000000) [n:127.0.0.1:44591_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44591_solr
[junit4] 2> 2994888 WARN (OverseerAutoScalingTriggerThread-99390929687216131-127.0.0.1:44591_solr-n_0000000000) [n:127.0.0.1:44591_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 2994893 INFO (jetty-closer-5581-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2b4aad90{/solr,null,UNAVAILABLE}
[junit4] 2> 2994893 INFO (jetty-closer-5581-thread-1) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 2994894 ERROR (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[6BA7020F5866EFF4]) [ ] 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> 2994895 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[6BA7020F5866EFF4]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39085 39085
[junit4] 2> 3004921 INFO (Thread-6622) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39085 39085
[junit4] 2> 3004922 WARN (Thread-6622) [ ] 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>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/collections/cdcr-target/state.json
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 2 /solr/collections/cdcr-target/cdcr/state/process
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> 3004922 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[6BA7020F5866EFF4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBootstrapWithContinousIndexingOnSourceCluster
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CdcrBootstrapTest -Dtests.method=testBootstrapWithContinousIndexingOnSourceCluster -Dtests.seed=6BA7020F5866EFF4 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar-LB -Dtests.timezone=Asia/Kuala_Lumpur -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 146s J2 | CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster <<<
[junit4] > Throwable #1: java.lang.AssertionError: Document mismatch on target after sync expected:<2000> but was:<1901>
[junit4] > at __randomizedtesting.SeedInfo.seed([6BA7020F5866EFF4:BFE24956BF305C0F]:0)
[junit4] > at org.apache.solr.cloud.cdcr.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster(CdcrBootstrapTest.java:292)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.cdcr.CdcrBootstrapTest_6BA7020F5866EFF4-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {xyz=Lucene50(blocksize=128), id=PostingsFormat(name=Direct)}, docValues:{_version_=DocValuesFormat(name=Lucene70), xyz=DocValuesFormat(name=Asserting), id=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=326, maxMBSortInHeap=5.922990206880156, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@e3100c9), locale=ar-LB, timezone=Asia/Kuala_Lumpur
[junit4] 2> NOTE: Linux 4.13.0-26-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=153512688,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [TestTolerantSearch, TestQuerySenderListener, TestCloudPseudoReturnFields, ConnectionReuseTest, SpatialHeatmapFacetsTest, TestJmxIntegration, OverseerRolesTest, TestChildDocTransformer, TestCodecSupport, AtomicUpdatesTest, InfixSuggestersTest, StatsReloadRaceTest, SearchHandlerTest, SpatialFilterTest, OverriddenZkACLAndCredentialsProvidersTest, URLClassifyProcessorTest, SolrCmdDistributorTest, TestRealTimeGet, TestLazyCores, DistributedDebugComponentTest, TestRawTransformer, TestDistributedStatsComponentCardinality, ClusterStateUpdateTest, JvmMetricsTest, TestCoreBackup, ExplicitHLLTest, ZkStateWriterTest, MoveReplicaHDFSFailoverTest, DirectoryFactoryTest, TestUtilizeNode, StatelessScriptUpdateProcessorFactoryTest, LukeRequestHandlerTest, TestExactSharedStatsCache, CurrencyRangeFacetCloudTest, TestCoreDiscovery, SpellPossibilityIteratorTest, TestBulkSchemaConcurrent, IgnoreCommitOptimizeUpdateProcessorFactoryTest, SolrGangliaReporterTest, SolrShardReporterTest, SolrJmxReporterTest, HdfsBasicDistributedZkTest, TestCollationFieldDocValues, PeerSyncReplicationTest, TestDFRSimilarityFactory, TestMissingGroups, TestImplicitCoreProperties, ResponseHeaderTest, AutoAddReplicasIntegrationTest, ConvertedLegacyTest, CurrencyFieldTypeTest, HdfsLockFactoryTest, TestJavabinTupleStreamParser, TestRangeQuery, TestSolrCoreProperties, TestComplexPhraseQParserPlugin, HdfsCollectionsAPIDistributedZkTest, TestAddFieldRealTimeGet, TestSchemaManager, TestLocalFSCloudBackupRestore, TestExportWriter, DeleteNodeTest, DistributedFacetPivotSmallTest, HdfsNNFailoverTest, TestSQLHandlerNonCloud, CoreMergeIndexesAdminHandlerTest, AddBlockUpdateTest, CdcrRequestHandlerTest, BlockDirectoryTest, ReturnFieldsTest, TestScoreJoinQPNoScore, TestRequestForwarding, DistributedSpellCheckComponentTest, CollectionReloadTest, VMParamsZkACLAndCredentialsProvidersTest, TestUseDocValuesAsStored2, ReplaceNodeTest, TestObjectReleaseTracker, ComputePlanActionTest, PingRequestHandlerTest, TestSolrCloudWithHadoopAuthPlugin, RollingRestartTest, PropertiesRequestHandlerTest, CachingDirectoryFactoryTest, TestOrdValues, TestLegacyField, TestFieldCacheReopen, EnumFieldTest, TestStressReorder, SolrXmlInZkTest, DistribJoinFromCollectionTest, MoreLikeThisHandlerTest, TestFieldResource, TestLockTree, SearchHandlerTest, DisMaxRequestHandlerTest, SolrTestCaseJ4Test, TestConfigSetsAPIZkFailure, CollectionsAPISolrJTest, SmileWriterTest, DistanceUnitsTest, TimeZoneUtilsTest, BlockJoinFacetDistribTest, BadCopyFieldTest, TestRandomFlRTGCloud, BasicAuthIntegrationTest, TestUpdate, TestFreeTextSuggestions, TestTriggerIntegration, DateMathParserTest, DataDrivenBlockJoinTest, LeaderElectionIntegrationTest, TestEmbeddedSolrServerConstructors, HttpPartitionTest, TestSolr4Spatial2, TestRestManager, TestFieldCacheVsDocValues, LegacyCloudClusterPropTest, TestNumericRangeQuery64, TestComputePlanAction, TestXmlQParser, UniqFieldsUpdateProcessorFactoryTest, TestSchemaNameResource, TestCorePropertiesReload, BigEndianAscendingWordDeserializerTest, AnalysisAfterCoreReloadTest, RegexBoostProcessorTest, BasicDistributedZk2Test, UnloadDistributedZkTest, SyncSliceTest, RecoveryZkTest, TestRandomFaceting, LeaderElectionTest, TestDistributedSearch, TestFaceting, TestRecovery, TestCoreContainer, SolrCoreTest, SpellCheckComponentTest, BadIndexSchemaTest, TestFiltering, DistributedQueryElevationComponentTest, SuggesterFSTTest, SolrRequestParserTest, DocValuesTest, SchemaVersionSpecificBehaviorTest, TestPseudoReturnFields, TestAtomicUpdateErrorCases, DocValuesMultiTest, SolrInfoBeanTest, CacheHeaderTest, IndexBasedSpellCheckerTest, DirectSolrSpellCheckerTest, FileBasedSpellCheckerTest, RequestHandlersTest, DocumentBuilderTest, TestValueSourceCache, TermVectorComponentTest, RequiredFieldsTest, TestSolrQueryParser, IndexSchemaTest, QueryParsingTest, TestAnalyzedSuggestions, BinaryUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, TestLFUCache, PreAnalyzedFieldTest, TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, DOMUtilTest, RAMDirectoryFactoryTest, ClusterStateTest, TestSolrJ, TestLRUCache, TestUtils, SliceStateTest, SystemInfoHandlerTest, CircularListTest, DistributedIntervalFacetingTest, TestCursorMarkWithoutUniqueKey, TestDistributedMissingSort, TestHighlightDedupGrouping, TestSimpleTrackingShardHandler, TestLuceneIndexBackCompat, TestEmbeddedSolrServerSchemaAPI, AddReplicaTest, AliasIntegrationTest, ChaosMonkeySafeLeaderWithPullReplicasTest, CleanupOldIndexTest, CloudExitableDirectoryReaderTest, ConnectionManagerTest, CreateCollectionCleanupTest, DeleteInactiveReplicaTest, DeleteStatusTest, DistribCursorPagingTest, DocValuesNotIndexedTest, HealthCheckHandlerTest, LeaderElectionContextKeyTest, LeaderFailureAfterFreshStartTest, LeaderInitiatedRecoveryOnCommitTest, MissingSegmentRecoveryTest, MoveReplicaTest, OverseerCollectionConfigSetProcessorTest, OverseerModifyCollectionTest, OverseerStatusTest, RemoteQueryErrorTest, SSLMigrationTest, SaslZkACLProviderTest, SharedFSAutoReplicaFailoverTest, SolrCLIZkUtilsTest, TestAuthenticationFramework, TestClusterProperties, TestConfigSetsAPIExclusivity, TestCryptoKeys, TestDeleteCollectionOnDownNodes, TestDistribDocBasedVersion, TestLeaderElectionZkExpiry, TestMiniSolrCloudClusterSSL, TestPrepRecovery, TestRandomRequestDistribution, TestSSLRandomization, TestShortCircuitedRequests, TestSkipOverseerOperations, TestStressInPlaceUpdates, TestTolerantUpdateProcessorRandomCloud, TlogReplayBufferedWhileIndexingTest, TriLevelCompositeIdRoutingTest, AssignTest, CollectionsAPIDistributedZkTest, TestCollectionAPI, AutoAddReplicasPlanActionTest, HttpTriggerListenerTest, MetricTriggerTest, SearchRateTriggerTest, TestGenericDistributedQueue, TestLargeCluster, TestNodeLostTrigger, BaseCdcrDistributedZkTest, CdcrBidirectionalTest, CdcrBootstrapTest]
[junit4] Completed [628/768 (1!)] on J2 in 201.61s, 3 tests, 1 failure <<< FAILURES!
[...truncated 48510 lines...]