Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2/ Java: 32bit/jdk1.8.0_131 -server -XX:+UseParallelGC
1 tests failed. FAILED: org.apache.solr.cloud.TestPullReplica.testKillLeader Error Message: Replica state not updated in cluster state null Live Nodes: [127.0.0.1:37547_solr, 127.0.0.1:35119_solr] Last available state: DocCollection(pull_replica_test_kill_leader//collections/pull_replica_test_kill_leader/state.json/5)={ "pullReplicas":"1", "replicationFactor":"1", "shards":{"shard1":{ "range":"80000000-7fffffff", "state":"active", "replicas":{ "core_node1":{ "core":"pull_replica_test_kill_leader_shard1_replica_n1", "base_url":"http://127.0.0.1:37547/solr", "node_name":"127.0.0.1:37547_solr", "state":"down", "type":"NRT", "leader":"true"}, "core_node2":{ "core":"pull_replica_test_kill_leader_shard1_replica_p1", "base_url":"http://127.0.0.1:35119/solr", "node_name":"127.0.0.1:35119_solr", "state":"active", "type":"PULL"}}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"100", "autoAddReplicas":"false", "nrtReplicas":"1", "tlogReplicas":"0"} Stack Trace: java.lang.AssertionError: Replica state not updated in cluster state null Live Nodes: [127.0.0.1:37547_solr, 127.0.0.1:35119_solr] Last available state: DocCollection(pull_replica_test_kill_leader//collections/pull_replica_test_kill_leader/state.json/5)={ "pullReplicas":"1", "replicationFactor":"1", "shards":{"shard1":{ "range":"80000000-7fffffff", "state":"active", "replicas":{ "core_node1":{ "core":"pull_replica_test_kill_leader_shard1_replica_n1", "base_url":"http://127.0.0.1:37547/solr", "node_name":"127.0.0.1:37547_solr", "state":"down", "type":"NRT", "leader":"true"}, "core_node2":{ "core":"pull_replica_test_kill_leader_shard1_replica_p1", "base_url":"http://127.0.0.1:35119/solr", "node_name":"127.0.0.1:35119_solr", "state":"active", "type":"PULL"}}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"100", "autoAddReplicas":"false", "nrtReplicas":"1", "tlogReplicas":"0"} at __randomizedtesting.SeedInfo.seed([56591437A7A7CE7B:1F4FE083C51C5A2D]:0) at org.junit.Assert.fail(Assert.java:93) at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:269) at org.apache.solr.cloud.TestPullReplica.doTestNoLeader(TestPullReplica.java:401) at org.apache.solr.cloud.TestPullReplica.testKillLeader(TestPullReplica.java:290) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) Build Log: [...truncated 12064 lines...] [junit4] Suite: org.apache.solr.cloud.TestPullReplica [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/init-core-data-001 [junit4] 2> 913073 WARN (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=8 numCloses=8 [junit4] 2> 913073 INFO (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true [junit4] 2> 913074 INFO (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-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> 913075 INFO (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001 [junit4] 2> 913075 INFO (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 913075 INFO (Thread-3949) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 913075 INFO (Thread-3949) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 913076 ERROR (Thread-3949) [ ] 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> 913175 INFO (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:43129 [junit4] 2> 913186 INFO (jetty-launcher-1101-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 913190 INFO (jetty-launcher-1101-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 913226 INFO (jetty-launcher-1101-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1849f76{/solr,null,AVAILABLE} [junit4] 2> 913236 INFO (jetty-launcher-1101-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1497fb{HTTP/1.1,[http/1.1]}{127.0.0.1:37547} [junit4] 2> 913236 INFO (jetty-launcher-1101-thread-2) [ ] o.e.j.s.Server Started @914789ms [junit4] 2> 913236 INFO (jetty-launcher-1101-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37547} [junit4] 2> 913236 ERROR (jetty-launcher-1101-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 913236 INFO (jetty-launcher-1101-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 913236 INFO (jetty-launcher-1101-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 913236 INFO (jetty-launcher-1101-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 913236 INFO (jetty-launcher-1101-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-07-04T14:13:57.271Z [junit4] 2> 913242 INFO (jetty-launcher-1101-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 913242 INFO (jetty-launcher-1101-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1e9eadf{/solr,null,AVAILABLE} [junit4] 2> 913242 INFO (jetty-launcher-1101-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@162fe5{HTTP/1.1,[http/1.1]}{127.0.0.1:35119} [junit4] 2> 913242 INFO (jetty-launcher-1101-thread-1) [ ] o.e.j.s.Server Started @914796ms [junit4] 2> 913243 INFO (jetty-launcher-1101-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35119} [junit4] 2> 913243 ERROR (jetty-launcher-1101-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 913243 INFO (jetty-launcher-1101-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 913243 INFO (jetty-launcher-1101-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 913243 INFO (jetty-launcher-1101-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 913243 INFO (jetty-launcher-1101-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-07-04T14:13:57.278Z [junit4] 2> 913271 INFO (jetty-launcher-1101-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43129/solr [junit4] 2> 913280 INFO (jetty-launcher-1101-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 913307 INFO (jetty-launcher-1101-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43129/solr [junit4] 2> 913342 INFO (jetty-launcher-1101-thread-1) [n:127.0.0.1:35119_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 913342 INFO (jetty-launcher-1101-thread-1) [n:127.0.0.1:35119_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35119_solr [junit4] 2> 913343 INFO (jetty-launcher-1101-thread-1) [n:127.0.0.1:35119_solr ] o.a.s.c.Overseer Overseer (id=98250105625640966-127.0.0.1:35119_solr-n_0000000000) starting [junit4] 2> 913365 INFO (jetty-launcher-1101-thread-2) [n:127.0.0.1:37547_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 913365 INFO (jetty-launcher-1101-thread-2) [n:127.0.0.1:37547_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37547_solr [junit4] 2> 913387 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 913387 INFO (jetty-launcher-1101-thread-1) [n:127.0.0.1:35119_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35119_solr [junit4] 2> 913402 INFO (zkCallback-1109-thread-1-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 913418 INFO (zkCallback-1109-thread-1-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 913418 INFO (zkCallback-1114-thread-1-processing-n:127.0.0.1:35119_solr) [n:127.0.0.1:35119_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 913560 INFO (jetty-launcher-1101-thread-2) [n:127.0.0.1:37547_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37547.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 913565 INFO (jetty-launcher-1101-thread-1) [n:127.0.0.1:35119_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35119.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 913570 INFO (jetty-launcher-1101-thread-1) [n:127.0.0.1:35119_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35119.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 913571 INFO (jetty-launcher-1101-thread-1) [n:127.0.0.1:35119_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35119.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 913571 INFO (jetty-launcher-1101-thread-1) [n:127.0.0.1:35119_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node1/. [junit4] 2> 913573 INFO (jetty-launcher-1101-thread-2) [n:127.0.0.1:37547_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37547.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 913573 INFO (jetty-launcher-1101-thread-2) [n:127.0.0.1:37547_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37547.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 913574 INFO (jetty-launcher-1101-thread-2) [n:127.0.0.1:37547_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node2/. [junit4] 2> 913624 INFO (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 913624 INFO (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43129/solr ready [junit4] 2> 913626 INFO (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.s.c.TestPullReplica Using legacyCloud?: false [junit4] 2> 913638 INFO (qtp26260405-9651) [n:127.0.0.1:37547_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterprop with params val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 913642 INFO (qtp26260405-9651) [n:127.0.0.1:37547_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2} status=0 QTime=4 [junit4] 2> 913666 INFO (TEST-TestPullReplica.testCreateDelete-seed#[56591437A7A7CE7B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateDelete { seed=[56591437A7A7CE7B:4D49E57B5157364B]} [junit4] 2> 913674 INFO (OverseerThreadFactory-3300-thread-1-processing-n:127.0.0.1:35119_solr) [n:127.0.0.1:35119_solr ] o.a.s.c.CreateCollectionCmd Create collection pull_replica_test_create_delete [junit4] 2> 913674 WARN (OverseerThreadFactory-3300-thread-1-processing-n:127.0.0.1:35119_solr) [n:127.0.0.1:35119_solr ] o.a.s.c.CreateCollectionCmd Specified number of replicas of 4 on collection pull_replica_test_create_delete is higher than the number of Solr instances currently live or live and part of your createNodeSet(2). It's unusual to run two replica of the same slice on the same Solr-instance. [junit4] 2> 913777 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"pull_replica_test_create_delete", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"pull_replica_test_create_delete_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:37547/solr", [junit4] 2> "type":"NRT"} [junit4] 2> 913779 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"pull_replica_test_create_delete", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"pull_replica_test_create_delete_shard1_replica_p1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:35119/solr", [junit4] 2> "type":"PULL"} [junit4] 2> 913781 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"pull_replica_test_create_delete", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"pull_replica_test_create_delete_shard1_replica_p2", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:37547/solr", [junit4] 2> "type":"PULL"} [junit4] 2> 913782 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"pull_replica_test_create_delete", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"pull_replica_test_create_delete_shard1_replica_p3", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:35119/solr", [junit4] 2> "type":"PULL"} [junit4] 2> 913783 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"pull_replica_test_create_delete", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"pull_replica_test_create_delete_shard2_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:37547/solr", [junit4] 2> "type":"NRT"} [junit4] 2> 913784 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"pull_replica_test_create_delete", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"pull_replica_test_create_delete_shard2_replica_p1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:35119/solr", [junit4] 2> "type":"PULL"} [junit4] 2> 913785 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"pull_replica_test_create_delete", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"pull_replica_test_create_delete_shard2_replica_p2", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:37547/solr", [junit4] 2> "type":"PULL"} [junit4] 2> 913786 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"pull_replica_test_create_delete", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"pull_replica_test_create_delete_shard2_replica_p3", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:35119/solr", [junit4] 2> "type":"PULL"} [junit4] 2> 913991 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_n1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=NRT [junit4] 2> 913991 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 913992 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_p2&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=PULL [junit4] 2> 913993 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_n1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=NRT [junit4] 2> 913997 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p2&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL [junit4] 2> 913998 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL [junit4] 2> 913998 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p3&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL [junit4] 2> 913998 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 913998 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_p1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=PULL [junit4] 2> 913999 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_p3&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=PULL [junit4] 2> 914110 INFO (zkCallback-1114-thread-1-processing-n:127.0.0.1:35119_solr) [n:127.0.0.1:35119_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 914110 INFO (zkCallback-1109-thread-1-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 914110 INFO (zkCallback-1109-thread-2-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 915003 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 915007 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 915012 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_n1] Schema name=minimal [junit4] 2> 915012 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_p2] Schema name=minimal [junit4] 2> 915014 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 915015 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 915015 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard2_replica_n1' using configuration from collection pull_replica_test_create_delete, trusted=true [junit4] 2> 915015 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 915015 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard2_replica_p2' using configuration from collection pull_replica_test_create_delete, trusted=true [junit4] 2> 915016 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 915016 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37547.solr.core.pull_replica_test_create_delete.shard2.replica_n1' (registry 'solr.core.pull_replica_test_create_delete.shard2.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 915016 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37547.solr.core.pull_replica_test_create_delete.shard2.replica_p2' (registry 'solr.core.pull_replica_test_create_delete.shard2.replica_p2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 915016 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 915016 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 915016 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard2_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node2/pull_replica_test_create_delete_shard2_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node2/./pull_replica_test_create_delete_shard2_replica_n1/data/] [junit4] 2> 915016 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard2_replica_p2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node2/pull_replica_test_create_delete_shard2_replica_p2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node2/./pull_replica_test_create_delete_shard2_replica_p2/data/] [junit4] 2> 915021 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_n1] Schema name=minimal [junit4] 2> 915024 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 915038 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 915043 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 915044 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_p2] Schema name=minimal [junit4] 2> 915045 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 915045 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 915048 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_p1] Schema name=minimal [junit4] 2> 915051 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_p3] Schema name=minimal [junit4] 2> 915052 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_p1] Schema name=minimal [junit4] 2> 915052 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 915052 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard2_replica_p1' using configuration from collection pull_replica_test_create_delete, trusted=true [junit4] 2> 915045 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard1_replica_p2' using configuration from collection pull_replica_test_create_delete, trusted=true [junit4] 2> 915053 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 915053 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard1_replica_p3' using configuration from collection pull_replica_test_create_delete, trusted=true [junit4] 2> 915050 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_p3] Schema name=minimal [junit4] 2> 915053 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35119.solr.core.pull_replica_test_create_delete.shard1.replica_p3' (registry 'solr.core.pull_replica_test_create_delete.shard1.replica_p3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 915054 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 915054 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard1_replica_p3] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node1/pull_replica_test_create_delete_shard1_replica_p3], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node1/./pull_replica_test_create_delete_shard1_replica_p3/data/] [junit4] 2> 915055 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 915055 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard2_replica_p3' using configuration from collection pull_replica_test_create_delete, trusted=true [junit4] 2> 915055 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 915055 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard1_replica_p1' using configuration from collection pull_replica_test_create_delete, trusted=true [junit4] 2> 915055 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35119.solr.core.pull_replica_test_create_delete.shard2.replica_p3' (registry 'solr.core.pull_replica_test_create_delete.shard2.replica_p3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 915055 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 915055 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35119.solr.core.pull_replica_test_create_delete.shard1.replica_p1' (registry 'solr.core.pull_replica_test_create_delete.shard1.replica_p1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 915056 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard2_replica_p3] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node1/pull_replica_test_create_delete_shard2_replica_p3], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node1/./pull_replica_test_create_delete_shard2_replica_p3/data/] [junit4] 2> 915056 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37547.solr.core.pull_replica_test_create_delete.shard1.replica_p2' (registry 'solr.core.pull_replica_test_create_delete.shard1.replica_p2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 915056 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 915056 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard1_replica_p2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node2/pull_replica_test_create_delete_shard1_replica_p2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node2/./pull_replica_test_create_delete_shard1_replica_p2/data/] [junit4] 2> 915048 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 915056 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 915057 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard1_replica_n1' using configuration from collection pull_replica_test_create_delete, trusted=true [junit4] 2> 915058 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35119.solr.core.pull_replica_test_create_delete.shard2.replica_p1' (registry 'solr.core.pull_replica_test_create_delete.shard2.replica_p1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 915058 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 915058 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard2_replica_p1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node1/pull_replica_test_create_delete_shard2_replica_p1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node1/./pull_replica_test_create_delete_shard2_replica_p1/data/] [junit4] 2> 915060 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37547.solr.core.pull_replica_test_create_delete.shard1.replica_n1' (registry 'solr.core.pull_replica_test_create_delete.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@aeb7a5 [junit4] 2> 915060 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 915060 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node2/pull_replica_test_create_delete_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node2/./pull_replica_test_create_delete_shard1_replica_n1/data/] [junit4] 2> 915062 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard1_replica_p1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node1/pull_replica_test_create_delete_shard1_replica_p1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001/tempDir-001/node1/./pull_replica_test_create_delete_shard1_replica_p1/data/] [junit4] 2> 915120 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 915120 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 915134 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.s.SolrIndexSearcher Opening [Searcher@140587f[pull_replica_test_create_delete_shard1_replica_p3] main] [junit4] 2> 915135 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 915135 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 915136 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 915136 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 915137 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 915137 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 915139 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 915139 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.ZkController pull_replica_test_create_delete_shard1_replica_p3 starting background replication from leader [junit4] 2> 915139 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03 [junit4] 2> 915141 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms [junit4] 2> 915144 INFO (searcherExecutor-3309-thread-1-processing-n:127.0.0.1:35119_solr x:pull_replica_test_create_delete_shard1_replica_p3 s:shard1 c:pull_replica_test_create_delete r:core_node4) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard1_replica_p3] Registered new searcher Searcher@140587f[pull_replica_test_create_delete_shard1_replica_p3] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 915145 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4b2af8[pull_replica_test_create_delete_shard2_replica_p1] main] [junit4] 2> 915146 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.s.SolrIndexSearcher Opening [Searcher@113b113[pull_replica_test_create_delete_shard2_replica_p2] main] [junit4] 2> 915147 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 915147 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 915147 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 915147 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 915148 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 915148 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 915149 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 915150 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 915150 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 915150 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.c.ZkController pull_replica_test_create_delete_shard2_replica_p1 starting background replication from leader [junit4] 2> 915150 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03 [junit4] 2> 915150 INFO (searcherExecutor-3307-thread-1-processing-n:127.0.0.1:35119_solr x:pull_replica_test_create_delete_shard2_replica_p1 s:shard2 c:pull_replica_test_create_delete r:core_node6) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard2_replica_p1] Registered new searcher Searcher@4b2af8[pull_replica_test_create_delete_shard2_replica_p1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 915151 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@83d575[pull_replica_test_create_delete_shard2_replica_n1] main] [junit4] 2> 915151 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms [junit4] 2> 915154 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 915154 INFO (searcherExecutor-3306-thread-1-processing-n:127.0.0.1:37547_solr x:pull_replica_test_create_delete_shard2_replica_p2 s:shard2 c:pull_replica_test_create_delete r:core_node7) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard2_replica_p2] Registered new searcher Searcher@113b113[pull_replica_test_create_delete_shard2_replica_p2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 915155 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 915155 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 915155 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.c.ZkController pull_replica_test_create_delete_shard2_replica_p2 starting background replication from leader [junit4] 2> 915155 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03 [junit4] 2> 915156 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 915156 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 915156 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.s.SolrIndexSearcher Opening [Searcher@107b19a[pull_replica_test_create_delete_shard2_replica_p3] main] [junit4] 2> 915156 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 915156 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms [junit4] 2> 915156 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1572001692192342016 [junit4] 2> 915157 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 915157 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 915157 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 915157 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 915157 INFO (searcherExecutor-3305-thread-1-processing-n:127.0.0.1:37547_solr x:pull_replica_test_create_delete_shard2_replica_n1 s:shard2 c:pull_replica_test_create_delete r:core_node5) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard2_replica_n1] Registered new searcher Searcher@83d575[pull_replica_test_create_delete_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 915158 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 915158 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 915158 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 915158 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.c.ZkController pull_replica_test_create_delete_shard2_replica_p3 starting background replication from leader [junit4] 2> 915158 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03 [junit4] 2> 915159 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms [junit4] 2> 915159 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@543117[pull_replica_test_create_delete_shard1_replica_n1] main] [junit4] 2> 915159 INFO (searcherExecutor-3310-thread-1-processing-n:127.0.0.1:35119_solr x:pull_replica_test_create_delete_shard2_replica_p3 s:shard2 c:pull_replica_test_create_delete r:core_node8) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard2_replica_p3] Registered new searcher Searcher@107b19a[pull_replica_test_create_delete_shard2_replica_p3] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 915160 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 915160 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 915160 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 915160 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 915160 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:37547/solr/pull_replica_test_create_delete_shard2_replica_n1/ [junit4] 2> 915160 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 915160 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 915160 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 915160 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:37547/solr/pull_replica_test_create_delete_shard2_replica_n1/ has no replicas [junit4] 2> 915160 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 915160 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 915161 INFO (searcherExecutor-3312-thread-1-processing-n:127.0.0.1:37547_solr x:pull_replica_test_create_delete_shard1_replica_n1 s:shard1 c:pull_replica_test_create_delete r:core_node1) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard1_replica_n1] Registered new searcher Searcher@543117[pull_replica_test_create_delete_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 915161 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1572001692197584896 [junit4] 2> 915162 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.s.SolrIndexSearcher Opening [Searcher@14a891b[pull_replica_test_create_delete_shard1_replica_p2] main] [junit4] 2> 915163 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 915163 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 915165 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.s.SolrIndexSearcher Opening [Searcher@681aeb[pull_replica_test_create_delete_shard1_replica_p1] main] [junit4] 2> 915165 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 915165 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 915166 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:37547/solr/pull_replica_test_create_delete_shard2_replica_n1/ shard2 [junit4] 2> 915166 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 915166 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 915166 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.ZkController pull_replica_test_create_delete_shard1_replica_p2 starting background replication from leader [junit4] 2> 915166 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03 [junit4] 2> 915167 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 915167 INFO (searcherExecutor-3308-thread-1-processing-n:127.0.0.1:37547_solr x:pull_replica_test_create_delete_shard1_replica_p2 s:shard1 c:pull_replica_test_create_delete r:core_node3) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard1_replica_p2] Registered new searcher Searcher@14a891b[pull_replica_test_create_delete_shard1_replica_p2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 915167 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms [junit4] 2> 915167 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 915168 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 915168 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 915168 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.c.ZkController pull_replica_test_create_delete_shard1_replica_p1 starting background replication from leader [junit4] 2> 915168 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:37547/solr/pull_replica_test_create_delete_shard1_replica_n1/ [junit4] 2> 915168 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03 [junit4] 2> 915168 INFO (searcherExecutor-3311-thread-1-processing-n:127.0.0.1:35119_solr x:pull_replica_test_create_delete_shard1_replica_p1 s:shard1 c:pull_replica_test_create_delete r:core_node2) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard1_replica_p1] Registered new searcher Searcher@681aeb[pull_replica_test_create_delete_shard1_replica_p1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 915168 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 915168 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:37547/solr/pull_replica_test_create_delete_shard1_replica_n1/ has no replicas [junit4] 2> 915168 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 915169 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms [junit4] 2> 915169 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:37547/solr/pull_replica_test_create_delete_shard1_replica_n1/ shard1 [junit4] 2> 915271 INFO (zkCallback-1114-thread-1-processing-n:127.0.0.1:35119_solr) [n:127.0.0.1:35119_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 915271 INFO (zkCallback-1109-thread-1-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 915271 INFO (zkCallback-1109-thread-2-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 915301 INFO (indexFetcher-3333-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.h.IndexFetcher Replica core_node5 is leader but it's state is down, skipping replication [junit4] 2> 915307 INFO (indexFetcher-3337-thread-1) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.h.IndexFetcher Replica core_node5 is leader but it's state is down, skipping replication [junit4] 2> 915317 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 915317 INFO (indexFetcher-3348-thread-1) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.h.IndexFetcher Replica core_node1 is leader but it's state is down, skipping replication [junit4] 2> 915318 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_n1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1325 [junit4] 2> 915319 INFO (indexFetcher-3350-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.h.IndexFetcher Replica core_node1 is leader but it's state is down, skipping replication [junit4] 2> 915319 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 915320 INFO (qtp26260405-9646) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_n1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1329 [junit4] 2> 915321 INFO (qtp31486874-9660) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node2 x:pull_replica_test_create_delete_shard1_replica_p1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL} status=0 QTime=1323 [junit4] 2> 915423 INFO (zkCallback-1114-thread-1-processing-n:127.0.0.1:35119_solr) [n:127.0.0.1:35119_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 915423 INFO (zkCallback-1109-thread-2-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 915423 INFO (zkCallback-1109-thread-1-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 916053 INFO (indexFetcher-3342-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.h.IndexFetcher Updated masterUrl to http://127.0.0.1:37547/solr/pull_replica_test_create_delete_shard2_replica_n1/ [junit4] 2> 916054 INFO (qtp26260405-9716) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node5 x:pull_replica_test_create_delete_shard2_replica_n1] o.a.s.c.S.Request [pull_replica_test_create_delete_shard2_replica_n1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 916054 INFO (indexFetcher-3342-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.h.IndexFetcher Master's generation: 1 [junit4] 2> 916054 INFO (indexFetcher-3342-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.h.IndexFetcher Master's version: 0 [junit4] 2> 916054 INFO (indexFetcher-3342-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 916054 INFO (indexFetcher-3342-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.h.IndexFetcher Slave's version: 0 [junit4] 2> 916142 INFO (qtp31486874-9645) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p3&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL} status=0 QTime=2144 [junit4] 2> 916157 INFO (qtp31486874-9654) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node6 x:pull_replica_test_create_delete_shard2_replica_p1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_p1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=PULL} status=0 QTime=2158 [junit4] 2> 916158 INFO (qtp26260405-9649) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard2 r:core_node7 x:pull_replica_test_create_delete_shard2_replica_p2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_p2&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=PULL} status=0 QTime=2166 [junit4] 2> 916160 INFO (qtp31486874-9656) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard2 r:core_node8 x:pull_replica_test_create_delete_shard2_replica_p3] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_p3&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=PULL} status=0 QTime=2161 [junit4] 2> 916169 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node3 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p2&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL} status=0 QTime=2172 [junit4] 2> 916170 INFO (qtp26260405-9647) [n:127.0.0.1:37547_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> 916269 INFO (zkCallback-1109-thread-2-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 916269 INFO (zkCallback-1114-thread-1-processing-n:127.0.0.1:35119_solr) [n:127.0.0.1:35119_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 916269 INFO (zkCallback-1109-thread-1-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2]) [junit4] 2> 916352 INFO (indexFetcher-3327-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.IndexFetcher Updated masterUrl to http://127.0.0.1:37547/solr/pull_replica_test_create_delete_shard1_replica_n1/ [junit4] 2> 916353 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr c:pull_replica_test_create_delete s:shard1 r:core_node1 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.S.Request [pull_replica_test_create_delete_shard1_replica_n1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 916353 INFO (indexFetcher-3327-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.IndexFetcher Master's generation: 1 [junit4] 2> 916353 INFO (indexFetcher-3327-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.IndexFetcher Master's version: 0 [junit4] 2> 916353 INFO (indexFetcher-3327-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 916353 INFO (indexFetcher-3327-thread-1) [n:127.0.0.1:35119_solr c:pull_replica_test_create_delete s:shard1 r:core_node4 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.IndexFetcher Slave's version: 0 [junit4] 2> 917170 INFO (qtp26260405-9647) [n:127.0.0.1:37547_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/c params={} status=0 QTime=3503 [junit4] 2> 917173 INFO (qtp26260405-9652) [n:127.0.0.1:37547_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :reload with params name=pull_replica_test_create_delete&action=RELOAD&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 917174 INFO (OverseerThreadFactory-3300-thread-2-processing-n:127.0.0.1:35119_solr) [n:127.0.0.1:35119_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=RELOAD [junit4] 2> 917175 INFO (OverseerCollectionConfigSetProcessor-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_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> 917193 INFO (qtp31486874-9644) [n:127.0.0.1:35119_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 917193 INFO (qtp26260405-9648) [n:127.0.0.1:37547_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 917194 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 917211 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 917215 INFO (qtp31486874-9661) [n:127.0.0.1:35119_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 917217 INFO (qtp31486874-9662) [n:127.0.0.1:35119_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 917222 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr ] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_n1] Schema name=minimal [junit4] 2> 917223 INFO (qtp31486874-9713) [n:127.0.0.1:35119_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 917224 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr ] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_p2] Schema name=minimal [junit4] 2> 917225 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 917225 INFO (qtp26260405-9712) [n:127.0.0.1:37547_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 917225 INFO (qtp26260405-9653) [n:127.0.0.1:37547_solr ] o.a.s.c.CoreContainer Reloading SolrCore 'pull_replica_test_create_delete_shard2_replica_n1' using configuration from collection pull_replica_test_create_delete [junit4] 2> 917255 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 917256 INFO (qtp26260405-9711) [n:127.0.0.1:37547_solr ] o.a.s.c.CoreContainer Reloading SolrCore 'pull_replica_test_create_delete_shard2_replica_p2' using configuration from collection pull_replica_test_create_delete [junit4] 2> 917258 INFO (qtp26260405-9648) [n:127.0.0.1:37547_solr ] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_p2] Schema name=minimal [junit4] 2> 917259 INFO (qtp31486874-9644) [n:127.0.0.1:35119_solr ] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_p3] Schema name=minimal [junit4] 2> 917260 INFO (qtp26260405-9648) [n:127.0.0.1:37547_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 917260 INFO (qtp26260405-9648) [n:127.0.0.1:37547_solr ] o.a.s.c.CoreContainer Reloading SolrC [...truncated too long message...] nrtReplicas":"1", [junit4] > "tlogReplicas":"0"} [junit4] > at __randomizedtesting.SeedInfo.seed([56591437A7A7CE7B:1F4FE083C51C5A2D]:0) [junit4] > at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:269) [junit4] > at org.apache.solr.cloud.TestPullReplica.doTestNoLeader(TestPullReplica.java:401) [junit4] > at org.apache.solr.cloud.TestPullReplica.testKillLeader(TestPullReplica.java:290) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] 2> 1056968 INFO (TEST-TestPullReplica.testSearchWhileReplicationHappens-seed#[56591437A7A7CE7B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSearchWhileReplicationHappens [junit4] 2> 1056968 INFO (TEST-TestPullReplica.testSearchWhileReplicationHappens-seed#[56591437A7A7CE7B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSearchWhileReplicationHappens [junit4] 2> 1056969 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15d0df354f60008, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> 1056970 INFO (jetty-closer-1102-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@102b11a{HTTP/1.1,[http/1.1]}{127.0.0.1:37547} [junit4] 2> 1056970 INFO (jetty-closer-1102-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@162fe5{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 1056973 INFO (jetty-closer-1102-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=17964865 [junit4] 2> 1056973 INFO (jetty-closer-1102-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=16578908 [junit4] 2> 1056973 INFO (jetty-closer-1102-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 1056973 INFO (jetty-closer-1102-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 1056975 INFO (jetty-closer-1102-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 1056975 INFO (jetty-closer-1102-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 1056975 INFO (jetty-closer-1102-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 1056976 INFO (jetty-closer-1102-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 1056977 INFO (jetty-closer-1102-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98250105625640966-127.0.0.1:35119_solr-n_0000000000) closing [junit4] 2> 1056977 INFO (OverseerStateUpdate-98250105625640966-127.0.0.1:35119_solr-n_0000000000) [n:127.0.0.1:35119_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35119_solr [junit4] 2> 1056977 INFO (jetty-closer-1102-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 1056977 WARN (zkCallback-1114-thread-5-processing-n:127.0.0.1:35119_solr) [n:127.0.0.1:35119_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 1056977 INFO (zkCallback-1130-thread-1-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 1056977 INFO (zkCallback-1130-thread-2-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37547_solr [junit4] 2> 1056977 INFO (jetty-closer-1102-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1e9eadf{/solr,null,UNAVAILABLE} [junit4] 2> 1056978 INFO (jetty-closer-1102-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 1058478 WARN (zkCallback-1130-thread-2-processing-n:127.0.0.1:37547_solr) [n:127.0.0.1:37547_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 1058479 INFO (jetty-closer-1102-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@141cb0b{/solr,null,UNAVAILABLE} [junit4] 2> 1058479 ERROR (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 1058479 INFO (SUITE-TestPullReplica-seed#[56591437A7A7CE7B]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43129 43129 [junit4] 2> 1058515 INFO (Thread-3949) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43129 43129 [junit4] 2> 1058517 WARN (Thread-3949) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 19 /solr/configs/conf [junit4] 2> 5 /solr/aliases.json [junit4] 2> 4 /solr/security.json [junit4] 2> 3 /solr/clusterprops.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 24 /solr/collections/pull_replica_test_create_delete/state.json [junit4] 2> 20 /solr/collections/pull_replica_test_remove_all_writer_replicas/state.json [junit4] 2> 20 /solr/collections/pull_replica_test_kill_pull_replica/state.json [junit4] 2> 19 /solr/collections/pull_replica_test_add_remove_pull_replica/state.json [junit4] 2> 18 /solr/collections/pull_replica_test_kill_leader/state.json [junit4] 2> 13 /solr/collections/pull_replica_test_add_docs/state.json [junit4] 2> 13 /solr/collections/pull_replica_test_real_time_get/state.json [junit4] 2> 5 /solr/clusterstate.json [junit4] 2> 5 /solr/clusterprops.json [junit4] 2> 3 /solr/overseer_elect/election/98250105625640966-127.0.0.1:35119_solr-n_0000000000 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 5 /solr/collections [junit4] 2> 3 /solr/live_nodes [junit4] 2> [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_56591437A7A7CE7B-001 [junit4] 2> Jul 04, 2017 2:16:22 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {_version_=FSTOrd50, foo=FSTOrd50, id=PostingsFormat(name=LuceneVarGapFixedInterval), foo_s=FSTOrd50}, docValues:{}, maxPointsInLeafNode=612, maxMBSortInHeap=6.518856480708839, sim=RandomSimilarity(queryNorm=false): {}, locale=es-EC, timezone=America/Montreal [junit4] 2> NOTE: Linux 4.10.0-21-generic i386/Oracle Corporation 1.8.0_131 (32-bit)/cpus=8,threads=1,free=175007824,total=463208448 [junit4] 2> NOTE: All tests run in this JVM: [SharedFSAutoReplicaFailoverUtilsTest, RecoveryZkTest, TestIndexSearcher, XsltUpdateRequestHandlerTest, UnloadDistributedZkTest, TestSolrCoreProperties, BlockCacheTest, TestRequestForwarding, HdfsRecoveryZkTest, PreAnalyzedFieldManagedSchemaCloudTest, FullSolrCloudDistribCmdsTest, TestIntervalFaceting, TestCopyFieldCollectionResource, PreAnalyzedUpdateProcessorTest, TestSolrDeletionPolicy2, PreAnalyzedFieldTest, TestDistributedMissingSort, HdfsCollectionsAPIDistributedZkTest, TestUtils, SparseHLLTest, SolrCoreMetricManagerTest, TestChildDocTransformer, OverseerModifyCollectionTest, BadIndexSchemaTest, TestQueryWrapperFilter, DistributedQueryComponentCustomSortTest, TestJmxIntegration, HdfsWriteToMultipleCollectionsTest, LeaderInitiatedRecoveryOnShardRestartTest, TestUniqueKeyFieldResource, TestDeleteCollectionOnDownNodes, AtomicUpdateProcessorFactoryTest, TestStandardQParsers, SimpleFacetsTest, TestFieldCollectionResource, ShowFileRequestHandlerTest, OverseerTaskQueueTest, TestDelegationWithHadoopAuth, TestSort, TestSlowCompositeReaderWrapper, ChaosMonkeyNothingIsSafeWithPullReplicasTest, JSONWriterTest, TestInitQParser, MinimalSchemaTest, HdfsDirectoryTest, TestSearcherReuse, TestLegacyFieldCache, ResponseLogComponentTest, HttpSolrCallGetCoreTest, TestHdfsUpdateLog, SolrInfoBeanTest, DistribCursorPagingTest, DirectUpdateHandlerOptimizeTest, DocumentBuilderTest, TestRTimerTree, TestScoreJoinQPScore, FullHLLTest, TestCoreAdminApis, TestCloudPivotFacet, TestConfigSetsAPIExclusivity, CollectionStateFormat2Test, TestNonDefinedSimilarityFactory, SpellPossibilityIteratorTest, AliasIntegrationTest, TlogReplayBufferedWhileIndexingTest, DistanceUnitsTest, CoreSorterTest, TestPointFields, TestManagedSchema, TestFoldingMultitermQuery, CleanupOldIndexTest, TestStressCloudBlindAtomicUpdates, TestUninvertingReader, SolrMetricsIntegrationTest, PathHierarchyTokenizerFactoryTest, TestFileDictionaryLookup, DocValuesMissingTest, TestFastWriter, TestTrie, TestJsonFacets, TestHttpShardHandlerFactory, TestSystemCollAutoCreate, DeleteReplicaTest, TestDefaultStatsCache, ZkStateReaderTest, TestSubQueryTransformerDistrib, TestTlogReplica, AutoCommitTest, TestFieldCacheSortRandom, TestJettySolrRunner, TestCloudNestedDocsSort, TestPullReplica] [junit4] Completed [355/725 (1!)] on J2 in 145.96s, 10 tests, 1 failure, 1 skipped <<< FAILURES! [...truncated 40557 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org