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/11 17:38:42 UTC
[JENKINS] Lucene-Solr-BadApples-Tests-master - Build # 619 - Still
Unstable
Build: https://builds.apache.org/job/Lucene-Solr-BadApples-Tests-master/619/
4 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.common.params.CommonAdminParamsTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.common.params.CommonAdminParamsTest: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonAdminParamsTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.common.params.CommonAdminParamsTest:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonAdminParamsTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([7B949A7EC3CDFDD5]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.common.params.CommonAdminParamsTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonAdminParamsTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonAdminParamsTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([7B949A7EC3CDFDD5]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.common.params.CommonParamsTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.common.params.CommonParamsTest: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonParamsTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.common.params.CommonParamsTest:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonParamsTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([7B949A7EC3CDFDD5]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.common.params.CommonParamsTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonParamsTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonParamsTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([7B949A7EC3CDFDD5]:0)
Build Log:
[...truncated 16047 lines...]
[junit4] Suite: org.apache.solr.common.params.CommonParamsTest
[junit4] 2> Feb 11, 2020 5:24:17 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> Feb 11, 2020 5:24:37 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.common.params.CommonParamsTest:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonParamsTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 11, 2020 5:24:37 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonParamsTest]
[junit4] 2> AsyncLogger error handling event seq=0, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=1, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=2, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=3, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=4, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 11, 2020 5:24:39 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonParamsTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {}, docValues:{}, maxPointsInLeafNode=1048, maxMBSortInHeap=7.3600034298084775, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@69c33077), locale=qu-EC, timezone=Europe/Riga
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=2,free=213843792,total=264241152
[junit4] 2> NOTE: All tests run in this JVM: [CommonParamsTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CommonParamsTest -Dtests.seed=7B949A7EC3CDFDD5 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=qu-EC -Dtests.timezone=Europe/Riga -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J2 | CommonParamsTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.common.params.CommonParamsTest:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonParamsTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([7B949A7EC3CDFDD5]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonParamsTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([7B949A7EC3CDFDD5]:0)
[junit4] Completed [5/207 (1!)] on J2 in 23.43s, 5 tests, 2 errors <<< FAILURES!
[...truncated 1 lines...]
[junit4] Suite: org.apache.solr.common.params.CommonAdminParamsTest
[junit4] 2> Feb 11, 2020 5:24:17 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> Feb 11, 2020 5:24:37 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.common.params.CommonAdminParamsTest:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonAdminParamsTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 11, 2020 5:24:37 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonAdminParamsTest]
[junit4] 2> AsyncLogger error handling event seq=0, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=1, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=2, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=3, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=4, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 11, 2020 5:24:39 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonAdminParamsTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {}, docValues:{}, maxPointsInLeafNode=871, maxMBSortInHeap=6.465191775237462, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6907c204), locale=vun, timezone=America/Santa_Isabel
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=2,free=225331824,total=264241152
[junit4] 2> NOTE: All tests run in this JVM: [CommonAdminParamsTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CommonAdminParamsTest -Dtests.seed=7B949A7EC3CDFDD5 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=vun -Dtests.timezone=America/Santa_Isabel -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J1 | CommonAdminParamsTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.common.params.CommonAdminParamsTest:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonAdminParamsTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([7B949A7EC3CDFDD5]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-CommonAdminParamsTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([7B949A7EC3CDFDD5]:0)
[junit4] Completed [6/207 (2!)] on J1 in 23.45s, 1 test, 2 errors <<< FAILURES!
[...truncated 51934 lines...]
[JENKINS] Lucene-Solr-BadApples-Tests-master - Build # 621 - Still
Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-BadApples-Tests-master/621/
1 tests failed.
FAILED: org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:45532/solr/.system]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:45532/solr/.system]
at __randomizedtesting.SeedInfo.seed([249A809720112E52:546F233E40D98724]: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: http://127.0.0.1:45532/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 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 14306 lines...]
[junit4] Suite: org.apache.solr.cloud.SystemCollectionCompatTest
[junit4] 2> 3025891 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/data-dir-192-001
[junit4] 2> 3025891 WARN (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=30 numCloses=30
[junit4] 2> 3025891 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 3025892 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 3025892 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 3025893 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/tempDir-001
[junit4] 2> 3025893 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 3025893 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3025893 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 3025993 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:37076
[junit4] 2> 3025994 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:37076
[junit4] 2> 3025994 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:37076
[junit4] 2> 3025994 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 37076
[junit4] 2> 3025996 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3025997 INFO (zkConnectionManagerCallback-11719-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3025997 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3026000 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3026001 INFO (zkConnectionManagerCallback-11721-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3026001 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3026002 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3026003 INFO (zkConnectionManagerCallback-11723-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3026003 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3026107 WARN (jetty-launcher-11724-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 3026107 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 3026107 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 3026107 INFO (jetty-launcher-11724-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> 3026107 WARN (jetty-launcher-11724-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 3026107 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 3026107 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 3026107 INFO (jetty-launcher-11724-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> 3026108 INFO (jetty-launcher-11724-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 3026108 INFO (jetty-launcher-11724-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 3026108 INFO (jetty-launcher-11724-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 3026108 INFO (jetty-launcher-11724-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5f2e07af{/solr,null,AVAILABLE}
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@ef35f30{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:45532}
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-1) [ ] o.e.j.s.Server Started @3026148ms
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3a49b406{/solr,null,AVAILABLE}
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45532}
[junit4] 2> 3026109 ERROR (jetty-launcher-11724-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-13T17:35:48.980937Z
[junit4] 2> 3026109 INFO (jetty-launcher-11724-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@734548f7{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:46420}
[junit4] 2> 3026110 INFO (jetty-launcher-11724-thread-2) [ ] o.e.j.s.Server Started @3026148ms
[junit4] 2> 3026110 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46420}
[junit4] 2> 3026110 ERROR (jetty-launcher-11724-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3026110 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 3026110 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 3026110 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3026110 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr
[junit4] 2> 3026110 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-13T17:35:48.981353Z
[junit4] 2> 3026110 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3026111 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3026113 INFO (zkConnectionManagerCallback-11726-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3026113 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3026114 INFO (zkConnectionManagerCallback-11728-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3026114 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3026114 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3026114 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3026365 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 3026366 WARN (jetty-launcher-11724-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@517b4965[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3026366 WARN (jetty-launcher-11724-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@517b4965[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3026369 WARN (jetty-launcher-11724-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@1f592912[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3026369 WARN (jetty-launcher-11724-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@1f592912[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3026371 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37076/solr
[junit4] 2> 3026372 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3026373 INFO (zkConnectionManagerCallback-11736-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3026373 INFO (jetty-launcher-11724-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3026476 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3026477 INFO (zkConnectionManagerCallback-11738-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3026477 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3026580 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46420_solr
[junit4] 2> 3026581 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.c.Overseer Overseer (id=72279819034755078-127.0.0.1:46420_solr-n_0000000000) starting
[junit4] 2> 3026587 INFO (OverseerStateUpdate-72279819034755078-127.0.0.1:46420_solr-n_0000000000) [n:127.0.0.1:46420_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:46420_solr
[junit4] 2> 3026587 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46420_solr
[junit4] 2> 3026588 INFO (OverseerStateUpdate-72279819034755078-127.0.0.1:46420_solr-n_0000000000) [n:127.0.0.1:46420_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3026590 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 3026591 WARN (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_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> 3026624 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 3026660 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46420.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@29209484
[junit4] 2> 3026698 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46420.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@29209484
[junit4] 2> 3026698 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46420.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@29209484
[junit4] 2> 3026700 INFO (jetty-launcher-11724-thread-2) [n:127.0.0.1:46420_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/tempDir-001/node2/.
[junit4] 2> 3027069 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 3027070 WARN (jetty-launcher-11724-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@6306906b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3027070 WARN (jetty-launcher-11724-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@6306906b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3027074 WARN (jetty-launcher-11724-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@6343383[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3027074 WARN (jetty-launcher-11724-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@6343383[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3027075 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37076/solr
[junit4] 2> 3027077 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3027078 INFO (zkConnectionManagerCallback-11748-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3027078 INFO (jetty-launcher-11724-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3027181 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3027182 INFO (zkConnectionManagerCallback-11750-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3027182 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3027189 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3027193 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:45532_solr as DOWN
[junit4] 2> 3027194 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 3027194 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45532_solr
[junit4] 2> 3027196 INFO (zkCallback-11737-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 3027196 INFO (zkCallback-11749-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 3027197 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 3027198 WARN (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_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> 3027222 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 3027254 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45532.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@29209484
[junit4] 2> 3027268 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45532.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@29209484
[junit4] 2> 3027268 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45532.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@29209484
[junit4] 2> 3027269 INFO (jetty-launcher-11724-thread-1) [n:127.0.0.1:45532_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/tempDir-001/node1/.
[junit4] 2> 3027305 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 3027306 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3027308 INFO (zkConnectionManagerCallback-11759-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3027308 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3027309 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 3027311 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37076/solr ready
[junit4] 2> 3027333 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[249A809720112E52]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBackCompat
[junit4] 2> 3027335 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[249A809720112E52]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 3027336 INFO (zkConnectionManagerCallback-11764-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3027336 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[249A809720112E52]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 3027338 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[249A809720112E52]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 3027339 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[249A809720112E52]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37076/solr ready
[junit4] 2> 3027341 INFO (qtp2105714999-33905) [n:127.0.0.1:46420_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 3027346 INFO (qtp2105714999-33905) [n:127.0.0.1:46420_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 3027347 INFO (qtp2105714999-33904) [n:127.0.0.1:46420_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:45532_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 3027356 INFO (OverseerThreadFactory-9928-thread-2-processing-n:127.0.0.1:46420_solr) [n:127.0.0.1:46420_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 3027356 INFO (OverseerCollectionConfigSetProcessor-72279819034755078-127.0.0.1:46420_solr-n_0000000000) [n:127.0.0.1:46420_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> 3027461 WARN (OverseerThreadFactory-9928-thread-2-processing-n:127.0.0.1:46420_solr) [n:127.0.0.1:46420_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> 3027465 INFO (OverseerStateUpdate-72279819034755078-127.0.0.1:46420_solr-n_0000000000) [n:127.0.0.1:46420_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":"http://127.0.0.1:45532/solr",
[junit4] 2> "node_name":"127.0.0.1:45532_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3027468 INFO (OverseerStateUpdate-72279819034755078-127.0.0.1:46420_solr-n_0000000000) [n:127.0.0.1:46420_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":"http://127.0.0.1:45532/solr",
[junit4] 2> "node_name":"127.0.0.1:45532_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3027672 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027672 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027683 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027683 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027692 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027692 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027695 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027695 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027699 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027699 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027700 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027700 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027702 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027702 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45532.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@29209484
[junit4] 2> 3027702 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 3027704 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027704 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027705 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45532.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@29209484
[junit4] 2> 3027705 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/tempDir-001/node1/.system_shard1_replica_n2], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/tempDir-001/node1/./.system_shard1_replica_n2/data/]
[junit4] 2> 3027803 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027803 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027805 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027805 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027805 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027805 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3027807 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@21fda246[.system_shard1_replica_n1] main]
[junit4] 2> 3027807 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027807 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3027809 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3542860a[.system_shard1_replica_n2] main]
[junit4] 2> 3027809 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027809 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027809 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027810 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027811 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027811 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027811 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027811 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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 1658443897956728832
[junit4] 2> 3027811 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027812 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027814 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027815 INFO (searcherExecutor-9940-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_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@21fda246[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3027818 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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}, version=0}
[junit4] 2> 3027818 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3027818 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027818 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 5 ms
[junit4] 2> 3027818 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027818 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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 1658443897964068864
[junit4] 2> 3027822 INFO (searcherExecutor-9941-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:45532_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@3542860a[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3027822 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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=0, core_node4=0}, version=1}
[junit4] 2> 3027822 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3027823 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 3028325 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 3028325 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 3028325 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:45532/solr/.system_shard1_replica_n1/
[junit4] 2> 3028326 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n1 url=http://127.0.0.1:45532/solr START replicas=[http://127.0.0.1:45532/solr/.system_shard1_replica_n2/] nUpdates=100
[junit4] 2> 3028326 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n1 url=http://127.0.0.1:45532/solr DONE. We have no versions. sync failed.
[junit4] 2> 3028328 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3028328 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 3028328 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] 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> 3028328 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/.system/leaders/shard1/leader after winning as /collections/.system/leader_elect/shard1/election/72279819034755080-core_node3-n_0000000000
[junit4] 2> 3028330 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:45532/solr/.system_shard1_replica_n1/ shard1
[junit4] 2> 3028433 INFO (zkCallback-11749-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> 3028434 INFO (qtp3449158-33897) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 3028437 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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=765
[junit4] 2> 3028536 INFO (zkCallback-11749-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> 3028536 INFO (zkCallback-11749-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> 3028827 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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=1155
[junit4] 2> 3028829 INFO (qtp2105714999-33904) [n:127.0.0.1:46420_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> 3028928 INFO (zkCallback-11737-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> 3028928 INFO (zkCallback-11749-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> 3028928 INFO (zkCallback-11749-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> 3028929 INFO (qtp2105714999-33904) [n:127.0.0.1:46420_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:45532_solr&wt=javabin&version=2} status=0 QTime=1581
[junit4] 2> 3028929 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[249A809720112E52]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: .system
[junit4] 2> 3028935 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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=1, core_node4=1}, version=2}
[junit4] 2> 3028939 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:45532/solr/.system_shard1_replica_n1/&wt=javabin&version=2}{add=[1703f9f07f9T13z74ev5pwkbahkzadtj235ge (1658443899133231104)]} 0 1
[junit4] 2> 3028939 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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={wt=javabin&version=2}{add=[1703f9f07f9T13z74ev5pwkbahkzadtj235ge (1658443899133231104)]} 0 7
[junit4] 2> 3028941 INFO (qtp3449158-33899) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1658443899140571136,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 3028941 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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@251bd21f commitCommandVersion:1658443899140571136
[junit4] 2> 3028942 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1658443899142668288,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 3028942 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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@4aeb2dbd commitCommandVersion:1658443899142668288
[junit4] 2> 3028948 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7a67030a[.system_shard1_replica_n2] main]
[junit4] 2> 3028948 INFO (qtp3449158-33899) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@42d39952[.system_shard1_replica_n1] main]
[junit4] 2> 3028948 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 3028948 INFO (qtp3449158-33899) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 3028951 INFO (searcherExecutor-9941-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:45532_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@7a67030a[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, os=Linux, java.vendor=Oracle Corporation, timestamp=1581615351815}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 3028951 INFO (searcherExecutor-9940-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_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@42d39952[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, os=Linux, java.vendor=Oracle Corporation, timestamp=1581615351815}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 3028952 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:45532/solr/.system_shard1_replica_n1/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 9
[junit4] 2> 3028952 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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={_stateVer_=.system:6&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 12
[junit4] 2> 3028954 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3028955 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3028956 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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=0
[junit4] 2> 3028961 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3028962 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3028987 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3028988 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3028990 INFO (Thread-4306) [ ] o.a.s.c.SolrCore config update listener called for core .system_shard1_replica_n1
[junit4] 2> 3028997 INFO (Thread-4306) [ ] o.a.s.c.SolrCore core reload .system_shard1_replica_n1
[junit4] 2> 3029003 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029011 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029015 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029015 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029093 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45532.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@29209484
[junit4] 2> 3029093 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 3029185 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029185 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3029190 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@555f566[.system_shard1_replica_n1] main]
[junit4] 2> 3029192 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029192 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029192 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029193 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029193 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029196 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029199 INFO (searcherExecutor-9950-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_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@555f566[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, os=Linux, java.vendor=Oracle Corporation, timestamp=1581615351815}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 3029200 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@62acf04b[.system_shard1_replica_n1] main]
[junit4] 2> 3029201 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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> 3029205 INFO (searcherExecutor-9950-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_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@62acf04b[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, java.vendor=Oracle Corporation, os=Linux, timestamp=1581615351815}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 3029207 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029208 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029208 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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=4
[junit4] 2> 3029208 INFO (Thread-4306) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 3029213 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029214 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029214 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029214 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029214 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029215 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029215 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029215 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029216 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029216 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029217 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029217 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029217 INFO (Thread-4306) [ ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 3029217 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029218 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029218 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029218 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029218 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029219 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029219 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029219 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029219 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029220 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029221 INFO (Thread-4306) [ ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 3029221 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029221 INFO (Thread-4306) [ ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n1' using configuration from configset .system
[junit4] 2> 3029221 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029221 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029222 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029222 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029222 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029222 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029223 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029223 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029223 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029224 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029224 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029225 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029225 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029225 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029225 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029226 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029226 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029226 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029227 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029227 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029227 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029228 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029228 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029229 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029229 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029229 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029229 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029230 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029230 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029230 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029231 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029231 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029231 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029231 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029232 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029232 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029232 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029233 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029233 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029234 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029234 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029234 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029235 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029235 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029235 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029235 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029236 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029236 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029236 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029236 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029237 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029238 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029238 INFO (qtp3449158-33899) [n:127.0.0.1:45532_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> 3029238 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029238 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029239 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029239 INFO (qtp3449158-33897) [n:127.0.0.1:45532_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> 3029239 ERROR (managedSchemaExecutor-9954-thread-1-processing-n:127.0.0.1:45532_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:45532/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 3029240 INFO (qtp3449158-33899) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refresh
[...truncated too long message...]
.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.h.i.e.RetryExec Retrying request to {}->http://127.0.0.1:45532
[junit4] 2> 3165750 WARN (qtp3449158-33895) [n:127.0.0.1:45532_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> 3165750 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Took 136549.0ms for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 3165750 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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=136791
[junit4] 2> 3165750 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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@2ff3b286
[junit4] 2> 3165751 WARN (qtp3449158-33895) [n:127.0.0.1:45532_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> 3165751 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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@2ff3b286
[junit4] 2> 3165751 INFO (qtp3449158-33895) [n:127.0.0.1:45532_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() .
[junit4] 2> 3165751 INFO (qtp3449158-33895) [n:127.0.0.1:45532_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@658719fb commitCommandVersion:0
[junit4] 2> 3165761 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 3165965 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/clusterprops.json
[junit4] 2> 7 /solr/aliases.json
[junit4] 2> 7 /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> 6 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 26 /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> 3165967 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:37076
[junit4] 2> 3165967 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:37076
[junit4] 2> 3165967 INFO (SUITE-SystemCollectionCompatTest-seed#[249A809720112E52]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 37076
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_249A809720112E52-001
[junit4] 2> Feb 13, 2020 5:38:08 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=PostingsFormat(name=LuceneVarGapDocFreqInterval), type=FST50}, docValues:{timestamp_l=DocValuesFormat(name=Lucene80), _version_=DocValuesFormat(name=Asserting), time_l=DocValuesFormat(name=Asserting), timestamp=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=1355, maxMBSortInHeap=7.658075013967525, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@7ab09106), locale=wae-CH, timezone=Africa/Banjul
[junit4] 2> NOTE: Linux 4.4.0-170-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=8,threads=1,free=128196432,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [RequiredFieldsTest, ResourceLoaderTest, SimpleCollectionCreateDeleteTest, TestPayloadCheckQParserPlugin, AnalysisAfterCoreReloadTest, TestLuceneIndexBackCompat, ReplicationFactorTest, SuggesterTest, TestQueryingOnDownCollection, UniqFieldsUpdateProcessorFactoryTest, TestConfigSetImmutable, EchoParamsTest, TestNamedUpdateProcessors, SpellPossibilityIteratorTest, TestPushWriter, TestTolerantUpdateProcessorCloud, TestMaxTokenLenTokenizer, TestFreeTextSuggestions, CustomTermsComponentTest, SolrMetricsIntegrationTest, HLLSerializationTest, RangeFacetCloudTest, InfixSuggestersTest, MoveReplicaHDFSTest, TlogReplayBufferedWhileIndexingTest, TestSimDistribStateManager, TestFieldCollectionResource, GraphQueryTest, TestBlobHandler, TestSafeXMLParsing, NodeMarkersRegistrationTest, AutoAddReplicasPlanActionTest, DeleteNodeTest, TestWaitForStateWithJettyShutdowns, IndexSchemaTest, TestUseDocValuesAsStored, TestCrossCoreJoin, MetricsHandlerTest, TestWriterPerf, DaemonStreamApiTest, CreateRoutedAliasTest, DocValuesNotIndexedTest, TestDocTermOrds, TestSearcherReuse, TestSolrDeletionPolicy1, TestManagedResourceStorage, NoCacheHeaderTest, HighlighterMaxOffsetTest, ClusterStateTest, SolrCoreMetricManagerTest, VMParamsZkACLAndCredentialsProvidersTest, TestFieldCacheVsDocValues, LoggingHandlerTest, TestPrepRecovery, TestSimScenario, UpdateParamsTest, TestInPlaceUpdatesStandalone, TestInPlaceUpdateWithRouteField, TestSolrXml, BJQFilterAccessibleTest, MigrateRouteKeyTest, TestPhraseSuggestions, TimeZoneUtilsTest, TestCoreContainer, TestManagedSchemaAPI, PreAnalyzedFieldManagedSchemaCloudTest, BasicZkTest, HdfsRecoverLeaseTest, TestImpersonationWithHadoopAuth, TestSimExtremeIndexing, TestNonDefinedSimilarityFactory, JavaBinAtomicUpdateMultivalueTest, DataDrivenBlockJoinTest, TestSolrCoreParser, TestConfigSetsAPIZkFailure, LegacyCloudClusterPropTest, BasicAuthIntegrationTest, TestSolr4Spatial, DimensionalRoutedAliasUpdateProcessorTest, TestShardHandlerFactory, CoreAdminOperationTest, RankQueryTest, TestQuerySenderListener, TestLeaderElectionWithEmptyReplica, TestDistributedStatsComponentCardinality, TestCollationFieldDocValues, CdcrBootstrapTest, MetricTriggerIntegrationTest, ScriptEngineTest, SimplePostToolTest, TestSolrConfigHandlerCloud, HttpPartitionTest, ZkSolrClientTest, TestQueryTypes, DistributedFacetPivotLongTailTest, TestFoldingMultitermQuery, HdfsSyncSliceTest, TestAtomicUpdateErrorCases, TestPointFields, TolerantUpdateProcessorTest, PingRequestHandlerTest, SparseHLLTest, XmlInterpolationTest, TestDFISimilarityFactory, DistribJoinFromCollectionTest, TestSolrCloudWithSecureImpersonation, TestFacetMethods, TestReplicaProperties, AssignBackwardCompatibilityTest, SecurityConfHandlerTest, TestSnapshotCloudManager, TestCloudPhrasesIdentificationComponent, DistributedQueryComponentOptimizationTest, JWTVerificationkeyResolverTest, IndexSizeTriggerMixedBoundsTest, TestLogWatcher, NumericFieldsTest, TestManagedSynonymGraphFilterFactory, AddBlockUpdateTest, QueryResultKeyTest, RecoveryAfterSoftCommitTest, TestComplexPhraseQParserPlugin, TestSystemCollAutoCreate, TriggerCooldownIntegrationTest, TestUniqueKeyFieldResource, RemoteQueryErrorTest, TestGroupingSearch, TestScoreJoinQPNoScore, TestCustomStream, SolrJmxReporterTest, CleanupOldIndexTest, TestGraphMLResponseWriter, TestSimNodeAddedTrigger, EnumFieldTest, TestSubQueryTransformerCrossCore, TestRealTimeGet, CollectionReloadTest, OverseerModifyCollectionTest, RulesTest, DocValuesMissingTest, ChaosMonkeySafeLeaderTest, TestCSVResponseWriter, TriggerSetPropertiesIntegrationTest, TestSegmentSorting, ConjunctionSolrSpellCheckerTest, TestRemoteStreaming, CursorPagingTest, DisMaxRequestHandlerTest, DistributedIntervalFacetingTest, MinimalSchemaTest, OutputWriterTest, SampleTest, SolrInfoBeanTest, SolrTestCaseJ4Test, TestCursorMarkWithoutUniqueKey, TestDistributedGrouping, TestDistributedMissingSort, TestRandomDVFaceting, TestRandomFaceting, TestSimpleTrackingShardHandler, TestSolrCoreProperties, TestSolrTestCaseJ4, TestTolerantSearch, TestTrie, PathHierarchyTokenizerFactoryTest, ProtectedTermFilterFactoryTest, TestCharFilters, TestDeprecatedFilters, TestLuceneMatchVersion, TestReversedWildcardFilterFactory, TestEmbeddedSolrServerSchemaAPI, TestJettySolrRunner, ConnectionReuseTest, ActionThrottleTest, BasicDistributedZk2Test, BasicDistributedZkTest, ChaosMonkeySafeLeaderWithPullReplicasTest, ClusterStateMockUtilTest, CollectionsAPISolrJTest, DistributedQueueTest, DistributedVersionInfoTest, LeaderElectionIntegrationTest, LeaderTragicEventTest, LeaderVoteWaitTimeoutTest, MultiSolrCloudTestCaseTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverseerRolesTest, PackageManagerCLITest, SSLMigrationTest, SaslZkACLProviderTest, ShardRoutingCustomTest, SharedFSAutoReplicaFailoverTest, SliceStateTest, SolrXmlInZkTest, SplitShardTest, SystemCollectionCompatTest]
[junit4] Completed [534/904 (1!)] on J0 in 140.74s, 1 test, 1 error <<< FAILURES!
[...truncated 53726 lines...]
[JENKINS] Lucene-Solr-BadApples-Tests-master - Build # 620 - Still
Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-BadApples-Tests-master/620/
6 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.client.solrj.io.stream.eval.AbsoluteValueEvaluatorTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AbsoluteValueEvaluatorTest: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AbsoluteValueEvaluatorTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AbsoluteValueEvaluatorTest:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AbsoluteValueEvaluatorTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.client.solrj.io.stream.eval.AbsoluteValueEvaluatorTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AbsoluteValueEvaluatorTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AbsoluteValueEvaluatorTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.client.solrj.io.stream.eval.AddEvaluatorTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AddEvaluatorTest: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AddEvaluatorTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AddEvaluatorTest:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AddEvaluatorTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.client.solrj.io.stream.eval.AddEvaluatorTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AddEvaluatorTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AddEvaluatorTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.client.solrj.io.stream.eval.AndEvaluatorTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AndEvaluatorTest: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AndEvaluatorTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AndEvaluatorTest:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AndEvaluatorTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.client.solrj.io.stream.eval.AndEvaluatorTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AndEvaluatorTest] at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method) at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123) at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38) at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159) at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125) at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AndEvaluatorTest]
at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)
Build Log:
[...truncated 16038 lines...]
[junit4] Suite: org.apache.solr.client.solrj.io.stream.eval.AndEvaluatorTest
[junit4] 2> Feb 12, 2020 4:14:13 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> Feb 12, 2020 4:14:33 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AndEvaluatorTest:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AndEvaluatorTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 12, 2020 4:14:33 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AndEvaluatorTest]
[junit4] 2> AsyncLogger error handling event seq=0, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=1, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=2, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=3, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=4, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 12, 2020 4:14:36 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AndEvaluatorTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {}, docValues:{}, maxPointsInLeafNode=883, maxMBSortInHeap=6.074068461340027, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@4f120360), locale=en-TZ, timezone=America/Montreal
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=2,free=211255872,total=264241152
[junit4] 2> NOTE: All tests run in this JVM: [AndEvaluatorTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=AndEvaluatorTest -Dtests.seed=24F6767D4080BFEC -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=en-TZ -Dtests.timezone=America/Montreal -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J2 | AndEvaluatorTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AndEvaluatorTest:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AndEvaluatorTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AndEvaluatorTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)
[junit4] Completed [1/207 (1!)] on J2 in 23.36s, 2 tests, 2 errors <<< FAILURES!
[...truncated 1 lines...]
[junit4] Suite: org.apache.solr.client.solrj.io.stream.eval.AbsoluteValueEvaluatorTest
[junit4] 2> Feb 12, 2020 4:14:13 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> Feb 12, 2020 4:14:33 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AbsoluteValueEvaluatorTest:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AbsoluteValueEvaluatorTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 12, 2020 4:14:33 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AbsoluteValueEvaluatorTest]
[junit4] 2> AsyncLogger error handling event seq=0, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=1, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=2, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=3, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=4, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 12, 2020 4:14:36 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AbsoluteValueEvaluatorTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6f3e890e), locale=ar-TD, timezone=Antarctica/South_Pole
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=2,free=212268048,total=264241152
[junit4] 2> NOTE: All tests run in this JVM: [AbsoluteValueEvaluatorTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=AbsoluteValueEvaluatorTest -Dtests.seed=24F6767D4080BFEC -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=ar-TD -Dtests.timezone=Antarctica/South_Pole -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J0 | AbsoluteValueEvaluatorTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AbsoluteValueEvaluatorTest:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AbsoluteValueEvaluatorTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AbsoluteValueEvaluatorTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)
[junit4] Completed [2/207 (2!)] on J0 in 23.51s, 6 tests, 2 errors <<< FAILURES!
[...truncated 40 lines...]
[junit4] Suite: org.apache.solr.client.solrj.io.stream.eval.AddEvaluatorTest
[junit4] 2> Feb 12, 2020 4:14:13 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> Feb 12, 2020 4:14:33 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AddEvaluatorTest:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AddEvaluatorTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 12, 2020 4:14:33 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AddEvaluatorTest]
[junit4] 2> AsyncLogger error handling event seq=0, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=1, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=2, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=3, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> AsyncLogger error handling event seq=4, value='null': java.lang.InterruptedException: null
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133)
[junit4] 2> at com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> Feb 12, 2020 4:14:36 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AddEvaluatorTest]
[junit4] 2> at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] 2> at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] 2> at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] 2> at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {}, docValues:{}, maxPointsInLeafNode=797, maxMBSortInHeap=7.269190230988503, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@41480000), locale=et-EE, timezone=Europe/Volgograd
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=2,free=210432216,total=264241152
[junit4] 2> NOTE: All tests run in this JVM: [AddEvaluatorTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=AddEvaluatorTest -Dtests.seed=24F6767D4080BFEC -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=et-EE -Dtests.timezone=Europe/Volgograd -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J1 | AddEvaluatorTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.eval.AddEvaluatorTest:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AddEvaluatorTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=15, name=Log4j2-TF-1-AsyncLoggerConfig-1, state=TIMED_WAITING, group=TGRP-AddEvaluatorTest]
[junit4] > at java.base@11.0.4/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@11.0.4/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] > at app//com.lmax.disruptor.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:38)
[junit4] > at app//com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
[junit4] > at app//com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[junit4] > at java.base@11.0.4/java.lang.Thread.run(Thread.java:834)
[junit4] > at __randomizedtesting.SeedInfo.seed([24F6767D4080BFEC]:0)
[junit4] Completed [16/207 (3!)] on J1 in 23.40s, 8 tests, 2 errors <<< FAILURES!
[...truncated 51903 lines...]