You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/09/05 00:34:15 UTC
[JENKINS] Lucene-Solr-7.x-Linux (64bit/jdk-10) - Build # 2689 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2689/
Java: 64bit/jdk-10 -XX:+UseCompressedOops -XX:+UseG1GC
3 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.search.TestXmlQParser
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.search.TestXmlQParser: 1) Thread[id=16, name=Log4j2-TF-1-AsyncLoggerConfig--1, state=TIMED_WAITING, group=TGRP-TestXmlQParser] at java.base@10/jdk.internal.misc.Unsafe.park(Native Method) at java.base@10/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2117) 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.run(BatchEventProcessor.java:128) at java.base@10/java.lang.Thread.run(Thread.java:844)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.search.TestXmlQParser:
1) Thread[id=16, name=Log4j2-TF-1-AsyncLoggerConfig--1, state=TIMED_WAITING, group=TGRP-TestXmlQParser]
at java.base@10/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@10/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2117)
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.run(BatchEventProcessor.java:128)
at java.base@10/java.lang.Thread.run(Thread.java:844)
at __randomizedtesting.SeedInfo.seed([A6ADE401B29C0D43]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.search.TestXmlQParser
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=16, name=Log4j2-TF-1-AsyncLoggerConfig--1, state=TIMED_WAITING, group=TGRP-TestXmlQParser] at java.base@10/jdk.internal.misc.Unsafe.park(Native Method) at java.base@10/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2117) 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.run(BatchEventProcessor.java:128) at java.base@10/java.lang.Thread.run(Thread.java:844)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=16, name=Log4j2-TF-1-AsyncLoggerConfig--1, state=TIMED_WAITING, group=TGRP-TestXmlQParser]
at java.base@10/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@10/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2117)
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.run(BatchEventProcessor.java:128)
at java.base@10/java.lang.Thread.run(Thread.java:844)
at __randomizedtesting.SeedInfo.seed([A6ADE401B29C0D43]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.search.TestXmlQParser
Error Message:
The test or suite printed 3746116 bytes to stdout and stderr, even though the limit was set to 8192 bytes. Increase the limit with @Limit, ignore it completely with @SuppressSysoutChecks or run with -Dtests.verbose=true
Stack Trace:
java.lang.AssertionError: The test or suite printed 3746116 bytes to stdout and stderr, even though the limit was set to 8192 bytes. Increase the limit with @Limit, ignore it completely with @SuppressSysoutChecks or run with -Dtests.verbose=true
at __randomizedtesting.SeedInfo.seed([A6ADE401B29C0D43]:0)
at org.apache.lucene.util.TestRuleLimitSysouts.afterIfSuccessful(TestRuleLimitSysouts.java:211)
at com.carrotsearch.randomizedtesting.rules.TestRuleAdapter$1.afterIfSuccessful(TestRuleAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:37)
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:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 15120 lines...]
[junit4] Suite: org.apache.solr.search.TestXmlQParser
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=103&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=80&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=11&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:23&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=43&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=61&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=98&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=33&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:85&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:88&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=46&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=105&wt=json} status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:39&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:37&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522341 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=80&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:64&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=71&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:85&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:98&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:100&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=41&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=73&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:61&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=73&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=20&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=90&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=62&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=97&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:28&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=29&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=97&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=41&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=73&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=46&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:36&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=79&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=78&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=76&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:103&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=95&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:69&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=75&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:74&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:33&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=61&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:2&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=88&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=53&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=94&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:53&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:58&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=49&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:81&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522342 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=70&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:20&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:4&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=64&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=96&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:5&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:35&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:34&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=102&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=77&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:21&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=102&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:22&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:18&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=103&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=64&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=104&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=88&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:104&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=48&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=101&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=41&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:32&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:3&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:90&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:56&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=105&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=75&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=98&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=72&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=72&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:101&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:45&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=31&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=79&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=80&wt=json} status=0 QTime=0
[junit4] 2> 2522343 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=58&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:67&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:80&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=59&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=34&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=3&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:51&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=77&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=65&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=33&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=34&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:95&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=55&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:39&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:92&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=78&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:91&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=73&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=52&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=104&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=48&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:60&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:101&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=29&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=70&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:43&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=51&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=40&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=85&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:60&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=20&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=32&wt=json} status=0 QTime=0
[junit4] 2> 2522344 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=51&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=91&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:99&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=57&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=94&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:28&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=95&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=45&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=88&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=105&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=30&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:10&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:88&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=42&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:19&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=65&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=99&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=63&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=40&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=3&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:87&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:75&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=72&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=59&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:71&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=83&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:3&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=101&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:83&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:33&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=77&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=77&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:50&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=32&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=47&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=83&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=68&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=90&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=80&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=85&wt=json} status=0 QTime=0
[junit4] 2> 2522345 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=100&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:77&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=29&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:23&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=102&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=65&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:8&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:54&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:14&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=39&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=89&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=88&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=92&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=78&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:90&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=20&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:33&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=68&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=66&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=35&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=51&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=65&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:30&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=60&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=85&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=3&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:83&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=55&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=66&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:100&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:5&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=90&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:41&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:61&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=36&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=84&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:92&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:101&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=98&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=60&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:67&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:15&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=51&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:61&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:17&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=65&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=43&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=56&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=57&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=45&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=69&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:65&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=33&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=61&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=104&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=53&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:79&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:24&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=31&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=102&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=82&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=78&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=89&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=99&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:67&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522346 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=83&wt=json} status=0 QTime=0
[junit4] 2> 2522346 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:28&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=49&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=36&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=90&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:55&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:6&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=35&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=81&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:94&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:59&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:14&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=54&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=59&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=99&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=76&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=49&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=88&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=47&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=48&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=39&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=97&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=47&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:11&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=69&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=70&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=90&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=104&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:72&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:20&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=33&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=72&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:83&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=62&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=31&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=31&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=105&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=47&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:88&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:22&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=54&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:98&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:40&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=29&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:48&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:60&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=99&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=42&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=56&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=53&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:48&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=59&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=11&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:40&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=42&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=40&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=30&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=91&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=93&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:83&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:74&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=53&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:68&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=41&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=89&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=30&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:6&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=57&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:82&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=47&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=97&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=0
[junit4] 2> 2522347 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:83&omitHeader=true&w
[...truncated too long message...]
t4] 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.run(BatchEventProcessor.java:128)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> AsyncLogger error handling event seq=2, value='null':
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2050)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2127)
[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.run(BatchEventProcessor.java:128)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> AsyncLogger error handling event seq=3, value='null':
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2050)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2127)
[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.run(BatchEventProcessor.java:128)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> AsyncLogger error handling event seq=4, value='null':
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2050)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2127)
[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.run(BatchEventProcessor.java:128)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> AsyncLogger error handling event seq=5, value='null':
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2050)
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2127)
[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.run(BatchEventProcessor.java:128)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> Sep 05, 2018 12:28:05 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=16, name=Log4j2-TF-1-AsyncLoggerConfig--1, state=TIMED_WAITING, group=TGRP-TestXmlQParser]
[junit4] 2> at java.base@10/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@10/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2117)
[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.run(BatchEventProcessor.java:128)
[junit4] 2> at java.base@10/java.lang.Thread.run(Thread.java:844)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {date=BlockTreeOrds(blocksize=128), contents=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{}, maxPointsInLeafNode=360, maxMBSortInHeap=5.237937881389747, sim=RandomSimilarity(queryNorm=true): {date=DFR I(ne)Z(0.3), contents=LM Jelinek-Mercer(0.700000), doesNotExist=LM Jelinek-Mercer(0.100000)}, locale=en-VG, timezone=Singapore
[junit4] 2> NOTE: Linux 4.15.0-32-generic amd64/Oracle Corporation 10 (64-bit)/cpus=8,threads=2,free=437323896,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestXmlQParser]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestXmlQParser -Dtests.seed=A6ADE401B29C0D43 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=en-VG -Dtests.timezone=Singapore -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J0 | TestXmlQParser (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.search.TestXmlQParser:
[junit4] > 1) Thread[id=16, name=Log4j2-TF-1-AsyncLoggerConfig--1, state=TIMED_WAITING, group=TGRP-TestXmlQParser]
[junit4] > at java.base@10/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@10/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2117)
[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.run(BatchEventProcessor.java:128)
[junit4] > at java.base@10/java.lang.Thread.run(Thread.java:844)
[junit4] > at __randomizedtesting.SeedInfo.seed([A6ADE401B29C0D43]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=16, name=Log4j2-TF-1-AsyncLoggerConfig--1, state=TIMED_WAITING, group=TGRP-TestXmlQParser]
[junit4] > at java.base@10/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@10/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2117)
[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.run(BatchEventProcessor.java:128)
[junit4] > at java.base@10/java.lang.Thread.run(Thread.java:844)
[junit4] > at __randomizedtesting.SeedInfo.seed([A6ADE401B29C0D43]:0)
[junit4] Completed [4/5 (3!)] on J0 in 26.94s, 19 tests, 2 errors <<< FAILURES!
[...truncated 16 lines...]
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/common-build.xml:1568: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/common-build.xml:1092: There were test failures: 5 suites, 95 tests, 6 suite-level errors, 38 ignored [seed: A6ADE401B29C0D43]
Total time: 30 seconds
[repro] Setting last failure code to 256
[repro] Failures:
[repro] 3/5 failed: org.apache.solr.search.TestXmlQParser
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=7f0967ad9303f4fa7fa302bca0908c8754948aad, workspace=/var/lib/jenkins/workspace/Lucene-Solr-7.x-Linux
[WARNINGS] Computing warning deltas based on reference build #2688
Recording test results
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[JENKINS] Lucene-Solr-7.x-Linux (32bit/jdk1.8.0_172) - Build # 2690
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2690/
Java: 32bit/jdk1.8.0_172 -client -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestSimPolicyCloud.testCreateCollectionAddReplica
Error Message:
Timeout waiting for collection to become active Live Nodes: [127.0.0.1:10102_solr, 127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10103_solr] Last available state: DocCollection(testCreateCollectionAddReplica//clusterstate.json/41)={ "replicationFactor":"1", "pullReplicas":"0", "router":{"name":"compositeId"}, "maxShardsPerNode":"1", "autoAddReplicas":"false", "nrtReplicas":"1", "tlogReplicas":"0", "autoCreated":"true", "policy":"c1", "shards":{"shard1":{ "replicas":{"core_node1":{ "core":"testCreateCollectionAddReplica_shard1_replica_n1", "SEARCHER.searcher.maxDoc":0, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":10240, "node_name":"127.0.0.1:10103_solr", "state":"active", "type":"NRT", "INDEX.sizeInGB":9.5367431640625E-6, "SEARCHER.searcher.numDocs":0}}, "range":"80000000-7fffffff", "state":"active"}}}
Stack Trace:
java.lang.AssertionError: Timeout waiting for collection to become active
Live Nodes: [127.0.0.1:10102_solr, 127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10103_solr]
Last available state: DocCollection(testCreateCollectionAddReplica//clusterstate.json/41)={
"replicationFactor":"1",
"pullReplicas":"0",
"router":{"name":"compositeId"},
"maxShardsPerNode":"1",
"autoAddReplicas":"false",
"nrtReplicas":"1",
"tlogReplicas":"0",
"autoCreated":"true",
"policy":"c1",
"shards":{"shard1":{
"replicas":{"core_node1":{
"core":"testCreateCollectionAddReplica_shard1_replica_n1",
"SEARCHER.searcher.maxDoc":0,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":10240,
"node_name":"127.0.0.1:10103_solr",
"state":"active",
"type":"NRT",
"INDEX.sizeInGB":9.5367431640625E-6,
"SEARCHER.searcher.numDocs":0}},
"range":"80000000-7fffffff",
"state":"active"}}}
at __randomizedtesting.SeedInfo.seed([71FA1D45253B7559:F1DA786B34789DFF]:0)
at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:70)
at org.apache.solr.cloud.autoscaling.sim.TestSimPolicyCloud.testCreateCollectionAddReplica(TestSimPolicyCloud.java:123)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:110)
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:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
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 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:368)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.util.concurrent.TimeoutException: last state: DocCollection(testCreateCollectionAddReplica//clusterstate.json/41)={
"replicationFactor":"1",
"pullReplicas":"0",
"router":{"name":"compositeId"},
"maxShardsPerNode":"1",
"autoAddReplicas":"false",
"nrtReplicas":"1",
"tlogReplicas":"0",
"autoCreated":"true",
"policy":"c1",
"shards":{"shard1":{
"replicas":{"core_node1":{
"core":"testCreateCollectionAddReplica_shard1_replica_n1",
"SEARCHER.searcher.maxDoc":0,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":10240,
"node_name":"127.0.0.1:10103_solr",
"state":"active",
"type":"NRT",
"INDEX.sizeInGB":9.5367431640625E-6,
"SEARCHER.searcher.numDocs":0}},
"range":"80000000-7fffffff",
"state":"active"}}}
at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:112)
at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:64)
... 41 more
Build Log:
[...truncated 14277 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestSimPolicyCloud
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestSimPolicyCloud_71FA1D45253B7559-001/init-core-data-001
[junit4] 2> 3279499 DEBUG (SUITE-TestSimPolicyCloud-seed#[71FA1D45253B7559]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10100_solr
[junit4] 2> 3279499 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3279499 INFO (SUITE-TestSimPolicyCloud-seed#[71FA1D45253B7559]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 3279499 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 3279500 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 3279500 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 3279501 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 3279501 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3279501 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
[junit4] 2> 3279501 DEBUG (ScheduledTrigger-9114-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279505 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionSplitShard-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 3279505 INFO (TEST-TestSimPolicyCloud.testCreateCollectionSplitShard-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3279505 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 3279506 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionSplitShard-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 3279506 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionSplitShard-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 3279506 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionSplitShard-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 3279506 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionSplitShard-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 3279507 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionSplitShard-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 3279507 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionSplitShard-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3279508 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3279508 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 3279508 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 3279508 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 3279509 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 3279509 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3279509 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 3279509 DEBUG (ScheduledTrigger-9119-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279529 DEBUG (ScheduledTrigger-9119-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279550 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279570 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279591 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279611 DEBUG (simCloudManagerPool-9118-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3279611 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279612 DEBUG (simCloudManagerPool-9118-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 3279612 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 3279613 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3279613 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 3279631 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279633 INFO (simCloudManagerPool-9118-thread-2) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1808079791 sessionWrapper.createTime 1808079615717920, this.sessionWrapper.createTime 1808079615717920
[junit4] 2> 3279645 DEBUG (simCloudManagerPool-9118-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testCreateCollectionSplitShard / shard1
[junit4] 2> 3279645 DEBUG (simCloudManagerPool-9118-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testCreateCollectionSplitShard / shard1
[junit4] 2> 3279645 DEBUG (simCloudManagerPool-9118-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCreateCollectionSplitShard / shard1: core_node1
[junit4] 2> 3279651 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279655 DEBUG (simCloudManagerPool-9118-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testCreateCollectionSplitShard / shard1
[junit4] 2> 3279672 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279692 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279712 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279732 DEBUG (ScheduledTrigger-9119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279753 DEBUG (ScheduledTrigger-9119-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279768 INFO (simCloudManagerPool-9118-thread-6) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1808086541 sessionWrapper.createTime 1808086042635470, this.sessionWrapper.createTime 1808086042635470
[junit4] 2> 3279773 DEBUG (ScheduledTrigger-9119-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279793 DEBUG (ScheduledTrigger-9119-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279812 DEBUG (simCloudManagerPool-9118-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testCreateCollectionSplitShard / shard1
[junit4] 2> 3279812 DEBUG (simCloudManagerPool-9118-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testCreateCollectionSplitShard / shard1_1
[junit4] 2> 3279812 DEBUG (simCloudManagerPool-9118-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testCreateCollectionSplitShard / shard1_0
[junit4] 2> 3279812 DEBUG (simCloudManagerPool-9118-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testCreateCollectionSplitShard / shard1_1
[junit4] 2> 3279812 DEBUG (simCloudManagerPool-9118-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testCreateCollectionSplitShard / shard1_0
[junit4] 2> 3279814 DEBUG (ScheduledTrigger-9119-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279814 DEBUG (simCloudManagerPool-9118-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCreateCollectionSplitShard / shard1_1: core_node7
[junit4] 2> 3279814 DEBUG (simCloudManagerPool-9118-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCreateCollectionSplitShard / shard1_0: core_node6
[junit4] 2> 3279834 DEBUG (ScheduledTrigger-9119-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279854 DEBUG (ScheduledTrigger-9119-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279875 DEBUG (ScheduledTrigger-9119-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279895 DEBUG (ScheduledTrigger-9119-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279915 DEBUG (ScheduledTrigger-9119-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279916 INFO (TEST-TestSimPolicyCloud.testCreateCollectionSplitShard-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 5
[junit4] 2> ## Empty nodes: 5
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: []
[junit4] 2> ## Max replicas per node: 0
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 0
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - DELETE 1
[junit4] 2> ## - SPLITSHARD 1
[junit4] 2> ## - autoscaling 1
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 3279922 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 3279922 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 3279923 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3279923 INFO (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3279923 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3279923 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 3279923 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:177) ~[java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 3279923 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 3279923 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 3279923 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 3279923 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 3279923 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3279925 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3279925 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 3279925 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion -1
[junit4] 2> 3279925 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 3279926 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 3279926 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3279926 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 3279926 DEBUG (ScheduledTrigger-9122-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279947 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279967 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3279987 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280008 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280025 INFO (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.TestSimPolicyCloud NRT 127.0.0.1:10100_solr PULL 127.0.0.1:10104_solr , TLOG 127.0.0.1:10104_solr
[junit4] 2> 3280027 DEBUG (simCloudManagerPool-9121-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3280027 DEBUG (simCloudManagerPool-9121-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 3280028 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 3280028 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280028 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 3280028 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280042 INFO (simCloudManagerPool-9121-thread-2) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1808100245 sessionWrapper.createTime 1808100122854320, this.sessionWrapper.createTime 1808100122854320
[junit4] 2> 3280053 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280053 DEBUG (simCloudManagerPool-9121-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for policiesTest / s1
[junit4] 2> 3280056 DEBUG (simCloudManagerPool-9121-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for policiesTest / s1
[junit4] 2> 3280057 DEBUG (simCloudManagerPool-9121-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for policiesTest / s1: core_node1
[junit4] 2> 3280067 DEBUG (simCloudManagerPool-9121-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader policiesTest / s1
[junit4] 2> 3280073 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280078 DEBUG (simCloudManagerPool-9121-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader policiesTest / s1
[junit4] 2> 3280093 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280114 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280134 DEBUG (ScheduledTrigger-9122-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280154 DEBUG (ScheduledTrigger-9122-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280175 DEBUG (ScheduledTrigger-9122-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280189 INFO (simCloudManagerPool-9121-thread-7) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1808107578 sessionWrapper.createTime 1808107326841770, this.sessionWrapper.createTime 1808107326841770
[junit4] 2> 3280195 DEBUG (ScheduledTrigger-9122-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280215 DEBUG (ScheduledTrigger-9122-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280231 DEBUG (simCloudManagerPool-9121-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for policiesTest / s3
[junit4] 2> 3280231 DEBUG (simCloudManagerPool-9121-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader policiesTest / s1
[junit4] 2> 3280232 DEBUG (simCloudManagerPool-9121-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for policiesTest / s3
[junit4] 2> 3280233 DEBUG (simCloudManagerPool-9121-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for policiesTest / s3: core_node4
[junit4] 2> 3280234 INFO (TEST-TestSimPolicyCloud.testCreateCollectionAddShardWithReplicaTypeUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 5
[junit4] 2> ## Empty nodes: 3
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [policiesTest]
[junit4] 2> ## Max replicas per node: 4
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 6
[junit4] 2> ## * policiesTest 6
[junit4] 2> ## - active 6
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - CREATESHARD 1
[junit4] 2> ## - autoscaling 1
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 3280236 DEBUG (ScheduledTrigger-9122-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280238 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 3280238 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 3280239 INFO (TEST-TestSimPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3280239 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3280239 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280239 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 3280239 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:177) ~[java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 3280239 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 3280239 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 3280239 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 3280239 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 3280239 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3280243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3280243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 3280243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion -1
[junit4] 2> 3280243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 3280244 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 3280244 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280244 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 3280244 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280265 DEBUG (ScheduledTrigger-9125-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280285 DEBUG (ScheduledTrigger-9125-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280306 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280326 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280344 DEBUG (simCloudManagerPool-9124-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3280344 DEBUG (simCloudManagerPool-9124-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 3280345 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 3280345 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280345 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 3280347 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280358 INFO (simCloudManagerPool-9124-thread-2) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1808116040 sessionWrapper.createTime 1808115979801120, this.sessionWrapper.createTime 1808115979801120
[junit4] 2> 3280367 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280369 DEBUG (simCloudManagerPool-9124-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for policiesTest / s1
[junit4] 2> 3280369 DEBUG (simCloudManagerPool-9124-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider -- no replicas in policiesTest / s2
[junit4] 2> 3280369 DEBUG (simCloudManagerPool-9124-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for policiesTest / s1
[junit4] 2> 3280370 DEBUG (simCloudManagerPool-9124-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for policiesTest / s1: core_node7
[junit4] 2> 3280380 DEBUG (simCloudManagerPool-9124-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader policiesTest / s1
[junit4] 2> 3280380 DEBUG (simCloudManagerPool-9124-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for policiesTest / s2
[junit4] 2> 3280380 DEBUG (simCloudManagerPool-9124-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for policiesTest / s2
[junit4] 2> 3280380 DEBUG (simCloudManagerPool-9124-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for policiesTest / s2: core_node8
[junit4] 2> 3280387 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280408 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280428 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280448 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280468 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280483 INFO (simCloudManagerPool-9124-thread-7) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1808122270 sessionWrapper.createTime 1808122242242870, this.sessionWrapper.createTime 1808122242242870
[junit4] 2> 3280488 DEBUG (ScheduledTrigger-9125-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280494 DEBUG (simCloudManagerPool-9124-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for policiesTest / s3
[junit4] 2> 3280494 DEBUG (simCloudManagerPool-9124-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader policiesTest / s1
[junit4] 2> 3280494 DEBUG (simCloudManagerPool-9124-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader policiesTest / s2
[junit4] 2> 3280494 DEBUG (simCloudManagerPool-9124-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for policiesTest / s3
[junit4] 2> 3280494 DEBUG (simCloudManagerPool-9124-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for policiesTest / s3: core_node9
[junit4] 2> 3280496 INFO (TEST-TestSimPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 5
[junit4] 2> ## Empty nodes: 4
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [policiesTest]
[junit4] 2> ## Max replicas per node: 3
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 3
[junit4] 2> ## * policiesTest 3
[junit4] 2> ## - active 3
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - CREATESHARD 1
[junit4] 2> ## - autoscaling 1
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 3280500 DEBUG (TEST-TestSimPolicyCloud.testMetricsTag-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 3280500 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 3280500 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3280500 INFO (TEST-TestSimPolicyCloud.testMetricsTag-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3280500 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280500 DEBUG (TEST-TestSimPolicyCloud.testMetricsTag-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 3280501 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:177) ~[java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 3280501 DEBUG (TEST-TestSimPolicyCloud.testMetricsTag-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 3280501 DEBUG (TEST-TestSimPolicyCloud.testMetricsTag-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 3280501 DEBUG (TEST-TestSimPolicyCloud.testMetricsTag-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 3280501 DEBUG (TEST-TestSimPolicyCloud.testMetricsTag-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 3280501 DEBUG (TEST-TestSimPolicyCloud.testMetricsTag-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3280501 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3280502 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 3280502 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion -1
[junit4] 2> 3280502 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 3280502 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 3280503 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280503 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 3280503 DEBUG (ScheduledTrigger-9128-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280523 DEBUG (ScheduledTrigger-9128-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280543 DEBUG (ScheduledTrigger-9128-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280564 DEBUG (ScheduledTrigger-9128-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280584 DEBUG (ScheduledTrigger-9128-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280603 ERROR (simCloudManagerPool-9127-thread-1) [ ] o.a.s.h.RequestHandlerBase org.apache.solr.api.ApiBag$ExceptionWithErrObject: Error in command payload, errors: [{set-cluster-policy=[{cores=<10, node=#ANY}, {replica=<2, shard=#EACH, node=#ANY}, {metrics:abc=overseer, replica=0}], errorMessages=[Invalid metrics: param in {
[junit4] 2> "metrics:abc":"overseer",
[junit4] 2> "replica":0} must have at 2 or 3 segments after 'metrics:' separated by ':']}],
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.processOps(AutoScalingHandler.java:210)
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.handleRequestBody(AutoScalingHandler.java:148)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199)
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:684)
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$15(SimCloudManager.java:629)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 3280603 DEBUG (simCloudManagerPool-9127-thread-1) [ ] o.a.s.c.a.s.SimCloudManager -- exception handling request
[junit4] 2> org.apache.solr.api.ApiBag$ExceptionWithErrObject: Error in command payload
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.processOps(AutoScalingHandler.java:210) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.handleRequestBody(AutoScalingHandler.java:148) ~[java/:?]
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:684) ~[test/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$15(SimCloudManager.java:629) ~[test/:?]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_172]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 3280604 DEBUG (simCloudManagerPool-9127-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3280604 DEBUG (simCloudManagerPool-9127-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 3280604 DEBUG (ScheduledTrigger-9128-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280605 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
[junit4] 2> 3280605 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280605 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12
[junit4] 2> 3280619 INFO (simCloudManagerPool-9127-thread-3) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1808129090 sessionWrapper.createTime 1808128979682620, this.sessionWrapper.createTime 1808128979682620
[junit4] 2> 3280625 DEBUG (ScheduledTrigger-9128-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280630 DEBUG (simCloudManagerPool-9127-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for metricsTest / shard1
[junit4] 2> 3280631 DEBUG (simCloudManagerPool-9127-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for metricsTest / shard1
[junit4] 2> 3280631 DEBUG (simCloudManagerPool-9127-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for metricsTest / shard1: core_node1
[junit4] 2> 3280632 INFO (TEST-TestSimPolicyCloud.testMetricsTag-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 5
[junit4] 2> ## Empty nodes: 4
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [metricsTest]
[junit4] 2> ## Max replicas per node: 1
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 1
[junit4] 2> ## * metricsTest 1
[junit4] 2> ## - active 1
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 2
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 3280637 DEBUG (TEST-TestSimPolicyCloud.testDataProviderPerReplicaDetails-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
[junit4] 2> 3280637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
[junit4] 2> 3280637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3280637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion 13
[junit4] 2> 3280637 INFO (TEST-TestSimPolicyCloud.testDataProviderPerReplicaDetails-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3280637 DEBUG (TEST-TestSimPolicyCloud.testDataProviderPerReplicaDetails-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 3280637 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 3280637 DEBUG (TEST-TestSimPolicyCloud.testDataProviderPerReplicaDetails-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 3280637 DEBUG (TEST-TestSimPolicyCloud.testDataProviderPerReplicaDetails-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 3280637 DEBUG (TEST-TestSimPolicyCloud.testDataProviderPerReplicaDetails-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 3280637 DEBUG (TEST-TestSimPolicyCloud.testDataProviderPerReplicaDetails-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 3280637 DEBUG (TEST-TestSimPolicyCloud.testDataProviderPerReplicaDetails-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3280640 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3280640 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
[junit4] 2> 3280640 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion -1
[junit4] 2> 3280640 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
[junit4] 2> 3280641 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 3280641 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280641 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
[junit4] 2> 3280641 DEBUG (ScheduledTrigger-9131-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280661 DEBUG (ScheduledTrigger-9131-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280682 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280702 DEBUG (ScheduledTrigger-9131-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280722 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280742 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280761 DEBUG (simCloudManagerPool-9130-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for perReplicaDataColl / shard1
[junit4] 2> 3280761 DEBUG (simCloudManagerPool-9130-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for perReplicaDataColl / shard1
[junit4] 2> 3280761 DEBUG (simCloudManagerPool-9130-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for perReplicaDataColl / shard1: core_node1
[junit4] 2> 3280762 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280771 DEBUG (simCloudManagerPool-9130-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader perReplicaDataColl / shard1
[junit4] 2> 3280782 DEBUG (simCloudManagerPool-9130-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader perReplicaDataColl / shard1
[junit4] 2> 3280782 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280793 DEBUG (simCloudManagerPool-9130-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader perReplicaDataColl / shard1
[junit4] 2> 3280803 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280803 DEBUG (simCloudManagerPool-9130-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader perReplicaDataColl / shard1
[junit4] 2> 3280823 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280843 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280863 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280884 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280904 DEBUG (ScheduledTrigger-9131-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280907 INFO (TEST-TestSimPolicyCloud.testDataProviderPerReplicaDetails-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 5
[junit4] 2> ## Empty nodes: 5
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: []
[junit4] 2> ## Max replicas per node: 0
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 0
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - DELETE 1
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 3280912 DEBUG (TEST-TestSimPolicyCloud.testDataProvider-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
[junit4] 2> 3280912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
[junit4] 2> 3280912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3280912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
[junit4] 2> 3280913 INFO (TEST-TestSimPolicyCloud.testDataProvider-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3280913 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 3280913 DEBUG (TEST-TestSimPolicyCloud.testDataProvider-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 3280913 DEBUG (TEST-TestSimPolicyCloud.testDataProvider-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 3280913 DEBUG (TEST-TestSimPolicyCloud.testDataProvider-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 3280913 DEBUG (TEST-TestSimPolicyCloud.testDataProvider-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 3280913 DEBUG (TEST-TestSimPolicyCloud.testDataProvider-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 3280913 DEBUG (TEST-TestSimPolicyCloud.testDataProvider-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3280914 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3280914 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16
[junit4] 2> 3280914 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion -1
[junit4] 2> 3280914 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16
[junit4] 2> 3280914 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 3280914 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3280914 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16
[junit4] 2> 3280914 DEBUG (ScheduledTrigger-9134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280935 DEBUG (ScheduledTrigger-9134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280955 DEBUG (ScheduledTrigger-9134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280975 DEBUG (ScheduledTrigger-9134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3280995 DEBUG (ScheduledTrigger-9134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281016 DEBUG (ScheduledTrigger-9134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281035 DEBUG (simCloudManagerPool-9133-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for policiesTest / shard1
[junit4] 2> 3281035 DEBUG (simCloudManagerPool-9133-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for policiesTest / shard1
[junit4] 2> 3281036 DEBUG (simCloudManagerPool-9133-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for policiesTest / shard1: core_node10
[junit4] 2> 3281036 DEBUG (ScheduledTrigger-9134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281046 DEBUG (simCloudManagerPool-9133-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader policiesTest / shard1
[junit4] 2> 3281056 DEBUG (ScheduledTrigger-9134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281069 INFO (TEST-TestSimPolicyCloud.testDataProvider-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 5
[junit4] 2> ## Empty nodes: 3
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [policiesTest]
[junit4] 2> ## Max replicas per node: 1
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 2
[junit4] 2> ## * policiesTest 2
[junit4] 2> ## - active 2
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - ADDROLE 1
[junit4] 2> ## - CREATE 1
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 3281074 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddReplica-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 17
[junit4] 2> 3281074 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 17
[junit4] 2> 3281075 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3281075 INFO (TEST-TestSimPolicyCloud.testCreateCollectionAddReplica-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3281075 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3281075 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:177) ~[java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 3281075 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddReplica-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 3281075 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddReplica-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 3281075 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddReplica-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 3281075 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddReplica-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 3281075 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddReplica-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 3281075 DEBUG (TEST-TestSimPolicyCloud.testCreateCollectionAddReplica-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3281076 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3281076 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 18
[junit4] 2> 3281076 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 18, lastZnodeVersion -1
[junit4] 2> 3281076 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 18
[junit4] 2> 3281077 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 3281077 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3281077 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 18, lastZnodeVersion 18
[junit4] 2> 3281077 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281097 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281117 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281138 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281158 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281177 DEBUG (simCloudManagerPool-9136-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3281177 DEBUG (simCloudManagerPool-9136-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 19
[junit4] 2> 3281178 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 19
[junit4] 2> 3281178 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3281178 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 19, lastZnodeVersion 19
[junit4] 2> 3281178 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281190 INFO (simCloudManagerPool-9136-thread-2) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1808157603 sessionWrapper.createTime 1808157576205420, this.sessionWrapper.createTime 1808157576205420
[junit4] 2> 3281199 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281200 DEBUG (simCloudManagerPool-9136-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testCreateCollectionAddReplica / shard1
[junit4] 2> 3281201 DEBUG (simCloudManagerPool-9136-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testCreateCollectionAddReplica / shard1
[junit4] 2> 3281201 DEBUG (simCloudManagerPool-9136-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCreateCollectionAddReplica / shard1: core_node1
[junit4] 2> 3281219 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281240 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281260 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281280 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281300 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281321 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281341 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281361 DEBUG (ScheduledTrigger-9137-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281381 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281401 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281422 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281442 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281462 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281482 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281503 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281523 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281543 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281563 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281583 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281604 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281624 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281644 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281664 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281684 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281705 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281725 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281745 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281765 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281786 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281806 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281826 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281846 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281866 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281887 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281907 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281927 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281947 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281967 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3281988 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282008 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282028 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282048 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282068 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282088 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282109 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282129 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282149 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282169 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282189 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282209 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282230 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282250 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282278 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282298 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282318 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282338 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282359 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282379 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282399 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282419 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282439 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282459 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282480 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282500 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282520 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282540 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282560 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282581 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282601 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282621 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282641 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282661 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282681 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282702 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282722 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282742 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282762 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282782 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282802 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282823 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282843 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282863 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282883 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282903 DEBUG (ScheduledTrigger-9137-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282924 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282944 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282964 DEBUG (ScheduledTrigger-9137-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282984 DEBUG (ScheduledTrigger-9137-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5
[junit4] 2> 3282992 INFO (TEST-TestSimPolicyCloud.testCreateCollectionAddReplica-seed#[71FA1D45253B7559]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 5
[junit4] 2> ## Empty nodes: 4
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [testCreateCollectionAddReplica]
[junit4] 2> ## Max replicas per node: 1
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 1
[junit4] 2> ## * testCreateCollectionAddReplica 1
[junit4] 2> ## - active 1
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 1
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSimPolicyCloud -Dtests.method=testCreateCollectionAddReplica -Dtests.seed=71FA1D45253B7559 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es-DO -Dtests.timezone=America/Thunder_Bay -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 1.92s J0 | TestSimPolicyCloud.testCreateCollectionAddReplica <<<
[junit4] > Throwable #1: java.lang.AssertionError: Timeout waiting for collection to become active
[junit4] > Live Nodes: [127.0.0.1:10102_solr, 127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10101_solr, 127.0.0.1:10103_solr]
[junit4] > Last available state: DocCollection(testCreateCollectionAddReplica//clusterstate.json/41)={
[junit4] > "replicationFactor":"1",
[junit4] > "pullReplicas":"0",
[junit4] > "router":{"name":"compositeId"},
[junit4] > "maxShardsPerNode":"1",
[junit4] > "autoAddReplicas":"false",
[junit4] > "nrtReplicas":"1",
[junit4] > "tlogReplicas":"0",
[junit4] > "autoCreated":"true",
[junit4] > "policy":"c1",
[junit4] > "shards":{"shard1":{
[junit4] > "replicas":{"core_node1":{
[junit4] > "core":"testCreateCollectionAddReplica_shard1_replica_n1",
[junit4] > "SEARCHER.searcher.maxDoc":0,
[junit4] > "SEARCHER.searcher.deletedDocs":0,
[junit4] > "INDEX.sizeInBytes":10240,
[junit4] > "node_name":"127.0.0.1:10103_solr",
[junit4] > "state":"active",
[junit4] > "type":"NRT",
[junit4] > "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] > "SEARCHER.searcher.numDocs":0}},
[junit4] > "range":"80000000-7fffffff",
[junit4] > "state":"active"}}}
[junit4] > at __randomizedtesting.SeedInfo.seed([71FA1D45253B7559:F1DA786B34789DFF]:0)
[junit4] > at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:70)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.TestSimPolicyCloud.testCreateCollectionAddReplica(TestSimPolicyCloud.java:123)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > Caused by: java.util.concurrent.TimeoutException: last state: DocCollection(testCreateCollectionAddReplica//clusterstate.json/41)={
[junit4] > "replicationFactor":"1",
[junit4] > "pullReplicas":"0",
[junit4] > "router":{"name":"compositeId"},
[junit4] > "maxShardsPerNode":"1",
[junit4] > "autoAddReplicas":"false",
[junit4] > "nrtReplicas":"1",
[junit4] > "tlogReplicas":"0",
[junit4] > "autoCreated":"true",
[junit4] > "policy":"c1",
[junit4] > "shards":{"shard1":{
[junit4] > "replicas":{"core_node1":{
[junit4] > "core":"testCreateCollectionAddReplica_shard1_replica_n1",
[junit4] > "SEARCHER.searcher.maxDoc":0,
[junit4] > "SEARCHER.searcher.deletedDocs":0,
[junit4] > "INDEX.sizeInBytes":10240,
[junit4] > "node_name":"127.0.0.1:10103_solr",
[junit4] > "state":"active",
[junit4] > "type":"NRT",
[junit4] > "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] > "SEARCHER.searcher.numDocs":0}},
[junit4] > "range":"80000000-7fffffff",
[junit4] > "state":"active"}}}
[junit4] > at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:112)
[junit4] > at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:64)
[junit4] > ... 41 more
[junit4] 2> 3282994 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 3282995 DEBUG (SUITE-TestSimPolicyCloud-seed#[71FA1D45253B7559]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 3282995 DEBUG (SUITE-TestSimPolicyCloud-seed#[71FA1D45253B7559]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 3282995 DEBUG (SUITE-TestSimPolicyCloud-seed#[71FA1D45253B7559]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 3282995 DEBUG (SUITE-TestSimPolicyCloud-seed#[71FA1D45253B7559]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 3282995 DEBUG (SUITE-TestSimPolicyCloud-seed#[71FA1D45253B7559]-worker) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 3282995 DEBUG (SUITE-TestSimPolicyCloud-seed#[71FA1D45253B7559]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestSimPolicyCloud_71FA1D45253B7559-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1007, maxMBSortInHeap=5.327958718023792, sim=RandomSimilarity(queryNorm=false): {}, locale=es-DO, timezone=America/Thunder_Bay
[junit4] 2> NOTE: Linux 4.15.0-32-generic i386/Oracle Corporation 1.8.0_172 (32-bit)/cpus=8,threads=1,free=178036864,total=378007552
[junit4] 2> NOTE: All tests run in this JVM: [TestFaceting, TestCloudDeleteByQuery, TestConfigSetImmutable, DistributedQueryElevationComponentTest, TestUpdate, AnalysisAfterCoreReloadTest, PeerSyncReplicationTest, DistributedFacetSimpleRefinementLongTailTest, TestCrossCoreJoin, DistributedFacetPivotSmallAdvancedTest, TestDocTermOrdsUninvertLimit, TestManagedSchema, TestRawResponseWriter, RulesTest, SampleTest, TestConfigReload, DirectSolrConnectionTest, TestOmitPositions, TestRangeQuery, ZkShardTermsTest, TestQueryUtils, TestRealTimeGet, TestSolrConfigHandlerCloud, TestStressLiveNodes, ChaosMonkeyNothingIsSafeTest, TestDistributedMissingSort, SolrCoreTest, StatelessScriptUpdateProcessorFactoryTest, TestQuerySenderNoQuery, XsltUpdateRequestHandlerTest, TestLeaderInitiatedRecoveryThread, DateRangeFieldTest, NodeLostTriggerIntegrationTest, ChaosMonkeySafeLeaderWithPullReplicasTest, TestFiltering, TestBulkSchemaConcurrent, LeaderFailureAfterFreshStartTest, TestSearcherReuse, HighlighterMaxOffsetTest, TestSkipOverseerOperations, TestScoreJoinQPScore, DeleteLastCustomShardedReplicaTest, TestLMDirichletSimilarityFactory, TestPartialUpdateDeduplication, LoggingHandlerTest, DistanceFunctionTest, TestFieldTypeCollectionResource, TestInPlaceUpdatesStandalone, RemoteQueryErrorTest, TestReload, TestCollectionAPIs, TestLFUCache, TestTolerantUpdateProcessorRandomCloud, TestMergePolicyConfig, TermVectorComponentDistributedTest, TestPayloadScoreQParserPlugin, StatsReloadRaceTest, DefaultValueUpdateProcessorTest, TestComplexPhraseQParserPlugin, BigEndianAscendingWordDeserializerTest, SolrJmxReporterTest, NodeMutatorTest, UtilsToolTest, DocValuesTest, ClassificationUpdateProcessorIntegrationTest, TestRandomDVFaceting, QueryElevationComponentTest, TestCloudJSONFacetSKG, EchoParamsTest, CursorPagingTest, SolrCLIZkUtilsTest, TestValueSourceCache, TestSolrQueryResponse, V2ApiIntegrationTest, HdfsCollectionsAPIDistributedZkTest, TestLocalFSCloudBackupRestore, MissingSegmentRecoveryTest, DistributedFacetExistsSmallTest, TriggerEventQueueTest, TestSimClusterStateProvider, TestConfigSetsAPI, SolrIndexSplitterTest, TestSolrCloudWithHadoopAuthPlugin, CdcrBidirectionalTest, CollectionReloadTest, CollectionsAPIDistributedZkTest, TestCoreContainer, TestSimDistributedQueue, HdfsTlogReplayBufferedWhileIndexingTest, TestSha256AuthenticationProvider, DistributedMLTComponentTest, TestSimLargeCluster, TestSchemaResource, TestZkChroot, DateMathParserTest, CreateCollectionCleanupTest, TestCloudRecovery, ExplicitHLLTest, CoreSorterTest, TestCodecSupport, SuggesterWFSTTest, TestCollationField, IndexSchemaRuntimeFieldTest, TestManagedSynonymFilterFactory, OverseerStatusTest, TestPullReplicaErrorHandling, TestMinMaxOnMultiValuedField, TestLegacyField, TestFuzzyAnalyzedSuggestions, TestCollectionAPI, SuggesterFSTTest, TestPivotHelperCode, TestSerializedLuceneMatchVersion, AliasIntegrationTest, LegacyCloudClusterPropTest, TestCustomDocTransformer, TestNumericRangeQuery64, BadIndexSchemaTest, TestCustomStream, ShardRoutingTest, UpdateRequestProcessorFactoryTest, HdfsNNFailoverTest, TestSort, TestEmbeddedSolrServerConstructors, PreAnalyzedFieldTest, MetricsHandlerTest, TestExactSharedStatsCache, TestExceedMaxTermLength, QueryResultKeyTest, SimpleMLTQParserTest, SignificantTermsQParserPluginTest, WrapperMergePolicyFactoryTest, TestBlendedInfixSuggestions, TestMacroExpander, BlockCacheTest, TestGroupingSearch, TestHighlightDedupGrouping, TestJoin, TestSolrCoreProperties, TestTolerantSearch, TestTrie, PathHierarchyTokenizerFactoryTest, ProtectedTermFilterFactoryTest, TestCharFilters, TestLuceneMatchVersion, TestReversedWildcardFilterFactory, TestWordDelimiterFilterFactory, TokenizerChainTest, TestLuceneIndexBackCompat, TestEmbeddedSolrServerAdminHandler, ConnectionReuseTest, ActionThrottleTest, AddReplicaTest, BasicDistributedZk2Test, BasicDistributedZkTest, TriggerCooldownIntegrationTest, TestSimPolicyCloud]
[junit4] Completed [527/831 (1!)] on J0 in 3.53s, 7 tests, 1 failure <<< FAILURES!
[...truncated 45892 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2690/consoleText
[repro] Revision: 7f0967ad9303f4fa7fa302bca0908c8754948aad
[repro] Ant options: "-Dargs=-client -XX:+UseSerialGC"
[repro] Repro line: ant test -Dtestcase=TestSimPolicyCloud -Dtests.method=testCreateCollectionAddReplica -Dtests.seed=71FA1D45253B7559 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es-DO -Dtests.timezone=America/Thunder_Bay -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestSimPolicyCloud
[repro] ant compile-test
[...truncated 3437 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestSimPolicyCloud" -Dtests.showOutput=onerror "-Dargs=-client -XX:+UseSerialGC" -Dtests.seed=71FA1D45253B7559 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es-DO -Dtests.timezone=America/Thunder_Bay -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[...truncated 101 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.sim.TestSimPolicyCloud
[repro] Exiting with code 0
[...truncated 40 lines...]