You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2020/02/06 12:21:09 UTC
[JENKINS] Lucene-Solr-Tests-master - Build # 4172 - Still Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/4172/
1 tests failed.
FAILED: org.apache.lucene.index.TestTransactions.testTransactions
Error Message:
MockDirectoryWrapper: cannot close: there are still 1 open files: {_3o_Lucene85FieldsIndexfile_pointers_ej.tmp=1}
Stack Trace:
java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still 1 open files: {_3o_Lucene85FieldsIndexfile_pointers_ej.tmp=1}
at __randomizedtesting.SeedInfo.seed([AF399153E9E3534F:6CAB2D9BBD77BA4B]:0)
at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:807)
at org.apache.lucene.index.TestTransactions.testTransactions(TestTransactions.java:269)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.RuntimeException: unclosed IndexOutput: _3o_Lucene85FieldsIndexfile_pointers_ej.tmp
at org.apache.lucene.store.MockDirectoryWrapper.addFileHandle(MockDirectoryWrapper.java:725)
at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:706)
at org.apache.lucene.store.FilterDirectory.createTempOutput(FilterDirectory.java:79)
at org.apache.lucene.store.FilterDirectory.createTempOutput(FilterDirectory.java:79)
at org.apache.lucene.store.TrackingDirectoryWrapper.createTempOutput(TrackingDirectoryWrapper.java:51)
at org.apache.lucene.codecs.compressing.FieldsIndexWriter.<init>(FieldsIndexWriter.java:87)
at org.apache.lucene.codecs.compressing.CompressingStoredFieldsWriter.<init>(CompressingStoredFieldsWriter.java:117)
at org.apache.lucene.codecs.compressing.CompressingStoredFieldsFormat.fieldsWriter(CompressingStoredFieldsFormat.java:130)
at org.apache.lucene.codecs.lucene50.Lucene50StoredFieldsFormat.fieldsWriter(Lucene50StoredFieldsFormat.java:145)
at org.apache.lucene.codecs.asserting.AssertingStoredFieldsFormat.fieldsWriter(AssertingStoredFieldsFormat.java:48)
at org.apache.lucene.index.SegmentMerger.mergeFields(SegmentMerger.java:228)
at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4446)
at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4040)
at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
Build Log:
[...truncated 1712 lines...]
[junit4] Suite: org.apache.lucene.index.TestTransactions
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTransactions -Dtests.method=testTransactions -Dtests.seed=AF399153E9E3534F -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=sn-ZW -Dtests.timezone=Mexico/BajaSur -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 1.37s J1 | TestTransactions.testTransactions <<<
[junit4] > Throwable #1: java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still 1 open files: {_3o_Lucene85FieldsIndexfile_pointers_ej.tmp=1}
[junit4] > at __randomizedtesting.SeedInfo.seed([AF399153E9E3534F:6CAB2D9BBD77BA4B]:0)
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:807)
[junit4] > at org.apache.lucene.index.TestTransactions.testTransactions(TestTransactions.java:269)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] > Caused by: java.lang.RuntimeException: unclosed IndexOutput: _3o_Lucene85FieldsIndexfile_pointers_ej.tmp
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.addFileHandle(MockDirectoryWrapper.java:725)
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:706)
[junit4] > at org.apache.lucene.store.FilterDirectory.createTempOutput(FilterDirectory.java:79)
[junit4] > at org.apache.lucene.store.FilterDirectory.createTempOutput(FilterDirectory.java:79)
[junit4] > at org.apache.lucene.store.TrackingDirectoryWrapper.createTempOutput(TrackingDirectoryWrapper.java:51)
[junit4] > at org.apache.lucene.codecs.compressing.FieldsIndexWriter.<init>(FieldsIndexWriter.java:87)
[junit4] > at org.apache.lucene.codecs.compressing.CompressingStoredFieldsWriter.<init>(CompressingStoredFieldsWriter.java:117)
[junit4] > at org.apache.lucene.codecs.compressing.CompressingStoredFieldsFormat.fieldsWriter(CompressingStoredFieldsFormat.java:130)
[junit4] > at org.apache.lucene.codecs.lucene50.Lucene50StoredFieldsFormat.fieldsWriter(Lucene50StoredFieldsFormat.java:145)
[junit4] > at org.apache.lucene.codecs.asserting.AssertingStoredFieldsFormat.fieldsWriter(AssertingStoredFieldsFormat.java:48)
[junit4] > at org.apache.lucene.index.SegmentMerger.mergeFields(SegmentMerger.java:228)
[junit4] > at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
[junit4] > at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4446)
[junit4] > at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4040)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {contents=PostingsFormat(name=Direct), id=Lucene84}, docValues:{}, maxPointsInLeafNode=853, maxMBSortInHeap=7.398746370631562, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@36e85c4c), locale=sn-ZW, timezone=Mexico/BajaSur
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=1,free=142256464,total=328204288
[junit4] 2> NOTE: All tests run in this JVM: [TestSubScorerFreqs, TestBKDRadixSelector, TestStopFilter, TestIndexWriterUnicode, TestSegmentToThreadMapping, TestFilterDirectoryReader, TestDirectoryReader, TestFlex, TestMinimize, TestDateSort, TestParallelLeafReader, TestLongDistanceFeatureQuery, TestBufferedChecksum, TestLatLonPolygonShapeQueries, TestMultiPhraseQuery, TestPForUtil, TestBooleanRewrites, TestCrash, Test2BPagedBytes, TestDistributionLL, TestAxiomaticF2EXP, TestSetOnce, TestUpgradeIndexMergePolicy, TestForDeltaUtil, TestCustomTermFreq, TestLucene60PointsFormat, TestXYMultiLineShapeQueries, TestDocsAndPositions, TestFilterWeight, TestDirectory, TestForceMergeForever, TestIndexOptions, TestBytesRefArray, TestRateLimiter, TestDirectPacked, TestWeakIdentityMap, TestLSBRadixSorter, TestBitUtil, TestCachingTokenFilter, TestIndexFileDeleter, TestLowercaseAsciiCompression, TestUTF32ToUTF8, TestOfflineSorter, TestSparseFixedBitDocIdSet, TestIntroSelector, TestFSTDirectAddressing, TestPolygon, TestDocument, TestGraphTokenFilter, TestBagOfPostings, TestSegmentReader, TestXYPointShapeQueries, TestSpanFirstQuery, TestLockFactory, TestNGramPhraseQuery, Test2BTerms, TestTermsEnum2, TestPayloads, TestWildcardRandom, TestMultiLevelSkipList, TestIndexWriterMergePolicy, TestDocCount, TestStringMSBRadixSorter, TestNearSpansOrdered, TestByteSlices, TestLMJelinekMercerSimilarity, TestBasicModelIne, TestDocValues, TermInSetQueryTest, TestXYShapeEncoding, TestSoftDeletesDirectoryReaderWrapper, TestDocIdSetBuilder, TestSingleInstanceLockFactory, Test2BPostingsBytes, TestReadOnlyIndex, TestConstantScoreScorer, TestCachingCollector, TestFastDecompressionMode, TestAutomaton, TestMSBRadixSorter, TestIndexWriterConfig, TestBasicModelG, TestMaxClauseLimit, TestSearchWithThreads, TestStressIndexing2, TestDuelingCodecsAtNight, TestIsCurrent, TestNamedSPILoader, Test2BPoints, TestDemo, TestReaderWrapperDVTypeCheck, TestMergeSchedulerExternal, TestSearch, TestSearchForDuplicates, TestCharArraySet, TestCharFilter, TestCharacterUtils, TestWordlistLoader, TestStandardAnalyzer, TestBytesRefAttImpl, TestCharTermAttributeImpl, TestPackedTokenAttributeImpl, TestSimpleAttributeImpl, TestCodecUtil, TestCompetitiveFreqNormAccumulator, TestLucene50CompoundFormat, TestLucene50StoredFieldsFormatHighCompression, TestLucene50TermVectorsFormat, TestLucene80DocValuesFormat, TestAllFilesDetectTruncation, TestAllFilesHaveCodecHeader, TestCodecHoldsOpenFiles, TestDocumentWriter, TestDocumentsWriterStallControl, TestIndexWriterDeleteByQuery, TestIndexWriterExceptions, TestIndexWriterExceptions2, TestIndexWriterFromReader, TestIndexWriterOnDiskFull, TestIndexWriterOnJRECrash, TestIndexWriterOnVMError, TestIndexWriterOutOfFileDescriptors, TestInfoStream, TestLongPostings, TestMixedCodecs, TestNRTThreads, TestNewestSegment, TestNoDeletionPolicy, TestNoMergePolicy, TestNoMergeScheduler, TestNorms, TestOmitNorms, TestOmitTf, TestOrdinalMap, TestPendingSoftDeletes, TestPersistentSnapshotDeletionPolicy, TestPostingsOffsets, TestSegmentInfos, TestStressAdvance, TestTermVectors, TestTermdocPerf, TestTragicIndexWriterDeadlock, TestTransactions]
[junit4] Completed [414/552 (1!)] on J1 in 1.39s, 1 test, 1 error <<< FAILURES!
[...truncated 66322 lines...]
[JENKINS] Lucene-Solr-Tests-master - Build # 4174 - Still Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/4174/
1 tests failed.
FAILED: org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat
Error Message:
No live SolrServers available to handle this request:[https://127.0.0.1:35663/solr/.system]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[https://127.0.0.1:35663/solr/.system]
at __randomizedtesting.SeedInfo.seed([1268FEEBC0AD8D41:629D5D42A0652437]:0)
at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:345)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.sendRequest(BaseCloudSolrClient.java:1143)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.requestWithRetryOnStaleState(BaseCloudSolrClient.java:906)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.request(BaseCloudSolrClient.java:838)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207)
at org.apache.solr.cloud.SystemCollectionCompatTest.setupSystemCollection(SystemCollectionCompatTest.java:118)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:976)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: https://127.0.0.1:35663/solr/.system
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:676)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:265)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
at org.apache.solr.client.solrj.impl.LBSolrClient.doRequest(LBSolrClient.java:368)
at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:296)
... 43 more
Caused by: java.net.SocketTimeoutException: Read timed out
at java.base/java.net.SocketInputStream.socketRead0(Native Method)
at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:168)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140)
at java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:448)
at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68)
at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1104)
at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:823)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:157)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:564)
... 47 more
Build Log:
[...truncated 13503 lines...]
[junit4] Suite: org.apache.solr.cloud.SystemCollectionCompatTest
[junit4] 2> 959747 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 959747 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/data-dir-61-001
[junit4] 2> 959747 WARN (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=84 numCloses=84
[junit4] 2> 959747 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 959748 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 959749 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/tempDir-001
[junit4] 2> 959750 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 959750 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 959750 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 959853 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:43537
[junit4] 2> 959853 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:43537
[junit4] 2> 959853 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:43537
[junit4] 2> 959853 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 43537
[junit4] 2> 959855 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 959857 INFO (zkConnectionManagerCallback-7122-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 959858 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 959870 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 959872 INFO (zkConnectionManagerCallback-7124-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 959872 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 959874 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 959876 INFO (zkConnectionManagerCallback-7126-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 959876 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 959986 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 959986 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 959986 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 959986 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 959986 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 959986 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 959986 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 959986 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 959991 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 959991 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 959991 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 959992 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4cac84ea{/solr,null,AVAILABLE}
[junit4] 2> 959993 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@48d01390{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:35663}
[junit4] 2> 959993 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.Server Started @960021ms
[junit4] 2> 959993 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35663}
[junit4] 2> 959997 ERROR (jetty-launcher-7127-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 959997 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 959997 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 959997 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 959997 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr
[junit4] 2> 959997 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-06T15:37:40.248219Z
[junit4] 2> 959998 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 959998 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 959998 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 959999 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@444a7d53{/solr,null,AVAILABLE}
[junit4] 2> 960000 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@d57cd10{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:38663}
[junit4] 2> 960000 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.Server Started @960028ms
[junit4] 2> 960000 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=38663}
[junit4] 2> 960000 ERROR (jetty-launcher-7127-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 960000 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 960000 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 960000 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 960000 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr
[junit4] 2> 960000 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-06T15:37:40.251452Z
[junit4] 2> 960000 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 960002 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 960003 INFO (zkConnectionManagerCallback-7129-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 960003 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 960003 INFO (zkConnectionManagerCallback-7131-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 960003 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 960004 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 960004 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 960472 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 960473 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@285d81da[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 960473 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@285d81da[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 960476 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7642c40[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 960476 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7642c40[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 960478 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43537/solr
[junit4] 2> 960480 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 960481 INFO (zkConnectionManagerCallback-7139-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 960481 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 960584 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 960585 INFO (zkConnectionManagerCallback-7141-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 960585 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 960645 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:38663_solr
[junit4] 2> 960646 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.c.Overseer Overseer (id=73199562327523334-127.0.0.1:38663_solr-n_0000000000) starting
[junit4] 2> 960650 INFO (OverseerStateUpdate-73199562327523334-127.0.0.1:38663_solr-n_0000000000) [n:127.0.0.1:38663_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:38663_solr
[junit4] 2> 960652 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38663_solr
[junit4] 2> 960654 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 960654 WARN (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 960660 INFO (zkCallback-7140-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 960680 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 960703 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38663.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17121d2c
[junit4] 2> 960710 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38663.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17121d2c
[junit4] 2> 960710 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38663.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17121d2c
[junit4] 2> 960711 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:38663_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/tempDir-001/node2/.
[junit4] 2> 960805 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 960806 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@79b5cae2[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 960806 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@79b5cae2[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 960809 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@75aae7d9[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 960809 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@75aae7d9[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 960811 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43537/solr
[junit4] 2> 960811 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 960814 INFO (zkConnectionManagerCallback-7151-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 960814 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 960917 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 960918 INFO (zkConnectionManagerCallback-7153-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 960918 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 960927 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 960929 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:35663_solr as DOWN
[junit4] 2> 960930 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 960930 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35663_solr
[junit4] 2> 960931 INFO (zkCallback-7140-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 960932 INFO (zkCallback-7152-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 960936 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 960937 WARN (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 960952 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 960970 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35663.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17121d2c
[junit4] 2> 960980 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35663.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17121d2c
[junit4] 2> 960980 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35663.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17121d2c
[junit4] 2> 960981 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:35663_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/tempDir-001/node1/.
[junit4] 2> 961005 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 961008 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 961012 INFO (zkConnectionManagerCallback-7162-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 961012 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 961013 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 961014 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43537/solr ready
[junit4] 2> 961026 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[1268FEEBC0AD8D41]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBackCompat
[junit4] 2> 961032 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[1268FEEBC0AD8D41]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 961039 INFO (zkConnectionManagerCallback-7167-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 961039 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[1268FEEBC0AD8D41]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 961040 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[1268FEEBC0AD8D41]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 961041 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[1268FEEBC0AD8D41]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43537/solr ready
[junit4] 2> 961083 INFO (qtp1118646542-18303) [n:127.0.0.1:38663_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 961091 INFO (qtp1118646542-18303) [n:127.0.0.1:38663_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 961102 INFO (qtp1118646542-18307) [n:127.0.0.1:38663_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params maxShardsPerNode=2&name=.system&nrtReplicas=2&action=CREATE&numShards=1&createNodeSet=127.0.0.1:35663_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 961108 INFO (OverseerCollectionConfigSetProcessor-73199562327523334-127.0.0.1:38663_solr-n_0000000000) [n:127.0.0.1:38663_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> 961108 INFO (OverseerThreadFactory-3622-thread-2-processing-n:127.0.0.1:38663_solr) [n:127.0.0.1:38663_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 961211 WARN (OverseerThreadFactory-3622-thread-2-processing-n:127.0.0.1:38663_solr) [n:127.0.0.1:38663_solr ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 2 on collection .system is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 961214 INFO (OverseerStateUpdate-73199562327523334-127.0.0.1:38663_solr-n_0000000000) [n:127.0.0.1:38663_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:35663/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 961216 INFO (OverseerStateUpdate-73199562327523334-127.0.0.1:38663_solr-n_0000000000) [n:127.0.0.1:38663_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:35663/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 961459 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 961466 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr x:.system_shard1_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 962477 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 962480 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 962483 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 962485 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 962487 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 962488 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 962492 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 962496 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 962496 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
[junit4] 2> 962497 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 962500 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak
[junit4] 2> 962501 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n2' using configuration from configset .system, trusted=true
[junit4] 2> 962501 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35663.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17121d2c
[junit4] 2> 962501 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [[.system_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/tempDir-001/node1/.system_shard1_replica_n2], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/tempDir-001/node1/./.system_shard1_replica_n2/data/]
[junit4] 2> 962501 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using configuration from configset .system, trusted=true
[junit4] 2> 962503 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35663.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17121d2c
[junit4] 2> 962503 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 962563 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 962563 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 962564 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 962564 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 962566 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3967e031[.system_shard1_replica_n2] main]
[junit4] 2> 962567 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 962567 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 962567 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 962568 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 0 from ZooKeeper
[junit4] 2> 962569 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 962573 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 962573 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 4 ms
[junit4] 2> 962573 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 962573 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1657802287034138624
[junit4] 2> 962576 INFO (searcherExecutor-3634-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@3967e031[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 962578 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 962578 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/.system/leaders/shard1
[junit4] 2> 962582 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 962591 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 962591 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 962592 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 962592 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 962593 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@553c08cf[.system_shard1_replica_n1] main]
[junit4] 2> 962594 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 962594 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 962595 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 962595 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 962595 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 962595 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1657802287057207296
[junit4] 2> 962598 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=0, core_node4=0}, version=1}
[junit4] 2> 962598 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/.system/leaders/shard1
[junit4] 2> 962600 INFO (searcherExecutor-3635-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@553c08cf[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 963083 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 963083 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 963083 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:35663/solr/.system_shard1_replica_n2/
[junit4] 2> 963083 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n2 url=https://127.0.0.1:35663/solr START replicas=[https://127.0.0.1:35663/solr/.system_shard1_replica_n1/] nUpdates=100
[junit4] 2> 963084 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n2 url=https://127.0.0.1:35663/solr DONE. We have no versions. sync failed.
[junit4] 2> 963096 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_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> 963096 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 963096 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_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> 963096 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/.system/leaders/shard1/leader after winning as /collections/.system/leader_elect/shard1/election/73199562327523336-core_node4-n_0000000000
[junit4] 2> 963098 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ shard1
[junit4] 2> 963199 INFO (zkCallback-7152-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 963200 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 963203 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1737
[junit4] 2> 963302 INFO (zkCallback-7152-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 963302 INFO (zkCallback-7152-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 963602 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2143
[junit4] 2> 963603 INFO (qtp1118646542-18307) [n:127.0.0.1:38663_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 963703 INFO (zkCallback-7152-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 963703 INFO (zkCallback-7152-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 963703 INFO (zkCallback-7140-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 963704 INFO (qtp1118646542-18307) [n:127.0.0.1:38663_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={maxShardsPerNode=2&name=.system&nrtReplicas=2&action=CREATE&numShards=1&createNodeSet=127.0.0.1:35663_solr&wt=javabin&version=2} status=0 QTime=2602
[junit4] 2> 963705 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[1268FEEBC0AD8D41]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: .system
[junit4] 2> 963718 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=1, core_node4=1}, version=2}
[junit4] 2> 963775 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:35663/solr/.system_shard1_replica_n2/&wt=javabin&version=2}{add=[1701b265d15Tdimbeplf5klg6y96j2rjosxgz (1657802288233709568)]} 0 1
[junit4] 2> 963776 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1701b265d15Tdimbeplf5klg6y96j2rjosxgz (1657802288233709568)]} 0 59
[junit4] 2> 963777 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1657802288296624128,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 963777 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2fb6f95a commitCommandVersion:1657802288296624128
[junit4] 2> 963779 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1657802288298721280,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 963779 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@75d14a19 commitCommandVersion:1657802288298721280
[junit4] 2> 963781 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2127871f[.system_shard1_replica_n2] main]
[junit4] 2> 963781 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 963782 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@69c0116d[.system_shard1_replica_n1] main]
[junit4] 2> 963783 INFO (searcherExecutor-3634-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@2127871f[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={timestamp=1581003464031, java.vendor=Oracle Corporation, os=Linux, os.version=4.15.0-54-generic, java.runtime.version=11.0.4+10-LTS, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=11.0.4+10-LTS, java.version=11.0.4}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 963784 INFO (searcherExecutor-3635-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@69c0116d[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={timestamp=1581003464032, java.vendor=Oracle Corporation, os=Linux, os.version=4.15.0-54-generic, java.runtime.version=11.0.4+10-LTS, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=11.0.4+10-LTS, java.version=11.0.4}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 963784 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 963784 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:35663/solr/.system_shard1_replica_n2/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5
[junit4] 2> 963785 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n2] webapp=/solr path=/update params={_stateVer_=.system:6&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 7
[junit4] 2> 963796 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963797 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963798 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963802 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SchemaManager managed schema loaded . version : 1
[junit4] 2> 963804 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 963807 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 963808 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkController Persisted config data to node /configs/.system/schema.xml.bak
[junit4] 2> 963810 INFO (Thread-2953) [ ] o.a.s.c.SolrCore config update listener called for core .system_shard1_replica_n1
[junit4] 2> 963811 INFO (Thread-2953) [ ] o.a.s.c.SolrCore core reload .system_shard1_replica_n1
[junit4] 2> 963814 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 963836 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 963839 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 963840 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n1' using configuration from configset .system
[junit4] 2> 963885 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35663.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17121d2c
[junit4] 2> 963885 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 963941 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 963941 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 963944 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2996b533[.system_shard1_replica_n1] main]
[junit4] 2> 963946 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 963946 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 963946 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 963947 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963947 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 963950 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 963952 INFO (searcherExecutor-3644-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@2996b533[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={timestamp=1581003464032, java.vendor=Oracle Corporation, os=Linux, os.version=4.15.0-54-generic, java.runtime.version=11.0.4+10-LTS, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=11.0.4+10-LTS, java.version=11.0.4}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 963953 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7755582c[.system_shard1_replica_n1] main]
[junit4] 2> 963953 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Waiting up to 599 secs for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 963957 INFO (searcherExecutor-3644-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@7755582c[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={timestamp=1581003464032, os=Linux, java.vendor=Oracle Corporation, os.version=4.15.0-54-generic, java.runtime.version=11.0.4+10-LTS, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=11.0.4+10-LTS, java.version=11.0.4}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 963961 INFO (Thread-2953) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 963967 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963967 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963967 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 963968 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963968 INFO (Thread-2953) [ ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 963969 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963969 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963969 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963970 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963970 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963970 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963970 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963971 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963972 INFO (Thread-2953) [ ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 963972 INFO (Thread-2953) [ ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n1' using configuration from configset .system
[junit4] 2> 963975 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963976 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963976 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963976 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963980 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963981 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963981 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963981 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963982 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963982 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963982 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963982 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963983 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963983 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963983 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963983 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963984 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963984 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963984 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963985 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963985 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963985 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963985 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963986 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963991 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963991 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963991 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963992 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963993 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963993 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963993 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963994 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963994 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963995 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963995 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963995 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963996 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963996 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963996 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963996 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963997 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963997 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963997 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963997 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963998 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963998 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963998 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963998 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 963999 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 963999 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 963999 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 963999 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 964000 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 964000 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 964000 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 964001 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 964001 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 964002 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 964002 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 964002 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 964002 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 964003 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 964003 INFO (qtp120252222-18297) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 964003 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 964003 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 964004 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 964004 INFO (qtp120252222-18301) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 964004 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 964005 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 964005 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 964005 INFO (qtp120252222-18295) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 964005 ERROR (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 964006 INFO (qtp120252222-18299) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelo
[...truncated too long message...]
shard1_replica_n2
[junit4] 2> 1100306 WARN (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: https://127.0.0.1:35663/solr/.system_shard1_replica_n2
[junit4] 2> 1100306 WARN (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: https://127.0.0.1:35663/solr/.system_shard1_replica_n2
[junit4] 2> 1100307 WARN (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: https://127.0.0.1:35663/solr/.system_shard1_replica_n2
[junit4] 2> 1100307 WARN (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: https://127.0.0.1:35663/solr/.system_shard1_replica_n2
[junit4] 2> 1100308 WARN (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: https://127.0.0.1:35663/solr/.system_shard1_replica_n2
[junit4] 2> 1100308 WARN (managedSchemaExecutor-3648-thread-1-processing-n:127.0.0.1:35663_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from https://127.0.0.1:35663/solr/.system_shard1_replica_n2/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: https://127.0.0.1:35663/solr/.system_shard1_replica_n2
[junit4] 2> 1100315 WARN (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Core core_node3 was interrupted waiting for schema version 2 to propagate to 1 replicas for collection .system
[junit4] 2> 1100316 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Took 136362.0ms for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 1100316 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=136515
[junit4] 2> 1100316 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@1f47a6d4
[junit4] 2> 1100317 WARN (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Interrupted while trying to obtain lock to modify reporters registry: solr.core..system.shard1.replica_n1
[junit4] 2> 1100317 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection..system.shard1.leader, tag=SolrCore@1f47a6d4
[junit4] 2> 1100317 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() .
[junit4] 2> 1100317 INFO (qtp120252222-18296) [n:127.0.0.1:35663_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1ace865c commitCommandVersion:0
[junit4] 2> 1100329 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 1100533 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/aliases.json
[junit4] 2> 6 /solr/collections/.system/terms/shard1
[junit4] 2> 4 /solr/configs/.system/managed-schema
[junit4] 2> 2 /solr/configs/.system
[junit4] 2> 2 /solr/packages.json
[junit4] 2> 2 /solr/security.json
[junit4] 2> 2 /solr/collections/.system/collectionprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 16 /solr/collections/.system/state.json
[junit4] 2> 7 /solr/clusterstate.json
[junit4] 2> 7 /solr/clusterprops.json
[junit4] 2> 6 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 24 /solr/overseer/queue
[junit4] 2> 18 /solr/collections
[junit4] 2> 11 /solr/live_nodes
[junit4] 2> 10 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 1100534 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:43537
[junit4] 2> 1100534 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:43537
[junit4] 2> 1100534 INFO (SUITE-SystemCollectionCompatTest-seed#[1268FEEBC0AD8D41]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 43537
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.SystemCollectionCompatTest_1268FEEBC0AD8D41-001
[junit4] 2> Feb 06, 2020 3:40:00 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {id=FST50, type=PostingsFormat(name=LuceneVarGapFixedInterval)}, docValues:{timestamp_l=DocValuesFormat(name=Lucene80), _version_=DocValuesFormat(name=Asserting), time_l=DocValuesFormat(name=Asserting), timestamp=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=603, maxMBSortInHeap=6.080439066194274, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@56e3d529), locale=tt, timezone=Asia/Tomsk
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=1,free=175269840,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [DocValuesMissingTest, TestQueryTypes, PreAnalyzedFieldManagedSchemaCloudTest, UpdateParamsTest, CollectionStateFormat2Test, TestDistributedGrouping, SynonymTokenizerTest, TestSnapshotCloudManager, ResourceLoaderTest, RemoteQueryErrorTest, ClusterStateTest, DataDrivenBlockJoinTest, TestSolrCloudSnapshots, SearchRateTriggerTest, ConnectionReuseTest, TlogReplayBufferedWhileIndexingTest, TestLazyCores, TestFieldCacheVsDocValues, TestCloudManagedSchema, TestSkipOverseerOperations, TestTolerantUpdateProcessorCloud, CdcrBootstrapTest, TaggerTest, TestInfoStreamLogging, TestSafeXMLParsing, BufferStoreTest, TestSimDistribStateManager, PreAnalyzedUpdateProcessorTest, TestWaitForStateWithJettyShutdowns, TestExclusionRuleCollectionAccess, ZkSolrClientTest, CheckHdfsIndexTest, TestBlobHandler, TestLuceneMatchVersion, TestSolrCloudWithSecureImpersonation, SolrCoreMetricManagerTest, TestTrackingShardHandlerFactory, UniqFieldsUpdateProcessorFactoryTest, TestLeaderElectionWithEmptyReplica, TestStressLiveNodes, TestRandomCollapseQParserPlugin, TestDocTermOrds, TestSegmentSorting, ConjunctionSolrSpellCheckerTest, TokenizerChainTest, SimpleCollectionCreateDeleteTest, ScheduledTriggerIntegrationTest, JavaBinAtomicUpdateMultivalueTest, TriggerCooldownIntegrationTest, SimplePostToolTest, TestCloudRecovery, TestSolrXml, TestLogWatcher, TestSolrDeletionPolicy1, OutOfBoxZkACLAndCredentialsProvidersTest, TestRestoreCore, JWTVerificationkeyResolverTest, NodeMarkersRegistrationTest, DateMathParserTest, ConfigSetsAPITest, JWTAuthPluginIntegrationTest, ConfigureRecoveryStrategyTest, TestLegacyNumericUtils, CustomCollectionTest, TestNumericTerms32, SystemCollectionCompatTest]
[junit4] Completed [294/900 (1!)] on J2 in 141.84s, 1 test, 1 error <<< FAILURES!
[...truncated 54538 lines...]
[JENKINS] Lucene-Solr-Tests-master - Build # 4173 - Still Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/4173/
1 tests failed.
FAILED: org.apache.lucene.index.TestTransactions.testTransactions
Error Message:
MockDirectoryWrapper: cannot close: there are still 1 open files: {_1j_Lucene85TermVectorsIndexfile_pointers_61.tmp=1}
Stack Trace:
java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still 1 open files: {_1j_Lucene85TermVectorsIndexfile_pointers_61.tmp=1}
at __randomizedtesting.SeedInfo.seed([31E1DA73B3FD200B:F27366BBE769C90F]:0)
at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:807)
at org.apache.lucene.index.TestTransactions.testTransactions(TestTransactions.java:269)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.RuntimeException: unclosed IndexOutput: _1j_Lucene85TermVectorsIndexfile_pointers_61.tmp
at org.apache.lucene.store.MockDirectoryWrapper.addFileHandle(MockDirectoryWrapper.java:725)
at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:706)
at org.apache.lucene.store.FilterDirectory.createTempOutput(FilterDirectory.java:79)
at org.apache.lucene.store.FilterDirectory.createTempOutput(FilterDirectory.java:79)
at org.apache.lucene.store.TrackingDirectoryWrapper.createTempOutput(TrackingDirectoryWrapper.java:51)
at org.apache.lucene.codecs.compressing.FieldsIndexWriter.<init>(FieldsIndexWriter.java:87)
at org.apache.lucene.codecs.compressing.CompressingTermVectorsWriter.<init>(CompressingTermVectorsWriter.java:226)
at org.apache.lucene.codecs.compressing.CompressingTermVectorsFormat.vectorsWriter(CompressingTermVectorsFormat.java:98)
at org.apache.lucene.codecs.asserting.AssertingTermVectorsFormat.vectorsWriter(AssertingTermVectorsFormat.java:49)
at org.apache.lucene.index.SegmentMerger.mergeVectors(SegmentMerger.java:238)
at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:173)
at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4446)
at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4040)
at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
Build Log:
[...truncated 541 lines...]
[junit4] Suite: org.apache.lucene.index.TestTransactions
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTransactions -Dtests.method=testTransactions -Dtests.seed=31E1DA73B3FD200B -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=saq-KE -Dtests.timezone=America/Caracas -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 1.20s J0 | TestTransactions.testTransactions <<<
[junit4] > Throwable #1: java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still 1 open files: {_1j_Lucene85TermVectorsIndexfile_pointers_61.tmp=1}
[junit4] > at __randomizedtesting.SeedInfo.seed([31E1DA73B3FD200B:F27366BBE769C90F]:0)
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:807)
[junit4] > at org.apache.lucene.index.TestTransactions.testTransactions(TestTransactions.java:269)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] > Caused by: java.lang.RuntimeException: unclosed IndexOutput: _1j_Lucene85TermVectorsIndexfile_pointers_61.tmp
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.addFileHandle(MockDirectoryWrapper.java:725)
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:706)
[junit4] > at org.apache.lucene.store.FilterDirectory.createTempOutput(FilterDirectory.java:79)
[junit4] > at org.apache.lucene.store.FilterDirectory.createTempOutput(FilterDirectory.java:79)
[junit4] > at org.apache.lucene.store.TrackingDirectoryWrapper.createTempOutput(TrackingDirectoryWrapper.java:51)
[junit4] > at org.apache.lucene.codecs.compressing.FieldsIndexWriter.<init>(FieldsIndexWriter.java:87)
[junit4] > at org.apache.lucene.codecs.compressing.CompressingTermVectorsWriter.<init>(CompressingTermVectorsWriter.java:226)
[junit4] > at org.apache.lucene.codecs.compressing.CompressingTermVectorsFormat.vectorsWriter(CompressingTermVectorsFormat.java:98)
[junit4] > at org.apache.lucene.codecs.asserting.AssertingTermVectorsFormat.vectorsWriter(AssertingTermVectorsFormat.java:49)
[junit4] > at org.apache.lucene.index.SegmentMerger.mergeVectors(SegmentMerger.java:238)
[junit4] > at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:173)
[junit4] > at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4446)
[junit4] > at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4040)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {contents=BlockTreeOrds(blocksize=128), id=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene84))}, docValues:{}, maxPointsInLeafNode=1904, maxMBSortInHeap=6.9408479374991305, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1214f404), locale=saq-KE, timezone=America/Caracas
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=1,free=153685440,total=264241152
[junit4] 2> NOTE: All tests run in this JVM: [TestAssertions, TestMatchesIterator, TestMergedIterator, TestBM25Similarity, TestCharTermAttributeImpl, TestLatLonPointShapeQueries, TestFeatureDoubleValues, TestTermQuery, TestEarlyTermination, TestCustomSearcherSort, TestSpanCollection, TestPrefixRandom, TestLongValuesSource, TestWordlistLoader, TestIndexManyDocuments, TestCustomNorms, TestDoc, TestIntRange, TestIndependenceChiSquared, TestSameScoresWithThreads, TestTermStates, TestAxiomaticF1LOG, TestMultiTermConstantScore, TestParallelCompositeReader, TestPositiveScoresOnlyCollector, TestTopFieldCollector, Test2BNumericDocValues, TestFuzzyQuery, TestRamUsageEstimator, TestSegmentMerger, TestDuelingCodecs, TestDocumentWriter, TestTransactions]
[junit4] Completed [98/552 (1!)] on J0 in 1.23s, 1 test, 1 error <<< FAILURES!
[...truncated 67473 lines...]