From dev-return-309104-archive-asf-public=cust-asf.ponee.io@lucene.apache.org Thu Jan 18 01:32:49 2018 Return-Path: X-Original-To: archive-asf-public@eu.ponee.io Delivered-To: archive-asf-public@eu.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by mx-eu-01.ponee.io (Postfix) with ESMTP id B42AD18062C for ; Thu, 18 Jan 2018 01:32:49 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id A44BD160C35; Thu, 18 Jan 2018 00:32:49 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 0091C160C25 for ; Thu, 18 Jan 2018 01:32:46 +0100 (CET) Received: (qmail 79162 invoked by uid 500); 18 Jan 2018 00:32:45 -0000 Mailing-List: contact dev-help@lucene.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@lucene.apache.org Delivered-To: mailing list dev@lucene.apache.org Received: (qmail 79150 invoked by uid 99); 18 Jan 2018 00:32:45 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd3-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 18 Jan 2018 00:32:45 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd3-us-west.apache.org (ASF Mail Server at spamd3-us-west.apache.org) with ESMTP id CD11518086F for ; Thu, 18 Jan 2018 00:32:44 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd3-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -0.299 X-Spam-Level: X-Spam-Status: No, score=-0.299 tagged_above=-999 required=6.31 tests=[KAM_BADIPHTTP=2, RCVD_IN_DNSWL_MED=-2.3, SPF_PASS=-0.001, URIBL_BLOCKED=0.001, WEIRD_PORT=0.001] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd3-us-west.apache.org [10.40.0.10]) (amavisd-new, port 10024) with ESMTP id PF6lySs-Vg7Z for ; Thu, 18 Jan 2018 00:32:27 +0000 (UTC) Received: from serv1.sd-datasolutions.de (serv1.sd-datasolutions.de [88.99.242.108]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id 94DA95F369 for ; Thu, 18 Jan 2018 00:32:26 +0000 (UTC) Received: from serv1 (ip6-localhost [IPv6:::1]) by serv1.sd-datasolutions.de (Postfix) with ESMTP id 9F4F11081ED1 for ; Thu, 18 Jan 2018 00:32:20 +0000 (UTC) Date: Thu, 18 Jan 2018 00:30:45 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <89397619.21.1516235540654.JavaMail.jenkins@serv1.sd-datasolutions.de> In-Reply-To: <527534318.15.1516224290344.JavaMail.jenkins@serv1.sd-datasolutions.de> References: <527534318.15.1516224290344.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-7.x-Linux (64bit/jdk1.8.0_144) - Build # 1194 - Still Unstable! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_20_653194927.1516235540072" X-Jenkins-Job: Lucene-Solr-7.x-Linux X-Jenkins-Result: UNSTABLE ------=_Part_20_653194927.1516235540072 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1194/ Java: 64bit/jdk1.8.0_144 -XX:-UseCompressedOops -XX:+UseParallelGC 1 tests failed. FAILED: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkT= est.testCollectionsAPI Error Message: Error from server at https://127.0.0.1:44823/solr/awhollynewcollection_0_sh= ard3_replica_n4: ClusterState says we are the leader (https://127.0.0.1:448= 23/solr/awhollynewcollection_0_shard3_replica_n4), but locally we don't thi= nk so. Request came from null Stack Trace: org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error fro= m server at https://127.0.0.1:44823/solr/awhollynewcollection_0_shard3_repl= ica_n4: ClusterState says we are the leader (https://127.0.0.1:44823/solr/a= whollynewcollection_0_shard3_replica_n4), but locally we don't think so. Re= quest came from null =09at __randomizedtesting.SeedInfo.seed([2CE134CEA9AE2639:6494407AAF9D09AC]= :0) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudS= olrClient.java:550) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSo= lrClient.java:1013) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnS= taleState(CloudSolrClient.java:884) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnS= taleState(CloudSolrClient.java:946) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnS= taleState(CloudSolrClient.java:946) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnS= taleState(CloudSolrClient.java:946) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnS= taleState(CloudSolrClient.java:946) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnS= taleState(CloudSolrClient.java:946) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrCl= ient.java:817) =09at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194= ) =09at org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateReque= st.java:233) =09at org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest= .testCollectionsAPI(CollectionsAPIDistributedZkTest.java:462) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:62) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:498) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:934) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:970) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:984) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:49) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:368) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:817) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:468) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:829) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:879) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:890) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:41) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:53) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:54) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:368) =09at java.lang.Thread.run(Thread.java:748) Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrExcep= tion: Error from server at https://127.0.0.1:44823/solr/awhollynewcollectio= n_0_shard3_replica_n4: ClusterState says we are the leader (https://127.0.0= .1:44823/solr/awhollynewcollection_0_shard3_replica_n4), but locally we don= 't think so. Request came from null =09at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSo= lrClient.java:643) =09at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClie= nt.java:255) =09at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClie= nt.java:244) =09at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSo= lrClient.java:483) =09at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolr= Client.java:413) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate= $0(CloudSolrClient.java:527) =09at java.util.concurrent.FutureTask.run(FutureTask.java:266) =09at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.l= ambda$execute$0(ExecutorUtil.java:188) =09at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.= java:1149) =09at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor= .java:624) =09... 1 more Build Log: [...truncated 13589 lines...] [junit4] Suite: org.apache.solr.cloud.api.collections.CollectionsAPIDist= ributedZkTest [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-= Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.Collecti= onsAPIDistributedZkTest_2CE134CEA9AE2639-001/init-core-data-001 [junit4] 2> 2611127 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearche= rs: numOpens=3D19 numCloses=3D19 [junit4] 2> 2611127 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (N= UMERIC_POINTS_SYSPROP=3Dtrue) w/NUMERIC_DOCVALUES_SYSPROP=3Dtrue [junit4] 2> 2611129 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true= ) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=3D,= value=3DNaN, ssl=3DNaN, clientAuth=3DNaN) [junit4] 2> 2611130 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity = checks: test.solr.allowed.securerandom=3Dnull & java.security.egd=3Dfile:/d= ev/./urandom [junit4] 2> 2611130 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting clu= ster of 4 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/bui= ld/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistribu= tedZkTest_2CE134CEA9AE2639-001/tempDir-001 [junit4] 2> 2611131 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SER= VER [junit4] 2> 2611131 INFO (Thread-13001) [ ] o.a.s.c.ZkTestServer c= lient port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2611131 INFO (Thread-13001) [ ] o.a.s.c.ZkTestServer S= tarting server [junit4] 2> 2611132 ERROR (Thread-13001) [ ] o.a.z.s.ZooKeeperServe= r ZKShutdownHandler is not registered, so ZooKeeper server won't take any a= ction on ERROR or SHUTDOWN server state changes [junit4] 2> 2611231 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.c.ZkTestServer start zk server on p= ort:43569 [junit4] 2> 2611234 INFO (zkConnectionManagerCallback-10314-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611258 INFO (jetty-launcher-10311-thread-1) [ ] o.e.j= .s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00= , git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2611258 INFO (jetty-launcher-10311-thread-4) [ ] o.e.j= .s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00= , git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2611258 INFO (jetty-launcher-10311-thread-2) [ ] o.e.j= .s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00= , git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2611258 INFO (jetty-launcher-10311-thread-3) [ ] o.e.j= .s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00= , git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2611266 INFO (jetty-launcher-10311-thread-4) [ ] o.e.j= .s.session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 2611266 INFO (jetty-launcher-10311-thread-4) [ ] o.e.j= .s.session No SessionScavenger set, using defaults [junit4] 2> 2611266 INFO (jetty-launcher-10311-thread-4) [ ] o.e.j= .s.session Scavenging every 600000ms [junit4] 2> 2611273 INFO (jetty-launcher-10311-thread-4) [ ] o.e.j= .s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5447a434{/solr,nu= ll,AVAILABLE} [junit4] 2> 2611278 INFO (jetty-launcher-10311-thread-2) [ ] o.e.j= .s.session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 2611278 INFO (jetty-launcher-10311-thread-1) [ ] o.e.j= .s.session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 2611278 INFO (jetty-launcher-10311-thread-2) [ ] o.e.j= .s.session No SessionScavenger set, using defaults [junit4] 2> 2611278 INFO (jetty-launcher-10311-thread-1) [ ] o.e.j= .s.session No SessionScavenger set, using defaults [junit4] 2> 2611278 INFO (jetty-launcher-10311-thread-2) [ ] o.e.j= .s.session Scavenging every 600000ms [junit4] 2> 2611278 INFO (jetty-launcher-10311-thread-1) [ ] o.e.j= .s.session Scavenging every 600000ms [junit4] 2> 2611278 INFO (jetty-launcher-10311-thread-4) [ ] o.e.j= .s.AbstractConnector Started ServerConnector@7e8c5f00{SSL,[ssl, http/1.1]}{= 127.0.0.1:36101} [junit4] 2> 2611278 INFO (jetty-launcher-10311-thread-4) [ ] o.e.j= .s.Server Started @2613112ms [junit4] 2> 2611278 INFO (jetty-launcher-10311-thread-4) [ ] o.a.s= .c.s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D3= 6101} [junit4] 2> 2611279 ERROR (jetty-launcher-10311-thread-4) [ ] o.a.s= .u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be mis= sing or incomplete. [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-1) [ ] o.e.j= .s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3a6875c1{/solr,nu= ll,AVAILABLE} [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-4) [ ] o.a.s= .s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3= .0 [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-2) [ ] o.e.j= .s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3d5e31cb{/solr,nu= ll,AVAILABLE} [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-4) [ ] o.a.s= .s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-3) [ ] o.e.j= .s.session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-3) [ ] o.e.j= .s.session No SessionScavenger set, using defaults [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-4) [ ] o.a.s= .s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-3) [ ] o.e.j= .s.session Scavenging every 660000ms [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-4) [ ] o.a.s= .s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-17T23:54:13.814= Z [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-1) [ ] o.e.j= .s.AbstractConnector Started ServerConnector@38f4a760{SSL,[ssl, http/1.1]}{= 127.0.0.1:42661} [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-1) [ ] o.e.j= .s.Server Started @2613113ms [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-2) [ ] o.e.j= .s.AbstractConnector Started ServerConnector@423b9d2b{SSL,[ssl, http/1.1]}{= 127.0.0.1:44823} [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-1) [ ] o.a.s= .c.s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D4= 2661} [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-2) [ ] o.e.j= .s.Server Started @2613113ms [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-3) [ ] o.e.j= .s.h.ContextHandler Started o.e.j.s.ServletContextHandler@67fc69bd{/solr,nu= ll,AVAILABLE} [junit4] 2> 2611279 INFO (jetty-launcher-10311-thread-2) [ ] o.a.s= .c.s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D4= 4823} [junit4] 2> 2611280 ERROR (jetty-launcher-10311-thread-1) [ ] o.a.s= .u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be mis= sing or incomplete. [junit4] 2> 2611280 ERROR (jetty-launcher-10311-thread-2) [ ] o.a.s= .u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be mis= sing or incomplete. [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-1) [ ] o.a.s= .s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3= .0 [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-2) [ ] o.a.s= .s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3= .0 [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-3) [ ] o.e.j= .s.AbstractConnector Started ServerConnector@f9a70a6{SSL,[ssl, http/1.1]}{1= 27.0.0.1:43157} [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-2) [ ] o.a.s= .s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-3) [ ] o.e.j= .s.Server Started @2613114ms [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-2) [ ] o.a.s= .s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-1) [ ] o.a.s= .s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-1) [ ] o.a.s= .s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-1) [ ] o.a.s= .s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-17T23:54:13.815= Z [junit4] 2> 2611280 INFO (zkConnectionManagerCallback-10316-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-2) [ ] o.a.s= .s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-17T23:54:13.815= Z [junit4] 2> 2611280 INFO (jetty-launcher-10311-thread-3) [ ] o.a.s= .c.s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D4= 3157} [junit4] 2> 2611281 ERROR (jetty-launcher-10311-thread-3) [ ] o.a.s= .u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be mis= sing or incomplete. [junit4] 2> 2611281 INFO (jetty-launcher-10311-thread-3) [ ] o.a.s= .s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3= .0 [junit4] 2> 2611281 INFO (jetty-launcher-10311-thread-4) [ ] o.a.s= .s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2611281 INFO (jetty-launcher-10311-thread-3) [ ] o.a.s= .s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2611281 INFO (jetty-launcher-10311-thread-3) [ ] o.a.s= .s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2611281 INFO (jetty-launcher-10311-thread-3) [ ] o.a.s= .s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-17T23:54:13.816= Z [junit4] 2> 2611282 INFO (zkConnectionManagerCallback-10318-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611283 INFO (jetty-launcher-10311-thread-1) [ ] o.a.s= .s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2611284 INFO (jetty-launcher-10311-thread-4) [ ] o.a.s= .c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay i= s ignored [junit4] 2> 2611284 INFO (jetty-launcher-10311-thread-4) [ ] o.a.s= .c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpirati= on is ignored [junit4] 2> 2611284 INFO (zkConnectionManagerCallback-10322-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611284 INFO (jetty-launcher-10311-thread-1) [ ] o.a.s= .c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay i= s ignored [junit4] 2> 2611284 INFO (jetty-launcher-10311-thread-1) [ ] o.a.s= .c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpirati= on is ignored [junit4] 2> 2611285 INFO (jetty-launcher-10311-thread-3) [ ] o.a.s= .s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2611287 INFO (zkConnectionManagerCallback-10320-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611287 INFO (jetty-launcher-10311-thread-3) [ ] o.a.s= .c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay i= s ignored [junit4] 2> 2611287 INFO (jetty-launcher-10311-thread-3) [ ] o.a.s= .c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpirati= on is ignored [junit4] 2> 2611287 INFO (jetty-launcher-10311-thread-2) [ ] o.a.s= .s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2611287 INFO (jetty-launcher-10311-thread-4) [ ] o.a.s= .c.ZkContainer Zookeeper client=3D127.0.0.1:43569/solr [junit4] 2> 2611288 INFO (jetty-launcher-10311-thread-1) [ ] o.a.s= .c.ZkContainer Zookeeper client=3D127.0.0.1:43569/solr [junit4] 2> 2611288 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 0x161068b63230003, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 2611289 INFO (jetty-launcher-10311-thread-2) [ ] o.a.s= .c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay i= s ignored [junit4] 2> 2611289 INFO (jetty-launcher-10311-thread-2) [ ] o.a.s= .c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpirati= on is ignored [junit4] 2> 2611290 INFO (zkConnectionManagerCallback-10330-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611290 INFO (zkConnectionManagerCallback-10327-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611291 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 0x161068b63230006, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 2611294 INFO (zkConnectionManagerCallback-10332-thread-1-= processing-n:127.0.0.1:36101_solr) [n:127.0.0.1:36101_solr ] o.a.s.c.c.C= onnectionManager zkClient has connected [junit4] 2> 2611294 INFO (jetty-launcher-10311-thread-3) [ ] o.a.s= .c.ZkContainer Zookeeper client=3D127.0.0.1:43569/solr [junit4] 2> 2611294 INFO (zkConnectionManagerCallback-10335-thread-1-= processing-n:127.0.0.1:42661_solr) [n:127.0.0.1:42661_solr ] o.a.s.c.c.C= onnectionManager zkClient has connected [junit4] 2> 2611295 INFO (jetty-launcher-10311-thread-2) [ ] o.a.s= .c.ZkContainer Zookeeper client=3D127.0.0.1:43569/solr [junit4] 2> 2611298 INFO (zkConnectionManagerCallback-10339-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611298 INFO (zkConnectionManagerCallback-10342-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611299 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 0x161068b6323000a, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 2611302 INFO (zkConnectionManagerCallback-10346-thread-1-= processing-n:127.0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.C= onnectionManager zkClient has connected [junit4] 2> 2611302 INFO (zkConnectionManagerCallback-10348-thread-1-= processing-n:127.0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.C= onnectionManager zkClient has connected [junit4] 2> 2611316 INFO (jetty-launcher-10311-thread-2) [n:127.0.0.1= :44823_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 2611316 INFO (jetty-launcher-10311-thread-3) [n:127.0.0.1= :43157_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 2611316 INFO (jetty-launcher-10311-thread-2) [n:127.0.0.1= :44823_solr ] o.a.s.c.OverseerElectionContext I am going to be the leade= r 127.0.0.1:44823_solr [junit4] 2> 2611316 INFO (jetty-launcher-10311-thread-3) [n:127.0.0.1= :43157_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/l= ive_nodes/127.0.0.1:43157_solr [junit4] 2> 2611316 INFO (jetty-launcher-10311-thread-2) [n:127.0.0.1= :44823_solr ] o.a.s.c.Overseer Overseer (id=3D99367862512320524-127.0.0.= 1:44823_solr-n_0000000000) starting [junit4] 2> 2611318 INFO (zkCallback-10345-thread-1-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2611319 INFO (zkCallback-10347-thread-1-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2611335 INFO (jetty-launcher-10311-thread-2) [n:127.0.0.1= :44823_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/l= ive_nodes/127.0.0.1:44823_solr [junit4] 2> 2611335 INFO (zkCallback-10345-thread-1-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2611335 INFO (zkCallback-10347-thread-1-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2611336 INFO (jetty-launcher-10311-thread-1) [n:127.0.0.1= :42661_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper.= .. (0) -> (2) [junit4] 2> 2611336 INFO (jetty-launcher-10311-thread-4) [n:127.0.0.1= :36101_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper.= .. (0) -> (2) [junit4] 2> 2611337 INFO (jetty-launcher-10311-thread-1) [n:127.0.0.1= :42661_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 2611337 INFO (jetty-launcher-10311-thread-4) [n:127.0.0.1= :36101_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 2611337 INFO (jetty-launcher-10311-thread-1) [n:127.0.0.1= :42661_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/l= ive_nodes/127.0.0.1:42661_solr [junit4] 2> 2611338 INFO (jetty-launcher-10311-thread-4) [n:127.0.0.1= :36101_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/l= ive_nodes/127.0.0.1:36101_solr [junit4] 2> 2611338 INFO (zkCallback-10347-thread-1-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2611338 INFO (zkCallback-10345-thread-1-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2611342 INFO (zkCallback-10347-thread-1-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2611342 INFO (zkCallback-10345-thread-1-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2611354 INFO (zkCallback-10334-thread-1-processing-n:127.= 0.0.1:42661_solr) [n:127.0.0.1:42661_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 2611359 INFO (zkCallback-10331-thread-1-processing-n:127.= 0.0.1:36101_solr) [n:127.0.0.1:36101_solr ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 2611373 INFO (jetty-launcher-10311-thread-2) [n:127.0.0.1= :44823_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (= registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanSe= rver@66395a59 [junit4] 2> 2611378 INFO (jetty-launcher-10311-thread-2) [n:127.0.0.1= :44823_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (r= egistry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServ= er@66395a59 [junit4] 2> 2611378 INFO (jetty-launcher-10311-thread-2) [n:127.0.0.1= :44823_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' = (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBean= Server@66395a59 [junit4] 2> 2611378 INFO (jetty-launcher-10311-thread-2) [n:127.0.0.1= :44823_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions und= erneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/= test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_2CE= 134CEA9AE2639-001/tempDir-001/node2 [junit4] 2> 2611400 INFO (jetty-launcher-10311-thread-3) [n:127.0.0.1= :43157_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (= registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanSe= rver@66395a59 [junit4] 2> 2611405 INFO (jetty-launcher-10311-thread-4) [n:127.0.0.1= :36101_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (= registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanSe= rver@66395a59 [junit4] 2> 2611407 INFO (jetty-launcher-10311-thread-3) [n:127.0.0.1= :43157_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (r= egistry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServ= er@66395a59 [junit4] 2> 2611408 INFO (jetty-launcher-10311-thread-3) [n:127.0.0.1= :43157_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' = (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBean= Server@66395a59 [junit4] 2> 2611409 INFO (jetty-launcher-10311-thread-3) [n:127.0.0.1= :43157_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions und= erneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/= test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_2CE= 134CEA9AE2639-001/tempDir-001/node3 [junit4] 2> 2611410 INFO (jetty-launcher-10311-thread-4) [n:127.0.0.1= :36101_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (r= egistry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServ= er@66395a59 [junit4] 2> 2611410 INFO (jetty-launcher-10311-thread-4) [n:127.0.0.1= :36101_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' = (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBean= Server@66395a59 [junit4] 2> 2611411 INFO (jetty-launcher-10311-thread-4) [n:127.0.0.1= :36101_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions und= erneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/= test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_2CE= 134CEA9AE2639-001/tempDir-001/node4 [junit4] 2> 2611451 INFO (jetty-launcher-10311-thread-1) [n:127.0.0.1= :42661_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (= registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanSe= rver@66395a59 [junit4] 2> 2611456 INFO (jetty-launcher-10311-thread-1) [n:127.0.0.1= :42661_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (r= egistry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServ= er@66395a59 [junit4] 2> 2611456 INFO (jetty-launcher-10311-thread-1) [n:127.0.0.1= :42661_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' = (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBean= Server@66395a59 [junit4] 2> 2611457 INFO (jetty-launcher-10311-thread-1) [n:127.0.0.1= :42661_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions und= erneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/= test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_2CE= 134CEA9AE2639-001/tempDir-001/node1 [junit4] 2> 2611478 INFO (zkConnectionManagerCallback-10356-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611480 INFO (zkConnectionManagerCallback-10360-thread-1)= [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2611480 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live node= s from ZooKeeper... (0) -> (4) [junit4] 2> 2611481 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider = Cluster at 127.0.0.1:43569/solr ready [junit4] 2> 2611503 INFO (TEST-CollectionsAPIDistributedZkTest.delete= PartiallyCreatedCollection-seed#[2CE134CEA9AE2639]) [ ] o.a.s.SolrTestCa= seJ4 ###Starting deletePartiallyCreatedCollection [junit4] 2> 2611504 INFO (TEST-CollectionsAPIDistributedZkTest.delete= PartiallyCreatedCollection-seed#[2CE134CEA9AE2639]) [ ] o.a.s.c.c.ZkStat= eReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 2611516 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with = params replicationFactor=3D1&collection.configName=3Dconf&name=3Dhalfdelete= dcollection&nrtReplicas=3D1&action=3DCREATE&numShards=3D2&createNodeSet=3D&= wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 2611518 INFO (OverseerThreadFactory-9635-thread-1-process= ing-n:127.0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.a.c.Create= CollectionCmd Create collection halfdeletedcollection [junit4] 2> 2611518 WARN (OverseerThreadFactory-9635-thread-1-process= ing-n:127.0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.a.c.Create= CollectionCmd It is unusual to create a collection (halfdeletedcollection) = without cores. [junit4] 2> 2611623 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active fo= r at most 30 seconds. Check all shard replicas [junit4] 2> 2611624 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections= params=3D{replicationFactor=3D1&collection.configName=3Dconf&name=3Dhalfde= letedcollection&nrtReplicas=3D1&action=3DCREATE&numShards=3D2&createNodeSet= =3D&wt=3Djavabin&version=3D2} status=3D0 QTime=3D107 [junit4] 2> 2611626 INFO (qtp2123243170-38791) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica w= ith params dataDir=3D/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/bui= ld/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistribu= tedZkTest_2CE134CEA9AE2639-001/tempDir-002&action=3DADDREPLICA&collection= =3Dhalfdeletedcollection&shard=3Dshard1&type=3DNRT&wt=3Djavabin&version=3D2= and sendToOCPQueue=3Dtrue [junit4] 2> 2611629 INFO (OverseerCollectionConfigSetProcessor-993678= 62512320524-127.0.0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ]= o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-wor= k/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKe= eper [junit4] 2> 2611630 INFO (OverseerThreadFactory-9635-thread-2-process= ing-n:127.0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.a.c.AddRep= licaCmd Node Identified 127.0.0.1:36101_solr for creating new replica [junit4] 2> 2611632 INFO (OverseerStateUpdate-99367862512320524-127.0= .0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ] o.a.s.c.o.SliceM= utator createReplica() { [junit4] 2> "operation":"addreplica", [junit4] 2> "collection":"halfdeletedcollection", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"halfdeletedcollection_shard1_replica_n41", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:36101/solr", [junit4] 2> "node_name":"127.0.0.1:36101_solr", [junit4] 2> "type":"NRT"}=20 [junit4] 2> 2611846 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&c= oreNodeName=3Dcore_node42&dataDir=3D/home/jenkins/workspace/Lucene-Solr-7.x= -Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.Collect= ionsAPIDistributedZkTest_2CE134CEA9AE2639-001/tempDir-002&collection.config= Name=3Dconf&name=3Dhalfdeletedcollection_shard1_replica_n41&action=3DCREATE= &collection=3Dhalfdeletedcollection&shard=3Dshard1&wt=3Djavabin&version=3D2= &replicaType=3DNRT [junit4] 2> 2611846 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for= 2147483647 transient cores [junit4] 2> 2611853 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2611857 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica= _n41] Schema name=3Dminimal [junit4] 2> 2611859 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with unique= id field id [junit4] 2> 2611859 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcolle= ction_shard1_replica_n41' using configuration from collection halfdeletedco= llection, trusted=3Dtrue [junit4] 2> 2611859 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.h= alfdeletedcollection.shard1.replica_n41' (registry 'solr.core.halfdeletedco= llection.shard1.replica_n41') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@66395a59 [junit4] 2> 2611860 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2611860 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica_n= 41] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linu= x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsA= PIDistributedZkTest_2CE134CEA9AE2639-001/tempDir-001/node4/halfdeletedcolle= ction_shard1_replica_n41], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-7= .x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.Colle= ctionsAPIDistributedZkTest_2CE134CEA9AE2639-001/tempDir-002/] [junit4] 2> 2611898 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.u.UpdateHandler Using UpdateLog implementation: org= .apache.solr.update.UpdateLog [junit4] 2> 2611899 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3Dnull = defaultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVe= rsionBuckets=3D65536 [junit4] 2> 2611899 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2611899 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2611901 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.s.SolrIndexSearcher Opening [Searcher@cc6ddb4[halfd= eletedcollection_shard1_replica_n41] main] [junit4] 2> 2611901 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorag= eIO with znodeBase: /configs/conf [junit4] 2> 2611902 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_= managed.json using ZooKeeperStorageIO:path=3D/configs/conf [junit4] 2> 2611902 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.h.ReplicationHandler Commits will be reserved for 1= 0000ms. [junit4] 2> 2611903 INFO (searcherExecutor-9644-thread-1-processing-n= :127.0.0.1:36101_solr x:halfdeletedcollection_shard1_replica_n41 s:shard1 c= :halfdeletedcollection r:core_node42) [n:127.0.0.1:36101_solr c:halfdeleted= collection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n4= 1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica_n41] Registered n= ew searcher Searcher@cc6ddb4[halfdeletedcollection_shard1_replica_n41] main= {ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2611903 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.u.UpdateLog Could not find max version in index or = recent updates, using new clock 1589885801005580288 [junit4] 2> 2611906 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.ShardLeaderElectionContext Enough replicas found = to continue. [junit4] 2> 2611906 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.ShardLeaderElectionContext I may be the new leade= r - try and sync [junit4] 2> 2611906 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:3= 6101/solr/halfdeletedcollection_shard1_replica_n41/ [junit4] 2> 2611906 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.SyncStrategy Sync Success - now sync replicas to = me [junit4] 2> 2611906 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.SyncStrategy https://127.0.0.1:36101/solr/halfdel= etedcollection_shard1_replica_n41/ has no replicas [junit4] 2> 2611906 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.ShardLeaderElectionContext Found all replicas par= ticipating in election, clear LIR [junit4] 2> 2611907 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.ShardLeaderElectionContext I am the new leader: h= ttps://127.0.0.1:36101/solr/halfdeletedcollection_shard1_replica_n41/ shard= 1 [junit4] 2> 2612008 INFO (zkCallback-10331-thread-1-processing-n:127.= 0.0.1:36101_solr) [n:127.0.0.1:36101_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2612008 INFO (zkCallback-10331-thread-2-processing-n:127.= 0.0.1:36101_solr) [n:127.0.0.1:36101_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2612058 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.c.ZkController I am the leader, no recovery necessa= ry [junit4] 2> 2612160 INFO (zkCallback-10331-thread-1-processing-n:127.= 0.0.1:36101_solr) [n:127.0.0.1:36101_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2612160 INFO (zkCallback-10331-thread-2-processing-n:127.= 0.0.1:36101_solr) [n:127.0.0.1:36101_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2612220 INFO (qtp1067358686-38777) [n:127.0.0.1:36101_sol= r c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_sh= ard1_replica_n41] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/= cores params=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node42&dataDir=3D/hom= e/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp= /solr.cloud.api.collections.CollectionsAPIDistributedZkTest_2CE134CEA9AE263= 9-001/tempDir-002&collection.configName=3Dconf&name=3Dhalfdeletedcollection= _shard1_replica_n41&action=3DCREATE&collection=3Dhalfdeletedcollection&shar= d=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DNRT} status=3D0 QTime=3D3= 73 [junit4] 2> 2612222 INFO (qtp2123243170-38791) [n:127.0.0.1:43157_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections= params=3D{dataDir=3D/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/bui= ld/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistribu= tedZkTest_2CE134CEA9AE2639-001/tempDir-002&action=3DADDREPLICA&collection= =3Dhalfdeletedcollection&shard=3Dshard1&type=3DNRT&wt=3Djavabin&version=3D2= } status=3D0 QTime=3D596 [junit4] 2> 2612222 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with = params name=3Dhalfdeletedcollection&action=3DDELETE&wt=3Djavabin&version=3D= 2 and sendToOCPQueue=3Dtrue [junit4] 2> 2612223 INFO (OverseerCollectionConfigSetProcessor-993678= 62512320524-127.0.0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ]= o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-wor= k/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKe= eper [junit4] 2> 2612223 INFO (OverseerThreadFactory-9635-thread-3-process= ing-n:127.0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.a.c.Overse= erCollectionMessageHandler Executing Collection Cmd : action=3DUNLOAD&delet= eInstanceDir=3Dtrue&deleteDataDir=3Dtrue [junit4] 2> 2612224 INFO (qtp1067358686-38773) [n:127.0.0.1:36101_sol= r ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dso= lr.core.halfdeletedcollection.shard1.replica_n41, tag=3Dnull [junit4] 2> 2612225 INFO (qtp1067358686-38773) [n:127.0.0.1:36101_sol= r ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.= reporters.SolrJmxReporter@2f5a548f: rootName =3D null, domain =3D solr.core= .halfdeletedcollection.shard1.replica_n41, service url =3D null, agent id = =3D null] for registry solr.core.halfdeletedcollection.shard1.replica_n41 /= com.codahale.metrics.MetricRegistry@248a2ecb [junit4] 2> 2612231 INFO (qtp1067358686-38773) [n:127.0.0.1:36101_sol= r ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica_n41] CLOSING= SolrCore org.apache.solr.core.SolrCore@1496406e [junit4] 2> 2612231 INFO (qtp1067358686-38773) [n:127.0.0.1:36101_sol= r ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dso= lr.core.halfdeletedcollection.shard1.replica_n41, tag=3D345391214 [junit4] 2> 2612231 INFO (qtp1067358686-38773) [n:127.0.0.1:36101_sol= r ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dso= lr.collection.halfdeletedcollection.shard1.leader, tag=3D345391214 [junit4] 2> 2612233 INFO (qtp1067358686-38773) [n:127.0.0.1:36101_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores param= s=3D{deleteInstanceDir=3Dtrue&core=3Dhalfdeletedcollection_shard1_replica_n= 41&qt=3D/admin/cores&deleteDataDir=3Dtrue&action=3DUNLOAD&wt=3Djavabin&vers= ion=3D2} status=3D0 QTime=3D8 [junit4] 2> 2612936 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections= params=3D{name=3Dhalfdeletedcollection&action=3DDELETE&wt=3Djavabin&versio= n=3D2} status=3D0 QTime=3D714 [junit4] 2> 2612937 INFO (qtp2123243170-38791) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with pa= rams action=3DLIST&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 2612937 INFO (qtp2123243170-38791) [n:127.0.0.1:43157_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections= params=3D{action=3DLIST&wt=3Djavabin&version=3D2} status=3D0 QTime=3D0 [junit4] 2> 2612937 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with = params replicationFactor=3D1&collection.configName=3Dconf&name=3Dhalfdelete= dcollection&nrtReplicas=3D1&action=3DCREATE&numShards=3D2&wt=3Djavabin&vers= ion=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 2612939 INFO (OverseerThreadFactory-9635-thread-4-process= ing-n:127.0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.a.c.Create= CollectionCmd Create collection halfdeletedcollection [junit4] 2> 2612940 INFO (OverseerCollectionConfigSetProcessor-993678= 62512320524-127.0.0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ]= o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-wor= k/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKe= eper [junit4] 2> 2613147 INFO (OverseerStateUpdate-99367862512320524-127.0= .0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ] o.a.s.c.o.SliceM= utator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"halfdeletedcollection", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"halfdeletedcollection_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:44823/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 2613149 INFO (OverseerStateUpdate-99367862512320524-127.0= .0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ] o.a.s.c.o.SliceM= utator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"halfdeletedcollection", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"halfdeletedcollection_shard2_replica_n2", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:42661/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 2613377 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&c= oreNodeName=3Dcore_node4&collection.configName=3Dconf&newCollection=3Dtrue&= name=3Dhalfdeletedcollection_shard2_replica_n2&action=3DCREATE&numShards=3D= 2&collection=3Dhalfdeletedcollection&shard=3Dshard2&wt=3Djavabin&version=3D= 2&replicaType=3DNRT [junit4] 2> 2613377 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&co= reNodeName=3Dcore_node3&collection.configName=3Dconf&newCollection=3Dtrue&n= ame=3Dhalfdeletedcollection_shard1_replica_n1&action=3DCREATE&numShards=3D2= &collection=3Dhalfdeletedcollection&shard=3Dshard1&wt=3Djavabin&version=3D2= &replicaType=3DNRT [junit4] 2> 2613377 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for= 2147483647 transient cores [junit4] 2> 2613377 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for = 2147483647 transient cores [junit4] 2> 2613481 INFO (zkCallback-10347-thread-1-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2613481 INFO (zkCallback-10334-thread-1-processing-n:127.= 0.0.1:42661_solr) [n:127.0.0.1:42661_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2613482 INFO (zkCallback-10347-thread-2-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2613482 INFO (zkCallback-10334-thread-2-processing-n:127.= 0.0.1:42661_solr) [n:127.0.0.1:42661_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2614390 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2614390 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2614398 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.s.IndexSchema [halfdeletedcollection_shard2_replica_n= 2] Schema name=3Dminimal [junit4] 2> 2614398 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica_n1= ] Schema name=3Dminimal [junit4] 2> 2614416 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid= field id [junit4] 2> 2614416 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid = field id [junit4] 2> 2614416 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollect= ion_shard2_replica_n2' using configuration from collection halfdeletedcolle= ction, trusted=3Dtrue [junit4] 2> 2614416 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollecti= on_shard1_replica_n1' using configuration from collection halfdeletedcollec= tion, trusted=3Dtrue [junit4] 2> 2614416 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.hal= fdeletedcollection.shard2.replica_n2' (registry 'solr.core.halfdeletedcolle= ction.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBe= anServer@66395a59 [junit4] 2> 2614416 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.half= deletedcollection.shard1.replica_n1' (registry 'solr.core.halfdeletedcollec= tion.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBea= nServer@66395a59 [junit4] 2> 2614416 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2614416 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2614417 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.SolrCore [[halfdeletedcollection_shard2_replica_n2]= ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/s= olr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPID= istributedZkTest_2CE134CEA9AE2639-001/tempDir-001/node1/halfdeletedcollecti= on_shard2_replica_n2], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-7.x-L= inux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.Collectio= nsAPIDistributedZkTest_2CE134CEA9AE2639-001/tempDir-001/node1/halfdeletedco= llection_shard2_replica_n2/data/] [junit4] 2> 2614417 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica_n1] = ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/so= lr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDi= stributedZkTest_2CE134CEA9AE2639-001/tempDir-001/node2/halfdeletedcollectio= n_shard1_replica_n1], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-7.x-Li= nux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.Collection= sAPIDistributedZkTest_2CE134CEA9AE2639-001/tempDir-001/node2/halfdeletedcol= lection_shard1_replica_n1/data/] [junit4] 2> 2614444 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.ap= ache.solr.update.UpdateLog [junit4] 2> 2614444 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.a= pache.solr.update.UpdateLog [junit4] 2> 2614444 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3Dnull def= aultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersi= onBuckets=3D65536 [junit4] 2> 2614444 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3Dnull de= faultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVers= ionBuckets=3D65536 [junit4] 2> 2614445 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2614445 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2614445 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2614445 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2614446 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@5948adf[halfdel= etedcollection_shard2_replica_n2] main] [junit4] 2> 2614446 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@fd9bb2c[halfdele= tedcollection_shard1_replica_n1] main] [junit4] 2> 2614446 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageI= O with znodeBase: /configs/conf [junit4] 2> 2614446 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO= with znodeBase: /configs/conf [junit4] 2> 2614446 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_ma= naged.json using ZooKeeperStorageIO:path=3D/configs/conf [junit4] 2> 2614446 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_man= aged.json using ZooKeeperStorageIO:path=3D/configs/conf [junit4] 2> 2614447 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 100= 00ms. [junit4] 2> 2614447 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 1000= 0ms. [junit4] 2> 2614447 INFO (searcherExecutor-9649-thread-1-processing-n= :127.0.0.1:42661_solr x:halfdeletedcollection_shard2_replica_n2 s:shard2 c:= halfdeletedcollection r:core_node4) [n:127.0.0.1:42661_solr c:halfdeletedco= llection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o= .a.s.c.SolrCore [halfdeletedcollection_shard2_replica_n2] Registered new se= archer Searcher@5948adf[halfdeletedcollection_shard2_replica_n2] main{Exita= bleDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2614447 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or re= cent updates, using new clock 1589885803673157632 [junit4] 2> 2614447 INFO (searcherExecutor-9650-thread-1-processing-n= :127.0.0.1:44823_solr x:halfdeletedcollection_shard1_replica_n1 s:shard1 c:= halfdeletedcollection r:core_node3) [n:127.0.0.1:44823_solr c:halfdeletedco= llection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o= .a.s.c.SolrCore [halfdeletedcollection_shard1_replica_n1] Registered new se= archer Searcher@fd9bb2c[halfdeletedcollection_shard1_replica_n1] main{Exita= bleDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2614448 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or rec= ent updates, using new clock 1589885803674206208 [junit4] 2> 2614450 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to = continue. [junit4] 2> 2614450 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to= continue. [junit4] 2> 2614450 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader -= try and sync [junit4] 2> 2614450 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader = - try and sync [junit4] 2> 2614450 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:4482= 3/solr/halfdeletedcollection_shard1_replica_n1/ [junit4] 2> 2614450 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:426= 61/solr/halfdeletedcollection_shard2_replica_n2/ [junit4] 2> 2614450 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2614450 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2614450 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:44823/solr/halfdelete= dcollection_shard1_replica_n1/ has no replicas [junit4] 2> 2614450 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.SyncStrategy https://127.0.0.1:42661/solr/halfdelet= edcollection_shard2_replica_n2/ has no replicas [junit4] 2> 2614450 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas partic= ipating in election, clear LIR [junit4] 2> 2614450 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas parti= cipating in election, clear LIR [junit4] 2> 2614451 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: htt= ps://127.0.0.1:42661/solr/halfdeletedcollection_shard2_replica_n2/ shard2 [junit4] 2> 2614451 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http= s://127.0.0.1:44823/solr/halfdeletedcollection_shard1_replica_n1/ shard1 [junit4] 2> 2614553 INFO (zkCallback-10347-thread-2-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2614553 INFO (zkCallback-10347-thread-3-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2614553 INFO (zkCallback-10334-thread-2-processing-n:127.= 0.0.1:42661_solr) [n:127.0.0.1:42661_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2614553 INFO (zkCallback-10334-thread-1-processing-n:127.= 0.0.1:42661_solr) [n:127.0.0.1:42661_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2614602 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2614602 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2614628 INFO (qtp355850227-38787) [n:127.0.0.1:44823_solr= c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shar= d1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cor= es params=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node3&collection.configN= ame=3Dconf&newCollection=3Dtrue&name=3Dhalfdeletedcollection_shard1_replica= _n1&action=3DCREATE&numShards=3D2&collection=3Dhalfdeletedcollection&shard= =3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DNRT} status=3D0 QTime=3D12= 51 [junit4] 2> 2614633 INFO (qtp1823181727-38785) [n:127.0.0.1:42661_sol= r c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_sha= rd2_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/co= res params=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node4&collection.config= Name=3Dconf&newCollection=3Dtrue&name=3Dhalfdeletedcollection_shard2_replic= a_n2&action=3DCREATE&numShards=3D2&collection=3Dhalfdeletedcollection&shard= =3Dshard2&wt=3Djavabin&version=3D2&replicaType=3DNRT} status=3D0 QTime=3D12= 56 [junit4] 2> 2614635 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active fo= r at most 30 seconds. Check all shard replicas [junit4] 2> 2614705 INFO (zkCallback-10334-thread-2-processing-n:127.= 0.0.1:42661_solr) [n:127.0.0.1:42661_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2614705 INFO (zkCallback-10347-thread-2-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2614705 INFO (zkCallback-10347-thread-3-processing-n:127.= 0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2614705 INFO (zkCallback-10334-thread-1-processing-n:127.= 0.0.1:42661_solr) [n:127.0.0.1:42661_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/halfdeletedcollection/state.json] for collection [halfdel= etedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2614941 INFO (OverseerCollectionConfigSetProcessor-993678= 62512320524-127.0.0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ]= o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-wor= k/qnr-0000000006 doesn't exist. Requestor may have disconnected from ZooKe= eper [junit4] 2> 2615636 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections= params=3D{replicationFactor=3D1&collection.configName=3Dconf&name=3Dhalfde= letedcollection&nrtReplicas=3D1&action=3DCREATE&numShards=3D2&wt=3Djavabin&= version=3D2} status=3D0 QTime=3D2698 [junit4] 2> 2615637 INFO (qtp2123243170-38791) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with pa= rams action=3DLIST&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 2615637 INFO (qtp2123243170-38791) [n:127.0.0.1:43157_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections= params=3D{action=3DLIST&wt=3Djavabin&version=3D2} status=3D0 QTime=3D0 [junit4] 2> 2615638 INFO (TEST-CollectionsAPIDistributedZkTest.delete= PartiallyCreatedCollection-seed#[2CE134CEA9AE2639]) [ ] o.a.s.SolrTestCa= seJ4 ###Ending deletePartiallyCreatedCollection [junit4] 2> 2615698 INFO (TEST-CollectionsAPIDistributedZkTest.testSp= ecificConfigsets-seed#[2CE134CEA9AE2639]) [ ] o.a.s.SolrTestCaseJ4 ###St= arting testSpecificConfigsets [junit4] 2> 2615699 INFO (TEST-CollectionsAPIDistributedZkTest.testSp= ecificConfigsets-seed#[2CE134CEA9AE2639]) [ ] o.a.s.c.c.ZkStateReader Up= dated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 2615700 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with = params name=3Dhalfdeletedcollection&action=3DDELETE&wt=3Djavabin&version=3D= 2 and sendToOCPQueue=3Dtrue [junit4] 2> 2615701 INFO (OverseerThreadFactory-9635-thread-5-process= ing-n:127.0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.a.c.Overse= erCollectionMessageHandler Executing Collection Cmd : action=3DUNLOAD&delet= eInstanceDir=3Dtrue&deleteDataDir=3Dtrue [junit4] 2> 2615703 INFO (qtp1823181727-38781) [n:127.0.0.1:42661_sol= r ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dso= lr.core.halfdeletedcollection.shard2.replica_n2, tag=3Dnull [junit4] 2> 2615703 INFO (qtp355850227-38783) [n:127.0.0.1:44823_solr= ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dsol= r.core.halfdeletedcollection.shard1.replica_n1, tag=3Dnull [junit4] 2> 2615703 INFO (qtp1823181727-38781) [n:127.0.0.1:42661_sol= r ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.= reporters.SolrJmxReporter@621e8550: rootName =3D null, domain =3D solr.core= .halfdeletedcollection.shard2.replica_n2, service url =3D null, agent id = =3D null] for registry solr.core.halfdeletedcollection.shard2.replica_n2 / = com.codahale.metrics.MetricRegistry@280d60ab [junit4] 2> 2615703 INFO (qtp355850227-38783) [n:127.0.0.1:44823_solr= ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.r= eporters.SolrJmxReporter@4e2acf08: rootName =3D null, domain =3D solr.core.= halfdeletedcollection.shard1.replica_n1, service url =3D null, agent id =3D= null] for registry solr.core.halfdeletedcollection.shard1.replica_n1 / com= .codahale.metrics.MetricRegistry@15e729f9 [junit4] 2> 2615713 INFO (qtp355850227-38783) [n:127.0.0.1:44823_solr= ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica_n1] CLOSING S= olrCore org.apache.solr.core.SolrCore@4e8067fa [junit4] 2> 2615713 INFO (qtp355850227-38783) [n:127.0.0.1:44823_solr= ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dsol= r.core.halfdeletedcollection.shard1.replica_n1, tag=3D1317038074 [junit4] 2> 2615713 INFO (qtp355850227-38783) [n:127.0.0.1:44823_solr= ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dsol= r.collection.halfdeletedcollection.shard1.leader, tag=3D1317038074 [junit4] 2> 2615714 INFO (qtp1823181727-38781) [n:127.0.0.1:42661_sol= r ] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica_n2] CLOSING = SolrCore org.apache.solr.core.SolrCore@641f6e07 [junit4] 2> 2615714 INFO (qtp1823181727-38781) [n:127.0.0.1:42661_sol= r ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dso= lr.core.halfdeletedcollection.shard2.replica_n2, tag=3D1679781383 [junit4] 2> 2615714 INFO (qtp1823181727-38781) [n:127.0.0.1:42661_sol= r ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dso= lr.collection.halfdeletedcollection.shard2.leader, tag=3D1679781383 [junit4] 2> 2615716 INFO (qtp355850227-38783) [n:127.0.0.1:44823_solr= ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores params= =3D{deleteInstanceDir=3Dtrue&core=3Dhalfdeletedcollection_shard1_replica_n1= &qt=3D/admin/cores&deleteDataDir=3Dtrue&action=3DUNLOAD&wt=3Djavabin&versio= n=3D2} status=3D0 QTime=3D13 [junit4] 2> 2615716 INFO (qtp1823181727-38781) [n:127.0.0.1:42661_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores param= s=3D{deleteInstanceDir=3Dtrue&core=3Dhalfdeletedcollection_shard2_replica_n= 2&qt=3D/admin/cores&deleteDataDir=3Dtrue&action=3DUNLOAD&wt=3Djavabin&versi= on=3D2} status=3D0 QTime=3D14 [junit4] 2> 2616420 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections= params=3D{name=3Dhalfdeletedcollection&action=3DDELETE&wt=3Djavabin&versio= n=3D2} status=3D0 QTime=3D719 [junit4] 2> 2616421 INFO (qtp2123243170-38791) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with = params replicationFactor=3D1&collection.configName=3Dconf2&name=3Dwithconfi= gset2&nrtReplicas=3D1&action=3DCREATE&numShards=3D1&wt=3Djavabin&version=3D= 2 and sendToOCPQueue=3Dtrue [junit4] 2> 2616422 INFO (OverseerThreadFactory-9635-thread-5-process= ing-n:127.0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.a.c.Create= CollectionCmd Create collection withconfigset2 [junit4] 2> 2616422 INFO (OverseerCollectionConfigSetProcessor-993678= 62512320524-127.0.0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ]= o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-wor= k/qnr-0000000008 doesn't exist. Requestor may have disconnected from ZooKe= eper [junit4] 2> 2616629 INFO (OverseerStateUpdate-99367862512320524-127.0= .0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ] o.a.s.c.o.SliceM= utator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"withconfigset2", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"withconfigset2_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:43157/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 2616833 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&c= oreNodeName=3Dcore_node2&collection.configName=3Dconf2&newCollection=3Dtrue= &name=3Dwithconfigset2_shard1_replica_n1&action=3DCREATE&numShards=3D1&coll= ection=3Dwithconfigset2&shard=3Dshard1&wt=3Djavabin&version=3D2&replicaType= =3DNRT [junit4] 2> 2616834 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for= 2147483647 transient cores [junit4] 2> 2616939 INFO (zkCallback-10345-thread-1-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/withconfigset2/state.json] for collection [withconfigset2= ] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2616939 INFO (zkCallback-10345-thread-2-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/withconfigset2/state.json] for collection [withconfigset2= ] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2617848 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2617855 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.s.IndexSchema [withconfigset2_shard1_replica_n1] Schema name=3Dmini= mal [junit4] 2> 2617858 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2617859 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.CoreContainer Creating SolrCore 'withconfigset2_shard1_replica_n1= ' using configuration from collection withconfigset2, trusted=3Dtrue [junit4] 2> 2617859 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.withconfigset2.sh= ard1.replica_n1' (registry 'solr.core.withconfigset2.shard1.replica_n1') en= abled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@66395a59 [junit4] 2> 2617859 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2617859 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.SolrCore [[withconfigset2_shard1_replica_n1] ] Opening new SolrCo= re at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/t= est/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_2CE1= 34CEA9AE2639-001/tempDir-001/node3/withconfigset2_shard1_replica_n1], dataD= ir=3D[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/te= st/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_2CE13= 4CEA9AE2639-001/tempDir-001/node3/withconfigset2_shard1_replica_n1/data/] [junit4] 2> 2617920 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.upd= ate.UpdateLog [junit4] 2> 2617920 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3Dnull defaultSyncLevel= =3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D6= 5536 [junit4] 2> 2617921 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2617921 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2617921 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.s.SolrIndexSearcher Opening [Searcher@17ccc9c0[withconfigset2_shard= 1_replica_n1] main] [junit4] 2> 2617922 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBa= se: /configs/conf2 [junit4] 2> 2617922 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json usi= ng ZooKeeperStorageIO:path=3D/configs/conf2 [junit4] 2> 2617923 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2617923 INFO (searcherExecutor-9659-thread-1-processing-n= :127.0.0.1:43157_solr x:withconfigset2_shard1_replica_n1 s:shard1 c:withcon= figset2 r:core_node2) [n:127.0.0.1:43157_solr c:withconfigset2 s:shard1 r:c= ore_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.SolrCore [withconfigs= et2_shard1_replica_n1] Registered new searcher Searcher@17ccc9c0[withconfig= set2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryRe= ader())} [junit4] 2> 2617923 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, = using new clock 1589885807318007808 [junit4] 2> 2617926 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2617926 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2617926 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:43157/solr/withco= nfigset2_shard1_replica_n1/ [junit4] 2> 2617927 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2617927 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.SyncStrategy https://127.0.0.1:43157/solr/withconfigset2_shard1_r= eplica_n1/ has no replicas [junit4] 2> 2617927 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in el= ection, clear LIR [junit4] 2> 2617927 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1= :43157/solr/withconfigset2_shard1_replica_n1/ shard1 [junit4] 2> 2618029 INFO (zkCallback-10345-thread-1-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/withconfigset2/state.json] for collection [withconfigset2= ] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2618029 INFO (zkCallback-10345-thread-2-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/withconfigset2/state.json] for collection [withconfigset2= ] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2618078 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2618113 INFO (qtp2123243170-38788) [n:127.0.0.1:43157_sol= r c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1= ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores params=3D{= qt=3D/admin/cores&coreNodeName=3Dcore_node2&collection.configName=3Dconf2&n= ewCollection=3Dtrue&name=3Dwithconfigset2_shard1_replica_n1&action=3DCREATE= &numShards=3D1&collection=3Dwithconfigset2&shard=3Dshard1&wt=3Djavabin&vers= ion=3D2&replicaType=3DNRT} status=3D0 QTime=3D1279 [junit4] 2> 2618115 INFO (qtp2123243170-38791) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active fo= r at most 30 seconds. Check all shard replicas [junit4] 2> 2618181 INFO (zkCallback-10345-thread-2-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/withconfigset2/state.json] for collection [withconfigset2= ] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2618181 INFO (zkCallback-10345-thread-1-processing-n:127.= 0.0.1:43157_solr) [n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader A cl= uster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged = path:/collections/withconfigset2/state.json] for collection [withconfigset2= ] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2618424 INFO (OverseerCollectionConfigSetProcessor-993678= 62512320524-127.0.0.1:44823_solr-n_0000000000) [n:127.0.0.1:44823_solr ]= o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-wor= k/qnr-0000000010 doesn't exist. Requestor may have disconnected from ZooKe= eper [junit4] 2> 2619116 INFO (qtp2123243170-38791) [n:127.0.0.1:43157_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections= params=3D{replicationFactor=3D1&collection.configName=3Dconf2&name=3Dwithc= onfigset2&nrtReplicas=3D1&action=3DCREATE&numShards=3D1&wt=3Djavabin&versio= n=3D2} status=3D0 QTime=3D2695 [junit4] 2> 2619117 INFO (TEST-CollectionsAPIDistributedZkTest.testSp= ecificConfigsets-seed#[2CE134CEA9AE2639]) [ ] o.a.s.SolrTestCaseJ4 ###En= ding testSpecificConfigsets [junit4] 2> 2619174 INFO (TEST-CollectionsAPIDistributedZkTest.testZe= roNumShards-seed#[2CE134CEA9AE2639]) [ ] o.a.s.SolrTestCaseJ4 ###Startin= g testZeroNumShards [junit4] 2> 2619174 INFO (TEST-CollectionsAPIDistributedZkTest.testZe= roNumShards-seed#[2CE134CEA9AE2639]) [ ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 2619175 INFO (qtp2123243170-38784) [n:127.0.0.1:43157_sol= r ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with = params name=3Dwithconfigset2&action=3DDELETE&wt=3Djavabin&version=3D2 and s= endToOCPQueue=3Dtrue [junit4] 2> 2619176 INFO (OverseerThreadFactory-9635-thread-5-process= ing-n:127.0.0.1:44823_solr) [n:127.0.0.1:44823_solr ] o.a.s.c.a.c.Overse= erCollectionMessageHandler Executing Collection Cmd : action=3DUNLOAD&delet= eInstanceDir=3Dtrue&deleteDataDir=3Dtrue [junit4] 2> 2619176 INFO (qtp2123243170-38762) [n:127.0.0.1:43157_sol= r ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dso= lr.core.wit [...truncated too long message...] pse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.j= ava:279) [junit4] 2> =09at org.eclipse.jetty.io.FillInterest.fillable(FillInter= est.java:102) [junit4] 2> =09at org.eclipse.jetty.io.ssl.SslConnection.onFillable(Ss= lConnection.java:289) [junit4] 2> =09at org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(S= slConnection.java:149) [junit4] 2> =09at org.eclipse.jetty.io.FillInterest.fillable(FillInter= est.java:102) [junit4] 2> =09at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEn= dPoint.java:124) [junit4] 2> =09at org.eclipse.jetty.util.thread.strategy.EatWhatYouKil= l.doProduce(EatWhatYouKill.java:247) [junit4] 2> =09at org.eclipse.jetty.util.thread.strategy.EatWhatYouKil= l.produce(EatWhatYouKill.java:140) [junit4] 2> =09at org.eclipse.jetty.util.thread.strategy.EatWhatYouKil= l.run(EatWhatYouKill.java:131) [junit4] 2> =09at org.eclipse.jetty.util.thread.ReservedThreadExecutor= $ReservedThread.run(ReservedThreadExecutor.java:382) [junit4] 2> =09at org.eclipse.jetty.util.thread.QueuedThreadPool.runJo= b(QueuedThreadPool.java:708) [junit4] 2> =09at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run= (QueuedThreadPool.java:626) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2>=20 [junit4] 2> 2716373 INFO (qtp1067358686-38773) [n:127.0.0.1:36101_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores param= s=3D{nodeName=3D127.0.0.1:43157_solr&onlyIfLeaderActive=3Dtrue&core=3DaddRe= plicaColl_shard1_replica_n2&coreNodeName=3Dcore_node13&action=3DPREPRECOVER= Y&checkLive=3Dtrue&state=3Drecovering&onlyIfLeader=3Dtrue&wt=3Djavabin&vers= ion=3D2} status=3D400 QTime=3D8033 [junit4] 2> 2716373 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler= is not registered, so ZooKeeper server won't take any action on ERROR or S= HUTDOWN server state changes [junit4] 2> 2716374 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#= [2CE134CEA9AE2639]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.= 0.1:43569 43569 [junit4] 2> 2721510 INFO (Thread-13053) [ ] o.a.s.c.ZkTestServer c= onnecting to 127.0.0.1:43569 43569 [junit4] 2> 2721511 WARN (Thread-13053) [ ] o.a.s.c.ZkTestServer W= atch limit violations:=20 [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2>=20 [junit4] 2> =0913=09/solr/aliases.json [junit4] 2> =0913=09/solr/configs/conf [junit4] 2>=20 [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2>=20 [junit4] 2> =0955=09/solr/collections/addReplicaColl/state.json [junit4] 2> =0939=09/solr/collections/nodes_used_collection/state.json [junit4] 2> =0913=09/solr/collections/onlyinzk/state.json [junit4] 2> =0913=09/solr/clusterprops.json [junit4] 2> =0913=09/solr/clusterstate.json [junit4] 2> =095=09/solr/collections/halfcollectionblocker/state.json [junit4] 2> =095=09/solr/collections/created_and_deleted/state.json [junit4] 2> =095=09/solr/collections/halfcollectionblocker2/state.json [junit4] 2> =094=09/solr/collections/halfcollection/state.json [junit4] 2> =092=09/solr/collections/awhollynewcollection_0/state.json [junit4] 2>=20 [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2>=20 [junit4] 2> =09236=09/solr/collections [junit4] 2> =0913=09/solr/live_nodes [junit4] 2>=20 [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/wo= rkspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.= api.collections.CollectionsAPIDistributedZkTest_2CE134CEA9AE2639-001 [junit4] 2> NOTE: test params are: codec=3DAsserting(Lucene70): {id=3D= PostingsFormat(name=3DLuceneFixedGap)}, docValues:{_version_=3DDocValuesFor= mat(name=3DMemory)}, maxPointsInLeafNode=3D482, maxMBSortInHeap=3D7.3704073= 11309299, sim=3DRandomSimilarity(queryNorm=3Dtrue): {}, locale=3Dund, timez= one=3DAmerica/Merida [junit4] 2> NOTE: Linux 4.13.0-26-generic amd64/Oracle Corporation 1.8= .0_144 (64-bit)/cpus=3D8,threads=3D1,free=3D173711864,total=3D505937920 [junit4] 2> NOTE: All tests run in this JVM: [TestDocumentBuilder, Tes= tHighlightDedupGrouping, DocumentAnalysisRequestHandlerTest, TestDistribIDF= , TestCloudDeleteByQuery, DefaultValueUpdateProcessorTest, TestMaxTokenLenT= okenizer, TestOmitPositions, TestHashQParserPlugin, TestOnReconnectListener= Support, SubstringBytesRefFilterTest, DistributedFacetPivotSmallAdvancedTes= t, AutoScalingHandlerTest, TestWriterPerf, CoreAdminRequestStatusTest, Test= NestedDocsSort, DistributedQueryElevationComponentTest, TestStressLucene, D= istributedFacetSimpleRefinementLongTailTest, TestComponentsName, TestBinary= Field, TestFieldCollectionResource, MoveReplicaTest, UpdateLogTest, TestHtt= pShardHandlerFactory, TestSQLHandler, TestManagedSynonymGraphFilterFactory,= TestSegmentSorting, PreAnalyzedFieldManagedSchemaCloudTest, TestStressLive= Nodes, TestJsonRequest, TestPhraseSuggestions, TestSolrQueryResponse, TestR= eplicationHandlerBackup, TestHashPartitioner, TestSolrConfigHandlerConcurre= nt, TestFieldCache, JSONWriterTest, TestMaxScoreQueryParser, TestFastOutput= Stream, UpdateParamsTest, CdcrReplicationHandlerTest, TestQuerySenderNoQuer= y, TestInitParams, TestSimDistributedQueue, TestNodeAddedTrigger, TestConfi= gSets, OverseerTaskQueueTest, SolrMetricsIntegrationTest, TestExecutePlanAc= tion, TestConfigOverlay, TestPointFields, RestartWhileUpdatingTest, StatsCo= mponentTest, ZkSolrClientTest, ChangedSchemaMergeTest, SortSpecParsingTest,= BadIndexSchemaTest, TestIBSimilarityFactory, TestTolerantUpdateProcessorRa= ndomCloud, ShufflingReplicaListTransformerTest, BlockJoinFacetSimpleTest, S= patialRPTFieldTypeTest, CheckHdfsIndexTest, FacetPivotSmallTest, JavabinLoa= derTest, SystemLogListenerTest, DeleteReplicaTest, TestClassicSimilarityFac= tory, TestCopyFieldCollectionResource, TestStreamBody, TestCollationField, = AtomicUpdateProcessorFactoryTest, UUIDFieldTest, TestIndexingPerformance, B= itVectorTest, DocValuesMissingTest, PluginInfoTest, PreAnalyzedUpdateProces= sorTest, TestCloudSearcherWarming, TestSolrFieldCacheBean, RequestHandlersT= est, TestConfigReload, NodeAddedTriggerTest, SpellCheckCollatorTest, SolrPl= uginUtilsTest, SolrCoreMetricManagerTest, ForceLeaderTest, TestLuceneIndexB= ackCompat, CoreSorterTest, TestNamedUpdateProcessors, AnalyticsQueryTest, F= ieldAnalysisRequestHandlerTest, SolrIndexConfigTest, TestSolrCLIRunExample,= TestGroupingSearch, TestRandomFaceting, DistributedFacetExistsSmallTest, T= estPseudoReturnFields, ConfigSetsAPITest, CdcrBidirectionalTest, Classifica= tionUpdateProcessorIntegrationTest, TestUniqueKeyFieldResource, TestRemoteS= treaming, CdcrUpdateLogTest, SimpleFacetsTest, TestSolrXml, TestComplexPhra= seLeadingWildcard, TestExtendedDismaxParser, HdfsChaosMonkeySafeLeaderTest,= DebugComponentTest, MBeansHandlerTest, LeaderFailoverAfterPartitionTest, E= xternalFileFieldSortTest, HdfsBasicDistributedZk2Test, TestPullReplicaError= Handling, TestSubQueryTransformerCrossCore, TestHdfsUpdateLog, TestTrieFace= t, TestClusterStateProvider, OpenCloseCoreStressTest, MetricsHandlerTest, T= ermVectorComponentDistributedTest, TestSolrQueryParser, CloudExitableDirect= oryReaderTest, ShardRoutingTest, BasicZkTest, FullSolrCloudDistribCmdsTest,= TestReplicationHandler, TestRandomDVFaceting, ZkCLITest, BasicFunctionalit= yTest, TestLazyCores, SolrIndexSplitterTest, TestCoreDiscovery, SuggesterFS= TTest, CoreAdminHandlerTest, SolrRequestParserTest, TestFoldingMultitermQue= ry, SuggesterTest, SpatialFilterTest, SuggesterWFSTTest, TestCSVLoader, Sch= emaVersionSpecificBehaviorTest, SolrCoreCheckLockOnStartupTest, TestAtomicU= pdateErrorCases, TestWordDelimiterFilterFactory, QueryEqualityTest, Statele= ssScriptUpdateProcessorFactoryTest, DocValuesMultiTest, TestSolrDeletionPol= icy1, SolrInfoBeanTest, XsltUpdateRequestHandlerTest, CacheHeaderTest, Inde= xBasedSpellCheckerTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, = DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, TestQueryTyp= es, PrimitiveFieldTypeTest, XmlUpdateRequestHandlerTest, DocumentBuilderTes= t, TestValueSourceCache, PathHierarchyTokenizerFactoryTest, IndexSchemaRunt= imeFieldTest, TestJmxIntegration, ReturnFieldsTest, UpdateRequestProcessorF= actoryTest, TestCSVResponseWriter, TestAnalyzedSuggestions, JsonLoaderTest,= BinaryUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, SearchHan= dlerTest, HighlighterConfigTest, TestQuerySenderListener, AlternateDirector= yTest, TestSolrIndexConfig, TestStressRecovery, TestMergePolicyConfig, Samp= leTest, TestDocSet, NumericFieldsTest, MinimalSchemaTest, TestConfig, Outpu= tWriterTest, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, TestLucene= MatchVersion, SpellPossibilityIteratorTest, TestCodecSupport, SynonymTokeni= zerTest, EchoParamsTest, TestLMDirichletSimilarityFactory, TestLMJelinekMer= cerSimilarityFactory, TestBM25SimilarityFactory, TestFastWriter, OpenExchan= geRatesOrgProviderTest, TestFastLRUCache, ChaosMonkeyNothingIsSafeTest, Ass= ignBackwardCompatibilityTest, ChaosMonkeySafeLeaderWithPullReplicasTest, Co= llectionStateFormat2Test, CreateCollectionCleanupTest, DeleteInactiveReplic= aTest, DeleteNodeTest, DeleteShardTest, DistribCursorPagingTest, Distribute= dVersionInfoTest, LeaderElectionContextKeyTest, LeaderInitiatedRecoveryOnCo= mmitTest, LeaderInitiatedRecoveryOnShardRestartTest, LegacyCloudClusterProp= Test, MissingSegmentRecoveryTest, MoveReplicaHDFSTest, OutOfBoxZkACLAndCred= entialsProvidersTest, OverseerCollectionConfigSetProcessorTest, OverseerMod= ifyCollectionTest, OverseerStatusTest, PeerSyncReplicationTest, Replication= FactorTest, RollingRestartTest, SolrXmlInZkTest, TestClusterProperties, Tes= tConfigSetsAPI, TestRebalanceLeaders, TestSolrCloudWithDelegationTokens, Te= stSolrCloudWithSecureImpersonation, TestTolerantUpdateProcessorCloud, VMPar= amsZkACLAndCredentialsProvidersTest, AssignTest, CollectionTooManyReplicasT= est, CollectionsAPIAsyncDistributedZkTest, CollectionsAPIDistributedZkTest] [junit4] Completed [581/767 (1!)] on J0 in 110.40s, 19 tests, 1 error <<= < FAILURES! [...truncated 48870 lines...] ------=_Part_20_653194927.1516235540072 Content-Type: text/plain; charset=us-ascii --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org For additional commands, e-mail: dev-help@lucene.apache.org ------=_Part_20_653194927.1516235540072--