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/05/12 00:17:38 UTC
[JENKINS] Lucene-Solr-master-Linux (32bit/jdk1.8.0_162) - Build #
21994 - Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21994/
Java: 32bit/jdk1.8.0_162 -client -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.search.TestStressReorder.testStressReorderVersions
Error Message:
Captured an uncaught exception in thread: Thread[id=31078, name=WRITER9, state=RUNNABLE, group=TGRP-TestStressReorder]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=31078, name=WRITER9, state=RUNNABLE, group=TGRP-TestStressReorder]
at __randomizedtesting.SeedInfo.seed([C2D69ECAC5E27E5:10EB50FAA695A368]:0)
Caused by: java.lang.RuntimeException: java.lang.NullPointerException
at __randomizedtesting.SeedInfo.seed([C2D69ECAC5E27E5]:0)
at org.apache.solr.search.TestStressReorder$1.run(TestStressReorder.java:253)
Caused by: java.lang.NullPointerException
at org.apache.solr.update.UpdateLog.getCurrentLogSizeFromStream(UpdateLog.java:299)
at org.apache.solr.update.DirectUpdateHandler2.getCurrentTLogSize(DirectUpdateHandler2.java:1007)
at org.apache.solr.update.DirectUpdateHandler2.updateDeleteTrackers(DirectUpdateHandler2.java:432)
at org.apache.solr.update.DirectUpdateHandler2.delete(DirectUpdateHandler2.java:465)
at org.apache.solr.update.processor.RunUpdateProcessor.processDelete(RunUpdateProcessorFactory.java:75)
at org.apache.solr.update.processor.UpdateRequestProcessor.processDelete(UpdateRequestProcessor.java:59)
at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalDelete(DistributedUpdateProcessor.java:956)
at org.apache.solr.update.processor.DistributedUpdateProcessor.versionDelete(DistributedUpdateProcessor.java:1844)
at org.apache.solr.update.processor.DistributedUpdateProcessor.doDeleteById(DistributedUpdateProcessor.java:1381)
at org.apache.solr.update.processor.DistributedUpdateProcessor.processDelete(DistributedUpdateProcessor.java:1359)
at org.apache.solr.update.processor.LogUpdateProcessorFactory$LogUpdateProcessor.processDelete(LogUpdateProcessorFactory.java:124)
at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.handleDeleteMap(JsonLoader.java:394)
at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.handleDeleteCommand(JsonLoader.java:311)
at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.processUpdate(JsonLoader.java:171)
at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.load(JsonLoader.java:121)
at org.apache.solr.handler.loader.JsonLoader.load(JsonLoader.java:84)
at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:97)
at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199)
at org.apache.solr.core.SolrCore.execute(SolrCore.java:2510)
at org.apache.solr.servlet.DirectSolrConnection.request(DirectSolrConnection.java:125)
at org.apache.solr.SolrTestCaseJ4.updateJ(SolrTestCaseJ4.java:1286)
at org.apache.solr.SolrTestCaseJ4.deleteAndGetVersion(SolrTestCaseJ4.java:1464)
at org.apache.solr.search.TestStressReorder$1.run(TestStressReorder.java:184)
Build Log:
[...truncated 13677 lines...]
[junit4] Suite: org.apache.solr.search.TestStressReorder
[junit4] 2> 1552441 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.search.TestStressReorder_C2D69ECAC5E27E5-001/init-core-data-001
[junit4] 2> 1552442 WARN (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1011 numCloses=1011
[junit4] 2> 1552442 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1552444 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 1552446 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 1552446 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1552480 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 1552507 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 1552591 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1552645 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@11ffc77
[junit4] 2> 1552652 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@11ffc77
[junit4] 2> 1552653 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@11ffc77
[junit4] 2> 1552654 INFO (coreLoadExecutor-6751-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1552654 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1552697 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 1552711 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1552784 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1552795 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1, trusted=true
[junit4] 2> 1552795 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@11ffc77
[junit4] 2> 1552796 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1552796 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.search.TestStressReorder_C2D69ECAC5E27E5-001/init-core-data-001/]
[junit4] 2> 1552798 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=72.689453125, floorSegmentMB=1.9013671875, forceMergeDeletesPctAllowed=2.45416667519729, segmentsPerTier=28.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7523069537928725
[junit4] 2> 1552802 WARN (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 1552851 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1552851 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1552853 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1552853 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1552854 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=26.65234375, floorSegmentMB=0.8916015625, forceMergeDeletesPctAllowed=25.989780630057016, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1552854 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@8ccf1b[collection1] main]
[junit4] 2> 1552854 WARN (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Cannot write to config directory /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf; switching to use InMemory storage instead.
[junit4] 2> 1552855 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 1552856 INFO (searcherExecutor-6752-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@8ccf1b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1552856 INFO (coreLoadExecutor-6751-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1600212734961516544
[junit4] 2> 1552858 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 1552862 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStressReorderVersions
[junit4] 2> 1552862 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1552863 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@d7395c[collection1] realtime]
[junit4] 2> 1552863 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 0
[junit4] 2> 1552863 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1600212734968856576,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1552863 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@68b7c4 commitCommandVersion:1600212734968856576
[junit4] 2> 1552864 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@197f509[collection1] main]
[junit4] 2> 1552864 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1552866 INFO (searcherExecutor-6752-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@197f509[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1552866 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 2
[junit4] 2> 1552868 INFO (TEST-TestStressReorder.testStressReorderVersions-seed#[C2D69ECAC5E27E5]) [ ] o.a.s.s.TestStressReorder VERBOSE: commitPercent 8 softCommitPercent 68 deletePercent 14 deleteByQueryPercent 6 ndocs 29 nWriteThreads 13 percentRealtimeQuery 75 operations 50000 nReadThreads 17
[junit4] 2> 1552870 INFO (WRITER0) [ ] o.a.s.s.TestStressReorder VERBOSE: hardCommit start
[junit4] 2> 1552870 INFO (WRITER2) [ ] o.a.s.s.TestStressReorder VERBOSE: deleting id 7 val= 2 version 2
[junit4] 2> 1552871 INFO (WRITER5) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 0 val= 2 version 4
[junit4] 2> 1552871 INFO (WRITER4) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 0 val= 2 version 3
[junit4] 2> 1552871 INFO (WRITER0) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1600212734977245184,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1552871 INFO (WRITER6) [ ] o.a.s.s.TestStressReorder VERBOSE: deleteByQuery id 28 val= 2 version 5
[junit4] 2> 1552871 INFO (WRITER3) [ ] o.a.s.s.TestStressReorder VERBOSE: hardCommit start
[junit4] 2> 1552870 INFO (WRITER1) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 0 val= 2 version 1
[junit4] 2> 1552871 INFO (WRITER7) [ ] o.a.s.s.TestStressReorder VERBOSE: deleteByQuery id 11 val= 2 version 6
[junit4] 2> 1552871 INFO (WRITER8) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 0 val= 2 version 7
[junit4] 2> 1552872 INFO (WRITER0) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@68b7c4 commitCommandVersion:1600212734977245184
[junit4] 2> 1552872 INFO (WRITER2) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-2&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{delete=[7 (-2)]} 0 0
[junit4] 2> 1552872 INFO (WRITER9) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 18 val= 2 version 8
[junit4] 2> 1552872 INFO (WRITER2) [ ] o.a.s.s.TestStressReorder VERBOSE: deleting id 7 val= 2 version 2 DONE
[junit4] 2> 1552872 INFO (WRITER2) [ ] o.a.s.s.TestStressReorder VERBOSE: softCommit start
[junit4] 2> 1552872 INFO (WRITER0) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@98c726[collection1] main]
[junit4] 2> 1552872 INFO (WRITER10) [ ] o.a.s.s.TestStressReorder VERBOSE: deleting id 22 val= 2 version 9
[junit4] 2> 1552872 INFO (WRITER11) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 22 val= 2 version 10
[junit4] 2> 1552872 INFO (WRITER12) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 22 val= 2 version 11
[junit4] 2> 1552872 INFO (WRITER0) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1552874 INFO (searcherExecutor-6752-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@98c726[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1552874 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=1
[junit4] 2> 1552874 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=1
[junit4] 2> 1552875 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=1
[junit4] 2> 1552875 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552875 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=1
[junit4] 2> 1552875 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 1552875 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=1
[junit4] 2> 1552875 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=1
[junit4] 2> 1552875 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:5&omitHeader=true&wt=json} hits=0 status=0 QTime=2
[junit4] 2> 1552875 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=2
[junit4] 2> 1552875 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> 1552875 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552875 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552875 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552875 INFO (READER1) [ ] 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> 1552875 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> 1552875 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=0
[junit4] 2> 1552875 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=3&wt=json} status=0 QTime=0
[junit4] 2> 1552875 INFO (READER12) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:7&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552875 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=1
[junit4] 2> 1552876 INFO (READER8) [ ] 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> 1552876 INFO (WRITER0) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 4
[junit4] 2> 1552876 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=0
[junit4] 2> 1552876 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:7&omitHeader=true&wt=json} hits=0 status=0 QTime=3
[junit4] 2> 1552876 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=3
[junit4] 2> 1552876 INFO (READER11) [ ] 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> 1552876 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> 1552876 INFO (READER12) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552876 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552876 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552876 INFO (WRITER6) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-5&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=id:28 (-5)} 0 4
[junit4] 2> 1552876 INFO (READER12) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552876 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:12&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552876 INFO (WRITER5) [ ] o.a.s.u.DirectUpdateHandler2 Reordered DBQs detected. Update=add{_version_=4,id=0} DBQs=[DBQ{version=5,q=id:28}]
[junit4] 2> 1552876 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 1552876 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 1552876 INFO (WRITER3) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1600212734977245185,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1552877 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> 1552877 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=1
[junit4] 2> 1552877 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> 1552877 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552877 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> 1552877 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 1552877 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> 1552876 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 1552877 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> 1552877 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552877 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> 1552877 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=0
[junit4] 2> 1552877 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> 1552877 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER13) [ ] 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> 1552877 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=1
[junit4] 2> 1552877 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=1
[junit4] 2> 1552877 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER3) [ ] 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> 1552877 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=1
[junit4] 2> 1552877 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=20&wt=json} status=0 QTime=1
[junit4] 2> 1552877 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER10) [ ] 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> 1552877 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER5) [ ] 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> 1552877 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552877 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER5) [ ] 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> 1552878 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (WRITER0) [ ] o.a.s.s.TestStressReorder VERBOSE: hardCommit end
[junit4] 2> 1552878 INFO (READER5) [ ] 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> 1552878 INFO (READER3) [ ] 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> 1552878 INFO (WRITER6) [ ] o.a.s.s.TestStressReorder VERBOSE: deleteByQuery id 28 val= 2 version 5 DONE
[junit4] 2> 1552878 INFO (WRITER6) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 28 val= 3 version 13
[junit4] 2> 1552878 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (WRITER0) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 22 val= 2 version 12
[junit4] 2> 1552878 INFO (READER5) [ ] 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> 1552878 INFO (READER3) [ ] 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> 1552878 INFO (READER5) [ ] 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> 1552877 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=1
[junit4] 2> 1552877 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=1
[junit4] 2> 1552878 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER3) [ ] 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> 1552878 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER9) [ ] 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> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552878 INFO (READER5) [ ] 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> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER7) [ ] 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> 1552878 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER5) [ ] 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> 1552878 INFO (READER3) [ ] 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> 1552878 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER7) [ ] 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> 1552878 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=2
[junit4] 2> 1552879 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER3) [ ] 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> 1552879 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:12&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552879 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER3) [ ] 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> 1552879 INFO (READER0) [ ] 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> 1552879 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:27&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552879 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=1
[junit4] 2> 1552879 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=3&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=20&wt=json} status=0 QTime=0
[junit4] 2> 1552879 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> 1552879 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER14) [ ] 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> 1552879 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=11&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER2) [ ] 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> 1552879 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER14) [ ] 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> 1552879 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER12) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=2
[junit4] 2> 1552879 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=2
[junit4] 2> 1552879 INFO (READER2) [ ] 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> 1552879 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552877 INFO (READER15) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=11&wt=json} status=0 QTime=1
[junit4] 2> 1552880 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER14) [ ] 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> 1552880 INFO (READER15) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 1552878 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=1
[junit4] 2> 1552878 INFO (READER5) [ ] 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> 1552880 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552878 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> 1552880 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER2) [ ] 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> 1552878 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> 1552880 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552880 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> 1552880 INFO (READER1) [ ] 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> 1552880 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER2) [ ] 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> 1552880 INFO (READER14) [ ] 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> 1552880 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> 1552880 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER2) [ ] 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> 1552880 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 1552880 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> 1552880 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER4) [ ] 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> 1552880 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:16&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552880 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:25&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552880 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:1&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552880 INFO (READER15) [ ] 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> 1552880 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:25&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552879 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> 1552881 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER3) [ ] 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> 1552881 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552881 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> 1552881 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER7) [ ] 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> 1552881 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552879 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER6) [ ] 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> 1552879 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=3&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER10) [ ] 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> 1552881 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER3) [ ] 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> 1552881 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER12) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER4) [ ] 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> 1552880 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552880 INFO (READER1) [ ] 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> 1552880 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552881 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552882 INFO (READER13) [ ] 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> 1552885 INFO (WRITER5) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1dd873e[collection1] realtime]
[junit4] 2> 1552885 INFO (WRITER3) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@68b7c4 commitCommandVersion:1600212734977245185
[junit4] 2> 1552885 INFO (WRITER5) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[0 (4)]} 0 14
[junit4] 2> 1552885 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=3
[junit4] 2> 1552885 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=3
[junit4] 2> 1552885 INFO (WRITER5) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 26 val= 2 version 14
[junit4] 2> 1552885 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=3
[junit4] 2> 1552885 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=3
[junit4] 2> 1552886 INFO (WRITER4) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[0 (3)]} 0 14
[junit4] 2> 1552885 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=3
[junit4] 2> 1552886 INFO (WRITER4) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 0 val= 3 version 15
[junit4] 2> 1552886 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=4
[junit4] 2> 1552886 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 1552886 INFO (WRITER1) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[0 (1)]} 0 14
[junit4] 2> 1552886 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=8&wt=json} status=0 QTime=4
[junit4] 2> 1552886 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552886 INFO (WRITER3) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@a9a1a3[collection1] main]
[junit4] 2> 1552886 INFO (WRITER1) [ ] o.a.s.s.TestStressReorder VERBOSE: deleteByQuery id 0 val= 3 version 16
[junit4] 2> 1552886 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=4
[junit4] 2> 1552886 INFO (READER15) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=4
[junit4] 2> 1552887 INFO (READER12) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=4
[junit4] 2> 1552887 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552887 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=4
[junit4] 2> 1552886 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552886 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=4
[junit4] 2> 1552887 INFO (READER5) [ ] 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> 1552887 INFO (READER12) [ ] 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> 1552887 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 1552887 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552887 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 1552886 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552887 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552887 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:7&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552887 INFO (READER11) [ ] 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> 1552887 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552887 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=5
[junit4] 2> 1552887 INFO (WRITER3) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1552889 INFO (searcherExecutor-6752-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@a9a1a3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c1)))}
[junit4] 2> 1552889 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=3
[junit4] 2> 1552889 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=3
[junit4] 2> 1552889 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=1
[junit4] 2> 1552889 INFO (WRITER3) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 17
[junit4] 2> 1552889 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=3
[junit4] 2> 1552889 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=2
[junit4] 2> 1552889 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552889 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> 1552890 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552890 INFO (READER12) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=2
[junit4] 2> 1552890 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:4&omitHeader=true&wt=json} hits=0 status=0 QTime=2
[junit4] 2> 1552890 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=8
[junit4] 2> 1552890 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=1
[junit4] 2> 1552890 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:9&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552890 INFO (READER15) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=3
[junit4] 2> 1552890 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=2
[junit4] 2> 1552890 INFO (READER6) [ ] 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> 1552890 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=8
[junit4] 2> 1552890 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=8
[junit4] 2> 1552890 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=20&wt=json} status=0 QTime=3
[junit4] 2> 1552891 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:9&omitHeader=true&wt=json} hits=0 status=0 QTime=3
[junit4] 2> 1552891 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=9
[junit4] 2> 1552891 INFO (READER3) [ ] 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> 1552891 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=1 status=0 QTime=3
[junit4] 2> 1552891 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=3
[junit4] 2> 1552891 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (WRITER10) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{delete=[22 (-9)]} 0 18
[junit4] 2> 1552891 INFO (READER15) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:12&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552891 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=1
[junit4] 2> 1552891 INFO (READER6) [ ] 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> 1552892 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=2
[junit4] 2> 1552891 INFO (WRITER2) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1600212734978293760,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 1552891 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552892 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552892 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:7&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552892 INFO (WRITER3) [ ] o.a.s.s.TestStressReorder VERBOSE: hardCommit end
[junit4] 2> 1552892 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 1552892 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 1552892 INFO (WRITER3) [ ] o.a.s.s.TestStressReorder VERBOSE: deleting id 17 val= 2 version 17
[junit4] 2> 1552892 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=1
[junit4] 2> 1552892 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=1
[junit4] 2> 1552892 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=2
[junit4] 2> 1552893 INFO (READER12) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=2
[junit4] 2> 1552892 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552892 INFO (WRITER7) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-6&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=id:11 (-6)} 0 20
[junit4] 2> 1552893 INFO (WRITER6) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[28 (13)]} 0 14
[junit4] 2> 1552893 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:12&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552893 INFO (READER12) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (WRITER6) [ ] o.a.s.s.TestStressReorder VERBOSE: deleting id 28 val= 4 version 18
[junit4] 2> 1552891 INFO (WRITER10) [ ] o.a.s.s.TestStressReorder VERBOSE: deleting id 22 val= 2 version 9 DONE
[junit4] 2> 1552893 INFO (READER14) [ ] 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> 1552893 INFO (WRITER10) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 7 val= 3 version 19
[junit4] 2> 1552893 INFO (READER10) [ ] 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> 1552893 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 1552891 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (WRITER11) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[22 (10)]} 0 20
[junit4] 2> 1552893 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (WRITER11) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 5 val= 2 version 20
[junit4] 2> 1552893 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (WRITER12) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[22 (11)]} 0 21
[junit4] 2> 1552893 INFO (WRITER12) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 7 val= 3 version 21
[junit4] 2> 1552891 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (READER16) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552893 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 1552893 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> 1552893 INFO (WRITER0) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[22 (12)]} 0 15
[junit4] 2> 1552893 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> 1552893 INFO (WRITER0) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 22 val= 3 version 22
[junit4] 2> 1552894 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 1552894 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> 1552894 INFO (READER15) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552894 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> 1552894 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552894 INFO (READER15) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:26&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552894 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> 1552894 INFO (READER15) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 1552894 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 1552894 INFO (READER15) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552894 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> 1552893 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=0
[junit4] 2> 1552894 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552894 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> 1552894 INFO (READER14) [ ] 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> 1552894 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 1552894 INFO (READER3) [ ] 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> 1552894 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552894 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 1552894 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552894 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 1552894 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> 1552894 INFO (READER14) [ ] 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> 1552894 INFO (READER11) [ ] 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> 1552895 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> 1552895 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552895 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> 1552895 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER14) [ ] 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> 1552895 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552895 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 1552895 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> 1552895 INFO (READER14) [ ] 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> 1552895 INFO (READER0) [ ] 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> 1552895 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=3&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (WRITER8) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[0 (7)]} 0 21
[junit4] 2> 1552893 INFO (WRITER9) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[18 (8)]} 0 21
[junit4] 2> 1552895 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552895 INFO (WRITER8) [ ] o.a.s.s.TestStressReorder VERBOSE: hardCommit start
[junit4] 2> 1552896 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (WRITER9) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 0 val= 3 version 23
[junit4] 2> 1552896 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> 1552896 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=0
[junit4] 2> 1552893 INFO (WRITER5) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{add=[26 (14)]} 0 7
[junit4] 2> 1552893 INFO (WRITER7) [ ] o.a.s.s.TestStressReorder VERBOSE: deleteByQuery id 11 val= 2 version 6 DONE
[junit4] 2> 1552896 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (WRITER7) [ ] o.a.s.s.TestStressReorder VERBOSE: softCommit start
[junit4] 2> 1552893 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 1552893 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> 1552893 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=2
[junit4] 2> 1552896 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (READER13) [ ] 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> 1552896 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=3&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:9&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552896 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> 1552896 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552896 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> 1552896 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=13&wt=json} status=0 QTime=0
[junit4] 2> 1552896 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> 1552893 INFO (READER9) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (READER13) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:9&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 1552896 INFO (WRITER5) [ ] o.a.s.s.TestStressReorder VERBOSE: adding id 26 val= 3 version 24
[junit4] 2> 1552896 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> 1552896 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 1552896 INFO (READER14) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552895 INFO (READER11) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 1552897 INFO (READER13) [ ] 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> 1552897 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> 1552897 INFO (READER2) [ ] 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> 1552897 INFO (READER10) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552897 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> 1552897 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 1552897 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 1552897 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 1552897 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 1552897 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=10&wt=json} status=0 QTime=0
[junit4] 2> 1552897 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 1552897 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 1552898 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null
[...truncated too long message...]
dUpdateProcessor.java:1844)
[junit4] > at org.apache.solr.update.processor.DistributedUpdateProcessor.doDeleteById(DistributedUpdateProcessor.java:1381)
[junit4] > at org.apache.solr.update.processor.DistributedUpdateProcessor.processDelete(DistributedUpdateProcessor.java:1359)
[junit4] > at org.apache.solr.update.processor.LogUpdateProcessorFactory$LogUpdateProcessor.processDelete(LogUpdateProcessorFactory.java:124)
[junit4] > at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.handleDeleteMap(JsonLoader.java:394)
[junit4] > at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.handleDeleteCommand(JsonLoader.java:311)
[junit4] > at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.processUpdate(JsonLoader.java:171)
[junit4] > at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.load(JsonLoader.java:121)
[junit4] > at org.apache.solr.handler.loader.JsonLoader.load(JsonLoader.java:84)
[junit4] > at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:97)
[junit4] > at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
[junit4] > at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199)
[junit4] > at org.apache.solr.core.SolrCore.execute(SolrCore.java:2510)
[junit4] > at org.apache.solr.servlet.DirectSolrConnection.request(DirectSolrConnection.java:125)
[junit4] > at org.apache.solr.SolrTestCaseJ4.updateJ(SolrTestCaseJ4.java:1286)
[junit4] > at org.apache.solr.SolrTestCaseJ4.deleteAndGetVersion(SolrTestCaseJ4.java:1464)
[junit4] > at org.apache.solr.search.TestStressReorder$1.run(TestStressReorder.java:184)
[junit4] 2> 1553696 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 1553696 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=20692181
[junit4] 2> 1553696 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1553696 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2dc05d: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@39dc92
[junit4] 2> 1553700 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1553700 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@14483f1: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@1f5f135
[junit4] 2> 1553702 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1553703 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@170cc6b: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@f18570
[junit4] 2> 1553703 INFO (coreCloseExecutor-6757-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1549411
[junit4] 2> 1553703 INFO (coreCloseExecutor-6757-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1549411
[junit4] 2> 1553703 INFO (coreCloseExecutor-6757-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@ccb2fc: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@16d646f
[junit4] 2> 1553711 INFO (coreCloseExecutor-6757-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter close.
[junit4] 2> 1553711 INFO (coreCloseExecutor-6757-thread-1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@68b7c4 commitCommandVersion:0
[junit4] 2> 1553714 INFO (SUITE-TestStressReorder-seed#[C2D69ECAC5E27E5]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@b0f03f), locale=es-EC, timezone=Etc/GMT-2
[junit4] 2> NOTE: Linux 4.13.0-39-generic i386/Oracle Corporation 1.8.0_162 (32-bit)/cpus=8,threads=1,free=127998784,total=399462400
[junit4] 2> NOTE: All tests run in this JVM: [TestLeaderInitiatedRecoveryThread, TestPullReplicaErrorHandling, TestUpdate, ShardSplitTest, DirectoryFactoryTest, AnalyticsMergeStrategyTest, TestValueSourceCache, TestSolrConfigHandlerCloud, SpatialRPTFieldTypeTest, TestNumericRangeQuery64, UUIDUpdateProcessorFallbackTest, V2ApiIntegrationTest, HealthCheckHandlerTest, SpellPossibilityIteratorTest, SpellCheckComponentTest, DistributedQueryComponentOptimizationTest, NotRequiredUniqueKeyTest, TestLazyCores, TestBlobHandler, BlockDirectoryTest, FileBasedSpellCheckerTest, AtomicUpdatesTest, TestRawResponseWriter, LukeRequestHandlerTest, CoreAdminHandlerTest, AnalysisAfterCoreReloadTest, LIROnShardRestartTest, TestCopyFieldCollectionResource, SpatialHeatmapFacetsTest, TestGraphTermsQParserPlugin, TestNamedUpdateProcessors, TestUniqueKeyFieldResource, TestCodecSupport, HdfsNNFailoverTest, TestPointFields, TestFaceting, TestSegmentSorting, ExecutePlanActionTest, JSONWriterTest, ConvertedLegacyTest, TestSolrCoreParser, OutOfBoxZkACLAndCredentialsProvidersTest, TestAnalyzedSuggestions, LeaderElectionTest, TestRandomCollapseQParserPlugin, AsyncCallRequestStatusResponseTest, TestCustomDocTransformer, TestJmxIntegration, TestSha256AuthenticationProvider, TestInPlaceUpdatesStandalone, TestFieldTypeResource, TestShardHandlerFactory, CacheHeaderTest, URLClassifyProcessorTest, TestCloudPseudoReturnFields, TimeZoneUtilsTest, TestRecoveryHdfs, TestSuggestSpellingConverter, AddReplicaTest, OverseerTaskQueueTest, DirectSolrSpellCheckerTest, TestRestoreCore, ChangedSchemaMergeTest, DistanceFunctionTest, TestCustomSort, LeaderElectionIntegrationTest, IndexSchemaRuntimeFieldTest, TestCoreContainer, RequestLoggingTest, TestInitParams, MultiSolrCloudTestCaseTest, TestConfigsApi, CdcrReplicationDistributedZkTest, TestSolrCloudWithHadoopAuthPlugin, ResponseLogComponentTest, TestGraphMLResponseWriter, TestDynamicLoading, DocValuesMultiTest, MinimalSchemaTest, TestPolicyCloud, DistributedFacetPivotLargeTest, TestReplicaProperties, BlockJoinFacetDistribTest, TestManagedSynonymGraphFilterFactory, CircularListTest, TestTolerantSearch, TestFastWriter, DistributedFacetPivotSmallTest, TestSolrQueryResponse, RulesTest, TermVectorComponentTest, TriLevelCompositeIdRoutingTest, TestTolerantUpdateProcessorRandomCloud, NoCacheHeaderTest, SuggesterTSTTest, DisMaxRequestHandlerTest, TestSkipOverseerOperations, DateFieldTest, ScheduledMaintenanceTriggerTest, TestDistributedStatsComponentCardinality, ClusterStateUpdateTest, InfixSuggestersTest, WordBreakSolrSpellCheckerTest, TestCloudSchemaless, AutoAddReplicasPlanActionTest, TestScoreJoinQPNoScore, TestExactSharedStatsCache, SolrCmdDistributorTest, SolrCLIZkUtilsTest, SolrJmxReporterTest, TestStressLiveNodes, TestDFISimilarityFactory, TestSolrCloudWithSecureImpersonation, CollectionTooManyReplicasTest, UnloadDistributedZkTest, SolrGangliaReporterTest, TestHdfsBackupRestoreCore, TestCoreDiscovery, TestSubQueryTransformerCrossCore, SearchHandlerTest, TestUnInvertedFieldException, TestCollectionsAPIViaSolrCloudCluster, TestLegacyNumericRangeQueryBuilder, PreAnalyzedFieldManagedSchemaCloudTest, TestLFUCache, HdfsTlogReplayBufferedWhileIndexingTest, NodeLostTriggerTest, TestExclusionRuleCollectionAccess, TestFiltering, BasicDistributedZk2Test, OverseerTest, BasicZkTest, RecoveryZkTest, TestZkChroot, TestRandomDVFaceting, DistributedSpellCheckComponentTest, TestRealTimeGet, TestStressReorder]
[junit4] Completed [387/806 (1!)] on J2 in 1.29s, 1 test, 1 error <<< FAILURES!
[...truncated 47731 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21994/consoleText
[repro] Revision: bad0e3f164872c9e96fa366ab2dc1409581d7a34
[repro] Ant options: "-Dargs=-client -XX:+UseConcMarkSweepGC"
[repro] Repro line: ant test -Dtestcase=TestStressReorder -Dtests.method=testStressReorderVersions -Dtests.seed=C2D69ECAC5E27E5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es-EC -Dtests.timezone=Etc/GMT-2 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestStressReorder
[repro] ant compile-test
[...truncated 3298 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestStressReorder" -Dtests.showOutput=onerror "-Dargs=-client -XX:+UseConcMarkSweepGC" -Dtests.seed=C2D69ECAC5E27E5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es-EC -Dtests.timezone=Etc/GMT-2 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 71 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.search.TestStressReorder
[repro] Exiting with code 0
[...truncated 40 lines...]
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk1.8.0_162) - Build #
21995 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21995/
Java: 64bit/jdk1.8.0_162 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
2 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.SearchRateTriggerTest.testTrigger
Error Message:
expected:<1> but was:<2>
Stack Trace:
java.lang.AssertionError: expected:<1> but was:<2>
at __randomizedtesting.SeedInfo.seed([32856CA0C9BC5F51:514E5A2250732C7C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.autoscaling.SearchRateTriggerTest.testTrigger(SearchRateTriggerTest.java:133)
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 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)
FAILED: org.apache.solr.cloud.autoscaling.SearchRateTriggerTest.testTrigger
Error Message:
expected:<1> but was:<2>
Stack Trace:
java.lang.AssertionError: expected:<1> but was:<2>
at __randomizedtesting.SeedInfo.seed([32856CA0C9BC5F51:514E5A2250732C7C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.autoscaling.SearchRateTriggerTest.testTrigger(SearchRateTriggerTest.java:133)
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 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)
Build Log:
[...truncated 13096 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.SearchRateTriggerTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/init-core-data-001
[junit4] 2> 523903 INFO (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 523903 INFO (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 523904 INFO (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 523904 INFO (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001
[junit4] 2> 523904 INFO (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 523905 INFO (Thread-1680) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 523905 INFO (Thread-1680) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 523906 ERROR (Thread-1680) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 524005 INFO (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:44579
[junit4] 2> 524007 INFO (zkConnectionManagerCallback-4025-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524010 INFO (jetty-launcher-4022-thread-3) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_162-b12
[junit4] 2> 524010 INFO (jetty-launcher-4022-thread-4) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_162-b12
[junit4] 2> 524010 INFO (jetty-launcher-4022-thread-1) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_162-b12
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-2) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_162-b12
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-4) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-3) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 524011 INFO (jetty-launcher-4022-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4ceb3382{/solr,null,AVAILABLE}
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4126ead7{/solr,null,AVAILABLE}
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6d96d383{SSL,[ssl, http/1.1]}{127.0.0.1:40355}
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-4) [ ] o.e.j.s.Server Started @524048ms
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6fb1fd62{/solr,null,AVAILABLE}
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40355}
[junit4] 2> 524012 ERROR (jetty-launcher-4022-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-4) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 524012 INFO (jetty-launcher-4022-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-12T07:05:17.522Z
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@59f8d688{/solr,null,AVAILABLE}
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6e5a1c9e{SSL,[ssl, http/1.1]}{127.0.0.1:39957}
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-2) [ ] o.e.j.s.Server Started @524050ms
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39957}
[junit4] 2> 524013 ERROR (jetty-launcher-4022-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-12T07:05:17.523Z
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@76781478{SSL,[ssl, http/1.1]}{127.0.0.1:44545}
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-1) [ ] o.e.j.s.Server Started @524050ms
[junit4] 2> 524013 INFO (jetty-launcher-4022-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44545}
[junit4] 2> 524014 ERROR (jetty-launcher-4022-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-12T07:05:17.524Z
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5d0906b7{SSL,[ssl, http/1.1]}{127.0.0.1:39913}
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-3) [ ] o.e.j.s.Server Started @524051ms
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39913}
[junit4] 2> 524014 INFO (zkConnectionManagerCallback-4027-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524014 ERROR (jetty-launcher-4022-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 524014 INFO (jetty-launcher-4022-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-12T07:05:17.524Z
[junit4] 2> 524015 INFO (jetty-launcher-4022-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 524015 INFO (zkConnectionManagerCallback-4029-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524015 INFO (jetty-launcher-4022-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 524015 INFO (zkConnectionManagerCallback-4031-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524015 INFO (jetty-launcher-4022-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 524018 INFO (zkConnectionManagerCallback-4033-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524018 INFO (jetty-launcher-4022-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 524023 INFO (jetty-launcher-4022-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44579/solr
[junit4] 2> 524023 INFO (jetty-launcher-4022-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44579/solr
[junit4] 2> 524024 INFO (zkConnectionManagerCallback-4041-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524024 INFO (jetty-launcher-4022-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44579/solr
[junit4] 2> 524024 INFO (jetty-launcher-4022-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44579/solr
[junit4] 2> 524024 INFO (zkConnectionManagerCallback-4045-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524026 INFO (zkConnectionManagerCallback-4049-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524026 INFO (zkConnectionManagerCallback-4051-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524031 INFO (zkConnectionManagerCallback-4048-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524032 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10051f06a530008, likely client has closed socket
[junit4] 2> 524050 INFO (zkConnectionManagerCallback-4053-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524050 INFO (zkConnectionManagerCallback-4059-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524054 INFO (zkConnectionManagerCallback-4057-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524054 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 524054 INFO (jetty-launcher-4022-thread-3) [n:127.0.0.1:39913_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 524059 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44545_solr
[junit4] 2> 524059 INFO (jetty-launcher-4022-thread-3) [n:127.0.0.1:39913_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39913_solr
[junit4] 2> 524059 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.c.Overseer Overseer (id=72147687055753226-127.0.0.1:44545_solr-n_0000000000) starting
[junit4] 2> 524061 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 524062 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 524063 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 524063 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 524064 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 524064 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39957_solr
[junit4] 2> 524066 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 524066 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40355_solr
[junit4] 2> 524070 INFO (zkCallback-4058-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 524070 INFO (zkCallback-4052-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 524082 INFO (zkCallback-4058-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 524094 INFO (zkConnectionManagerCallback-4070-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524094 INFO (zkCallback-4052-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 524094 INFO (zkCallback-4056-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 524095 INFO (zkCallback-4050-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 524095 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 524095 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44579/solr ready
[junit4] 2> 524110 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 524110 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44545_solr
[junit4] 2> 524111 INFO (zkCallback-4058-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 524111 INFO (zkCallback-4052-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 524114 INFO (zkCallback-4056-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 524126 INFO (zkCallback-4050-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 524130 INFO (zkCallback-4069-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 524194 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39957.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524194 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44545.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524203 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39957.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524203 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44545.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524203 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39957.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524203 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44545.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524204 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node2/.
[junit4] 2> 524204 INFO (jetty-launcher-4022-thread-1) [n:127.0.0.1:44545_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node1/.
[junit4] 2> 524209 INFO (jetty-launcher-4022-thread-3) [n:127.0.0.1:39913_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39913.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524214 INFO (zkConnectionManagerCallback-4075-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524214 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 524214 INFO (jetty-launcher-4022-thread-2) [n:127.0.0.1:39957_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44579/solr ready
[junit4] 2> 524215 INFO (jetty-launcher-4022-thread-3) [n:127.0.0.1:39913_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39913.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524216 INFO (jetty-launcher-4022-thread-3) [n:127.0.0.1:39913_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39913.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524217 INFO (jetty-launcher-4022-thread-3) [n:127.0.0.1:39913_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node3/.
[junit4] 2> 524222 INFO (zkConnectionManagerCallback-4080-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524222 INFO (jetty-launcher-4022-thread-3) [n:127.0.0.1:39913_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 524223 INFO (jetty-launcher-4022-thread-3) [n:127.0.0.1:39913_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44579/solr ready
[junit4] 2> 524259 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40355.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524263 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40355.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524263 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40355.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 524264 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node4/.
[junit4] 2> 524266 INFO (zkConnectionManagerCallback-4085-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524267 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 524267 INFO (jetty-launcher-4022-thread-4) [n:127.0.0.1:40355_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44579/solr ready
[junit4] 2> 524306 INFO (zkConnectionManagerCallback-4087-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524308 INFO (zkConnectionManagerCallback-4092-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 524308 INFO (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 524309 INFO (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44579/solr ready
[junit4] 2> 524328 INFO (TEST-SearchRateTriggerTest.testTrigger-seed#[32856CA0C9BC5F51]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTrigger
[junit4] 2> 524328 INFO (TEST-SearchRateTriggerTest.testTrigger-seed#[32856CA0C9BC5F51]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 524345 INFO (qtp859746121-8149) [n:127.0.0.1:39913_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=SearchRateTriggerTest-collection1&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 524347 INFO (OverseerThreadFactory-1877-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection SearchRateTriggerTest-collection1
[junit4] 2> 524450 INFO (OverseerStateUpdate-72147687055753226-127.0.0.1:44545_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"SearchRateTriggerTest-collection1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"SearchRateTriggerTest-collection1_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:40355/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 524451 INFO (OverseerStateUpdate-72147687055753226-127.0.0.1:44545_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"SearchRateTriggerTest-collection1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"SearchRateTriggerTest-collection1_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:44545/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 524452 INFO (OverseerStateUpdate-72147687055753226-127.0.0.1:44545_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"SearchRateTriggerTest-collection1",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"SearchRateTriggerTest-collection1_shard2_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39913/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 524453 INFO (OverseerStateUpdate-72147687055753226-127.0.0.1:44545_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"SearchRateTriggerTest-collection1",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"SearchRateTriggerTest-collection1_shard2_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39957/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 524674 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection1_shard2_replica_n4&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 524674 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 524682 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection1_shard2_replica_n6&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 524682 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection1_shard1_replica_n2&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 524684 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection1_shard1_replica_n1&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 525690 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 525690 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 525690 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 525700 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.s.IndexSchema [SearchRateTriggerTest-collection1_shard1_replica_n2] Schema name=minimal
[junit4] 2> 525700 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.s.IndexSchema [SearchRateTriggerTest-collection1_shard2_replica_n6] Schema name=minimal
[junit4] 2> 525700 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.s.IndexSchema [SearchRateTriggerTest-collection1_shard2_replica_n4] Schema name=minimal
[junit4] 2> 525702 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 525702 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 525702 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'SearchRateTriggerTest-collection1_shard2_replica_n6' using configuration from collection SearchRateTriggerTest-collection1, trusted=true
[junit4] 2> 525702 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'SearchRateTriggerTest-collection1_shard1_replica_n2' using configuration from collection SearchRateTriggerTest-collection1, trusted=true
[junit4] 2> 525702 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 525702 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 525702 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'SearchRateTriggerTest-collection1_shard2_replica_n4' using configuration from collection SearchRateTriggerTest-collection1, trusted=true
[junit4] 2> 525702 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44545.solr.core.SearchRateTriggerTest-collection1.shard1.replica_n2' (registry 'solr.core.SearchRateTriggerTest-collection1.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 525702 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39913.solr.core.SearchRateTriggerTest-collection1.shard2.replica_n4' (registry 'solr.core.SearchRateTriggerTest-collection1.shard2.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 525702 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39957.solr.core.SearchRateTriggerTest-collection1.shard2.replica_n6' (registry 'solr.core.SearchRateTriggerTest-collection1.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 525703 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 525703 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 525703 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 525703 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.c.SolrCore [[SearchRateTriggerTest-collection1_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node1/SearchRateTriggerTest-collection1_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node1/./SearchRateTriggerTest-collection1_shard1_replica_n2/data/]
[junit4] 2> 525703 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.c.SolrCore [[SearchRateTriggerTest-collection1_shard2_replica_n4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node3/SearchRateTriggerTest-collection1_shard2_replica_n4], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node3/./SearchRateTriggerTest-collection1_shard2_replica_n4/data/]
[junit4] 2> 525703 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.SolrCore [[SearchRateTriggerTest-collection1_shard2_replica_n6] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node2/SearchRateTriggerTest-collection1_shard2_replica_n6], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node2/./SearchRateTriggerTest-collection1_shard2_replica_n6/data/]
[junit4] 2> 525706 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.s.IndexSchema [SearchRateTriggerTest-collection1_shard1_replica_n1] Schema name=minimal
[junit4] 2> 525707 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 525708 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'SearchRateTriggerTest-collection1_shard1_replica_n1' using configuration from collection SearchRateTriggerTest-collection1, trusted=true
[junit4] 2> 525708 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40355.solr.core.SearchRateTriggerTest-collection1.shard1.replica_n1' (registry 'solr.core.SearchRateTriggerTest-collection1.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 525708 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 525708 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.SolrCore [[SearchRateTriggerTest-collection1_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node4/SearchRateTriggerTest-collection1_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node4/./SearchRateTriggerTest-collection1_shard1_replica_n1/data/]
[junit4] 2> 525754 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 525754 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 525754 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 525754 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 525754 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 525754 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 525755 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 525755 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 525756 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 525756 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 525756 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 525756 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 525757 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@5d1d1b05[SearchRateTriggerTest-collection1_shard2_replica_n6] main]
[junit4] 2> 525757 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@36dfbf61[SearchRateTriggerTest-collection1_shard1_replica_n2] main]
[junit4] 2> 525757 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5cd1c82e[SearchRateTriggerTest-collection1_shard1_replica_n1] main]
[junit4] 2> 525758 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 525758 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 525758 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 525758 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 525759 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 525759 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 525759 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 525760 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 525760 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 525762 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 525762 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 525762 INFO (searcherExecutor-1887-thread-1-processing-n:127.0.0.1:44545_solr x:SearchRateTriggerTest-collection1_shard1_replica_n2 c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.c.SolrCore [SearchRateTriggerTest-collection1_shard1_replica_n2] Registered new searcher Searcher@36dfbf61[SearchRateTriggerTest-collection1_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 525763 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1600240976420405248
[junit4] 2> 525763 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 525763 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 525764 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1600240976421453824
[junit4] 2> 525764 INFO (searcherExecutor-1886-thread-1-processing-n:127.0.0.1:39957_solr x:SearchRateTriggerTest-collection1_shard2_replica_n6 c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.SolrCore [SearchRateTriggerTest-collection1_shard2_replica_n6] Registered new searcher Searcher@5d1d1b05[SearchRateTriggerTest-collection1_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 525765 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@60782795[SearchRateTriggerTest-collection1_shard2_replica_n4] main]
[junit4] 2> 525765 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1600240976422502400
[junit4] 2> 525766 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 525766 INFO (searcherExecutor-1889-thread-1-processing-n:127.0.0.1:40355_solr x:SearchRateTriggerTest-collection1_shard1_replica_n1 c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.SolrCore [SearchRateTriggerTest-collection1_shard1_replica_n1] Registered new searcher Searcher@5cd1c82e[SearchRateTriggerTest-collection1_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 525766 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 525767 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 525767 INFO (searcherExecutor-1888-thread-1-processing-n:127.0.0.1:39913_solr x:SearchRateTriggerTest-collection1_shard2_replica_n4 c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.c.SolrCore [SearchRateTriggerTest-collection1_shard2_replica_n4] Registered new searcher Searcher@60782795[SearchRateTriggerTest-collection1_shard2_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 525767 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1600240976424599552
[junit4] 2> 525769 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/SearchRateTriggerTest-collection1/terms/shard1 to Terms{values={core_node5=0}, version=0}
[junit4] 2> 525769 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.ZkShardTerms Successful update of terms at /collections/SearchRateTriggerTest-collection1/terms/shard2 to Terms{values={core_node8=0}, version=0}
[junit4] 2> 525769 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.ZkShardTerms Failed to save terms, version is not a match, retrying
[junit4] 2> 525799 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/SearchRateTriggerTest-collection1/terms/shard1 to Terms{values={core_node3=0, core_node5=0}, version=1}
[junit4] 2> 525800 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.c.ZkShardTerms Successful update of terms at /collections/SearchRateTriggerTest-collection1/terms/shard2 to Terms{values={core_node7=0, core_node8=0}, version=1}
[junit4] 2> 525801 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 525801 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 525801 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:40355/solr/SearchRateTriggerTest-collection1_shard1_replica_n1/
[junit4] 2> 525801 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=SearchRateTriggerTest-collection1_shard1_replica_n1 url=https://127.0.0.1:40355/solr START replicas=[https://127.0.0.1:44545/solr/SearchRateTriggerTest-collection1_shard1_replica_n2/] nUpdates=100
[junit4] 2> 525802 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 525802 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 525802 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:39957/solr/SearchRateTriggerTest-collection1_shard2_replica_n6/
[junit4] 2> 525803 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.u.PeerSync PeerSync: core=SearchRateTriggerTest-collection1_shard2_replica_n6 url=https://127.0.0.1:39957/solr START replicas=[https://127.0.0.1:39913/solr/SearchRateTriggerTest-collection1_shard2_replica_n4/] nUpdates=100
[junit4] 2> 525805 INFO (qtp1763325845-8154) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.c.S.Request [SearchRateTriggerTest-collection1_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 525805 INFO (qtp859746121-8136) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.c.S.Request [SearchRateTriggerTest-collection1_shard2_replica_n4] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 526102 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=SearchRateTriggerTest-collection1_shard1_replica_n1 url=https://127.0.0.1:40355/solr DONE. We have no versions. sync failed.
[junit4] 2> 526102 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 526102 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 526102 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 526103 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.u.PeerSync PeerSync: core=SearchRateTriggerTest-collection1_shard2_replica_n6 url=https://127.0.0.1:39957/solr DONE. We have no versions. sync failed.
[junit4] 2> 526103 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 526103 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 526103 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 526105 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:40355/solr/SearchRateTriggerTest-collection1_shard1_replica_n1/ shard1
[junit4] 2> 526105 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:39957/solr/SearchRateTriggerTest-collection1_shard2_replica_n6/ shard2
[junit4] 2> 526206 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 526206 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 526308 INFO (zkCallback-4050-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SearchRateTriggerTest-collection1/state.json] for collection [SearchRateTriggerTest-collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 526308 INFO (zkCallback-4056-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SearchRateTriggerTest-collection1/state.json] for collection [SearchRateTriggerTest-collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 526764 INFO (qtp1312485891-8163) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection1_shard2_replica_n6&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2082
[junit4] 2> 526768 INFO (qtp564868703-8143) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection1_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection1_shard1_replica_n1&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2083
[junit4] 2> 526805 INFO (qtp1763325845-8151) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection1_shard1_replica_n2&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2122
[junit4] 2> 526805 INFO (qtp859746121-8155) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection1_shard2_replica_n4&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2131
[junit4] 2> 526806 INFO (qtp859746121-8149) [n:127.0.0.1:39913_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 526906 INFO (zkCallback-4050-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SearchRateTriggerTest-collection1/state.json] for collection [SearchRateTriggerTest-collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 526906 INFO (zkCallback-4056-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SearchRateTriggerTest-collection1/state.json] for collection [SearchRateTriggerTest-collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 526906 INFO (zkCallback-4058-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SearchRateTriggerTest-collection1/state.json] for collection [SearchRateTriggerTest-collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 526906 INFO (zkCallback-4052-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SearchRateTriggerTest-collection1/state.json] for collection [SearchRateTriggerTest-collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 527806 INFO (qtp859746121-8149) [n:127.0.0.1:39913_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=SearchRateTriggerTest-collection1&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3461
[junit4] 2> 527807 INFO (qtp859746121-8152) [n:127.0.0.1:39913_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=SearchRateTriggerTest-collection2&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 527808 INFO (OverseerThreadFactory-1877-thread-2) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection SearchRateTriggerTest-collection2
[junit4] 2> 527809 INFO (OverseerCollectionConfigSetProcessor-72147687055753226-127.0.0.1:44545_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 528013 INFO (OverseerStateUpdate-72147687055753226-127.0.0.1:44545_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"SearchRateTriggerTest-collection2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"SearchRateTriggerTest-collection2_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:40355/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 528014 INFO (OverseerStateUpdate-72147687055753226-127.0.0.1:44545_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"SearchRateTriggerTest-collection2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"SearchRateTriggerTest-collection2_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39957/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 528014 INFO (OverseerStateUpdate-72147687055753226-127.0.0.1:44545_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"SearchRateTriggerTest-collection2",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"SearchRateTriggerTest-collection2_shard2_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39913/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 528015 INFO (OverseerStateUpdate-72147687055753226-127.0.0.1:44545_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"SearchRateTriggerTest-collection2",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"SearchRateTriggerTest-collection2_shard2_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:44545/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 528219 INFO (qtp1763325845-8147) [n:127.0.0.1:44545_solr x:SearchRateTriggerTest-collection2_shard2_replica_n6] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection2_shard2_replica_n6&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection2&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 528219 INFO (qtp1312485891-8162) [n:127.0.0.1:39957_solr x:SearchRateTriggerTest-collection2_shard1_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection2_shard1_replica_n2&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection2&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 528219 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection2_shard1_replica_n1&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection2&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 528219 INFO (qtp859746121-8275) [n:127.0.0.1:39913_solr x:SearchRateTriggerTest-collection2_shard2_replica_n4] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=SearchRateTriggerTest-collection2_shard2_replica_n4&action=CREATE&numShards=2&collection=SearchRateTriggerTest-collection2&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 529228 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 529228 INFO (qtp1763325845-8147) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection2_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 529228 INFO (qtp1312485891-8162) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection2_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 529229 INFO (qtp859746121-8275) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection2_shard2_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 529233 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.s.IndexSchema [SearchRateTriggerTest-collection2_shard1_replica_n1] Schema name=minimal
[junit4] 2> 529235 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 529235 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'SearchRateTriggerTest-collection2_shard1_replica_n1' using configuration from collection SearchRateTriggerTest-collection2, trusted=true
[junit4] 2> 529235 INFO (qtp859746121-8275) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection2_shard2_replica_n4] o.a.s.s.IndexSchema [SearchRateTriggerTest-collection2_shard2_replica_n4] Schema name=minimal
[junit4] 2> 529235 INFO (qtp1312485891-8162) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection2_shard1_replica_n2] o.a.s.s.IndexSchema [SearchRateTriggerTest-collection2_shard1_replica_n2] Schema name=minimal
[junit4] 2> 529235 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40355.solr.core.SearchRateTriggerTest-collection2.shard1.replica_n1' (registry 'solr.core.SearchRateTriggerTest-collection2.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 529235 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 529235 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.c.SolrCore [[SearchRateTriggerTest-collection2_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node4/SearchRateTriggerTest-collection2_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node4/./SearchRateTriggerTest-collection2_shard1_replica_n1/data/]
[junit4] 2> 529253 INFO (qtp1312485891-8162) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection2_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 529253 INFO (qtp859746121-8275) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection2_shard2_replica_n4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 529253 INFO (qtp1312485891-8162) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection2_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'SearchRateTriggerTest-collection2_shard1_replica_n2' using configuration from collection SearchRateTriggerTest-collection2, trusted=true
[junit4] 2> 529253 INFO (qtp859746121-8275) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection2_shard2_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'SearchRateTriggerTest-collection2_shard2_replica_n4' using configuration from collection SearchRateTriggerTest-collection2, trusted=true
[junit4] 2> 529253 INFO (qtp1763325845-8147) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection2_shard2_replica_n6] o.a.s.s.IndexSchema [SearchRateTriggerTest-collection2_shard2_replica_n6] Schema name=minimal
[junit4] 2> 529254 INFO (qtp1312485891-8162) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection2_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39957.solr.core.SearchRateTriggerTest-collection2.shard1.replica_n2' (registry 'solr.core.SearchRateTriggerTest-collection2.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 529254 INFO (qtp859746121-8275) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection2_shard2_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39913.solr.core.SearchRateTriggerTest-collection2.shard2.replica_n4' (registry 'solr.core.SearchRateTriggerTest-collection2.shard2.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 529254 INFO (qtp1312485891-8162) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection2_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 529254 INFO (qtp859746121-8275) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection2_shard2_replica_n4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 529254 INFO (qtp859746121-8275) [n:127.0.0.1:39913_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection2_shard2_replica_n4] o.a.s.c.SolrCore [[SearchRateTriggerTest-collection2_shard2_replica_n4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node3/SearchRateTriggerTest-collection2_shard2_replica_n4], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node3/./SearchRateTriggerTest-collection2_shard2_replica_n4/data/]
[junit4] 2> 529254 INFO (qtp1312485891-8162) [n:127.0.0.1:39957_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection2_shard1_replica_n2] o.a.s.c.SolrCore [[SearchRateTriggerTest-collection2_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node2/SearchRateTriggerTest-collection2_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node2/./SearchRateTriggerTest-collection2_shard1_replica_n2/data/]
[junit4] 2> 529254 INFO (qtp1763325845-8147) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection2_shard2_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 529254 INFO (qtp1763325845-8147) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection2_shard2_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'SearchRateTriggerTest-collection2_shard2_replica_n6' using configuration from collection SearchRateTriggerTest-collection2, trusted=true
[junit4] 2> 529255 INFO (qtp1763325845-8147) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection2_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44545.solr.core.SearchRateTriggerTest-collection2.shard2.replica_n6' (registry 'solr.core.SearchRateTriggerTest-collection2.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d8adf7
[junit4] 2> 529255 INFO (qtp1763325845-8147) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection2_shard2_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 529255 INFO (qtp1763325845-8147) [n:127.0.0.1:44545_solr c:SearchRateTriggerTest-collection2 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection2_shard2_replica_n6] o.a.s.c.SolrCore [[SearchRateTriggerTest-collection2_shard2_replica_n6] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node1/SearchRateTriggerTest-collection2_shard2_replica_n6], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001/tempDir-001/node1/./SearchRateTriggerTest-collection2_shard2_replica_n6/data/]
[junit4] 2> 529286 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 529286 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 529286 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 529286 INFO (qtp564868703-8146) [n:127.0.0.1:40355_solr c:SearchRateTriggerTest-collection2 s:shard1 r:core_node3 x:SearchRateTriggerTest-collection2_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 529287 INFO (qtp564868703-8146) [n:127.0.0
[...truncated too long message...]
metric reporters for registry=solr.core.SearchRateTriggerTest-collection1.shard2.replica_n4, tag=3d26b470
[junit4] 2> 158649 INFO (coreCloseExecutor-194-thread-1) [n:127.0.0.1:35613_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.SearchRateTriggerTest-collection1.shard2.replica_n6, tag=6046648d
[junit4] 2> 158649 INFO (coreCloseExecutor-196-thread-1) [n:127.0.0.1:41853_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@48c4d639: rootName = solr_41853, domain = solr.core.SearchRateTriggerTest-collection1.shard2.replica_n4, service url = null, agent id = null] for registry solr.core.SearchRateTriggerTest-collection1.shard2.replica_n4 / com.codahale.metrics.MetricRegistry@4e6f002b
[junit4] 2> 158649 INFO (coreCloseExecutor-194-thread-1) [n:127.0.0.1:35613_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5bc86b0: rootName = solr_35613, domain = solr.core.SearchRateTriggerTest-collection1.shard2.replica_n6, service url = null, agent id = null] for registry solr.core.SearchRateTriggerTest-collection1.shard2.replica_n6 / com.codahale.metrics.MetricRegistry@3b20851a
[junit4] 2> 158649 INFO (zkCallback-127-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 158651 INFO (coreCloseExecutor-195-thread-1) [n:127.0.0.1:42971_solr c:SearchRateTriggerTest-collection1 s:shard1 r:core_node5 x:SearchRateTriggerTest-collection1_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.SearchRateTriggerTest-collection1.shard1.leader, tag=5ce3e533
[junit4] 2> 158660 INFO (coreCloseExecutor-194-thread-1) [n:127.0.0.1:35613_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node8 x:SearchRateTriggerTest-collection1_shard2_replica_n6] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.SearchRateTriggerTest-collection1.shard2.leader, tag=6046648d
[junit4] 2> 158662 INFO (coreCloseExecutor-196-thread-1) [n:127.0.0.1:41853_solr c:SearchRateTriggerTest-collection1 s:shard2 r:core_node7 x:SearchRateTriggerTest-collection1_shard2_replica_n4] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.SearchRateTriggerTest-collection1.shard2.leader, tag=3d26b470
[junit4] 2> 158668 INFO (jetty-closer-94-thread-4) [ ] o.a.s.c.Overseer Overseer (id=72147851664490507-127.0.0.1:41853_solr-n_0000000000) closing
[junit4] 2> 158668 INFO (jetty-closer-94-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@31639c8{/solr,null,UNAVAILABLE}
[junit4] 2> 158668 INFO (jetty-closer-94-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 158668 INFO (OverseerStateUpdate-72147851664490507-127.0.0.1:41853_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:41853_solr
[junit4] 2> 158669 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1005216bdc5000c, likely client has closed socket
[junit4] 2> 158669 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1005216bdc50010, likely client has closed socket
[junit4] 2> 158673 WARN (OverseerAutoScalingTriggerThread-72147851664490507-127.0.0.1:41853_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 158674 INFO (jetty-closer-94-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@114d5a1c{/solr,null,UNAVAILABLE}
[junit4] 2> 158674 INFO (jetty-closer-94-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 158675 INFO (jetty-closer-94-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@765f729f{/solr,null,UNAVAILABLE}
[junit4] 2> 158675 INFO (jetty-closer-94-thread-4) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 160170 INFO (jetty-closer-94-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6cdd1ac{/solr,null,UNAVAILABLE}
[junit4] 2> 160170 INFO (jetty-closer-94-thread-3) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 160171 ERROR (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 160171 INFO (SUITE-SearchRateTriggerTest-seed#[32856CA0C9BC5F51]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34535 34535
[junit4] 2> 160954 INFO (Thread-68) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34535 34535
[junit4] 2> 160955 WARN (Thread-68) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 12 /solr/aliases.json
[junit4] 2> 12 /solr/collections/SearchRateTriggerTest-collection1/terms/shard1
[junit4] 2> 12 /solr/collections/SearchRateTriggerTest-collection1/terms/shard2
[junit4] 2> 8 /solr/configs/conf
[junit4] 2> 8 /solr/collections/SearchRateTriggerTest-collection2/terms/shard2
[junit4] 2> 8 /solr/collections/SearchRateTriggerTest-collection2/terms/shard1
[junit4] 2> 4 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 12 /solr/clusterprops.json
[junit4] 2> 12 /solr/clusterstate.json
[junit4] 2> 8 /solr/collections/SearchRateTriggerTest-collection1/state.json
[junit4] 2> 4 /solr/collections/SearchRateTriggerTest-collection2/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 21 /solr/collections
[junit4] 2> 12 /solr/live_nodes
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SearchRateTriggerTest_32856CA0C9BC5F51-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=517, maxMBSortInHeap=7.4658036842382005, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@57b075d2), locale=el-CY, timezone=Europe/Copenhagen
[junit4] 2> NOTE: Linux 4.13.0-39-generic amd64/Oracle Corporation 1.8.0_162 (64-bit)/cpus=8,threads=1,free=379483736,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [SearchRateTriggerTest, SearchRateTriggerTest]
[junit4] Completed [4/5 (1!)] on J0 in 52.98s, 3 tests, 1 failure <<< FAILURES!
[junit4]
[junit4] Suite: org.apache.solr.cloud.autoscaling.SearchRateTriggerTest
[junit4] OK 64.2s J1 | SearchRateTriggerTest.testTrigger
[junit4] OK 1.69s J1 | SearchRateTriggerTest.testDefaultsAndBackcompat
[junit4] OK 23.7s J1 | SearchRateTriggerTest.testWaitForElapsed
[junit4] Completed [5/5 (1!)] on J1 in 91.19s, 3 tests
[junit4]
[junit4]
[junit4] Tests with failures [seed: 32856CA0C9BC5F51]:
[junit4] - org.apache.solr.cloud.autoscaling.SearchRateTriggerTest.testTrigger
[junit4]
[junit4]
[junit4] JVM J0: 0.70 .. 161.55 = 160.84s
[junit4] JVM J1: 0.71 .. 202.26 = 201.55s
[junit4] JVM J2: 0.70 .. 110.89 = 110.19s
[junit4] Execution time total: 3 minutes 22 seconds
[junit4] Tests summary: 5 suites, 15 tests, 1 failure
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/common-build.xml:1568: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/common-build.xml:1092: There were test failures: 5 suites, 15 tests, 1 failure [seed: 32856CA0C9BC5F51]
Total time: 3 minutes 23 seconds
[repro] Setting last failure code to 256
[repro] Failures:
[repro] 1/5 failed: org.apache.solr.cloud.autoscaling.SearchRateTriggerTest
[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=ab58b7f9ba646a294005f1e433e4faee43c7d22b, workspace=/var/lib/jenkins/workspace/Lucene-Solr-master-Linux
[WARNINGS] Computing warning deltas based on reference build #21994
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