From dev-return-309263-archive-asf-public=cust-asf.ponee.io@lucene.apache.org Sun Jan 21 01:09:19 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 86B9E18066D for ; Sun, 21 Jan 2018 01:09:19 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 75EFE160C3B; Sun, 21 Jan 2018 00:09:19 +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 EEC19160C38 for ; Sun, 21 Jan 2018 01:09:16 +0100 (CET) Received: (qmail 87544 invoked by uid 500); 21 Jan 2018 00:09:15 -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 87534 invoked by uid 99); 21 Jan 2018 00:09:15 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd1-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Sun, 21 Jan 2018 00:09:15 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd1-us-west.apache.org (ASF Mail Server at spamd1-us-west.apache.org) with ESMTP id C25C0C2470 for ; Sun, 21 Jan 2018 00:09:14 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd1-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -0.05 X-Spam-Level: X-Spam-Status: No, score=-0.05 tagged_above=-999 required=6.31 tests=[KAM_BADIPHTTP=2, KAM_LOTSOFHASH=0.25, RCVD_IN_DNSWL_MED=-2.3, SPF_PASS=-0.001, WEIRD_PORT=0.001] autolearn=disabled Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd1-us-west.apache.org [10.40.0.7]) (amavisd-new, port 10024) with ESMTP id yRLjsT1zK-Ax for ; Sun, 21 Jan 2018 00:09:07 +0000 (UTC) Received: from serv1.sd-datasolutions.de (serv1.sd-datasolutions.de [88.99.242.108]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTP id C71A25F23E for ; Sun, 21 Jan 2018 00:09:06 +0000 (UTC) Received: from serv1 (ip6-localhost [IPv6:::1]) by serv1.sd-datasolutions.de (Postfix) with ESMTP id 07A9B108017D for ; Sun, 21 Jan 2018 00:09:06 +0000 (UTC) Date: Sun, 21 Jan 2018 00:07:37 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <1441587898.57.1516493346032.JavaMail.jenkins@serv1.sd-datasolutions.de> In-Reply-To: <56873691.45.1516448988577.JavaMail.jenkins@serv1.sd-datasolutions.de> References: <56873691.45.1516448988577.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-master-Windows (64bit/jdk-9.0.1) - Build # 7126 - Still Unstable! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_56_1491971523.1516493345997" X-Jenkins-Job: Lucene-Solr-master-Windows X-Jenkins-Result: UNSTABLE ------=_Part_56_1491971523.1516493345997 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/7126/ Java: 64bit/jdk-9.0.1 -XX:-UseCompressedOops -XX:+UseSerialGC 3 tests failed. FAILED: junit.framework.TestSuite.org.apache.solr.search.join.TestCloudNes= tedDocsSort Error Message: 1 thread leaked from SUITE scope at org.apache.solr.search.join.TestCloudNe= stedDocsSort: 1) Thread[id=3D2931, name=3Dqtp1327657358-2931, state=3DT= IMED_WAITING, group=3DTGRP-TestCloudNestedDocsSort] at java.base@9.= 0.1/jdk.internal.misc.Unsafe.park(Native Method) at java.base@9.0.1= /java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) = at java.base@9.0.1/java.util.concurrent.locks.AbstractQueuedSynchroniz= er$ConditionObject.await(AbstractQueuedSynchronizer.java:2192) at a= pp//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.res= ervedWait(ReservedThreadExecutor.java:308) at app//org.eclipse.jett= y.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecu= tor.java:373) at app//org.eclipse.jetty.util.thread.QueuedThreadPoo= l.runJob(QueuedThreadPool.java:708) at app//org.eclipse.jetty.util.= thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626) at java.ba= se@9.0.1/java.lang.Thread.run(Thread.java:844) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SU= ITE scope at org.apache.solr.search.join.TestCloudNestedDocsSort:=20 1) Thread[id=3D2931, name=3Dqtp1327657358-2931, state=3DTIMED_WAITING, g= roup=3DTGRP-TestCloudNestedDocsSort] at java.base@9.0.1/jdk.internal.misc.Unsafe.park(Native Method) at java.base@9.0.1/java.util.concurrent.locks.LockSupport.parkNanos= (LockSupport.java:234) at java.base@9.0.1/java.util.concurrent.locks.AbstractQueuedSynchro= nizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192) at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$Reserv= edThread.reservedWait(ReservedThreadExecutor.java:308) at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$Reserv= edThread.run(ReservedThreadExecutor.java:373) at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(Queue= dThreadPool.java:708) at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(Queued= ThreadPool.java:626) at java.base@9.0.1/java.lang.Thread.run(Thread.java:844) =09at __randomizedtesting.SeedInfo.seed([CC2303865C37EFC]:0) FAILED: junit.framework.TestSuite.org.apache.solr.search.join.TestCloudNes= tedDocsSort Error Message: There are still zombie threads that couldn't be terminated: 1) Thread[id= =3D2931, name=3Dqtp1327657358-2931, state=3DTIMED_WAITING, group=3DTGRP-Tes= tCloudNestedDocsSort] at java.base@9.0.1/jdk.internal.misc.Unsafe.p= ark(Native Method) at java.base@9.0.1/java.util.concurrent.locks.Lo= ckSupport.parkNanos(LockSupport.java:234) at java.base@9.0.1/java.u= til.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Abstr= actQueuedSynchronizer.java:2192) at app//org.eclipse.jetty.util.thr= ead.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecut= or.java:308) at app//org.eclipse.jetty.util.thread.ReservedThreadEx= ecutor$ReservedThread.run(ReservedThreadExecutor.java:373) at app//= org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java= :708) at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(= QueuedThreadPool.java:626) at java.base@9.0.1/java.lang.Thread.run(= Thread.java:844) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie = threads that couldn't be terminated: 1) Thread[id=3D2931, name=3Dqtp1327657358-2931, state=3DTIMED_WAITING, g= roup=3DTGRP-TestCloudNestedDocsSort] at java.base@9.0.1/jdk.internal.misc.Unsafe.park(Native Method) at java.base@9.0.1/java.util.concurrent.locks.LockSupport.parkNanos= (LockSupport.java:234) at java.base@9.0.1/java.util.concurrent.locks.AbstractQueuedSynchro= nizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192) at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$Reserv= edThread.reservedWait(ReservedThreadExecutor.java:308) at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$Reserv= edThread.run(ReservedThreadExecutor.java:373) at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(Queue= dThreadPool.java:708) at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(Queued= ThreadPool.java:626) at java.base@9.0.1/java.lang.Thread.run(Thread.java:844) =09at __randomizedtesting.SeedInfo.seed([CC2303865C37EFC]:0) FAILED: junit.framework.TestSuite.org.apache.solr.update.processor.TestOpe= nNLPExtractNamedEntitiesUpdateProcessorFactory Error Message: Could not remove the following files (in the order of attempts): C:\User= s\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-anal= ysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntit= iesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collection1\conf= : java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Luce= ne-Solr-master-Windows\solr\build\contrib\solr-analysis-extras\test\J1\temp= \solr.update.processor.TestOpenNLPExtractNamedEntitiesUpdateProcessorFactor= y_BA32251F038485ED-001\tempDir-001\collection1\conf C:\Users\jenkins\wor= kspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-analysis-extras\t= est\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntitiesUpdateProc= essorFactory_BA32251F038485ED-001\tempDir-001\collection1: java.nio.file.Di= rectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-master-Win= dows\solr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.proce= ssor.TestOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED= -001\tempDir-001\collection1 C:\Users\jenkins\workspace\Lucene-Solr-mast= er-Windows\solr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update= .processor.TestOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F03= 8485ED-001\tempDir-001: java.nio.file.DirectoryNotEmptyException: C:\Users\= jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-analys= is-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntitie= sUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001 C:\Users\jenkin= s\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-analysis-ext= ras\test\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntitiesUpdat= eProcessorFactory_BA32251F038485ED-001\tempDir-001\collection1\conf\en-test= -ner-person.bin: java.nio.file.AccessDeniedException: C:\Users\jenkins\work= space\Lucene-Solr-master-Windows\solr\build\contrib\solr-analysis-extras\te= st\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntitiesUpdateProce= ssorFactory_BA32251F038485ED-001\tempDir-001\collection1\conf\en-test-ner-p= erson.bin C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\bui= ld\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpen= NLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-= 001\collection1\conf\en-test-sent.bin: java.nio.file.AccessDeniedException:= C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\s= olr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtractNa= medEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collecti= on1\conf\en-test-sent.bin C:\Users\jenkins\workspace\Lucene-Solr-master-= Windows\solr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.pr= ocessor.TestOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F03848= 5ED-001\tempDir-001\collection1\conf\en-test-tokenizer.bin: java.nio.file.A= ccessDeniedException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows= \solr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor= .TestOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001= \tempDir-001\collection1\conf\en-test-tokenizer.bin C:\Users\jenkins\wor= kspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-analysis-extras\t= est\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntitiesUpdateProc= essorFactory_BA32251F038485ED-001: java.nio.file.DirectoryNotEmptyException= : C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\= solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtractN= amedEntitiesUpdateProcessorFactory_BA32251F038485ED-001=20 Stack Trace: java.io.IOException: Could not remove the following files (in the order of = attempts): C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib= \solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtract= NamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collec= tion1\conf: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\work= space\Lucene-Solr-master-Windows\solr\build\contrib\solr-analysis-extras\te= st\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntitiesUpdateProce= ssorFactory_BA32251F038485ED-001\tempDir-001\collection1\conf C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib= \solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtract= NamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collec= tion1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace= \Lucene-Solr-master-Windows\solr\build\contrib\solr-analysis-extras\test\J1= \temp\solr.update.processor.TestOpenNLPExtractNamedEntitiesUpdateProcessorF= actory_BA32251F038485ED-001\tempDir-001\collection1 C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib= \solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtract= NamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001: java.= nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr= -master-Windows\solr\build\contrib\solr-analysis-extras\test\J1\temp\solr.u= pdate.processor.TestOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA322= 51F038485ED-001\tempDir-001 C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib= \solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtract= NamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collec= tion1\conf\en-test-ner-person.bin: java.nio.file.AccessDeniedException: C:\= Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-= analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtractNamedE= ntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collection1\= conf\en-test-ner-person.bin C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib= \solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtract= NamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collec= tion1\conf\en-test-sent.bin: java.nio.file.AccessDeniedException: C:\Users\= jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-analys= is-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntitie= sUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collection1\conf\e= n-test-sent.bin C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib= \solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtract= NamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collec= tion1\conf\en-test-tokenizer.bin: java.nio.file.AccessDeniedException: C:\U= sers\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-a= nalysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEn= titiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collection1\c= onf\en-test-tokenizer.bin C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib= \solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtract= NamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001: java.nio.file.Dir= ectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-master-Wind= ows\solr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.proces= sor.TestOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-= 001 =09at __randomizedtesting.SeedInfo.seed([BA32251F038485ED]:0) =09at org.apache.lucene.util.IOUtils.rm(IOUtils.java:329) =09at org.apache.lucene.util.TestRuleTemporaryFilesCleanup.afterAlways(Test= RuleTemporaryFilesCleanup.java:216) =09at com.carrotsearch.randomizedtesting.rules.TestRuleAdapter$1.afterAlway= s(TestRuleAdapter.java:31) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:43) =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.base/java.lang.Thread.run(Thread.java:844) Build Log: [...truncated 11906 lines...] [junit4] Suite: org.apache.solr.search.join.TestCloudNestedDocsSort [junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-m= aster-Windows\solr\build\solr-core\test\J1\temp\solr.search.join.TestCloudN= estedDocsSort_CC2303865C37EFC-001\init-core-data-001 [junit4] 2> 219326 WARN (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpe= ns=3D1 numCloses=3D1 [junit4] 2> 219329 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POI= NTS_SYSPROP=3Dtrue) w/NUMERIC_DOCVALUES_SYSPROP=3Dtrue [junit4] 2> 219330 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clie= ntAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=3D"", value= =3D0.0/0.0, ssl=3D0.0/0.0, clientAuth=3D0.0/0.0) [junit4] 2> 219331 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: te= st.solr.allowed.securerandom=3Dnull & java.security.egd=3Dfile:/dev/./urand= om [junit4] 2> 219332 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 5 = servers in C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build= \solr-core\test\J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C= 37EFC-001\tempDir-001 [junit4] 2> 219332 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 219335 INFO (Thread-384) [ ] o.a.s.c.ZkTestServer clie= nt port:0.0.0.0/0.0.0.0:0 [junit4] 2> 219335 INFO (Thread-384) [ ] o.a.s.c.ZkTestServer Star= ting server [junit4] 2> 219340 ERROR (Thread-384) [ ] o.a.z.s.ZooKeeperServer Z= KShutdownHandler is not registered, so ZooKeeper server won't take any acti= on on ERROR or SHUTDOWN server state changes [junit4] 2> 219434 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:58241 [junit4] 2> 219437 INFO (zkConnectionManagerCallback-413-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219464 INFO (jetty-launcher-410-thread-3) [ ] o.e.j.s.= Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, g= it hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 219465 INFO (jetty-launcher-410-thread-5) [ ] o.e.j.s.= Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, g= it hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 219465 INFO (jetty-launcher-410-thread-2) [ ] o.e.j.s.= Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, g= it hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 219465 INFO (jetty-launcher-410-thread-3) [ ] o.e.j.s.= session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 219465 INFO (jetty-launcher-410-thread-3) [ ] o.e.j.s.= session No SessionScavenger set, using defaults [junit4] 2> 219465 INFO (jetty-launcher-410-thread-3) [ ] o.e.j.s.= session Scavenging every 660000ms [junit4] 2> 219465 INFO (jetty-launcher-410-thread-1) [ ] o.e.j.s.= Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, g= it hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 219465 INFO (jetty-launcher-410-thread-2) [ ] o.e.j.s.= session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 219465 INFO (jetty-launcher-410-thread-2) [ ] o.e.j.s.= session No SessionScavenger set, using defaults [junit4] 2> 219465 INFO (jetty-launcher-410-thread-2) [ ] o.e.j.s.= session Scavenging every 660000ms [junit4] 2> 219465 INFO (jetty-launcher-410-thread-4) [ ] o.e.j.s.= Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, g= it hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 219465 INFO (jetty-launcher-410-thread-2) [ ] o.e.j.s.= h.ContextHandler Started o.e.j.s.ServletContextHandler@5b770906{/solr,null,= AVAILABLE} [junit4] 2> 219466 INFO (jetty-launcher-410-thread-4) [ ] o.e.j.s.= session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 219466 INFO (jetty-launcher-410-thread-4) [ ] o.e.j.s.= session No SessionScavenger set, using defaults [junit4] 2> 219466 INFO (jetty-launcher-410-thread-4) [ ] o.e.j.s.= session Scavenging every 600000ms [junit4] 2> 219466 INFO (jetty-launcher-410-thread-4) [ ] o.e.j.s.= h.ContextHandler Started o.e.j.s.ServletContextHandler@34730a55{/solr,null,= AVAILABLE} [junit4] 2> 219466 INFO (jetty-launcher-410-thread-5) [ ] o.e.j.s.= session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 219466 INFO (jetty-launcher-410-thread-5) [ ] o.e.j.s.= session No SessionScavenger set, using defaults [junit4] 2> 219468 INFO (jetty-launcher-410-thread-5) [ ] o.e.j.s.= session Scavenging every 600000ms [junit4] 2> 219468 INFO (jetty-launcher-410-thread-1) [ ] o.e.j.s.= session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 219468 INFO (jetty-launcher-410-thread-1) [ ] o.e.j.s.= session No SessionScavenger set, using defaults [junit4] 2> 219468 INFO (jetty-launcher-410-thread-1) [ ] o.e.j.s.= session Scavenging every 600000ms [junit4] 2> 219469 INFO (jetty-launcher-410-thread-1) [ ] o.e.j.s.= h.ContextHandler Started o.e.j.s.ServletContextHandler@548a4acc{/solr,null,= AVAILABLE} [junit4] 2> 219469 INFO (jetty-launcher-410-thread-2) [ ] o.e.j.s.= AbstractConnector Started ServerConnector@ed852ca{SSL,[ssl, http/1.1]}{127.= 0.0.1:58245} [junit4] 2> 219469 INFO (jetty-launcher-410-thread-2) [ ] o.e.j.s.= Server Started @229479ms [junit4] 2> 219469 INFO (jetty-launcher-410-thread-2) [ ] o.a.s.c.= s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D5824= 5} [junit4] 2> 219469 ERROR (jetty-launcher-410-thread-2) [ ] o.a.s.u.= StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missin= g or incomplete. [junit4] 2> 219469 INFO (jetty-launcher-410-thread-2) [ ] o.a.s.s.= SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 219469 INFO (jetty-launcher-410-thread-2) [ ] o.a.s.s.= SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 219469 INFO (jetty-launcher-410-thread-2) [ ] o.a.s.s.= SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 219469 INFO (jetty-launcher-410-thread-2) [ ] o.a.s.s.= SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-20T23:30:11.474101= 500Z [junit4] 2> 219469 INFO (jetty-launcher-410-thread-1) [ ] o.e.j.s.= AbstractConnector Started ServerConnector@45b4a20{SSL,[ssl, http/1.1]}{127.= 0.0.1:58251} [junit4] 2> 219470 INFO (jetty-launcher-410-thread-1) [ ] o.e.j.s.= Server Started @229479ms [junit4] 2> 219470 INFO (jetty-launcher-410-thread-1) [ ] o.a.s.c.= s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D5825= 1} [junit4] 2> 219470 ERROR (jetty-launcher-410-thread-1) [ ] o.a.s.u.= StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missin= g or incomplete. [junit4] 2> 219470 INFO (jetty-launcher-410-thread-1) [ ] o.a.s.s.= SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 219470 INFO (jetty-launcher-410-thread-1) [ ] o.a.s.s.= SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 219470 INFO (jetty-launcher-410-thread-1) [ ] o.a.s.s.= SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 219470 INFO (jetty-launcher-410-thread-1) [ ] o.a.s.s.= SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-20T23:30:11.475035= 400Z [junit4] 2> 219470 INFO (jetty-launcher-410-thread-5) [ ] o.e.j.s.= h.ContextHandler Started o.e.j.s.ServletContextHandler@6f59d36b{/solr,null,= AVAILABLE} [junit4] 2> 219471 INFO (jetty-launcher-410-thread-5) [ ] o.e.j.s.= AbstractConnector Started ServerConnector@63ca6008{SSL,[ssl, http/1.1]}{127= .0.0.1:58256} [junit4] 2> 219471 INFO (jetty-launcher-410-thread-5) [ ] o.e.j.s.= Server Started @229481ms [junit4] 2> 219471 INFO (jetty-launcher-410-thread-5) [ ] o.a.s.c.= s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D5825= 6} [junit4] 2> 219471 ERROR (jetty-launcher-410-thread-5) [ ] o.a.s.u.= StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missin= g or incomplete. [junit4] 2> 219471 INFO (jetty-launcher-410-thread-5) [ ] o.a.s.s.= SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 219471 INFO (jetty-launcher-410-thread-5) [ ] o.a.s.s.= SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 219471 INFO (jetty-launcher-410-thread-5) [ ] o.a.s.s.= SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 219471 INFO (jetty-launcher-410-thread-5) [ ] o.a.s.s.= SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-20T23:30:11.476970= 700Z [junit4] 2> 219471 INFO (jetty-launcher-410-thread-3) [ ] o.e.j.s.= h.ContextHandler Started o.e.j.s.ServletContextHandler@746e680a{/solr,null,= AVAILABLE} [junit4] 2> 219473 INFO (jetty-launcher-410-thread-4) [ ] o.e.j.s.= AbstractConnector Started ServerConnector@1a02d77e{SSL,[ssl, http/1.1]}{127= .0.0.1:58246} [junit4] 2> 219473 INFO (jetty-launcher-410-thread-4) [ ] o.e.j.s.= Server Started @229482ms [junit4] 2> 219473 INFO (jetty-launcher-410-thread-4) [ ] o.a.s.c.= s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D5824= 6} [junit4] 2> 219473 ERROR (jetty-launcher-410-thread-4) [ ] o.a.s.u.= StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missin= g or incomplete. [junit4] 2> 219473 INFO (jetty-launcher-410-thread-4) [ ] o.a.s.s.= SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 219473 INFO (jetty-launcher-410-thread-4) [ ] o.a.s.s.= SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 219473 INFO (jetty-launcher-410-thread-4) [ ] o.a.s.s.= SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 219473 INFO (jetty-launcher-410-thread-4) [ ] o.a.s.s.= SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-20T23:30:11.478021= 700Z [junit4] 2> 219473 INFO (jetty-launcher-410-thread-3) [ ] o.e.j.s.= AbstractConnector Started ServerConnector@36d5c884{SSL,[ssl, http/1.1]}{127= .0.0.1:58263} [junit4] 2> 219473 INFO (jetty-launcher-410-thread-3) [ ] o.e.j.s.= Server Started @229483ms [junit4] 2> 219473 INFO (jetty-launcher-410-thread-3) [ ] o.a.s.c.= s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D5826= 3} [junit4] 2> 219473 ERROR (jetty-launcher-410-thread-3) [ ] o.a.s.u.= StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missin= g or incomplete. [junit4] 2> 219473 INFO (jetty-launcher-410-thread-3) [ ] o.a.s.s.= SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 219473 INFO (jetty-launcher-410-thread-3) [ ] o.a.s.s.= SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 219473 INFO (jetty-launcher-410-thread-3) [ ] o.a.s.s.= SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 219473 INFO (jetty-launcher-410-thread-3) [ ] o.a.s.s.= SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-20T23:30:11.478976= 900Z [junit4] 2> 219484 INFO (zkConnectionManagerCallback-415-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219484 INFO (zkConnectionManagerCallback-423-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219486 INFO (zkConnectionManagerCallback-421-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219486 INFO (zkConnectionManagerCallback-417-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219486 INFO (zkConnectionManagerCallback-419-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219494 INFO (jetty-launcher-410-thread-2) [ ] o.a.s.s.= SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 219496 INFO (jetty-launcher-410-thread-3) [ ] o.a.s.s.= SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 219496 INFO (jetty-launcher-410-thread-4) [ ] o.a.s.s.= SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 219496 INFO (jetty-launcher-410-thread-1) [ ] o.a.s.s.= SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 219496 INFO (jetty-launcher-410-thread-5) [ ] o.a.s.s.= SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 219502 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 0x16115e875100001, 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.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 219503 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 0x16115e875100005, 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.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 219505 INFO (jetty-launcher-410-thread-2) [ ] o.a.s.c.= ZkContainer Zookeeper client=3D127.0.0.1:58241/solr [junit4] 2> 219506 INFO (jetty-launcher-410-thread-4) [ ] o.a.s.c.= ZkContainer Zookeeper client=3D127.0.0.1:58241/solr [junit4] 2> 219522 INFO (zkConnectionManagerCallback-428-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219525 INFO (jetty-launcher-410-thread-3) [ ] o.a.s.c.= ZkContainer Zookeeper client=3D127.0.0.1:58241/solr [junit4] 2> 219526 INFO (jetty-launcher-410-thread-1) [ ] o.a.s.c.= ZkContainer Zookeeper client=3D127.0.0.1:58241/solr [junit4] 2> 219528 INFO (zkConnectionManagerCallback-431-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219528 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 0x16115e875100006, 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.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 219531 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 0x16115e875100007, 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.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 219533 INFO (zkConnectionManagerCallback-436-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219534 INFO (jetty-launcher-410-thread-5) [ ] o.a.s.c.= ZkContainer Zookeeper client=3D127.0.0.1:58241/solr [junit4] 2> 219537 INFO (zkConnectionManagerCallback-440-thread-1-pro= cessing-n:127.0.0.1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.Conn= ectionManager zkClient has connected [junit4] 2> 219538 INFO (zkConnectionManagerCallback-441-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219542 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 0x16115e87510000a, 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.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 219542 INFO (zkConnectionManagerCallback-447-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 219544 INFO (zkConnectionManagerCallback-444-thread-1-pro= cessing-n:127.0.0.1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.Conn= ectionManager zkClient has connected [junit4] 2> 219545 INFO (zkConnectionManagerCallback-449-thread-1-pro= cessing-n:127.0.0.1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.Conn= ectionManager zkClient has connected [junit4] 2> 219549 INFO (zkConnectionManagerCallback-451-thread-1-pro= cessing-n:127.0.0.1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.Conn= ectionManager zkClient has connected [junit4] 2> 219552 INFO (zkConnectionManagerCallback-453-thread-1-pro= cessing-n:127.0.0.1:58256_solr) [n:127.0.0.1:58256_solr ] o.a.s.c.c.Conn= ectionManager zkClient has connected [junit4] 2> 219750 INFO (jetty-launcher-410-thread-2) [n:127.0.0.1:58= 245_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 219750 INFO (jetty-launcher-410-thread-4) [n:127.0.0.1:58= 246_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 219751 INFO (jetty-launcher-410-thread-3) [n:127.0.0.1:58= 263_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 219752 INFO (jetty-launcher-410-thread-1) [n:127.0.0.1:58= 251_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 219752 INFO (jetty-launcher-410-thread-5) [n:127.0.0.1:58= 256_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 219753 INFO (jetty-launcher-410-thread-2) [n:127.0.0.1:58= 245_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 1= 27.0.0.1:58245_solr [junit4] 2> 219755 INFO (jetty-launcher-410-thread-4) [n:127.0.0.1:58= 246_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live= _nodes/127.0.0.1:58246_solr [junit4] 2> 219755 INFO (jetty-launcher-410-thread-3) [n:127.0.0.1:58= 263_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live= _nodes/127.0.0.1:58263_solr [junit4] 2> 219755 INFO (jetty-launcher-410-thread-1) [n:127.0.0.1:58= 251_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live= _nodes/127.0.0.1:58251_solr [junit4] 2> 219755 INFO (jetty-launcher-410-thread-5) [n:127.0.0.1:58= 256_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live= _nodes/127.0.0.1:58256_solr [junit4] 2> 219756 INFO (jetty-launcher-410-thread-2) [n:127.0.0.1:58= 245_solr ] o.a.s.c.Overseer Overseer (id=3D99384754919440393-127.0.0.1:5= 8245_solr-n_0000000000) starting [junit4] 2> 219815 INFO (jetty-launcher-410-thread-4) [n:127.0.0.1:58= 246_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58246.solr= .node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@2944dc64 [junit4] 2> 219820 INFO (jetty-launcher-410-thread-4) [n:127.0.0.1:58= 246_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58246.solr= .jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxM= BeanServer@2944dc64 [junit4] 2> 219820 INFO (jetty-launcher-410-thread-4) [n:127.0.0.1:58= 246_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58246.solr= .jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@2944dc64 [junit4] 2> 219821 INFO (jetty-launcher-410-thread-4) [n:127.0.0.1:58= 246_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions undern= eath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-= core\test\J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C37EFC-= 001\tempDir-001\node4\. [junit4] 2> 219840 INFO (zkCallback-448-thread-1-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 219859 INFO (zkCallback-450-thread-1-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 219862 INFO (zkCallback-439-thread-1-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 219862 INFO (zkCallback-452-thread-1-processing-n:127.0.0= .1:58256_solr) [n:127.0.0.1:58256_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 219863 INFO (zkCallback-443-thread-1-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 219870 INFO (jetty-launcher-410-thread-1) [n:127.0.0.1:58= 251_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58251.solr= .node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@2944dc64 [junit4] 2> 219876 INFO (jetty-launcher-410-thread-1) [n:127.0.0.1:58= 251_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58251.solr= .jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxM= BeanServer@2944dc64 [junit4] 2> 219877 INFO (jetty-launcher-410-thread-1) [n:127.0.0.1:58= 251_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58251.solr= .jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@2944dc64 [junit4] 2> 219878 INFO (jetty-launcher-410-thread-1) [n:127.0.0.1:58= 251_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions undern= eath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-= core\test\J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C37EFC-= 001\tempDir-001\node1\. [junit4] 2> 219878 INFO (jetty-launcher-410-thread-3) [n:127.0.0.1:58= 263_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58263.solr= .node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@2944dc64 [junit4] 2> 219884 INFO (jetty-launcher-410-thread-3) [n:127.0.0.1:58= 263_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58263.solr= .jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxM= BeanServer@2944dc64 [junit4] 2> 219884 INFO (jetty-launcher-410-thread-3) [n:127.0.0.1:58= 263_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58263.solr= .jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@2944dc64 [junit4] 2> 219885 INFO (jetty-launcher-410-thread-3) [n:127.0.0.1:58= 263_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions undern= eath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-= core\test\J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C37EFC-= 001\tempDir-001\node3\. [junit4] 2> 219890 INFO (jetty-launcher-410-thread-2) [n:127.0.0.1:58= 245_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live= _nodes/127.0.0.1:58245_solr [junit4] 2> 219911 INFO (zkCallback-448-thread-1-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 219912 INFO (zkCallback-452-thread-1-processing-n:127.0.0= .1:58256_solr) [n:127.0.0.1:58256_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 219913 INFO (zkCallback-450-thread-1-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 219913 INFO (zkCallback-443-thread-1-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 219913 INFO (OverseerStateUpdate-99384754919440393-127.0.= 0.1:58245_solr-n_0000000000) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkState= Reader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 219918 INFO (jetty-launcher-410-thread-5) [n:127.0.0.1:58= 256_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58256.solr= .node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@2944dc64 [junit4] 2> 219925 INFO (jetty-launcher-410-thread-5) [n:127.0.0.1:58= 256_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58256.solr= .jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxM= BeanServer@2944dc64 [junit4] 2> 219926 INFO (jetty-launcher-410-thread-5) [n:127.0.0.1:58= 256_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58256.solr= .jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@2944dc64 [junit4] 2> 219927 INFO (jetty-launcher-410-thread-5) [n:127.0.0.1:58= 256_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions undern= eath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-= core\test\J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C37EFC-= 001\tempDir-001\node5\. [junit4] 2> 219950 INFO (jetty-launcher-410-thread-2) [n:127.0.0.1:58= 245_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58245.solr= .node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@2944dc64 [junit4] 2> 219972 INFO (jetty-launcher-410-thread-2) [n:127.0.0.1:58= 245_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58245.solr= .jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxM= BeanServer@2944dc64 [junit4] 2> 219972 INFO (jetty-launcher-410-thread-2) [n:127.0.0.1:58= 245_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58245.solr= .jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@2944dc64 [junit4] 2> 219973 INFO (jetty-launcher-410-thread-2) [n:127.0.0.1:58= 245_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions undern= eath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-= core\test\J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C37EFC-= 001\tempDir-001\node2\. [junit4] 2> 220061 INFO (zkConnectionManagerCallback-465-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 220068 INFO (zkConnectionManagerCallback-469-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 220071 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from Zoo= Keeper... (0) -> (5) [junit4] 2> 220072 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at= 127.0.0.1:58241/solr ready [junit4] 2> 220534 INFO (qtp1214056186-2906) [n:127.0.0.1:58256_solr = ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with pa= rams replicationFactor=3D2&property.schema=3Dschema.xml&property.config=3Ds= olrconfig-minimal.xml&collection.configName=3DsolrCloudCollectionConfig&nam= e=3Dcollection1&nrtReplicas=3D2&action=3DCREATE&numShards=3D2&wt=3Djavabin&= version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 220537 INFO (OverseerThreadFactory-782-thread-1-processin= g-n:127.0.0.1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.a.c.CreateCo= llectionCmd Create collection collection1 [junit4] 2> 220646 INFO (OverseerStateUpdate-99384754919440393-127.0.= 0.1:58245_solr-n_0000000000) [n:127.0.0.1:58245_solr ] o.a.s.c.o.SliceMu= tator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"collection1_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:58245/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 220652 INFO (OverseerStateUpdate-99384754919440393-127.0.= 0.1:58245_solr-n_0000000000) [n:127.0.0.1:58245_solr ] o.a.s.c.o.SliceMu= tator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"collection1_shard1_replica_n2", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:58251/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 220657 INFO (OverseerStateUpdate-99384754919440393-127.0.= 0.1:58245_solr-n_0000000000) [n:127.0.0.1:58245_solr ] o.a.s.c.o.SliceMu= tator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"collection1_shard2_replica_n4", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:58263/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 220659 INFO (OverseerStateUpdate-99384754919440393-127.0.= 0.1:58245_solr-n_0000000000) [n:127.0.0.1:58245_solr ] o.a.s.c.o.SliceMu= tator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"collection1_shard2_replica_n6", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:58246/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 220896 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr = ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&coll= ection.configName=3DsolrCloudCollectionConfig&newCollection=3Dtrue&collecti= on=3Dcollection1&version=3D2&replicaType=3DNRT&property.schema=3Dschema.xml= &property.config=3Dsolrconfig-minimal.xml&coreNodeName=3Dcore_node8&name=3D= collection1_shard2_replica_n6&action=3DCREATE&numShards=3D2&shard=3Dshard2&= wt=3Djavabin [junit4] 2> 220897 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr = ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 21= 47483647 transient cores [junit4] 2> 220897 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr = ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&coll= ection.configName=3DsolrCloudCollectionConfig&newCollection=3Dtrue&collecti= on=3Dcollection1&version=3D2&replicaType=3DNRT&property.schema=3Dschema.xml= &property.config=3Dsolrconfig-minimal.xml&coreNodeName=3Dcore_node3&name=3D= collection1_shard1_replica_n1&action=3DCREATE&numShards=3D2&shard=3Dshard1&= wt=3Djavabin [junit4] 2> 220897 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&col= lection.configName=3DsolrCloudCollectionConfig&newCollection=3Dtrue&collect= ion=3Dcollection1&version=3D2&replicaType=3DNRT&property.schema=3Dschema.xm= l&property.config=3Dsolrconfig-minimal.xml&coreNodeName=3Dcore_node7&name= =3Dcollection1_shard2_replica_n4&action=3DCREATE&numShards=3D2&shard=3Dshar= d2&wt=3Djavabin [junit4] 2> 220897 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr = ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 21= 47483647 transient cores [junit4] 2> 220897 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2= 147483647 transient cores [junit4] 2> 220902 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr = ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&coll= ection.configName=3DsolrCloudCollectionConfig&newCollection=3Dtrue&collecti= on=3Dcollection1&version=3D2&replicaType=3DNRT&property.schema=3Dschema.xml= &property.config=3Dsolrconfig-minimal.xml&coreNodeName=3Dcore_node5&name=3D= collection1_shard1_replica_n2&action=3DCREATE&numShards=3D2&shard=3Dshard1&= wt=3Djavabin [junit4] 2> 220903 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr = ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 21= 47483647 transient cores [junit4] 2> 221014 INFO (zkCallback-443-thread-1-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 221014 INFO (zkCallback-448-thread-1-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 221014 INFO (zkCallback-439-thread-1-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 221014 INFO (zkCallback-450-thread-1-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 221015 INFO (zkCallback-443-thread-2-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 221015 INFO (zkCallback-448-thread-2-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 221015 INFO (zkCallback-450-thread-2-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 221015 INFO (zkCallback-439-thread-2-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 221925 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= c.SolrConfig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 221926 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .SolrConfig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 221949 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.s= .IndexSchema [collection1_shard2_replica_n6] Schema name=3Dtest [junit4] 2> 221950 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= s.IndexSchema [collection1_shard2_replica_n4] Schema name=3Dtest [junit4] 2> 221966 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.c= .SolrConfig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 222199 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .SolrConfig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 222266 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.s= .IndexSchema [collection1_shard1_replica_n1] Schema name=3Dtest [junit4] 2> 222322 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.s= .IndexSchema [collection1_shard1_replica_n2] Schema name=3Dtest [junit4] 2> 222436 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.s= .IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 222443 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 222470 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.s= .IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 222474 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.s= .IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 222501 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .CoreContainer Creating SolrCore 'collection1_shard2_replica_n6' using conf= iguration from collection collection1, trusted=3Dtrue [junit4] 2> 222501 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.m= .r.SolrJmxReporter JMX monitoring for 'solr_58246.solr.core.collection1.sha= rd2.replica_n6' (registry 'solr.core.collection1.shard2.replica_n6') enable= d at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2944dc64 [junit4] 2> 222501 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 222501 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .SolrCore [[collection1_shard2_replica_n6] ] Opening new SolrCore at [C:\Us= ers\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\= J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C37EFC-001\tempDi= r-001\node4\collection1_shard2_replica_n6], dataDir=3D[C:\Users\jenkins\wor= kspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.se= arch.join.TestCloudNestedDocsSort_CC2303865C37EFC-001\tempDir-001\node4\.\c= ollection1_shard2_replica_n6\data\] [junit4] 2> 222503 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.u= .RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index= .TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=3D50, maxMergeAtOnce= Explicit=3D34, maxMergedSegmentMB=3D63.083984375, floorSegmentMB=3D1.417968= 75, forceMergeDeletesPctAllowed=3D14.111913779560917, segmentsPerTier=3D34.= 0, maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 222506 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= c.CoreContainer Creating SolrCore 'collection1_shard2_replica_n4' using con= figuration from collection collection1, trusted=3Dtrue [junit4] 2> 222507 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= m.r.SolrJmxReporter JMX monitoring for 'solr_58263.solr.core.collection1.sh= ard2.replica_n4' (registry 'solr.core.collection1.shard2.replica_n4') enabl= ed at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2944dc64 [junit4] 2> 222507 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 222507 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= c.SolrCore [[collection1_shard2_replica_n4] ] Opening new SolrCore at [C:\U= sers\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test= \J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C37EFC-001\tempD= ir-001\node3\collection1_shard2_replica_n4], dataDir=3D[C:\Users\jenkins\wo= rkspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.s= earch.join.TestCloudNestedDocsSort_CC2303865C37EFC-001\tempDir-001\node3\.\= collection1_shard2_replica_n4\data\] [junit4] 2> 222509 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.inde= x.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=3D50, maxMergeAtOnc= eExplicit=3D34, maxMergedSegmentMB=3D63.083984375, floorSegmentMB=3D1.41796= 875, forceMergeDeletesPctAllowed=3D14.111913779560917, segmentsPerTier=3D34= .0, maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 222510 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.c= .CoreContainer Creating SolrCore 'collection1_shard1_replica_n1' using conf= iguration from collection collection1, trusted=3Dtrue [junit4] 2> 222511 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.m= .r.SolrJmxReporter JMX monitoring for 'solr_58245.solr.core.collection1.sha= rd1.replica_n1' (registry 'solr.core.collection1.shard1.replica_n1') enable= d at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2944dc64 [junit4] 2> 222511 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.c= .SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 222511 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.c= .SolrCore [[collection1_shard1_replica_n1] ] Opening new SolrCore at [C:\Us= ers\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\= J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C37EFC-001\tempDi= r-001\node2\collection1_shard1_replica_n1], dataDir=3D[C:\Users\jenkins\wor= kspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.se= arch.join.TestCloudNestedDocsSort_CC2303865C37EFC-001\tempDir-001\node2\.\c= ollection1_shard1_replica_n1\data\] [junit4] 2> 222512 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .CoreContainer Creating SolrCore 'collection1_shard1_replica_n2' using conf= iguration from collection collection1, trusted=3Dtrue [junit4] 2> 222513 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.m= .r.SolrJmxReporter JMX monitoring for 'solr_58251.solr.core.collection1.sha= rd1.replica_n2' (registry 'solr.core.collection1.shard1.replica_n2') enable= d at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2944dc64 [junit4] 2> 222513 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 222513 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .SolrCore [[collection1_shard1_replica_n2] ] Opening new SolrCore at [C:\Us= ers\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\= J1\temp\solr.search.join.TestCloudNestedDocsSort_CC2303865C37EFC-001\tempDi= r-001\node1\collection1_shard1_replica_n2], dataDir=3D[C:\Users\jenkins\wor= kspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.se= arch.join.TestCloudNestedDocsSort_CC2303865C37EFC-001\tempDir-001\node1\.\c= ollection1_shard1_replica_n2\data\] [junit4] 2> 222513 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.u= .RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index= .TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=3D50, maxMergeAtOnce= Explicit=3D34, maxMergedSegmentMB=3D63.083984375, floorSegmentMB=3D1.417968= 75, forceMergeDeletesPctAllowed=3D14.111913779560917, segmentsPerTier=3D34.= 0, maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 222515 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.u= .RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index= .TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=3D50, maxMergeAtOnce= Explicit=3D34, maxMergedSegmentMB=3D63.083984375, floorSegmentMB=3D1.417968= 75, forceMergeDeletesPctAllowed=3D14.111913779560917, segmentsPerTier=3D34.= 0, maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 222610 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.u= .CommitTracker Hard AutoCommit: disabled [junit4] 2> 222610 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.u= .CommitTracker Soft AutoCommit: disabled [junit4] 2> 222626 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.u= .CommitTracker Hard AutoCommit: disabled [junit4] 2> 222626 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.u= .CommitTracker Soft AutoCommit: disabled [junit4] 2> 222627 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.u= .RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index= .TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=3D28, maxMergeAtOnce= Explicit=3D15, maxMergedSegmentMB=3D31.2890625, floorSegmentMB=3D1.88476562= 5, forceMergeDeletesPctAllowed=3D22.091114631655433, segmentsPerTier=3D21.0= , maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 222627 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.s= .SolrIndexSearcher Opening [Searcher@258c2189[collection1_shard2_replica_n6= ] main] [junit4] 2> 222628 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.r= .ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /conf= igs/solrCloudCollectionConfig [junit4] 2> 222629 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.r= .ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKee= perStorageIO:path=3D/configs/solrCloudCollectionConfig [junit4] 2> 222629 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.h= .ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 222635 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 222635 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 222636 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .ShardLeaderElectionContext Waiting until we see more replicas up for shard= shard2: total=3D2 found=3D1 timeoutin=3D9999ms [junit4] 2> 222637 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.u= .RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index= .TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=3D28, maxMergeAtOnce= Explicit=3D15, maxMergedSegmentMB=3D31.2890625, floorSegmentMB=3D1.88476562= 5, forceMergeDeletesPctAllowed=3D22.091114631655433, segmentsPerTier=3D21.0= , maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 222637 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.s= .SolrIndexSearcher Opening [Searcher@2b182054[collection1_shard1_replica_n2= ] main] [junit4] 2> 222638 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.r= .ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /conf= igs/solrCloudCollectionConfig [junit4] 2> 222638 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.r= .ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKee= perStorageIO:path=3D/configs/solrCloudCollectionConfig [junit4] 2> 222638 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.inde= x.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=3D28, maxMergeAtOnc= eExplicit=3D15, maxMergedSegmentMB=3D31.2890625, floorSegmentMB=3D1.8847656= 25, forceMergeDeletesPctAllowed=3D22.091114631655433, segmentsPerTier=3D21.= 0, maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 222640 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.h= .ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 222640 INFO (searcherExecutor-786-thread-1-processing-n:1= 27.0.0.1:58246_solr x:collection1_shard2_replica_n6 s:shard2 c:collection1 = r:core_node8) [n:127.0.0.1:58246_solr c:collection1 s:shard2 r:core_node8 x= :collection1_shard2_replica_n6] o.a.s.c.SolrCore [collection1_shard2_replic= a_n6] Registered new searcher Searcher@258c2189[collection1_shard2_replica_= n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 222641 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= s.SolrIndexSearcher Opening [Searcher@6be4b1b9[collection1_shard2_replica_n= 4] main] [junit4] 2> 222642 INFO (searcherExecutor-789-thread-1-processing-n:1= 27.0.0.1:58251_solr x:collection1_shard1_replica_n2 s:shard1 c:collection1 = r:core_node5) [n:127.0.0.1:58251_solr c:collection1 s:shard1 r:core_node5 x= :collection1_shard1_replica_n2] o.a.s.c.SolrCore [collection1_shard1_replic= a_n2] Registered new searcher Searcher@2b182054[collection1_shard1_replica_= n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 222643 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /con= figs/solrCloudCollectionConfig [junit4] 2> 222643 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKe= eperStorageIO:path=3D/configs/solrCloudCollectionConfig [junit4] 2> 222644 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 222645 INFO (searcherExecutor-787-thread-1-processing-n:1= 27.0.0.1:58263_solr x:collection1_shard2_replica_n4 s:shard2 c:collection1 = r:core_node7) [n:127.0.0.1:58263_solr c:collection1 s:shard2 r:core_node7 x= :collection1_shard2_replica_n4] o.a.s.c.SolrCore [collection1_shard2_replic= a_n4] Registered new searcher Searcher@6be4b1b9[collection1_shard2_replica_= n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 222650 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .ShardLeaderElectionContext Waiting until we see more replicas up for shard= shard1: total=3D2 found=3D1 timeoutin=3D9999ms [junit4] 2> 222683 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.u= .CommitTracker Hard AutoCommit: disabled [junit4] 2> 222683 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.u= .CommitTracker Soft AutoCommit: disabled [junit4] 2> 222685 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.u= .RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index= .TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=3D28, maxMergeAtOnce= Explicit=3D15, maxMergedSegmentMB=3D31.2890625, floorSegmentMB=3D1.88476562= 5, forceMergeDeletesPctAllowed=3D22.091114631655433, segmentsPerTier=3D21.0= , maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 222686 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.s= .SolrIndexSearcher Opening [Searcher@35d54646[collection1_shard1_replica_n1= ] main] [junit4] 2> 222687 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.r= .ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /conf= igs/solrCloudCollectionConfig [junit4] 2> 222687 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.r= .ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKee= perStorageIO:path=3D/configs/solrCloudCollectionConfig [junit4] 2> 222688 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.h= .ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 222689 INFO (searcherExecutor-788-thread-1-processing-n:1= 27.0.0.1:58245_solr x:collection1_shard1_replica_n1 s:shard1 c:collection1 = r:core_node3) [n:127.0.0.1:58245_solr c:collection1 s:shard1 r:core_node3 x= :collection1_shard1_replica_n1] o.a.s.c.SolrCore [collection1_shard1_replic= a_n1] Registered new searcher Searcher@35d54646[collection1_shard1_replica_= n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 222753 INFO (zkCallback-443-thread-2-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 222753 INFO (zkCallback-439-thread-3-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 222753 INFO (zkCallback-448-thread-1-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 222753 INFO (zkCallback-439-thread-2-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 222753 INFO (zkCallback-448-thread-2-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 222753 INFO (zkCallback-450-thread-1-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 222753 INFO (zkCallback-450-thread-2-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 222753 INFO (zkCallback-443-thread-1-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223137 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 223137 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 223137 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .SyncStrategy Sync replicas to https://127.0.0.1:58246/solr/collection1_sha= rd2_replica_n6/ [junit4] 2> 223137 ERROR (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .SyncStrategy No UpdateLog found - cannot sync [junit4] 2> 223137 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .ShardLeaderElectionContext We failed sync, but we have no versions - we ca= n't sync in that case - we were active before, so become leader anyway [junit4] 2> 223137 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .ShardLeaderElectionContext Found all replicas participating in election, c= lear LIR [junit4] 2> 223142 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .ShardLeaderElectionContext I am the new leader: https://127.0.0.1:58246/so= lr/collection1_shard2_replica_n6/ shard2 [junit4] 2> 223151 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 223151 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 223151 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .SyncStrategy Sync replicas to https://127.0.0.1:58251/solr/collection1_sha= rd1_replica_n2/ [junit4] 2> 223151 ERROR (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .SyncStrategy No UpdateLog found - cannot sync [junit4] 2> 223154 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .ShardLeaderElectionContext We failed sync, but we have no versions - we ca= n't sync in that case - we were active before, so become leader anyway [junit4] 2> 223154 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .ShardLeaderElectionContext Found all replicas participating in election, c= lear LIR [junit4] 2> 223158 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .ShardLeaderElectionContext I am the new leader: https://127.0.0.1:58251/so= lr/collection1_shard1_replica_n2/ shard1 [junit4] 2> 223259 INFO (zkCallback-450-thread-2-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223260 INFO (zkCallback-443-thread-1-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223260 INFO (zkCallback-450-thread-1-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223260 INFO (zkCallback-443-thread-2-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223260 INFO (zkCallback-448-thread-2-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223260 INFO (zkCallback-439-thread-3-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223260 INFO (zkCallback-448-thread-1-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223260 INFO (zkCallback-439-thread-2-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223293 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.c= .ZkController I am the leader, no recovery necessary [junit4] 2> 223295 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.s= .HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/adm= in/cores&collection.configName=3DsolrCloudCollectionConfig&newCollection=3D= true&collection=3Dcollection1&version=3D2&replicaType=3DNRT&property.schema= =3Dschema.xml&property.config=3Dsolrconfig-minimal.xml&coreNodeName=3Dcore_= node8&name=3Dcollection1_shard2_replica_n6&action=3DCREATE&numShards=3D2&sh= ard=3Dshard2&wt=3Djavabin} status=3D0 QTime=3D2399 [junit4] 2> 223310 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.c= .ZkController I am the leader, no recovery necessary [junit4] 2> 223312 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.s= .HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/adm= in/cores&collection.configName=3DsolrCloudCollectionConfig&newCollection=3D= true&collection=3Dcollection1&version=3D2&replicaType=3DNRT&property.schema= =3Dschema.xml&property.config=3Dsolrconfig-minimal.xml&coreNodeName=3Dcore_= node5&name=3Dcollection1_shard1_replica_n2&action=3DCREATE&numShards=3D2&sh= ard=3Dshard1&wt=3Djavabin} status=3D0 QTime=3D2410 [junit4] 2> 223413 INFO (zkCallback-450-thread-1-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223413 INFO (zkCallback-443-thread-1-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223413 INFO (zkCallback-448-thread-1-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223413 INFO (zkCallback-448-thread-2-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223413 INFO (zkCallback-439-thread-2-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223413 INFO (zkCallback-439-thread-1-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223413 INFO (zkCallback-450-thread-2-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223413 INFO (zkCallback-443-thread-2-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223653 INFO (qtp1327657358-2881) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/ad= min/cores&collection.configName=3DsolrCloudCollectionConfig&newCollection= =3Dtrue&collection=3Dcollection1&version=3D2&replicaType=3DNRT&property.sch= ema=3Dschema.xml&property.config=3Dsolrconfig-minimal.xml&coreNodeName=3Dco= re_node7&name=3Dcollection1_shard2_replica_n4&action=3DCREATE&numShards=3D2= &shard=3Dshard2&wt=3Djavabin} status=3D0 QTime=3D2755 [junit4] 2> 223693 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.s= .HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/adm= in/cores&collection.configName=3DsolrCloudCollectionConfig&newCollection=3D= true&collection=3Dcollection1&version=3D2&replicaType=3DNRT&property.schema= =3Dschema.xml&property.config=3Dsolrconfig-minimal.xml&coreNodeName=3Dcore_= node3&name=3Dcollection1_shard1_replica_n1&action=3DCREATE&numShards=3D2&sh= ard=3Dshard1&wt=3Djavabin} status=3D0 QTime=3D2796 [junit4] 2> 223696 INFO (qtp1214056186-2906) [n:127.0.0.1:58256_solr = ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for = at most 30 seconds. Check all shard replicas [junit4] 2> 223797 INFO (zkCallback-450-thread-2-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223798 INFO (zkCallback-450-thread-1-processing-n:127.0.0= .1:58251_solr) [n:127.0.0.1:58251_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223798 INFO (zkCallback-443-thread-2-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223798 INFO (zkCallback-443-thread-1-processing-n:127.0.0= .1:58246_solr) [n:127.0.0.1:58246_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223798 INFO (zkCallback-448-thread-2-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223798 INFO (zkCallback-448-thread-1-processing-n:127.0.0= .1:58263_solr) [n:127.0.0.1:58263_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223798 INFO (zkCallback-439-thread-1-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 223799 INFO (zkCallback-439-thread-2-processing-n:127.0.0= .1:58245_solr) [n:127.0.0.1:58245_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/collection1/state.json] for collection [collection1] has occ= urred - updating... (live nodes size: [5]) [junit4] 2> 224546 INFO (OverseerCollectionConfigSetProcessor-9938475= 4919440393-127.0.0.1:58245_solr-n_0000000000) [n:127.0.0.1:58245_solr ] = o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work= /qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKee= per [junit4] 2> 224698 INFO (qtp1214056186-2906) [n:127.0.0.1:58256_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections p= arams=3D{replicationFactor=3D2&property.schema=3Dschema.xml&property.config= =3Dsolrconfig-minimal.xml&collection.configName=3DsolrCloudCollectionConfig= &name=3Dcollection1&nrtReplicas=3D2&action=3DCREATE&numShards=3D2&wt=3Djava= bin&version=3D2} status=3D0 QTime=3D4163 [junit4] 2> 224699 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveri= es to finish - collection: collection1 failOnTimeout:true timeout (sec):30 [junit4] 1> - [junit4] 1> replica:core_node3 rstate:active live:true [junit4] 1> replica:core_node5 rstate:active live:true [junit4] 1> replica:core_node7 rstate:active live:true [junit4] 1> replica:core_node8 rstate:active live:true [junit4] 1> no one is recoverying [junit4] 2> 224699 INFO (SUITE-TestCloudNestedDocsSort-seed#[CC230386= 5C37EFC]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finish= ed - collection: collection1 [junit4] 2> 224753 INFO (qtp1327657358-2879) [n:127.0.0.1:58263_solr = c:collection1 s:shard2 r:core_node7 x:collection1_shard2_replica_n4] o.a.s.= u.p.LogUpdateProcessorFactory [collection1_shard2_replica_n4] webapp=3D/so= lr path=3D/update params=3D{update.distrib=3DFROMLEADER&distrib.from=3Dhttp= s://127.0.0.1:58246/solr/collection1_shard2_replica_n6/&wt=3Djavabin&versio= n=3D2}{add=3D[-144860250, -892374266, -399316924, 825769730, -1094207096, -= 1070170076]} 0 14 [junit4] 2> 224753 INFO (qtp672332403-2898) [n:127.0.0.1:58246_solr c= :collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n6] o.a.s.u= .p.LogUpdateProcessorFactory [collection1_shard2_replica_n6] webapp=3D/sol= r path=3D/update params=3D{wt=3Djavabin&version=3D2}{add=3D[-144860250, -89= 2374266, -399316924, 825769730, -1094207096, -1070170076]} 0 39 [junit4] 2> 224759 INFO (qtp727993966-2888) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.u= .p.LogUpdateProcessorFactory [collection1_shard1_replica_n1] webapp=3D/sol= r path=3D/update params=3D{update.distrib=3DFROMLEADER&distrib.from=3Dhttps= ://127.0.0.1:58251/solr/collection1_shard1_replica_n2/&wt=3Djavabin&version= =3D2}{add=3D[489873974, 2015072252, 1997842125, -1679239780, -766193965, -1= 70313444, -1273390380, 1522430893, -1336435054]} 0 26 [junit4] 2> 224760 INFO (qtp153969115-2913) [n:127.0.0.1:58251_solr c= :collection1 s:shard1 r:core_node5 x:collection1_shard1_replica_n2] o.a.s.u= .p.LogUpdateProcessorFactory [collection1_shard1_replica_n2] webapp=3D/sol= r path=3D/update params=3D{wt=3Djavabin&version=3D2}{add=3D[489873974, 2015= 072252, 1997842125, -1679239780, -766193965, -170313444, -1273390380, 15224= 30893, -1336435054]} 0 45 [junit4] 2> 224780 INFO (qtp727993966-2887) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.u= .DirectUpdateHandler2 start commit{,optimize=3Dfalse,openSearcher=3Dtrue,wa= itSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4] 2> 224780 INFO (qtp727993966-2887) [n:127.0.0.1:58245_solr c= :collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.u= .SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrI= ndexWriter@49ec25dc commitCommandVersion:0 [junit4]=20 [...truncated too long message...] apDocFreqInterval), parent_id_s1=3DLucene50(blocksize=3D128), _root_=3DPost= ingsFormat(name=3DAsserting), val_s1=3DPostingsFormat(name=3DLuceneVarGapDo= cFreqInterval), id=3DBlockTreeOrds(blocksize=3D128)}, docValues:{range_face= t_l_dv=3DDocValuesFormat(name=3DMemory), intDefault=3DDocValuesFormat(name= =3DAsserting), id_i1=3DDocValuesFormat(name=3DAsserting), range_facet_i_dv= =3DDocValuesFormat(name=3DLucene70), intDvoDefault=3DDocValuesFormat(name= =3DMemory), timestamp=3DDocValuesFormat(name=3DLucene70), range_facet_l=3DD= ocValuesFormat(name=3DLucene70)}, maxPointsInLeafNode=3D1563, maxMBSortInHe= ap=3D7.10429450547787, sim=3DAsserting(org.apache.lucene.search.similaritie= s.AssertingSimilarity@47b7bf92), locale=3Dzh-Hant-TW, timezone=3DBrazil/Eas= t [junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 9.0.1 (64-b= it)/cpus=3D3,threads=3D2,free=3D98157624,total=3D257183744 [junit4] 2> NOTE: All tests run in this JVM: [TestHashQParserPlugin, T= estSolrCLIRunExample, TestConfig, DistributedFacetPivotWhiteBoxTest, Assign= Test, TestDeleteCollectionOnDownNodes, TestUseDocValuesAsStored, DeleteStat= usTest, RemoteQueryErrorTest, TestMinMaxOnMultiValuedField, PreAnalyzedUpda= teProcessorTest, TestRestoreCore, TestLMJelinekMercerSimilarityFactory, Tes= tAnalyzeInfixSuggestions, RuleEngineTest, TestExtendedDismaxParser, TestLMD= irichletSimilarityFactory, TestSolrCoreProperties, ReplicaListTransformerTe= st, ChaosMonkeyNothingIsSafeTest, TestUnifiedSolrHighlighter, TestGraphMLRe= sponseWriter, TestFilteredDocIdSet, TestSerializedLuceneMatchVersion, TestC= loudNestedDocsSort] [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DTestCloudNest= edDocsSort -Dtests.seed=3DCC2303865C37EFC -Dtests.slow=3Dtrue -Dtests.local= e=3Dzh-Hant-TW -Dtests.timezone=3DBrazil/East -Dtests.asserts=3Dtrue -Dtest= s.file.encoding=3DUS-ASCII [junit4] ERROR 0.00s J1 | TestCloudNestedDocsSort (suite) <<< [junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLea= kError: 1 thread leaked from SUITE scope at org.apache.solr.search.join.Tes= tCloudNestedDocsSort:=20 [junit4] > 1) Thread[id=3D2931, name=3Dqtp1327657358-2931, state= =3DTIMED_WAITING, group=3DTGRP-TestCloudNestedDocsSort] [junit4] > at java.base@9.0.1/jdk.internal.misc.Unsafe.park(N= ative Method) [junit4] > at java.base@9.0.1/java.util.concurrent.locks.Lock= Support.parkNanos(LockSupport.java:234) [junit4] > at java.base@9.0.1/java.util.concurrent.locks.Abst= ractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.jav= a:2192) [junit4] > at app//org.eclipse.jetty.util.thread.ReservedThre= adExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308) [junit4] > at app//org.eclipse.jetty.util.thread.ReservedThre= adExecutor$ReservedThread.run(ReservedThreadExecutor.java:373) [junit4] > at app//org.eclipse.jetty.util.thread.QueuedThread= Pool.runJob(QueuedThreadPool.java:708) [junit4] > at app//org.eclipse.jetty.util.thread.QueuedThread= Pool$2.run(QueuedThreadPool.java:626) [junit4] > at java.base@9.0.1/java.lang.Thread.run(Thread.jav= a:844) [junit4] > =09at __randomizedtesting.SeedInfo.seed([CC2303865C37EFC]:= 0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There a= re still zombie threads that couldn't be terminated: [junit4] > 1) Thread[id=3D2931, name=3Dqtp1327657358-2931, state= =3DTIMED_WAITING, group=3DTGRP-TestCloudNestedDocsSort] [junit4] > at java.base@9.0.1/jdk.internal.misc.Unsafe.park(N= ative Method) [junit4] > at java.base@9.0.1/java.util.concurrent.locks.Lock= Support.parkNanos(LockSupport.java:234) [junit4] > at java.base@9.0.1/java.util.concurrent.locks.Abst= ractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.jav= a:2192) [junit4] > at app//org.eclipse.jetty.util.thread.ReservedThre= adExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308) [junit4] > at app//org.eclipse.jetty.util.thread.ReservedThre= adExecutor$ReservedThread.run(ReservedThreadExecutor.java:373) [junit4] > at app//org.eclipse.jetty.util.thread.QueuedThread= Pool.runJob(QueuedThreadPool.java:708) [junit4] > at app//org.eclipse.jetty.util.thread.QueuedThread= Pool$2.run(QueuedThreadPool.java:626) [junit4] > at java.base@9.0.1/java.lang.Thread.run(Thread.jav= a:844) [junit4] > =09at __randomizedtesting.SeedInfo.seed([CC2303865C37EFC]:= 0) [junit4] Completed [81/768 (1!)] on J1 in 58.92s, 1 test, 2 errors <<< F= AILURES! [...truncated 4574 lines...] [junit4] Suite: org.apache.solr.update.processor.TestOpenNLPExtractNamed= EntitiesUpdateProcessorFactory [junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-m= aster-Windows\solr\build\contrib\solr-analysis-extras\test\J1\temp\solr.upd= ate.processor.TestOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251= F038485ED-001\init-core-data-001 [junit4] 2> NOTE: test params are: codec=3DAsserting(Lucene70): {}, do= cValues:{}, maxPointsInLeafNode=3D152, maxMBSortInHeap=3D5.30238632620377, = sim=3DAsserting(org.apache.lucene.search.similarities.AssertingSimilarity@2= 7f232a), locale=3Dne-NP, timezone=3DAmerica/Dominica [junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 9.0.1 (64-b= it)/cpus=3D3,threads=3D1,free=3D55973024,total=3D97386496 [junit4] 2> NOTE: All tests run in this JVM: [TestFoldingMultitermExtr= asQuery, TestOpenNLPExtractNamedEntitiesUpdateProcessorFactory] [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DTestOpenNLPEx= tractNamedEntitiesUpdateProcessorFactory -Dtests.seed=3DBA32251F038485ED -D= tests.slow=3Dtrue -Dtests.locale=3Dne-NP -Dtests.timezone=3DAmerica/Dominic= a -Dtests.asserts=3Dtrue -Dtests.file.encoding=3DUS-ASCII [junit4] ERROR 0.00s J1 | TestOpenNLPExtractNamedEntitiesUpdateProcess= orFactory (suite) <<< [junit4] > Throwable #1: java.io.IOException: Could not remove the fo= llowing files (in the order of attempts): [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\s= olr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.T= estOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\t= empDir-001\collection1\conf: java.nio.file.DirectoryNotEmptyException: C:\U= sers\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-a= nalysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEn= titiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collection1\c= onf [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\s= olr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.T= estOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\t= empDir-001\collection1: java.nio.file.DirectoryNotEmptyException: C:\Users\= jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-analys= is-extras\test\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntitie= sUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\collection1 [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\s= olr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.T= estOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\t= empDir-001: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\work= space\Lucene-Solr-master-Windows\solr\build\contrib\solr-analysis-extras\te= st\J1\temp\solr.update.processor.TestOpenNLPExtractNamedEntitiesUpdateProce= ssorFactory_BA32251F038485ED-001\tempDir-001 [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\s= olr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.T= estOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\t= empDir-001\collection1\conf\en-test-ner-person.bin: java.nio.file.AccessDen= iedException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\bu= ild\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpe= nNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir= -001\collection1\conf\en-test-ner-person.bin [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\s= olr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.T= estOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\t= empDir-001\collection1\conf\en-test-sent.bin: java.nio.file.AccessDeniedExc= eption: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\co= ntrib\solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpenNLPEx= tractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-001\c= ollection1\conf\en-test-sent.bin [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\s= olr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.T= estOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\t= empDir-001\collection1\conf\en-test-tokenizer.bin: java.nio.file.AccessDeni= edException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\bui= ld\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.TestOpen= NLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001\tempDir-= 001\collection1\conf\en-test-tokenizer.bin [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\s= olr\build\contrib\solr-analysis-extras\test\J1\temp\solr.update.processor.T= estOpenNLPExtractNamedEntitiesUpdateProcessorFactory_BA32251F038485ED-001: = java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene= -Solr-master-Windows\solr\build\contrib\solr-analysis-extras\test\J1\temp\s= olr.update.processor.TestOpenNLPExtractNamedEntitiesUpdateProcessorFactory_= BA32251F038485ED-001 [junit4] > =09at __randomizedtesting.SeedInfo.seed([BA32251F038485ED]= :0) [junit4] > =09at org.apache.lucene.util.IOUtils.rm(IOUtils.java:329) [junit4] > =09at java.base/java.lang.Thread.run(Thread.java:844) [junit4] Completed [4/5 (1!)] on J1 in 0.69s, 8 tests, 1 error <<< FAILU= RES! [...truncated 38458 lines...] ------=_Part_56_1491971523.1516493345997 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_56_1491971523.1516493345997--