Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/7190/ Java: 32bit/jdk1.8.0_144 -server -XX:+UseConcMarkSweepGC
No tests ran. Build Log: [...truncated 1336 lines...] [junit4] Suite: org.apache.lucene.index.TestIndexFileDeleter [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestIndexFileDeleter -Dtests.method=testDeleteLeftoverFiles -Dtests.seed=7C586020B961247B -Dtests.slow=true -Dtests.locale=ko -Dtests.timezone=Asia/Taipei -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1 [junit4] FAILURE 0.09s J1 | TestIndexFileDeleter.testDeleteLeftoverFiles <<< [junit4] > Throwable #1: java.lang.AssertionError: IndexFileDeleter failed to delete unreferenced extra files: should have deleted 6 files but only deleted 5; expected files: [junit4] > _0.cfe [junit4] > _0.cfs [junit4] > _0.si [junit4] > _0_1.liv [junit4] > _1.cfe [junit4] > _1.cfs [junit4] > _1.si [junit4] > _2.cfe [junit4] > _2.cfs [junit4] > _2.si [junit4] > _3.doc [junit4] > _3.fdt [junit4] > _3.fdx [junit4] > _3.fnm [junit4] > _3.nvd [junit4] > _3.nvm [junit4] > _3.pos [junit4] > _3.si [junit4] > _3.tim [junit4] > _3.tip [junit4] > _4.doc [junit4] > _4.fdt [junit4] > _4.fdx [junit4] > _4.fnm [junit4] > _4.nvd [junit4] > _4.nvm [junit4] > _4.pos [junit4] > _4.si [junit4] > _4.tim [junit4] > _4.tip [junit4] > segments_2 [junit4] > write.lock [junit4] > actual files: [junit4] > _0.cfe [junit4] > _0.cfs [junit4] > _0.si [junit4] > _0_1.liv [junit4] > _1.cfe [junit4] > _1.cfs [junit4] > _1.si [junit4] > _188.cfs [junit4] > _2.cfe [junit4] > _2.cfs [junit4] > _2.si [junit4] > _3.doc [junit4] > _3.fdt [junit4] > _3.fdx [junit4] > _3.fnm [junit4] > _3.nvd [junit4] > _3.nvm [junit4] > _3.pos [junit4] > _3.si [junit4] > _3.tim [junit4] > _3.tip [junit4] > _4.doc [junit4] > _4.fdt [junit4] > _4.fdx [junit4] > _4.fnm [junit4] > _4.nvd [junit4] > _4.nvm [junit4] > _4.pos [junit4] > _4.si [junit4] > _4.tim [junit4] > _4.tip [junit4] > segments_2 [junit4] > write.lock [junit4] > diff: [_188.cfs] [junit4] > at __randomizedtesting.SeedInfo.seed([7C586020B961247B:B615692DDFA17362]:0) [junit4] > at org.apache.lucene.index.TestIndexFileDeleter.testDeleteLeftoverFiles(TestIndexFileDeleter.java:153) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\J1\temp\lucene.index.TestIndexFileDeleter_7C586020B961247B-001 [junit4] 2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1fab618), locale=ko, timezone=Asia/Taipei [junit4] 2> NOTE: Windows 10 10.0 x86/Oracle Corporation 1.8.0_144 (32-bit)/cpus=3,threads=1,free=341095240,total=473702400 [junit4] 2> NOTE: All tests run in this JVM: [TestGrowableByteArrayDataOutput, TestRateLimiter, Test2BPositions, TestIndexWriterMaxDocs, TestMultiCollector, TestBlockPostingsFormat2, TestSloppyPhraseQuery2, TestIntRange, TestSizeBoundedForceMerge, Test2BSortedDocValuesOrds, TestTransactions, TestMSBRadixSorter, TestDeterminism, TestAxiomaticF3EXP, TestLMJelinekMercerSimilarity, TestSimpleAttributeImpl, TestByteSlices, TestTerms, TestVirtualMethod, TestOperations, TestFieldInvertState, TestSearch, TestCloseableThreadLocal, TestCheckIndex, TestNIOFSDirectory, Test4GBStoredFields, TestTimSorterWorstCase, TestAxiomaticF2EXP, TestScoreCachingWrappingScorer, TestPerFieldPostingsFormat2, TestUniqueTermCount, TestSegmentMerger, TestUsageTrackingFilterCachingPolicy, TestInPlaceMergeSorter, LimitedFiniteStringsIteratorTest, TestExceedMaxTermLength, TestSegmentInfos, TestIndexTooManyDocs, TestIndexWriterReader, TestStressAdvance, TestNRTCachingDirectory, TestMaxTermFrequency, TestTermsEnum, TestDirectoryReaderReopen, TestSameTokenSamePosition, TestDoubleRangeFieldQueries, TestWildcardRandom, TestStringMSBRadixSorter, TestPostingsOffsets, TestMultiTermsEnum, TestStressNRT, TestRoaringDocIdSet, TestFixedLengthBytesRefArray, TestRollingBuffer, TestSpanTermQuery, TestMultiDocValues, TestBufferedChecksum, TestByteArrayDataInput, TestShardSearching, TestBytesStore, TestRollingUpdates, TestQueryRescorer, TestSearcherManager, TestFilterWeight, TestTopFieldCollector, TestParallelTermEnum, TestLongRangeFieldQueries, TestQueryBuilder, TestTwoPhaseCommitTool, TestNRTReaderWithThreads, TestSegmentTermDocs, TestSloppyMath, TestBytesRefArray, TestSimpleExplanationsWithFillerDocs, TestReqOptSumScorer, TestCharFilter, TestConjunctionDISI, TestDelegatingAnalyzerWrapper, TestDocumentWriter, TestNumericDocValuesUpdates, TestAllFilesDetectTruncation, TestBlockMaxConjunction, Test2BBKDPoints, TestAutomatonQueryUnicode, TestFieldType, TestPerSegmentDeletes, TestFileSwitchDirectory, TestWeakIdentityMap, TestMultiFields, TestMultiset, TestBytesRef, TestDocInverterPerFieldErrorInfo, TestStressDeletes, TestForUtil, TestIsCurrent, TestCompetitiveFreqNormAccumulator, TestIndexManyDocuments, TestDocumentsWriterStallControl, TestNumericUtils, TestNamedSPILoader, TestPayloadsOnVectors, TestAxiomaticF1EXP, TestBoolean2, TestNewestSegment, TestIndexWriterOnDiskFull, TestSearchForDuplicates, TestMergedIterator, TestPhraseQuery, TestFastCompressionMode, TestBooleanRewrites, TestSimpleSearchEquivalence, TestOmitNorms, TestMaxPosition, TestDisjunctionMaxQuery, TestEarlyTermination, TestBasicModelIn, TestSparseFixedBitSet, TestSimpleExplanations, TestNearSpansOrdered, Test2BPostings, TestIndexWriter, TestPerFieldDocValuesFormat, TestFSTs, TestPackedInts, TestGraphTokenizers, TestIndexWriterExceptions, TestMultiMMap, TestDeletionPolicy, TestBooleanOr, TestBasics, TestFlushByRamOrCountsPolicy, TestIndexWriterDelete, TestIndexWriterMergePolicy, TestNRTThreads, TestNorms, TestIndexWriterCommit, TestNeverDelete, TestLongPostings, TestStressIndexing, TestIndexWriterForceMerge, TestDirectoryReader, TestBagOfPositions, TestParallelCompositeReader, TestIndexWriterNRTIsCurrent, TestCrash, TestCustomSearcherSort, TestSimilarityBase, TestBooleanMinShouldMatch, TestTermsEnum2, Test2BDocs, TestMixedCodecs, TestUTF32ToUTF8, TestMultiPhraseQuery, TestMergeSchedulerExternal, TestTermVectorsWriter, TestCharTermAttributeImpl, TestBytesRefHash, TestTermRangeQuery, TestMultiTermConstantScore, TestForTooMuchCloning, TestPayloads, TestWildcard, TestNoDeletionPolicy, TestTermVectorsReader, TestPrefixInBooleanQuery, TestSortRandom, TestAutomatonQuery, TestSentinelIntSet, TestRegexpRandom, TestSpanMultiTermQueryWrapper, TestIndexFileDeleter] [junit4] Completed [336/486 (1!)] on J1 in 0.31s, 10 tests, 1 failure <<< FAILURES! [...truncated 10888 lines...] [junit4] Suite: org.apache.solr.response.transform.TestSubQueryTransformerDistrib [junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\init-core-data-001 [junit4] 2> 182257 WARN (SUITE-TestSubQueryTransformerDistrib-seed#[E456B4827472B745]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1 [junit4] 2> 182257 INFO (SUITE-TestSubQueryTransformerDistrib-seed#[E456B4827472B745]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false [junit4] 2> 182263 INFO (SUITE-TestSubQueryTransformerDistrib-seed#[E456B4827472B745]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) [junit4] 2> 182264 INFO (SUITE-TestSubQueryTransformerDistrib-seed#[E456B4827472B745]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> 182270 INFO (SUITE-TestSubQueryTransformerDistrib-seed#[E456B4827472B745]-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\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001 [junit4] 2> 182271 INFO (SUITE-TestSubQueryTransformerDistrib-seed#[E456B4827472B745]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 182271 INFO (Thread-591) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 182271 INFO (Thread-591) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 182276 ERROR (Thread-591) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 182372 INFO (SUITE-TestSubQueryTransformerDistrib-seed#[E456B4827472B745]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:52773 [junit4] 2> 182381 INFO (zkConnectionManagerCallback-545-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182386 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x100001d31280000, likely client has closed socket [junit4] 2> 182394 INFO (jetty-launcher-542-thread-4) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T17:27:37-04:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 182395 INFO (jetty-launcher-542-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 182395 INFO (jetty-launcher-542-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 182395 INFO (jetty-launcher-542-thread-4) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 182396 INFO (jetty-launcher-542-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@14f10d6{/solr,null,AVAILABLE} [junit4] 2> 182397 INFO (jetty-launcher-542-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@716b85{SSL,[ssl, http/1.1]}{127.0.0.1:52777} [junit4] 2> 182398 INFO (jetty-launcher-542-thread-4) [ ] o.e.j.s.Server Started @190465ms [junit4] 2> 182398 INFO (jetty-launcher-542-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52777} [junit4] 2> 182398 ERROR (jetty-launcher-542-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 182398 INFO (jetty-launcher-542-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 182398 INFO (jetty-launcher-542-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 182398 INFO (jetty-launcher-542-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 182398 INFO (jetty-launcher-542-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-24T10:31:08.240Z [junit4] 2> 182403 INFO (jetty-launcher-542-thread-3) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T17:27:37-04:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 182403 INFO (jetty-launcher-542-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 182403 INFO (jetty-launcher-542-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 182403 INFO (jetty-launcher-542-thread-3) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 182403 INFO (jetty-launcher-542-thread-5) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T17:27:37-04:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 182403 INFO (jetty-launcher-542-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1b20280{/solr,null,AVAILABLE} [junit4] 2> 182403 INFO (jetty-launcher-542-thread-5) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 182403 INFO (jetty-launcher-542-thread-5) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 182403 INFO (jetty-launcher-542-thread-5) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 182404 INFO (jetty-launcher-542-thread-5) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@9df90f{/solr,null,AVAILABLE} [junit4] 2> 182404 INFO (jetty-launcher-542-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@67f642{SSL,[ssl, http/1.1]}{127.0.0.1:52782} [junit4] 2> 182404 INFO (jetty-launcher-542-thread-3) [ ] o.e.j.s.Server Started @190472ms [junit4] 2> 182404 INFO (jetty-launcher-542-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52782} [junit4] 2> 182405 ERROR (jetty-launcher-542-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 182405 INFO (jetty-launcher-542-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 182405 INFO (jetty-launcher-542-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 182405 INFO (jetty-launcher-542-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 182405 INFO (jetty-launcher-542-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-24T10:31:08.247Z [junit4] 2> 182423 INFO (jetty-launcher-542-thread-5) [ ] o.e.j.s.AbstractConnector Started ServerConnector@b2e411{SSL,[ssl, http/1.1]}{127.0.0.1:52787} [junit4] 2> 182423 INFO (jetty-launcher-542-thread-5) [ ] o.e.j.s.Server Started @190491ms [junit4] 2> 182423 INFO (jetty-launcher-542-thread-5) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52787} [junit4] 2> 182424 ERROR (jetty-launcher-542-thread-5) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 182424 INFO (jetty-launcher-542-thread-5) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 182424 INFO (jetty-launcher-542-thread-5) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 182424 INFO (jetty-launcher-542-thread-5) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 182424 INFO (jetty-launcher-542-thread-5) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-24T10:31:08.266Z [junit4] 2> 182426 INFO (jetty-launcher-542-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T17:27:37-04:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 182427 INFO (jetty-launcher-542-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 182427 INFO (jetty-launcher-542-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 182427 INFO (jetty-launcher-542-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 182428 INFO (jetty-launcher-542-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1ebeb12{/solr,null,AVAILABLE} [junit4] 2> 182428 INFO (jetty-launcher-542-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T17:27:37-04:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 182429 INFO (jetty-launcher-542-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 182429 INFO (jetty-launcher-542-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 182429 INFO (jetty-launcher-542-thread-1) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 182429 INFO (jetty-launcher-542-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@15b4b86{SSL,[ssl, http/1.1]}{127.0.0.1:52795} [junit4] 2> 182430 INFO (jetty-launcher-542-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1deb3d6{/solr,null,AVAILABLE} [junit4] 2> 182430 INFO (jetty-launcher-542-thread-2) [ ] o.e.j.s.Server Started @190497ms [junit4] 2> 182430 INFO (jetty-launcher-542-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52795} [junit4] 2> 182431 ERROR (jetty-launcher-542-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 182431 INFO (jetty-launcher-542-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1b0e4f6{SSL,[ssl, http/1.1]}{127.0.0.1:52798} [junit4] 2> 182431 INFO (jetty-launcher-542-thread-1) [ ] o.e.j.s.Server Started @190498ms [junit4] 2> 182431 INFO (jetty-launcher-542-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 182431 INFO (jetty-launcher-542-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52798} [junit4] 2> 182431 INFO (jetty-launcher-542-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 182431 INFO (jetty-launcher-542-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 182431 INFO (jetty-launcher-542-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-24T10:31:08.273Z [junit4] 2> 182431 ERROR (jetty-launcher-542-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 182431 INFO (jetty-launcher-542-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0 [junit4] 2> 182431 INFO (jetty-launcher-542-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 182431 INFO (jetty-launcher-542-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 182431 INFO (jetty-launcher-542-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-24T10:31:08.273Z [junit4] 2> 182436 INFO (zkConnectionManagerCallback-547-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182437 INFO (jetty-launcher-542-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 182445 INFO (zkConnectionManagerCallback-549-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182445 INFO (jetty-launcher-542-thread-5) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 182457 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x100001d31280001, likely client has closed socket [junit4] 2> 182459 INFO (zkConnectionManagerCallback-555-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182459 INFO (zkConnectionManagerCallback-553-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182462 INFO (zkConnectionManagerCallback-551-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182465 INFO (jetty-launcher-542-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52773/solr [junit4] 2> 182467 INFO (jetty-launcher-542-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 182467 INFO (jetty-launcher-542-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 182470 INFO (jetty-launcher-542-thread-5) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52773/solr [junit4] 2> 182471 INFO (jetty-launcher-542-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 182485 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x100001d31280004, likely client has closed socket [junit4] 2> 182493 INFO (jetty-launcher-542-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52773/solr [junit4] 2> 182493 INFO (jetty-launcher-542-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52773/solr [junit4] 2> 182494 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x100001d31280003, likely client has closed socket [junit4] 2> 182497 INFO (jetty-launcher-542-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52773/solr [junit4] 2> 182499 INFO (zkConnectionManagerCallback-563-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182501 INFO (zkConnectionManagerCallback-559-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182503 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x100001d31280007, likely client has closed socket [junit4] 2> 182510 INFO (zkConnectionManagerCallback-571-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182510 INFO (zkConnectionManagerCallback-569-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182513 INFO (zkConnectionManagerCallback-575-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182513 INFO (zkConnectionManagerCallback-577-thread-1-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182513 INFO (zkConnectionManagerCallback-579-thread-1-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182520 INFO (zkConnectionManagerCallback-581-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182524 INFO (zkConnectionManagerCallback-583-thread-1-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182529 INFO (zkConnectionManagerCallback-585-thread-1-processing-n:127.0.0.1:52782_solr) [n:127.0.0.1:52782_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 182762 INFO (jetty-launcher-542-thread-2) [n:127.0.0.1:52795_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 182764 INFO (jetty-launcher-542-thread-1) [n:127.0.0.1:52798_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 182764 INFO (jetty-launcher-542-thread-2) [n:127.0.0.1:52795_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:52795_solr [junit4] 2> 182768 INFO (jetty-launcher-542-thread-1) [n:127.0.0.1:52798_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52798_solr [junit4] 2> 182768 INFO (jetty-launcher-542-thread-2) [n:127.0.0.1:52795_solr ] o.a.s.c.Overseer Overseer (id=72057719416684558-127.0.0.1:52795_solr-n_0000000000) starting [junit4] 2> 182768 INFO (jetty-launcher-542-thread-3) [n:127.0.0.1:52782_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 182775 INFO (jetty-launcher-542-thread-3) [n:127.0.0.1:52782_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52782_solr [junit4] 2> 182869 INFO (zkCallback-582-thread-1-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 182871 INFO (zkCallback-584-thread-1-processing-n:127.0.0.1:52782_solr) [n:127.0.0.1:52782_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 182872 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 182904 INFO (jetty-launcher-542-thread-2) [n:127.0.0.1:52795_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52795_solr [junit4] 2> 182914 INFO (zkCallback-584-thread-1-processing-n:127.0.0.1:52782_solr) [n:127.0.0.1:52782_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 182914 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 182914 INFO (zkCallback-582-thread-1-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 182951 INFO (jetty-launcher-542-thread-4) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 182952 INFO (jetty-launcher-542-thread-5) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 182956 INFO (jetty-launcher-542-thread-4) [n:127.0.0.1:52777_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 182956 INFO (jetty-launcher-542-thread-5) [n:127.0.0.1:52787_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 182958 INFO (jetty-launcher-542-thread-5) [n:127.0.0.1:52787_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52787_solr [junit4] 2> 182959 INFO (jetty-launcher-542-thread-4) [n:127.0.0.1:52777_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52777_solr [junit4] 2> 183020 INFO (zkCallback-582-thread-1-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5) [junit4] 2> 183020 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5) [junit4] 2> 183020 INFO (zkCallback-584-thread-1-processing-n:127.0.0.1:52782_solr) [n:127.0.0.1:52782_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5) [junit4] 2> 183021 INFO (zkCallback-578-thread-1-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5) [junit4] 2> 183022 INFO (zkCallback-576-thread-1-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5) [junit4] 2> 183058 INFO (jetty-launcher-542-thread-1) [n:127.0.0.1:52798_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52798.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183068 INFO (jetty-launcher-542-thread-1) [n:127.0.0.1:52798_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52798.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183068 INFO (jetty-launcher-542-thread-1) [n:127.0.0.1:52798_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52798.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183068 INFO (jetty-launcher-542-thread-1) [n:127.0.0.1:52798_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node5\. [junit4] 2> 183102 INFO (jetty-launcher-542-thread-2) [n:127.0.0.1:52795_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52795.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183124 INFO (jetty-launcher-542-thread-2) [n:127.0.0.1:52795_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52795.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183124 INFO (jetty-launcher-542-thread-2) [n:127.0.0.1:52795_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52795.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183126 INFO (jetty-launcher-542-thread-2) [n:127.0.0.1:52795_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node4\. [junit4] 2> 183133 INFO (jetty-launcher-542-thread-3) [n:127.0.0.1:52782_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52782.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183141 INFO (jetty-launcher-542-thread-3) [n:127.0.0.1:52782_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52782.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183141 INFO (jetty-launcher-542-thread-3) [n:127.0.0.1:52782_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52782.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183142 INFO (jetty-launcher-542-thread-3) [n:127.0.0.1:52782_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node3\. [junit4] 2> 183202 INFO (jetty-launcher-542-thread-4) [n:127.0.0.1:52777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52777.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183202 INFO (jetty-launcher-542-thread-5) [n:127.0.0.1:52787_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52787.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183207 INFO (jetty-launcher-542-thread-4) [n:127.0.0.1:52777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52777.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183207 INFO (jetty-launcher-542-thread-5) [n:127.0.0.1:52787_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52787.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183207 INFO (jetty-launcher-542-thread-4) [n:127.0.0.1:52777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52777.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183207 INFO (jetty-launcher-542-thread-5) [n:127.0.0.1:52787_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52787.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 183212 INFO (jetty-launcher-542-thread-4) [n:127.0.0.1:52777_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node2\. [junit4] 2> 183212 INFO (jetty-launcher-542-thread-5) [n:127.0.0.1:52787_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node1\. [junit4] 2> 183302 INFO (zkConnectionManagerCallback-597-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 183308 INFO (zkConnectionManagerCallback-601-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 183309 INFO (SUITE-TestSubQueryTransformerDistrib-seed#[E456B4827472B745]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 183310 INFO (SUITE-TestSubQueryTransformerDistrib-seed#[E456B4827472B745]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:52773/solr ready [junit4] 2> 183898 INFO (qtp30702434-2531) [n:127.0.0.1:52777_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&collection.configName=solrCloudCollectionConfig&name=people&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 183900 INFO (OverseerThreadFactory-1299-thread-1-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection people [junit4] 2> 184018 INFO (OverseerStateUpdate-72057719416684558-127.0.0.1:52795_solr-n_0000000000) [n:127.0.0.1:52795_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"people", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"people_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:52795/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 184022 INFO (OverseerStateUpdate-72057719416684558-127.0.0.1:52795_solr-n_0000000000) [n:127.0.0.1:52795_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"people", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"people_shard1_replica_n2", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:52787/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 184025 INFO (OverseerStateUpdate-72057719416684558-127.0.0.1:52795_solr-n_0000000000) [n:127.0.0.1:52795_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"people", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"people_shard2_replica_n4", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:52798/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 184028 INFO (OverseerStateUpdate-72057719416684558-127.0.0.1:52795_solr-n_0000000000) [n:127.0.0.1:52795_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"people", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"people_shard2_replica_n6", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:52777/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 184281 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=people&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&coreNodeName=core_node8&name=people_shard2_replica_n6&action=CREATE&numShards=2&shard=shard2&wt=javabin [junit4] 2> 184282 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 184333 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=people&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&coreNodeName=core_node7&name=people_shard2_replica_n4&action=CREATE&numShards=2&shard=shard2&wt=javabin [junit4] 2> 184334 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 184337 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=people&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&coreNodeName=core_node5&name=people_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin [junit4] 2> 184338 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 184346 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=people&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&coreNodeName=core_node3&name=people_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin [junit4] 2> 184347 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 184481 INFO (zkCallback-582-thread-1-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 184481 INFO (zkCallback-578-thread-1-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 184481 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 184482 INFO (zkCallback-576-thread-1-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 184483 INFO (zkCallback-578-thread-2-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 184483 INFO (zkCallback-582-thread-2-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 184483 INFO (zkCallback-576-thread-2-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 184483 INFO (zkCallback-580-thread-2-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 185369 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 185379 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.s.IndexSchema [people_shard2_replica_n6] Schema name=doc-values-for-Join [junit4] 2> 185390 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.s.IndexSchema Loaded schema doc-values-for-Join/1.6 with uniqueid field id [junit4] 2> 185390 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 185411 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 185415 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 185424 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.s.IndexSchema [people_shard2_replica_n4] Schema name=doc-values-for-Join [junit4] 2> 185431 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.s.IndexSchema Loaded schema doc-values-for-Join/1.6 with uniqueid field id [junit4] 2> 185431 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.s.IndexSchema [people_shard1_replica_n1] Schema name=doc-values-for-Join [junit4] 2> 185432 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.s.IndexSchema [people_shard1_replica_n2] Schema name=doc-values-for-Join [junit4] 2> 185439 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema doc-values-for-Join/1.6 with uniqueid field id [junit4] 2> 185439 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema doc-values-for-Join/1.6 with uniqueid field id [junit4] 2> 185439 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'people_shard2_replica_n6' using configuration from collection people, trusted=true [junit4] 2> 185440 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52777.solr.core.people.shard2.replica_n6' (registry 'solr.core.people.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 185440 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 185440 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.c.SolrCore [[people_shard2_replica_n6] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node2\people_shard2_replica_n6], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node2\.\people_shard2_replica_n6\data\] [junit4] 2> 185444 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'people_shard2_replica_n4' using configuration from collection people, trusted=true [junit4] 2> 185445 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52798.solr.core.people.shard2.replica_n4' (registry 'solr.core.people.shard2.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 185445 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 185445 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.SolrCore [[people_shard2_replica_n4] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node5\people_shard2_replica_n4], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node5\.\people_shard2_replica_n4\data\] [junit4] 2> 185446 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'people_shard1_replica_n1' using configuration from collection people, trusted=true [junit4] 2> 185446 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'people_shard1_replica_n2' using configuration from collection people, trusted=true [junit4] 2> 185446 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52795.solr.core.people.shard1.replica_n1' (registry 'solr.core.people.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 185446 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_52787.solr.core.people.shard1.replica_n2' (registry 'solr.core.people.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@e434d8 [junit4] 2> 185446 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 185446 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 185446 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.SolrCore [[people_shard1_replica_n2] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node1\people_shard1_replica_n2], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node1\.\people_shard1_replica_n2\data\] [junit4] 2> 185446 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.c.SolrCore [[people_shard1_replica_n1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node4\people_shard1_replica_n1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.response.transform.TestSubQueryTransformerDistrib_E456B4827472B745-001\tempDir-001\node4\.\people_shard1_replica_n1\data\] [junit4] 2> 185596 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 185596 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 185599 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 185599 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 185600 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 185601 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 185602 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 185602 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 185602 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 185602 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 185602 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 185604 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 185605 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@a68626[people_shard1_replica_n2] main] [junit4] 2> 185607 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 185607 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@47f4d3[people_shard2_replica_n6] main] [junit4] 2> 185608 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@158557[people_shard2_replica_n4] main] [junit4] 2> 185609 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 185609 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 185609 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 185610 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593277962206052352 [junit4] 2> 185611 INFO (searcherExecutor-1312-thread-1-processing-n:127.0.0.1:52787_solr x:people_shard1_replica_n2 s:shard1 c:people r:core_node5) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.SolrCore [people_shard1_replica_n2] Registered new searcher Searcher@a68626[people_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 185611 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 185613 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 185613 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593277962209198080 [junit4] 2> 185614 INFO (searcherExecutor-1310-thread-1-processing-n:127.0.0.1:52798_solr x:people_shard2_replica_n4 s:shard2 c:people r:core_node7) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.SolrCore [people_shard2_replica_n4] Registered new searcher Searcher@158557[people_shard2_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 185637 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 185638 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 185639 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 185639 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593277962236461056 [junit4] 2> 185641 INFO (searcherExecutor-1309-thread-1-processing-n:127.0.0.1:52777_solr x:people_shard2_replica_n6 s:shard2 c:people r:core_node8) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.c.SolrCore [people_shard2_replica_n6] Registered new searcher Searcher@47f4d3[people_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 185648 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 185648 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 185649 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.c.ZkShardTerms Failed to save terms, version is not match, retrying [junit4] 2> 185651 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 185651 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 185659 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 185659 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 185659 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:52798/solr/people_shard2_replica_n4/ [junit4] 2> 185660 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.u.PeerSync PeerSync: core=people_shard2_replica_n4 url=https://127.0.0.1:52798/solr START replicas=[https://127.0.0.1:52777/solr/people_shard2_replica_n6/] nUpdates=100 [junit4] 2> 185660 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9998ms [junit4] 2> 185666 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1a0d43a[people_shard1_replica_n1] main] [junit4] 2> 185680 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 185680 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 185680 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 185680 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593277962279452672 [junit4] 2> 185680 INFO (searcherExecutor-1311-thread-1-processing-n:127.0.0.1:52795_solr x:people_shard1_replica_n1 s:shard1 c:people r:core_node3) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.c.SolrCore [people_shard1_replica_n1] Registered new searcher Searcher@1a0d43a[people_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 185703 INFO (qtp30702434-2561) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.c.S.Request [people_shard2_replica_n6] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=23 [junit4] 2> 185763 INFO (zkCallback-578-thread-2-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 185763 INFO (zkCallback-578-thread-1-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 185763 INFO (zkCallback-582-thread-2-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 185763 INFO (zkCallback-582-thread-1-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 185763 INFO (zkCallback-580-thread-2-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 185763 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 185763 INFO (zkCallback-576-thread-2-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 185763 INFO (zkCallback-576-thread-1-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 185961 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.u.PeerSync PeerSync: core=people_shard2_replica_n4 url=https://127.0.0.1:52798/solr DONE. We have no versions. sync failed. [junit4] 2> 185961 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate [junit4] 2> 185961 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway [junit4] 2> 185961 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 185966 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:52798/solr/people_shard2_replica_n4/ shard2 [junit4] 2> 186069 INFO (zkCallback-578-thread-1-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186069 INFO (zkCallback-582-thread-1-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186069 INFO (zkCallback-582-thread-2-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186069 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186069 INFO (zkCallback-576-thread-2-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186069 INFO (zkCallback-576-thread-1-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186069 INFO (zkCallback-578-thread-2-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186069 INFO (zkCallback-580-thread-2-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186118 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 186127 INFO (qtp27849098-2582) [n:127.0.0.1:52798_solr c:people s:shard2 r:core_node7 x:people_shard2_replica_n4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=people&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&coreNodeName=core_node7&name=people_shard2_replica_n4&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=1796 [junit4] 2> 186161 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 186161 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 186161 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:52787/solr/people_shard1_replica_n2/ [junit4] 2> 186161 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.u.PeerSync PeerSync: core=people_shard1_replica_n2 url=https://127.0.0.1:52787/solr START replicas=[https://127.0.0.1:52795/solr/people_shard1_replica_n1/] nUpdates=100 [junit4] 2> 186174 INFO (qtp8247311-2571) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.c.S.Request [people_shard1_replica_n1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 186229 INFO (zkCallback-580-thread-2-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186229 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186229 INFO (zkCallback-576-thread-1-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186229 INFO (zkCallback-576-thread-2-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186229 INFO (zkCallback-582-thread-3-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186229 INFO (zkCallback-582-thread-2-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186229 INFO (zkCallback-578-thread-2-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186229 INFO (zkCallback-578-thread-1-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186461 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.u.PeerSync PeerSync: core=people_shard1_replica_n2 url=https://127.0.0.1:52787/solr DONE. We have no versions. sync failed. [junit4] 2> 186461 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate [junit4] 2> 186461 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway [junit4] 2> 186461 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 186466 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:52787/solr/people_shard1_replica_n2/ shard1 [junit4] 2> 186570 INFO (zkCallback-582-thread-3-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186570 INFO (zkCallback-578-thread-1-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186570 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186570 INFO (zkCallback-578-thread-2-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186570 INFO (zkCallback-576-thread-2-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186570 INFO (zkCallback-576-thread-1-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186570 INFO (zkCallback-582-thread-2-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186570 INFO (zkCallback-580-thread-2-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186620 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 186623 INFO (qtp10372088-2552) [n:127.0.0.1:52787_solr c:people s:shard1 r:core_node5 x:people_shard1_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=people&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&coreNodeName=core_node5&name=people_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2286 [junit4] 2> 186665 INFO (qtp30702434-2530) [n:127.0.0.1:52777_solr c:people s:shard2 r:core_node8 x:people_shard2_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=people&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&coreNodeName=core_node8&name=people_shard2_replica_n6&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=2384 [junit4] 2> 186685 INFO (qtp8247311-2570) [n:127.0.0.1:52795_solr c:people s:shard1 r:core_node3 x:people_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=people&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&coreNodeName=core_node3&name=people_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2338 [junit4] 2> 186696 INFO (qtp30702434-2531) [n:127.0.0.1:52777_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> 186784 INFO (zkCallback-582-thread-2-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186784 INFO (zkCallback-578-thread-2-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186784 INFO (zkCallback-582-thread-3-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186784 INFO (zkCallback-580-thread-2-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186784 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186784 INFO (zkCallback-576-thread-1-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186784 INFO (zkCallback-576-thread-2-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 186784 INFO (zkCallback-578-thread-1-processing-n:127.0.0.1:52777_solr) [n:127.0.0.1:52777_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/people/state.json] for collection [people] has occurred - updating... (live nodes size: [5]) [junit4] 2> 187696 INFO (qtp30702434-2531) [n:127.0.0.1:52777_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&property.config=solrconfig-doctransformers.xml&property.schema=schema-docValuesJoin.xml&collection.configName=solrCloudCollectionConfig&name=people&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3798 [junit4] 2> 187697 INFO (qtp30702434-2533) [n:127.0.0.1:52777_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&property.config=solrconfig-doctransformers.xml&property.schema=schema-minimal-with-another-uniqkey.xml&collection.configName=solrCloudCollectionConfig&name=departments&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 187700 INFO (OverseerThreadFactory-1299-thread-2-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection departments [junit4] 2> 187700 INFO (OverseerCollectionConfigSetProcessor-72057719416684558-127.0.0.1:52795_solr-n_0000000000) [n:127.0.0.1:52795_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 187910 INFO (OverseerStateUpdate-72057719416684558-127.0.0.1:52795_solr-n_0000000000) [n:127.0.0.1:52795_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"departments", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"departments_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:52787/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 187915 INFO (OverseerStateUpdate-72057719416684558-127.0.0.1:52795_solr-n_0000000000) [n:127.0.0.1:52795_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"departments", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"departments_shard1_replica_n2", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:52798/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 187918 INFO (OverseerStateUpdate-72057719416684558-127.0.0.1:52795_solr-n_0000000000) [n:127.0.0.1:52795_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"departments", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"departments_shard2_replica_n4", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:52795/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 187922 INFO (OverseerStateUpdate-72057719416684558-127.0.0.1:52795_solr-n_0000000000) [n:127.0.0.1:52795_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"departments", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"departments_shard2_replica_n6", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:52782/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 188130 INFO (qtp10372088-2551) [n:127.0.0.1:52787_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=departments&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-minimal-with-another-uniqkey.xml&coreNodeName=core_node3&name=departments_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin [junit4] 2> 188130 INFO (qtp8247311-2573) [n:127.0.0.1:52795_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=departments&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-minimal-with-another-uniqkey.xml&coreNodeName=core_node7&name=departments_shard2_replica_n4&action=CREATE&numShards=2&shard=shard2&wt=javabin [junit4] 2> 188143 INFO (qtp27849098-2584) [n:127.0.0.1:52798_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=departments&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-minimal-with-another-uniqkey.xml&coreNodeName=core_node5&name=departments_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin [junit4] 2> 188209 INFO (qtp31631981-2542) [n:127.0.0.1:52782_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&collection=departments&version=2&replicaType=NRT&property.config=solrconfig-doctransformers.xml&property.schema=schema-minimal-with-another-uniqkey.xml&coreNodeName=core_node8&name=departments_shard2_replica_n6&action=CREATE&numShards=2&shard=shard2&wt=javabin [junit4] 2> 188211 INFO (qtp31631981-2542) [n:127.0.0.1:52782_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 188342 INFO (zkCallback-582-thread-3-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/departments/state.json] for collection [departments] has occurred - updating... (live nodes size: [5]) [junit4] 2> 188342 INFO (zkCallback-582-thread-2-processing-n:127.0.0.1:52795_solr) [n:127.0.0.1:52795_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/departments/state.json] for collection [departments] has occurred - updating... (live nodes size: [5]) [junit4] 2> 188342 INFO (zkCallback-580-thread-1-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/departments/state.json] for collection [departments] has occurred - updating... (live nodes size: [5]) [junit4] 2> 188343 INFO (zkCallback-580-thread-2-processing-n:127.0.0.1:52798_solr) [n:127.0.0.1:52798_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/departments/state.json] for collection [departments] has occurred - updating... (live nodes size: [5]) [junit4] 2> 188343 INFO (zkCallback-584-thread-1-processing-n:127.0.0.1:52782_solr) [n:127.0.0.1:52782_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/departments/state.json] for collection [departments] has occurred - updating... (live nodes size: [5]) [junit4] 2> 188344 INFO (zkCallback-576-thread-2-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/departments/state.json] for collection [departments] has occurred - updating... (live nodes size: [5]) [junit4] 2> 188344 INFO (zkCallback-576-thread-1-processing-n:127.0.0.1:52787_solr) [n:127.0.0.1:52787_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/departments/state.json] for collection [departments] has occurred - updating... (live nodes size: [5]) [junit4] 2> 188347 INFO (zkCallback-584-thread-2-processing-n:127.0.0.1:52782_solr) [n:127.0.0.1:52782_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/departments/state.json] for collection [departments] has occurred - updating... (live nodes size: [5]) [junit4] 2> 189305 INFO (qtp31631981-2542) [n:127.0.0.1:52782_solr c:departments s:shard2 r:core_node8 x:departments_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 189 [...truncated too long message...] 1] o.a.s.c.S.Request [collection1] webapp=/solr path=/query params={fv=true&q=*:*&indent=on&fl=*,+score,fv:[fv]&rows=4&wt=json&rq={!ltr+model%3Dnomatchmodel+reRankDocs%3D4}} hits=8 status=0 QTime=0 [junit4] 2> 19634 INFO (TEST-TestNoMatchSolrFeature.test2NoMatch1YesMatchFeatureReturnsFvWith1FeatureAndDocScoreScaledByModel-seed#[76E8BFB95D577630]) [ ] o.a.s.SolrTestCaseJ4 ###Ending test2NoMatch1YesMatchFeatureReturnsFvWith1FeatureAndDocScoreScaledByModel [junit4] 2> 19636 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@f33511{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 19636 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=26340482 [junit4] 2> 19636 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 19636 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 19637 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 19642 INFO (coreCloseExecutor-49-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@ec4b24 [junit4] 2> 19642 INFO (coreCloseExecutor-49-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=15485732 [junit4] 2> 19652 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1e874db{/solr,null,UNAVAILABLE} [junit4] 2> 19652 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 19661 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> 19662 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=21285153 [junit4] 2> 19662 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 19662 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3e4152: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / null [junit4] 2> 19662 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 19662 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@ab273d: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / null [junit4] 2> 19662 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 19662 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1391db2: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / null [junit4] 2> 19664 INFO (coreCloseExecutor-51-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@8f3547 [junit4] 2> 19664 INFO (coreCloseExecutor-51-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=9385287 [junit4] 2> 19664 INFO (coreCloseExecutor-51-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@419eab: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / null [junit4] 2> 19668 INFO (SUITE-TestNoMatchSolrFeature-seed#[76E8BFB95D577630]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {description=PostingsFormat(name=Memory), id=PostingsFormat(name=LuceneFixedGap), text=PostingsFormat(name=LuceneVarGapDocFreqInterval), title=PostingsFormat(name=LuceneVarGapFixedInterval)}, docValues:{}, maxPointsInLeafNode=1562, maxMBSortInHeap=6.473563588640033, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@2c2cd6), locale=bg-BG, timezone=America/Matamoros [junit4] 2> NOTE: Windows 10 10.0 x86/Oracle Corporation 1.8.0_144 (32-bit)/cpus=3,threads=1,free=24316656,total=64880640 [junit4] 2> NOTE: All tests run in this JVM: [TestUserTermScoreWithQ, TestNoMatchSolrFeature] [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestNoMatchSolrFeature -Dtests.seed=76E8BFB95D577630 -Dtests.slow=true -Dtests.locale=bg-BG -Dtests.timezone=America/Matamoros -Dtests.asserts=true -Dtests.file.encoding=Cp1252 [junit4] ERROR 0.00s J0 | TestNoMatchSolrFeature (suite) <<< [junit4] > Throwable #1: java.io.IOException: Could not remove the following files (in the order of attempts): [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores\core\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores\core\data\tlog [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores\core\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores\core\data [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores\core: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores\core [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003 [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores\core\data\tlog\tlog.0000000000000000000: java.nio.file.AccessDeniedException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001\tempDir-003\cores\core\data\tlog\tlog.0000000000000000000 [junit4] > C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\contrib\solr-ltr\test\J0\temp\solr.ltr.feature.TestNoMatchSolrFeature_76E8BFB95D577630-001 [junit4] > at __randomizedtesting.SeedInfo.seed([76E8BFB95D577630]:0) [junit4] > at org.apache.lucene.util.IOUtils.rm(IOUtils.java:329) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] Completed [5/36 (1!)] on J0 in 1.48s, 4 tests, 1 error <<< FAILURES! [...truncated 36779 lines...] [repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/7190/consoleText [repro] Revision: 4e198a273763e27122a00243e3694d28f1e5b3a4 [repro] Ant options: "-Dargs=-server -XX:+UseConcMarkSweepGC" [repro] ant clean [...truncated 8 lines...] [repro] Traceback (most recent call last): [...truncated 30 lines...] ERROR: Step ‘Publish JUnit test result report’ failed: No test report files were found. Configuration error? Email was triggered for: Failure - Any Sending email for trigger: Failure - Any Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2 Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2 Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2 Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org